flaky: `parallel/test-http2-*` on Windows #20750

Trott · 2018-05-15T17:48:28Z

Version: v11.0.0-pre (master)
Platform: win2008r2-vs2017,
Subsystem: test http2

test file - parallel/test-http2-pipe
CI job windows/17290/COMPILED_BY=vs2017,RUNNER=win2008r2-vs2017,RUN_SUBSET=0
CI worker test-rackspace-win2008r2-x64-3
output:

not ok 251 parallel/test-http2-pipe
  ---
  duration_ms: 0.323
  severity: fail
  exitcode: 1
  stack: |-
    (node:6548) ExperimentalWarning: The http2 module is an experimental API.
    events.js:167
          throw er; // Unhandled 'error' event
          ^
    
    Error: read ECONNRESET
        at TCP.onread (net.js:658: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)
  ...

@nodejs/build @nodejs/platform-windows @nodejs/testing @nodejs/http2

[refack: edited info and added link to test file]

apapirovski · 2018-05-15T19:04:41Z

This happens as a result of the recent change to destroy the socket properly but it might be revealing an actual bug rather than just being a flaky test. That test does a pretty basic pipe operation, it shouldn't ever trigger an ECONNRESET.

ping @nodejs/http2

apapirovski · 2018-05-16T04:51:43Z

This also just happened in parallel/test-http2-client-upload. Same root cause. It's definitely a bug.

https://ci.nodejs.org/job/node-test-binary-windows/17277/COMPILED_BY=vs2017,RUNNER=win2016,RUN_SUBSET=3/tapResults/

Trott · 2018-05-16T05:54:08Z

For posterity (since the link provided by @apapirovski will eventually 404):

not ok 231 parallel/test-http2-client-upload
  ---
  duration_ms: 0.220
  severity: fail
  exitcode: 1
  stack: |-
    (node:2492) ExperimentalWarning: The http2 module is an experimental API.
    events.js:167
          throw er; // Unhandled 'error' event
          ^
    
    Error: read ECONNRESET
        at TCP.onread (net.js:658: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)
  ...

Host: test-azure_msft-win2016-x64-2

The fact that it's happening on both Azure and Rackspace, win2008 and win2016, seems to suggest (to me at least) a bug in Node.js or a dependency like libuv.

apapirovski · 2018-05-16T05:56:20Z

Pretty sure it's because we use setImmediate to destroy rather than having some more certain method of confirming that everything has been sent and we're truly done. Hopefully someone else from the http2 team will have a look soon. I'm not on Windows and it's not a problem on macOS as far as I can tell.

mcollina · 2018-05-16T06:07:29Z

The bug on pipe happens on a mac too.

apapirovski · 2018-05-16T06:30:05Z

@mcollina I can't seem to replicate on mine :( This is what I run it with: tools/test.py -j 96 --repeat 960 parallel/test-http2-pipe.

Trott · 2018-05-16T06:34:15Z

I also can't replicate on macOS nor do I see instances looking through macOS failures in Ci. It may very well be a bug on macOS too, but if so, we're definitely seeing it with much greater frequency on Windows in CI.

apapirovski · 2018-05-16T06:52:00Z

I'm testing a possible fix in https://ci.nodejs.org/job/node-stress-single-test/1845/ and https://ci.nodejs.org/job/node-test-commit-windows-fanned/18023/

mcollina · 2018-05-16T07:54:18Z

=== release test-http2-pipe ===
Path: parallel/test-http2-pipe
(node:37337) ExperimentalWarning: The http2 module is an experimental API.
events.js:167
      throw er; // Unhandled 'error' event
      ^

Error: read ECONNRESET
    at TCP.onread (net.js:658: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: out/Release/node /Users/matteo/Repositories/node/test/parallel/test-http2-pipe.js
[01:05|% 100|+ 938|-  22]: Done

On my system.

Currently http2 does not properly submit GOAWAY frames when a session is being destroyed. It also doesn't properly handle when the other party severs the connection after sending a GOAWAY frame, even though it should. Edge, IE & Safari are currently unable to handle empty TRAILERS frames despite them being correctly to spec. Instead send an empty DATA frame with END_STREAM flag in those situations. Fix and adjust several flaky and/or incorrect tests. PR-URL: #20772 Fixes: #20705 Fixes: #20750 Fixes: #20850 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Rich Trott <rtrott@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com>

It's possible for the connections to take too long and since the server is already unrefed, the process will just exit. Instead adjust the test so that server unref only happens after all sessions have been successfuly established and unrefed. That still tests the same condition but will not fail under load. PR-URL: #20772 Fixes: #20705 Fixes: #20750 Fixes: #20850 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Rich Trott <rtrott@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com>

Currently http2 does not properly submit GOAWAY frames when a session is being destroyed. It also doesn't properly handle when the other party severs the connection after sending a GOAWAY frame, even though it should. Edge, IE & Safari are currently unable to handle empty TRAILERS frames despite them being correctly to spec. Instead send an empty DATA frame with END_STREAM flag in those situations. Fix and adjust several flaky and/or incorrect tests. PR-URL: #20772 Fixes: #20705 Fixes: #20750 Fixes: #20850 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Rich Trott <rtrott@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com>

It's possible for the connections to take too long and since the server is already unrefed, the process will just exit. Instead adjust the test so that server unref only happens after all sessions have been successfuly established and unrefed. That still tests the same condition but will not fail under load. PR-URL: #20772 Fixes: #20705 Fixes: #20750 Fixes: #20850 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Rich Trott <rtrott@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com>

Trott · 2018-05-25T14:21:15Z

It's back. /ping @apapirovski

https://ci.nodejs.org/job/node-test-binary-windows/17579/COMPILED_BY=vs2017,RUNNER=win2008r2-vs2017,RUN_SUBSET=2/console

Host: test-rackspace-win2008r2-x64-4

not ok 252 parallel/test-http2-pipe
  ---
  duration_ms: 0.274
  severity: fail
  exitcode: 1
  stack: |-
    (node:5876) ExperimentalWarning: The http2 module is an experimental API.
    events.js:167
          throw er; // Unhandled 'error' event
          ^
    
    Error: read ECONNRESET
        at TCP.onread (net.js:657: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)
  ...

Wait for close event on server stream before shuting down server and client to avoid races seen on windows CI. Refs: nodejs#20750 (comment)

Wait for close event on server stream before shuting down server and client to avoid races seen on windows CI. Refs: #20750 (comment) PR-URL: #29889 Refs: #29852 Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: Rich Trott <rtrott@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com>

Alternative to nodejs#31590. It appears that the issue here is that the test falsely assumed that closing the client (which also currently destroys the socket rather than gracefully shutting down the connection) would still leave enough time for the server side to receive the stream error. Address that by explicitly waiting for the server side to receive the stream error before closing the client and the connection with it. Refs: nodejs#31590 Refs: nodejs#20750

Wait for close event on server stream before shuting down server and client to avoid races seen on windows CI. Refs: #20750 (comment) PR-URL: #29889 Refs: #29852 Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: Rich Trott <rtrott@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com>

Alternative to nodejs#31590. It appears that the issue here is that the test falsely assumed that closing the client (which also currently destroys the socket rather than gracefully shutting down the connection) would still leave enough time for the server side to receive the stream error. Address that by explicitly waiting for the server side to receive the stream error before closing the client and the connection with it. Refs: nodejs#31590 Refs: nodejs#20750 PR-URL: nodejs#31610 Reviewed-By: Richard Lau <riclau@uk.ibm.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com> Reviewed-By: Denys Otrishko <shishugi@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Luigi Pinca <luigipinca@gmail.com> Reviewed-By: Rich Trott <rtrott@gmail.com>

Alternative to #31590. It appears that the issue here is that the test falsely assumed that closing the client (which also currently destroys the socket rather than gracefully shutting down the connection) would still leave enough time for the server side to receive the stream error. Address that by explicitly waiting for the server side to receive the stream error before closing the client and the connection with it. Refs: #31590 Refs: #20750 PR-URL: #31610 Reviewed-By: Richard Lau <riclau@uk.ibm.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com> Reviewed-By: Denys Otrishko <shishugi@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Luigi Pinca <luigipinca@gmail.com> Reviewed-By: Rich Trott <rtrott@gmail.com>

It hasn't failed in a long time. Refs: nodejs#20750

It hasn't failed for a long time. Closes: nodejs#20750

It hasn't failed for a long time. Closes: nodejs#20750 PR-URL: nodejs#37631 Fixes: nodejs#20750 Reviewed-By: Michaël Zasso <targos@protonmail.com> Reviewed-By: Ruy Adorno <ruyadorno@github.com>

It hasn't failed in a long time. Refs: #20750 PR-URL: #37631 Fixes: #20750 Reviewed-By: Michaël Zasso <targos@protonmail.com> Reviewed-By: Ruy Adorno <ruyadorno@github.com>

It hasn't failed for a long time. Closes: #20750 PR-URL: #37631 Fixes: #20750 Reviewed-By: Michaël Zasso <targos@protonmail.com> Reviewed-By: Ruy Adorno <ruyadorno@github.com>

It hasn't failed in a long time. Refs: #20750 PR-URL: #37631 Fixes: #20750 Reviewed-By: Michaël Zasso <targos@protonmail.com> Reviewed-By: Ruy Adorno <ruyadorno@github.com>

It hasn't failed for a long time. Closes: #20750 PR-URL: #37631 Fixes: #20750 Reviewed-By: Michaël Zasso <targos@protonmail.com> Reviewed-By: Ruy Adorno <ruyadorno@github.com>

Trott added windows Issues and PRs related to the Windows platform. test Issues and PRs related to the tests. flaky-test Issues and PRs related to the tests with unstable failures on the CI. http2 Issues or PRs related to the http2 subsystem. labels May 15, 2018

apapirovski mentioned this issue May 16, 2018

http2: send GOAWAY properly & don't continue reading unnecessarily #20772

Closed

2 tasks

BridgeAR mentioned this issue May 18, 2018

Flaky parallel/test-http2-client-upload-reject #20808

Closed

ChALkeR mentioned this issue May 18, 2018

fs: drop duplicate API in promises mode #20559

Merged

4 tasks

BridgeAR mentioned this issue May 19, 2018

http2: fix end without read #20621

Closed

3 tasks

apapirovski added confirmed-bug Issues with confirmed bugs. and removed flaky-test Issues and PRs related to the tests with unstable failures on the CI. test Issues and PRs related to the tests. windows Issues and PRs related to the Windows platform. labels May 19, 2018

addaleax mentioned this issue May 19, 2018

test: mark tests as flaky as intermediate step #20835

Closed

4 tasks

apapirovski closed this as completed in b11e19e May 22, 2018

apapirovski mentioned this issue May 23, 2018

Investigate test-child-process-fork-closed-channel-segfault #20836

Closed

Trott added the Hacktoberfest label Oct 5, 2019

bcoe mentioned this issue Oct 5, 2019

We could use your help improving Node.js' Windows testing #29852

Closed

7 tasks

Flarna mentioned this issue Oct 8, 2019

test: fix flaky test-http2-client-upload #29889

Closed

3 tasks

Trott removed the Hacktoberfest label Nov 3, 2019

Flarna added a commit to dynatrace-oss-contrib/node that referenced this issue Dec 18, 2019

test: fix flaky test-http2-client-upload

85ab527

Wait for close event on server stream before shuting down server and client to avoid races seen on windows CI. Refs: nodejs#20750 (comment)

Trott mentioned this issue Jan 5, 2020

stream: refactor Writable buffering #31046

Closed

4 tasks

addaleax mentioned this issue Feb 1, 2020

test: fix flaky test-http2-stream-destroy-event-order #31610

Closed

3 tasks

Trott added a commit to Trott/io.js that referenced this issue Mar 6, 2021

test: clear FLAKY designation for test-http2-pipe

600193c

It hasn't failed in a long time. Refs: nodejs#20750

Trott added a commit to Trott/io.js that referenced this issue Mar 6, 2021

test: clear flaky designation for test-stream-pipeline-http2

cf15eac

It hasn't failed for a long time. Closes: nodejs#20750

Trott mentioned this issue Mar 6, 2021

test: clear obsolete FLAKY entries #37631

Merged

Trott closed this as completed in cd4b095 Mar 8, 2021

targos pushed a commit that referenced this issue May 1, 2021

test: clear FLAKY designation for test-http2-pipe

ed30e52

It hasn't failed in a long time. Refs: #20750 PR-URL: #37631 Fixes: #20750 Reviewed-By: Michaël Zasso <targos@protonmail.com> Reviewed-By: Ruy Adorno <ruyadorno@github.com>

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

flaky: `parallel/test-http2-*` on Windows #20750

flaky: `parallel/test-http2-*` on Windows #20750

Trott commented May 15, 2018 •

edited by refack

Loading

apapirovski commented May 15, 2018

apapirovski commented May 16, 2018

Trott commented May 16, 2018

apapirovski commented May 16, 2018

mcollina commented May 16, 2018

apapirovski commented May 16, 2018

Trott commented May 16, 2018

apapirovski commented May 16, 2018 •

edited

Loading

mcollina commented May 16, 2018

Trott commented May 25, 2018

flaky: parallel/test-http2-* on Windows #20750

flaky: parallel/test-http2-* on Windows #20750

Comments

Trott commented May 15, 2018 • edited by refack Loading

apapirovski commented May 15, 2018

apapirovski commented May 16, 2018

Trott commented May 16, 2018

apapirovski commented May 16, 2018

mcollina commented May 16, 2018

apapirovski commented May 16, 2018

Trott commented May 16, 2018

apapirovski commented May 16, 2018 • edited Loading

mcollina commented May 16, 2018

Trott commented May 25, 2018

flaky: `parallel/test-http2-*` on Windows #20750

flaky: `parallel/test-http2-*` on Windows #20750

Trott commented May 15, 2018 •

edited by refack

Loading

apapirovski commented May 16, 2018 •

edited

Loading