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

Promise never resolves if process output pipes are read first in node 18.14.0 #516

Closed
anomiex opened this issue Feb 9, 2023 · 5 comments

Comments

@anomiex
Copy link

anomiex commented Feb 9, 2023

Consider this code:

import { execa } from 'execa';
import readline from 'node:readline';

const proc = execa( 'find', [ '/usr/bin', '-type', 'f' ], { stdio: [ 'ignore', 'pipe', 'inherit' ] } );

const rl = readline.createInterface( {
	input: proc.stdout,
	crlfDelay: Infinity,
} );

let ct = 0;
for await ( const l of rl ) {
	ct++;
}
console.log( `Saw ${ct} files` );

const result = await proc;
console.log( `Process exit code: ${result.exitCode}` );

When run with execa 6.1.0 and node 18.14.0, node will exit without ever finishing the await, presumably due to the event loop becoming empty.

This seems to be something of the opposite of the caution that's already in the documentation for the buffer option:

When set to false, you must read the output of stdout and stderr (or all if the all option is true). Otherwise the returned promise will not be resolved/rejected.

Apparently starting with node 18.14.0 the converse is also true: if you're going to read the output of stdout or stderr (or all) yourself then you need to set buffer: false or the returned promise will not be resolved/rejected.

I don't know if there's a way around this (maybe you could check if the streams' readableEnded is true before trying to create promises for them? Or create the buffer streams before returning from execa()?) or if this behavior change in node is itself a bug.

@ehmicky
Copy link
Collaborator

ehmicky commented Feb 10, 2023

Hi @anomiex,

Thanks for reporting this.

This appears to also be a problem with 19.5.0 (but not 19.4.0).
The following is a smaller reproduction, which relies on timing:

import { execa } from 'execa'
import { setTimeout } from 'node:timers/promises'

const proc = execa('echo')
await setTimeout(1e3) // Must be longer than the duration of `echo`
await proc
console.log('done')
$ nve 19.4.0,19.5.0 node file.js

 ⬢  Node 19.4.0

done

 ⬢  Node 19.5.0

Node 19.5.0 failed with exit code 13

This appears to be a bug in Node.js, which I just reported here: nodejs/node#46595
This bug creates some issue with get-stream, which is used by Execa. I created an issue in get-stream too: sindresorhus/get-stream#50

In a nutshell, the promise returned by Execa waits for stdin/stdout/stderr to complete to resolve (which is good):

return await Promise.all([processDone, stdoutPromise, stderrPromise, allPromise]);

Under the hood, this relies on Stream.pipeline(). However, a recent commit in Node.js core (nodejs/node#46226) appears to have changed how Stream.pipeline() behaves. This makes Execa hang forever when stdin/stdout/stderr have already ended.

While the underlying bug is being worked out by the Node.js team, the following workaround is available for Execa users: await the promise returned by Execa as early as possible. This removes the possibility for stdin/stdout/stderr to have already ended.

For instance, to re-take your example:

import { execa } from 'execa';
import readline from 'node:readline';

const readProcess = async (proc) => {
  const rl = readline.createInterface( {
    input: proc.stdout,
    crlfDelay: Infinity,
  } );

  let ct = 0;
  for await ( const l of rl ) {
    ct++;
  }
  console.log( `Saw ${ct} files` );
};

const proc = execa( 'find', [ '/usr/bin', '-type', 'f' ], { stdio: [ 'ignore', 'pipe', 'inherit' ] } );
const [result] = await Promise.all([proc, readProcess(proc)]);
console.log( `Process exit code: ${result.exitCode}` );

This is actually good practice since leaving promises without a then/catch callback can lead to problems. For instance, in your earlier example, if the proc promise is rejected while the for await (...) loop is ongoing, this would lead to an unhandled promise rejection, which would terminate the process. Instead, in the example above, the proc promise is being awaited right away, which removes that potential issue.

@anomiex
Copy link
Author

anomiex commented Feb 10, 2023

Thanks for the link to the node bug.

In our case, we just set buffer: false since we weren't making any use of the (empty) buffered output anyway.

For instance, in your earlier example, if the proc promise is rejected while the for await (...) loop is ongoing, this would lead to an unhandled promise rejection

Not really. The proc promise's rejection would be "handled" once the promise is eventually await-ed. Your version just makes it so the processing of the output might not be finished first.

@ehmicky
Copy link
Collaborator

ehmicky commented Feb 10, 2023

If the proc promise is rejected before await proc is called, an unhandledRejection event is emitted on the process. By default (i.e. unless an handler for that event exists), this exits the process immediately, before reaching the await proc line of code.

For example:

import { execa } from 'execa';
import readline from 'node:readline';

const proc = execa( 'find_mispelled', [ '/usr/bin', '-type', 'f' ], { stdio: [ 'ignore', 'pipe', 'inherit' ] } );

const rl = readline.createInterface( {
	input: proc.stdout,
	crlfDelay: Infinity,
} );

let ct = 0;
console.log('Start loop');
for await ( const l of rl ) {
	ct++;
}
console.log('End loop');

const result = await proc;
console.log( `Process exit code: ${result.exitCode}` );

The binary find_mispelled cannot be found, which emits an error event on the child process, which itself rejects the proc promise. This happens not immediately when execa() is called, but in the middle of the for await loop. When the proc promise is rejected, await proc has not been called yet, which triggers an unhandledRejection on the process. This exits the process, before console.log('End loop') and await proc are called.

$ node file.js
Start loop
node:internal/errors:490
    ErrorCaptureStackTrace(err);
    ^

Error: spawn find_mispelled ENOENT
    at __node_internal_captureLargerStackTrace (node:internal/errors:490:5)
    at __node_internal_errnoException (node:internal/errors:620:12)
    at ChildProcess._handle.onexit (node:internal/child_process:285:19)
    at onErrorNT (node:internal/child_process:483:16)
    at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
  errno: -2,
  code: 'ENOENT',
  syscall: 'spawn find_mispelled',
  path: 'find_mispelled',
  spawnargs: [ '/usr/bin', '-type', 'f' ]
}

Node.js v19.4.0

@anomiex
Copy link
Author

anomiex commented Feb 10, 2023

Huh, that's unexpected. I see nodejs/node#43326 (comment) already mentions something similar.

@ehmicky
Copy link
Collaborator

ehmicky commented Mar 14, 2023

The underlying Node.js bug has now been fixed in Node 19.8.0. 🎉

@ehmicky ehmicky closed this as completed Mar 14, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants