Skip to content

Only a single console.log is logged from a worker when exiting #40961

Closed as not planned

Description

@kripken

Version

16.5.0

Platform

Linux64

Subsystem

No response

What steps will reproduce the bug?

Testcase:

const {
  Worker, isMainThread
} = require('worker_threads');

if (isMainThread) {
  console.log('main');
  const worker = new Worker(__filename, {});
} else {
  console.log('worker1');
  console.log('worker2');
  console.log('worker3');
  process.exit(0);
}

Run with node b.js

How often does it reproduce? Is there a required condition?

100% of the time.

What is the expected behavior?

I would expect to see

main
worker1
worker2
worker3

What do you see instead?

main
worker1

The main thread logged, but the worker only logged the first of three loggings.

Additional information

Somehow the first console.log is always logged out, but the other ones are stopped by the presence of the process.exit after them. This does not seem to be a race in my testing: the first one is always shown, and none of the others.

Returning to the main event loop after the first logging allows one more logging to show up. That is:

const {
  Worker, isMainThread
} = require('worker_threads');

if (isMainThread) {
  console.log('main');
  const worker = new Worker(__filename, {});
} else {
  console.log('worker1');
  setTimeout(() => { // return to main event loop after first logging
    console.log('worker2');
    console.log('worker3');
    process.exit(0);
  }, 0);
}

That prints out worker2. Once more a single logging appears of all those that are expected to happen, and worker3 is not logged.

This was noticed in Emscripten here: emscripten-core/emscripten#14804 Emscripten will use process.exit when the program is done, and we were only getting the first console.log out of all those the program prints. (As a workaround we write synchonously to the fd for stdout, which does work.)

Activity

  1. added
    workerIssues and PRs related to the worker_threads module and Worker API.
    on Nov 25, 2021
  2. added a commit that references this issue on Nov 25, 2021
  3. targos commented on Nov 25, 2021

    @targos
    Member

    @nodejs/workers

  4. addaleax commented on Nov 25, 2021

    @addaleax
    Member

    console.log() writes to stdout, which is an asynchrononous operation in Node.js (potentially also on the main thread, but always in worker threads). process.exit() exits synchronously, effectively aborting all currently ongoing asynchronous operations.

  5. RaisinTen commented on Nov 25, 2021

    @RaisinTen
    Member

    When #40813 lands, you will be able to wait for the async operations to be over before exiting like this:

    const {
      Worker, isMainThread
    } = require('worker_threads');
    
    if (isMainThread) {
      console.log('main');
      const worker = new Worker(__filename, {});
    } else {
      console.log('worker1');
      console.log('worker2');
      console.log('worker3');
      setInterval(() => process.getActiveResourcesInfo().length === 0 && process.exit(0));
    }
  6. addaleax commented on Nov 25, 2021

    @addaleax
    Member

    @RaisinTen Wouldn’t the interval also be a resource? 😉

    I think in general the recommendation here should be to let workers finish naturally whenever possible instead of using process.exit(), or using synchronous operations when you need synchronous operations (e.g. using Atomics here).

  7. RaisinTen commented on Nov 25, 2021

    @RaisinTen
    Member

    @RaisinTen Wouldn’t the interval also be a resource? 😉

    @addaleax I don't think the Immediate would be an active resource when the callback is run 🤔:

    console.log('before', process.getActiveResourcesInfo());
    setImmediate(() => console.log('during', process.getActiveResourcesInfo()));
    console.log('after', process.getActiveResourcesInfo());
    $ ./node test.js
    before []
    after [
      { type: 'TTYWrap', asyncId: 2, triggerAsyncId: 1 },
      { type: 'Immediate', asyncId: 5, triggerAsyncId: 1 }
    ]
    during [ { type: 'TTYWrap', asyncId: 2, triggerAsyncId: 1 } ]

    I think in general the recommendation here should be to let workers finish naturally whenever possible instead of using process.exit(), or using synchronous operations when you need synchronous operations (e.g. using Atomics here).

    👍

  8. addaleax commented on Nov 25, 2021

    @addaleax
    Member

    I don't think the Immediate would be an active resource when the callback is run 🤔:

    This is getting a bit off topic for this issue, but I'd consider that a bug.

  9. kripken commented on Nov 29, 2021

    @kripken
    Author

    Thanks for the info @RaisinTen and @addaleax !

    It's possible that with some work Emscripten can avoid calling process.exit() from workers and instead leave that to the main thread.

  10. sbc100 commented on Jul 31, 2023

    @sbc100

    FWIW, we work around this in emscripten by using fs.writeSync with 1 or 2 instead of console.error/log to implement our logging functions: https://github.com/emscripten-core/emscripten/blob/995ba815a9ac62b1de2d45b5bbb4b796f051cddb/src/shell.js#L432-L443.

    Without this, it makes the use of logging to debug of multi-threaded programs very hard, because normal program stdout/stderr doesn't interleave as expected with log messages.

  11. avivkeller commented on Jul 2, 2024

    @avivkeller
    Member

    Hey, is it known if the process.exit() is the cause of this, or it worker threads in general (ref: #53701)

  12. sbc100 commented on Jul 2, 2024

    @sbc100

    That looks like the same issue yes.

  13. avivkeller commented on Jul 3, 2024

    @avivkeller
    Member

    I'm aware it looks like the same issue, but is process.exit the core of this issue, or is it the worker_threads.

  14. sbc100 commented on Jul 3, 2024

    @sbc100

    I think it stems from the use of worker_threads that don't yield to event loop. Its seems that consecutive console message to not reach the console while you not yielding.

    This is very common in emscripten since workers that run pthreads normally never yield to the event loop.

  15. avivkeller commented on Jul 3, 2024

    @avivkeller
    Member

    Thanks for the insight!

  16. sbc100 commented on May 15, 2025

    @sbc100

    The original reproducer seems to seems to be fixed in node v24 (but still fails in node v23). Do I guess this issue can be closed even though we don't know what the actual fix way? Maybe somebody could bisect, or we could just close this issue?

  17. github-actions commented on Jun 25, 2026

    @github-actions
    Contributor

    This issue has been marked as stale due to 210 days of inactivity.
    It will be automatically closed in 30 days if no further activity occurs. If this is still relevant, please leave a comment or update it to keep it open.

  18. added
    staleIssues and PRs marked stale due to inactivity and scheduled for automatic closure.
    on Jun 25, 2026
  19. github-actions commented on Jul 26, 2026

    @github-actions
    Contributor

    This issue has been automatically closed after 30 days of inactivity following its stale status (no activity for a total of 120 days).
    If this is still relevant, feel free to reopen it or leave a comment with additional details so we can continue the discussion.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    staleIssues and PRs marked stale due to inactivity and scheduled for automatic closure.workerIssues and PRs related to the worker_threads module and Worker API.

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions