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   ...