http2: [8.x] server stream emits error after close

[Flarna]

• Version: 8.13.0
• Platform: Tested on Windows I expect it's platform independent
• Subsystem: http2

With 8.13.0 http2 server stream emits error after close whereas 10.13.0 and 11.2.0 emit error before close.

I was expecting that 8.13.0 acts like 10.13.0 as http2 is out of experimental now and quite a lot was backported to reach parity.
The sequence is not documented to my understanding but I have the feeling that error should come first.

In my use case (APM) the consequence is that I can't attach the error event to the server transaction as this one is already closed.

Reproducer:

const { createServer, connect } = require('http2');

createServer()
  .on('stream', (stream) => {
    console.log('ServerStream created');
    stream
      .on('close', () => console.log('ServerStream close'))
      .on('error', (err) => console.log('ServerStream error'))
      .respondWithFile('dont exist');;
  })
  .listen(8000);

connect('http://localhost:8000').request()
  .on('response', () => console.log('response'))
  .on('error', () => console.log('ClientRequest error'));

prints:

for 8.13.0:
ServerStream created
ServerStream close
ServerStream error
ClientRequest error

for 10.13.0/11.2.0:
ServerStream created
ServerStream error
ServerStream close
ClientRequest error

Refs: #22850

[ofrobots]

/cc @nodejs/http2

[MylesBorins]

I've opened a PR with a test for this... gonna start digging

#24685

[MylesBorins]

So it would appear that the change that introduced this behavior difference landed in 10.x... as the order is consistent all the way through 9.x.

I believe it is this Semver-Major change to net

net: emit 'close' after 'end'

As such I think that this behavior difference is expected, and unfortunately not something that can be fixed. I'll let someone else chime in to confirm. Perhaps it makes sense to document this?

[MylesBorins]

/cc @lpinca

[mcollina]

Emitting error after close is a bug. In a lot of cases, an hard-to-solve one. I’m inclined to consider this just a bug.

(bugs could be semver-major)

[MylesBorins]

@mcollina are you suggesting we change the behavior in net in 8.x LTS?

[mcollina]

No, we should fix http2 everywhere.

[lpinca]

I don't think backporting #19241 is an option. It's definitely semver-major.

[MylesBorins]

to add to what @lpinca said... the issue here is not http2 it is net, which I don't think we can change

[mcollina]

@MylesBorins I'm proposing we fix http2 to handle this new event ordering correctly. Worst case, we swallow the error. IMHO after 'close' no error should be emitted. This change might be semver-major, but that's a different decision.

I agree we should not revert the change in net.

[lpinca]

@mcollina I like you proposal. I'm not sure what it means in practice though, wouldn't it make future backports harder or is the plan to apply the changes on master first?

[mcollina]

I would apply the changes on master first, and backport as usual.

[Flarna]

I haven't digged into this yet but I wonder why a net change should impact the ordering of events on a single http2 stream. The TCP connection (net) is not closed in the use case above.

[lpinca]

If there is no issue on master how would you fix something that isn't broken? I mean how do you justify the change?

[mcollina]

Oh I misunderstood the issue. Then we should probably work on a fix on Node 8 to address the situation. This is probably going to be very hard.

IMHO it's better than we just swallow the error on Node 8. Unfortunately this is going to make the backports harder.

[Flarna]

I did some debugging and I think #19836 is the change which fixed this in Node >= 10.

[MylesBorins]

#19836 is built on top of #18438 which landed on v10.0.0

As the behavior for the test we wrote passes on 10.x I'm not 100% sure that #19836 is the PR that fixed it... but we can dig in a bit and see if we can get something working

[Flarna]

Yes, it seems it's a combination of these. Also #19451 seems to be involved.
I got following call chain:

respondWithFile => fs.open() ==>
afterOpen() => this.destroy(err) => this._destroy()

NodeJS 8:
ServerHttp2Stream._destroy() calls process.nextTick(emit, this, 'close', code) => close comes first
Callback passed to _destroy() does a process.nextTick(emitErrorNT, this, err)

NodeJS 10:
Callback passed to _destroy() does a process.nextTick(emitErrorAndCloseNT, this, err) ==> emits first error then close
==> the process.nextTick(emit, this, 'close', code); in ServerHttp2Stream._destroy() has been removed in #19451

[MylesBorins]

#19451 has already landed on 8.x in e4c10e1 fwiw

[Flarna]

But not the complete change - the line process.nextTick(emit, this, 'close', code) in _destroy() is still there. Most likely because #19836 and/or #18438 have not been backported.

[Flarna]

I have a fix in http2 to correct the sequence but I found that v8.x has a test which verifies that error comes after close.... This test was adapted in #17406 to verify close is after error.

Edit: PR: #24789

Should I submit a PR to correct the sequence or is this anyway something which can't be done in a patch/minor release?

[Flarna]

fixed via #24789