test: fix flaky test-worker-prof

[Trott]

Fixes: #26401

[nodejs-github-bot]

CI: https://ci.nodejs.org/job/node-test-pull-request/36133/

[nodejs-github-bot]

CI: https://ci.nodejs.org/job/node-test-pull-request/36134/

[nodejs-github-bot]

CI: https://ci.nodejs.org/job/node-test-pull-request/36136/

[Trott]

I removed the author ready label because I want to run some stress tests to make sure this really fixes things.

[Trott]

@gireeshpunathil @addaleax

[Trott]

Stress test on Windows for this PR: https://ci.nodejs.org/job/node-stress-single-test/212/
Stress test on Windows for master: https://ci.nodejs.org/job/node-stress-single-test/214/

Stress test on Raspberry Pi for this PR: https://ci.nodejs.org/view/Stress/job/node-stress-single-test-pi1-fanned/136/
Stress test on Raspberry Pi for master: https://ci.nodejs.org/view/Stress/job/node-stress-single-test-pi1-fanned/135/

[Trott]

Stress test show it happening less but still happening. I'm going to move this to draft while I investigate more.

[Trott]

Extending the timeout is the wrong solution. It's not that the test needs more time. It's that there is a race condition so the child process never exits.

[gireeshpunathil]

@Trott - from my earlier observation (I will soon search and find out where and what it was), I guess it was to do with CPU starvation on systems with very less CPU:

• if the worker thread is grabbing the CPU, it uses the CPU slice in its entirety so the parent does not get enough ticks
• if the parent grabs the CPU, it does the same
• so either case, one of the profile ticks were insufficient
• (I?) modified this by doing a pingpong where both threads are forced to use CPU to complete the work
• however, from the TIMEOUT, it looks like the work becomes too heavy to handle within the timeout of the harness, in certain systems.

Do you know how many CPUs the failing system has?

I think

node/test/sequential/test-worker-prof.js

Line 29 in 1de4b38

fs.readFileSync(m.toString()).slice(0, 1024 * 1024));

is the key. We are reading the whole node executable file and converting that into a single char array that proves to be too slow at times? Should we either read a small part of it, or change the process.execPath to __filename? WDYT?

[gireeshpunathil]

ok, these are the relevant comments where I had observations on the CPU starvation patterns:
#26401 (comment)
#26401 (comment)

[Trott]

Should we either read a small part of it, or change the process.execPath to __filename? WDYT?

Let's try changing process.execPath to __filename. (If that doesn't work, I wonder if skipping the test when common.enoughTestCpu is false will work.)

[nodejs-github-bot]

CI: https://ci.nodejs.org/job/node-test-pull-request/36172/

[Trott]

Stress test with this PR: https://ci.nodejs.org/job/node-stress-single-test/215/

[Trott]

Should we either read a small part of it, or change the process.execPath to __filename? WDYT?

Let's try changing process.execPath to __filename. (If that doesn't work, I wonder if skipping the test when common.enoughTestCpu is false will work.)

Test failed on macOS in CI because there were only 8 ticks rather than more than 15.

    // Test that at least 15 ticks have been recorded for both parent and child
    // threads. When not tracking Worker threads, only 1 or 2 ticks would
    // have been recorded.
    // When running locally on x64 Linux, this number is usually at least 200
    // for both threads, so 15 seems like a very safe threshold.
    assert(ticks >= 15, `${ticks} >= 15`);

[gireeshpunathil]

Test failed on macOS in CI because there were only 8 ticks rather than more than 15.

ok, so this time it was too lightweight to produce enough work. How about increasing the pingpong count from 10 to say 100? given one unit of work is pretty small, increasing the loop iteration should be ok I guess.

[Trott]

ok, so this time it was too lightweight to produce enough work. How about increasing the pingpong count from 10 to say 100? given one unit of work is pretty small, increasing the loop iteration should be ok I guess.

On my local machine, there was no noticeable difference in ticks between n=10 and n=100. But up around n=1000, we start to see a ticks go from around 80 to around 200. So, trying n=1024....

[Trott]

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

[nodejs-github-bot]

CI: https://ci.nodejs.org/job/node-test-pull-request/36180/

[nodejs-github-bot]

CI: https://ci.nodejs.org/job/node-test-pull-request/36258/

[nodejs-github-bot]

CI: https://ci.nodejs.org/job/node-test-pull-request/36261/

[nodejs-github-bot]

CI: https://ci.nodejs.org/job/node-test-pull-request/36262/

[Trott]

Landed in 04fb597

[kapouer]

It's probably flaky on node 12.21.0 too:
https://buildd.debian.org/status/fetch.php?pkg=nodejs&arch=s390x&ver=12.21.0~dfsg-2&stamp=1616165623&raw=0