Repository navigation
http2 compat layer failing #14925
Description
I'm running node 8.4.0 with the experimental flag --expose-http2 set and am running a server. Currrently running on my desktop which is linux on Intel
This is a server supporting both the serving of static files via res.stream.respondWithFile() and an api. I am routing using the npm router module.
I am invoking the compat layer (I think) because my server create includes a callback
this.server = require('http2').createSecureServer(certs,async (req,res) => {
...
I have been mainly working on the client side app which is served by this server, which is definitely (when it is running) making an api call every 60 seconds. I frequently reload the whole app (by clicking the browser reload button) which normally causes an error (8) to be omitted on both req and res. I have listeners for both of these errors which just logs them.
I have noticed occassionally that I am not doing much other allowing the client to run that the following error occurs.
internal/http2/compat.js:72
stream.resume();
^
TypeError: Cannot read property 'resume' of undefined
at Http2ServerRequest.onRequestResume (internal/http2/compat.js:72:9)
at emitNone (events.js:105:13)
at Http2ServerRequest.emit (events.js:207:7)
at resume_ (_stream_readable.js:830:10)
at _combinedTickCallback (internal/process/next_tick.js:138:11)
at process._tickCallback (internal/process/next_tick.js:180:9)
I don't think that is the result of any client action by me. Because the reload causes serveral hundred calls for static files to the server (which may respond with a 304) before the regular heartbeat api call gets started.
The browser console log is showing a an initial failure of the regular api call (connection reset) followed by a string of connection refused for each of the subsequent attempts.
The server log shows the api call that failed output a debug message just before a call res.end() (which is the last thing that particular api call does.). So the either the above error happened during res.end() or sometime after it, but before the next request happens.
Activity
jasnell commentedon Aug 18, 2017
ping @mcollina
akc42 commentedon Aug 18, 2017
I just left my system idle whilst I went for a meal and the error occurred again 28 minutes since I last restarted the client (with the server having been started shortly before hand). So it is definitely not as a result of any action by me.
I repeated the experiment of starting the server and leaving the application with its xhr request running once a minute and this time it failed after 58 minutes.
jasnell commentedon Aug 18, 2017
Will take a look!
akc42 commentedon Aug 20, 2017
I made a small server and client to try and replicate this problem on a smaller body of code. Despite over 3600 heartbeat requests with one every 5 seconds, it has not failed at all, yet the data points I listed above show failure after around 30 or 60 requests
I tried to understand, by code reading how the problem occurred in the first place, but I didn't get all that far. Its looking like the stream gets closed before the last of the response has been sent, so when the stream resumes, there is nothing to resume to, but I've made no further progress than that
jasnell commentedon Aug 20, 2017
Yeah, it's likely a race condition in the resume logic. Should be a straightforward fix to check if the stream is open when resume is called
apapirovski commentedon Sep 24, 2017
@akc42 I'm guessing this is no longer an issue? Can it be closed? If there's still an issue, let me know and I can definitely look into it. Thanks!
akc42 commentedon Sep 24, 2017
Yes, this can be closed. This issue was caused by the problem of end failing when stream was closed, but that was dealt with in another issue.