Log slow autocompletes

Author: gc

src/lib/discord/autoCompleteHandler.ts

@@ -7,6 +7,7 @@ import {
 } from 'discord.js';
 
 import type { ICommand } from '@/lib/discord/index.js';
+import { DebugStopwatch } from '@/lib/structures/DebugTimer.js';
 
 async function handleAutocomplete(
 	user: MUser,
@@ -58,14 +59,16 @@ async function handleAutocomplete(
 
 export async function autoCompleteHandler(interaction: AutocompleteInteraction) {
 	const member: GuildMember | undefined = interaction.inCachedGuild() ? interaction.member : undefined;
-	const command = globalClient.allCommands.find(c => c.name === interaction.commandName);
+	const command = globalClient.allCommands.find(c => c.name === interaction.commandName)!;
 	const user = await mUserFetch(interaction.user.id);
+	const sw = new DebugStopwatch(`AutoCompleteHandler[${command.name}]`);
 	const choices = await handleAutocomplete(
 		user,
 		command,
 		(interaction.options as any).data as CommandInteractionOption[],
 		member
 	);
+	sw.check(`Got choices`);
 	await interaction.respond(choices);
 	return;
 }

src/lib/structures/DebugTimer.ts

@@ -0,0 +1,79 @@
+export class DebugStopwatch {
+	public digits: number = 2;
+	public name: string;
+	#start: number;
+	#end: number | null;
+	public minLogTimeMs: number;
+
+	public constructor(name: string, minLogTimeMs = 100) {
+		this.name = name;
+		this.#start = performance.now();
+		this.#end = null;
+		this.minLogTimeMs = minLogTimeMs;
+	}
+
+	private log(str: string) {
+		Logging.logDebug(`[${this.name}] [${this.toString()}] ${str}`);
+	}
+
+	public get duration(): number {
+		return this.#end ? this.#end - this.#start : performance.now() - this.#start;
+	}
+
+	public get running(): boolean {
+		return Boolean(!this.#end);
+	}
+
+	public restart(): this {
+		this.#start = performance.now();
+		this.#end = null;
+		return this;
+	}
+
+	public reset(): this {
+		this.#start = performance.now();
+		this.#end = this.#start;
+		return this;
+	}
+
+	public start(): this {
+		if (!this.running) {
+			this.#start = performance.now() - this.duration;
+			this.#end = null;
+		}
+
+		return this;
+	}
+
+	public stop(text?: string): this {
+		if (this.running) this.#end = performance.now();
+		if (text) {
+			this.log(text);
+		}
+		return this;
+	}
+
+	private timeToString(time: number): string {
+		if (time >= 1000) return `${(time / 1000).toFixed(this.digits)}s`;
+		if (time >= 1) return `${time.toFixed(this.digits)}ms`;
+		return `${(time * 1000).toFixed(this.digits)}μs`;
+	}
+
+	public toString(): string {
+		return this.timeToString(this.duration);
+	}
+
+	public lastCheckpoint: number | null = null;
+	public check(text?: string) {
+		const checkTime = performance.now() - (this.lastCheckpoint ?? this.#start);
+		this.lastCheckpoint = performance.now();
+
+		if (text) {
+			if (checkTime < this.minLogTimeMs) {
+				return;
+			}
+			const checkTimeStr = checkTime > 0 ? `${this.timeToString(checkTime)}` : '';
+			this.log(`${text} in ${checkTimeStr}`);
+		}
+	}
+}