diff --git a/lib/internal/console/constructor.js b/lib/internal/console/constructor.js index a618457124c877..554323d9e30c1d 100644 --- a/lib/internal/console/constructor.js +++ b/lib/internal/console/constructor.js @@ -32,6 +32,10 @@ const kTraceBegin = 'b'.charCodeAt(0); const kTraceEnd = 'e'.charCodeAt(0); const kTraceInstant = 'n'.charCodeAt(0); +const kSecond = 1000; +const kMinute = 60 * kSecond; +const kHour = 60 * kMinute; + const { isArray: ArrayIsArray, from: ArrayFrom, @@ -518,14 +522,35 @@ function timeLogImpl(self, name, label, data) { } const duration = process.hrtime(time); const ms = duration[0] * 1000 + duration[1] / 1e6; + + const formatted = formatTime(ms); + if (data === undefined) { - self.log('%s: %sms', label, ms.toFixed(3)); + self.log('%s: %s', label, formatted); } else { - self.log('%s: %sms', label, ms.toFixed(3), ...data); + self.log('%s: %s', label, formatted, ...data); } return true; } +function formatTime(ms) { + let value = ms; + let unit = 'ms'; + + if (ms >= kHour) { + value = ms / kHour; + unit = 'h'; + } else if (ms >= kMinute) { + value = ms / kMinute; + unit = 'min'; + } else if (ms >= kSecond) { + value = ms / kSecond; + unit = 's'; + } + + return value.toFixed(3) + unit; +} + const keyKey = 'Key'; const valuesKey = 'Values'; const indexKey = '(index)'; @@ -547,5 +572,6 @@ Console.prototype.groupCollapsed = Console.prototype.group; module.exports = { Console, kBindStreamsLazy, - kBindProperties + kBindProperties, + formatTime // exported for tests }; diff --git a/test/parallel/test-console-formatTime.js b/test/parallel/test-console-formatTime.js new file mode 100644 index 00000000000000..aa5f7ec7aa4bf2 --- /dev/null +++ b/test/parallel/test-console-formatTime.js @@ -0,0 +1,15 @@ +'use strict'; +// Flags: --expose-internals +require('../common'); +const { formatTime } = require('internal/console/constructor'); +const assert = require('assert'); + +const test1 = formatTime(100); +const test2 = formatTime(1500); +const test3 = formatTime(60300); +const test4 = formatTime(4000000); + +assert.strictEqual(test1, '100.000ms'); +assert.strictEqual(test2, '1.500s'); +assert.strictEqual(test3, '1.005min'); +assert.strictEqual(test4, '1.111h'); diff --git a/test/parallel/test-console.js b/test/parallel/test-console.js index e2c5291d915c1d..1d76c42edc082e 100644 --- a/test/parallel/test-console.js +++ b/test/parallel/test-console.js @@ -246,24 +246,24 @@ assert.ok(strings[0].includes('foo: { bar: { baz:')); assert.ok(strings[0].includes('quux')); assert.ok(strings.shift().includes('quux: true')); -assert.ok(/^label: \d+\.\d{3}ms$/.test(strings.shift().trim())); -assert.ok(/^__proto__: \d+\.\d{3}ms$/.test(strings.shift().trim())); -assert.ok(/^constructor: \d+\.\d{3}ms$/.test(strings.shift().trim())); -assert.ok(/^hasOwnProperty: \d+\.\d{3}ms$/.test(strings.shift().trim())); +assert.ok(/^label: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); +assert.ok(/^__proto__: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); +assert.ok(/^constructor: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); +assert.ok(/^hasOwnProperty: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); // Verify that console.time() coerces label values to strings as expected -assert.ok(/^: \d+\.\d{3}ms$/.test(strings.shift().trim())); -assert.ok(/^\[object Object\]: \d+\.\d{3}ms$/.test(strings.shift().trim())); -assert.ok(/^\[object Object\]: \d+\.\d{3}ms$/.test(strings.shift().trim())); -assert.ok(/^null: \d+\.\d{3}ms$/.test(strings.shift().trim())); -assert.ok(/^default: \d+\.\d{3}ms$/.test(strings.shift().trim())); -assert.ok(/^default: \d+\.\d{3}ms$/.test(strings.shift().trim())); -assert.ok(/^NaN: \d+\.\d{3}ms$/.test(strings.shift().trim())); - -assert.ok(/^log1: \d+\.\d{3}ms$/.test(strings.shift().trim())); -assert.ok(/^log1: \d+\.\d{3}ms test$/.test(strings.shift().trim())); -assert.ok(/^log1: \d+\.\d{3}ms {} \[ 1, 2, 3 ]$/.test(strings.shift().trim())); -assert.ok(/^log1: \d+\.\d{3}ms$/.test(strings.shift().trim())); +assert.ok(/^: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); +assert.ok(/^\[object Object\]: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); +assert.ok(/^\[object Object\]: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); +assert.ok(/^null: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); +assert.ok(/^default: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); +assert.ok(/^default: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); +assert.ok(/^NaN: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); + +assert.ok(/^log1: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); +assert.ok(/^log1: \d+\.\d{3}(ms|s|min|h) test$/.test(strings.shift().trim())); +assert.ok(/^log1: \d+\.\d{3}(ms|s|min|h) {} \[ 1, 2, 3 ]$/.test(strings.shift().trim())); +assert.ok(/^log1: \d+\.\d{3}(ms|s|min|h)$/.test(strings.shift().trim())); // Make sure that we checked all strings assert.strictEqual(strings.length, 0);