http2: fix premature destroy

[apapirovski]

Check stream._writableState.finished instead of stream.writable as the latter can lead to premature calls to destroy and dropped writes on busy processes.

Fixes: #20750

Checklist

• make -j4 test (UNIX), or vcbuild test (Windows) passes
• commit message follows commit guidelines

[apapirovski]

/cc @nodejs/http2

@bzoz Could you check if this fixes the failures you were seeing on Windows? If not, please let me know what the new debugging output is as it would likely be a different / new bug. Thanks in advance!!

[apapirovski]

CI: https://ci.nodejs.org/job/node-test-pull-request/15183/

[addaleax]

LGTM if CI is good

(Maybe also /cc @ryzokuken)

[ryzokuken]

Umm, this should fix the bug, but it uses the hidden property?

@apapirovski I understand that literally everyone in the userland uses _writeableState, but we have been trying to move away from it as much as possible in core, possibly even refactoring parts of code to remove any instances. Would you rather like to leverage this into an opportunity to change the stream class in such a way that we don't need to access _writableState anymore?

/cc @mcollina

[apapirovski]

Landed in 7b6c428

[bzoz]

Sorry, this does not fix the issue:

Path: parallel/test-http2-pipe(node:2416) ExperimentalWarning: The http2 module is an experimental API.events.js:167 throw er; // Unhandled 'error' event ^Error: read ECONNRESET at TCP.onread (net.js:656:25)Emitted 'error' event at: at emitErrorNT (internal/streams/destroy.js:82:8) at emitErrorAndCloseNT (internal/streams/destroy.js:50:3) at process._tickCallback (internal/process/next_tick.js:63:19)Command: C:\Users\Administrator\Desktop\node\Release\node.exe C:\Users\Administrator\Desktop\node\test\parallel\test-http2-pipe.js

I'll try to produce the --debug-http2 --debug-nghttp2 log

[apapirovski]

@bzoz thanks. I'm guessing there's another race condition elsewhere in the code. This would've fixed the last one I saw based on the debug logs.

[bzoz]

Got it:

Details

=== release test-http2-pipe ===Path: parallel/test-http2-pipe(node:1060) ExperimentalWarning: The http2 module is an experimental API.Http2Session server (19) session createdHttp2Session server (19) i/o stream consumedHttp2Session server (19) scheduling writeHttp2Session client (24) session createdHttp2Session client (24) i/o stream consumedHttp2Session client (24) scheduling writeHttp2Priority: parent: 0, weight: 16, exclusive: 0Http2Session client (24) request submittedHttp2Session client (24) submitting requestHttp2Session client (24) request submitted, new stream id 1HttpStream 1 (27) [Http2Session client (24)] queuing 1 buffers to sendHttpStream 1 (27) [Http2Session client (24)] reading startingHttp2Session server (19) sending pending dataHttp2Session server (19) nghttp2 has 9 bytes to sendHttp2Session server (19) wants read? 1Http2Session client (24) sending pending dataHttp2Session client (24) nghttp2 has 24 bytes to sendHttp2Session client (24) nghttp2 has 9 bytes to sendHttp2Session client (24) nghttp2 has 25 bytes to sendHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) stream 1 has pending outbound dataHttp2Session client (24) sending 16384 bytes for data frame on stream 1Http2Session client (24) nghttp2 has 16384 bytes to send directlyHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) stream 1 has pending outbound dataHttp2Session client (24) sending 16384 bytes for data frame on stream 1Http2Session client (24) nghttp2 has 16384 bytes to send directlyHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) stream 1 has pending outbound dataHttp2Session client (24) sending 16384 bytes for data frame on stream 1Http2Session client (24) nghttp2 has 16384 bytes to send directlyHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) stream 1 has pending outbound dataHttp2Session client (24) sending 16383 bytes for data frame on stream 1Http2Session client (24) nghttp2 has 16383 bytes to send directlyHttp2Session client (24) wants read? 1Http2Session client (24) receiving 9 bytesHttp2Session client (24) receiving 9 bytes [wants data? 1]Http2Session client (24) complete frame received: type: 4Http2Session client (24) settings refreshed for sessionHttp2Session client (24) sending pending dataHttp2Session client (24) nghttp2 has 9 bytes to sendHttp2Session client (24) wants read? 1Http2Session client (24) wants read? 1Http2Session server (19) receiving 23360 bytesHttp2Session server (19) receiving 23360 bytes [wants data? 1]Http2Session server (19) complete frame received: type: 4Http2Session server (19) settings refreshed for sessionHttp2Session server (19) beginning headers for stream 1Http2Session server (19) complete frame received: type: 1Http2Session server (19) handle headers frame for stream 1HttpStream 1 (29) [Http2Session server (19)] submitting responseHttpStream 1 (29) [Http2Session server (19)] response submittedHttpStream 1 (29) [Http2Session server (19)] reading startingHttpStream 1 (29) [Http2Session server (19)] writable side shutdownHttp2Session server (19) buffering data chunk for stream 1, size: 16384, flags: 0HttpStream 1 (29) [Http2Session server (19)] reading stoppedHttpStream 1 (29) [Http2Session server (19)] reading startingHttp2Session server (19) complete frame received: type: 0Http2Session server (19) handling data frame for stream 1Http2Session server (19) buffering data chunk for stream 1, size: 6900, flags: 0HttpStream 1 (29) [Http2Session server (19)] reading startingHttp2Session server (19) sending pending dataHttp2Session server (19) nghttp2 has 9 bytes to sendHttp2Session server (19) nghttp2 has 34 bytes to sendHttp2Session server (19) reading outbound data for stream 1Http2Session server (19) no more data for stream 1Http2Session server (19) nghttp2 has 9 bytes to sendHttp2Session server (19) wants read? 1Http2Session server (19) wants read? 1Http2Session client (24) receiving 52 bytesHttp2Session client (24) receiving 52 bytes [wants data? 1]Http2Session client (24) complete frame received: type: 4Http2Session client (24) settings refreshed for sessionHttp2Session client (24) beginning headers for stream 1HttpStream 1 (27) [Http2Session client (24)] starting headers, category: 1Http2Session client (24) complete frame received: type: 1Http2Session client (24) handle headers frame for stream 1Http2Session client (24) complete frame received: type: 0Http2Session client (24) handling data frame for stream 1Http2Session client (24) sending pending dataHttp2Session client (24) wants read? 1Http2Session server (19) receiving 23360 bytesHttp2Session server (19) receiving 23360 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 9484, flags: 0HttpStream 1 (29) [Http2Session server (19)] reading stoppedHttp2Session server (19) complete frame received: type: 0Http2Session server (19) handling data frame for stream 1Http2Session server (19) buffering data chunk for stream 1, size: 13867, flags: 0Http2Session server (19) sending pending dataHttp2Session server (19) nghttp2 has 13 bytes to sendHttp2Session server (19) wants read? 1Http2Session server (19) wants read? 1Http2Session client (24) receiving 13 bytesHttp2Session client (24) receiving 13 bytes [wants data? 1]Http2Session client (24) complete frame received: type: 8Http2Session client (24) sending pending dataHttp2Session client (24) wants read? 1Http2Session server (19) receiving 7300 bytesHttp2Session server (19) receiving 7300 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 2517, flags: 0Http2Session server (19) complete frame received: type: 0Http2Session server (19) handling data frame for stream 1Http2Session server (19) buffering data chunk for stream 1, size: 4774, flags: 0Http2Session server (19) sending pending dataHttp2Session server (19) wants read? 1Http2Session server (19) receiving 7300 bytesHttp2Session server (19) receiving 7300 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 7300, flags: 0Http2Session server (19) sending pending dataHttp2Session server (19) wants read? 1Http2Session server (19) receiving 4318 bytesHttp2Session server (19) receiving 4318 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 4309, flags: 0Http2Session server (19) complete frame received: type: 0Http2Session server (19) handling data frame for stream 1Http2Session server (19) complete frame received: type: 4Http2Session server (19) settings refreshed for sessionHttp2Session server (19) sending pending dataHttp2Session server (19) nghttp2 has 13 bytes to sendHttp2Session server (19) wants read? 1Http2Session server (19) wants read? 1Http2Session client (24) receiving 13 bytesHttp2Session client (24) receiving 13 bytes [wants data? 1]Http2Session client (24) complete frame received: type: 8Http2Session client (24) sending pending dataHttp2Session client (24) wants read? 1HttpStream 1 (29) [Http2Session server (19)] reading startingHttp2Session server (19) scheduling writeHttpStream 1 (29) [Http2Session server (19)] reading stoppedHttp2Session server (19) sending pending dataHttp2Session server (19) nghttp2 has 13 bytes to sendHttp2Session server (19) wants read? 1Http2Session client (24) receiving 13 bytesHttp2Session client (24) receiving 13 bytes [wants data? 1]Http2Session client (24) complete frame received: type: 8Http2Session client (24) sending pending dataHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) stream 1 has pending outbound dataHttp2Session client (24) sending 1 bytes for data frame on stream 1Http2Session client (24) nghttp2 has 1 bytes to send directlyHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) deferring stream 1HttpStream 1 (27) [Http2Session client (24)] queuing 1 buffers to sendHttp2Session client (24) wants read? 1Http2Session client (24) wants read? 1Http2Session client (24) scheduling writeHttp2Session client (24) sending pending dataHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) stream 1 has pending outbound dataHttp2Session client (24) sending 16384 bytes for data frame on stream 1Http2Session client (24) nghttp2 has 16384 bytes to send directlyHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) stream 1 has pending outbound dataHttp2Session client (24) sending 16384 bytes for data frame on stream 1Http2Session client (24) nghttp2 has 16384 bytes to send directlyHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) stream 1 has pending outbound dataHttp2Session client (24) sending 16384 bytes for data frame on stream 1Http2Session client (24) nghttp2 has 16384 bytes to send directlyHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) stream 1 has pending outbound dataHttp2Session client (24) sending 16382 bytes for data frame on stream 1Http2Session client (24) nghttp2 has 16382 bytes to send directlyHttp2Session client (24) wants read? 1Http2Session server (19) receiving 7310 bytesHttp2Session server (19) receiving 7310 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 1, flags: 0Http2Session server (19) complete frame received: type: 0Http2Session server (19) handling data frame for stream 1Http2Session server (19) buffering data chunk for stream 1, size: 7291, flags: 0Http2Session server (19) sending pending dataHttp2Session server (19) wants read? 1Http2Session server (19) receiving 7300 bytesHttp2Session server (19) receiving 7300 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 7300, flags: 0Http2Session server (19) sending pending dataHttp2Session server (19) wants read? 1Http2Session server (19) receiving 7300 bytesHttp2Session server (19) receiving 7300 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 1793, flags: 0Http2Session server (19) complete frame received: type: 0Http2Session server (19) handling data frame for stream 1Http2Session server (19) buffering data chunk for stream 1, size: 5498, flags: 0Http2Session server (19) sending pending dataHttp2Session server (19) wants read? 1Http2Session server (19) receiving 7300 bytesHttp2Session server (19) receiving 7300 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 7300, flags: 0Http2Session server (19) sending pending dataHttp2Session server (19) wants read? 1Http2Session server (19) receiving 7300 bytesHttp2Session server (19) receiving 7300 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 3586, flags: 0Http2Session server (19) complete frame received: type: 0Http2Session server (19) handling data frame for stream 1Http2Session server (19) buffering data chunk for stream 1, size: 3705, flags: 0Http2Session server (19) sending pending dataHttp2Session server (19) nghttp2 has 13 bytes to sendHttp2Session server (19) wants read? 1Http2Session server (19) wants read? 1HttpStream 1 (29) [Http2Session server (19)] reading startingHttp2Session server (19) scheduling writeHttpStream 1 (29) [Http2Session server (19)] reading stoppedHttp2Session server (19) sending pending dataHttp2Session server (19) nghttp2 has 13 bytes to sendHttp2Session server (19) wants read? 1Http2Session client (24) receiving 13 bytesHttp2Session client (24) receiving 13 bytes [wants data? 1]Http2Session client (24) complete frame received: type: 8Http2Session client (24) sending pending dataHttp2Session client (24) wants read? 1Http2Session server (19) receiving 7300 bytesHttp2Session server (19) receiving 7300 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 7300, flags: 0HttpStream 1 (29) [Http2Session server (19)] reading startingHttp2Session server (19) sending pending dataHttp2Session server (19) wants read? 1Http2Session client (24) receiving 13 bytesHttp2Session client (24) receiving 13 bytes [wants data? 1]Http2Session client (24) complete frame received: type: 8Http2Session client (24) sending pending dataHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) stream 1 has pending outbound dataHttp2Session client (24) sending 2 bytes for data frame on stream 1Http2Session client (24) nghttp2 has 2 bytes to send directlyHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) deferring stream 1HttpStream 1 (27) [Http2Session client (24)] queuing 1 buffers to sendHttp2Session client (24) wants read? 1Http2Session client (24) wants read? 1Http2Session client (24) scheduling writeHttp2Session client (24) sending pending dataHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) stream 1 has pending outbound dataHttp2Session client (24) sending 16312 bytes for data frame on stream 1Http2Session client (24) nghttp2 has 16312 bytes to send directlyHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) deferring stream 1Http2Session client (24) wants read? 1Http2Session server (19) receiving 7300 bytesHttp2Session server (19) receiving 7300 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 5379, flags: 0HttpStream 1 (29) [Http2Session server (19)] reading startingHttp2Session server (19) complete frame received: type: 0Http2Session server (19) handling data frame for stream 1Http2Session server (19) buffering data chunk for stream 1, size: 1912, flags: 0HttpStream 1 (29) [Http2Session server (19)] reading startingHttp2Session server (19) sending pending dataHttp2Session server (19) wants read? 1Http2Session server (19) receiving 7300 bytesHttp2Session server (19) receiving 7300 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 7300, flags: 0HttpStream 1 (29) [Http2Session server (19)] reading startingHttp2Session server (19) sending pending dataHttp2Session server (19) wants read? 1Http2Session server (19) receiving 7300 bytesHttp2Session server (19) receiving 7300 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 7170, flags: 0HttpStream 1 (29) [Http2Session server (19)] reading startingHttp2Session server (19) complete frame received: type: 0Http2Session server (19) handling data frame for stream 1Http2Session server (19) buffering data chunk for stream 1, size: 2, flags: 0HttpStream 1 (29) [Http2Session server (19)] reading startingHttp2Session server (19) complete frame received: type: 0Http2Session server (19) handling data frame for stream 1Http2Session server (19) buffering data chunk for stream 1, size: 110, flags: 0HttpStream 1 (29) [Http2Session server (19)] reading startingHttp2Session server (19) sending pending dataHttp2Session server (19) nghttp2 has 13 bytes to sendHttp2Session server (19) wants read? 1Http2Session server (19) wants read? 1Http2Session client (24) receiving 13 bytesHttp2Session client (24) receiving 13 bytes [wants data? 1]Http2Session client (24) complete frame received: type: 8Http2Session client (24) sending pending dataHttp2Session client (24) wants read? 1Http2Session client (24) write finished with status 0HttpStream 1 (27) [Http2Session client (24)] writable side shutdownHttp2Session client (24) scheduling writeHttp2Session client (24) sending pending dataHttp2Session client (24) reading outbound data for stream 1Http2Session client (24) no more data for stream 1Http2Session client (24) stream 1 closed with code: 0HttpStream 1 (27) [Http2Session client (24)] closed with code 0HttpStream 1 (27) [Http2Session client (24)] destroying streamHttpStream 1 (27) [Http2Session client (24)] destroying streamHttp2Session client (24) nghttp2 has 9 bytes to sendHttp2Session client (24) wants read? 1Http2Session client (24) submitting goawayHttp2Session client (24) scheduling writeHttp2Session client (24) destroying sessionHttp2Session client (24) closing sessionHttp2Session client (24) terminating session with code 0Http2Session client (24) sending pending dataHttp2Session client (24) nghttp2 has 17 bytes to sendHttp2Session client (24) nghttp2 has 17 bytes to sendHttp2Session client (24) wants read? 0HttpStream 1 (27) [Http2Session client (24)] tearing down streamHttp2Session client (24) write finished with status -4081Http2Session server (19) receiving 7300 bytesHttp2Session server (19) receiving 7300 bytes [wants data? 1]Http2Session server (19) buffering data chunk for stream 1, size: 7300, flags: 0HttpStream 1 (29) [Http2Session server (19)] reading startingHttp2Session server (19) sending pending dataHttp2Session server (19) nghttp2 has 13 bytes to sendHttp2Session server (19) wants read? 1Http2Session server (19) wants read? 1Http2Session server (19) receiving -4077 bytesHttpStream 1 (29) [Http2Session server (19)] sending rst_stream with code 2Http2Session server (19) sending pending dataHttpStream 1 (29) [Http2Session server (19)] destroying streamHttpStream 1 (29) [Http2Session server (19)] destroying streamHttp2Session server (19) destroying sessionHttp2Session server (19) closing sessionevents.js:167 throw er; // Unhandled 'error' event ^Error: read ECONNRESET at TCP.onread (net.js:656:25)Emitted 'error' event at: at emitErrorNT (internal/streams/destroy.js:82:8) at emitErrorAndCloseNT (internal/streams/destroy.js:50:3) at process._tickCallback (internal/process/next_tick.js:63:19)Command: C:\Users\Administrator\Desktop\node\Release\node.exe C:\Users\Administrator\Desktop\node\test\parallel\test-http2-pipe.js