From d60d8f63f328ebf343f73eaac9a0dca84aa8501b Mon Sep 17 00:00:00 2001 From: Kir_Antipov Date: Mon, 19 Dec 2022 17:34:43 +0000 Subject: [PATCH] `LoggingStopwatch` refactoring --- src/utils/logging/logging-stopwatch.ts | 102 +++++++--- .../utils/logging/logging-stopwatch.spec.ts | 192 ++++++++++++++++++ 2 files changed, 269 insertions(+), 25 deletions(-) create mode 100644 tests/unit/utils/logging/logging-stopwatch.spec.ts diff --git a/src/utils/logging/logging-stopwatch.ts b/src/utils/logging/logging-stopwatch.ts index cf79457..3d3d5d2 100644 --- a/src/utils/logging/logging-stopwatch.ts +++ b/src/utils/logging/logging-stopwatch.ts @@ -1,44 +1,96 @@ -import Logger from "./logger"; -import Stopwatch from "../diagnostics/stopwatch"; +import { Stopwatch } from "@/utils/diagnostics"; +import { Logger } from "./logger"; +/** + * A callback function that is called when the {@link LoggingStopwatch} is started. + */ interface StartCallback { - (currentDate: Date, stopwatch: Stopwatch): string; + /** + * @param date - The date when the {@link LoggingStopwatch} was started. + * @param stopwatch - The {@link LoggingStopwatch} instance that was started. + * + * @returns The message to log, or `void` if no message should be logged. + */ + (date: Date, stopwatch: LoggingStopwatch): string | void; } +/** + * A callback function that is called when the {@link LoggingStopwatch} is stopped. + */ interface StopCallback { - (elapsedMilliseconds: number, currentDate: Date, stopwatch: Stopwatch): string; + /** + * @param elapsedTime - The elapsed time in milliseconds since the {@link LoggingStopwatch} was started. + * @param date - The date when the {@link LoggingStopwatch} was stopped. + * @param stopwatch - The {@link LoggingStopwatch} instance that was stopped. + * + * @returns The message to log, or `void` if no message should be logged. + */ + (elapsedTime: number, date: Date, stopwatch: LoggingStopwatch): string | void; } -type VoidCallback any> = (...args: Parameters) => void; +/** + * A callback wrapper that always returns void. + */ +type VoidCallback = T extends StartCallback | StopCallback ? (...args: Parameters) => void : () => void; -function toCallback string>(func: string | T): T { - if (typeof func === "string") { - return (() => func) as T; - } - return func; -} - -function loggingCallbackToVoidCallback any>(logger: Logger, func: T): VoidCallback { - if (!func) { - return func; +/** + * Creates a callback that will log a message if one is returned by the provided `message` callback. + * + * @param logger - The {@link Logger} instance to use for logging. + * @param message - A string or a callback that returns a string or `void` indicating whether to log a message. + * + * @returns A callback that takes the same amount of arguments as the original `message` one + * and logs a message if one is returned by the `message` callback. + */ +function createMessageCallback(logger: Logger, message: T): VoidCallback { + if (typeof message === "string") { + return (() => logger.info(message)) as VoidCallback; } - return (...args: any[]) => { - const msg = func(...args) as string; - if (typeof msg === "string") { - logger?.info(msg); + if (!message) { + return undefined; + } + + return ((...args: Parameters>) => { + const result = (message as (...args: Parameters>) => string | void)(...args); + if (typeof result === "string") { + logger.info(result); } - }; + }) as VoidCallback; } +/** + * An extension of the {@link Stopwatch} class that adds logging functionality. +*/ +// For God's sake, it's been 8 years! +// https://github.com/microsoft/TypeScript/issues/4628 // eslint-disable-next-line -// @ts-ignore: ts2417 -export default class LoggingStopwatch extends Stopwatch { - public constructor(logger: Logger, onStart?: string | StartCallback, onStop?: string | StopCallback) { - super(loggingCallbackToVoidCallback(logger, toCallback(onStart)), loggingCallbackToVoidCallback(logger, toCallback(onStop))); +// @ts-expect-error: ts2417 +export class LoggingStopwatch extends Stopwatch { + /** + * Creates a new {@link LoggingStopwatch} instance. + * + * @param logger - The {@link Logger} instance to use for logging. + * @param onStart - A string or a callback to be called when the stopwatch is started. + * @param onStop - A string or a callback to be called when the stopwatch is stopped. + */ + constructor(logger: Logger, onStart?: string | StartCallback, onStop?: string | StopCallback) { + const startCallback = createMessageCallback(logger, onStart); + const stopCallback = createMessageCallback(logger, onStop); + + super(startCallback, stopCallback); } - public static startNew(logger: Logger, onStart?: string | StartCallback, onStop?: string | StopCallback): LoggingStopwatch { + /** + * Creates a new {@link LoggingStopwatch} instance and starts it. + * + * @param logger - The {@link Logger} instance to use for logging. + * @param onStart - A string or a callback to be called when the stopwatch is started. + * @param onStop - A string or a callback to be called when the stopwatch is stopped. + * + * @returns The newly created and started {@link LoggingStopwatch} instance. + */ + static startNew(logger: Logger, onStart?: string | StartCallback, onStop?: string | StopCallback): LoggingStopwatch { const stopwatch = new LoggingStopwatch(logger, onStart, onStop); stopwatch.start(); return stopwatch; diff --git a/tests/unit/utils/logging/logging-stopwatch.spec.ts b/tests/unit/utils/logging/logging-stopwatch.spec.ts new file mode 100644 index 0000000..59b75d9 --- /dev/null +++ b/tests/unit/utils/logging/logging-stopwatch.spec.ts @@ -0,0 +1,192 @@ +import { Logger } from "@/utils/logging/logger"; +import { LoggingStopwatch } from "@/utils/logging/logging-stopwatch"; + +function createMockLogger(): Logger { + return { + fatal: jest.fn(), + error: jest.fn(), + warn: jest.fn(), + info: jest.fn(), + debug: jest.fn(), + }; +} + +describe("LoggingStopwatch", () => { + beforeEach(() => { + jest.useFakeTimers(); + jest.setSystemTime(0); + }); + + afterEach(() => { + jest.useRealTimers(); + }); + + describe("constructor", () => { + test("initializes with default values", () => { + const stopwatch = new LoggingStopwatch(createMockLogger()); + + expect(stopwatch.isRunning).toBe(false); + expect(stopwatch.elapsedMilliseconds).toBe(0); + }); + }); + + describe("start", () => { + test("starts stopwatch and logs start message", () => { + const logger = createMockLogger(); + const stopwatch = new LoggingStopwatch(logger, "Stopwatch started"); + + expect(stopwatch.start()).toBe(true); + expect(logger.info).toHaveBeenCalledWith("Stopwatch started"); + }); + + test("doesn't start if stopwatch is already running", () => { + const logger = createMockLogger(); + const stopwatch = LoggingStopwatch.startNew(logger, "Stopwatch started"); + + expect(stopwatch.start()).toBe(false); + expect(logger.info).toHaveBeenCalledTimes(1); + }); + }); + + describe("stop", () => { + test("stops stopwatch and logs stop message", () => { + const logger = createMockLogger(); + const onStart = jest.fn().mockReturnValue("Stopwatch started"); + const onStop = jest.fn().mockReturnValue("Stopwatch stopped"); + const stopwatch = LoggingStopwatch.startNew(logger, onStart, onStop); + + jest.advanceTimersByTime(1000); + + expect(stopwatch.stop()).toBe(true); + expect(onStart).toHaveBeenCalledTimes(1); + expect(onStart).toHaveBeenCalledWith(new Date(0), stopwatch); + expect(onStop).toHaveBeenCalledTimes(1); + expect(onStop).toHaveBeenCalledWith(1000, new Date(1000), stopwatch); + expect(logger.info).toHaveBeenCalledTimes(2); + expect(logger.info).toHaveBeenNthCalledWith(1, "Stopwatch started"); + expect(logger.info).toHaveBeenNthCalledWith(2, "Stopwatch stopped"); + }); + + test("doesn't stop if stopwatch is already stopped", () => { + const logger = createMockLogger(); + const stopwatch = new LoggingStopwatch(logger, undefined, "Stopwatch stopped"); + + expect(stopwatch.stop()).toBe(false); + expect(logger.info).not.toBeCalled(); + }); + }); + + describe("elapsedMilliseconds", () => { + test("measures elapsed time while stopwatch is running", () => { + const stopwatch = LoggingStopwatch.startNew(createMockLogger()); + + expect(stopwatch.elapsedMilliseconds).toBe(0); + + jest.advanceTimersByTime(1000); + expect(stopwatch.elapsedMilliseconds).toBe(1000); + + jest.advanceTimersByTime(1000); + expect(stopwatch.elapsedMilliseconds).toBe(2000); + }); + + test("measures elapsed time correctly when stopwatch is stopped", () => { + const stopwatch = LoggingStopwatch.startNew(createMockLogger()); + + expect(stopwatch.elapsedMilliseconds).toBe(0); + + jest.advanceTimersByTime(1000); + expect(stopwatch.elapsedMilliseconds).toBe(1000); + + jest.advanceTimersByTime(1000); + expect(stopwatch.elapsedMilliseconds).toBe(2000); + + stopwatch.stop(); + jest.advanceTimersByTime(1000); + expect(stopwatch.elapsedMilliseconds).toBe(2000); + }); + + test("returns 0 if the stopwatch was never started", () => { + const stopwatch = new LoggingStopwatch(createMockLogger()); + + expect(stopwatch.elapsedMilliseconds).toBe(0); + }); + }); + + describe("reset", () => { + test("resets stopwatch correctly while it's running", () => { + const stopwatch = LoggingStopwatch.startNew(createMockLogger()); + + jest.advanceTimersByTime(1000); + stopwatch.reset(); + + expect(stopwatch.elapsedMilliseconds).toBe(0); + expect(stopwatch.isRunning).toBe(false); + }); + + test("resets stopwatch correctly when it's stopped", () => { + const stopwatch = LoggingStopwatch.startNew(createMockLogger()); + + jest.advanceTimersByTime(1000); + stopwatch.stop(); + stopwatch.reset(); + + expect(stopwatch.elapsedMilliseconds).toBe(0); + expect(stopwatch.isRunning).toBe(false); + }); + + test("does nothing if the stopwatch was never started", () => { + const stopwatch = new LoggingStopwatch(createMockLogger()); + stopwatch.reset(); + + expect(stopwatch.elapsedMilliseconds).toBe(0); + expect(stopwatch.isRunning).toBe(false); + }); + }); + + describe("restart", () => { + test("restarts stopwatch correctly while it's running", () => { + const stopwatch = LoggingStopwatch.startNew(createMockLogger()); + + jest.advanceTimersByTime(1000); + stopwatch.restart(); + + expect(stopwatch.elapsedMilliseconds).toBe(0); + expect(stopwatch.isRunning).toBe(true); + }); + + test("restarts stopwatch correctly when it's stopped", () => { + const stopwatch = LoggingStopwatch.startNew(createMockLogger()); + + jest.advanceTimersByTime(1000); + stopwatch.stop(); + stopwatch.restart(); + + expect(stopwatch.elapsedMilliseconds).toBe(0); + expect(stopwatch.isRunning).toBe(true); + }); + + test("starts the stopwatch if it was never started", () => { + const stopwatch = new LoggingStopwatch(createMockLogger()); + stopwatch.restart(); + + expect(stopwatch.elapsedMilliseconds).toBe(0); + expect(stopwatch.isRunning).toBe(true); + }); + }); + + describe("startNew", () => { + test("starts new stopwatch correctly", () => { + const logger = createMockLogger(); + const onStart = jest.fn().mockReturnValue("Stopwatch started"); + const onStop = jest.fn(); + const stopwatch = LoggingStopwatch.startNew(logger, onStart, onStop); + + expect(stopwatch.isRunning).toBe(true); + expect(onStart).toHaveBeenCalledTimes(1); + expect(onStart).toHaveBeenCalledWith(new Date(0), stopwatch); + expect(logger.info).toHaveBeenCalledTimes(1); + expect(logger.info).toHaveBeenCalledWith("Stopwatch started"); + expect(onStop).not.toHaveBeenCalled(); + }); + }); +});