parallel/test-http2-close-while-writing is flaky

[lpinca]

Test

test-http2-close-while-writing

Platform

macOS x64

Console output

---
duration_ms: 120080.257
exitcode: -15
severity: fail
stack: timeout
...

Build links

• https://ci.nodejs.org/job/node-test-commit-osx/64920/nodes=osx13-x64/testReport/junit/(root)/parallel/test_http2_close_while_writing/
• https://ci.nodejs.org/job/node-test-commit-osx/64990/nodes=osx13-x64/testReport/junit/(root)/parallel/test_http2_close_while_writing/

Additional information

I can reproduce the issue locally via

$ python3 tools/test.py --repeat=10000 parallel/test-http2-close-while-writing

$ lldb -p 79156
(lldb) process attach --pid 79156
Process 79156 stopped
* thread #1, name = 'MainThread', queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
    frame #0: 0x00007ff80b21281e libsystem_kernel.dylib`kevent + 10
libsystem_kernel.dylib`kevent:
->  0x7ff80b21281e <+10>: jae    0x7ff80b212828 ; <+20>
    0x7ff80b212820 <+12>: movq   %rax, %rdi
    0x7ff80b212823 <+15>: jmp    0x7ff80b20e2a2 ; cerror_nocancel
    0x7ff80b212828 <+20>: retq   
Target 0: (node) stopped.
Executable binary set to "/Users/luigi/code/node/out/Release/node".
Architecture set to: x86_64-apple-macosx-.
(lldb) bt
* thread #1, name = 'MainThread', queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  * frame #0: 0x00007ff80b21281e libsystem_kernel.dylib`kevent + 10
    frame #1: 0x000000010543d4ec node`uv__io_poll(loop=<unavailable>, timeout=<unavailable>) at kqueue.c:286:12 [opt]
    frame #2: 0x0000000105429280 node`uv_run(loop=0x0000000109b4d530, mode=UV_RUN_DEFAULT) at core.c:460:5 [opt]
    frame #3: 0x00000001044e6663 node`node::SpinEventLoopInternal(env=0x00007f80ee009600) at embed_helpers.cc:41:7 [opt]
    frame #4: 0x00000001046072bd node`node::NodeMainInstance::Run() [inlined] node::NodeMainInstance::Run(this=<unavailable>, exit_code=<unavailable>, env=0x00007f80ee009600) at node_main_instance.cc:110:9 [opt]
    frame #5: 0x0000000104607229 node`node::NodeMainInstance::Run(this=<unavailable>) at node_main_instance.cc:99:3 [opt]
    frame #6: 0x0000000104591aef node`node::Start(int, char**) [inlined] node::StartInternal(argc=<unavailable>, argv=<unavailable>) at node.cc:1545:24 [opt]
    frame #7: 0x0000000104591aa4 node`node::Start(argc=<unavailable>, argv=<unavailable>) at node.cc:1552:27 [opt]
    frame #8: 0x00007ff80aeab530 dyld`start + 3056

[lpinca]

This callback

node/test/parallel/test-http2-close-while-writing.js

Line 40 in 264cad7

client_stream.on('close', common.mustCall(() => {

is called when the test times out.

[lpinca]

I don't think the original intention was to call stream.write(Buffer.alloc(1)) for each received chunk, and the following patch fixes the issue

diff --git a/test/parallel/test-http2-close-while-writing.js b/test/parallel/test-http2-close-while-writing.js
index d8537c31b00..231bf712d40 100644
--- a/test/parallel/test-http2-close-while-writing.js
+++ b/test/parallel/test-http2-close-while-writing.js
@@ -23,8 +23,8 @@ let client_stream;
 
 server.on('session', common.mustCall(function(session) {
   session.on('stream', common.mustCall(function(stream) {
-    stream.resume();
-    stream.on('data', function() {
+    stream.once('data', function() {
+      this.resume();
       this.write(Buffer.alloc(1));
       process.nextTick(() => client_stream.destroy());
     });

However it is not clear to me why the stream sometimes hangs. The reason for the hang/timeout is that this callback

node/lib/internal/http2/core.js

Lines 2192 to 2196 in 6710c00

	const writeCallback = (err) => {
	waitingForWriteCallback = false;
	writeCallbackErr = err;
	done();
	};

is not called.

I'm not opening a PR with the patch because it would hide the bug.

cc: @nodejs/http2