Repository navigation
http2: [8.x] server stream emits error after close #24559
Description
- 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
Metadata
Metadata
Assignees
Labels
No labels
Activity
ofrobots commentedon Nov 21, 2018
/cc @nodejs/http2
MylesBorins commentedon Nov 27, 2018
I've opened a PR with a test for this... gonna start digging
#24685
MylesBorins commentedon Nov 27, 2018
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 commentedon Nov 27, 2018
/cc @lpinca
mcollina commentedon Nov 27, 2018
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 commentedon Nov 28, 2018
@mcollina are you suggesting we change the behavior in net in 8.x LTS?
mcollina commentedon Nov 28, 2018
No, we should fix http2 everywhere.
lpinca commentedon Nov 28, 2018
I don't think backporting #19241 is an option. It's definitely semver-major.
MylesBorins commentedon Nov 28, 2018
to add to what @lpinca said... the issue here is not http2 it is net, which I don't think we can change
mcollina commentedon Nov 28, 2018
@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 commentedon Nov 28, 2018
@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 commentedon Nov 28, 2018
I would apply the changes on master first, and backport as usual.
Flarna commentedon Nov 28, 2018
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 commentedon Nov 28, 2018
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 commentedon Nov 28, 2018
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 commentedon Nov 29, 2018
I did some debugging and I think #19836 is the change which fixed this in Node >= 10.
MylesBorins commentedon Nov 29, 2018
#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 commentedon Nov 29, 2018
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()callsprocess.nextTick(emit, this, 'close', code)=> close comes firstCallback passed to
_destroy()does aprocess.nextTick(emitErrorNT, this, err)NodeJS 10:
Callback passed to
_destroy()does aprocess.nextTick(emitErrorAndCloseNT, this, err)==> emits first error then close==> the
process.nextTick(emit, this, 'close', code);inServerHttp2Stream._destroy()has been removed in #19451MylesBorins commentedon Nov 29, 2018
#19451 has already landed on 8.x in e4c10e1 fwiw
Flarna commentedon Nov 29, 2018
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 commentedon Dec 2, 2018
I have a fix in http2 to correct the sequence but I found that v8.x has a test which verifies that
errorcomes afterclose.... This test was adapted in #17406 to verifycloseis aftererror.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?http2: fix sequence of error/close events
Flarna commentedon Dec 11, 2018
fixed via #24789