From 3487f83dc5b64b7cc805ca7221232786110fb83d Mon Sep 17 00:00:00 2001 From: eliasm307 <13420359+eliasm307@users.noreply.github.com> Date: Thu, 18 Nov 2021 20:02:54 +0000 Subject: [PATCH] Update src/flow-control/log-timings.js Co-authored-by: Gustavo Henke --- bin/concurrently.js | 8 +++---- bin/concurrently.spec.js | 15 +++++++------- index.js | 5 +++-- src/completion-listener.js | 3 +-- src/concurrently.js | 7 +++---- src/defaults.js | 2 +- src/flow-control/log-timings.js | 23 ++++++++++++++------- src/flow-control/log-timings.spec.js | 31 ++++++++++++++-------------- 8 files changed, 51 insertions(+), 43 deletions(-) diff --git a/bin/concurrently.js b/bin/concurrently.js index ed4750db..82b3030e 100755 --- a/bin/concurrently.js +++ b/bin/concurrently.js @@ -62,10 +62,10 @@ const args = yargs default: defaults.hide, type: 'string' }, - 'show-timings': { + 'timings': { describe: 'Show timing information for all processes', type: 'boolean', - default: defaults.showTimings + default: defaults.timings }, // Kill others @@ -147,7 +147,7 @@ const args = yargs 'Can be either the index or the name of the process.' } }) - .group(['m', 'n', 'name-separator', 'raw', 's', 'no-color', 'hide', 'show-timings'], 'General') + .group(['m', 'n', 'name-separator', 'raw', 's', 'no-color', 'hide', 'timings'], 'General') .group(['p', 'c', 'l', 't'], 'Prefix styling') .group(['i', 'default-input-target'], 'Input handling') .group(['k', 'kill-others-on-fail'], 'Killing other processes') @@ -177,7 +177,7 @@ concurrently(args._.map((command, index) => ({ restartTries: args.restartTries, successCondition: args.success, timestampFormat: args.timestampFormat, - showTimings: args.showTimings + timings: args.timings }).then( () => process.exit(0), () => process.exit(1) diff --git a/bin/concurrently.spec.js b/bin/concurrently.spec.js index e975e214..8fb9d18f 100644 --- a/bin/concurrently.spec.js +++ b/bin/concurrently.spec.js @@ -383,14 +383,13 @@ describe('--handle-input', () => { }); }); -describe('--show-timings', () => { - const dateRegex = '\\d+\/\\d+\/\\d+'; - const timeRegex = '\\d+:\\d+:\\d+(AM|PM|\\s)*'; +describe('--timings', () => { + const defaultTimestampFormatRegex = /\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}/; const processStartedMessageRegex = (index, command) => { - return new RegExp( `^\\[${ index }] ${ command } started at ${ dateRegex }, ${ timeRegex }$` ); + return new RegExp( `^\\[${ index }] ${ command } started at ${ defaultTimestampFormatRegex.source }$` ); }; const processStoppedMessageRegex = (index, command) => { - return new RegExp( `^\\[${ index }] ${ command } stopped at ${ dateRegex }, ${ timeRegex } after (\\d|,)+ms$` ); + return new RegExp( `^\\[${ index }] ${ command } stopped at ${ defaultTimestampFormatRegex.source } after (\\d|,)+ms$` ); }; const expectLinesForProcessStartAndStop = (lines, index, command) => { const escapedCommand = _.escapeRegExp(command); @@ -401,14 +400,14 @@ describe('--show-timings', () => { const expectLinesForTimingsTable = (lines) => { const tableTopBorderRegex = /┌[─┬]+┐/g; expect(lines).toContainEqual(expect.stringMatching(tableTopBorderRegex)); - const tableHeaderRowRegex = /(\W+(\(index\)|call-index|name|duration|exit-code|killed|command)\W+){7}/g; + const tableHeaderRowRegex = /(\W+(\(index\)|name|duration|exit code|killed|command)\W+){6}/g; expect(lines).toContainEqual(expect.stringMatching(tableHeaderRowRegex)); const tableBottomBorderRegex = /└[─┴]+┘/g; expect(lines).toContainEqual(expect.stringMatching(tableBottomBorderRegex)); }; it('shows timings on success', done => { - const child = run('--show-timings "sleep 0.5" "exit 0"'); + const child = run('--timings "sleep 0.5" "exit 0"'); child.log.pipe(buffer(child.close)).subscribe(lines => { expectLinesForProcessStartAndStop(lines, 0, 'sleep 0.5'); expectLinesForProcessStartAndStop(lines, 1, 'exit 0'); @@ -418,7 +417,7 @@ describe('--show-timings', () => { }); it('shows timings on failure', done => { - const child = run('--show-timings "sleep 0.75" "exit 1"'); + const child = run('--timings "sleep 0.75" "exit 1"'); child.log.pipe(buffer(child.close)).subscribe(lines => { expectLinesForProcessStartAndStop(lines, 0, 'sleep 0.75'); expectLinesForProcessStartAndStop(lines, 1, 'exit 1'); diff --git a/index.js b/index.js index 9ad94634..35a94ecc 100644 --- a/index.js +++ b/index.js @@ -46,11 +46,12 @@ module.exports = exports = (commands, options = {}) => { conditions: options.killOthers }), new LogTimings({ - logger: options.showTimings ? logger: null + logger: options.timings ? logger: null, + timestampFormat: options.timestampFormat, }) ], prefixColors: options.prefixColors || [], - showTimings: options.showTimings + timings: options.timings }); }; diff --git a/src/completion-listener.js b/src/completion-listener.js index ce741a9a..75478c7e 100644 --- a/src/completion-listener.js +++ b/src/completion-listener.js @@ -2,10 +2,9 @@ const Rx = require('rxjs'); const { bufferCount, switchMap, take } = require('rxjs/operators'); module.exports = class CompletionListener { - constructor({ successCondition, scheduler, showTimings}) { + constructor({ successCondition, scheduler }) { this.successCondition = successCondition; this.scheduler = scheduler; - this.showTimings = showTimings; } isSuccess(exitCodes) { diff --git a/src/concurrently.js b/src/concurrently.js index 54d4bfd3..2b77cc73 100644 --- a/src/concurrently.js +++ b/src/concurrently.js @@ -18,7 +18,7 @@ const defaults = { raw: false, controllers: [], cwd: undefined, - showTimings: false + timings: false }; module.exports = (commands, options) => { @@ -51,7 +51,7 @@ module.exports = (commands, options) => { prefixColor: lastColor, killProcess: options.kill, spawn: options.spawn, - showTimings: options.showTimings, + timings: options.timings, }, command) ); }) @@ -77,10 +77,9 @@ module.exports = (commands, options) => { return new CompletionListener({ successCondition: options.successCondition, - showTimings: options.showTimings }) .listen(commands) - .finally((...args) => { + .finally(() => { handleResult.onFinishCallbacks.forEach((onFinish) => onFinish()); }); }; diff --git a/src/defaults.js b/src/defaults.js index 97e99a9f..dee15904 100644 --- a/src/defaults.js +++ b/src/defaults.js @@ -31,5 +31,5 @@ module.exports = { // Current working dir passed as option to spawn command. Default: process.cwd() cwd: undefined, // Whether to show timing information for processes in console output - showTimings: false, + timings: false, }; diff --git a/src/flow-control/log-timings.js b/src/flow-control/log-timings.js index 45a0e10b..7308c13e 100644 --- a/src/flow-control/log-timings.js +++ b/src/flow-control/log-timings.js @@ -1,23 +1,30 @@ const Rx = require('rxjs'); const _ = require('lodash'); +const formatDate = require('date-fns/format'); const { bufferCount, take } = require('rxjs/operators'); const BaseHandler = require('./base-handler'); module.exports = class LogTimings extends BaseHandler { + constructor({ logger, timestampFormat }) { + super({ logger }); + + this.timestampFormat = timestampFormat; + } + printExitInfoTimingTable(exitInfos) { const exitInfoTable = _(exitInfos) - .map(({ command, timings, index, killed, exitCode }) => { + .sortBy(({timings}) => timings.durationSeconds) + .reverse() + .map(({ command, timings, killed, exitCode }) => { const readableDurationMs = (timings.endDate - timings.startDate).toLocaleString(); return { - 'call-index': index, name: command.name, - duration: `~${readableDurationMs}ms`, - 'exit-code': exitCode, + duration: `${readableDurationMs}ms`, + 'exit code': exitCode, killed, command: command.command, }; }) - .sortBy('duration') .value(); console.log('\nTimings:'); @@ -28,16 +35,18 @@ module.exports = class LogTimings extends BaseHandler { handle(commands) { if (!this.logger) { return {commands}; } + const controllerInstance = this; + // individual process timings commands.forEach(command => { command.timer.subscribe( { next: ({startDate, endDate}) => { if (!endDate) { - this.logger.logCommandEvent( `${ command.command } started at ${ startDate.toLocaleString() }`, command ); + controllerInstance.logger.logCommandEvent( `${ command.command } started at ${ formatDate(startDate, controllerInstance.timestampFormat) }`, command ); } else { const durationMs = (endDate.getTime() - startDate.getTime()); - this.logger.logCommandEvent( `${ command.command } stopped at ${ endDate.toLocaleString() } after ${durationMs.toLocaleString()}ms`, command ); + controllerInstance.logger.logCommandEvent( `${ command.command } stopped at ${ formatDate(endDate, controllerInstance.timestampFormat) } after ${durationMs.toLocaleString()}ms`, command ); } }, } ); diff --git a/src/flow-control/log-timings.spec.js b/src/flow-control/log-timings.spec.js index 40a0f06b..870b9a07 100644 --- a/src/flow-control/log-timings.spec.js +++ b/src/flow-control/log-timings.spec.js @@ -1,4 +1,5 @@ const { createMockInstance } = require('jest-create-mock-instance'); +const formatDate = require('date-fns/format'); const Logger = require('../logger'); const LogTimings = require( './log-timings' ); const createFakeCommand = require('./fixtures/fake-command'); @@ -9,17 +10,17 @@ const startDate1 = new Date(startDate0.getTime() + 1000); const endDate1 = new Date(startDate0.getTime() + 3000); const endDate0 = new Date(startDate0.getTime() + 5000); -const getDurationText = (startDate, endDate) => (endDate.getTime() - startDate.getTime()).toLocaleString(); +const timestampFormat = 'yyyy-MM-dd HH:mm:ss.SSS'; +const getDurationText = (startDate, endDate) => `${(endDate.getTime() - startDate.getTime()).toLocaleString()}ms`; const command0DurationTextMs = getDurationText(startDate0, endDate0); const command1DurationTextMs = getDurationText(startDate1, endDate1); -const exitInfoToTimingInfo = ({ command, timings, index, killed, exitCode }) => { - const readableDurationMs = (timings.endDate - timings.startDate).toLocaleString(); +const exitInfoToTimingInfo = ({ command, timings, killed, exitCode }) => { + const readableDurationMs = getDurationText(timings.startDate, timings.endDate); return { - 'call-index': index, name: command.name, - duration: `~${readableDurationMs}ms`, - 'exit-code': exitCode, + duration: readableDurationMs, + 'exit code': exitCode, killed, command: command.command, }; @@ -56,7 +57,7 @@ beforeEach(() => { }; logger = createMockInstance(Logger); - controller = new LogTimings({ logger }); + controller = new LogTimings({ logger, timestampFormat }); }); it('returns same commands', () => { @@ -69,8 +70,8 @@ it('does not log timings and doesn\'t throw if no logger is provided', () => { commands[0].timer.next({ startDate: startDate0 }); commands[1].timer.next({ startDate: startDate1 }); - commands[1].timer.next({startDate: startDate1, endDate: endDate1 }); - commands[0].timer.next({startDate: startDate0, endDate: endDate0 }); + commands[1].timer.next({ startDate: startDate1, endDate: endDate1 }); + commands[0].timer.next({ startDate: startDate0, endDate: endDate0 }); expect(logger.logCommandEvent).toHaveBeenCalledTimes(0); }); @@ -80,24 +81,24 @@ it('logs the timings at the start and end (ie complete or error) event of each c commands[0].timer.next({ startDate: startDate0 }); commands[1].timer.next({ startDate: startDate1 }); - commands[1].timer.next({startDate: startDate1, endDate: endDate1 }); - commands[0].timer.next({startDate: startDate0, endDate: endDate0 }); + commands[1].timer.next({ startDate: startDate1, endDate: endDate1 }); + commands[0].timer.next({ startDate: startDate0, endDate: endDate0 }); expect(logger.logCommandEvent).toHaveBeenCalledTimes(4); expect(logger.logCommandEvent).toHaveBeenCalledWith( - `${commands[0].command} started at ${startDate0.toLocaleString()}`, + `${commands[0].command} started at ${formatDate(startDate0, timestampFormat)}`, commands[0] ); expect(logger.logCommandEvent).toHaveBeenCalledWith( - `${commands[1].command} started at ${startDate1.toLocaleString()}`, + `${commands[1].command} started at ${formatDate(startDate1, timestampFormat)}`, commands[1] ); expect(logger.logCommandEvent).toHaveBeenCalledWith( - `${commands[1].command} stopped at ${endDate1.toLocaleString()} after ${command1DurationTextMs}ms`, + `${commands[1].command} stopped at ${formatDate(endDate1, timestampFormat)} after ${command1DurationTextMs}`, commands[1] ); expect(logger.logCommandEvent).toHaveBeenCalledWith( - `${commands[0].command} stopped at ${endDate0.toLocaleString()} after ${command0DurationTextMs}ms`, + `${commands[0].command} stopped at ${formatDate(endDate0, timestampFormat)} after ${command0DurationTextMs}`, commands[0] ); });