stream: call _final synchronously #30597

ronag · 2019-11-22T18:50:31Z

We don't actually have to call _final in a nextTick we just need to emit the event asynchronously. Try to call _final as soon as possible. With this change it's possible to remove some prefinish hacks where prefinish is used to get a synchronous pre _final.

This is blocking some other pending fixes.

Blocked by #29656

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

ronag · 2019-11-22T21:04:09Z

Those failures are very interesting. WIP

ronag · 2019-11-23T11:59:26Z

@mcollina: I think you might be interested in this change.

@jasnell @addaleax The http2 failures are very strange to me. The way http2 uses streams a bit of a challenge. My gut feeling is that there is a bug hiding somewhere and this PR activates it. Would either if you be interested in collaborating with me to figure out why this PR would cause the failing tests in http2?

ronag · 2019-11-23T12:07:22Z

e.g. in test-http2-client-upload-reject

  server.on('stream', common.mustCall((stream) => {
    // Wait for some data to come through.
    setImmediate(() => {
      stream.on('close', common.mustCall(() => {
        assert.strictEqual(stream.rstCode, 0);
      }));

      stream.respond({ ':status': 400 });
      stream.end();
    });
  }));

stream won't emit 'close' until the reading side has also emitted 'end' (due to allowHalfOpen = true in the HTTP2Stream constructor). However, since this test never starts to read it should actually never emit 'end' and 'close' so I'm unsure how this test could have passed previously?

The rest of the failures seem related to this.

test/parallel/test-internal-fs-syncwritestream.js

addaleax · 2019-11-23T22:39:20Z

lib/internal/fs/streams.js

@@ -286,7 +286,8 @@ Object.setPrototypeOf(WriteStream, Writable);
 WriteStream.prototype._final = function(callback) {
  if (typeof this.fd !== 'number') {
    return this.once('open', function() {
-      this._final(callback);
+      // Make sure _final is called after every 'open' listener
+      process.nextTick(() => this._final(callback));


Would this maybe be a good reason to keep _final behind a nextTick, at least in a semver-patch PR? Or maybe, why does this need to be changed here but not in the other places where we use a similar pattern (e.g. net, http2)?

That's one reason to keep _final behind a nextTick but there are other reasons which make it not a good idea. I don't think this becomes a relevant problem once #29656 is merged.

but not in the other places where we use a similar pattern (e.g. net, http2)?

It should probably be changed in those places as well.

ronag · 2019-11-24T09:54:52Z

@Trott a WIP label please

ronag · 2019-12-07T11:14:11Z

This has some overlap with #30733. This is more about calling _final synchronously as to avoid 'prefinish' hacks.

mcollina

I’m positive to this change, however I would wait for #29656 to land. I’d just be cautious and flag it semver-major. All things that interact with the timing order are hard to debug.

ronag · 2019-12-07T11:48:21Z

Using this transform stream could be potentially significantly simplified, see https://github.com/nxtedition/node/blob/stream-transform-simplify/lib/_stream_transform.js (WIP). As well as other "sync" streams.

ronag · 2019-12-15T10:27:04Z

@mcollina @Trott this is no longer WIP

ronag · 2019-12-15T10:27:43Z

lib/internal/http2/core.js

-      const err = handle.shutdown(req);
-      if (err === 1)  // synchronous finish
-        return afterShutdown.call(req, 0);
+      // TODO: Why does this need to be in nextTick?


@addaleax Maybe you have some insight here?

What happens when it isn’t? 😅

Oh! I forgot about that small detail:

Path: parallel/test-http2-client-socket-destroy Mismatched noop function calls. Expected exactly 1, actual 0. at Object.mustCall (/Users/ronagy/GitHub/nxtedition/node/test/common/index.js:324:10) at Http2Server.<anonymous> (/Users/ronagy/GitHub/nxtedition/node/test/parallel/test-http2-client-socket-destroy.js:19:29) at Http2Server.<anonymous> (/Users/ronagy/GitHub/nxtedition/node/test/common/index.js:358:15) at Http2Server.emit (events.js:304:20) at ServerHttp2Session.sessionOnStream (internal/http2/core.js:2739:19) at ServerHttp2Session.emit (events.js:304:20) at emit (internal/http2/core.js:285:8) at processTicksAndRejections (internal/process/task_queues.js:87:22) Command: out/Release/node --expose-internals /Users/ronagy/GitHub/nxtedition/node/test/parallel/test-http2-client-socket-destroy.js

Seems like some form of timing issue.

ronag · 2019-12-15T10:28:13Z

test/parallel/test-stream-transform-final-sync.js

@@ -82,15 +82,15 @@ const t = new stream.Transform({
    process.nextTick(function() {


This PR makes the order here more sensible

ronag · 2019-12-15T10:28:28Z

This is semver-major due to the change in timing

ronag · 2019-12-28T15:34:28Z

@Trott: node/streams ping?

mcollina

I’m not convinced by this change given the impact in our codebase.

ronag · 2019-12-28T18:46:14Z

My main motivation is that it would be significantly easier to implement streams which need to support both sync and async behavior, e.g. Transform. See for example, https://github.com/nxtedition/node/blob/stream-fix-end-finish/lib/_stream_transform.js vs https://github.com/nodejs/node/blob/master/lib/_stream_transform.js.

This is currently not possible. It's made worse by the fact that you can't properly emulate this with prefinish hacks since prefinish will be emitted sync if _final === null but async otherwise.

Though this doesn't actually "fix" anything other than make things easier to maintain. So whether it's worth the risk or not is debatable...

ronag · 2019-12-28T18:50:52Z

I think there are more pressing PR's to land so if this is controversial I'm fine with closing this for now and re-open at a more appropriate time.

ronag · 2019-12-28T18:56:18Z

The prefinish sometimes sync and sometimes async thing is something I just noticed today. Not sure if there are and what the implications of that might be, i.e. a stream might behave differently if it uses prefinish and sometimes has and sometimes doesn't have a _final.

Example:

let ticked = false;
const t1 = new Transform({
  transform(chunk, encoding, cb) {
    cb();
  }
});
t1.on('finish', () => {
  console.log('t1', ticked);
});
t1.end();

const t2 = new Transform({
  transform(chunk, encoding, cb) {
    cb();
  },
  final(callback) {
    callback();
  }
});
t2.on('finish', () => {
  console.log('t2', ticked);
});
t2.end();
ticked = true;

// Prints
// t1 false
// t2 true

Though providing a _final to a Transform stream doesn't make much sense (should use _flush). But it does illustrate the potential of difference in behavior.

ronag · 2019-12-28T20:10:47Z

Pushed a stream: simplify Transform commit to better show why this PR is useful (still some tests failing), i.e. making it possible to implement Transform strictly in terms of Duplex without extra state and logic. I would prefer to continue working on the Transform part as a separate future PR.

ronag · 2019-12-29T17:40:11Z

Yea, I still think this is a good idea long term but now that I started digging into it again it's significantly more complicated than I thought. We have higher prio stuff to put energy into.

I'll re-open this in the future.

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

ronag force-pushed the stream-fix-end-finish branch 4 times, most recently from b6777af to 9cb4bbb Compare November 23, 2019 00:54

ronag commented Nov 23, 2019

View reviewed changes

test/parallel/test-internal-fs-syncwritestream.js Outdated Show resolved Hide resolved

ronag mentioned this pull request Nov 23, 2019

stream: Transform questions #30605

Closed

addaleax reviewed Nov 23, 2019

View reviewed changes

lpinca added the wip Issues and PRs that are still a work in progress. label Nov 24, 2019

ronag changed the title ~~stream: 'finish' should always be emitted asynchronously~~ stream: call _final synchronously Dec 7, 2019

mcollina reviewed Dec 7, 2019

View reviewed changes

ronag force-pushed the stream-fix-end-finish branch 10 times, most recently from 1672b25 to 66e2654 Compare December 14, 2019 22:36

ronag requested review from mcollina and addaleax December 15, 2019 10:26

ronag commented Dec 15, 2019

View reviewed changes

ronag force-pushed the stream-fix-end-finish branch 2 times, most recently from 866be29 to b6f2f1a Compare December 15, 2019 15:17

Trott removed the wip Issues and PRs that are still a work in progress. label Dec 15, 2019

BridgeAR added the semver-major PRs that contain breaking changes and should be released in the next major version. label Dec 25, 2019

mcollina requested changes Dec 28, 2019

View reviewed changes

ronag closed this Dec 28, 2019

ronag reopened this Dec 28, 2019

ronag force-pushed the stream-fix-end-finish branch from b6f2f1a to da175f0 Compare December 28, 2019 20:10

ronag force-pushed the stream-fix-end-finish branch 4 times, most recently from 91618f5 to 5cf54fb Compare December 28, 2019 20:18

stream: call _final synchronously

d17f233

ronag force-pushed the stream-fix-end-finish branch 5 times, most recently from b43b23e to 63380c2 Compare December 28, 2019 21:23

stream: simplify Transform

68c0d3b

ronag force-pushed the stream-fix-end-finish branch from 63380c2 to 68c0d3b Compare December 29, 2019 15:26

ronag closed this Dec 29, 2019

		@@ -82,15 +82,15 @@ const t = new stream.Transform({
		process.nextTick(function() {

Uh oh!

stream: call _final synchronously #30597

stream: call _final synchronously #30597

Uh oh!

Conversation

ronag commented Nov 22, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Checklist

Uh oh!

ronag commented Nov 22, 2019

Uh oh!

ronag commented Nov 23, 2019

Uh oh!

ronag commented Nov 23, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Uh oh!

addaleax Nov 23, 2019

Choose a reason for hiding this comment

Uh oh!

ronag Nov 23, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

ronag Nov 23, 2019

Choose a reason for hiding this comment

Uh oh!

ronag commented Nov 24, 2019

Uh oh!

ronag commented Dec 7, 2019

Uh oh!

mcollina left a comment

Choose a reason for hiding this comment

Uh oh!

ronag commented Dec 7, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

ronag commented Dec 15, 2019

Uh oh!

ronag Dec 15, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

addaleax Dec 16, 2019

Choose a reason for hiding this comment

Uh oh!

ronag Dec 16, 2019

Choose a reason for hiding this comment

Uh oh!

ronag Dec 16, 2019

Choose a reason for hiding this comment

Uh oh!

ronag Dec 15, 2019

Choose a reason for hiding this comment

Uh oh!

ronag commented Dec 15, 2019

Uh oh!

ronag commented Dec 28, 2019

Uh oh!

mcollina left a comment

Choose a reason for hiding this comment

Uh oh!

ronag commented Dec 28, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

ronag commented Dec 28, 2019

Uh oh!

ronag commented Dec 28, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

ronag commented Dec 28, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

ronag commented Dec 29, 2019

Uh oh!

Uh oh!

ronag commented Nov 22, 2019 •

edited

Loading

ronag commented Nov 23, 2019 •

edited

Loading

ronag Nov 23, 2019 •

edited

Loading

ronag commented Dec 7, 2019 •

edited

Loading

ronag Dec 15, 2019 •

edited

Loading

ronag commented Dec 28, 2019 •

edited

Loading

ronag commented Dec 28, 2019 •

edited

Loading

ronag commented Dec 28, 2019 •

edited

Loading