From 596c9ded4702c7fb17eb0f7701bda1d1ca8bfc0c 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 +-- .../expand-npm-wildcard.spec.js | 29 +++++++++++++++++ src/completion-listener.js | 3 +- src/concurrently.js | 7 ++--- src/defaults.js | 2 +- src/flow-control/base-handler.spec.js | 22 +++++++++++++ src/flow-control/log-timings.js | 23 +++++++++----- src/flow-control/log-timings.spec.js | 31 ++++++++++--------- 10 files changed, 102 insertions(+), 43 deletions(-) create mode 100644 src/flow-control/base-handler.spec.js 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/command-parser/expand-npm-wildcard.spec.js b/src/command-parser/expand-npm-wildcard.spec.js index cf72eb67..27d1aebf 100644 --- a/src/command-parser/expand-npm-wildcard.spec.js +++ b/src/command-parser/expand-npm-wildcard.spec.js @@ -1,4 +1,5 @@ const ExpandNpmWildcard = require('./expand-npm-wildcard'); +const fs = require('fs'); let parser, readPkg; @@ -7,6 +8,34 @@ beforeEach(() => { parser = new ExpandNpmWildcard(readPkg); }); +describe('ExpandNpmWildcard#readPackage', () => { + it('can read package', () => { + const expectedPackage = { + 'name': 'concurrently', + 'version': '6.4.0', + }; + jest.spyOn(fs, 'readFileSync').mockImplementation((path, options) => { + if (path === 'package.json') { + return JSON.stringify(expectedPackage); + } + return null; + }); + + const actualReadPackage = ExpandNpmWildcard.readPackage(); + expect(actualReadPackage).toEqual(expectedPackage); + }); + + it('can handle errors reading package', () => { + jest.spyOn(fs, 'readFileSync').mockImplementation(() => { + throw new Error('Error reading package'); + }); + + expect(() => ExpandNpmWildcard.readPackage()).not.toThrow(); + expect(ExpandNpmWildcard.readPackage()).toEqual({}); + }); + +}); + it('returns same command if not an npm run command', () => { const commandInfo = { command: 'npm test' 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/base-handler.spec.js b/src/flow-control/base-handler.spec.js new file mode 100644 index 00000000..99a44190 --- /dev/null +++ b/src/flow-control/base-handler.spec.js @@ -0,0 +1,22 @@ +const stream = require('stream'); +const { createMockInstance } = require('jest-create-mock-instance'); + +const Logger = require('../logger'); +const createFakeCommand = require('./fixtures/fake-command'); +const BaseHandler = require('./base-handler'); + +let commands, controller, inputStream, logger; + +beforeEach(() => { + commands = [ + createFakeCommand('foo', 'echo foo', 0), + createFakeCommand('bar', 'echo bar', 1), + ]; + inputStream = new stream.PassThrough(); + logger = createMockInstance(Logger); + controller = new BaseHandler({ logger }); +}); + +it('returns same commands and null onFinish callback by default', () => { + expect(controller.handle(commands)).toMatchObject({ commands, onFinish: null }); +}); \ No newline at end of file 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] ); });