investigate flaky sequential/test-perf-hooks in CI

[gireeshpunathil]

• Version: master
• Platform: ubuntu1804_sharedlibs_withoutssl_x64
• Subsystem: perf_hooks

not ok 2761 sequential/test-perf-hooks
  ---
  duration_ms: 1.517
  severity: fail
  exitcode: 1
  stack: |-
    {
      name: 'node',
      entryType: 'node',
      startTime: 0,
      duration: { around: 52.144811153411865 },
      nodeStart: { around: 0 },
      v8Start: { around: 0 },
      bootstrapComplete: { around: 48.848198890686035, delay: 2500 },
      environment: { around: 0 },
      loopStart: -1,
      loopExit: -1
    }
    {
      name: 'node',
      entryType: 'node',
      startTime: 0,
      duration: { around: 1058.5430703163147 },
      nodeStart: { around: 0 },
      v8Start: { around: 0 },
      bootstrapComplete: { around: 48.848198890686035, delay: 2500 },
      environment: { around: 0 },
      loopStart: { around: 48.848198890686035, delay: 2500 },
      loopExit: -1
    }
    {
      name: 'node',
      entryType: 'node',
      startTime: 0,
      duration: { around: 1379.0943932533264 },
      nodeStart: { around: 0 },
      v8Start: { around: 0 },
      bootstrapComplete: { around: 48.848198890686035, delay: 2500 },
      environment: { around: 0 },
      loopStart: { around: 48.848198890686035, delay: 2500 },
      loopExit: { around: 1379.1089520454407 }
    }
    assert.js:383
        throw err;
        ^
    
    AssertionError [ERR_ASSERTION]: duration: 319.4689869880676 >= 250
        at checkNodeTiming (/home/iojs/build/workspace/node-test-commit-linux-containered/test/sequential/test-perf-hooks.js:67:7)
        at Timeout._onTimeout (/home/iojs/build/workspace/node-test-commit-linux-containered/test/sequential/test-perf-hooks.js:93:3)
        at listOnTimeout (internal/timers.js:535:17)
        at processTimers (internal/timers.js:479:7) {
      generatedMessage: false,
      code: 'ERR_ASSERTION',
      actual: false,
      expected: true,
      operator: '=='
    }
  ...

ref: https://ci.nodejs.org/job/node-test-commit-linux-containered/nodes=ubuntu1804_sharedlibs_withoutssl_x64/16233/consoleText

[mscdex]

This happened again in ubuntu1804_sharedlibs_debug_x64:

not ok 2569 sequential/test-perf-hooks
  ---
  duration_ms: 0.962
  severity: fail
  exitcode: 1
  stack: |-
    {
      name: 'node',
      entryType: 'node',
      startTime: 0,
      duration: { around: 666.947943687439 },
      nodeStart: { around: 0 },
      v8Start: { around: 0 },
      bootstrapComplete: { around: 653.3463382720947, delay: 2500 },
      environment: { around: 0 },
      loopStart: -1,
      loopExit: -1
    }
    assert.js:387
        throw err;
        ^
    
    AssertionError [ERR_ASSERTION]: environment: 298.97513580322266 >= 250
        at checkNodeTiming (/home/iojs/build/workspace/node-test-commit-linux-containered/test/sequential/test-perf-hooks.js:67:7)
        at Object.<anonymous> (/home/iojs/build/workspace/node-test-commit-linux-containered/test/sequential/test-perf-hooks.js:79:1)
        at Module._compile (internal/modules/cjs/loader.js:1208:30)
        at Object.Module._extensions..js (internal/modules/cjs/loader.js:1228:10)
        at Module.load (internal/modules/cjs/loader.js:1057:32)
        at Function.Module._load (internal/modules/cjs/loader.js:952:14)
        at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:71:12)
        at internal/main/run_main_module.js:17:47 {
      generatedMessage: false,
      code: 'ERR_ASSERTION',
      actual: false,
      expected: true,
      operator: '=='
    }

[gireeshpunathil]

seeing again:

10:29:46 not ok 2619 sequential/test-perf-hooks
10:29:46   ---
10:29:46   duration_ms: 0.989
10:29:46   severity: fail
10:29:46   exitcode: 1
10:29:46   stack: |-
10:29:46     {
10:29:46       name: 'node',
10:29:46       entryType: 'node',
10:29:46       startTime: 0,
10:29:46       duration: { around: 812.3277568817139 },
10:29:46       nodeStart: { around: 0 },
10:29:46       v8Start: { around: 0 },
10:29:46       bootstrapComplete: { around: 802.1083354949951, delay: 2500 },
10:29:46       environment: { around: 0 },
10:29:46       loopStart: -1,
10:29:46       loopExit: -1
10:29:46     }
10:29:46     assert.js:387
10:29:46         throw err;
10:29:46         ^
10:29:46     
10:29:46     AssertionError [ERR_ASSERTION]: environment: 376.6369514465332 >= 250
10:29:46         at checkNodeTiming (/home/iojs/build/workspace/node-test-commit-linux-containered/test/sequential/test-perf-hooks.js:67:7)
10:29:46         at Object.<anonymous> (/home/iojs/build/workspace/node-test-commit-linux-containered/test/sequential/test-perf-hooks.js:79:1)
10:29:46         at Module._compile (internal/modules/cjs/loader.js:1204:30)
10:29:46         at Object.Module._extensions..js (internal/modules/cjs/loader.js:1224:10)
10:29:46         at Module.load (internal/modules/cjs/loader.js:1053:32)
10:29:46         at Function.Module._load (internal/modules/cjs/loader.js:948:14)
10:29:46         at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:71:12)
10:29:46         at internal/main/run_main_module.js:17:47 {
10:29:46       generatedMessage: false,
10:29:46       code: 'ERR_ASSERTION',
10:29:46       actual: false,
10:29:46       expected: true,
10:29:46       operator: '=='
10:29:46     }

https://ci.nodejs.org/job/node-test-commit-linux-containered/nodes=ubuntu1804_sharedlibs_debug_x64/18284/console

[Trott]

This is slightly different in that it failed on Raspberry Pi rather than a container/shared libs build:

https://ci.nodejs.org/job/node-test-binary-arm-12+/10366/RUN_SUBSET=1,label=pi2-docker/console

06:49:53 not ok 804 sequential/test-perf-hooks
06:49:53   ---
06:49:53   duration_ms: 2.605
06:49:53   severity: fail
06:49:53   exitcode: 1
06:49:53   stack: |-
06:49:53     {
06:49:53       name: 'node',
06:49:53       entryType: 'node',
06:49:53       startTime: 0,
06:49:53       duration: { around: 2115.6457719802856 },
06:49:53       nodeStart: { around: 0 },
06:49:53       v8Start: { around: 0 },
06:49:53       bootstrapComplete: { around: 2115.0729010105133, delay: 2500 },
06:49:53       environment: { around: 0 },
06:49:53       loopStart: -1,
06:49:53       loopExit: -1
06:49:53     }
06:49:53     node:assert:412
06:49:53         throw err;
06:49:53         ^
06:49:53     
06:49:53     AssertionError [ERR_ASSERTION]: environment: 327.359983921051 >= 250
06:49:53         at checkNodeTiming (/home/iojs/build/workspace/node-test-binary-arm/test/sequential/test-perf-hooks.js:31:7)
06:49:53         at Object.<anonymous> (/home/iojs/build/workspace/node-test-binary-arm/test/sequential/test-perf-hooks.js:43:1)
06:49:53         at Module._compile (node:internal/modules/cjs/loader:1108:14)
06:49:53         at Object.Module._extensions..js (node:internal/modules/cjs/loader:1137:10)
06:49:53         at Module.load (node:internal/modules/cjs/loader:988:32)
06:49:53         at Function.Module._load (node:internal/modules/cjs/loader:828:14)
06:49:53         at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:76:12)
06:49:53         at node:internal/main/run_main_module:17:47 {
06:49:53       generatedMessage: false,
06:49:53       code: 'ERR_ASSERTION',
06:49:53       actual: false,
06:49:53       expected: true,
06:49:53       operator: '=='
06:49:53     }
06:49:53   ...

[github-actions]

This issue has been marked as stale due to 210 days of inactivity.
It will be automatically closed in 30 days if no further activity occurs. If this is still relevant, please leave a comment or update it to keep it open.

[github-actions]

This issue has been automatically closed after 30 days of inactivity following its stale status (no activity for a total of 120 days).
If this is still relevant, feel free to reopen it or leave a comment with additional details so we can continue the discussion.