From 1dcb3d1a4ee358ca718a0e0e1d0de50cae100cab Mon Sep 17 00:00:00 2001 From: Ruben Bridgewater Date: Wed, 4 Sep 2019 20:08:56 +0200 Subject: [PATCH 1/3] console: update time formatting This improves the readability of the `console.timeEnd()` output while keeping a higher output's precision in multiple cases. Instead of e.g. '1.005min' it will print '1m and 300ms'. --- lib/internal/console/constructor.js | 47 ++++++++++++++++++------ test/parallel/test-console-formatTime.js | 16 ++++---- 2 files changed, 42 insertions(+), 21 deletions(-) diff --git a/lib/internal/console/constructor.js b/lib/internal/console/constructor.js index 554323d9e30c1d..2c0ba4b2fb8d38 100644 --- a/lib/internal/console/constructor.js +++ b/lib/internal/console/constructor.js @@ -3,7 +3,7 @@ // The Console constructor is not actually used to construct the global // console. It's exported for backwards compatibility. -const { Object, ObjectPrototype, Reflect } = primordials; +const { Object, ObjectPrototype, Reflect, Math } = primordials; const { trace } = internalBinding('trace_events'); const { @@ -534,21 +534,44 @@ function timeLogImpl(self, name, label, data) { } function formatTime(ms) { - let value = ms; - let unit = 'ms'; + let end = 3; + const values = []; 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'; + end = -1; + values.push(`${Math.floor(ms / kHour)}h`); + ms = Math.floor(ms % kHour); + } + if (ms >= kMinute) { + if (end === 3) { + end = 0; + } + values.push(`${Math.floor(ms / kMinute)}min`); + ms = ms % kMinute; + } + if (ms >= kSecond) { + if (end === -1) { + values.push(`${String(Number((ms / kSecond).toFixed(1)))}s`); + } else { + values.push(`${Math.floor(ms / kSecond)}s`); + if (end === 3) { + end = 1; + } + } + ms = ms % kSecond; + } + if (end !== -1) { + values.push(`${String(Number(ms.toFixed(end)))}ms`); } - return value.toFixed(3) + unit; + let res = values.pop(); + if (values.length) { + res = `${values.pop()} and ${res}`; + } + while (values.length !== 0) { + res = `${values.pop()}, ${res}`; + } + return res; } const keyKey = 'Key'; diff --git a/test/parallel/test-console-formatTime.js b/test/parallel/test-console-formatTime.js index aa5f7ec7aa4bf2..530ed6f785e5f3 100644 --- a/test/parallel/test-console-formatTime.js +++ b/test/parallel/test-console-formatTime.js @@ -4,12 +4,10 @@ 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'); +assert.strictEqual(formatTime(100.0096), '100.01ms'); +assert.strictEqual(formatTime(100.0115), '100.011ms'); +assert.strictEqual(formatTime(1500.04), '1s and 500ms'); +assert.strictEqual(formatTime(1500.056), '1s and 500.1ms'); +assert.strictEqual(formatTime(60300.3), '1min and 300ms'); +assert.strictEqual(formatTime(4000457.4), '1h, 6min and 40.5s'); +assert.strictEqual(formatTime(3601017.4), '1h and 1s'); From 1c5e1b14ad1307767c52bcedb11eda84518c324d Mon Sep 17 00:00:00 2001 From: Ruben Bridgewater Date: Mon, 23 Sep 2019 21:59:39 +0200 Subject: [PATCH 2/3] fixup: reformat for easier comparison --- lib/internal/console/constructor.js | 53 ++++++++++-------------- test/parallel/test-console-formatTime.js | 11 ++--- 2 files changed, 29 insertions(+), 35 deletions(-) diff --git a/lib/internal/console/constructor.js b/lib/internal/console/constructor.js index 2c0ba4b2fb8d38..c3339241aa7741 100644 --- a/lib/internal/console/constructor.js +++ b/lib/internal/console/constructor.js @@ -533,45 +533,38 @@ function timeLogImpl(self, name, label, data) { return true; } +function pad(value) { + return `${value}`.padStart(2, '0'); +} + function formatTime(ms) { - let end = 3; - const values = []; + let hours = 0; + let minutes = 0; + let seconds = 0; - if (ms >= kHour) { - end = -1; - values.push(`${Math.floor(ms / kHour)}h`); - ms = Math.floor(ms % kHour); - } - if (ms >= kMinute) { - if (end === 3) { - end = 0; - } - values.push(`${Math.floor(ms / kMinute)}min`); - ms = ms % kMinute; - } if (ms >= kSecond) { - if (end === -1) { - values.push(`${String(Number((ms / kSecond).toFixed(1)))}s`); - } else { - values.push(`${Math.floor(ms / kSecond)}s`); - if (end === 3) { - end = 1; + if (ms >= kMinute) { + if (ms >= kHour) { + hours = Math.floor(ms / kHour); + ms = ms % kHour; } + minutes = Math.floor(ms / kMinute); + ms = ms % kMinute; } - ms = ms % kSecond; - } - if (end !== -1) { - values.push(`${String(Number(ms.toFixed(end)))}ms`); + seconds = ms / kSecond; } - let res = values.pop(); - if (values.length) { - res = `${values.pop()} and ${res}`; + if (hours !== 0 || minutes !== 0) { + [seconds, ms] = seconds.toFixed(3).split('.'); + const res = hours !== 0 ? `${hours}:${pad(minutes)}` : minutes; + return `${res}:${pad(seconds)}.${ms} (${hours !== 0 ? 'h:m' : ''}m:ss.mmm)`; } - while (values.length !== 0) { - res = `${values.pop()}, ${res}`; + + if (seconds !== 0) { + return `${seconds.toFixed(3)}s`; } - return res; + + return `${Number(ms.toFixed(3))}ms`; } const keyKey = 'Key'; diff --git a/test/parallel/test-console-formatTime.js b/test/parallel/test-console-formatTime.js index 530ed6f785e5f3..0420013c50e77c 100644 --- a/test/parallel/test-console-formatTime.js +++ b/test/parallel/test-console-formatTime.js @@ -6,8 +6,9 @@ const assert = require('assert'); assert.strictEqual(formatTime(100.0096), '100.01ms'); assert.strictEqual(formatTime(100.0115), '100.011ms'); -assert.strictEqual(formatTime(1500.04), '1s and 500ms'); -assert.strictEqual(formatTime(1500.056), '1s and 500.1ms'); -assert.strictEqual(formatTime(60300.3), '1min and 300ms'); -assert.strictEqual(formatTime(4000457.4), '1h, 6min and 40.5s'); -assert.strictEqual(formatTime(3601017.4), '1h and 1s'); +assert.strictEqual(formatTime(1500.04), '1.500s'); +assert.strictEqual(formatTime(1000.056), '1.000s'); +assert.strictEqual(formatTime(60300.3), '1:00.300 (m:ss.mmm)'); +assert.strictEqual(formatTime(4000457.4), '1:06:40.457 (h:mm:ss.mmm)'); +assert.strictEqual(formatTime(3601310.4), '1:00:01.310 (h:mm:ss.mmm)'); +assert.strictEqual(formatTime(3213601017.6), '892:40:01.018 (h:mm:ss.mmm)'); From 7f9d5e764baaec14a1dae802115fef9cac56d53c Mon Sep 17 00:00:00 2001 From: Ruben Bridgewater Date: Mon, 23 Sep 2019 22:30:47 +0200 Subject: [PATCH 3/3] fixup: fix tests --- test/parallel/test-console.js | 32 ++++++++++++++++---------------- 1 file changed, 16 insertions(+), 16 deletions(-) diff --git a/test/parallel/test-console.js b/test/parallel/test-console.js index 1d76c42edc082e..e5e80ee61b2777 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|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())); +assert.ok(/^label: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); +assert.ok(/^__proto__: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); +assert.ok(/^constructor: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); +assert.ok(/^hasOwnProperty: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); // Verify that console.time() coerces label values to strings as expected -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())); +assert.ok(/^: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); +assert.ok(/^\[object Object\]: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); +assert.ok(/^\[object Object\]: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); +assert.ok(/^null: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); +assert.ok(/^default: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); +assert.ok(/^default: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); +assert.ok(/^NaN: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); + +assert.ok(/^log1: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); +assert.ok(/^log1: \d+(\.\d{1,3})?(ms|s) test$/.test(strings.shift().trim())); +assert.ok(/^log1: \d+(\.\d{1,3})?(ms|s) {} \[ 1, 2, 3 ]$/.test(strings.shift().trim())); +assert.ok(/^log1: \d+(\.\d{1,3})?(ms|s)$/.test(strings.shift().trim())); // Make sure that we checked all strings assert.strictEqual(strings.length, 0);