src: fix cb scope bugs involved in termination #45596

ywave620 · 2022-11-23T09:11:28Z

An inheritor of #45422 and a fix to #43084. I move the original failing test back to the test/parallel/ to increase the chance that it exercises the defect, at which this PR is targeted.

To see the bug in 43084, apply this patch and run the script

diff --git a/src/env.cc b/src/env.cc
index 2f0720d402..5a4d9b2146 100644
--- a/src/env.cc
+++ b/src/env.cc
@@ -27,6 +27,8 @@
 #include <iostream>
 #include <limits>
 #include <memory>
+#include <thread> 
+#include <chrono>
 
 namespace node {
 
@@ -907,6 +909,7 @@ void Environment::InitializeLibuv() {
 void Environment::ExitEnv() {
   set_can_call_into_js(false);
   set_stopping(true);
+  std::this_thread::sleep_for(std::chrono::milliseconds(2000));
   isolate_->TerminateExecution();
   SetImmediateThreadsafe([](Environment* env) { uv_stop(env->event_loop()); });
 }

// Flags: --expose-internals

'use strict';
const common = require('../common');
const { Worker } = require('worker_threads');

/**
 * This file is a minimal possible reproduction and an
 * explanation of https://github.com/nodejs/node/issues/43084.
 *
 * It can not trigger the bug consistently because
 * that would require a rare thread execution interleaving
 * condition.
 *
 * test-worker-http2-stream-terminate.js has a bigger chance
 * to trigger the bug.
 */

if (!process.env.HAS_STARTED_WORKER) {
  process.env.HAS_STARTED_WORKER = 1;

  const workerData = new Int32Array(new SharedArrayBuffer(4));
  const w = new Worker(__filename, { workerData });
  w.on('exit', common.mustCall());

  // Wait for the worker to enter the _write() below
  // eslint-disable-next-line
  while (Atomics.load(workerData, 0) !== 1) {}
  w.terminate(); // node::Environment::ExitEnv() is called under the hood

  return;
}

// --------- worker thread ---------

const JSStreamSocket = require('internal/js_stream_socket');
const { Duplex } = require('stream');

class DummyDuplex extends Duplex {
  _read() {
  }

  _write(chunk, encoding, callback) {
    /**
     * Now, this worker thread has a stack looks like:
     * _pthread_start
     * ...
     * node::CheckImmediate
     * ...
     * node::MakeCallback
     * ...
     * v8::internal::FunctionCallbackArguments::Call
     * ...
     * node::MakeCallback
     * ...
     */

    const { workerData } = require('worker_threads');
    Atomics.store(workerData, 0, 1);

    // Make some time for the main thread to enter node::Environment::ExitEnv()
    // eslint-disable-next-line
    for (let i = 0; i < 1000000; i++) {}

    // Just before this function returns, if the main thread
    // 1. called node::Environment::ExitEnv()/set_can_call_into_js(false)
    // 2. but did not called node::Environment::ExitEnv()/TerminateExecution() yet
    // 3. and got suspended by the OS
    // Without the fix, this bug https://github.com/nodejs/node/issues/43084 occurs
    // and emitAfter() in processImmediate() in lib/internal/timers.js complains
    // Error: async hook stack has become corrupted (actual: 6, expected: 5)
  }

  _final(callback) {
  }
}

setImmediate(() => {
  const sock = new JSStreamSocket(new DummyDuplex());
  sock.write(Buffer.alloc(10));
  // JSStreamSocket basically delegate r/w to the Duplex paased to its constructor
  // It is a net.Socket
  // lib/net.js write()
  //  lib/internal/stream_base_commons.js writeGeneric()
  //    handleWriteReq()
  //      handle.writeBuffer()
  //        node::StreamBase::WriteBuffer()
  //          node::StreamBase::Write()
  //            node::JSStream::DoWrite()
  //              call to the above DummyDuplex
});

ywave620 · 2022-12-02T06:54:07Z

Any idea? :)

legendecas · 2022-12-06T15:16:29Z

Stress test: https://ci.nodejs.org/job/node-stress-single-test/383

test/parallel/test-worker-with-nested-async-stack-gets-terminated.js

nodejs-github-bot · 2022-12-06T15:48:11Z

CI: https://ci.nodejs.org/job/node-test-pull-request/48311/

ywave620 · 2022-12-13T06:25:24Z

@legendecas Could you run the CI for this?

nodejs-github-bot · 2022-12-15T03:31:36Z

CI: https://ci.nodejs.org/job/node-test-pull-request/48495/

legendecas · 2022-12-19T06:28:24Z

src/api/callback.cc

  auto perform_stopping_check = [&]() {
-    if (env_->is_stopping()) {
+    if (!env_->can_call_into_js()) {


The difference here between !env_->can_call_into_js() and env_->is_stopping() is trivial. Environment::can_call_into_js() also checks if Environment::is_stopping_ is set. Maybe @addaleax can chime in here?

If this line is updated, the lambda variable should also be renamed as perform_call_js_check or similar. Also, I'd find the checks if (!env_->can_call_into_js()) return; below can be merged with this lambda call too.

Yeah, semantically, this should be checking for whether we’re currently stopping the current environment through a termination exception, so is_stopping() would seem to be the correct choice?

ywave620 · 2023-02-15T08:21:05Z

Any thoughts on this PR?

legendecas · 2023-02-16T15:16:48Z

Would you mind updating the PR according to addaleax's comment above? Thanks!

ywave620 · 2023-02-20T02:52:11Z

@legendecas addaleax's suggestion does not fix the bug. Please see above for why.

I suggest that remove set_can_call_into_js(false) from Environment::ExitEnv(), this is ok because can_call_into_js() also check is_stopping():

node/src/env-inl.h

Lines 637 to 639 in c203921

    
           inline bool Environment::can_call_into_js() const { 
        
             return can_call_into_js_ && !is_stopping(); 
        
           }

legendecas · 2023-02-20T02:59:12Z

With #45907, env->is_stopping() implies !env->can_call_into_js() on the JavaScript thread. With regard to the comment of #45596 (comment), the current check on if env is stopping is the expected semantic.

Be more aggresive to clean up the async id stack, and ensure the cleanup when terminating. Calling SetIdle() when terminating is not harmless. When node terminates due to an unhandled exception, v8 preseves the vm state, which is JS and notifies node through PerIsolateMessageListener(). If node calls SetIdle() later, v8 complains because it requires the vm state to either be EXTERNEL or IDLE when embedder calling SetIdle().

ywave620 · 2023-02-20T09:10:29Z

@legendecas Got you. Changed, PTAL

legendecas

Thanks!

nodejs-github-bot · 2023-02-20T16:40:35Z

CI: https://ci.nodejs.org/job/node-test-pull-request/49793/

ywave620 · 2023-02-21T04:21:50Z

A test crashed. I wonder if there is a way to get a full stacktrace 🤔️
https://ci.nodejs.org/job/node-test-commit-osx-arm/10087/nodes=osx11/testReport/junit/(root)/test/parallel_test_tls_server_verify/

Failing for the past 1 build (Since [#10087](https://ci.nodejs.org/job/node-test-commit-osx-arm/10087/nodes=osx11/) )
[Took 0.85 sec.](https://ci.nodejs.org/job/node-test-commit-osx-arm/10087/nodes=osx11/testReport/junit/(root)/test/parallel_test_tls_server_verify/history)
Error Message
crashed (-10)
Stacktrace
0 0   connecting with agent1
0 1   connecting with agent2
0 2   connecting with agent3
0 3   connecting with nocert
1 0   connecting with agent1
1 1   connecting with agent2
1 2   connecting with agent3
1 3   connecting with nocert
2 0   connecting with agent1
2 1   connecting with agent2
2 2   connecting with agent3
2 3   connecting with nocert
3 0   connecting with agent1
3 1   connecting with agent2
3 2   connecting with agent3
3 3   connecting with nocert
4 0   connecting with agent1
4 1   connecting with agent2
4 2   connecting with agent3
4 3   connecting with nocert
5 0   connecting with agent1
5 1   connecting with agent2
5 2   connecting with agent3
5 3   connecting with agent4
0 Running 'Do not request certs. Everyone is unauthorized.'
0 - unauthed connection: null
0 - unauthed connection: null
0 2   * unauthed
0 1   * unauthed
0 - unauthed connection: null
0 0   * unauthed
0 - unauthed connection: null
0 3   * unauthed
1 Running 'Allow both authed and unauthed connections with CA1'
1 - unauthed connection: DEPTH_ZERO_SELF_SIGNED_CERT
1 - authed connection: agent1
1 - unauthed connection: UNABLE_TO_VERIFY_LEAF_SIGNATURE
1 1   * unauthed
1 0   * authed
1 2   * unauthed
1 - unauthed connection: UNABLE_TO_GET_ISSUER_CERT
1 3   * unauthed
2 Running 'Do not request certs at connection. Do that later'
2 - connected, renegotiating
2 - authed connection: agent1
2 0   * authed
2 - unauthed connection: null
2 1   * unauthed
2 - unauthed connection: null
2 2   * unauthed
2 - unauthed connection: null
2 3   * unauthed
3 Running 'Allow only authed connections with CA1'
3 - authed connection: agent1
3 0   * authed
4 Running 'Allow only authed connections with CA1 and CA2'
4 - authed connection: agent3
4 - authed connection: agent1
4 2   * authed
4 0   * authed
5 Running 'Allow only certs signed by CA2 but not in the CRL'

nodejs-github-bot · 2023-02-22T05:58:35Z

CI: https://ci.nodejs.org/job/node-test-pull-request/49863/

legendecas · 2023-02-22T05:58:48Z

According to the reliability report nodejs/reliability#503, the failed test doesn't seem to be introduced in this PR. I've resumed the build.

ywave620 · 2023-02-25T12:37:39Z

@legendecas Could you merge this?

nodejs-github-bot · 2023-02-28T03:17:48Z

Landed in 7a37829

Be more aggresive to clean up the async id stack, and ensure the cleanup when terminating. Calling SetIdle() when terminating is not harmless. When node terminates due to an unhandled exception, v8 preseves the vm state, which is JS and notifies node through PerIsolateMessageListener(). If node calls SetIdle() later, v8 complains because it requires the vm state to either be EXTERNEL or IDLE when embedder calling SetIdle(). PR-URL: #45596 Reviewed-By: Chengzhong Wu <legendecas@gmail.com>

nodejs-github-bot added c++ Issues and PRs that require attention from people who are familiar with C++. needs-ci PRs that need a full CI run. labels Nov 23, 2022

ywave620 mentioned this pull request Nov 23, 2022

No call to SetIdle() when terminating #45422

Closed

legendecas reviewed Dec 6, 2022

View reviewed changes

test/parallel/test-worker-with-nested-async-stack-gets-terminated.js Outdated Show resolved Hide resolved

legendecas added the request-ci Add this label to start a Jenkins CI on a PR. label Dec 6, 2022

github-actions bot removed the request-ci Add this label to start a Jenkins CI on a PR. label Dec 6, 2022

legendecas added the request-ci Add this label to start a Jenkins CI on a PR. label Dec 15, 2022

github-actions bot removed the request-ci Add this label to start a Jenkins CI on a PR. label Dec 15, 2022

This was referenced Dec 17, 2022

CI Reliability 2022-12-17 nodejs/reliability#460

Open

CI Reliability 2022-12-18 nodejs/reliability#461

Open

CI Reliability 2022-12-19 nodejs/reliability#462

Open

legendecas reviewed Dec 19, 2022

View reviewed changes

ywave620 force-pushed the fix-terminate-issue branch from 53f19ce to af95ec8 Compare February 20, 2023 09:08

ywave620 requested a review from legendecas February 20, 2023 09:08

legendecas approved these changes Feb 20, 2023

View reviewed changes

legendecas added the request-ci Add this label to start a Jenkins CI on a PR. label Feb 20, 2023

github-actions bot removed the request-ci Add this label to start a Jenkins CI on a PR. label Feb 20, 2023

github-actions bot mentioned this pull request Feb 21, 2023

CI Reliability 2023-02-21 nodejs/reliability#502

Open

26 tasks

github-actions bot mentioned this pull request Feb 22, 2023

CI Reliability 2023-02-22 nodejs/reliability#503

Open

34 tasks

legendecas added the commit-queue Add this label to land a pull request using GitHub Actions. label Feb 28, 2023

nodejs-github-bot removed the commit-queue Add this label to land a pull request using GitHub Actions. label Feb 28, 2023

nodejs-github-bot merged commit 7a37829 into nodejs:main Feb 28, 2023

legendecas mentioned this pull request Feb 28, 2023

Crash if unhandled exception is thrown inside a node program with worker_threads inuse #45421

Closed

targos mentioned this pull request Mar 14, 2023

v19.8.0 release proposal #47087

Merged

danielleadams mentioned this pull request Apr 11, 2023

v18.16.0 release proposal #47502

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

src: fix cb scope bugs involved in termination #45596

src: fix cb scope bugs involved in termination #45596

ywave620 commented Nov 23, 2022 •

edited

Loading

ywave620 commented Dec 2, 2022

legendecas commented Dec 6, 2022

nodejs-github-bot commented Dec 6, 2022

ywave620 commented Dec 13, 2022

nodejs-github-bot commented Dec 15, 2022

legendecas Dec 19, 2022

addaleax Dec 20, 2022

ywave620 commented Feb 15, 2023

legendecas commented Feb 16, 2023

ywave620 commented Feb 20, 2023

legendecas commented Feb 20, 2023

ywave620 commented Feb 20, 2023

legendecas left a comment

nodejs-github-bot commented Feb 20, 2023

ywave620 commented Feb 21, 2023 •

edited

Loading

nodejs-github-bot commented Feb 22, 2023

legendecas commented Feb 22, 2023

ywave620 commented Feb 25, 2023

nodejs-github-bot commented Feb 28, 2023

src: fix cb scope bugs involved in termination #45596

src: fix cb scope bugs involved in termination #45596

Conversation

ywave620 commented Nov 23, 2022 • edited Loading

ywave620 commented Dec 2, 2022

legendecas commented Dec 6, 2022

nodejs-github-bot commented Dec 6, 2022

ywave620 commented Dec 13, 2022

nodejs-github-bot commented Dec 15, 2022

legendecas Dec 19, 2022

Choose a reason for hiding this comment

addaleax Dec 20, 2022

Choose a reason for hiding this comment

ywave620 commented Feb 15, 2023

legendecas commented Feb 16, 2023

ywave620 commented Feb 20, 2023

legendecas commented Feb 20, 2023

ywave620 commented Feb 20, 2023

legendecas left a comment

Choose a reason for hiding this comment

nodejs-github-bot commented Feb 20, 2023

ywave620 commented Feb 21, 2023 • edited Loading

nodejs-github-bot commented Feb 22, 2023

legendecas commented Feb 22, 2023

ywave620 commented Feb 25, 2023

nodejs-github-bot commented Feb 28, 2023

ywave620 commented Nov 23, 2022 •

edited

Loading

ywave620 commented Feb 21, 2023 •

edited

Loading