fix(ext/ffi): Avoid keeping JsRuntimeState RefCell borrowed for event loop middleware calls (#15116)

3 files changed, 125 insertions, 0 deletions

diff --git a/test_ffi/src/lib.rs b/test_ffi/src/lib.rs
index d6f29cbb8..257a47368 100644
--- a/test_ffi/src/lib.rs
+++ b/test_ffi/src/lib.rs
@@ -224,6 +224,20 @@ pub extern "C" fn call_stored_function_thread_safe() {
   });
 }
 
+#[no_mangle]
+pub extern "C" fn call_stored_function_thread_safe_and_log() {
+  std::thread::spawn(move || {
+    std::thread::sleep(std::time::Duration::from_millis(1500));
+    unsafe {
+      if STORED_FUNCTION.is_none() {
+        return;
+      }
+      STORED_FUNCTION.unwrap()();
+      println!("STORED_FUNCTION called");
+    }
+  });
+}
+
 // FFI performance helper functions
 #[no_mangle]
 pub extern "C" fn nop() {}
diff --git a/test_ffi/tests/event_loop_integration.ts b/test_ffi/tests/event_loop_integration.ts
new file mode 100644
index 000000000..c3b34cc8f
--- /dev/null
+++ b/test_ffi/tests/event_loop_integration.ts
@@ -0,0 +1,64 @@
+const targetDir = Deno.execPath().replace(/[^\/\\]+$/, "");
+const [libPrefix, libSuffix] = {
+  darwin: ["lib", "dylib"],
+  linux: ["lib", "so"],
+  windows: ["", "dll"],
+}[Deno.build.os];
+const libPath = `${targetDir}/${libPrefix}test_ffi.${libSuffix}`;
+
+const dylib = Deno.dlopen(
+  libPath,
+  {
+    store_function: {
+      parameters: ["function"],
+      result: "void",
+    },
+    call_stored_function: {
+      parameters: [],
+      result: "void",
+    },
+    call_stored_function_thread_safe_and_log: {
+      parameters: [],
+      result: "void",
+    },
+  } as const,
+);
+
+const tripleLogCallback = () => {
+  console.log("Sync");
+  Promise.resolve().then(() => {
+    console.log("Async");
+    callback.unref();
+  });
+  setTimeout(() => {
+    console.log("Timeout");
+    callback.unref();
+  }, 10);
+};
+
+const callback = new Deno.UnsafeCallback(
+  {
+    parameters: [],
+    result: "void",
+  } as const,
+  tripleLogCallback,
+);
+
+// Store function
+dylib.symbols.store_function(callback.pointer);
+
+// Synchronous callback logging
+console.log("SYNCHRONOUS");
+dylib.symbols.call_stored_function();
+console.log("STORED_FUNCTION called");
+
+// Wait to make sure synch logging and async logging
+await new Promise((res) => setTimeout(res, 100));
+
+// Ref twice to make sure both `Promise.resolve().then()` and `setTimeout()`
+// must resolve before isolate exists.
+callback.ref();
+callback.ref();
+
+console.log("THREAD SAFE");
+dylib.symbols.call_stored_function_thread_safe_and_log();
diff --git a/test_ffi/tests/integration_tests.rs b/test_ffi/tests/integration_tests.rs
index 5ca430f43..55b0f7a60 100644
--- a/test_ffi/tests/integration_tests.rs
+++ b/test_ffi/tests/integration_tests.rs
@@ -156,3 +156,50 @@ fn thread_safe_callback() {
   assert_eq!(stdout, expected);
   assert_eq!(stderr, "");
 }
+
+#[test]
+fn event_loop_integration() {
+  build();
+
+  let output = deno_cmd()
+    .arg("run")
+    .arg("--allow-ffi")
+    .arg("--allow-read")
+    .arg("--unstable")
+    .arg("--quiet")
+    .arg("tests/event_loop_integration.ts")
+    .env("NO_COLOR", "1")
+    .output()
+    .unwrap();
+  let stdout = std::str::from_utf8(&output.stdout).unwrap();
+  let stderr = std::str::from_utf8(&output.stderr).unwrap();
+  if !output.status.success() {
+    println!("stdout {}", stdout);
+    println!("stderr {}", stderr);
+  }
+  println!("{:?}", output.status);
+  assert!(output.status.success());
+  // TODO(aapoalas): The order of logging in thread safe callbacks is
+  // unexpected: The callback logs synchronously and creates an asynchronous
+  // logging task, which then gets called synchronously before the callback
+  // actually yields to the calling thread. This is in contrast to what the
+  // logging would look like if the call was coming from within Deno itself,
+  // and may lead users to unknowingly run heavy asynchronous tasks from thread
+  // safe callbacks synchronously.
+  // The fix would be to make sure microtasks are only run after the event loop
+  // middleware that polls them has completed its work. This just does not seem
+  // to work properly with Linux release builds.
+  let expected = "\
+    SYNCHRONOUS\n\
+    Sync\n\
+    STORED_FUNCTION called\n\
+    Async\n\
+    Timeout\n\
+    THREAD SAFE\n\
+    Sync\n\
+    Async\n\
+    STORED_FUNCTION called\n\
+    Timeout\n";
+  assert_eq!(stdout, expected);
+  assert_eq!(stderr, "");
+}