Skip to content

Commit

Permalink
Delay summary timings output until finished (#431)
Browse files Browse the repository at this point in the history
This fixes the problem that summary timings are printed before grouped output (Fixes #316).
  • Loading branch information
kayahr authored Jun 24, 2023
1 parent c36f059 commit 744ece9
Show file tree
Hide file tree
Showing 2 changed files with 18 additions and 8 deletions.
16 changes: 12 additions & 4 deletions src/flow-control/log-timings.spec.ts
Original file line number Diff line number Diff line change
Expand Up @@ -57,13 +57,15 @@ it('returns same commands', () => {

it("does not log timings and doesn't throw if no logger is provided", () => {
controller = new LogTimings({});
controller.handle(commands);
const { onFinish } = controller.handle(commands);

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 });

onFinish?.();

expect(logger.logCommandEvent).toHaveBeenCalledTimes(0);
});

Expand Down Expand Up @@ -101,20 +103,26 @@ it('logs the timings at the start and end (ie complete or error) event of each c
});

it('does not log timings summary if there was an error', () => {
controller.handle(commands);
const { onFinish } = controller.handle(commands);

commands[0].close.next(command0ExitInfo);
commands[1].error.next(undefined);

onFinish?.();

expect(logger.logTable).toHaveBeenCalledTimes(0);
});

it('logs the sorted timings summary when all processes close successfully', () => {
controller.handle(commands);
it('logs the sorted timings summary when all processes close successfully after onFinish is called', () => {
const { onFinish } = controller.handle(commands);

commands[0].close.next(command0ExitInfo);
commands[1].close.next(command1ExitInfo);

expect(logger.logGlobalEvent).toHaveBeenCalledTimes(0);

onFinish?.();

expect(logger.logGlobalEvent).toHaveBeenCalledTimes(1);
expect(logger.logGlobalEvent).toHaveBeenCalledWith('Timings:');
expect(logger.logTable).toHaveBeenCalledTimes(1);
Expand Down
10 changes: 6 additions & 4 deletions src/flow-control/log-timings.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@ import * as assert from 'assert';
import formatDate from 'date-fns/format';
import _ from 'lodash';
import * as Rx from 'rxjs';
import { bufferCount, take } from 'rxjs/operators';
import { bufferCount, combineLatestWith, take } from 'rxjs/operators';

import { CloseEvent, Command } from '../command';
import * as defaults from '../defaults';
Expand Down Expand Up @@ -97,11 +97,13 @@ export class LogTimings implements FlowController {

// overall summary timings
const closeStreams = commands.map((command) => command.close);
const finished = new Rx.Subject<void>();
const allProcessesClosed = Rx.merge(...closeStreams).pipe(
bufferCount(closeStreams.length),
take(1)
take(1),
combineLatestWith(finished)
);
allProcessesClosed.subscribe((exitInfos) => this.printExitInfoTimingTable(exitInfos));
return { commands };
allProcessesClosed.subscribe(([exitInfos]) => this.printExitInfoTimingTable(exitInfos));
return { commands, onFinish: () => finished.next() };
}
}

0 comments on commit 744ece9

Please sign in to comment.