flaky test parallel/test-worker-eventlooputil #35844

gireeshpunathil · 2020-10-28T06:47:22Z

fail: https://ci.nodejs.org/job/node-test-commit-freebsd/nodes=freebsd11-x64/36185/console
pass: https://ci.nodejs.org/job/node-test-commit-freebsd/nodes=freebsd11-x64/36184/console

11:49:30 not ok 2731 parallel/test-worker-eventlooputil
11:49:30   ---
11:49:30   duration_ms: 0.855
11:49:30   severity: fail
11:49:30   exitcode: 1
11:49:30   stack: |-
11:49:30     node:events:304
11:49:30           throw er; // Unhandled 'error' event
11:49:30           ^
11:49:30     
11:49:30     AssertionError [ERR_ASSERTION]: 266.02071380615234 <= 380.5895614624024
11:49:30         at MessagePort.<anonymous> (/usr/home/iojs/build/workspace/node-test-commit-freebsd/nodes/freebsd11-x64/test/parallel/test-worker-eventlooputil.js:107:12)
11:49:30         at MessagePort.[nodejs.internal.kHybridDispatch] (node:internal/event_target:355:41)
11:49:30         at MessagePort.exports.emitMessage (node:internal/per_context/messageport:18:26)
11:49:30     Emitted 'error' event on process instance at:
11:49:30         at emitUnhandledRejectionOrErr (node:internal/event_target:544:11)
11:49:30         at MessagePort.[nodejs.internal.kHybridDispatch] (node:internal/event_target:359:9)
11:49:30         at MessagePort.exports.emitMessage (node:internal/per_context/messageport:18:26) {
11:49:30       generatedMessage: false,
11:49:30       code: 'ERR_ASSERTION',
11:49:30       actual: false,
11:49:30       expected: true,
11:49:30       operator: '=='
11:49:30     }
11:49:30   ...

/cc @nodejs/workers @trevnorris

The text was updated successfully, but these errors were encountered:

gireeshpunathil · 2020-10-28T07:24:32Z

I am yet to fully understand the logic at the assertion site, just wondering in:

node/test/parallel/test-worker-eventlooputil.js

Line 107 in 3df5afb

assert.ok(idleActive(wElu) > idleActive(w2),

is wElu actually w? I ask this because w is unused in the entire section:

node/test/parallel/test-worker-eventlooputil.js

Lines 99 to 112 in 3df5afb

    
           function checkWorkerActive() { 
        
             const w = workerELU(); 
        
             metricsCh.port2.postMessage({ cmd: 'spin', dur: 50 }); 
        
             metricsCh.port2.once('message', (wElu) => { 
        
               const w2 = workerELU(w); 
        
               assert.ok(w2.active >= 50, `${w2.active} < 50`); 
        
               assert.ok(idleActive(wElu) > idleActive(w2), 
        
                         `${idleActive(wElu)} <= ${idleActive(w2)}`); 
        
               metricsCh.port2.postMessage({ cmd: 'close' }); 
        
             }); 
        
           }

Trott · 2020-10-30T14:07:19Z

This test is failing a lot in CI.

https://ci.nodejs.org/job/node-test-commit-freebsd/36245/nodes=freebsd11-x64/console on test-digitalocean-freebsd11-x64-2

00:19:11 not ok 2731 parallel/test-worker-eventlooputil
00:19:11   ---
00:19:11   duration_ms: 0.777
00:19:11   severity: fail
00:19:11   exitcode: 1
00:19:11   stack: |-
00:19:11     node:events:304
00:19:11           throw er; // Unhandled 'error' event
00:19:11           ^
00:19:11     
00:19:11     AssertionError [ERR_ASSERTION]: 173.09381866455078 <= 272.75743865966797
00:19:11         at MessagePort.<anonymous> (/usr/home/iojs/build/workspace/node-test-commit-freebsd/nodes/freebsd11-x64/test/parallel/test-worker-eventlooputil.js:107:12)
00:19:11         at MessagePort.[nodejs.internal.kHybridDispatch] (node:internal/event_target:367:41)
00:19:11         at MessagePort.exports.emitMessage (node:internal/per_context/messageport:18:26)
00:19:11     Emitted 'error' event on process instance at:
00:19:11         at emitUnhandledRejectionOrErr (node:internal/event_target:558:11)
00:19:11         at MessagePort.[nodejs.internal.kHybridDispatch] (node:internal/event_target:371:9)
00:19:11         at MessagePort.exports.emitMessage (node:internal/per_context/messageport:18:26) {
00:19:11       generatedMessage: false,
00:19:11       code: 'ERR_ASSERTION',
00:19:11       actual: false,
00:19:11       expected: true,
00:19:11       operator: '=='
00:19:11     }
00:19:11   ...

gireeshpunathil · 2020-10-30T14:21:29Z

looks like, at least the failing site is consistent.

This is consistently failing in CI right now. Lets mark it flaky while we figure out what is going on. Refs: nodejs#35844

This is consistently failing in CI right now. Lets mark it flaky while we figure out what is going on. Refs: #35844 PR-URL: #35886 Reviewed-By: Gireesh Punathil <[email protected]> Reviewed-By: Stephen Belanger <[email protected]> Reviewed-By: Rich Trott <[email protected]> Reviewed-By: Ricky Zhou <[email protected]>

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread. PR-URL: #35891 Fixes: #35844 Refs: #35886 Refs: #35664 Reviewed-By: Gireesh Punathil <[email protected]> Reviewed-By: Rich Trott <[email protected]>

This is consistently failing in CI right now. Lets mark it flaky while we figure out what is going on. Refs: #35844 PR-URL: #35886 Reviewed-By: Gireesh Punathil <[email protected]> Reviewed-By: Stephen Belanger <[email protected]> Reviewed-By: Rich Trott <[email protected]> Reviewed-By: Ricky Zhou <[email protected]>

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread. PR-URL: nodejs#35891 Fixes: nodejs#35844 Refs: nodejs#35886 Refs: nodejs#35664 Reviewed-By: Gireesh Punathil <[email protected]> Reviewed-By: Rich Trott <[email protected]> Backport-PR-URL: nodejs#37165

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread. PR-URL: nodejs#35891 Fixes: nodejs#35844 Refs: nodejs#35886 Refs: nodejs#35664 Reviewed-By: Gireesh Punathil <[email protected]> Reviewed-By: Rich Trott <[email protected]> Backport-PR-URL: nodejs#37163

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread. PR-URL: nodejs#35891 Fixes: nodejs#35844 Refs: nodejs#35886 Refs: nodejs#35664 Reviewed-By: Gireesh Punathil <[email protected]> Reviewed-By: Rich Trott <[email protected]> Backport-PR-URL: nodejs#37165

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread. PR-URL: #35891 Fixes: #35844 Refs: #35886 Refs: #35664 Reviewed-By: Gireesh Punathil <[email protected]> Reviewed-By: Rich Trott <[email protected]> Backport-PR-URL: #37163

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread. PR-URL: nodejs#35891 Fixes: nodejs#35844 Refs: nodejs#35886 Refs: nodejs#35664 Reviewed-By: Gireesh Punathil <[email protected]> Reviewed-By: Rich Trott <[email protected]> Backport-PR-URL: nodejs#37165

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread. PR-URL: #35891 Fixes: #35844 Refs: #35886 Refs: #35664 Reviewed-By: Gireesh Punathil <[email protected]> Reviewed-By: Rich Trott <[email protected]> Backport-PR-URL: #37163

gireeshpunathil added flaky-test Issues and PRs related to the tests with unstable failures on the CI. worker Issues and PRs related to Worker support. labels Oct 28, 2020

gireeshpunathil mentioned this issue Oct 28, 2020

child_process: add ChildProcess 'spawn' event #35369

Closed

4 tasks

gireeshpunathil added the test Issues and PRs related to the tests. label Oct 28, 2020

MylesBorins mentioned this issue Oct 30, 2020

test: mark test-worker-eventlooputil flaky #35886

Closed

MylesBorins added a commit to MylesBorins/node that referenced this issue Oct 30, 2020

test: mark test-worker-eventlooputil flaky

5b7b0b1

This is consistently failing in CI right now. Lets mark it flaky while we figure out what is going on. Refs: nodejs#35844

Flarna mentioned this issue Oct 31, 2020

test: correct test-worker-eventlooputil #35891

Closed

nodejs-github-bot closed this as completed in 9dbde1d Nov 4, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

flaky test parallel/test-worker-eventlooputil #35844

flaky test parallel/test-worker-eventlooputil #35844

gireeshpunathil commented Oct 28, 2020

gireeshpunathil commented Oct 28, 2020

Trott commented Oct 30, 2020 •

edited

Loading

gireeshpunathil commented Oct 30, 2020

flaky test parallel/test-worker-eventlooputil #35844

flaky test parallel/test-worker-eventlooputil #35844

Comments

gireeshpunathil commented Oct 28, 2020

gireeshpunathil commented Oct 28, 2020

Trott commented Oct 30, 2020 • edited Loading

gireeshpunathil commented Oct 30, 2020

Trott commented Oct 30, 2020 •

edited

Loading