Investigate flaky parallel/test-http-dump-req-when-res-ends.js #19139

Activity

1. apapirovski

   added

   flaky-testIssues and PRs involving tests that fail intermittently in CI.Issues and PRs involving tests that fail intermittently in CI.

   httpIssues and PRs related to the http subsystem.Issues and PRs related to the http subsystem.

   on Mar 4, 2018
2. addaleax commented on Mar 5, 2018

   

   addaleax

   on Mar 5, 2018

   Member

   More actions

   I can reproduce this locally, and get errors even on Node 8; so it’s most likely a bug in the test.

   It also looks like increasing the timer duration in the test helps. Ideally, we’d just get rid of it, and instead call res.end() based on other events happening?
3. mcollina commented on Mar 5, 2018

   

   mcollina

   on Mar 5, 2018

   SponsorMember

   More actions

   @addaleax I tried that approach, but couldn't get the dump to happen reliably. It would be good if someone else brought in some new eyes into the problem. That part of the codebase was never tested :/.
4. Trott commented on Apr 5, 2018

   

   Trott

   on Apr 5, 2018

   Member

   More actions

   Happened on FreeBSD today:

   https://ci.nodejs.org/job/node-test-commit-freebsd/16727/nodes=freebsd10-64/console

   not ok 732 parallel/test-http-dump-req-when-res-ends
     ---
     duration_ms: 1.242
     severity: fail
     stack: |-
       resume called
       Mismatched <anonymous> function calls. Expected at least 1, actual 0.
           at Object.exports.mustCallAtLeast (/usr/home/iojs/build/workspace/node-test-commit-freebsd/nodes/freebsd10-64/test/common/index.js:431:10)
           at IncomingMessage.<anonymous> (/usr/home/iojs/build/workspace/node-test-commit-freebsd/nodes/freebsd10-64/test/parallel/test-http-dump-req-when-res-ends.js:12:27)
           at IncomingMessage.<anonymous> (/usr/home/iojs/build/workspace/node-test-commit-freebsd/nodes/freebsd10-64/test/common/index.js:467:15)
           at IncomingMessage.emit (events.js:182:13)
           at resume_ (_stream_readable.js:855:10)
           at process._tickCallback (internal/process/next_tick.js:174:19)
5. Trott commented on Apr 5, 2018

   

   Trott

   on Apr 5, 2018

   Member

   More actions

   Very easy to reproduce:

   $ tools/test.py -j 96 --repeat 192 test/parallel/test-http-dump-req-when-res-ends.js 
   === release test-http-dump-req-when-res-ends ===                    
   Path: parallel/test-http-dump-req-when-res-ends
   resume called
   Mismatched <anonymous> function calls. Expected at least 1, actual 0.
       at Object.exports.mustCallAtLeast (/Users/trott/io.js/test/common/index.js:431:10)
       at IncomingMessage.<anonymous> (/Users/trott/io.js/test/parallel/test-http-dump-req-when-res-ends.js:12:27)
       at IncomingMessage.<anonymous> (/Users/trott/io.js/test/common/index.js:467:15)
       at IncomingMessage.emit (events.js:182:13)
       at resume_ (_stream_readable.js:855:10)
       at process._tickCallback (internal/process/next_tick.js:174:19)
   Command: out/Release/node /Users/trott/io.js/test/parallel/test-http-dump-req-when-res-ends.js
   === release test-http-dump-req-when-res-ends ===                    
   Path: parallel/test-http-dump-req-when-res-ends
   resume called
   Mismatched <anonymous> function calls. Expected at least 1, actual 0.
       at Object.exports.mustCallAtLeast (/Users/trott/io.js/test/common/index.js:431:10)
       at IncomingMessage.<anonymous> (/Users/trott/io.js/test/parallel/test-http-dump-req-when-res-ends.js:12:27)
       at IncomingMessage.<anonymous> (/Users/trott/io.js/test/common/index.js:467:15)
       at IncomingMessage.emit (events.js:182:13)
       at resume_ (_stream_readable.js:855:10)
       at process._tickCallback (internal/process/next_tick.js:174:19)
   Command: out/Release/node /Users/trott/io.js/test/parallel/test-http-dump-req-when-res-ends.js
   [SNIP]
6. Trott commented on Apr 5, 2018

   

   Trott

   on Apr 5, 2018

   Member

   More actions

   Opening PR to move to sequential. That's more of a mitigation strategy than a fix, but it's better than doing nothing.
7. Trott commented on Apr 5, 2018

   

   Trott

   on Apr 5, 2018

   Member

   More actions

   PR: #19819
8. Trott

   added a commit that references this issue on Apr 5, 2018

   test: move test-http-dump-req-when-res-end

   ...

   e1df198
9. Trott

   added a commit that references this issue on Apr 7, 2018

   test: move test-http-dump-req-when-res-end

   ...

   a639ec4
10. Trott

    closed this as completedin a639ec4on Apr 7, 2018
11. mcollina

    added 2 commits that reference this issue on Apr 7, 2018

    test,http: fix http dump test

    ...

    8e245ea

    test,http: fix http dump test

    ...

    1f29963