Skip to content

investigate flaky test-cpu-prof #27611

Closed
Closed
investigate flaky test-cpu-prof#27611
Labels
flaky-testIssues and PRs involving tests that fail intermittently in CI.

Description

@Trott
Trott
opened on May 8, 2019

https://ci.nodejs.org/job/node-test-commit-freebsd/26122/nodes=freebsd11-x64/console

test-digitalocean-freebsd11-x64-2

Details 
00:15:35 not ok 2553 sequential/test-cpu-prof
00:15:35   ---
00:15:35   duration_ms: 2.101
00:15:35   severity: fail
00:15:35   exitcode: 1
00:15:35   stack: |-
00:15:35     Dispatching message { "id": 1, "method": "Profiler.enable" }
00:15:35     Receive CPU profile message, ending = false
00:15:35     Dispatching message { "id": 2, "method": "Profiler.start" }
00:15:35     Receive CPU profile message, ending = false
00:15:35     Dispatching message { "id": 3, "method": "Profiler.setSamplingInterval", "params": { "interval": 50 } }
00:15:35     Receive CPU profile message, ending = false
00:15:35     Dispatching message { "id": 1, "method": "Profiler.enable" }
00:15:35     Receive CPU profile message, ending = false
00:15:35     Dispatching message { "id": 2, "method": "Profiler.start" }
00:15:35     Receive CPU profile message, ending = false
00:15:35     Dispatching message { "id": 3, "method": "Profiler.setSamplingInterval", "params": { "interval": 50 } }
00:15:35     Receive CPU profile message, ending = false
00:15:35     EndStartedProfilers
00:15:35     Ending cpu profiling
00:15:35     Dispatching message { "id": 4, "method": "Profiler.stop" }
00:15:35     Receive CPU profile message, ending = true
00:15:35     Written result to prof/CPU.20190508.071535.5764.1.002.cpuprofile
00:15:35     EndStartedProfilers
00:15:35     Ending cpu profiling
00:15:35     Dispatching message { "id": 4, "method": "Profiler.stop" }
00:15:35     Receive CPU profile message, ending = true
00:15:35     Written result to prof/CPU.20190508.071535.5764.0.001.cpuprofile
00:15:35     
00:15:35     CPU path:  /usr/home/iojs/node-tmp/.tmp.0/prof/CPU.20190508.071535.5764.0.001.cpuprofile
00:15:35     [
00:15:35       {
00:15:35         id: 1,
00:15:35         callFrame: {
00:15:35           functionName: '(root)',
00:15:35           scriptId: '0',
00:15:35           url: '',
00:15:35           lineNumber: -1,
00:15:35           columnNumber: -1
00:15:35         },
00:15:35         hitCount: 0,
00:15:35         children: [ 2, 3, 5, 25, 55, 58 ]
00:15:35       },
00:15:35       {
00:15:35         id: 2,
00:15:35         callFrame: {
00:15:35           functionName: '(program)',
00:15:35           scriptId: '0',
00:15:35           url: '',
00:15:35           lineNumber: -1,
00:15:35           columnNumber: -1
00:15:35         },
00:15:35         hitCount: 9
00:15:35       },
00:15:35       {
00:15:35         id: 3,
00:15:35         callFrame: {
00:15:35           functionName: '',
00:15:35           scriptId: '7',
00:15:35           url: 'internal/bootstrap/loaders.js',
00:15:35           lineNumber: 0,
00:15:35           columnNumber: 0
00:15:35         },
00:15:35         hitCount: 0,
00:15:35         children: [ 4 ]
00:15:35       },
00:15:35       {
00:15:35         id: 4,
00:15:35         callFrame: {
00:15:35           functionName: 'internalBinding',
00:15:35           scriptId: '7',
00:15:35           url: 'internal/bootstrap/loaders.js',
00:15:35           lineNumber: 127,
00:15:35           columnNumber: 44
00:15:35         },
00:15:35         hitCount: 1,
00:15:35         positionTicks: [ [Object] ]
00:15:35       },
00:15:35       {
00:15:35         id: 5,
00:15:35         callFrame: {
00:15:35           functionName: '',
00:15:35           scriptId: '8',
00:15:35           url: 'internal/bootstrap/node.js',
00:15:35           lineNumber: 0,
00:15:35           columnNumber: 0
00:15:35         },
00:15:35         hitCount: 4,
00:15:35         children: [ 6, 15, 23 ],
00:15:35         positionTicks: [ [Object], [Object], [Object], [Object] ]
00:15:35       },
00:15:35       {
00:15:35         id: 6,
00:15:35         callFrame: {
00:15:35           functionName: 'nativeModuleRequire',
00:15:35           scriptId: '7',
00:15:35           url: 'internal/bootstrap/loaders.js',
00:15:35           lineNumber: 182,
00:15:35           columnNumber: 28
00:15:35         },
00:15:35         hitCount: 0,
00:15:35         children: [ 7 ]
00:15:35       },
00:15:35       {
00:15:35         id: 7,
00:15:35         callFrame: {
00:15:35           functionName: 'NativeModule.compile',
00:15:35           scriptId: '7',
00:15:35           url: 'internal/bootstrap/loaders.js',
00:15:35           lineNumber: 286,
00:15:35           columnNumber: 41
00:15:35         },
00:15:35         hitCount: 3,
00:15:35         children: [ 8, 24 ],
00:15:35         positionTicks: [ [Object] ]
00:15:35       },
00:15:35       {
00:15:35         id: 8,
00:15:35         callFrame: {
00:15:35           functionName: '',
00:15:35           scriptId: '9',
00:15:35           url: 'internal/util.js',
00:15:35           lineNumber: 0,
00:15:35           columnNumber: 0
00:15:35         },
00:15:35         hitCount: 0,
00:15:35         children: [ 9, 14 ]
00:15:35       },
00:15:35       {
00:15:35         id: 9,
00:15:35         callFrame: {
00:15:35           functionName: 'nativeModuleRequire',
00:15:35           scriptId: '7',
00:15:35           url: 'internal/bootstrap/loaders.js',
00:15:35           lineNumber: 182,
00:15:35           columnNumber: 28
00:15:35         },
00:15:35         hitCount: 0,
00:15:35         children: [ 10 ]
00:15:35       },
00:15:35       {
00:15:35         id: 10,
00:15:35         callFrame: {
00:15:35           functionName: 'NativeModule.compile',
00:15:35           scriptId: '7',
00:15:35           url: 'internal/bootstrap/loaders.js',
00:15:35           lineNumber: 286,
00:15:35           columnNumber: 41
00:15:35         },
00:15:35         hitCount: 1,
00:15:35         children: [ 11 ],
00:15:35         positionTicks: [ [Object] ]
00:15:35       },
00:15:35       {
00:15:35         id: 11,
00:15:35         callFrame: {
00:15:35           functionName: '',
00:15:35           scriptId: '10',
00:15:35           url: 'internal/errors.js',
00:15:35           lineNumber: 0,
00:15:35           columnNumber: 0
00:15:35         },
00:15:35         hitCount: 0,
00:15:35         children: [ 12 ]
00:15:35       },
00:15:35       {
00:15:35         id: 12,
00:15:35         callFrame: {
00:15:35           functionName: 'E',
00:15:35           scriptId: '10',
00:15:35           url: 'internal/errors.js',
00:15:35           lineNumber: 250,
00:15:36           columnNumber: 10
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         children: [ 13 ],
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 13,
00:15:36         callFrame: {
00:15:36           functionName: 'makeNodeErrorWithCode',
00:15:36           scriptId: '10',
00:15:36           url: 'internal/errors.js',
00:15:36           lineNumber: 164,
00:15:36           columnNumber: 30
00:15:36         },
00:15:36         hitCount: 2,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 14,
00:15:36         callFrame: {
00:15:36           functionName: 'internalBinding',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 127,
00:15:36           columnNumber: 44
00:15:36         },
00:15:36         hitCount: 2,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 24,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '21',
00:15:36           url: 'internal/async_hooks.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 15,
00:15:36         callFrame: {
00:15:36           functionName: 'setupBuffer',
00:15:36           scriptId: '8',
00:15:36           url: 'internal/bootstrap/node.js',
00:15:36           lineNumber: 376,
00:15:36           columnNumber: 20
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 16 ]
00:15:36       },
00:15:36       {
00:15:36         id: 16,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 17 ]
00:15:36       },
00:15:36       {
00:15:36         id: 17,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 18 ]
00:15:36       },
00:15:36       {
00:15:36         id: 18,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '12',
00:15:36           url: 'buffer.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 19, 22 ]
00:15:36       },
00:15:36       {
00:15:36         id: 19,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 20 ]
00:15:36       },
00:15:36       {
00:15:36         id: 20,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 2,
00:15:36         children: [ 21 ],
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 21,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '14',
00:15:36           url: 'internal/util/inspect.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 22,
00:15:36         callFrame: {
00:15:36           functionName: 'createPool',
00:15:36           scriptId: '12',
00:15:36           url: 'buffer.js',
00:15:36           lineNumber: 120,
00:15:36           columnNumber: 19
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 23,
00:15:36         callFrame: {
00:15:36           functionName: 'wrapPosixCredentialSetters',
00:15:36           scriptId: '19',
00:15:36           url: 'internal/process/main_thread_only.js',
00:15:36           lineNumber: 53,
00:15:36           columnNumber: 35
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 25,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '40',
00:15:36           url: 'internal/main/run_main_module.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 26, 27 ]
00:15:36       },
00:15:36       {
00:15:36         id: 26,
00:15:36         callFrame: {
00:15:36           functionName: 'prepareMainThreadExecution',
00:15:36           scriptId: '41',
00:15:36           url: 'internal/bootstrap/pre_execution.js',
00:15:36           lineNumber: 7,
00:15:36           columnNumber: 35
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 27,
00:15:36         callFrame: {
00:15:36           functionName: 'Module.runMain',
00:15:36           scriptId: '44',
00:15:36           url: 'internal/modules/cjs/loader.js',
00:15:36           lineNumber: 807,
00:15:36           columnNumber: 25
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 28 ]
00:15:36       },
00:15:36       {
00:15:36         id: 28,
00:15:36         callFrame: {
00:15:36           functionName: 'Module._load',
00:15:36           scriptId: '44',
00:15:36           url: 'internal/modules/cjs/loader.js',
00:15:36           lineNumber: 506,
00:15:36           columnNumber: 23
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 29 ]
00:15:36       },
00:15:36       {
00:15:36         id: 29,
00:15:36         callFrame: {
00:15:36           functionName: 'Module.load',
00:15:36           scriptId: '44',
00:15:36           url: 'internal/modules/cjs/loader.js',
00:15:36           lineNumber: 619,
00:15:36           columnNumber: 32
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 30 ]
00:15:36       },
00:15:36       {
00:15:36         id: 30,
00:15:36         callFrame: {
00:15:36           functionName: 'Module._extensions..js',
00:15:36           scriptId: '44',
00:15:36           url: 'internal/modules/cjs/loader.js',
00:15:36           lineNumber: 767,
00:15:36           columnNumber: 36
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 31 ]
00:15:36       },
00:15:36       {
00:15:36         id: 31,
00:15:36         callFrame: {
00:15:36           functionName: 'Module._compile',
00:15:36           scriptId: '44',
00:15:36           url: 'internal/modules/cjs/loader.js',
00:15:36           lineNumber: 681,
00:15:36           columnNumber: 36
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 32 ]
00:15:36       },
00:15:36       {
00:15:36         id: 32,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '52',
00:15:36           url: 'file:///usr/home/iojs/build/workspace/node-test-commit-freebsd/nodes/freebsd11-x64/test/fixtures/workload/fibonacci-worker.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 33, 54 ]
00:15:36       },
00:15:36       {
00:15:36         id: 33,
00:15:36         callFrame: {
00:15:36           functionName: 'require',
00:15:36           scriptId: '49',
00:15:36           url: 'internal/modules/cjs/helpers.js',
00:15:36           lineNumber: 14,
00:15:36           columnNumber: 18
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 34 ]
00:15:36       },
00:15:36       {
00:15:36         id: 34,
00:15:36         callFrame: {
00:15:36           functionName: 'Module.require',
00:15:36           scriptId: '44',
00:15:36           url: 'internal/modules/cjs/loader.js',
00:15:36           lineNumber: 657,
00:15:36           columnNumber: 35
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 35 ]
00:15:36       },
00:15:36       {
00:15:36         id: 35,
00:15:36         callFrame: {
00:15:36           functionName: 'Module._load',
00:15:36           scriptId: '44',
00:15:36           url: 'internal/modules/cjs/loader.js',
00:15:36           lineNumber: 506,
00:15:36           columnNumber: 23
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 36 ]
00:15:36       },
00:15:36       {
00:15:36         id: 36,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compileForPublicLoader',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 210,
00:15:36           columnNumber: 56
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 37 ]
00:15:36       },
00:15:36       {
00:15:36         id: 37,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 38 ]
00:15:36       },
00:15:36       {
00:15:36         id: 38,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '53',
00:15:36           url: 'worker_threads.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 39 ]
00:15:36       },
00:15:36       {
00:15:36         id: 39,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 40 ]
00:15:36       },
00:15:36       {
00:15:36         id: 40,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 41 ]
00:15:36       },
00:15:36       {
00:15:36         id: 41,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '54',
00:15:36           url: 'internal/worker.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 42 ]
00:15:36       },
00:15:36       {
00:15:36         id: 42,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 43 ]
00:15:36       },
00:15:36       {
00:15:36         id: 43,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 44 ]
00:15:36       },
00:15:36       {
00:15:36         id: 44,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '55',
00:15:36           url: 'internal/worker/io.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         children: [ 45 ],
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 45,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 46 ]
00:15:36       },
00:15:36       {
00:15:36         id: 46,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 47 ]
00:15:36       },
00:15:36       {
00:15:36         id: 47,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '56',
00:15:36           url: 'stream.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 48 ]
00:15:36       },
00:15:36       {
00:15:36         id: 48,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 49 ]
00:15:36       },
00:15:36       {
00:15:36         id: 49,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 50, 53 ]
00:15:36       },
00:15:36       {
00:15:36         id: 50,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '60',
00:15:36           url: '_stream_readable.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 51 ]
00:15:36       },
00:15:36       {
00:15:36         id: 51,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 52 ]
00:15:36       },
00:15:36       {
00:15:36         id: 52,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 53,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '64',
00:15:36           url: '_stream_writable.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 54,
00:15:36         callFrame: {
00:15:36           functionName: 'join',
00:15:36           scriptId: '31',
00:15:36           url: 'path.js',
00:15:36           lineNumber: 1030,
00:15:36           columnNumber: 6
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 55,
00:15:36         callFrame: {
00:15:36           functionName: 'processTicksAndRejections',
00:15:36           scriptId: '22',
00:15:36           url: 'internal/process/task_queues.js',
00:15:36           lineNumber: 61,
00:15:36           columnNumber: 34
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 56 ]
00:15:36       },
00:15:36       {
00:15:36         id: 56,
00:15:36         callFrame: {
00:15:36           functionName: 'resume_',
00:15:36           scriptId: '60',
00:15:36           url: '_stream_readable.js',
00:15:36           lineNumber: 932,
00:15:36           columnNumber: 16
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 57 ]
00:15:36       },
00:15:36       {
00:15:36         id: 57,
00:15:36         callFrame: {
00:15:36           functionName: 'Readable.read',
00:15:36           scriptId: '60',
00:15:36           url: '_stream_readable.js',
00:15:36           lineNumber: 376,
00:15:36           columnNumber: 34
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 58,
00:15:36         callFrame: {
00:15:36           functionName: 'onmessage',
00:15:36           scriptId: '55',
00:15:36           url: 'internal/worker/io.js',
00:15:36           lineNumber: 63,
00:15:36           columnNumber: 62
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 59 ]
00:15:36       },
00:15:36       {
00:15:36         id: 59,
00:15:36         callFrame: {
00:15:36           functionName: 'emit',
00:15:36           scriptId: '11',
00:15:36           url: 'events.js',
00:15:36           lineNumber: 144,
00:15:36           columnNumber: 43
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 60 ]
00:15:36       },
00:15:36       {
00:15:36         id: 60,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '54',
00:15:36           url: 'internal/worker.js',
00:15:36           lineNumber: 117,
00:15:36           columnNumber: 30
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 61 ]
00:15:36       },
00:15:36       {
00:15:36         id: 61,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '54',
00:15:36           url: 'internal/worker.js',
00:15:36           lineNumber: 178,
00:15:36           columnNumber: 14
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 62 ]
00:15:36       },
00:15:36       {
00:15:36         id: 62,
00:15:36         callFrame: {
00:15:36           functionName: 'Readable.push',
00:15:36           scriptId: '60',
00:15:36           url: '_stream_readable.js',
00:15:36           lineNumber: 208,
00:15:36           columnNumber: 34
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 63 ]
00:15:36       },
00:15:36       {
00:15:36         id: 63,
00:15:36         callFrame: {
00:15:36           functionName: 'readableAddChunk',
00:15:36           scriptId: '60',
00:15:36           url: '_stream_readable.js',
00:15:36           lineNumber: 233,
00:15:36           columnNumber: 25
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 64 ]
00:15:36       },
00:15:36       {
00:15:36         id: 64,
00:15:36         callFrame: {
00:15:36           functionName: 'addChunk',
00:15:36           scriptId: '60',
00:15:36           url: '_stream_readable.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 17
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 65 ]
00:15:36       },
00:15:36       {
00:15:36         id: 65,
00:15:36         callFrame: {
00:15:36           functionName: 'maybeReadMore',
00:15:36           scriptId: '60',
00:15:36           url: '_stream_readable.js',
00:15:36           lineNumber: 564,
00:15:36           columnNumber: 22
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       }
00:15:36     ]
00:15:36     CPU path:  /usr/home/iojs/node-tmp/.tmp.0/prof/CPU.20190508.071535.5764.1.002.cpuprofile
00:15:36     [
00:15:36       {
00:15:36         id: 1,
00:15:36         callFrame: {
00:15:36           functionName: '(root)',
00:15:36           scriptId: '0',
00:15:36           url: '',
00:15:36           lineNumber: -1,
00:15:36           columnNumber: -1
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 2, 3, 5, 37 ]
00:15:36       },
00:15:36       {
00:15:36         id: 2,
00:15:36         callFrame: {
00:15:36           functionName: '(program)',
00:15:36           scriptId: '0',
00:15:36           url: '',
00:15:36           lineNumber: -1,
00:15:36           columnNumber: -1
00:15:36         },
00:15:36         hitCount: 2
00:15:36       },
00:15:36       {
00:15:36         id: 3,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         children: [ 4 ],
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 4,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 148,
00:15:36           columnNumber: 21
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 5,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '8',
00:15:36           url: 'internal/bootstrap/node.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         children: [ 6, 14, 15, 16 ],
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 6,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         children: [ 7 ],
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 7,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         children: [ 8, 25 ],
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 8,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '9',
00:15:36           url: 'internal/util.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         children: [ 9, 13 ],
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 9,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 10 ]
00:15:36       },
00:15:36       {
00:15:36         id: 10,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         children: [ 11 ],
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 11,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '10',
00:15:36           url: 'internal/errors.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         children: [ 12 ],
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 12,
00:15:36         callFrame: {
00:15:36           functionName: 'E',
00:15:36           scriptId: '10',
00:15:36           url: 'internal/errors.js',
00:15:36           lineNumber: 250,
00:15:36           columnNumber: 10
00:15:36         },
00:15:36         hitCount: 2,
00:15:36         positionTicks: [ [Object], [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 13,
00:15:36         callFrame: {
00:15:36           functionName: 'internalBinding',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 127,
00:15:36           columnNumber: 44
00:15:36         },
00:15:36         hitCount: 2,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 25,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '19',
00:15:36           url: 'internal/process/worker_thread_only.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 26 ]
00:15:36       },
00:15:36       {
00:15:36         id: 26,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 27 ]
00:15:36       },
00:15:36       {
00:15:36         id: 27,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 28 ]
00:15:36       },
00:15:36       {
00:15:36         id: 28,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '20',
00:15:36           url: 'internal/worker/io.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 29 ]
00:15:36       },
00:15:36       {
00:15:36         id: 29,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 30 ]
00:15:36       },
00:15:36       {
00:15:36         id: 30,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 31 ]
00:15:36       },
00:15:36       {
00:15:36         id: 31,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '21',
00:15:36           url: 'stream.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 32 ]
00:15:36       },
00:15:36       {
00:15:36         id: 32,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 33 ]
00:15:36       },
00:15:36       {
00:15:36         id: 33,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 3,
00:15:36         children: [ 34 ],
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 34,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '25',
00:15:36           url: '_stream_readable.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 35 ]
00:15:36       },
00:15:36       {
00:15:36         id: 35,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 36 ]
00:15:36       },
00:15:36       {
00:15:36         id: 36,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 14,
00:15:36         callFrame: {
00:15:36           functionName: 'setupProcessObject',
00:15:36           scriptId: '8',
00:15:36           url: 'internal/bootstrap/node.js',
00:15:36           lineNumber: 292,
00:15:36           columnNumber: 27
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 15,
00:15:36         callFrame: {
00:15:36           functionName: 'setupGlobalProxy',
00:15:36           scriptId: '8',
00:15:36           url: 'internal/bootstrap/node.js',
00:15:36           lineNumber: 337,
00:15:36           columnNumber: 25
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 16,
00:15:36         callFrame: {
00:15:36           functionName: 'setupBuffer',
00:15:36           scriptId: '8',
00:15:36           url: 'internal/bootstrap/node.js',
00:15:36           lineNumber: 376,
00:15:36           columnNumber: 20
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 17 ]
00:15:36       },
00:15:36       {
00:15:36         id: 17,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 18 ]
00:15:36       },
00:15:36       {
00:15:36         id: 18,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         children: [ 19 ],
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 19,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '12',
00:15:36           url: 'buffer.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 20, 24 ]
00:15:36       },
00:15:36       {
00:15:36         id: 20,
00:15:36         callFrame: {
00:15:36           functionName: 'nativeModuleRequire',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 182,
00:15:36           columnNumber: 28
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 21 ]
00:15:36       },
00:15:36       {
00:15:36         id: 21,
00:15:36         callFrame: {
00:15:36           functionName: 'NativeModule.compile',
00:15:36           scriptId: '7',
00:15:36           url: 'internal/bootstrap/loaders.js',
00:15:36           lineNumber: 286,
00:15:36           columnNumber: 41
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 22, 23 ]
00:15:36       },
00:15:36       {
00:15:36         id: 22,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '14',
00:15:36           url: 'internal/util/inspect.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 3,
00:15:36         positionTicks: [ [Object], [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 23,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '17',
00:15:36           url: 'internal/buffer.js',
00:15:36           lineNumber: 0,
00:15:36           columnNumber: 0
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 24,
00:15:36         callFrame: {
00:15:36           functionName: 'createPool',
00:15:36           scriptId: '12',
00:15:36           url: 'buffer.js',
00:15:36           lineNumber: 120,
00:15:36           columnNumber: 19
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 37,
00:15:36         callFrame: {
00:15:36           functionName: 'onmessage',
00:15:36           scriptId: '20',
00:15:36           url: 'internal/worker/io.js',
00:15:36           lineNumber: 63,
00:15:36           columnNumber: 62
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 38 ]
00:15:36       },
00:15:36       {
00:15:36         id: 38,
00:15:36         callFrame: {
00:15:36           functionName: 'emit',
00:15:36           scriptId: '11',
00:15:36           url: 'events.js',
00:15:36           lineNumber: 144,
00:15:36           columnNumber: 43
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 39 ]
00:15:36       },
00:15:36       {
00:15:36         id: 39,
00:15:36         callFrame: {
00:15:36           functionName: '',
00:15:36           scriptId: '52',
00:15:36           url: 'internal/main/worker_thread.js',
00:15:36           lineNumber: 89,
00:15:36           columnNumber: 19
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 40 ]
00:15:36       },
00:15:36       {
00:15:36         id: 40,
00:15:36         callFrame: {
00:15:36           functionName: 'Module.runMain',
00:15:36           scriptId: '61',
00:15:36           url: 'internal/modules/cjs/loader.js',
00:15:36           lineNumber: 807,
00:15:36           columnNumber: 25
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 41 ]
00:15:36       },
00:15:36       {
00:15:36         id: 41,
00:15:36         callFrame: {
00:15:36           functionName: 'Module._load',
00:15:36           scriptId: '61',
00:15:36           url: 'internal/modules/cjs/loader.js',
00:15:36           lineNumber: 506,
00:15:36           columnNumber: 23
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 42 ]
00:15:36       },
00:15:36       {
00:15:36         id: 42,
00:15:36         callFrame: {
00:15:36           functionName: 'Module.load',
00:15:36           scriptId: '61',
00:15:36           url: 'internal/modules/cjs/loader.js',
00:15:36           lineNumber: 619,
00:15:36           columnNumber: 32
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 43 ]
00:15:36       },
00:15:36       {
00:15:36         id: 43,
00:15:36         callFrame: {
00:15:36           functionName: 'Module._extensions..js',
00:15:36           scriptId: '61',
00:15:36           url: 'internal/modules/cjs/loader.js',
00:15:36           lineNumber: 767,
00:15:36           columnNumber: 36
00:15:36         },
00:15:36         hitCount: 0,
00:15:36         children: [ 44 ]
00:15:36       },
00:15:36       {
00:15:36         id: 44,
00:15:36         callFrame: {
00:15:36           functionName: 'readFileSync',
00:15:36           scriptId: '64',
00:15:36           url: 'fs.js',
00:15:36           lineNumber: 332,
00:15:36           columnNumber: 21
00:15:36         },
00:15:36         hitCount: 3,
00:15:36         children: [ 45 ],
00:15:36         positionTicks: [ [Object], [Object], [Object] ]
00:15:36       },
00:15:36       {
00:15:36         id: 45,
00:15:36         callFrame: {
00:15:36           functionName: 'tryReadSync',
00:15:36           scriptId: '64',
00:15:36           url: 'fs.js',
00:15:36           lineNumber: 320,
00:15:36           columnNumber: 20
00:15:36         },
00:15:36         hitCount: 1,
00:15:36         positionTicks: [ [Object] ]
00:15:36       }
00:15:36     ]
00:15:36     assert.js:362
00:15:36         throw err;
00:15:36         ^
00:15:36     
00:15:36     AssertionError [ERR_ASSERTION]: The expression evaluated to a falsy value:
00:15:36     
00:15:36       assert(profile1.frames.length > 0 || profile2.frames.length > 0)
00:15:36     
00:15:36         at Object.<anonymous> (/usr/home/iojs/build/workspace/node-test-commit-freebsd/nodes/freebsd11-x64/test/sequential/test-cpu-prof.js:366:3)
00:15:36         at Module._compile (internal/modules/cjs/loader.js:759:30)
00:15:36         at Object.Module._extensions..js (internal/modules/cjs/loader.js:770:10)
00:15:36         at Module.load (internal/modules/cjs/loader.js:628:32)
00:15:36         at Function.Module._load (internal/modules/cjs/loader.js:555:12)
00:15:36         at Function.Module.runMain (internal/modules/cjs/loader.js:822:10)
00:15:36         at internal/main/run_main_module.js:17:11
00:15:36   ...

@joyeecheung

Activity

  1. Trott
    added
    flaky-testIssues and PRs involving tests that fail intermittently in CI.
    on May 8, 2019

  2. joyeecheung commented on May 8, 2019

    @joyeecheung
    joyeecheung
    on May 8, 2019
    Member

    I think this is caused by the function finishing too fast before it gets sampled in the profile. I have a rewritten version of the test here which may be more stable than the current one, though it runs longer (the current one takes < 1 sec on my laptop while the new one takes about 3 sec), because it intentionally keeps the function being profiled running for much longer than the sampling interval (1000x) to make sure it shows up in the profile.

    I will see if https://ci.nodejs.org/job/node-test-commit/28455/ works before opening a PR.

  3. joyeecheung commented on May 8, 2019

    @joyeecheung
    joyeecheung
    on May 8, 2019
    Member

    Although, on the other hand, another approach would be to not looking for a specific function in the profile at all but instead only make sure the profile exits and can be parsed. But this is kind of like the tick processor test - we want to make sure the generated profile actually can be analyzed by users and the functionality don't get broken randomly by V8.

  4. joyeecheung commented on May 9, 2019

    @joyeecheung
    joyeecheung
    on May 9, 2019
    Member

    From https://ci.nodejs.org/job/node-test-commit/28459/ there is an alarming DCHECK:

    See failures on test-digitalocean-ubuntu1604_sharedlibs_container-x64-7: 
    not ok 436 parallel/test-cpu-prof
  ---
  duration_ms: 1.978
  severity: fail
  exitcode: 1
  stack: |-
    Dispatching message { "id": 1, "method": "Profiler.enable" }
    Receive CPU profile message, ending = false
    Dispatching message { "id": 2, "method": "Profiler.start" }
    Receive CPU profile message, ending = false
    Dispatching message { "id": 3, "method": "Profiler.setSamplingInterval", "params": { "interval": 1000 } }
    Receive CPU profile message, ending = false
    
    
    #
    # Fatal error in ../deps/v8/src/profiler/profile-generator.cc, line 24
    # Debug check failed: line > 0 (0 vs. 0).
    #
    #
    #
    #FailureMessage Object: 0x7ffc07a223e0
    assert.js:89
      throw new AssertionError(obj);
      ^
    
    AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
    
    null !== 0
    
        at Object.<anonymous> (/home/iojs/build/workspace/node-test-commit-linux-containered/test/parallel/test-cpu-prof.js:78:10)
        at Module._compile (internal/modules/cjs/loader.js:759:30)
        at Object.Module._extensions..js (internal/modules/cjs/loader.js:770:10)
        at Module.load (internal/modules/cjs/loader.js:628:32)
        at Function.Module._load (internal/modules/cjs/loader.js:555:12)
        at Function.Module.runMain (internal/modules/cjs/loader.js:822:10)
        at internal/main/run_main_module.js:17:11
  ...

    And from a glance I think test failures in release builds all have frames where lineNumber = -1 so it might be an upstream bug.

    EDIT: it looks like the -1s are just for synthetic nodes which makes sense..

  5. Trott commented on Jun 10, 2019

    @Trott
    Trott
    on Jun 10, 2019
    MemberAuthor

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

    10:18:23 not ok 2340 sequential/test-cpu-prof
10:18:23   ---
10:18:23   duration_ms: 480.79
10:18:23   severity: fail
10:18:23   exitcode: -15
10:18:23   stack: |-
10:18:23     timeout
10:18:23   ...

  6. Trott commented on Jun 10, 2019

    @Trott
    Trott
    on Jun 10, 2019
    MemberAuthor

    And again...I wondered if these particular failures are just because debug build is slow, but nope. On a successful run, this test takes 4 seconds or so on the debug build.

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

    10:57:29 not ok 2339 sequential/test-cpu-prof
10:57:29   ---
10:57:29   duration_ms: 480.70
10:57:29   severity: fail
10:57:29   exitcode: -15
10:57:29   stack: |-
10:57:29     timeout
10:57:29   ...

  7. Trott commented on Jun 11, 2019

    @Trott
    Trott
    on Jun 11, 2019
    MemberAuthor

    The test is failing consistently on debug builds in CI. Last success was about 36 hours ago.

    /cc @joyeecheung @addaleax (based on git log...sorry if you're not the right folks to ping here)

  8. joyeecheung commented on Jun 11, 2019

    @joyeecheung
    joyeecheung
    on Jun 11, 2019
    Member

    This takes 29 seconds to finish on a debug build for me locally..maybe we should split it into multiple tests instead.

  9. joyeecheung
    added a commit that references this issue on Jun 11, 2019

    test: split test-cpu-prof.js

    8f98cf5

  10. rvagg commented on Jun 12, 2019

    @rvagg
    rvagg
    on Jun 12, 2019
    Member

    @Trott just a minor follow-up to your notes in IRC: all of the test-softlayer-ubuntu1604_sharedlibs_container-x64-? Jenkins nodes are all running on the same single host server, test-softlayer-ubuntu1604-docker-x64-1 (which you have access to if you're brave enough to try and debug locally). If it's true that you're only getting failures on test-softlayer-ubuntu1604_sharedlibs_container-x64-? machines and not the other sharedlibs machines then it could be a local problem. But, you mentioned test-softlayer-ubuntu1604_sharedlibs_container-x64-7 which isn't a thing, there's test-digitalocean-ubuntu1604_sharedlibs_container-x64-7 but that's on one of the two DigitalOcean hosts that run these containers (one has the even numbers and the other has the odd numbers). We also have one running on Joyent too so that may show up occasionally.
    So, when looking for failure patterns with these container runs, pay attention to the provider name, in the case of SoftLayer and Joyent, they are all on the same base host. In the case of DO they span 2 hosts.

  11. joyeecheung commented on Jun 12, 2019

    @joyeecheung
    joyeecheung
    on Jun 12, 2019
    Member

    I did a quick scan and it seems after #28170 the flake has only showed up on freebsd due to being unable to find the target function in the samples e.g. https://ci.nodejs.org/job/node-test-commit-freebsd/26826/nodes=freebsd11-x64/consoleFull

  12. Trott commented on Jun 12, 2019

    @Trott
    Trott
    on Jun 12, 2019
    MemberAuthor

    I did a quick scan and it seems after #28170 the flake has only showed up on freebsd due to being unable to find the target function in the samples e.g. https://ci.nodejs.org/job/node-test-commit-freebsd/26826/nodes=freebsd11-x64/consoleFull

    FreeBSD tends to be our most sensitive host in terms of "failures caused by running a bunch of processes all at once rather than just a few or even one at a time". I'm still on Team Move-It-To-Sequential, but I seem to be the only one. :-| I can get on Team More-Lenient-Checking though.

  13. joyeecheung commented on Jun 13, 2019

    @joyeecheung
    joyeecheung
    on Jun 13, 2019
    Member

    I opened #28210 to move them to sequential - if the flake ever shows up again, we should consider relaxing the tests.

  14. BridgeAR
    added 2 commits that reference this issue on Jun 17, 2019

    test: split test-cpu-prof.js

    2353c63

    test: move --cpu-prof tests to sequential

    720a2a6

  15. 2 remaining items

  16. sam-github commented on Apr 13, 2020

    @sam-github
    sam-github
    on Apr 13, 2020
    Contributor

    flaky on lots of platforms, it seems:

    ... snip.... too long 
assert.js:384
    throw err;
    ^

AssertionError [ERR_ASSERTION]: The expression evaluated to a falsy value:

  assert(profile1.frames.length > 0 || profile2.frames.length > 0)

    at Object.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/sequential/test-cpu-prof-dir-worker.js:54:3)
    at Module._compile (internal/modules/cjs/loader.js:1178:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1198:10)
    at Module.load (internal/modules/cjs/loader.js:1027:32)
    at Function.Module._load (internal/modules/cjs/loader.js:923:14)
    at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:71:12)
    at internal/main/run_main_module.js:17:47 {
  generatedMessage: true,
  code: 'ERR_ASSERTION',
  actual: false,
  expected: true,
  operator: '=='
}
  17. Trott
    added a commit that references this issue on Apr 15, 2020

    test: mark cpu-prof-dir-worker flaky on all

    3f5142d
  18. MylesBorins
    added a commit that references this issue on Apr 17, 2020

    test: mark cpu-prof-dir-worker flaky on all

    4bb29ed
  19. BridgeAR
    added a commit that references this issue on Apr 28, 2020

    test: mark cpu-prof-dir-worker flaky on all

    23a4d60
  20. targos
    added a commit that references this issue on Apr 28, 2020

    test: mark cpu-prof-dir-worker flaky on all

    50130f0

  21. trivikr commented on May 21, 2026

    @trivikr
    trivikr
    on May 21, 2026
    Member

    Should this be closed?

    The file in question sequential/test-cpu-prof.js was split into 11 other files in 8f98cf5e15 in 2019

    There were some test failures in test-cpu-prof- files up until 2024, but those are tracked in https://github.com/search?q=repo%3Anodejs%2Freliability+test-cpu-prof&type=issues

  22. Trott
    closed this as completedon May 21, 2026
  23. nodejs-github-bot
    added a commit that references this issue on Sep 28, 2026

    test: unmark test-cpu-prof-dir-worker as flaky

    1a15692
  24. HoonDongKang
    added a commit that references this issue on Sep 29, 2026

    test: unmark test-cpu-prof-dir-worker as flaky

    2211841
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    flaky-testIssues and PRs involving tests that fail intermittently in CI.

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions