test: investigate - async-hooks/test-graph.signal

@Fishrock123

Version: master
Platform: linux
Subsystem: async_hooks

https://ci.nodejs.org/job/node-test-commit-linux/11523/nodes=centos5-64

not ok 26 async-hooks/test-graph.signal
  ---
  duration_ms: 0.155
  severity: fail
  stack: |-
    Mismatched onsigusr2 function calls. Expected exactly 2, actual 0.
        at Object.exports.mustCall (/home/iojs/build/workspace/node-test-commit-linux/nodes/centos5-64/test/common/index.js:475:10)
        at Object.<anonymous> (/home/iojs/build/workspace/node-test-commit-linux/nodes/centos5-64/test/async-hooks/test-graph.signal.js:16:30)
        at Module._compile (module.js:573:30)
        at Object.Module._extensions..js (module.js:584:10)
        at Module.load (module.js:507:32)
        at tryModuleLoad (module.js:470:12)
        at Function.Module._load (module.js:462:3)
        at Function.Module.runMain (module.js:609:10)
        at startup (bootstrap_node.js:158:16)
  ...

code

...
hooks.enable();
process.on('SIGUSR2', common.mustCall(onsigusr2, 2));

let count = 0;
exec(`kill -USR2 ${process.pid}`);
...

/cc @nodejs/async_hooks @Fishrock123 @thlorenz

Making sure it's just a flake: https://ci.nodejs.org/job/node-test-commit-linux/11526/

@refack

@refack do you still know the outcome of that CI?

@nodejs/async_hooks it would be great if you could have a look at this. Having a green CI for the next Code & Learn would be really neat!

It is a flake (did not reproduce under normal load).

https://ci.nodejs.org/job/node-test-commit-linux/14214/nodes=centos7-64/consoleFull:

not ok 27 async-hooks/test-graph.signal
  ---
  duration_ms: 0.205
  severity: fail
  stack: |-
    Mismatched onsigusr2Again function calls. Expected exactly 1, actual 0.
        at Object.exports.mustCall (/home/iojs/build/workspace/node-test-commit-linux/nodes/centos7-64/test/common/index.js:490:10)
        at process.onsigusr2 (/home/iojs/build/workspace/node-test-commit-linux/nodes/centos7-64/test/async-hooks/test-graph.signal.js:30:34)
        at process.<anonymous> (/home/iojs/build/workspace/node-test-commit-linux/nodes/centos7-64/test/common/index.js:522:15)
        at process.emit (events.js:159:13)
        at Signal.wrap.onsignal (internal/process.js:198:44)

ubuntu1604_sharedlibs_fips20_x64 too:

https://ci.nodejs.org/job/node-test-commit-linux-linked/nodes=ubuntu1604_sharedlibs_fips20_x64/620/consoleFull

03:19:01 not ok 27 async-hooks/test-graph.signal
03:19:01   ---
03:19:01   duration_ms: 0.255
03:19:01   severity: fail
03:19:01   stack: |-
03:19:01     Mismatched onsigusr2Again function calls. Expected exactly 1, actual 0.
03:19:01         at Object.exports.mustCall (/home/iojs/build/workspace/node-test-commit-linux-linked/nodes/ubuntu1604_sharedlibs_fips20_x64/test/common/index.js:488:10)
03:19:01         at process.onsigusr2 (/home/iojs/build/workspace/node-test-commit-linux-linked/nodes/ubuntu1604_sharedlibs_fips20_x64/test/async-hooks/test-graph.signal.js:30:34)
03:19:01         at process.<anonymous> (/home/iojs/build/workspace/node-test-commit-linux-linked/nodes/ubuntu1604_sharedlibs_fips20_x64/test/common/index.js:522:15)
03:19:01         at process.emit (events.js:126:13)
03:19:01         at Signal.wrap.onsignal (internal/process.js:198:44)
03:19:01   ...

Stress test under load (96 concurrent processes): https://ci.nodejs.org/job/node-stress-single-test/1556/nodes=centos5-64/

(UPDATE: clean)

Now trying a stress test without load, because wondering if maybe it's when something happens too fast or something:

https://ci.nodejs.org/job/node-stress-single-test/1557/nodes=centos5-64/console

(UPDATE: clean)

My theory at this point is that exec being asynchronous and/or kill returns control to the caller before the target of the signal has responded to it, and nothing is keeping the event loop open, so there's no reason the process just can't exit without ever receiving the signal.

If that makes sense, the solution might be to use an interval or something to keep the event loop open. Will experiment with that, but would prefer to be able to reproduce first...

Seeing if I have any better luck with a centos7-64 stress test:

1 process: https://ci.nodejs.org/job/node-stress-single-test/1558/nodes=centos7-64/

96 processes: https://ci.nodejs.org/job/node-stress-single-test/1559/nodes=centos7-64/

Hooray! The CentOS7-64 with 96 simultaneous processes is showing failures! So now I can try out a fix...

not ok 1745 async-hooks/test-graph.signal
  ---
  duration_ms: 8.664
  severity: fail
  stack: |-
    Mismatched onsigusr2Again function calls. Expected exactly 1, actual 0.
        at Object.exports.mustCall (/home/iojs/build/workspace/node-stress-single-test/nodes/centos7-64/test/common/index.js:488:10)
        at process.onsigusr2 (/home/iojs/build/workspace/node-stress-single-test/nodes/centos7-64/test/async-hooks/test-graph.signal.js:30:34)
        at process.<anonymous> (/home/iojs/build/workspace/node-stress-single-test/nodes/centos7-64/test/common/index.js:522:15)
        at process.emit (events.js:126:13)
        at Signal.wrap.onsignal (internal/process.js:198:44)

test: fix flaky async-hooks/test-graph.signal

Proposed fix: #17509

test: fix flaky async-hooks/test-graph.signal

Navigation Menu

Repository navigation

test: investigate - async-hooks/test-graph.signal #14568

code

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

test: investigate - async-hooks/test-graph.signal #14568

Description

code

Activity

refack commented on Aug 1, 2017

BridgeAR commented on Sep 28, 2017

refack commented on Sep 28, 2017

Trott commented on Nov 18, 2017

Trott commented on Dec 6, 2017

Trott commented on Dec 6, 2017

Trott commented on Dec 6, 2017

Trott commented on Dec 6, 2017

Trott commented on Dec 6, 2017

Trott commented on Dec 6, 2017

Trott commented on Dec 6, 2017

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions