LoggingStopwatch refactoring

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<T extends (...args: any[]) => any> = (...args: Parameters<T>) => void;
+/**
+ * A callback wrapper that always returns void.
+ */
+type VoidCallback<T> = T extends StartCallback | StopCallback ? (...args: Parameters<T>) => void : () => void;
 
-function toCallback<T extends (...args: any[]) => string>(func: string | T): T {
-    if (typeof func === "string") {
-        return (() => func) as T;
+/**
+ * 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<T extends string | StartCallback | StopCallback>(logger: Logger, message: T): VoidCallback<T> {
+    if (typeof message === "string") {
+        return (() => logger.info(message)) as VoidCallback<T>;
     }
-    return func;
-}
-
-function loggingCallbackToVoidCallback<T extends (...args: any[]) => any>(logger: Logger, func: T): VoidCallback<T> {
-    if (!func) {
-        return func;
-    }
-
-    return (...args: any[]) => {
-        const msg = func(...args) as string;
-        if (typeof msg === "string") {
-            logger?.info(msg);
-        }
-    };
+
+    if (!message) {
+        return undefined;
+    }
+
+    return ((...args: Parameters<Exclude<T, string>>) => {
+        const result = (message as (...args: Parameters<Exclude<T, string>>) => string | void)(...args);
+        if (typeof result === "string") {
+            logger.info(result);
+        }
+    }) as VoidCallback<T>;
 }
 
+/**
+ * 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;

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