[ Bug ] parseFiles callback is called after the returning promise is resolved

[ShenQingchuan]

Summary

callback of parseFiles is called even after parseFiles promise is resolved.

Reproduction repo

https://github.com/ShenQingchuan/repro-sg-parse-files-0.2.2

Reproduction

You could see this kind of output in reproduction:

File: /workspace/repro-sg-parse-files/src/mockFiles/test-file-7304-7bf21e37-8fda-473d-8d0f-74804dd95620.js - Run callback
File: /workspace/repro-sg-parse-files/src/mockFiles/test-file-7303-9f5f76c6-b72f-46bf-a2b7-1c1e01c01a56.tsx - Run callback
File: /workspace/repro-sg-parse-files/src/mockFiles/test-file-7302-d89a12ba-0e94-4e3f-bd95-a0b3ff1fca4e.tsx - Run callback
File: /workspace/repro-sg-parse-files/src/mockFiles/test-file-7301-c85276ef-f257-4563-bc63-74ca8084f8ec.js - Run callback
File: /workspace/repro-sg-parse-files/src/mockFiles/test-file-7300-649fcf13-ce01-4f6f-900b-da37d249b6ca.tsx - Run callback

 --- Main Function Over ---

/workspace/repro-sg-parse-files/src/mockFiles/test-file-9999-5113bbf8-4df2-4bde-b3de-3f13155ede8a.tsx == Imports ==>
/workspace/repro-sg-parse-files/src/mockFiles/test-file-9998-eadc0534-fc86-4a20-acd7-e95d60410f31.ts == Imports ==> './dynamic-plain-65/some-file-1', './dynamic-plain-34/some-file-2', './dynamic-plain-43/some-file-3'

the async function runAstGrepParse is not worked as expected, it should end after every callback function synchronously executed.

Issue cause

Limit maximum synchronous iteration count to prevent event loop
starvation. See src/node_messaging.cc for an inspiration.

https://github.com/nodejs/node/blob/8ba54e50496a6a5c21d93133df60a9f7cb6c46ce/src/node_api.cc#L336

[HerringtonDarkholme]

Thanks for the reporting and the detailed reproduction! It is very helpful!

I have found the root cause of the problem. Sorry to introduce this bug due to my limited understanding of Napi and NodeJS.

Here is the detailed walk through of this bug. I hope it can help you.

---

Background

The parseFiles in ast-grep is implemented by napi-rs' thread safe function. Its behavior is more detailed documented here.

The crux of the problem is that calling thread safe function in napi from Rust will not actually call the JavaScript function. Instead, the callback task is pushed to a queue as a record.

Issue

I expect the parseFiles function call should be resolved only after all JS callbacks are executed. I suspected that pushing to the queue will not immediately call the JS function.
And the bug will be reproduced if Rust has pushed all files to the queue but NodeJS did not feed them to JavaScript. However, when I tried to reproduce the issue by increasing the execution time of the callback, the issue cannot be reproduced, no matter how long I synchronously sleep.

So when will the queue execution be yielded?

Investigation

I investigated the BlockingCall API. It looks like the function just call the C API: napi_call_threadsafe_function.
And that function will eventually call the Push method of ThreadSafeFunction, which looks totally innocent.

Further Repro

I tried another way to reproduce the issue by reducing the file items. Curiously, the returning promise almost always stop when file count is 999.

It probably means that NodeJS will suspend the callback execution when item count reaches 1000. So I "GitHub Search"ed the NodeJS core. Fortunately the 1000 magic number has only a few matching hits.

Indeed! NodeJS' event loop will not drain the sync task queue!

After 1000 files are processed by JavaScript, NodeJS will take a break to make event loop progress. But Rust will ruthlessly push all files to the queue. And the parseFile promise will resolve immediately after all files are pushed while files are still in the message queue awaiting JS callback.

[HerringtonDarkholme]

Fixed in ac266db

[evangalen]

I'm a bit confused about the fact that this issue is Closed whereas the documentatiom of findInFiles still refers to this issue as if it's not fixed.

[HerringtonDarkholme]

This is not fixable in JavaScript world. Nothing to do from our side so the issue is closed.