fix(ui): add configurable debug logging for webchat chat events

This commit is contained in:
maxmaxrouge 2026-01-29 13:09:44 +10:00
parent 9bcfb78d8e
commit 1e0123b671
8 changed files with 113 additions and 24 deletions

View File

@ -1,10 +1,18 @@
import { normalizeVerboseLevel } from "../auto-reply/thinking.js"; import { normalizeVerboseLevel } from "../auto-reply/thinking.js";
import { loadConfig } from "../config/config.js"; import { loadConfig } from "../config/config.js";
import { type AgentEventPayload, getAgentRunContext } from "../infra/agent-events.js"; import { type AgentEventPayload, getAgentRunContext } from "../infra/agent-events.js";
import { isTruthyEnvValue } from "../infra/env.js";
import { resolveHeartbeatVisibility } from "../infra/heartbeat-visibility.js"; import { resolveHeartbeatVisibility } from "../infra/heartbeat-visibility.js";
import { loadSessionEntry } from "./session-utils.js"; import { loadSessionEntry } from "./session-utils.js";
import { formatForLog } from "./ws-log.js"; import { formatForLog } from "./ws-log.js";
const debugChatEnabled = isTruthyEnvValue(process.env.CLAWDBOT_DEBUG_CHAT);
const debugChat = (message: string) => {
if (debugChatEnabled) {
console.log(`[DEBUG] ${message}`);
}
};
/** /**
* Check if webchat broadcasts should be suppressed for heartbeat runs. * Check if webchat broadcasts should be suppressed for heartbeat runs.
* Returns true if the run is a heartbeat and showOk is false. * Returns true if the run is a heartbeat and showOk is false.
@ -134,14 +142,14 @@ export function createAgentEventHandler({
clearAgentRunContext, clearAgentRunContext,
}: AgentEventHandlerOptions) { }: AgentEventHandlerOptions) {
const emitChatDelta = (sessionKey: string, clientRunId: string, seq: number, text: string) => { const emitChatDelta = (sessionKey: string, clientRunId: string, seq: number, text: string) => {
console.log( debugChat(
`[DEBUG] emitChatDelta: sessionKey=${sessionKey} runId=${clientRunId} textLen=${text.length}`, `emitChatDelta: sessionKey=${sessionKey} runId=${clientRunId} textLen=${text.length}`,
); );
chatRunState.buffers.set(clientRunId, text); chatRunState.buffers.set(clientRunId, text);
const now = Date.now(); const now = Date.now();
const last = chatRunState.deltaSentAt.get(clientRunId) ?? 0; const last = chatRunState.deltaSentAt.get(clientRunId) ?? 0;
if (now - last < 150) { if (now - last < 150) {
console.log(`[DEBUG] emitChatDelta: throttled (${now - last}ms < 150ms)`); debugChat(`emitChatDelta: throttled (${now - last}ms < 150ms)`);
return; return;
} }
chatRunState.deltaSentAt.set(clientRunId, now); chatRunState.deltaSentAt.set(clientRunId, now);
@ -158,12 +166,12 @@ export function createAgentEventHandler({
}; };
// Suppress webchat broadcast for heartbeat runs when showOk is false // Suppress webchat broadcast for heartbeat runs when showOk is false
const suppressed = shouldSuppressHeartbeatBroadcast(clientRunId); const suppressed = shouldSuppressHeartbeatBroadcast(clientRunId);
console.log(`[DEBUG] emitChatDelta: heartbeatSuppressed=${suppressed}`); debugChat(`emitChatDelta: heartbeatSuppressed=${suppressed}`);
if (!suppressed) { if (!suppressed) {
console.log(`[DEBUG] emitChatDelta: calling broadcast("chat")`); debugChat(`emitChatDelta: calling broadcast("chat")`);
broadcast("chat", payload, { dropIfSlow: true }); broadcast("chat", payload, { dropIfSlow: true });
} }
console.log(`[DEBUG] emitChatDelta: calling nodeSendToSession`); debugChat(`emitChatDelta: calling nodeSendToSession`);
nodeSendToSession(sessionKey, "chat", payload); nodeSendToSession(sessionKey, "chat", payload);
}; };
@ -226,11 +234,11 @@ export function createAgentEventHandler({
}; };
return (evt: AgentEventPayload) => { return (evt: AgentEventPayload) => {
console.log(`[DEBUG] agent event: runId=${evt.runId} stream=${evt.stream} seq=${evt.seq}`); debugChat(`agent event: runId=${evt.runId} stream=${evt.stream} seq=${evt.seq}`);
const chatLink = chatRunState.registry.peek(evt.runId); const chatLink = chatRunState.registry.peek(evt.runId);
console.log(`[DEBUG] chatLink: ${chatLink ? JSON.stringify(chatLink) : "null"}`); debugChat(`chatLink: ${chatLink ? JSON.stringify(chatLink) : "null"}`);
const sessionKey = chatLink?.sessionKey ?? resolveSessionKeyForRun(evt.runId); const sessionKey = chatLink?.sessionKey ?? resolveSessionKeyForRun(evt.runId);
console.log(`[DEBUG] sessionKey: ${sessionKey}`); debugChat(`sessionKey: ${sessionKey}`);
const clientRunId = chatLink?.clientRunId ?? evt.runId; const clientRunId = chatLink?.clientRunId ?? evt.runId;
const isAborted = const isAborted =
chatRunState.abortedRuns.has(clientRunId) || chatRunState.abortedRuns.has(evt.runId); chatRunState.abortedRuns.has(clientRunId) || chatRunState.abortedRuns.has(evt.runId);
@ -262,11 +270,11 @@ export function createAgentEventHandler({
if (sessionKey) { if (sessionKey) {
nodeSendToSession(sessionKey, "agent", agentPayload); nodeSendToSession(sessionKey, "agent", agentPayload);
console.log( debugChat(
`[DEBUG] checking emitChatDelta: isAborted=${isAborted} stream=${evt.stream} hasText=${typeof evt.data?.text === "string"} text="${String(evt.data?.text ?? "").slice(0, 50)}..."`, `checking emitChatDelta: isAborted=${isAborted} stream=${evt.stream} hasText=${typeof evt.data?.text === "string"} text="${String(evt.data?.text ?? "").slice(0, 50)}..."`,
); );
if (!isAborted && evt.stream === "assistant" && typeof evt.data?.text === "string") { if (!isAborted && evt.stream === "assistant" && typeof evt.data?.text === "string") {
console.log(`[DEBUG] calling emitChatDelta`); debugChat(`calling emitChatDelta`);
emitChatDelta(sessionKey, clientRunId, evt.seq, evt.data.text); emitChatDelta(sessionKey, clientRunId, evt.seq, evt.data.text);
} else if (!isAborted && (lifecyclePhase === "end" || lifecyclePhase === "error")) { } else if (!isAborted && (lifecyclePhase === "end" || lifecyclePhase === "error")) {
if (chatLink) { if (chatLink) {

View File

@ -1,6 +1,14 @@
import { randomUUID } from "node:crypto"; import { randomUUID } from "node:crypto";
import fs from "node:fs"; import fs from "node:fs";
import path from "node:path"; import path from "node:path";
import { isTruthyEnvValue } from "../../infra/env.js";
const debugChatEnabled = isTruthyEnvValue(process.env.CLAWDBOT_DEBUG_CHAT);
const debugChat = (message: string) => {
if (debugChatEnabled) {
console.log(`[DEBUG] ${message}`);
}
};
import { CURRENT_SESSION_VERSION } from "@mariozechner/pi-coding-agent"; import { CURRENT_SESSION_VERSION } from "@mariozechner/pi-coding-agent";
import { resolveSessionAgentId } from "../../agents/agent-scope.js"; import { resolveSessionAgentId } from "../../agents/agent-scope.js";
@ -200,8 +208,12 @@ export const chatHandlers: GatewayRequestHandlers = {
}; };
const { cfg, storePath, entry } = loadSessionEntry(sessionKey); const { cfg, storePath, entry } = loadSessionEntry(sessionKey);
const sessionId = entry?.sessionId; const sessionId = entry?.sessionId;
debugChat(
`chat.history: sessionKey="${sessionKey}" sessionId="${sessionId}" storePath="${storePath}" hasEntry=${!!entry}`,
);
const rawMessages = const rawMessages =
sessionId && storePath ? readSessionMessages(sessionId, storePath, entry?.sessionFile) : []; sessionId && storePath ? readSessionMessages(sessionId, storePath, entry?.sessionFile) : [];
debugChat(`chat.history: rawMessages.length=${rawMessages.length}`);
const hardMax = 1000; const hardMax = 1000;
const defaultLimit = 200; const defaultLimit = 200;
const requested = typeof limit === "number" ? limit : defaultLimit; const requested = typeof limit === "number" ? limit : defaultLimit;

View File

@ -10,6 +10,7 @@ import type { Tab } from "./navigation";
import type { UiSettings } from "./storage"; import type { UiSettings } from "./storage";
import { handleAgentEvent, resetToolStream, type AgentEventPayload } from "./app-tool-stream"; import { handleAgentEvent, resetToolStream, type AgentEventPayload } from "./app-tool-stream";
import { flushChatQueueForEvent } from "./app-chat"; import { flushChatQueueForEvent } from "./app-chat";
import { debug } from "./debug";
import { import {
applySettings, applySettings,
loadCron, loadCron,
@ -81,10 +82,10 @@ function normalizeSessionKeyForDefaults(
} }
function applySessionDefaults(host: GatewayHost, defaults?: SessionDefaultsSnapshot) { function applySessionDefaults(host: GatewayHost, defaults?: SessionDefaultsSnapshot) {
console.log(`[DEBUG UI] applySessionDefaults: defaults=${JSON.stringify(defaults)}`); debug(`applySessionDefaults: defaults=${JSON.stringify(defaults)}`);
console.log(`[DEBUG UI] applySessionDefaults: host.sessionKey="${host.sessionKey}" host.settings.sessionKey="${host.settings.sessionKey}"`); debug(`applySessionDefaults: host.sessionKey="${host.sessionKey}" host.settings.sessionKey="${host.settings.sessionKey}"`);
if (!defaults?.mainSessionKey) { if (!defaults?.mainSessionKey) {
console.log(`[DEBUG UI] applySessionDefaults: no mainSessionKey, returning early`); debug(`applySessionDefaults: no mainSessionKey, returning early`);
return; return;
} }
const resolvedSessionKey = normalizeSessionKeyForDefaults(host.sessionKey, defaults); const resolvedSessionKey = normalizeSessionKeyForDefaults(host.sessionKey, defaults);
@ -96,7 +97,7 @@ function applySessionDefaults(host: GatewayHost, defaults?: SessionDefaultsSnaps
host.settings.lastActiveSessionKey, host.settings.lastActiveSessionKey,
defaults, defaults,
); );
console.log(`[DEBUG UI] applySessionDefaults: resolved="${resolvedSessionKey}" settingsResolved="${resolvedSettingsSessionKey}"`); debug(`applySessionDefaults: resolved="${resolvedSessionKey}" settingsResolved="${resolvedSettingsSessionKey}"`);
const nextSessionKey = resolvedSessionKey || resolvedSettingsSessionKey || host.sessionKey; const nextSessionKey = resolvedSessionKey || resolvedSettingsSessionKey || host.sessionKey;
const nextSettings = { const nextSettings = {
...host.settings, ...host.settings,
@ -106,9 +107,9 @@ function applySessionDefaults(host: GatewayHost, defaults?: SessionDefaultsSnaps
const shouldUpdateSettings = const shouldUpdateSettings =
nextSettings.sessionKey !== host.settings.sessionKey || nextSettings.sessionKey !== host.settings.sessionKey ||
nextSettings.lastActiveSessionKey !== host.settings.lastActiveSessionKey; nextSettings.lastActiveSessionKey !== host.settings.lastActiveSessionKey;
console.log(`[DEBUG UI] applySessionDefaults: nextSessionKey="${nextSessionKey}" shouldUpdate=${shouldUpdateSettings}`); debug(`applySessionDefaults: nextSessionKey="${nextSessionKey}" shouldUpdate=${shouldUpdateSettings}`);
if (nextSessionKey !== host.sessionKey) { if (nextSessionKey !== host.sessionKey) {
console.log(`[DEBUG UI] applySessionDefaults: updating host.sessionKey from "${host.sessionKey}" to "${nextSessionKey}"`); debug(`applySessionDefaults: updating host.sessionKey from "${host.sessionKey}" to "${nextSessionKey}"`);
host.sessionKey = nextSessionKey; host.sessionKey = nextSessionKey;
} }
if (shouldUpdateSettings) { if (shouldUpdateSettings) {
@ -197,13 +198,18 @@ function handleGatewayEventUnsafe(host: GatewayHost, evt: GatewayEventFrame) {
); );
} }
const state = handleChatEvent(host as unknown as MoltbotApp, payload); const state = handleChatEvent(host as unknown as MoltbotApp, payload);
// Force Lit to re-render after chatStream mutation
if (state === "delta") {
(host as unknown as MoltbotApp).requestUpdate();
}
if (state === "final" || state === "error" || state === "aborted") { if (state === "final" || state === "error" || state === "aborted") {
resetToolStream(host as unknown as Parameters<typeof resetToolStream>[0]); resetToolStream(host as unknown as Parameters<typeof resetToolStream>[0]);
void flushChatQueueForEvent( void flushChatQueueForEvent(
host as unknown as Parameters<typeof flushChatQueueForEvent>[0], host as unknown as Parameters<typeof flushChatQueueForEvent>[0],
); );
} }
if (state === "final") void loadChatHistory(host as unknown as MoltbotApp); // Don't call loadChatHistory - we already added the message from the final payload
// loadChatHistory returns 0 messages because the session transcript file doesn't exist
return; return;
} }

View File

@ -3,6 +3,7 @@ import { html, nothing } from "lit";
import type { GatewayBrowserClient, GatewayHelloOk } from "./gateway"; import type { GatewayBrowserClient, GatewayHelloOk } from "./gateway";
import type { AppViewState } from "./app-view-state"; import type { AppViewState } from "./app-view-state";
import { parseAgentSessionKey } from "../../../src/routing/session-key.js"; import { parseAgentSessionKey } from "../../../src/routing/session-key.js";
import { debug } from "./debug";
import { import {
TAB_GROUPS, TAB_GROUPS,
iconForTab, iconForTab,
@ -427,7 +428,7 @@ export function renderApp(state: AppViewState) {
: nothing} : nothing}
${state.tab === "chat" ${state.tab === "chat"
? renderChat({ ? (() => { debug(`RENDER chatStream="${state.chatStream?.slice(0, 50) ?? "null"}..." chatRunId="${state.chatRunId}" messages=${state.chatMessages?.length ?? 0}`); return renderChat({
sessionKey: state.sessionKey, sessionKey: state.sessionKey,
onSessionKeyChange: (next) => { onSessionKeyChange: (next) => {
state.sessionKey = next; state.sessionKey = next;
@ -497,7 +498,7 @@ export function renderApp(state: AppViewState) {
onSplitRatioChange: (ratio: number) => state.handleSplitRatioChange(ratio), onSplitRatioChange: (ratio: number) => state.handleSplitRatioChange(ratio),
assistantName: state.assistantName, assistantName: state.assistantName,
assistantAvatar: state.assistantAvatar, assistantAvatar: state.assistantAvatar,
}) }); })()
: nothing} : nothing}
${state.tab === "config" ${state.tab === "config"

View File

@ -16,6 +16,7 @@ import { startThemeTransition, type ThemeTransitionContext } from "./theme-trans
import { scheduleChatScroll, scheduleLogsScroll } from "./app-scroll"; import { scheduleChatScroll, scheduleLogsScroll } from "./app-scroll";
import { startLogsPolling, stopLogsPolling, startDebugPolling, stopDebugPolling } from "./app-polling"; import { startLogsPolling, stopLogsPolling, startDebugPolling, stopDebugPolling } from "./app-polling";
import { refreshChat } from "./app-chat"; import { refreshChat } from "./app-chat";
import { setDebugEnabled } from "./debug";
import type { MoltbotApp } from "./app"; import type { MoltbotApp } from "./app";
type SettingsHost = { type SettingsHost = {
@ -43,6 +44,7 @@ export function applySettings(host: SettingsHost, next: UiSettings) {
}; };
host.settings = normalized; host.settings = normalized;
saveSettings(normalized); saveSettings(normalized);
setDebugEnabled(normalized.debugLogs);
if (next.theme !== host.theme) { if (next.theme !== host.theme) {
host.theme = next.theme; host.theme = next.theme;
applyResolvedTheme(host, resolveTheme(next.theme)); applyResolvedTheme(host, resolveTheme(next.theme));

View File

@ -2,6 +2,7 @@ import { extractText } from "../chat/message-extract";
import type { GatewayBrowserClient } from "../gateway"; import type { GatewayBrowserClient } from "../gateway";
import { generateUUID } from "../uuid"; import { generateUUID } from "../uuid";
import type { ChatAttachment } from "../ui-types"; import type { ChatAttachment } from "../ui-types";
import { debug } from "../debug";
export type ChatState = { export type ChatState = {
client: GatewayBrowserClient | null; client: GatewayBrowserClient | null;
@ -28,7 +29,11 @@ export type ChatEventPayload = {
}; };
export async function loadChatHistory(state: ChatState) { export async function loadChatHistory(state: ChatState) {
if (!state.client || !state.connected) return; debug(`loadChatHistory: starting, sessionKey="${state.sessionKey}"`);
if (!state.client || !state.connected) {
debug(`loadChatHistory: aborted - not connected`);
return;
}
state.chatLoading = true; state.chatLoading = true;
state.lastError = null; state.lastError = null;
try { try {
@ -36,9 +41,11 @@ export async function loadChatHistory(state: ChatState) {
sessionKey: state.sessionKey, sessionKey: state.sessionKey,
limit: 200, limit: 200,
})) as { messages?: unknown[]; thinkingLevel?: string | null }; })) as { messages?: unknown[]; thinkingLevel?: string | null };
debug(`loadChatHistory: got ${res.messages?.length ?? 0} messages`);
state.chatMessages = Array.isArray(res.messages) ? res.messages : []; state.chatMessages = Array.isArray(res.messages) ? res.messages : [];
state.chatThinkingLevel = res.thinkingLevel ?? null; state.chatThinkingLevel = res.thinkingLevel ?? null;
} catch (err) { } catch (err) {
debug(`loadChatHistory: error - ${err}`);
state.lastError = String(err); state.lastError = String(err);
} finally { } finally {
state.chatLoading = false; state.chatLoading = false;
@ -159,10 +166,11 @@ export function handleChatEvent(
state: ChatState, state: ChatState,
payload?: ChatEventPayload, payload?: ChatEventPayload,
) { ) {
console.log(`[DEBUG UI] handleChatEvent: payload.sessionKey="${payload?.sessionKey}" state.sessionKey="${state.sessionKey}"`); debug(`handleChatEvent: payload.sessionKey="${payload?.sessionKey}" state.sessionKey="${state.sessionKey}"`);
debug(`handleChatEvent: payload.runId="${payload?.runId}" state.chatRunId="${state.chatRunId}" payload.state="${payload?.state}"`);
if (!payload) return null; if (!payload) return null;
if (payload.sessionKey !== state.sessionKey) { if (payload.sessionKey !== state.sessionKey) {
console.log(`[DEBUG UI] handleChatEvent: sessionKey mismatch, ignoring event`); debug(`handleChatEvent: sessionKey mismatch, ignoring event`);
return null; return null;
} }
@ -173,19 +181,27 @@ export function handleChatEvent(
state.chatRunId && state.chatRunId &&
payload.runId !== state.chatRunId payload.runId !== state.chatRunId
) { ) {
debug(`handleChatEvent: runId mismatch (payload=${payload.runId} state=${state.chatRunId}), dropping non-final`);
if (payload.state === "final") return "final"; if (payload.state === "final") return "final";
return null; return null;
} }
if (payload.state === "delta") { if (payload.state === "delta") {
const next = extractText(payload.message); const next = extractText(payload.message);
debug(`handleChatEvent: delta event, extracted text="${next?.slice(0, 50)}..."`);
if (typeof next === "string") { if (typeof next === "string") {
const current = state.chatStream ?? ""; const current = state.chatStream ?? "";
if (!current || next.length >= current.length) { if (!current || next.length >= current.length) {
debug(`handleChatEvent: updating chatStream (len ${current.length} -> ${next.length})`);
state.chatStream = next; state.chatStream = next;
} }
} }
} else if (payload.state === "final") { } else if (payload.state === "final") {
// Add the final message to chatMessages if present
if (payload.message) {
debug(`handleChatEvent: final with message, adding to chatMessages`);
state.chatMessages = [...state.chatMessages, payload.message];
}
state.chatStream = null; state.chatStream = null;
state.chatRunId = null; state.chatRunId = null;
state.chatStreamStartedAt = null; state.chatStreamStartedAt = null;

38
ui/src/ui/debug.ts Normal file
View File

@ -0,0 +1,38 @@
/**
* Debug logging utility for the UI.
* Controlled by the debugLogs setting in UI settings.
* Can also be enabled via:
* - localStorage.setItem('moltbot-ui-debug', 'true')
* - window.MOLTBOT_UI_DEBUG = true
*/
declare global {
interface Window {
MOLTBOT_UI_DEBUG?: boolean;
}
}
let debugEnabled = false;
export function setDebugEnabled(enabled: boolean): void {
debugEnabled = enabled;
}
export function isDebugEnabled(): boolean {
if (debugEnabled) return true;
if (typeof window !== "undefined") {
if (window.MOLTBOT_UI_DEBUG) return true;
try {
return localStorage.getItem("moltbot-ui-debug") === "true";
} catch {
return false;
}
}
return false;
}
export function debug(message: string, ...args: unknown[]): void {
if (isDebugEnabled()) {
console.log(`[DEBUG UI] ${message}`, ...args);
}
}

View File

@ -13,6 +13,7 @@ export type UiSettings = {
splitRatio: number; // Sidebar split ratio (0.4 to 0.7, default 0.6) splitRatio: number; // Sidebar split ratio (0.4 to 0.7, default 0.6)
navCollapsed: boolean; // Collapsible sidebar state navCollapsed: boolean; // Collapsible sidebar state
navGroupsCollapsed: Record<string, boolean>; // Which nav groups are collapsed navGroupsCollapsed: Record<string, boolean>; // Which nav groups are collapsed
debugLogs: boolean; // Enable verbose debug logging in browser console
}; };
export function loadSettings(): UiSettings { export function loadSettings(): UiSettings {
@ -32,6 +33,7 @@ export function loadSettings(): UiSettings {
splitRatio: 0.6, splitRatio: 0.6,
navCollapsed: false, navCollapsed: false,
navGroupsCollapsed: {}, navGroupsCollapsed: {},
debugLogs: false,
}; };
try { try {
@ -84,6 +86,10 @@ export function loadSettings(): UiSettings {
parsed.navGroupsCollapsed !== null parsed.navGroupsCollapsed !== null
? parsed.navGroupsCollapsed ? parsed.navGroupsCollapsed
: defaults.navGroupsCollapsed, : defaults.navGroupsCollapsed,
debugLogs:
typeof parsed.debugLogs === "boolean"
? parsed.debugLogs
: defaults.debugLogs,
}; };
} catch { } catch {
return defaults; return defaults;