pullfrog[bot]
b6e6a8976c
* Replace Date.now() with performance.now() for duration measurements - Import performance from node:perf_hooks in all affected files - Update Timer and ThinkingTimer classes to use performance.now() - Update activity tracking (markActivity, getIdleMs) to use performance.now() - Update cache duration measurements to use performance.now() - Update agent execution timing (cursor, opencode) to use performance.now() - Update subprocess execution timing to use performance.now() - Update API performance monitoring to use performance.now() - Update prep phase timing to use performance.now() - Update timer.test.ts to mock performance.now() instead of Date.now() Benefits: - Monotonic clock immune to system clock adjustments - Higher precision (microsecond vs millisecond resolution) - Purpose-built for performance measurement Fixes #245 * fix lint. * Round float durations to integers in logging Preserve original behavior by rounding performance.now() float values to integers when displaying/logging millisecond durations. * fix lint. --------- Co-authored-by: pullfrog[bot] <226033991+pullfrog[bot]@users.noreply.github.com> Co-authored-by: Robin Tail <robin_tail@me.com>
53 lines
1.5 KiB
TypeScript
53 lines
1.5 KiB
TypeScript
import { performance } from "node:perf_hooks";
|
|
import { log } from "./cli.ts";
|
|
|
|
export class Timer {
|
|
private initialTimestamp: number;
|
|
private lastCheckpointTimestamp: number | null = null;
|
|
|
|
constructor() {
|
|
this.initialTimestamp = performance.now();
|
|
}
|
|
|
|
checkpoint(name: string): void {
|
|
const now = performance.now();
|
|
const duration = this.lastCheckpointTimestamp
|
|
? now - this.lastCheckpointTimestamp
|
|
: now - this.initialTimestamp;
|
|
|
|
log.debug(`» ${name}: ${duration}ms`);
|
|
this.lastCheckpointTimestamp = now;
|
|
}
|
|
}
|
|
|
|
const THINKING_THRESHOLD = 3000; // ms
|
|
|
|
export class ThinkingTimer {
|
|
private readonly durationFormatter = new Intl.NumberFormat("en-US", {
|
|
style: "unit",
|
|
unit: "second",
|
|
unitDisplay: "long",
|
|
minimumFractionDigits: 0,
|
|
maximumFractionDigits: 1,
|
|
});
|
|
|
|
private lastToolResultTimestamp: number | null = null;
|
|
|
|
markToolResult(): void {
|
|
this.lastToolResultTimestamp = performance.now();
|
|
log.debug(`» thinking timer: markToolResult at ${this.lastToolResultTimestamp}`);
|
|
}
|
|
|
|
markToolCall(): void {
|
|
const now = performance.now();
|
|
log.debug(
|
|
`» thinking timer: markToolCall at ${now}, lastToolResult=${this.lastToolResultTimestamp}`
|
|
);
|
|
if (this.lastToolResultTimestamp === null) return;
|
|
const elapsed = now - this.lastToolResultTimestamp;
|
|
if (elapsed < THINKING_THRESHOLD) return;
|
|
const seconds = elapsed / 1000;
|
|
log.info(`» thought for ${this.durationFormatter.format(seconds)}`);
|
|
}
|
|
}
|