1'use strict'; 2 3const common = require('../common'); 4const { performance } = require('perf_hooks'); 5// Get the start time as soon as possible. 6const testStartTime = performance.now(); 7const assert = require('assert'); 8const { writeSync } = require('fs'); 9 10// Use writeSync to stdout to avoid disturbing the loop. 11function log(str) { 12 writeSync(1, str + '\n'); 13} 14 15assert(performance); 16assert(performance.nodeTiming); 17assert.strictEqual(typeof performance.timeOrigin, 'number'); 18 19assert(testStartTime > 0, `${testStartTime} <= 0`); 20// Use a fairly large epsilon value, since we can only guarantee that the node 21// process started up in 15 seconds. 22assert(testStartTime < 15000, `${testStartTime} >= 15000`); 23 24// Use different ways to calculate process uptime to check that 25// performance.timeOrigin and performance.now() are in reasonable range. 26const epsilon = 50; 27{ 28 const uptime1 = Date.now() - performance.timeOrigin; 29 const uptime2 = performance.now(); 30 const uptime3 = process.uptime() * 1000; 31 assert(Math.abs(uptime1 - uptime2) < epsilon, 32 `Date.now() - performance.timeOrigin (${uptime1}) - ` + 33 `performance.now() (${uptime2}) = ` + 34 `${uptime1 - uptime2} >= +- ${epsilon}`); 35 assert(Math.abs(uptime1 - uptime3) < epsilon, 36 `Date.now() - performance.timeOrigin (${uptime1}) - ` + 37 `process.uptime() * 1000 (${uptime3}) = ` + 38 `${uptime1 - uptime3} >= +- ${epsilon}`); 39} 40 41assert.strictEqual(performance.nodeTiming.name, 'node'); 42assert.strictEqual(performance.nodeTiming.entryType, 'node'); 43 44// Copy all the values from the getters. 45const initialTiming = { ...performance.nodeTiming }; 46 47{ 48 const { 49 startTime, 50 nodeStart, 51 v8Start, 52 environment, 53 bootstrapComplete, 54 } = initialTiming; 55 56 assert.strictEqual(startTime, 0); 57 assert.strictEqual(typeof nodeStart, 'number'); 58 assert(nodeStart > 0, `nodeStart ${nodeStart} <= 0`); 59 // The whole process starts before this test starts. 60 assert(nodeStart < testStartTime, 61 `nodeStart ${nodeStart} >= ${testStartTime}`); 62 63 assert.strictEqual(typeof v8Start, 'number'); 64 assert(v8Start > 0, `v8Start ${v8Start} <= 0`); 65 // V8 starts after the process starts. 66 assert(v8Start > nodeStart, `v8Start ${v8Start} <= ${nodeStart}`); 67 // V8 starts before this test starts. 68 assert(v8Start < testStartTime, 69 `v8Start ${v8Start} >= ${testStartTime}`); 70 71 assert.strictEqual(typeof environment, 'number'); 72 assert(environment > 0, `environment ${environment} <= 0`); 73 // Environment starts after V8 starts. 74 assert(environment > v8Start, 75 `environment ${environment} <= ${v8Start}`); 76 // Environment starts before this test starts. 77 assert(environment < testStartTime, 78 `environment ${environment} >= ${testStartTime}`); 79 80 assert.strictEqual(typeof bootstrapComplete, 'number'); 81 assert(bootstrapComplete > 0, `bootstrapComplete ${bootstrapComplete} <= 0`); 82 // Bootstrap completes after environment starts. 83 assert(bootstrapComplete > environment, 84 `bootstrapComplete ${bootstrapComplete} <= ${environment}`); 85 // Bootstrap completes before this test starts. 86 assert(bootstrapComplete < testStartTime, 87 `bootstrapComplete ${bootstrapComplete} >= ${testStartTime}`); 88} 89 90function checkNodeTiming(timing) { 91 // Calculate the difference between now() and duration as soon as possible. 92 const now = performance.now(); 93 const delta = Math.abs(now - timing.duration); 94 95 log(JSON.stringify(timing, null, 2)); 96 // Check that the properties are still reasonable. 97 assert.strictEqual(timing.name, 'node'); 98 assert.strictEqual(timing.entryType, 'node'); 99 100 // Check that duration is positive and practically the same as 101 // performance.now() i.e. measures Node.js instance up time. 102 assert.strictEqual(typeof timing.duration, 'number'); 103 assert(timing.duration > 0, `timing.duration ${timing.duration} <= 0`); 104 assert(delta < 10, 105 `now (${now}) - timing.duration (${timing.duration}) = ${delta} >= 10`); 106 107 // Check that the following fields do not change. 108 assert.strictEqual(timing.startTime, initialTiming.startTime); 109 assert.strictEqual(timing.nodeStart, initialTiming.nodeStart); 110 assert.strictEqual(timing.v8Start, initialTiming.v8Start); 111 assert.strictEqual(timing.environment, initialTiming.environment); 112 assert.strictEqual(timing.bootstrapComplete, initialTiming.bootstrapComplete); 113 114 assert.strictEqual(typeof timing.loopStart, 'number'); 115 assert.strictEqual(typeof timing.loopExit, 'number'); 116} 117 118log('check initial nodeTiming'); 119checkNodeTiming(initialTiming); 120assert.strictEqual(initialTiming.loopExit, -1); 121 122function checkValue(timing, name, min, max) { 123 const value = timing[name]; 124 assert(value > 0, `${name} ${value} <= 0`); 125 // Loop starts after bootstrap completes. 126 assert(value > min, 127 `${name} ${value} <= ${min}`); 128 assert(value < max, `${name} ${value} >= ${max}`); 129} 130 131let loopStart = initialTiming.loopStart; 132if (common.isMainThread) { 133 // In the main thread, the loop does not start until we start an operation 134 // that requires it, e.g. setTimeout(). 135 assert.strictEqual(initialTiming.loopStart, -1); 136 log('Start timer'); 137 setTimeout(() => { 138 log('Check nodeTiming in timer'); 139 const timing = { ...performance.nodeTiming }; 140 checkNodeTiming(timing); 141 // Loop should start after we fire the timeout, and before we call 142 // performance.now() here. 143 loopStart = timing.loopStart; 144 checkValue(timing, 'loopStart', initialTiming.duration, performance.now()); 145 }, 1000); 146} else { 147 // In the worker, the loop always starts before the user code is evaluated, 148 // and after bootstrap completes. 149 checkValue(initialTiming, 150 'loopStart', 151 initialTiming.bootstrapComplete, 152 testStartTime); 153} 154 155process.on('exit', () => { 156 log('Check nodeTiming in process exit event'); 157 const timing = { ...performance.nodeTiming }; 158 checkNodeTiming(timing); 159 // Check that loopStart does not change. 160 assert.strictEqual(timing.loopStart, loopStart); 161 checkValue(timing, 162 'loopExit', 163 loopStart, 164 performance.now()); 165}); 166