diff options
author | Xavier Stouder <xavier@stouder.io> | 2019-08-21 18:31:06 +0200 |
---|---|---|
committer | Anna Henningsen <anna@addaleax.net> | 2019-08-25 16:39:18 +0200 |
commit | 66043e18128dc80457f4e184b7ed7faedcd93ca7 (patch) | |
tree | 029a1f6b0529321de21c6422c830e1ce8a5ef5e4 | |
parent | b3172f834f418f4f2656d851e585f17aece73333 (diff) | |
download | node-new-66043e18128dc80457f4e184b7ed7faedcd93ca7.tar.gz |
console: display timeEnd with suitable time unit
When timeEnd function is called, display result with a suitable
time unit instead of a big amount of milliseconds.
Refs: https://github.com/nodejs/node/issues/29099
PR-URL: https://github.com/nodejs/node/pull/29251
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Michaƫl Zasso <targos@protonmail.com>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
-rw-r--r-- | lib/internal/console/constructor.js | 32 | ||||
-rw-r--r-- | test/parallel/test-console-formatTime.js | 15 | ||||
-rw-r--r-- | test/parallel/test-console.js | 32 |
3 files changed, 60 insertions, 19 deletions
diff --git a/lib/internal/console/constructor.js b/lib/internal/console/constructor.js index a618457124..554323d9e3 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 0000000000..aa5f7ec7aa --- /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 e2c5291d91..1d76c42edc 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); |