Investigate flaky test-http-destroyed-socket-write2

[Trott]

• win2012r2

[Trott]

Stress test to see if flakiness is detectable via stress test: https://ci.nodejs.org/job/node-stress-single-test/89/nodes=win2012r2/

[Trott]

Closing #4064, #4065, and #4066. All three tests were flaky in the same CI build/run on just win2012r2, but have never been flaky before. Stress test runs on all three tests did not produce any test failures. Chalking this up to something weird that probably happened inside CI itself just this one time.

/cc @nodejs/build in case it's something they want to investigate (but totally get it if no one really wants to go down that rabbit hole right now or ever).

[BridgeAR]

I am reopening this one, since it started to fail a couple of times recently.

@ronag could you have a look?

https://ci.nodejs.org/job/node-test-commit-osx/34333/nodes=osx1014/testReport/junit/(root)/test/parallel_test_http_destroyed_socket_write2/

[BridgeAR]

Stress test: https://ci.nodejs.org/job/node-stress-single-test/74/

[BridgeAR]

@ronag would you be so kind and open a PR to fix that? That would be great!

[ronag]

@BridgeAR Sure. I'll put it on my list.

[ronag]

@BridgeAR How do I see in CI what Node version run is against? I can see the commit 77e6691 but not what version that was based on.

I don't think this flakiness should be able to occur on Node 14+. Just wanted to make sure whether that's the case or whether this is for older LTS versions.

[BridgeAR]

@ronag click on "Parameters". It's v15.0.0-pre.

[ronag]

@BridgeAR Did

Stress test: ci.nodejs.org/job/node-stress-single-test/74

reproduce it? Is it reproducible with these stress test single tests?

[ronag]

Made a PR to make the test stricter. If the error occurs again after landing that PR please ping me.

[BridgeAR]

reproduce it? Is it reproducible with these stress test single tests?

It did not fail. Seems like it's difficult to reproduce that way.

[ronag]

I've landed a PR which might make this easier to debug. Please ping me if you encounter this again.

[Trott]

@ronag Just came across it now again in https://pipelines.actions.githubusercontent.com/A76h8lUgAkJrcbixwhN7BUAsUydYrQl8Ux3JbU2S9vu9HqtlrL/_apis/pipelines/1/runs/30920/signedlogcontent/17?urlExpires=2020-06-04T19%3A01%3A31.8124169Z&urlSigningMethod=HMACV1&urlSignature=mTQIwRpEDtvfZ5PIYD%2FC%2F%2F7Ky1nk17UdFua%2BYdvppzw%3D.

2020-06-04T14:33:18.1314890Z not ok 848 parallel/test-http-destroyed-socket-write2
2020-06-04T14:33:18.1316040Z   ---
2020-06-04T14:33:18.1316740Z   duration_ms: 0.213
2020-06-04T14:33:18.1316980Z   severity: fail
2020-06-04T14:33:18.1317130Z   exitcode: 1
2020-06-04T14:33:18.1317880Z   stack: |-
2020-06-04T14:33:18.1318430Z     assert.js:103
2020-06-04T14:33:18.1319340Z       throw new AssertionError(obj);
2020-06-04T14:33:18.1322280Z       ^
2020-06-04T14:33:18.1322970Z     
2020-06-04T14:33:18.1325630Z     AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
2020-06-04T14:33:18.1326820Z     + actual - expected
2020-06-04T14:33:18.1326950Z     
2020-06-04T14:33:18.1327900Z     + 'ERR_STREAM_DESTROYED'
2020-06-04T14:33:18.1328590Z     - 'ECONNRESET'
2020-06-04T14:33:18.1329810Z         at ClientRequest.<anonymous> (/Users/runner/runners/2.263.0/work/node/node/node-v15.0.0-nightly2020-06-04xxxx/test/parallel/test-http-destroyed-socket-write2.js:67:16)
2020-06-04T14:33:18.1330580Z         at ClientRequest.<anonymous> (/Users/runner/runners/2.263.0/work/node/node/node-v15.0.0-nightly2020-06-04xxxx/test/common/index.js:363:15)
2020-06-04T14:33:18.1331190Z         at ClientRequest.emit (events.js:315:20)
2020-06-04T14:33:18.1331340Z         at emitErrorNt (_http_outgoing.js:666:43)
2020-06-04T14:33:18.1331870Z         at processTicksAndRejections (internal/process/task_queues.js:85:21) {
2020-06-04T14:33:18.1333790Z       generatedMessage: true,
2020-06-04T14:33:18.1335490Z       code: 'ERR_ASSERTION',
2020-06-04T14:33:18.1335950Z       actual: 'ERR_STREAM_DESTROYED',
2020-06-04T14:33:18.1336390Z       expected: 'ECONNRESET',
2020-06-04T14:33:18.1336810Z       operator: 'strictEqual'
2020-06-04T14:33:18.1337280Z     }
2020-06-04T14:33:18.1337590Z   ...

[ronag]

@Trott: there is a revert PR pending for v14 and follow up PR's pending for master.

[Trott]

@Trott: there is a revert PR pending for v14 and follow up PR's pending for master.

Ah! OK, I was pasting that in there because the last comment said to ping if it was seen again. Awesome. Thanks.

[Trott]

Showed up in node-daily-master last night as a timeout.

https://ci.nodejs.org/job/node-test-commit-osx/35784/nodes=osx1014/consoleText

not ok 1756 parallel/test-http-destroyed-socket-write2
  ---
  duration_ms: 120.117
  severity: fail
  exitcode: -15
  stack: |-
    timeout

I am able to replicate locally on macOS:

$ tools/test.py -j96 --repeat 192 test/parallel/test-http-destroyed-socket-write2.js
=== release test-http-destroyed-socket-write2 ===                   
Path: parallel/test-http-destroyed-socket-write2
Command: out/Release/node /Users/trott/io.js/test/parallel/test-http-destroyed-socket-write2.js
--- TIMEOUT ---
[02:00|% 100|+ 191|-   1]: Done    
$

Pinging @ronag again since they may already have ideas.

[Trott]

Showed up again last night as a timeout on macOS:

https://ci.nodejs.org/job/node-test-commit-osx/36476/nodes=osx1015/console

00:46:42 not ok 1805 parallel/test-http-destroyed-socket-write2
00:46:42   ---
00:46:42   duration_ms: 120.112
00:46:42   severity: fail
00:46:42   exitcode: -15
00:46:42   stack: |-
00:46:42     timeout
00:46:42   ...

[Trott]

Able to replicate locally:

$ tools/test.py -j8 --repeat=1024  test/parallel/test-http-destroyed-socket-write2.js
=== release test-http-destroyed-socket-write2 ===                    
Path: parallel/test-http-destroyed-socket-write2
Command: out/Release/node /Users/trott/io.js/test/parallel/test-http-destroyed-socket-write2.js
--- TIMEOUT ---
=== release test-http-destroyed-socket-write2 ===                    
Path: parallel/test-http-destroyed-socket-write2
Command: out/Release/node /Users/trott/io.js/test/parallel/test-http-destroyed-socket-write2.js
--- TIMEOUT ---
[02:42|% 100|+ 1022|-   2]: Done                                     
$