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

fix: Set up listeners first, in case of long write to stdin. #520

Merged
merged 6 commits into from
Sep 26, 2022

Conversation

Jordan-Alloy
Copy link
Contributor

@Jordan-Alloy Jordan-Alloy commented Sep 2, 2022

We discovered a bug where large payloads can cause unhandled errors. This is a fix for that bug.

Root cause of bug

In the exec method defined in src/exec.js, the child process is spawned, then the JSON data is sent to stdin, and then listeners are added. The problem here is that the child process can exit while we are still writing to its stdin. If this happens, its stdin will also close, and will generate a low-level EPIPE error event, as we will be writing to a closed pipe. Nothing will handle that error event.

const process = childProcess.spawn(command, args, spawnOptions)

if (stdin) {
  process.stdin.setEncoding('utf-8')
  process.stdin.write(stdin) // <- This line can take a while to complete, during which the child process can exit.
  process.stdin.end()
}
// ... other listeners
process.on('close', code => {
  // ... further code

Steps to reproduce

The following code should reproduce the bug:

const jq = require('node-jq');

const generateRandomString = (n) => {
  var result = "";
  var characters = "ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789";
  for (var i = 0; i < n; i++) {
    result += characters.charAt(Math.floor(Math.random() * characters.length));
  }
  return result;
}

async function demo() {
  // The big JSON payload is key, as it will take a long time to write to stdin.
  // Depending on the speed of your machine, you may need to increase its size further in order to trigger the bug.
  var bigPayload = { attribute: generateRandomString(10000) };
  try {
    // "Hello world" is an invalid filter, and will cause jq to exit early (without waiting for stdin)
    await Jq.run("Hello world!", bigPayload, { input: "json" })
  } catch (e) {
    console.log(`Successfully caught jq error: \n----------\n${e}`);
  }
}

demo();

Expected result:

With a big enough payload, we should get and catch the EPIPE:

Successfully caught jq error:
----------
Error: write EPIPE

Actual result:

But without the bugfix, you get this:

node:events:491
      throw er; // Unhandled 'error' event
      ^

Error: write EPIPE
    at WriteWrap.onWriteComplete [as oncomplete] (node:internal/stream_base_commons:94:16)
Emitted 'error' event on Socket instance at:
    at emitErrorNT (node:internal/streams/destroy:157:8)
    at emitErrorCloseNT (node:internal/streams/destroy:122:3)
    at processTicksAndRejections (node:internal/process/task_queues:83:21) {
  errno: -32,
  code: 'EPIPE',
  syscall: 'write'
}

Notes

With a smaller payload, the bug is not triggered, and we see this:

Caught error: Error: jq: error: syntax error, unexpected IDENT, expecting $end (Unix shell quoting issues?) at <top-level>, line 1:
Hello world!
jq: 1 compile error

Node versioning note

On older versions of Node, this sort of unhandled error event may have been ignored. On Node v16, it will crash the application.

@Jordan-Alloy Jordan-Alloy marked this pull request as ready for review September 2, 2022 15:54
@Jordan-Alloy
Copy link
Contributor Author

Closed as this does not seem to actually fix the bug. Investigating further.

@Jordan-Alloy Jordan-Alloy reopened this Sep 2, 2022
@Jordan-Alloy
Copy link
Contributor Author

Re-opened: demo code now passes on this branch; fails on main.

@eaviles
Copy link

eaviles commented Sep 2, 2022

Hi @davesnx! do you mind reviewing this? The same issue might be affecting others trying to upgrade to Node 16. Thanks in advance! 🙏🏽

Copy link
Member

@davesnx davesnx left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the PR, those cases are great to fix!

Let a few comments for having a better status of the code.

I don't think is a good idea to merge this without any test case. Let me know If you need help making it.

Thanks again!

src/exec.js Outdated
Comment on lines 24 to 29
process.stdin.on('error', err => {
if (!promiseIsClosed) {
promiseIsClosed = true
return reject(err)
}
})
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This onError should be only attached to process.stdin when there's stdin, right?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fair enough, yes. If there is not stdin, there will be no error.

src/exec.js Outdated
// All of these handlers can close the Promise, so guard closing it twice.
let promiseIsClosed = false

process.on('error', err => {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm confused about this. Reading your comments seems like the error happens when process is closed, not when it "errors". When this happens?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure this process.on('error' is actually necessary; I can try removing it. What is necessary is the next handler, the process.stdin.on('error.

The error happens when the process is closed, but is actually generated by the process's stdin. The chain of events is:

  1. We are still writing to stdin.
  2. Child process closes for some reason (such as an invalid jq filter).
  3. When the child process closes, its stdin closes as well.
  4. We continue to try to write to its stdin.
  5. Its stdin generates an error, because we're trying to write to it but it's been closed.

src/exec.js Outdated
@@ -12,6 +12,33 @@ const exec = (command, args, stdin, cwd) => {

const process = childProcess.spawn(command, args, spawnOptions)

// All of these handlers can close the Promise, so guard closing it twice.
let promiseIsClosed = false
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could we rename this to express better what it means?

isStdinClosed or stdinClosedEarly?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe promiseIsRejected? I should've used better wording here; this is about making sure we don't call reject() on the Promise twice.

@Jordan-Alloy Jordan-Alloy reopened this Sep 6, 2022
@Jordan-Alloy
Copy link
Contributor Author

Hi @davesnx, can you review again? I've refactored some things per your comments, and have added a unit test. If you comment out the process.stdin.on('error'... listener in exec.js, you should see the unit test fail.

@davesnx
Copy link
Member

davesnx commented Sep 12, 2022

I allowed the CI to run again (this isn't ideal :()

If you need more help, DM me on Twitter https://twitter.com/davesnx

const largeJsonString = JSON.parse(readFileSync(PATH_LARGE_JSON_FIXTURE))
run(FILTER_INVALID, largeJsonString, { input: 'json' })
.then(result => {
done('Expected an error to be thrown from child process stdin')
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This shouldn't be here otherwise the test always pass green. Can you remove the done call, and maybe throw or handle this in another fashion?

Copy link
Contributor Author

@Jordan-Alloy Jordan-Alloy Sep 26, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Calling done without any arguments passes a test, but calling it with arguments fails the test. Per the Mocha documentation, "This callback accepts both an Error instance (or subclass thereof) or a falsy value; anything else is invalid usage and throws an error (usually causing a failed test)."

I've tried this out locally - making the run(...) Promise resolve so that this done call is hit, and the test does fail in that case. It would be more proper to wrap this error message in an Error, but either way this done call does fail the test.

@davesnx davesnx merged commit df6d580 into sanack:main Sep 26, 2022
@davesnx
Copy link
Member

davesnx commented Sep 26, 2022

🎉 This PR is included in version 2.3.4 🎉

The release is available on:

Your semantic-release bot 📦🚀

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants