stream: always invoke callback before emitting error #29293

ronag · 2019-08-24T14:35:30Z

This is a very subtle but possibly serious bug.

The order of invoking the callback and emitting the error should be the same regardless if sync or async. We have code that depends on this order, e.g.

node/lib/internal/console/constructor.js

Line 190 in d5c3837

function createWriteErrorHandler(instance, streamSymbol) {

In particular the callback should give the user a chance to install an 'error' handler before the error is emitted. If the 'error' event sometimes (depending on sync/async write()) is emitted before the callback, this might not always be possible/consistent.

This also fixes so that error is emitted asynchronously instead of synchronously in some places, as you might notice in the tests.

Encountered this while working on #29179.

EDIT: This is blocking work on a few other PR's.

Checklist

make -j4 test (UNIX), or vcbuild test (Windows) passes
tests and/or benchmarks are included
documentation is changed or added
commit message follows commit guidelines

NOTE TO SELF: after merge looking into optimising away a redudant nextTick caused by destroy. Also destroyed could be set synchronously?

ronag · 2019-08-24T18:03:20Z

test/parallel/test-stream-writable-write-writev-finish.js

@@ -146,7 +146,7 @@ const stream = require('stream');

  const ws = new stream.Writable();

-  ws.on('finish', common.mustNotCall());
+  ws.on('finish', common.mustCall());


Even if this is weird (there is a separate issue for 'finish' after 'error')... all the other tests assume exactly this. Only reason this was different was because of the sync/async difference. Was there a purpose here?

Ensure the callback is always invoked before emitting the error in both sync and async case. PR-URL: #29293 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com>

Trott · 2019-09-27T22:46:54Z

Landed in 3de5eae

richardlau · 2019-09-28T00:25:22Z

This seems to have broken the build.

e.g. https://ci.nodejs.org/job/node-test-commit-linuxone/nodes=rhel72-s390x/15969/testReport/(root)/test/parallel_test_zlib_write_after_close/

and on Travis:

https://travis-ci.com/nodejs/node/jobs/239983147

=== release test-zlib-write-after-close ===

Path: parallel/test-zlib-write-after-close

--- stderr ---

events.js:187

      throw er; // Unhandled 'error' event

      ^

Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed

    at Gunzip.Writable.write (_stream_writable.js:310:17)

    at Gzip.<anonymous> (/home/travis/build/nodejs/node/test/parallel/test-zlib-write-after-close.js:30:9)

    at Gzip.cb (/home/travis/build/nodejs/node/test/common/index.js:371:15)

    at Gzip.zlibBufferOnEnd (zlib.js:139:10)

    at Gzip.emit (events.js:215:7)

    at endReadableNT (_stream_readable.js:1193:12)

    at processTicksAndRejections (internal/process/task_queues.js:80:21)

Emitted 'error' event on Gunzip instance at:

    at errorOrDestroy (internal/streams/destroy.js:127:12)

    at Gunzip.Writable.write (_stream_writable.js:312:5)

    at Gzip.<anonymous> (/home/travis/build/nodejs/node/test/parallel/test-zlib-write-after-close.js:30:9)

    [... lines matching original stack trace ...]

    at processTicksAndRejections (internal/process/task_queues.js:80:21)

Command: out/Release/node /home/travis/build/nodejs/node/test/parallel/test-zlib-write-after-close.js

Trott · 2019-09-28T04:03:53Z

I guess we really ought to get that commit queue project moving again so that I don't rely on 5-day-old CI results for things like this. 😞 (No changes had landed in this PR in the intervening time, but obviously a lot had landed on master itself.)

benjamingr · 2019-09-28T13:34:17Z

@Trott what is the standard protocol here? Make a second revert PR or to pluck these changes from the tree?

Trott · 2019-09-28T13:48:52Z

@Trott what is the standard protocol here? Make a second revert PR or to pluck these changes from the tree?

I don't think there is a standard. My experience/observation is that when we talk about this sort of thing hypothetically, people usually come on the side of "revert quickly and then figure out what to do next" but when it actually happens, people usually want to try to fix it rather than revert. So...
¯\(ツ)/¯

Trott · 2019-09-28T13:50:40Z

@Trott what is the standard protocol here? Make a second revert PR or to pluck these changes from the tree?

I don't think there is a standard. My experience/observation is that when we talk about this sort of thing hypothetically, people usually come on the side of "revert quickly and then figure out what to do next" but when it actually happens, people usually want to try to fix it rather than revert. So...
¯_(ツ)_/¯

Actually, if what you mean by "pluck the changes from the tree" is force-push to remove the change, we don't do that unless something landed VERY recently and nothing else has landed since. Instead, we revert.

Trott · 2019-09-28T13:55:02Z

Revert landed. I'm going to see what happens if I reopen this PR.....

Trott · 2019-09-28T13:57:55Z

@ronag Because the way this PR landed, it looks like you should be able to push a fix to the branch here and if it all checks out, we can re-land. That seems not too onerous, I hope.

nodejs-github-bot · 2019-09-28T13:58:50Z

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

ronag · 2019-09-28T14:14:25Z

@Trott: Updated. The only change I did was to remove a no longer necessary change in a test. I hope that's not significant enough to require a full re-review by everyone.

I think that CI run might miss the fix?

nodejs-github-bot · 2019-09-28T16:58:34Z

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

nodejs-github-bot · 2019-09-28T20:51:43Z

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

Trott · 2019-09-28T23:56:38Z

CI is green. The one commit added since this was re-opened looks good to me. Wouldn't mind a re-approval from either @jasnell or @mcollina too.

mcollina

LGTM, hopefully this will result in minima breakage.

Good work, I wanted to get this fixed for a long time.

Trott · 2019-09-30T17:57:01Z

(Landing, but going to compile and run tests locally this time before pushing. 😅 )

Trott · 2019-09-30T18:12:25Z

Landed in f663b31

Ensure the callback is always invoked before emitting the error in both sync and async case. PR-URL: #29293 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com>

Notable changes: - **assert**: - do not repeat .throws() code (Ruben Bridgewater) [#28263](#28263) - wrap validation function errors (Ruben Bridgewater) [#28263](#28263) - fix generatedMessage property (Ruben Bridgewater) [#28263](#28263) - improve class instance errors (Ruben Bridgewater) [#28263](#28263) - **benchmark**: - use test/common/tmpdir consistently (João Reis) [#28858](#28858) - **build**: - make full-icu the default for releases (Richard Lau) [#29887](#29887) - update minimum Xcode version for macOS (Michael Dawson) [#29622](#29622) - **child_process**: - runtime deprecate \_channel (cjihrig) [#27949](#27949) - simplify spawn argument parsing (cjihrig) [#27854](#27854) - **console**: - display timeEnd with suitable time unit (Xavier Stouder) [#29251](#29251) - **deps**: - patch V8 to 7.8.279.14 (Myles Borins) [#29694](#29694) - patch V8 to 7.8.279.12 (Myles Borins) [#29694](#29694) - patch V8 to 7.8.279.10 (Myles Borins) [#29694](#29694) - update V8's postmortem script (cjihrig) [#29694](#29694) - V8: cherry-pick 716875d (Myles Borins) [#29694](#29694) - update V8 to 7.8.279.9 (Myles Borins) [#29694](#29694) - V8: cherry-pick b33af60 (Michaël Zasso) [#28016](#28016) - update V8 to 7.6.303.28 (Michaël Zasso) [#28016](#28016) - **domain**: - error handler runs outside of its domain (Julien Gilli) [#26211](#26211) - **fs**: - make FSWatcher.start private (Lucas Holmquist) [#29905](#29905) - add runtime deprecate for file stream open() (Robert Nagy) [#29061](#29061) - allow int64 offset in fs.write/writeSync/fd.write (Zach Bjornson) [#26572](#26572) - use IsSafeJsInt instead of IsNumber for ftruncate (Zach Bjornson) [#26572](#26572) - allow int64 offset in fs.read/readSync/fd.read (Zach Bjornson) [#26572](#26572) - close file descriptor of promisified truncate (João Reis) [#28858](#28858) - **http**: - do not emit end after aborted (Robert Nagy) [#27984](#27984) - don't emit 'data' after 'error' (Robert Nagy) [#28711](#28711) - remove legacy parser (Anna Henningsen) [#29589](#29589) - throw if 'host' agent header is not a string value (Giorgos Ntemiris) [#29568](#29568) - replace superfluous connection property with getter/setter (Robert Nagy) [#29015](#29015) - fix test where aborted should not be emitted (Robert Nagy) [#20077](#20077) - remove default 'timeout' listener on upgrade (Luigi Pinca) [#26030](#26030) - **http, http2**: - remove default server timeout (Ali Ijaz Sheikh) [#27558](#27558) - **http2**: - remove security revert flags (Anna Henningsen) [#29141](#29141) - remove callback-based padding (Anna Henningsen) [#29144](#29144) - **lib**: - rename validateInteger to validateSafeInteger (Zach Bjornson) [#26572](#26572) - correct error.errno to always be numeric (Joyee Cheung) [#28140](#28140) - no need to strip BOM or shebang for scripts (Refael Ackermann) [#27375](#27375) - rework logic of stripping BOM+Shebang from commonjs (Gus Caplan) [#27768](#27768) - **module**: - runtime deprecate createRequireFromPath() (cjihrig) [#27951](#27951) - **readline**: - error on falsy values for callback (Sam Roberts) [#28109](#28109) - **repl**: - close file descriptor of history file (João Reis) [#28858](#28858) - **src**: - bring 425 status code name into accordance with RFC 8470 (Sergei Osipov) [#29880](#29880) - update NODE\_MODULE\_VERSION to 79 (Myles Borins) [#29694](#29694) - update NODE\_MODULE\_VERSION to 78 (Michaël Zasso) [#28918](#28918) - add error codes to errors thrown in C++ (Yaniv Friedensohn) [#27700](#27700) - use non-deprecated overload of V8::SetFlagsFromString (Michaël Zasso) [#28016](#28016) - update NODE\_MODULE\_VERSION to 77 (Michaël Zasso) [#28016](#28016) - update NODE\_MODULE\_VERSION to 74 (Refael Ackermann) [#27375](#27375) - make process.env.TZ setter clear tz cache (Ben Noordhuis) [#20026](#20026) - enable V8's WASM trap handlers (Gus Caplan) [#27246](#27246) - **stream**: - throw unhandled error for readable with autoDestroy (Robert Nagy) [#29806](#29806) - always invoke callback before emitting error (Robert Nagy) [#29293](#29293) - invoke callback before emitting error always (Robert Nagy) [#29293](#29293) - do not flush destroyed writable (Robert Nagy) [#29028](#29028) - don't emit finish on error (Robert Nagy) [#28979](#28979) - disallow stream methods on finished stream (Robert Nagy) [#28687](#28687) - do not emit after 'error' (Robert Nagy) [#28708](#28708) - fix destroy() behavior (Robert Nagy) [#29058](#29058) - simplify `.pipe()` and `.unpipe()` in Readable (Weijia Wang) [#28583](#28583) - **tools**: - patch V8 to run on older XCode versions (Ujjwal Sharma) [#29694](#29694) - update V8 gypfiles (Michaël Zasso) [#29694](#29694) - support full-icu by default (Steven R. Loomis) [#29522](#29522) - **util**: validate formatWithOptions inspectOptions (Ruben Bridgewater) [#29824](#29824) PR-URL: #29504

nodejs-github-bot added the stream Issues and PRs related to the stream subsystem. label Aug 24, 2019

ronag mentioned this pull request Aug 24, 2019

stream: use callback to properly propagate error #29179

Closed

4 tasks

ronag force-pushed the stream-cb-error-order branch 13 times, most recently from f51d382 to 25a40ec Compare August 24, 2019 17:55

ronag commented Aug 24, 2019

View reviewed changes

ronag force-pushed the stream-cb-error-order branch 14 times, most recently from fa33145 to 970691f Compare August 25, 2019 12:57

Trott closed this Sep 27, 2019

richardlau mentioned this pull request Sep 28, 2019

Revert "stream: invoke callback before emitting error always" #29741

Closed

2 tasks

Trott reopened this Sep 28, 2019

fixup: remove no longer necessary test change

60dac52

mcollina approved these changes Sep 30, 2019

View reviewed changes

Trott added the notable-change PRs with changes that should be highlighted in changelogs. label Sep 30, 2019

Trott closed this Sep 30, 2019

BethGriggs mentioned this pull request Oct 1, 2019

2019-10-22, Version 13.0.0 (Current) #29504

Merged

ceeser mentioned this pull request Feb 4, 2022

Throwing a synchronous error in a custom writable stream implementation doesn't immediately stop execution #41846

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

stream: always invoke callback before emitting error #29293

stream: always invoke callback before emitting error #29293

ronag commented Aug 24, 2019 •

edited

Loading

ronag Aug 24, 2019 •

edited

Loading

Trott commented Sep 27, 2019

richardlau commented Sep 28, 2019

Trott commented Sep 28, 2019 •

edited

Loading

benjamingr commented Sep 28, 2019

Trott commented Sep 28, 2019

Trott commented Sep 28, 2019

Trott commented Sep 28, 2019

Trott commented Sep 28, 2019

nodejs-github-bot commented Sep 28, 2019

ronag commented Sep 28, 2019 •

edited

Loading

nodejs-github-bot commented Sep 28, 2019

nodejs-github-bot commented Sep 28, 2019

Trott commented Sep 28, 2019

mcollina left a comment

Trott commented Sep 30, 2019

Trott commented Sep 30, 2019

stream: always invoke callback before emitting error #29293

stream: always invoke callback before emitting error #29293

Conversation

ronag commented Aug 24, 2019 • edited Loading

Checklist

ronag Aug 24, 2019 • edited Loading

Choose a reason for hiding this comment

Trott commented Sep 27, 2019

richardlau commented Sep 28, 2019

Trott commented Sep 28, 2019 • edited Loading

benjamingr commented Sep 28, 2019

Trott commented Sep 28, 2019

Trott commented Sep 28, 2019

Trott commented Sep 28, 2019

Trott commented Sep 28, 2019

nodejs-github-bot commented Sep 28, 2019

ronag commented Sep 28, 2019 • edited Loading

nodejs-github-bot commented Sep 28, 2019

nodejs-github-bot commented Sep 28, 2019

Trott commented Sep 28, 2019

mcollina left a comment

Choose a reason for hiding this comment

Trott commented Sep 30, 2019

Trott commented Sep 30, 2019

ronag commented Aug 24, 2019 •

edited

Loading

ronag Aug 24, 2019 •

edited

Loading

Trott commented Sep 28, 2019 •

edited

Loading

ronag commented Sep 28, 2019 •

edited

Loading