Skip to content

Commit

Permalink
Update src/flow-control/log-timings.js
Browse files Browse the repository at this point in the history 
Co-authored-by: Gustavo Henke <guhenke@gmail.com>
  • Loading branch information
@eliasm307 @gustavohenke
eliasm307 and gustavohenke committed Nov 18, 2021
1 parent 2bc5bcc commit 3487f83
Show file tree
Hide file tree
Showing 8 changed files with 51 additions and 43 deletions.
8 changes: 4 additions & 4 deletions bin/concurrently.js
View file
Expand Up @@ -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
Expand Down Expand Up @@ -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')
Expand Down Expand Up @@ -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)
Expand Down
15 changes: 7 additions & 8 deletions bin/concurrently.spec.js
View file
Expand Up @@ -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);
Expand All @@ -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');
Expand All @@ -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');
Expand Down
5 changes: 3 additions & 2 deletions index.js
View file
Expand Up @@ -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
});
};

Expand Down
3 changes: 1 addition & 2 deletions src/completion-listener.js
View file
Expand Up @@ -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) {
Expand Down
7 changes: 3 additions & 4 deletions src/concurrently.js
View file
Expand Up @@ -18,7 +18,7 @@ const defaults = {
raw: false,
controllers: [],
cwd: undefined,
showTimings: false
timings: false
};

module.exports = (commands, options) => {
Expand Down Expand Up @@ -51,7 +51,7 @@ module.exports = (commands, options) => {
prefixColor: lastColor,
killProcess: options.kill,
spawn: options.spawn,
showTimings: options.showTimings,
timings: options.timings,
}, command)
);
})
Expand All @@ -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());
});
};
Expand Down
2 changes: 1 addition & 1 deletion src/defaults.js
View file
Expand Up @@ -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,
};
23 changes: 16 additions & 7 deletions src/flow-control/log-timings.js
View file
@@ -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:');
Expand All @@ -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 );
}
},
} );
Expand Down
31 changes: 16 additions & 15 deletions src/flow-control/log-timings.spec.js
View file
@@ -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');
Expand All @@ -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,
};
Expand Down Expand Up @@ -56,7 +57,7 @@ beforeEach(() => {
};

logger = createMockInstance(Logger);
controller = new LogTimings({ logger });
controller = new LogTimings({ logger, timestampFormat });
});

it('returns same commands', () => {
Expand All @@ -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);
});
Expand All @@ -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]
);
});
Expand Down

0 comments on commit 3487f83

Please sign in to comment.