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

Worker Threads can't read stdout #24636

Closed
Ethan-Arrowood opened this issue Nov 25, 2018 · 3 comments
Closed

Worker Threads can't read stdout #24636

Ethan-Arrowood opened this issue Nov 25, 2018 · 3 comments

Comments

@Ethan-Arrowood
Copy link
Contributor

  • Version: 11.2.0
  • Platform: Darwin Ethans-MacBook-Pro.local 18.0.0 Darwin Kernel Version 18.0.0: Wed Aug 22 20:13:40 PDT 2018; root:xnu-4903.201.2~1/RELEASE_X86_64 x86_64
  • Subsystem:

Hard to describe this bug but I'd like to document the strange behaviour I am experiencing with this experimental feature.

const {
  Worker, isMainThread, parentPort, workerData, theadId, MessageChannel
} = require('worker_threads')

const DATA = [
  7, 12, 19, 3, 18, 16, 4, 2,
  6, 9, 18, 38, 15, 8, 123, 72,
  4, 3, 11, 33, 15, 48, 13, 17,
  23, 19, 30, 45, 31, 1, 14, 50
]

const TYPE_SORT_THREAD = 'sort_thread'

if (isMainThread) {
  console.log("I'm the main thread")

  // Split data
  const x = DATA.slice(0, DATA.length/2)
  const y = DATA.slice(DATA.length/2, DATA.length)

  const sortedArrays = []

  function sortThreadCb(sortedArray) {
    console.log('Sorted array: ', sortedArray)
    sortedArrays.push(sortedArray)
  }

  for (var subArray of [x, y]) {
    let sortThread = new Worker(__filename, { workerData: {
      array: subArray,
      type: TYPE_SORT_THREAD
    }})
    sortThread.on('message', sorted => sortThreadCb(sorted))
  }


} else {
  console.log("I'm a sub thread")

  if ( workerData.type === TYPE_SORT_THREAD) {
    console.log("I'm a sort thread")
    let { array } = workerData
    array.sort((a, b) => a - b)
    // console.log('foobar') <-- REFERENCE THIS LINE
    parentPort.postMessage(array)
  } 
}

In the above code snippet, the expected output looks something like so (due to the way threading works sometimes the console is out of order but I do not think this is relevant):

I'm the main thread
I'm a sub thread
I'm a sort thread
Sorted array:  [ 2, 3, 4, 6, 7, 8, 9, 12, 15, 16, 18, 18, 19, 38, 72, 123 ]
I'm a sub thread
I'm a sort thread
Sorted array:  [ 1, 3, 4, 11, 13, 14, 15, 17, 19, 23, 30, 31, 33, 45, 48, 50 ]

However, with the console.log('foobar') line commented out I get this output (and error message instead):

Ethans-MacBook-Pro:lab5 ethanarrowood$ node --experimental-worker lab5.js
I'm the main thread
I'm a sub thread
Sorted array:  [ 2, 3, 4, 6, 7, 8, 9, 12, 15, 16, 18, 18, 19, 38, 72, 123 ]
I'm a sub thread
I'm a sort thread
Sorted array:  [ 1, 3, 4, 11, 13, 14, 15, 17, 19, 23, 30, 31, 33, 45, 48, 50 ]
internal/worker.js:346
        return this[kParentSideStdio][stream].push(chunk, encoding);
                                     ^

TypeError: Cannot read property 'stdout' of null
    at Worker.[kOnMessage] (internal/worker.js:346:38)
    at MessagePort.Worker.(anonymous function).on (internal/worker.js:279:57)
    at MessagePort.emit (events.js:182:13)
    at MessagePort.onmessage (internal/worker.js:84:8)

The error trace does not have a line from my lab5.js to reference.

The actual output when console.log('foobar') is active is:

I'm the main thread
I'm a sub thread
Sorted array:  [ 2, 3, 4, 6, 7, 8, 9, 12, 15, 16, 18, 18, 19, 38, 72, 123 ]
I'm a sub thread
Sorted array:  [ 1, 3, 4, 11, 13, 14, 15, 17, 19, 23, 30, 31, 33, 45, 48, 50 ]
I'm a sort thread
foobar
I'm a sort thread
foobar

Order does not seem perfectly correct but I don't think that is an issue AFAIK.

I'm not exactly expecting a solution to this just wanted to bring this behavior to whichever contributors are working on this part of Node JS

@Trott
Copy link
Member

Trott commented Nov 25, 2018

@nodejs/workers

@benjamingr
Copy link
Member

@Ethan-Arrowood Thanks for the report! We're taking a look. I think for the very least the error message should be better.

leeight added a commit to leeight/node that referenced this issue Nov 26, 2018
@yaelhe
Copy link
Contributor

yaelhe commented Dec 2, 2018

I've figured out what's happening and have a fix coming up

yaelhe added a commit to yaelhe/node that referenced this issue Dec 10, 2018
When the worker thread exits, drain the messages also from the internal
message port so that the call to 'kDispose' will occur only after all
the messages from the worker were processed in the parent, so stdio
messages from the worker will be successfully pushed to their target
streams in the parent.

Fixes: nodejs#24636
@danbev danbev closed this as completed in c61327d Dec 13, 2018
BethGriggs pushed a commit that referenced this issue Dec 17, 2018
When the worker thread exits, drain the messages also from the internal
message port so that the call to 'kDispose' will occur only after all
the messages from the worker were processed in the parent, so stdio
messages from the worker will be successfully pushed to their target
streams in the parent.

PR-URL: #24932
Fixes: #24636
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Anna Henningsen <[email protected]>
refack pushed a commit to refack/node that referenced this issue Jan 14, 2019
When the worker thread exits, drain the messages also from the internal
message port so that the call to 'kDispose' will occur only after all
the messages from the worker were processed in the parent, so stdio
messages from the worker will be successfully pushed to their target
streams in the parent.

PR-URL: nodejs#24932
Fixes: nodejs#24636
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Anna Henningsen <[email protected]>
BethGriggs pushed a commit that referenced this issue Feb 12, 2019
When the worker thread exits, drain the messages also from the internal
message port so that the call to 'kDispose' will occur only after all
the messages from the worker were processed in the parent, so stdio
messages from the worker will be successfully pushed to their target
streams in the parent.

PR-URL: #24932
Fixes: #24636
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Anna Henningsen <[email protected]>
BethGriggs pushed a commit that referenced this issue Feb 20, 2019
When the worker thread exits, drain the messages also from the internal
message port so that the call to 'kDispose' will occur only after all
the messages from the worker were processed in the parent, so stdio
messages from the worker will be successfully pushed to their target
streams in the parent.

PR-URL: #24932
Fixes: #24636
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Anna Henningsen <[email protected]>
rvagg pushed a commit that referenced this issue Feb 28, 2019
When the worker thread exits, drain the messages also from the internal
message port so that the call to 'kDispose' will occur only after all
the messages from the worker were processed in the parent, so stdio
messages from the worker will be successfully pushed to their target
streams in the parent.

PR-URL: #24932
Fixes: #24636
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Anna Henningsen <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
4 participants