feat: better duration measuring especially for short time intervals

src/timer/README.md

@@ -0,0 +1,50 @@
+# ExecutionTimer
+
+`ExecutionTimer` is a simple TypeScript class for measuring the execution time of code blocks. It provides methods to start, stop, and retrieve the duration of the timer. Additionally, it includes a function to get human-readable elapsed time.
+
+## Usage
+
+```typescript
+import { ExecutionTimer } from 'execution-timer';
+
+// Create an instance of ExecutionTimer
+const timer = new ExecutionTimer();
+
+// Start the timer
+timer.start();
+
+// Code execution you want to measure
+for (let i = 0; i < 1000000; i++) {
+  // Some computation
+}
+
+// Stop the timer
+timer.stop();
+
+// Get and log the duration
+const duration = timer.getDuration();
+console.log(`Execution time: ${duration} milliseconds`);
+
+// Get and log the human-readable elapsed time
+const elapsedTime = timer.getElapsedTime();
+console.log(`Elapsed time: ${elapsedTime}`);
+
+```
+
+You can use a custom execution ID to track multiple timers independently:
+
+```typescript
+const customTimer = new ExecutionTimer('customId');
+
+// Start and stop the timer with the custom ID
+customTimer.start();
+// Code execution
+customTimer.stop();
+
+// Get the duration and human-readable elapsed time
+const customDuration = customTimer.getDuration();
+const customElapsedTime = customTimer.getElapsedTime();
+
+console.log(`Custom Timer Duration: ${customDuration} milliseconds`);
+console.log(`Custom Timer Elapsed Time: ${customElapsedTime}`);
+```

src/timer/executionTimer.spec.ts

@@ -0,0 +1,112 @@
+import { ExecutionTimer } from "./executionTimer";
+
+describe("ExecutionTimer", () => {
+  let timer: ExecutionTimer;
+
+  beforeEach(() => {
+    timer = new ExecutionTimer();
+  });
+
+  it("should start the timer", () => {
+    timer.start();
+    expect(timer.getStartDate()).toBeDefined();
+  });
+
+  it("should stop the timer", () => {
+    timer.start();
+    timer.stop();
+    expect(timer.getEndDate()).toBeDefined();
+  });
+
+  it("should get the duration", () => {
+    jest.spyOn(performance, "now").mockReturnValueOnce(200);
+    timer.start();
+    // Simulate some code execution time
+    jest.spyOn(performance, "now").mockReturnValueOnce(1000);
+    timer.stop();
+    expect(timer.getDuration()).toBe(800);
+  });
+
+  it("should get the start date in ISO format", () => {
+    timer.start();
+    expect(timer.getStartDate() instanceof Date).toBe(true);
+  });
+
+  it("should get the end date in ISO format", () => {
+    timer.start();
+    timer.stop();
+    expect(timer.getEndDate() instanceof Date).toBe(true);
+  });
+
+  it("should get the duration with a custom execution ID", () => {
+    const customId = "customId";
+    jest.spyOn(performance, "now").mockReturnValueOnce(200);
+    timer.start(customId);
+    // Simulate some code execution time
+    jest.spyOn(performance, "now").mockReturnValueOnce(2000);
+    expect(timer.getDuration(customId)).toBe(1800);
+  });
+
+  it("should get the start date with a custom execution ID", () => {
+    const customId = "customId";
+    timer.start(customId);
+    expect(timer.getStartDate(customId) instanceof Date).toBe(true);
+  });
+
+  it("should get the end date with a custom execution ID", () => {
+    const customId = "customId";
+    timer.start(customId);
+    timer.stop(customId);
+    expect(timer.getEndDate(customId) instanceof Date).toBe(true);
+  });
+
+  it("should get human-readable elapsed time for a duration", () => {
+    jest.spyOn(performance, "now").mockReturnValueOnce(1000);
+    timer.start();
+    // Simulate some code execution time
+    jest.spyOn(performance, "now").mockReturnValueOnce(4000);
+    timer.stop();
+    const elapsedTime = timer.getElapsedTime();
+    expect(elapsedTime).toMatch(/3 seconds/);
+  });
+
+  it("should get human-readable elapsed time with hours and minutes", () => {
+    jest.spyOn(performance, "now").mockReturnValueOnce(1000);
+    timer.start();
+    // Advance time by 1 hour, 1 minute, and 5 seconds
+    jest.spyOn(performance, "now").mockReturnValueOnce(3666000);
+    timer.stop();
+    const elapsedTime = timer.getElapsedTime();
+    expect(elapsedTime).toMatch(/1 hour 1 minute 5 seconds/);
+  });
+
+  it("should get human-readable elapsed time with milliseconds", () => {
+    jest.spyOn(performance, "now").mockReturnValueOnce(1000);
+    timer.start();
+    jest.spyOn(performance, "now").mockReturnValueOnce(1123);
+    timer.stop();
+    const elapsedTime = timer.getElapsedTime();
+    expect(elapsedTime).toMatch(/123 ms/);
+  });
+
+  it("should return undefined for getElapsedTime when timer is not started", () => {
+    const elapsedTime = timer.getElapsedTime();
+    expect(elapsedTime).toBeUndefined();
+  });
+
+  // it("should return undefined for getElapsedTime when timer is not stopped", () => {
+  //   timer.start();
+  //   const elapsedTime = timer.getElapsedTime();
+  //   expect(elapsedTime).toBeUndefined();
+  // });
+
+  it("should get human-readable elapsed time with a custom execution ID", () => {
+    const customId = "customId";
+    jest.spyOn(performance, "now").mockReturnValueOnce(1000);
+    timer.start(customId);
+    jest.spyOn(performance, "now").mockReturnValueOnce(6000);
+    timer.stop(customId);
+    const elapsedTime = timer.getElapsedTime(customId);
+    expect(elapsedTime).toMatch(/5 seconds/);
+  });
+});

src/timer/executionTimer.ts

@@ -0,0 +1,112 @@
+/**
+ * A class for measuring the execution time of code blocks.
+ */
+export class ExecutionTimer {
+  private timer: { [key: string]: { startTime: number; endTime: number } } = {};
+
+  /**
+   * Creates an instance of ExecutionTimer.
+   * @param executionId - An optional identifier for the execution timer. Defaults to 'default'.
+   */
+  constructor(executionId?: string) {
+    this.timer[executionId ?? "default"] = {
+      startTime: 0,
+      endTime: 0,
+    };
+  }
+
+  /**
+   * Starts the execution timer.
+   * @param executionId - An optional identifier for the execution timer. Defaults to 'default'.
+   */
+  start(executionId?: string) {
+    this.timer[executionId ?? "default"] = {
+      startTime: performance.now(),
+      endTime: 0,
+    };
+  }
+
+  /**
+   * Stops the execution timer.
+   * @param executionId - An optional identifier for the execution timer. Defaults to 'default'.
+   */
+  stop(executionId?: string) {
+    if (this.timer[executionId ?? "default"]?.startTime) {
+      this.timer[executionId ?? "default"].endTime = performance.now();
+    }
+  }
+
+  /**
+   * Gets the duration of the execution timer in milliseconds.
+   * @param executionId - An optional identifier for the execution timer. Defaults to 'default'.
+   * @returns The duration of the execution timer in milliseconds.
+   */
+  getDuration(executionId?: string) {
+    const timerId = executionId ?? "default";
+    if (this.timer[executionId ?? "default"]?.startTime) {
+      if (!this.timer[executionId ?? "default"].endTime) {
+        this.stop(timerId);
+      }
+      return (
+        this.timer[executionId ?? "default"].endTime -
+        this.timer[executionId ?? "default"].startTime
+      );
+    }
+  }
+
+  /**
+   * Gets the start date of the execution timer.
+   * @param executionId - An optional identifier for the execution timer. Defaults to 'default'.
+   * @returns The start date of the execution timer.
+   */
+  getStartDate(executionId?: string): Date | undefined {
+    if (this.timer[executionId ?? "default"]?.startTime) {
+      return new Date(this.timer[executionId ?? "default"]?.startTime);
+    }
+  }
+
+  /**
+   * Gets the end date of the execution timer.
+   * @param executionId - An optional identifier for the execution timer. Defaults to 'default'.
+   * @returns The end date of the execution timer.
+   */
+  getEndDate(executionId?: string): Date | undefined {
+    if (this.timer[executionId ?? "default"]?.endTime) {
+      return new Date(this.timer[executionId ?? "default"]?.endTime);
+    }
+  }
+
+  /**
+   * Gets the human-readable elapsed time of the execution timer.
+   * @param executionId - An optional identifier for the execution timer. Defaults to 'default'.
+   * @returns A string representing the human-readable elapsed time.
+   */
+  getElapsedTime(executionId?: string): string | undefined {
+    const duration = this.getDuration(executionId);
+    if (duration === undefined) {
+      return undefined;
+    }
+
+    const milliseconds = Math.floor(duration % 1000);
+    const seconds = Math.floor((duration / 1000) % 60);
+    const minutes = Math.floor((duration / (1000 * 60)) % 60);
+    const hours = Math.floor((duration / (1000 * 60 * 60)) % 24);
+
+    const parts = [];
+
+    if (hours > 0) {
+      parts.push(`${hours} hour${hours > 1 ? 's' : ''}`);
+    }
+    if (minutes > 0) {
+      parts.push(`${minutes} minute${minutes > 1 ? 's' : ''}`);
+    }
+    if (seconds > 0) {
+      parts.push(`${seconds} second${seconds > 1 ? 's' : ''}`);
+    }
+    if (milliseconds > 0) {
+      parts.push(`${milliseconds} ms`);
+    }
+
+    return parts.join(' ');
+  }
+}

src/trace/traceableExecution.ts

@@ -11,6 +11,7 @@ import {
 } from "./trace.model";
 import { v4 as uuidv4 } from "uuid";
 import { extract } from "../common/jsonQuery";
+import { ExecutionTimer } from "../timer/executionTimer";
 
 export type Awaited<T> = T extends PromiseLike<infer U> ? U : T;
 
@@ -191,12 +192,12 @@ export class TraceableExecution {
       ? undefined
       : options.config ?? DEFAULT_TRACE_CONFIG;
     const nodeTraceFromOptions = isNodeTrace(options) ? options : options.trace;
-    const startTime = new Date();
-
+    const executionTimer = new ExecutionTimer();
+    executionTimer?.start();
     const nodeTrace: NodeData = {
       id: [
         blockFunction.name ? blockFunction.name : "function",
-        startTime?.getTime(),
+        executionTimer?.getStartDate()?.getTime(),
         TraceableExecution.getUniqueString(),
       ]?.join("_"),
       label: [
@@ -214,7 +215,7 @@ export class TraceableExecution {
           const executionTrace = {
             inputs,
             outputs,
-            ...this.calculateTimeAndDuration(startTime),
+            ...this.calculateTimeAndDuration(executionTimer),
           };
           this.buildTrace<O>(
             nodeTrace,
@@ -227,7 +228,7 @@ export class TraceableExecution {
           const executionTrace = {
             inputs,
             errors: [{ name: e?.name, code: e?.code, message: e?.message }],
-            ...this.calculateTimeAndDuration(startTime),
+            ...this.calculateTimeAndDuration(executionTimer),
           };
           this.buildTrace<O>(
             nodeTrace,
@@ -250,7 +251,7 @@ export class TraceableExecution {
               const executionTrace = {
                 inputs,
                 outputs,
-                ...this.calculateTimeAndDuration(startTime),
+                ...this.calculateTimeAndDuration(executionTimer),
               };
               this.buildTrace<O>(
                 nodeTrace,
@@ -263,7 +264,7 @@ export class TraceableExecution {
               const executionTrace = {
                 inputs,
                 errors: [{ name: e?.name, code: e?.code, message: e?.message }],
-                ...this.calculateTimeAndDuration(startTime),
+                ...this.calculateTimeAndDuration(executionTimer),
               };
               this.buildTrace<O>(
                 nodeTrace,
@@ -282,7 +283,7 @@ export class TraceableExecution {
         const executionTrace: NodeExecutionTrace<Array<unknown>, O> = {
           inputs,
           outputs: outputsOrPromise,
-          ...this.calculateTimeAndDuration(startTime),
+          ...this.calculateTimeAndDuration(executionTimer),
         };
         this.buildTrace<O>(
           nodeTrace,
@@ -294,7 +295,7 @@ export class TraceableExecution {
         const executionTrace = {
           inputs,
           errors: [{ name: e?.name, code: e?.code, message: e?.message }],
-          ...this.calculateTimeAndDuration(startTime),
+          ...this.calculateTimeAndDuration(executionTimer),
         };
         this.buildTrace<O>(
           nodeTrace,
@@ -487,12 +488,12 @@ export class TraceableExecution {
     }
   }
 
-  private calculateTimeAndDuration(startTime: Date) {
-    const endTime = new Date();
+  private calculateTimeAndDuration(executionTimer: ExecutionTimer) {
+    executionTimer?.stop();
     return {
-      startTime,
-      endTime,
-      duration: endTime?.getTime() - startTime?.getTime(),
+      startTime: executionTimer?.getStartDate(),
+      endTime: executionTimer?.getEndDate(),
+      duration: executionTimer?.getDuration(),
     };
   }