http2: client browser refresh crashing the server.

[akc42]

This is with version 8.5.0 of node.

I have a situation where as the browser window is closing (or refreshing!) it sends a last ditch attempt to release locks that the user may hold. There is an api function for this which when it has completed calls response.end('{}') (I have a convention that all api calls should return a valid json object even if its a null object).

I catch unhandled rejections and print the error stack, along with what url is being processed at the time. The url is a red herring (its a call several milliseconds into the new browser window starting up), but the error is real.

My server falls over with

 Unhandled Rejection: Error [ERR_HTTP2_STREAM_CLOSED]: The stream is already closed
    at Http2ServerResponse.write (internal/http2/compat.js:456:19)
    at Http2ServerResponse.end (internal/http2/compat.js:479:12)
    at API.module.exports (/home/alan/dev/pasv5/server/api/release_lock.js:32:14)
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:188:7)
          Request in Progress At time of Rejection:
            url:/src/pas-notify.html
            body:undefined

What I believe is happening is the api call gets through, takes a while to make a database call to release the locks, and then tries to send the response.end(), by which time the original stream (and maybe even the session) have disappeared.

I would have expected from the new compatability api docs that request would have fired an 'aborted' event at some point before this happens, but I log those and nothing happened.

Looking at the compat code, I can see the error would not have thrown if a callback had been provided to response.write(), but as is indicated in the stack this is called from response.end() where no callback is passed through. Regardless of this issue I do have an on('error') listener on the response. and that wasn't fired either. Should the error be sent there?

[ronag]

Related #15387?

[apapirovski]

@akc42 Thanks for the report! Any chance you could post a reduced code sample that illustrates this? Also, I know you were previously able to build from master and test that. Could you do it for this error? I believe that this behaviour might've changed in c981483 (which didn't make it into 8.5.0)

[jasnell]

Ping @mcollina

[akc42]

@apapirovski https://github.com/akc42/simple-server.git shows this, and I also built against yesterdays master and tried that, but no difference

[apapirovski]

Thanks so much! As far as I can tell, comparing to http, we should not be throwing in this situation at all — it should just return false to match http.

@mcollina Do you see any reason that in Http2ServerResponse.end we wouldn't swap the order of these two statements to match the http behaviour? (We would also need to check for stream.finished in addition to stream === undefined.)

if (chunk !== null && chunk !== undefined) {
  this.write(chunk, encoding);
}

if (stream === undefined) {
  return;
}

[apapirovski]

@akc42 I'm still looking at why it actually closes the stream, that bit seems weird.

[apapirovski]

Ignore the comment above, the stream being closed made complete sense since the client aborted the request. It looks to me like you're listening to abort rather than aborted which explains why it's not logging. When I switched it to aborted it works as expected.

I'll get started on a PR to fix the incorrect end behaviour though as it doesn't match the http module.

Let me know if any of this doesn't line up for you though, @akc42.

[akc42]

@apapirovski I was half way responding when you made your posts

I presume what you are saying is that I'll get an 'aborted' event on the request and then response.end doesn't fail but silently returns. That is good for me. BUT according to the docs - there should have been a 'close' event on the response which I didn't get. I assume that should have happened at the same time the aborted event was thrown.

[apapirovski]

Ah, yea I see what you mean. It doesn't look this was ever working for http2. Working on a PR.

[akc42]

This shouldn't really be closed until #15415 is

[mcollina]

Fixed in 8fa5fcc.