Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

investigate flaky test-cpu-prof #27611

Open
Trott opened this issue May 8, 2019 · 13 comments
Open

investigate flaky test-cpu-prof #27611

Trott opened this issue May 8, 2019 · 13 comments
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI.

Comments

@Trott
Copy link
Member

Trott commented May 8, 2019

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

test-digitalocean-freebsd11-x64-2

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

@Trott Trott added the flaky-test Issues and PRs related to the tests with unstable failures on the CI. label May 8, 2019
@joyeecheung
Copy link
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.

@joyeecheung
Copy link
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.

@joyeecheung
Copy link
Member

joyeecheung commented May 9, 2019

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

@Trott
Copy link
Member Author

Trott commented Jun 10, 2019

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

@Trott
Copy link
Member Author

Trott commented Jun 10, 2019

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

@Trott
Copy link
Member Author

Trott commented Jun 11, 2019

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)

@joyeecheung
Copy link
Member

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

joyeecheung added a commit that referenced this issue Jun 11, 2019
Split test-cpu-prof.js into multiple files for different
test cases so it's easier to find the problematic one if
it flakes.

Also move the split tests into parallel.

PR-URL: #28170
Refs: #27611
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Yongsheng Zhang <zyszys98@gmail.com>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Sam Roberts <vieuxtech@gmail.com>
Reviewed-By: Trivikram Kamat <trivikr.dev@gmail.com>
@rvagg
Copy link
Member

rvagg commented Jun 12, 2019

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

@joyeecheung
Copy link
Member

joyeecheung commented Jun 12, 2019

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

@Trott
Copy link
Member Author

Trott commented Jun 12, 2019

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.

@joyeecheung
Copy link
Member

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

pull bot pushed a commit to zys-contrib/node that referenced this issue Jun 16, 2019
The tests still fail after being split into multiple files,
(2 out of 30 runs in roughly 48 hours) and the causes are missing
target frames in the samples. This patch moves them to sequential
to observe if the flakiness can be fixed when the tests are
run on a system with less load.

If the flake ever shows up again even after the tests are moved
to sequential, we should consider make the test conditions more
lenient - that is, we would only assert that there are *some* frames
in the generated CPU profile but do not look for the target
function there.

PR-URL: nodejs#28210
Refs: nodejs#27611
Reviewed-By: Rich Trott <rtrott@gmail.com>
Reviewed-By: Michael Dawson <michael_dawson@ca.ibm.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
BridgeAR pushed a commit that referenced this issue Jun 17, 2019
Split test-cpu-prof.js into multiple files for different
test cases so it's easier to find the problematic one if
it flakes.

Also move the split tests into parallel.

PR-URL: #28170
Refs: #27611
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Yongsheng Zhang <zyszys98@gmail.com>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Sam Roberts <vieuxtech@gmail.com>
Reviewed-By: Trivikram Kamat <trivikr.dev@gmail.com>
BridgeAR pushed a commit that referenced this issue Jun 17, 2019
The tests still fail after being split into multiple files,
(2 out of 30 runs in roughly 48 hours) and the causes are missing
target frames in the samples. This patch moves them to sequential
to observe if the flakiness can be fixed when the tests are
run on a system with less load.

If the flake ever shows up again even after the tests are moved
to sequential, we should consider make the test conditions more
lenient - that is, we would only assert that there are *some* frames
in the generated CPU profile but do not look for the target
function there.

PR-URL: #28210
Refs: #27611
Reviewed-By: Rich Trott <rtrott@gmail.com>
Reviewed-By: Michael Dawson <michael_dawson@ca.ibm.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
targos pushed a commit that referenced this issue Jun 18, 2019
The tests still fail after being split into multiple files,
(2 out of 30 runs in roughly 48 hours) and the causes are missing
target frames in the samples. This patch moves them to sequential
to observe if the flakiness can be fixed when the tests are
run on a system with less load.

If the flake ever shows up again even after the tests are moved
to sequential, we should consider make the test conditions more
lenient - that is, we would only assert that there are *some* frames
in the generated CPU profile but do not look for the target
function there.

PR-URL: #28210
Refs: #27611
Reviewed-By: Rich Trott <rtrott@gmail.com>
Reviewed-By: Michael Dawson <michael_dawson@ca.ibm.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
@bnoordhuis
Copy link
Member

I just saw this failure: https://ci.nodejs.org/job/node-test-commit-linuxone/nodes=rhel72-s390x/15156/testReport/junit/(root)/test/sequential_test_cpu_prof_dir_worker/

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": 50 } }
Receive CPU profile message, ending = false
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": 50 } }
Receive CPU profile message, ending = false
EndStartedProfilers
Ending cpu profiling
Dispatching message { "id": 4, "method": "Profiler.stop" }
Receive CPU profile message, ending = true
Written result to prof/CPU.20190814.062019.42611.1.002.cpuprofile
EndStartedProfilers
Ending cpu profiling
Dispatching message { "id": 4, "method": "Profiler.stop" }
Receive CPU profile message, ending = true
Written result to prof/CPU.20190814.062019.42611.0.001.cpuprofile

CPU path:  /data/iojs/node-tmp/.tmp.2539/prof/CPU.20190814.062019.42611.0.001.cpuprofile
[
  {
    id: 1,
    callFrame: {
      functionName: '(root)',
      scriptId: '0',
      url: '',
      lineNumber: -1,
      columnNumber: -1
    },
    hitCount: 0,
    children: [ 2, 3, 5, 35, 55, 56 ]
  },
  {
    id: 2,
    callFrame: {
      functionName: '(program)',
      scriptId: '0',
      url: '',
      lineNumber: -1,
      columnNumber: -1
    },
    hitCount: 21
  },
  {
    id: 3,
    callFrame: {
      functionName: '',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 4 ]
  },
  {
    id: 4,
    callFrame: {
      functionName: 'NativeModule',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 148,
      columnNumber: 21
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 5,
    callFrame: {
      functionName: '',
      scriptId: '8',
      url: 'internal/bootstrap/node.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [
       6,  9, 10, 13,
      16, 21, 25
    ]
  },
  {
    id: 6,
    callFrame: {
      functionName: 'setupPrepareStackTrace',
      scriptId: '8',
      url: 'internal/bootstrap/node.js',
      lineNumber: 301,
      columnNumber: 31
    },
    hitCount: 0,
    children: [ 7 ]
  },
  {
    id: 7,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 8 ]
  },
  {
    id: 8,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 9,
    callFrame: {
      functionName: 'internalBinding',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 127,
      columnNumber: 44
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 10,
    callFrame: {
      functionName: 'setupProcessObject',
      scriptId: '8',
      url: 'internal/bootstrap/node.js',
      lineNumber: 320,
      columnNumber: 27
    },
    hitCount: 0,
    children: [ 11 ]
  },
  {
    id: 11,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 12 ]
  },
  {
    id: 12,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 13,
    callFrame: {
      functionName: 'setupGlobalProxy',
      scriptId: '8',
      url: 'internal/bootstrap/node.js',
      lineNumber: 365,
      columnNumber: 25
    },
    hitCount: 0,
    children: [ 14 ]
  },
  {
    id: 14,
    callFrame: {
      functionName: 'makeGetter',
      scriptId: '8',
      url: 'internal/bootstrap/node.js',
      lineNumber: 373,
      columnNumber: 21
    },
    hitCount: 0,
    children: [ 15 ]
  },
  {
    id: 15,
    callFrame: {
      functionName: 'deprecate',
      scriptId: '10',
      url: 'internal/util.js',
      lineNumber: 42,
      columnNumber: 18
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 16,
    callFrame: {
      functionName: 'setupBuffer',
      scriptId: '8',
      url: 'internal/bootstrap/node.js',
      lineNumber: 404,
      columnNumber: 20
    },
    hitCount: 0,
    children: [ 17 ]
  },
  {
    id: 17,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 18 ]
  },
  {
    id: 18,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 0,
    children: [ 19 ]
  },
  {
    id: 19,
    callFrame: {
      functionName: '',
      scriptId: '15',
      url: 'buffer.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 20 ]
  },
  {
    id: 20,
    callFrame: {
      functionName: 'internalBinding',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 127,
      columnNumber: 44
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 21,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 22 ]
  },
  {
    id: 22,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 0,
    children: [ 23, 30, 34 ]
  },
  {
    id: 23,
    callFrame: {
      functionName: '',
      scriptId: '21',
      url: 'internal/async_hooks.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 24 ]
  },
  {
    id: 24,
    callFrame: {
      functionName: 'internalBinding',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 127,
      columnNumber: 44
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 30,
    callFrame: {
      functionName: '',
      scriptId: '28',
      url: 'internal/url.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 31 ]
  },
  {
    id: 31,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 32 ]
  },
  {
    id: 32,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 0,
    children: [ 33 ]
  },
  {
    id: 33,
    callFrame: {
      functionName: '',
      scriptId: '31',
      url: 'path.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 34,
    callFrame: {
      functionName: '',
      scriptId: '32',
      url: 'internal/encoding.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 25,
    callFrame: {
      functionName: 'createGlobalConsole',
      scriptId: '8',
      url: 'internal/bootstrap/node.js',
      lineNumber: 421,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 26 ]
  },
  {
    id: 26,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 27 ]
  },
  {
    id: 27,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 0,
    children: [ 28 ]
  },
  {
    id: 28,
    callFrame: {
      functionName: '',
      scriptId: '25',
      url: 'internal/console/global.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 29 ]
  },
  {
    id: 29,
    callFrame: {
      functionName: 'Console.<computed>',
      scriptId: '26',
      url: 'internal/console/constructor.js',
      lineNumber: 165,
      columnNumber: 45
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 35,
    callFrame: {
      functionName: '',
      scriptId: '40',
      url: 'internal/main/run_main_module.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 36, 45 ]
  },
  {
    id: 36,
    callFrame: {
      functionName: 'prepareMainThreadExecution',
      scriptId: '41',
      url: 'internal/bootstrap/pre_execution.js',
      lineNumber: 8,
      columnNumber: 35
    },
    hitCount: 0,
    children: [ 37 ]
  },
  {
    id: 37,
    callFrame: {
      functionName: 'initializeCJSLoader',
      scriptId: '41',
      url: 'internal/bootstrap/pre_execution.js',
      lineNumber: 366,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 38 ]
  },
  {
    id: 38,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 39 ]
  },
  {
    id: 39,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 0,
    children: [ 40 ]
  },
  {
    id: 40,
    callFrame: {
      functionName: '',
      scriptId: '44',
      url: 'internal/modules/cjs/loader.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 41 ]
  },
  {
    id: 41,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 42 ]
  },
  {
    id: 42,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 0,
    children: [ 43 ]
  },
  {
    id: 43,
    callFrame: {
      functionName: '',
      scriptId: '45',
      url: 'vm.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 44 ]
  },
  {
    id: 44,
    callFrame: {
      functionName: 'internalBinding',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 127,
      columnNumber: 44
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 45,
    callFrame: {
      functionName: 'Module.runMain',
      scriptId: '44',
      url: 'internal/modules/cjs/loader.js',
      lineNumber: 984,
      columnNumber: 25
    },
    hitCount: 0,
    children: [ 46 ]
  },
  {
    id: 46,
    callFrame: {
      functionName: 'Module._load',
      scriptId: '44',
      url: 'internal/modules/cjs/loader.js',
      lineNumber: 656,
      columnNumber: 23
    },
    hitCount: 0,
    children: [ 47 ]
  },
  {
    id: 47,
    callFrame: {
      functionName: 'Module.load',
      scriptId: '44',
      url: 'internal/modules/cjs/loader.js',
      lineNumber: 780,
      columnNumber: 32
    },
    hitCount: 0,
    children: [ 48, 49 ]
  },
  {
    id: 48,
    callFrame: {
      functionName: 'findLongestRegisteredExtension',
      scriptId: '44',
      url: 'internal/modules/cjs/loader.js',
      lineNumber: 345,
      columnNumber: 39
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 49,
    callFrame: {
      functionName: 'Module._extensions..js',
      scriptId: '44',
      url: 'internal/modules/cjs/loader.js',
      lineNumber: 944,
      columnNumber: 36
    },
    hitCount: 0,
    children: [ 50 ]
  },
  {
    id: 50,
    callFrame: {
      functionName: 'Module._compile',
      scriptId: '44',
      url: 'internal/modules/cjs/loader.js',
      lineNumber: 896,
      columnNumber: 36
    },
    hitCount: 0,
    children: [ 51 ]
  },
  {
    id: 51,
    callFrame: {
      functionName: '',
      scriptId: '51',
      url: 'file:///data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/test/fixtures/workload/fibonacci-worker.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 52 ]
  },
  {
    id: 52,
    callFrame: {
      functionName: 'Worker',
      scriptId: '53',
      url: 'internal/worker.js',
      lineNumber: 67,
      columnNumber: 13
    },
    hitCount: 0,
    children: [ 53 ]
  },
  {
    id: 53,
    callFrame: {
      functionName: 'pathToFileURL',
      scriptId: '28',
      url: 'internal/url.js',
      lineNumber: 1360,
      columnNumber: 22
    },
    hitCount: 0,
    children: [ 54 ]
  },
  {
    id: 54,
    callFrame: {
      functionName: 'URL',
      scriptId: '28',
      url: 'internal/url.js',
      lineNumber: 310,
      columnNumber: 13
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 55,
    callFrame: {
      functionName: '(garbage collector)',
      scriptId: '0',
      url: '',
      lineNumber: -1,
      columnNumber: -1
    },
    hitCount: 2
  },
  {
    id: 56,
    callFrame: {
      functionName: 'Worker.<computed>.onexit',
      scriptId: '53',
      url: 'internal/worker.js',
      lineNumber: 115,
      columnNumber: 27
    },
    hitCount: 0,
    children: [ 57 ]
  },
  {
    id: 57,
    callFrame: {
      functionName: '',
      scriptId: '53',
      url: 'internal/worker.js',
      lineNumber: 159,
      columnNumber: 11
    },
    hitCount: 0,
    children: [ 58 ]
  },
  {
    id: 58,
    callFrame: {
      functionName: 'removeAllListeners',
      scriptId: '11',
      url: 'events.js',
      lineNumber: 381,
      columnNumber: 31
    },
    hitCount: 0,
    children: [ 59 ]
  },
  {
    id: 59,
    callFrame: {
      functionName: 'removeAllListeners',
      scriptId: '11',
      url: 'events.js',
      lineNumber: 381,
      columnNumber: 31
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  }
]
CPU path:  /data/iojs/node-tmp/.tmp.2539/prof/CPU.20190814.062019.42611.1.002.cpuprofile
[
  {
    id: 1,
    callFrame: {
      functionName: '(root)',
      scriptId: '0',
      url: '',
      lineNumber: -1,
      columnNumber: -1
    },
    hitCount: 0,
    children: [ 2, 3, 25 ]
  },
  {
    id: 2,
    callFrame: {
      functionName: '(program)',
      scriptId: '0',
      url: '',
      lineNumber: -1,
      columnNumber: -1
    },
    hitCount: 0
  },
  {
    id: 3,
    callFrame: {
      functionName: '',
      scriptId: '8',
      url: 'internal/bootstrap/node.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 4, 10, 13, 16, 18, 19 ]
  },
  {
    id: 4,
    callFrame: {
      functionName: 'setupPrepareStackTrace',
      scriptId: '8',
      url: 'internal/bootstrap/node.js',
      lineNumber: 301,
      columnNumber: 31
    },
    hitCount: 0,
    children: [ 5 ]
  },
  {
    id: 5,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 6 ]
  },
  {
    id: 6,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 1,
    children: [ 7 ],
    positionTicks: [ [Object] ]
  },
  {
    id: 7,
    callFrame: {
      functionName: '',
      scriptId: '9',
      url: 'internal/errors.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 8 ]
  },
  {
    id: 8,
    callFrame: {
      functionName: 'E',
      scriptId: '9',
      url: 'internal/errors.js',
      lineNumber: 275,
      columnNumber: 10
    },
    hitCount: 0,
    children: [ 9 ]
  },
  {
    id: 9,
    callFrame: {
      functionName: 'makeNodeErrorWithCode',
      scriptId: '9',
      url: 'internal/errors.js',
      lineNumber: 189,
      columnNumber: 30
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 10,
    callFrame: {
      functionName: 'setupProcessObject',
      scriptId: '8',
      url: 'internal/bootstrap/node.js',
      lineNumber: 320,
      columnNumber: 27
    },
    hitCount: 0,
    children: [ 11 ]
  },
  {
    id: 11,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 12 ]
  },
  {
    id: 12,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 13,
    callFrame: {
      functionName: 'setupBuffer',
      scriptId: '8',
      url: 'internal/bootstrap/node.js',
      lineNumber: 404,
      columnNumber: 20
    },
    hitCount: 0,
    children: [ 14 ]
  },
  {
    id: 14,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 15 ]
  },
  {
    id: 15,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 16,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 17 ]
  },
  {
    id: 17,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 1,
    children: [ 26, 29 ],
    positionTicks: [ [Object] ]
  },
  {
    id: 26,
    callFrame: {
      functionName: '',
      scriptId: '41',
      url: 'internal/url.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 27 ]
  },
  {
    id: 27,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 28 ]
  },
  {
    id: 28,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 29,
    callFrame: {
      functionName: '',
      scriptId: '45',
      url: 'internal/encoding.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 18,
    callFrame: {
      functionName: 'wrapProcessMethods',
      scriptId: '18',
      url: 'internal/process/per_thread.js',
      lineNumber: 32,
      columnNumber: 27
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 19,
    callFrame: {
      functionName: 'createGlobalConsole',
      scriptId: '8',
      url: 'internal/bootstrap/node.js',
      lineNumber: 421,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 20 ]
  },
  {
    id: 20,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 21 ]
  },
  {
    id: 21,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 0,
    children: [ 22 ]
  },
  {
    id: 22,
    callFrame: {
      functionName: '',
      scriptId: '38',
      url: 'internal/console/global.js',
      lineNumber: 0,
      columnNumber: 0
    },
    hitCount: 0,
    children: [ 23 ]
  },
  {
    id: 23,
    callFrame: {
      functionName: 'nativeModuleRequire',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 182,
      columnNumber: 28
    },
    hitCount: 0,
    children: [ 24 ]
  },
  {
    id: 24,
    callFrame: {
      functionName: 'NativeModule.compile',
      scriptId: '7',
      url: 'internal/bootstrap/loaders.js',
      lineNumber: 286,
      columnNumber: 41
    },
    hitCount: 1,
    positionTicks: [ [Object] ]
  },
  {
    id: 25,
    callFrame: {
      functionName: '(garbage collector)',
      scriptId: '0',
      url: '',
      lineNumber: -1,
      columnNumber: -1
    },
    hitCount: 1
  }
]
assert.js:373
    throw err;
    ^

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

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

    at Object.<anonymous> (/data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/test/sequential/test-cpu-prof-dir-worker.js:54:3)
    at Module._compile (internal/modules/cjs/loader.js:936:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:947:10)
    at Module.load (internal/modules/cjs/loader.js:789:32)
    at Function.Module._load (internal/modules/cjs/loader.js:702:12)
    at Function.Module.runMain (internal/modules/cjs/loader.js:999:10)
    at internal/main/run_main_module.js:17:11 {
  generatedMessage: true,
  code: 'ERR_ASSERTION',
  actual: false,
  expected: true,
  operator: '=='
}

@sam-github
Copy link
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: '=='
}

sam-github added a commit to sam-github/node that referenced this issue Apr 14, 2020
Trott pushed a commit that referenced this issue Apr 15, 2020
Refs: #27611 (comment)

PR-URL: #32828
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Myles Borins <myles.borins@gmail.com>
Reviewed-By: Rich Trott <rtrott@gmail.com>
MylesBorins pushed a commit that referenced this issue Apr 17, 2020
Refs: #27611 (comment)

PR-URL: #32828
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Myles Borins <myles.borins@gmail.com>
Reviewed-By: Rich Trott <rtrott@gmail.com>
targos pushed a commit to targos/node that referenced this issue Apr 25, 2020
Refs: nodejs#27611 (comment)

PR-URL: nodejs#32828
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Myles Borins <myles.borins@gmail.com>
Reviewed-By: Rich Trott <rtrott@gmail.com>
BridgeAR pushed a commit that referenced this issue Apr 28, 2020
Refs: #27611 (comment)

PR-URL: #32828
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Myles Borins <myles.borins@gmail.com>
Reviewed-By: Rich Trott <rtrott@gmail.com>
targos pushed a commit that referenced this issue Apr 28, 2020
Refs: #27611 (comment)

PR-URL: #32828
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Myles Borins <myles.borins@gmail.com>
Reviewed-By: Rich Trott <rtrott@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI.
Projects
None yet
Development

No branches or pull requests

5 participants