Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

I am able to reproduce this with https://github.com/jaydenseric/graphql-upload/commit/3b7f034e1c2d084f314734377c4351c171b87a42 on macOS. It does not reproduce 100% of the time (possibly a race condition?) so I used a small bash script: #51314

Closed
jjakj opened this issue Dec 30, 2023 · 1 comment
Labels
invalid Issues and PRs that are invalid.

Comments

@jjakj
Copy link

jjakj commented Dec 30, 2023

          I am able to reproduce this with https://github.com/jaydenseric/graphql-upload/commit/3b7f034e1c2d084f314734377c4351c171b87a42 on macOS. It does not reproduce 100% of the time (possibly a race condition?) so I used a small bash script:
while :
do
  NODE_V8_COVERAGE=./coverage ~/iojs/node/node processRequest.test.mjs
done

I believe this is only related to NODE_V8_COVERAGE and not the test runner. Also note that the bash script does not use --test. I've also heard from other folks that this can be reproduced without the test runner (ie, using node-tap on a different codebase).

When NODE_V8_COVERAGE is present, the inspector is enabled at startup. When the process is getting ready to exit, we call EndStartedProfilers().

I'm not yet sure if we are missing some cleanup step, but when the process hangs, we enter an infinite loop of flushing and adding new tasks:

(lldb) bt
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  * frame #0: 0x000000018886a1e0 libsystem_malloc.dylib`nanov2_pointer_size + 312
    frame #1: 0x000000018886a06c libsystem_malloc.dylib`nanov2_size + 32
    frame #2: 0x0000000188869e48 libsystem_malloc.dylib`free + 148
    frame #3: 0x000000010295f52c node`node::PerIsolatePlatformData::FlushForegroundTasksInternal() [inlined] std::__1::default_delete<v8::Task>::operator()(this=<unavailable>, __ptr=0x00006000013c8720) const at memory:1428:5 [opt]
    frame #4: 0x000000010295f51c node`node::PerIsolatePlatformData::FlushForegroundTasksInternal() [inlined] std::__1::unique_ptr<v8::Task, std::__1::default_delete<v8::Task>>::reset(this=<unavailable>, __p=0x0000000000000000) at memory:1689:7 [opt]
    frame #5: 0x000000010295f514 node`node::PerIsolatePlatformData::FlushForegroundTasksInternal() [inlined] std::__1::unique_ptr<v8::Task, std::__1::default_delete<v8::Task>>::~unique_ptr(this=<unavailable>) at memory:1643:19 [opt]
    frame #6: 0x000000010295f514 node`node::PerIsolatePlatformData::FlushForegroundTasksInternal() [inlined] std::__1::unique_ptr<v8::Task, std::__1::default_delete<v8::Task>>::~unique_ptr(this=<unavailable>) at memory:1643:17 [opt]
    frame #7: 0x000000010295f514 node`node::PerIsolatePlatformData::FlushForegroundTasksInternal(this=0x000000014ae073f8) at node_platform.cc:494:5 [opt]
    frame #8: 0x0000000102960b34 node`node::NodePlatform::DrainTasks(this=0x0000600002ce4000, isolate=<unavailable>) at node_platform.cc:457:25 [opt]
    frame #9: 0x00000001028311b0 node`node::FreeEnvironment(env=<unavailable>) at environment.cc:513:15 [opt]
    frame #10: 0x000000010293ead8 node`node::NodeMainInstance::Run() [inlined] node::FunctionDeleter<node::Environment, &node::FreeEnvironment(node::Environment*)>::operator()(this=<unavailable>, pointer=0x000000014b033800) const at util.h:675:39 [opt]
    frame #11: 0x000000010293ead0 node`node::NodeMainInstance::Run() [inlined] std::__1::unique_ptr<node::Environment, node::FunctionDeleter<node::Environment, &node::FreeEnvironment(node::Environment*)>>::reset(this=<unavailable>, __p=0x0000000000000000) at memory:1689:7 [opt]
    frame #12: 0x000000010293ead0 node`node::NodeMainInstance::Run() [inlined] std::__1::unique_ptr<node::Environment, node::FunctionDeleter<node::Environment, &node::FreeEnvironment(node::Environment*)>>::~unique_ptr(this=<unavailable>) at memory:1643:19 [opt]
    frame #13: 0x000000010293ead0 node`node::NodeMainInstance::Run() [inlined] std::__1::unique_ptr<node::Environment, node::FunctionDeleter<node::Environment, &node::FreeEnvironment(node::Environment*)>>::~unique_ptr(this=<unavailable>) at memory:1643:17 [opt]
    frame #14: 0x000000010293ead0 node`node::NodeMainInstance::Run(this=<unavailable>) at node_main_instance.cc:90:1 [opt]
    frame #15: 0x00000001028c76c8 node`node::Start(int, char**) [inlined] node::StartInternal(argc=<unavailable>, argv=<unavailable>) at node.cc:1374:24 [opt]
    frame #16: 0x00000001028c762c node`node::Start(argc=<unavailable>, argv=<unavailable>) at node.cc:1381:27 [opt]
    frame #17: 0x00000001083f50f4 dyld`start + 520

At least some of the new tasks are coming from v8::internal::Heap::PostFinalizationRegistryCleanupTaskIfNeeded() (note that I added a printf() if you're curious about the top couple frames):

(lldb) bt
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  * frame #0: 0x0000000188a1d8d4 libsystem_kernel.dylib`__write_nocancel + 8
    frame #1: 0x000000018894ce14 libsystem_c.dylib`__swrite + 24
    frame #2: 0x000000018892c1ac libsystem_c.dylib`_swrite + 108
    frame #3: 0x000000018891e564 libsystem_c.dylib`__sfvwrite + 492
    frame #4: 0x0000000188948df8 libsystem_c.dylib`puts + 152
    frame #5: 0x000000010256389c node`non-virtual thunk to node::PerIsolatePlatformData::PostNonNestableTask(std::__1::unique_ptr<v8::Task, std::__1::default_delete<v8::Task>>) [inlined] node::PerIsolatePlatformData::PostNonNestableTask(this=<unavailable>, task=v8::Task @ 0x00006000010abb90) at node_platform.cc:281:3 [opt]
    frame #6: 0x0000000102563890 node`non-virtual thunk to node::PerIsolatePlatformData::PostNonNestableTask(std::__1::unique_ptr<v8::Task, std::__1::default_delete<v8::Task>>) at node_platform.cc:0 [opt]
    frame #7: 0x0000000102884418 node`v8::internal::Heap::PostFinalizationRegistryCleanupTaskIfNeeded(this=0x00000001280152b8) at heap.cc:6559:15 [opt]
    frame #8: 0x0000000102863874 node`v8::internal::FinalizationRegistryCleanupTask::RunInternal(this=0x00006000010abbd0) at finalization-registry-cleanup-task.cc:98:10 [opt]
    frame #9: 0x0000000102564880 node`node::PerIsolatePlatformData::RunForegroundTask(this=0x00000001216051e8, task=v8::Task @ 0x00006000010abbf0) at node_platform.cc:435:11 [opt]
    frame #10: 0x0000000102563504 node`node::PerIsolatePlatformData::FlushForegroundTasksInternal(this=0x00000001216051e8) at node_platform.cc:504:5 [opt]
    frame #11: 0x0000000102564b88 node`node::NodePlatform::DrainTasks(this=0x0000600002f98000, isolate=<unavailable>) at node_platform.cc:462:25 [opt]
    frame #12: 0x00000001024351b0 node`node::FreeEnvironment(env=<unavailable>) at environment.cc:513:15 [opt]
    frame #13: 0x0000000102542ad8 node`node::NodeMainInstance::Run() [inlined] node::FunctionDeleter<node::Environment, &node::FreeEnvironment(node::Environment*)>::operator()(this=<unavailable>, pointer=0x0000000121822c00) const at util.h:675:39 [opt]
    frame #14: 0x0000000102542ad0 node`node::NodeMainInstance::Run() [inlined] std::__1::unique_ptr<node::Environment, node::FunctionDeleter<node::Environment, &node::FreeEnvironment(node::Environment*)>>::reset(this=<unavailable>, __p=0x0000000000000000) at memory:1689:7 [opt]
    frame #15: 0x0000000102542ad0 node`node::NodeMainInstance::Run() [inlined] std::__1::unique_ptr<node::Environment, node::FunctionDeleter<node::Environment, &node::FreeEnvironment(node::Environment*)>>::~unique_ptr(this=<unavailable>) at memory:1643:19 [opt]
    frame #16: 0x0000000102542ad0 node`node::NodeMainInstance::Run() [inlined] std::__1::unique_ptr<node::Environment, node::FunctionDeleter<node::Environment, &node::FreeEnvironment(node::Environment*)>>::~unique_ptr(this=<unavailable>) at memory:1643:17 [opt]
    frame #17: 0x0000000102542ad0 node`node::NodeMainInstance::Run(this=<unavailable>) at node_main_instance.cc:90:1 [opt]
    frame #18: 0x00000001024cb6c8 node`node::Start(int, char**) [inlined] node::StartInternal(argc=<unavailable>, argv=<unavailable>) at node.cc:1374:24 [opt]
    frame #19: 0x00000001024cb62c node`node::Start(argc=<unavailable>, argv=<unavailable>) at node.cc:1381:27 [opt]
    frame #20: 0x0000000107e090f4 dyld`start + 520

@nodejs/v8 does anything immediately stand out to you?

Originally posted by @cjihrig in #49344 (comment)

@legendecas
Copy link
Member

legendecas commented Jan 2, 2024

I didn't see the difference from the original post and didn't find the necessity to create a new issue for this post. Please avoid using "Reference in a new issue" button if the original comment is not a new topic.

Closing.

@legendecas legendecas closed this as not planned Won't fix, can't repro, duplicate, stale Jan 2, 2024
@legendecas legendecas added the invalid Issues and PRs that are invalid. label Jan 2, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
invalid Issues and PRs that are invalid.
Projects
None yet
Development

No branches or pull requests

2 participants