fix(desktop): batch debug log writes to avoid UI stalls

This commit is contained in:
zipg
2026-09-27 10:36:55 +08:00
committed by GitHub
parent b3f78b5871
commit e092e5bae9
2 changed files with 115 additions and 4 deletions
+48 -1
View File
@@ -1,5 +1,5 @@
import { afterEach, beforeEach, describe, expect, it, vi } from "vitest";
import { appendDebugLog, formatLocalTimestamp, formatLocalTimestampForFilename, formatLocalTimezoneOffset, getDebugLogText, padNumber } from "@/lib/backend/debugLog";
import { appendDebugLog, clearDebugLogs, formatLocalTimestamp, formatLocalTimestampForFilename, formatLocalTimezoneOffset, getDebugLogText, padNumber } from "@/lib/backend/debugLog";
class MemoryStorage implements Storage {
private data = new Map<string, string>();
@@ -46,6 +46,7 @@ beforeEach(() => {
configurable: true,
value: new MemoryStorage(),
});
clearDebugLogs();
});
afterEach(() => {
@@ -54,6 +55,52 @@ afterEach(() => {
else Reflect.deleteProperty(globalThis, "localStorage");
});
describe("debug log write batching", () => {
it("does not rewrite the stored buffer on every appended entry", () => {
vi.useFakeTimers();
localStorage.setItem(DEBUG_LOG_ENABLED_KEY, "1");
const setItem = vi.spyOn(localStorage, "setItem");
for (let index = 0; index < 200; index += 1) appendDebugLog("info", `entry-${index}`);
const entryWrites = () => setItem.mock.calls.filter(([key]) => key === "dbx-debug-log-entries");
expect(entryWrites().length).toBe(0);
// Pending entries are readable before they are persisted.
expect(getDebugLogText()).toContain("entry-199");
vi.advanceTimersByTime(250);
const writes = entryWrites();
expect(writes.length).toBe(1);
const stored = JSON.parse(String(writes[0][1])) as { message: string }[];
expect(stored.length).toBe(200);
expect(stored[199].message).toContain("entry-199");
});
it("persists error entries without waiting for the flush delay", () => {
vi.useFakeTimers();
localStorage.setItem(DEBUG_LOG_ENABLED_KEY, "1");
const setItem = vi.spyOn(localStorage, "setItem");
appendDebugLog("error", "boom");
const writes = setItem.mock.calls.filter(([key]) => key === "dbx-debug-log-entries");
expect(writes.length).toBe(1);
expect(String(writes[0][1])).toContain("boom");
});
it("re-reads the stored buffer when it changes underneath the cache", () => {
localStorage.setItem(DEBUG_LOG_ENABLED_KEY, "1");
localStorage.setItem("dbx-debug-log-entries", JSON.stringify([{ timestamp: "t", level: "info", message: "external" }]));
appendDebugLog("info", "local");
const text = getDebugLogText();
expect(text).toContain("external");
expect(text).toContain("local");
});
});
describe("debug log local timestamps", () => {
it("pads date and time parts", () => {
expect(padNumber(7)).toBe("07");
+67 -3
View File
@@ -56,8 +56,19 @@ export function isDebugLoggingEnabled(): boolean {
return safeLocalStorageGet(DEBUG_LOG_ENABLED_KEY) === "1";
}
function readEntries(): DebugLogEntry[] {
const raw = safeLocalStorageGet(DEBUG_LOG_ENTRIES_KEY);
// The stored value is the whole entry array, so re-reading it costs a JSON
// parse and rewriting it costs a JSON stringify plus a synchronous
// localStorage write. Doing that per console call made every click and menu
// interaction on a large document rewrite a multi-hundred-KB buffer, which is
// itself a long task. Keep the parsed array as the working copy, only re-parse
// when the stored value changed underneath us, and write back in batches.
const DEBUG_LOG_FLUSH_DELAY_MS = 200;
const DEBUG_LOG_FLUSH_HOOK_INSTALLED_KEY = "__dbxDebugLogFlushHook";
let cachedRawEntries: string | null = null;
let cachedEntries: DebugLogEntry[] = [];
let pendingFlushTimer: ReturnType<typeof setTimeout> | null = null;
function parseEntries(raw: string | null): DebugLogEntry[] {
if (!raw) return [];
try {
const parsed = JSON.parse(raw);
@@ -67,6 +78,50 @@ function readEntries(): DebugLogEntry[] {
}
}
function readEntries(): DebugLogEntry[] {
const raw = safeLocalStorageGet(DEBUG_LOG_ENTRIES_KEY);
if (raw !== cachedRawEntries) {
cachedRawEntries = raw;
cachedEntries = parseEntries(raw);
}
return cachedEntries;
}
function flushEntries() {
if (pendingFlushTimer !== null) {
clearTimeout(pendingFlushTimer);
pendingFlushTimer = null;
}
const serialized = JSON.stringify(cachedEntries.slice(-MAX_DEBUG_LOG_ENTRIES));
cachedRawEntries = serialized;
safeLocalStorageSet(DEBUG_LOG_ENTRIES_KEY, serialized);
}
function scheduleEntriesFlush(immediate: boolean) {
if (immediate) {
flushEntries();
return;
}
if (pendingFlushTimer !== null) return;
pendingFlushTimer = setTimeout(() => {
pendingFlushTimer = null;
flushEntries();
}, DEBUG_LOG_FLUSH_DELAY_MS);
}
// A pending batch would be lost when the WebView is torn down or hidden.
function installEntriesFlushHooks() {
const host = globalThis as Record<string, unknown>;
if (host[DEBUG_LOG_FLUSH_HOOK_INSTALLED_KEY]) return;
host[DEBUG_LOG_FLUSH_HOOK_INSTALLED_KEY] = true;
if (typeof window !== "undefined") window.addEventListener("pagehide", () => flushEntries());
if (typeof document !== "undefined") {
document.addEventListener("visibilitychange", () => {
if (document.visibilityState === "hidden") flushEntries();
});
}
}
function redactSensitiveText(value: string): string {
return value.replace(/("[^"]*(?:password|passphrase|api[_-]?key|token|secret|jwt|connection[_-]?string)[^"]*"\s*:\s*")([^"]*)(")/gi, "$1[redacted]$3").replace(/\b([^=&\s]*(?:password|passphrase|api[_-]?key|token|secret|jwt)[^=&\s]*)=([^&\s]+)/gi, "$1=[redacted]");
}
@@ -127,7 +182,9 @@ export function appendDebugLog(level: DebugLogLevel, ...args: unknown[]) {
level,
message: formatArgs(args),
});
safeLocalStorageSet(DEBUG_LOG_ENTRIES_KEY, JSON.stringify(entries.slice(-MAX_DEBUG_LOG_ENTRIES)));
if (entries.length > MAX_DEBUG_LOG_ENTRIES) entries.splice(0, entries.length - MAX_DEBUG_LOG_ENTRIES);
// Errors are the entries most likely to be needed after a crash.
scheduleEntriesFlush(level === "error");
}
export function getBrowserMemorySnapshot(): BrowserMemorySnapshot {
@@ -173,6 +230,12 @@ export function setDebugLoggingEnabled(enabled: boolean) {
}
export function clearDebugLogs() {
if (pendingFlushTimer !== null) {
clearTimeout(pendingFlushTimer);
pendingFlushTimer = null;
}
cachedRawEntries = null;
cachedEntries = [];
safeLocalStorageRemove(DEBUG_LOG_ENTRIES_KEY);
}
@@ -229,6 +292,7 @@ function isTauriRuntimeLike(): boolean {
export function installDebugLogCapture() {
if (installed) return;
installed = true;
installEntriesFlushHooks();
originalConsole = {
debug: console.debug.bind(console),
info: console.info.bind(console),