diff --git a/src/index.ts b/src/index.ts index 57e1ef6..85be091 100644 --- a/src/index.ts +++ b/src/index.ts @@ -23,10 +23,7 @@ import { getRegisteredChannelNames, } from './channels/registry.js'; import { - AgentOutput, - runAgentProcess, writeGroupsSnapshot, - writeTasksSnapshot, } from './agent-runner.js'; import { getAllChats, @@ -34,32 +31,23 @@ import { getAllSessions, getAllTasks, getLatestMessageSeqAtOrBefore, - getMessagesSinceSeq, - getNewMessagesBySeq, - getOpenWorkItem, hasRecentRestartAnnouncement, getRegisteredGroup, getRouterState, initDatabase, - isPairedRoomJid, - markWorkItemDelivered, - markWorkItemDeliveryRetry, setRegisteredGroup, setRouterState, updateRegisteredGroupName, deleteSession, setSession, storeChatMetadata, - createProducedWorkItem, storeMessage, - WorkItem, } from './db.js'; -import { filterProcessableMessages } from './bot-message-filter.js'; import { GroupQueue } from './group-queue.js'; import { readEnvFile } from './env.js'; import { resolveGroupFolderPath } from './group-folder.js'; import { startIpcWatcher } from './ipc.js'; -import { findChannel, formatMessages, formatOutbound } from './router.js'; +import { findChannel, formatOutbound } from './router.js'; import { buildRestartAnnouncement, buildInterruptedRestartAnnouncement, @@ -73,21 +61,7 @@ import { loadSenderAllowlist, shouldDropMessage, } from './sender-allowlist.js'; -import { - extractSessionCommand, - handleSessionCommand, - isSessionCommandAllowed, -} from './session-commands.js'; -import { - detectFallbackTrigger, - getActiveProvider, - getFallbackEnvOverrides, - getFallbackProviderName, - hasGroupProviderOverride, - isFallbackEnabled, - markPrimaryCooldown, -} from './provider-fallback.js'; -import { shouldResetSessionOnAgentFailure } from './session-recovery.js'; +import { createMessageRuntime } from './message-runtime.js'; import { readStatusSnapshots, writeStatusSnapshot, @@ -148,10 +122,31 @@ let lastTimestamp = ''; let sessions: Record = {}; let registeredGroups: Record = {}; let lastAgentTimestamp: Record = {}; -let messageLoopRunning = false; const channels: Channel[] = []; const queue = new GroupQueue(); +const runtime = createMessageRuntime({ + assistantName: ASSISTANT_NAME, + idleTimeout: IDLE_TIMEOUT, + pollInterval: POLL_INTERVAL, + timezone: TIMEZONE, + triggerPattern: TRIGGER_PATTERN, + channels, + queue, + getRegisteredGroups: () => registeredGroups, + getSessions: () => sessions, + getLastTimestamp: () => lastTimestamp, + setLastTimestamp: (timestamp) => { + lastTimestamp = timestamp; + }, + getLastAgentTimestamps: () => lastAgentTimestamp, + saveState, + persistSession: (groupFolder, sessionId) => { + sessions[groupFolder] = sessionId; + setSession(groupFolder, sessionId); + }, + clearSession, +}); function normalizeStoredSeqCursor( cursor: string | undefined, @@ -162,62 +157,6 @@ function normalizeStoredSeqCursor( return String(getLatestMessageSeqAtOrBefore(cursor, chatJid)); } -function advanceLastAgentCursor( - chatJid: string, - cursorOrTimestamp: string | number, -): void { - if (typeof cursorOrTimestamp === 'number') { - lastAgentTimestamp[chatJid] = String(cursorOrTimestamp); - } else { - lastAgentTimestamp[chatJid] = normalizeStoredSeqCursor( - cursorOrTimestamp, - chatJid, - ); - } - saveState(); -} - -function getProcessableMessages( - chatJid: string, - messages: NewMessage[], - channel?: import('./types.js').Channel, -): NewMessage[] { - const isOwn = channel?.isOwnMessage?.bind(channel); - return filterProcessableMessages(messages, isPairedRoomJid(chatJid), isOwn); -} - -async function deliverOpenWorkItem( - channel: Channel, - item: WorkItem, -): Promise { - try { - await channel.sendMessage(item.chat_jid, item.result_payload); - markWorkItemDelivered(item.id); - logger.info( - { - chatJid: item.chat_jid, - workItemId: item.id, - deliveryAttempts: item.delivery_attempts + 1, - }, - 'Delivered produced work item', - ); - return true; - } catch (err) { - const errorMessage = err instanceof Error ? err.message : String(err); - markWorkItemDeliveryRetry(item.id, errorMessage); - logger.warn( - { - chatJid: item.chat_jid, - workItemId: item.id, - deliveryAttempts: item.delivery_attempts + 1, - err, - }, - 'Failed to deliver produced work item', - ); - return false; - } -} - function loadState(): void { lastTimestamp = normalizeStoredSeqCursor( getRouterState('last_seq') || getRouterState('last_timestamp'), @@ -310,868 +249,6 @@ export function _setRegisteredGroups( registeredGroups = groups; } -/** - * Process all pending messages for a group. - * Called by the GroupQueue when it's this group's turn. - */ -async function processGroupMessages(chatJid: string): Promise { - const group = registeredGroups[chatJid]; - if (!group) return true; - - const channel = findChannel(channels, chatJid); - if (!channel) { - logger.warn({ chatJid }, 'No channel owns JID, skipping messages'); - return true; - } - - const openWorkItem = getOpenWorkItem( - chatJid, - (group.agentType || 'claude-code') as 'claude-code' | 'codex', - ); - if (openWorkItem) { - const delivered = await deliverOpenWorkItem(channel, openWorkItem); - if (!delivered) { - return false; - } - } - - const isMainGroup = group.isMain === true; - - const sinceSeqCursor = lastAgentTimestamp[chatJid] || '0'; - const rawMissedMessages = getMessagesSinceSeq( - chatJid, - sinceSeqCursor, - ASSISTANT_NAME, - ); - const missedMessages = getProcessableMessages( - chatJid, - rawMissedMessages, - channel, - ); - - if (missedMessages.length === 0) { - const lastIgnored = rawMissedMessages[rawMissedMessages.length - 1]; - if (lastIgnored) { - advanceLastAgentCursor(chatJid, lastIgnored.timestamp); - } - return true; - } - - // --- Session command interception (before trigger check) --- - const cmdResult = await handleSessionCommand({ - missedMessages, - isMainGroup, - groupName: group.name, - triggerPattern: TRIGGER_PATTERN, - timezone: TIMEZONE, - deps: { - sendMessage: (text) => channel.sendMessage(chatJid, text), - setTyping: (typing) => - channel.setTyping?.(chatJid, typing) ?? Promise.resolve(), - runAgent: (prompt, onOutput) => - runAgent(group, prompt, chatJid, onOutput), - closeStdin: () => - queue.closeStdin(chatJid, { - reason: 'session-command', - }), - clearSession: () => clearSession(group.folder), - advanceCursor: (ts) => { - advanceLastAgentCursor(chatJid, ts); - }, - formatMessages, - isAdminSender: (msg) => isSessionCommandSenderAllowed(msg.sender), - canSenderInteract: (msg) => { - const hasTrigger = TRIGGER_PATTERN.test(msg.content.trim()); - const reqTrigger = !isMainGroup && group.requiresTrigger !== false; - return ( - isMainGroup || - !reqTrigger || - (hasTrigger && - (msg.is_from_me || - isTriggerAllowed(chatJid, msg.sender, loadSenderAllowlist()))) - ); - }, - }, - }); - if (cmdResult.handled) return cmdResult.success; - // --- End session command interception --- - - // For non-main groups, check if trigger is required and present - if (!isMainGroup && group.requiresTrigger !== false) { - const allowlistCfg = loadSenderAllowlist(); - const hasTrigger = missedMessages.some( - (m) => - TRIGGER_PATTERN.test(m.content.trim()) && - (m.is_from_me || isTriggerAllowed(chatJid, m.sender, allowlistCfg)), - ); - if (!hasTrigger) { - return true; - } - } - - const prompt = formatMessages(missedMessages, TIMEZONE); - - // Advance cursor so the piping path in startMessageLoop won't re-fetch - // these messages. Save the old cursor so we can roll back on error. - const previousCursor = lastAgentTimestamp[chatJid] || '0'; - const startSeq = missedMessages[0].seq ?? null; - const endSeq = missedMessages[missedMessages.length - 1].seq ?? null; - if (endSeq !== null) { - advanceLastAgentCursor(chatJid, endSeq); - } - - logger.info( - { group: group.name, messageCount: missedMessages.length }, - 'Processing messages', - ); - - // Track idle timer for closing stdin when agent is idle - let idleTimer: ReturnType | null = null; - let producedFinalText: string | null = null; - - const resetIdleTimer = () => { - if (idleTimer) clearTimeout(idleTimer); - idleTimer = setTimeout(() => { - logger.debug({ group: group.name }, 'Idle timeout, closing agent stdin'); - if (followUpQueuedAt !== null) { - logger.warn( - { - group: group.name, - chatJid, - followUpQueuedAt: new Date(followUpQueuedAt).toISOString(), - followUpQueuedTextLength, - followUpQueuedFilename, - followUpWaitMs: Date.now() - followUpQueuedAt, - }, - 'Idle timeout reached while a queued follow-up still had no agent output', - ); - } - queue.closeStdin(chatJid, { reason: 'idle-timeout' }); - }, IDLE_TIMEOUT); - }; - let followUpQueuedAt: number | null = null; - let followUpQueuedTextLength: number | null = null; - let followUpQueuedFilename: string | null = null; - let followUpNoOutputWarnTimer: ReturnType | null = null; - const FOLLOW_UP_NO_OUTPUT_WARN_MS = 10_000; - - const clearFollowUpNoOutputWarnTimer = () => { - if (followUpNoOutputWarnTimer) { - clearTimeout(followUpNoOutputWarnTimer); - followUpNoOutputWarnTimer = null; - } - }; - - const clearPendingFollowUpDiagnostics = () => { - clearFollowUpNoOutputWarnTimer(); - followUpQueuedAt = null; - followUpQueuedTextLength = null; - followUpQueuedFilename = null; - }; - - const scheduleFollowUpNoOutputWarning = () => { - clearFollowUpNoOutputWarnTimer(); - followUpNoOutputWarnTimer = setTimeout(() => { - if (followUpQueuedAt === null) return; - logger.warn( - { - group: group.name, - chatJid, - followUpQueuedAt: new Date(followUpQueuedAt).toISOString(), - followUpQueuedTextLength, - followUpQueuedFilename, - elapsedMs: Date.now() - followUpQueuedAt, - }, - 'No agent output observed within 10s of queuing a follow-up message', - ); - }, FOLLOW_UP_NO_OUTPUT_WARN_MS); - }; - - const noteFollowUpQueued = (meta?: { - source: 'follow-up'; - textLength: number; - filename: string; - }) => { - if (meta?.source !== 'follow-up') return; - followUpQueuedAt = Date.now(); - followUpQueuedTextLength = meta.textLength; - followUpQueuedFilename = meta.filename; - scheduleFollowUpNoOutputWarning(); - logger.info( - { - group: group.name, - chatJid, - followUpQueuedTextLength, - followUpQueuedFilename, - }, - 'Registered follow-up activity for active agent', - ); - }; - - const noteAgentOutputObserved = (phase?: string) => { - if (followUpQueuedAt === null) return; - logger.info( - { - group: group.name, - chatJid, - followUpQueuedAt: new Date(followUpQueuedAt).toISOString(), - followUpQueuedTextLength, - followUpQueuedFilename, - followUpWaitMs: Date.now() - followUpQueuedAt, - resultPhase: phase, - }, - 'Agent produced output after a queued follow-up', - ); - clearPendingFollowUpDiagnostics(); - }; - - const warnFollowUpEndedWithoutOutput = (reason: string) => { - if (followUpQueuedAt === null) return; - logger.warn( - { - group: group.name, - chatJid, - followUpQueuedAt: new Date(followUpQueuedAt).toISOString(), - followUpQueuedTextLength, - followUpQueuedFilename, - followUpWaitMs: Date.now() - followUpQueuedAt, - reason, - }, - 'Active agent ended a turn without any output after a queued follow-up', - ); - clearPendingFollowUpDiagnostics(); - }; - - queue.setActivityTouch(chatJid, (meta) => { - noteFollowUpQueued(meta); - resetIdleTimer(); - }); - - let hadError = false; - let latestProgressText: string | null = null; - let latestProgressRendered: string | null = null; - let progressMessageId: string | null = null; - let progressStartedAt: number | null = null; - let progressTicker: ReturnType | null = null; - let finalOutputSentToUser = false; - let progressOutputSentToUser = false; - let latestModelProgressTextForFinalFallback: string | null = null; - let sawNonProgressOutput = false; - let producedDeliverySucceeded = true; - let isFirstLogicalTurn = true; - let poisonedSessionDetected = false; - const isClaudeCodeAgent = - (group.agentType || 'claude-code') === 'claude-code'; - - const clearProgressTicker = () => { - if (progressTicker) { - clearInterval(progressTicker); - progressTicker = null; - } - }; - - const resetTurnOutputState = () => { - finalOutputSentToUser = false; - progressOutputSentToUser = false; - latestModelProgressTextForFinalFallback = null; - sawNonProgressOutput = false; - producedFinalText = null; - }; - - const flushProducedFinalText = async () => { - if (!producedFinalText) { - return; - } - - try { - const workItem = createProducedWorkItem({ - group_folder: group.folder, - chat_jid: chatJid, - agent_type: group.agentType || 'claude-code', - start_seq: isFirstLogicalTurn ? startSeq : null, - end_seq: isFirstLogicalTurn ? endSeq : null, - result_payload: producedFinalText, - }); - const delivered = await deliverOpenWorkItem(channel, workItem); - if (delivered) { - finalOutputSentToUser = true; - } else { - producedDeliverySucceeded = false; - } - } catch (err) { - producedDeliverySucceeded = false; - logger.warn( - { group: group.name, chatJid, err }, - 'Failed to persist produced output for delivery', - ); - } finally { - producedFinalText = null; - latestModelProgressTextForFinalFallback = null; - isFirstLogicalTurn = false; - } - }; - - const resetProgressState = () => { - clearProgressTicker(); - latestProgressText = null; - latestProgressRendered = null; - progressMessageId = null; - progressStartedAt = null; - }; - - const renderProgressMessage = (text: string) => { - const elapsedSeconds = - progressStartedAt === null - ? 0 - : Math.floor((Date.now() - progressStartedAt) / 10_000) * 10; - const hours = Math.floor(elapsedSeconds / 3600); - const minutes = Math.floor((elapsedSeconds % 3600) / 60); - const seconds = elapsedSeconds % 60; - const elapsedParts: string[] = []; - - if (hours > 0) elapsedParts.push(`${hours}시간`); - if (minutes > 0) elapsedParts.push(`${minutes}분`); - elapsedParts.push(`${seconds}초`); - - return `${text}\n\n${elapsedParts.join(' ')}`; - }; - - const syncTrackedProgressMessage = async () => { - if (!progressMessageId || !channel.editMessage || !latestProgressText) { - return; - } - - const rendered = renderProgressMessage(latestProgressText); - if (rendered === latestProgressRendered) { - return; - } - - try { - await channel.editMessage(chatJid, progressMessageId, rendered); - latestProgressRendered = rendered; - } catch { - clearProgressTicker(); - progressMessageId = null; - } - }; - - const ensureProgressTicker = () => { - if (!progressMessageId || !channel.editMessage || progressTicker) { - return; - } - - progressTicker = setInterval(() => { - void syncTrackedProgressMessage(); - }, 10_000); - }; - - const finalizeProgressMessage = async () => { - logger.info( - { group: group.name, chatJid, progressMessageId, latestProgressText }, - 'Finalizing tracked progress message', - ); - await syncTrackedProgressMessage(); - resetProgressState(); - }; - - const sendProgressMessage = async (text: string) => { - if (!text || text === latestProgressText) { - return; - } - - if (progressStartedAt === null) { - resetTurnOutputState(); - progressStartedAt = Date.now(); - } - latestModelProgressTextForFinalFallback = text; - latestProgressText = text; - const rendered = renderProgressMessage(text); - - if (progressMessageId && channel.editMessage) { - logger.info( - { group: group.name, chatJid, progressMessageId, text }, - 'Updating tracked progress message', - ); - await syncTrackedProgressMessage(); - progressOutputSentToUser = true; - return; - } - - if (!channel.sendAndTrack) { - return; - } - - try { - progressMessageId = await channel.sendAndTrack(chatJid, rendered); - } catch (err) { - logger.warn( - { group: group.name, chatJid, err }, - 'Failed to send tracked progress message', - ); - return; - } - if (progressMessageId) { - logger.info( - { group: group.name, chatJid, progressMessageId, text }, - 'Created tracked progress message', - ); - latestProgressRendered = rendered; - ensureProgressTicker(); - progressOutputSentToUser = true; - } - }; - - await channel.setTyping?.(chatJid, true); - - const output = await runAgent(group, prompt, chatJid, async (result) => { - if ( - isClaudeCodeAgent && - shouldResetSessionOnAgentFailure(result) && - !poisonedSessionDetected - ) { - poisonedSessionDetected = true; - hadError = true; - clearSession(group.folder); - queue.closeStdin(chatJid, { - reason: 'poisoned-session-detected', - }); - logger.warn( - { group: group.name, chatJid }, - 'Detected poisoned Claude session from streamed output, forcing close', - ); - } - - if (result.result) { - const raw = - typeof result.result === 'string' - ? result.result - : JSON.stringify(result.result); - const text = formatOutbound(raw); - logger.info( - { - group: group.name, - chatJid, - resultStatus: result.status, - resultPhase: result.phase, - progressMessageId, - }, - `Agent output: ${raw.slice(0, 200)}`, - ); - noteAgentOutputObserved(result.phase); - if (result.phase === 'progress') { - if (finalOutputSentToUser || sawNonProgressOutput) { - logger.info( - { group: group.name, chatJid }, - 'New logical turn detected (follow-up), resetting turn state', - ); - resetTurnOutputState(); - resetProgressState(); - isFirstLogicalTurn = false; - await channel.setTyping?.(chatJid, true); - } - if (text) { - await sendProgressMessage(text); - } - if (!poisonedSessionDetected) { - resetIdleTimer(); - } - return; - } - sawNonProgressOutput = true; - if (text) { - await finalizeProgressMessage(); - producedFinalText = text; - await flushProducedFinalText(); - } else { - logger.info( - { - group: group.name, - chatJid, - resultStatus: result.status, - resultPhase: result.phase, - progressMessageId, - }, - 'Agent output became empty after formatting; resetting tracked progress state', - ); - await finalizeProgressMessage(); - latestModelProgressTextForFinalFallback = null; - } - } else { - if (result.status === 'success') { - warnFollowUpEndedWithoutOutput('success-null-result'); - } - await finalizeProgressMessage(); - } - - // Always clear typing and reset idle timer on any output (including null results) - await channel.setTyping?.(chatJid, false); - if (!poisonedSessionDetected) { - resetIdleTimer(); - } - - if (result.status === 'success' && !poisonedSessionDetected) { - queue.notifyIdle(chatJid); - } - - if (result.status === 'error') { - hadError = true; - } - }); - - await channel.setTyping?.(chatJid, false); - - if (output === 'error') { - hadError = true; - } - - if ( - output === 'success' && - !hadError && - !producedFinalText && - !sawNonProgressOutput && - latestModelProgressTextForFinalFallback - ) { - logger.info( - { group: group.name, chatJid }, - 'Promoting last progress output to final message after agent completion', - ); - producedFinalText = latestModelProgressTextForFinalFallback; - await flushProducedFinalText(); - } - - clearProgressTicker(); - - if (idleTimer) clearTimeout(idleTimer); - clearPendingFollowUpDiagnostics(); - queue.setActivityTouch(chatJid, null); - - if (hadError) { - if ( - finalOutputSentToUser || - progressOutputSentToUser || - producedFinalText - ) { - logger.warn( - { group: group.name }, - 'Agent error after output was produced, skipping cursor rollback to prevent duplicates', - ); - return producedFinalText ? producedDeliverySucceeded : true; - } - lastAgentTimestamp[chatJid] = previousCursor; - saveState(); - logger.warn( - { group: group.name }, - 'Agent error, rolled back message cursor for retry', - ); - return false; - } - - if (!producedDeliverySucceeded) { - logger.warn( - { group: group.name, chatJid }, - 'Persisted produced output for delivery retry without rerunning agent', - ); - return false; - } - - return true; -} - -async function runAgent( - group: RegisteredGroup, - prompt: string, - chatJid: string, - onOutput?: (output: AgentOutput) => Promise, -): Promise<'success' | 'error'> { - const isMain = group.isMain === true; - const sessionId = sessions[group.folder]; - - // Update tasks snapshot for agent to read (filtered by group) - const tasks = getAllTasks(); - writeTasksSnapshot( - group.folder, - isMain, - tasks.map((t) => ({ - id: t.id, - groupFolder: t.group_folder, - prompt: t.prompt, - schedule_type: t.schedule_type, - schedule_value: t.schedule_value, - status: t.status, - next_run: t.next_run, - })), - ); - - // Update available groups snapshot (main group only can see all groups) - const availableGroups = getAvailableGroups(); - writeGroupsSnapshot( - group.folder, - isMain, - availableGroups, - new Set(Object.keys(registeredGroups)), - ); - - const isClaudeCode = (group.agentType || 'claude-code') === 'claude-code'; - const settingsPath = path.join( - DATA_DIR, - 'sessions', - group.folder, - '.claude', - 'settings.json', - ); - const groupHasOverride = hasGroupProviderOverride(settingsPath); - const canFallback = isClaudeCode && isFallbackEnabled() && !groupHasOverride; - - const agentInput = { - prompt, - sessionId, - groupFolder: group.folder, - chatJid, - isMain, - assistantName: ASSISTANT_NAME, - }; - - const runAttempt = async ( - provider: string, - ): Promise<{ - output?: AgentOutput; - error?: unknown; - sawOutput: boolean; - sawSuccessNullResultWithoutOutput: boolean; - streamedTriggerReason?: { - reason: string; - retryAfterMs?: number; - }; - }> => { - const persistSessionIds = provider === 'claude'; - let sawOutput = false; - let sawSuccessNullResultWithoutOutput = false; - let streamedTriggerReason: - | { - reason: string; - retryAfterMs?: number; - } - | undefined; - - const wrappedOnOutput = onOutput - ? async (output: AgentOutput) => { - if (persistSessionIds && output.newSessionId) { - sessions[group.folder] = output.newSessionId; - setSession(group.folder, output.newSessionId); - } - - if (output.result !== null && output.result !== undefined) { - sawOutput = true; - } else if ( - provider === 'claude' && - output.status === 'success' && - !sawOutput - ) { - sawSuccessNullResultWithoutOutput = true; - } - - if ( - provider === 'claude' && - output.status === 'error' && - !sawOutput && - !streamedTriggerReason - ) { - const trigger = detectFallbackTrigger(output.error); - if (trigger.shouldFallback) { - streamedTriggerReason = { - reason: trigger.reason, - retryAfterMs: trigger.retryAfterMs, - }; - } - } - - await onOutput(output); - } - : undefined; - - if (provider !== 'claude') { - logger.info( - { - group: group.name, - chatJid, - provider, - }, - `Claude provider in cooldown, routing request to ${provider}`, - ); - } - - logger.info( - { - group: group.name, - chatJid, - provider, - canFallback, - groupHasOverride, - }, - `Using provider: ${provider}`, - ); - - try { - const output = await runAgentProcess( - group, - { - ...agentInput, - sessionId: persistSessionIds ? sessionId : undefined, - }, - (proc, processName) => - queue.registerProcess(chatJid, proc, processName, group.folder), - wrappedOnOutput, - provider === 'claude' ? undefined : getFallbackEnvOverrides(), - ); - - if (persistSessionIds && output.newSessionId) { - sessions[group.folder] = output.newSessionId; - setSession(group.folder, output.newSessionId); - } - - logger.info( - { - group: group.name, - chatJid, - provider, - status: output.status, - sawOutput, - }, - `Provider response completed (provider: ${provider})`, - ); - - return { - output, - sawOutput, - sawSuccessNullResultWithoutOutput, - streamedTriggerReason, - }; - } catch (error) { - return { - error, - sawOutput, - sawSuccessNullResultWithoutOutput, - streamedTriggerReason, - }; - } - }; - - const runFallbackAttempt = async ( - reason: string, - retryAfterMs?: number, - ): Promise<'success' | 'error'> => { - const fallbackName = getFallbackProviderName(); - markPrimaryCooldown(reason, retryAfterMs); - - logger.info( - { - group: group.name, - chatJid, - reason, - retryAfterMs, - fallbackProvider: fallbackName, - }, - `Falling back to provider: ${fallbackName} (reason: ${reason})`, - ); - - const fallbackAttempt = await runAttempt(fallbackName); - if (fallbackAttempt.error) { - logger.error( - { - group: group.name, - provider: fallbackName, - err: fallbackAttempt.error, - }, - 'Fallback provider also threw', - ); - return 'error'; - } - - if (fallbackAttempt.output?.status === 'error') { - logger.error( - { - group: group.name, - provider: fallbackName, - error: fallbackAttempt.output.error, - }, - `Fallback provider (${fallbackName}) also failed`, - ); - return 'error'; - } - - return 'success'; - }; - - const provider = canFallback ? getActiveProvider() : 'claude'; - const primaryAttempt = await runAttempt(provider); - - if (primaryAttempt.error) { - if (canFallback && provider === 'claude' && !primaryAttempt.sawOutput) { - const errMsg = - primaryAttempt.error instanceof Error - ? primaryAttempt.error.message - : String(primaryAttempt.error); - const trigger = primaryAttempt.streamedTriggerReason - ? { - shouldFallback: true, - reason: primaryAttempt.streamedTriggerReason.reason, - retryAfterMs: primaryAttempt.streamedTriggerReason.retryAfterMs, - } - : detectFallbackTrigger(errMsg); - if (trigger.shouldFallback) { - return runFallbackAttempt(trigger.reason, trigger.retryAfterMs); - } - } - - logger.error( - { group: group.name, chatJid, provider, err: primaryAttempt.error }, - 'Agent error', - ); - return 'error'; - } - - const output = primaryAttempt.output; - if (!output) { - logger.error( - { group: group.name, chatJid, provider }, - 'Agent produced no output object', - ); - return 'error'; - } - - if ( - canFallback && - provider === 'claude' && - !primaryAttempt.sawOutput && - primaryAttempt.sawSuccessNullResultWithoutOutput - ) { - return runFallbackAttempt('success-null-result'); - } - - if (output.status === 'error') { - if (canFallback && provider === 'claude' && !primaryAttempt.sawOutput) { - const trigger = primaryAttempt.streamedTriggerReason - ? { - shouldFallback: true, - reason: primaryAttempt.streamedTriggerReason.reason, - retryAfterMs: primaryAttempt.streamedTriggerReason.retryAfterMs, - } - : detectFallbackTrigger(output.error); - if (trigger.shouldFallback) { - return runFallbackAttempt(trigger.reason, trigger.retryAfterMs); - } - } - - logger.error( - { group: group.name, chatJid, provider, error: output.error }, - 'Agent process error', - ); - return 'error'; - } - - return 'success'; -} - // ── Status & Usage Dashboards ─────────────────────────────────── function formatElapsed(ms: number): string { @@ -1903,191 +980,6 @@ async function startUsageDashboard(): Promise { // Usage is now integrated into the unified dashboard } -async function startMessageLoop(): Promise { - if (messageLoopRunning) { - logger.debug('Message loop already running, skipping duplicate start'); - return; - } - messageLoopRunning = true; - - logger.info(`NanoClaw running (trigger: @${ASSISTANT_NAME})`); - - while (true) { - try { - const jids = Object.keys(registeredGroups); - const { messages, newSeqCursor } = getNewMessagesBySeq( - jids, - lastTimestamp, - ASSISTANT_NAME, - ); - - if (messages.length > 0) { - logger.info({ count: messages.length }, 'New messages'); - - // Advance the "seen" cursor for all messages immediately - lastTimestamp = newSeqCursor; - saveState(); - - // Deduplicate by group - const messagesByGroup = new Map(); - for (const msg of messages) { - const existing = messagesByGroup.get(msg.chat_jid); - if (existing) { - existing.push(msg); - } else { - messagesByGroup.set(msg.chat_jid, [msg]); - } - } - - for (const [chatJid, groupMessages] of messagesByGroup) { - const group = registeredGroups[chatJid]; - if (!group) continue; - - const channel = findChannel(channels, chatJid); - if (!channel) { - logger.warn({ chatJid }, 'No channel owns JID, skipping messages'); - continue; - } - - const isMainGroup = group.isMain === true; - const processableGroupMessages = getProcessableMessages( - chatJid, - groupMessages, - channel, - ); - - if (processableGroupMessages.length === 0) { - const lastIgnored = groupMessages[groupMessages.length - 1]; - if (lastIgnored?.seq != null) { - advanceLastAgentCursor(chatJid, lastIgnored.seq); - } - continue; - } - - // --- Session command interception (message loop) --- - // Scan ALL messages in the batch for a session command. - const loopCmdMsg = processableGroupMessages.find( - (m) => extractSessionCommand(m.content, TRIGGER_PATTERN) !== null, - ); - - if (loopCmdMsg) { - // Only close active agent if the sender is authorized — otherwise an - // untrusted user could kill in-flight work by sending /compact (DoS). - // closeStdin no-ops internally when no agent is active. - if ( - isSessionCommandAllowed( - isMainGroup, - loopCmdMsg.is_from_me === true, - isSessionCommandSenderAllowed(loopCmdMsg.sender), - ) - ) { - queue.closeStdin(chatJid, { - reason: 'session-command-detected', - }); - } - // Enqueue so processGroupMessages handles auth + cursor advancement. - // Don't pipe via IPC — slash commands need a fresh agent with - // string prompt (not MessageStream) for SDK recognition. - queue.enqueueMessageCheck(chatJid); - continue; - } - // --- End session command interception --- - - const needsTrigger = !isMainGroup && group.requiresTrigger !== false; - - // For non-main groups, only act on trigger messages. - // Non-trigger messages accumulate in DB and get pulled as - // context when a trigger eventually arrives. - if (needsTrigger) { - const allowlistCfg = loadSenderAllowlist(); - const hasTrigger = processableGroupMessages.some( - (m) => - TRIGGER_PATTERN.test(m.content.trim()) && - (m.is_from_me || - isTriggerAllowed(chatJid, m.sender, allowlistCfg)), - ); - if (!hasTrigger) continue; - } - - // Pull all messages since lastAgentTimestamp so non-trigger - // context that accumulated between triggers is included. - const allPending = getMessagesSinceSeq( - chatJid, - lastAgentTimestamp[chatJid] || '', - ASSISTANT_NAME, - ); - const processablePending = getProcessableMessages( - chatJid, - allPending, - channel, - ); - const messagesToSend = - processablePending.length > 0 - ? processablePending - : processableGroupMessages; - const formatted = formatMessages(messagesToSend, TIMEZONE); - - if (queue.sendMessage(chatJid, formatted)) { - logger.debug( - { chatJid, count: messagesToSend.length }, - 'Piped messages to active agent', - ); - const endSeq = messagesToSend[messagesToSend.length - 1].seq; - if (endSeq != null) { - advanceLastAgentCursor(chatJid, endSeq); - } - // Show typing indicator while the agent processes the piped message - channel - .setTyping?.(chatJid, true) - ?.catch((err) => - logger.warn({ chatJid, err }, 'Failed to set typing indicator'), - ); - } else { - // No active agent — enqueue for a new one - queue.enqueueMessageCheck(chatJid, group.folder); - } - } - } - } catch (err) { - logger.error({ err }, 'Error in message loop'); - } - await new Promise((resolve) => setTimeout(resolve, POLL_INTERVAL)); - } -} - -/** - * Startup recovery: check for unprocessed messages in registered groups. - * Handles crash between advancing lastTimestamp and processing messages. - */ -function recoverPendingMessages(): void { - for (const [chatJid, group] of Object.entries(registeredGroups)) { - const sinceSeqCursor = lastAgentTimestamp[chatJid] || ''; - const rawPending = getMessagesSinceSeq( - chatJid, - sinceSeqCursor, - ASSISTANT_NAME, - ); - const recoveryChannel = findChannel(channels, chatJid); - const pending = getProcessableMessages( - chatJid, - rawPending, - recoveryChannel ?? undefined, - ); - if (pending.length > 0) { - logger.info( - { group: group.name, pendingCount: pending.length }, - 'Recovery: found unprocessed messages', - ); - queue.enqueueMessageCheck(chatJid, group.folder); - } else if (rawPending.length > 0) { - const endSeq = rawPending[rawPending.length - 1].seq; - if (endSeq != null) { - advanceLastAgentCursor(chatJid, endSeq); - } - } - } -} - async function announceRestartRecovery( processStartedAtMs: number, ): Promise { @@ -2283,8 +1175,8 @@ async function main(): Promise { getAvailableGroups, writeGroupsSnapshot, }); - queue.setProcessMessagesFn(processGroupMessages); - recoverPendingMessages(); + queue.setProcessMessagesFn(runtime.processGroupMessages); + runtime.recoverPendingMessages(); await announceRestartRecovery(processStartedAtMs); // Purge old messages in status channel before creating fresh dashboards if (STATUS_CHANNEL_ID && SERVICE_AGENT_TYPE === 'claude-code') { @@ -2298,7 +1190,7 @@ async function main(): Promise { } await startStatusDashboard(); await startUsageDashboard(); - startMessageLoop().catch((err) => { + runtime.startMessageLoop().catch((err) => { logger.fatal({ err }, 'Message loop crashed unexpectedly'); process.exit(1); }); diff --git a/src/message-runtime.test.ts b/src/message-runtime.test.ts index b8cd563..49a3f9f 100644 --- a/src/message-runtime.test.ts +++ b/src/message-runtime.test.ts @@ -11,13 +11,98 @@ vi.mock('./config.js', () => ({ isSessionCommandSenderAllowed: vi.fn(() => false), })); -vi.mock('./db.js', () => ({ +vi.mock('./db.js', () => { + const getMessagesSince = vi.fn( + ( + _chatJid?: string, + _sinceCursor?: string, + _botPrefix?: string, + _limit?: number, + ) => [], + ); + const getNewMessages = vi.fn( + ( + _jids?: string[], + _lastSeqCursor?: string, + _botPrefix?: string, + _limit?: number, + ) => ({ messages: [], newSeqCursor: '0' }), + ); + const withSeqs = (messages: Array>) => + messages.map((message, index) => ({ + ...message, + seq: + typeof message.seq === 'number' + ? message.seq + : index + 1, + })); + + return { getAllChats: vi.fn(() => []), getAllTasks: vi.fn(() => []), getLastHumanMessageTimestamp: vi.fn(() => null), - getMessagesSince: vi.fn(), - getNewMessages: vi.fn(() => ({ messages: [], newTimestamp: '' })), -})); + getMessagesSince, + getNewMessages, + getLatestMessageSeqAtOrBefore: vi.fn(() => 0), + getMessagesSinceSeq: vi.fn( + ( + chatJid: string, + sinceSeqCursor: string, + botPrefix: string, + limit?: number, + ) => withSeqs(getMessagesSince(chatJid, sinceSeqCursor, botPrefix, limit)), + ), + getNewMessagesBySeq: vi.fn( + ( + jids: string[], + lastSeqCursor: string, + botPrefix: string, + limit?: number, + ) => { + const result: + | { + messages?: Array>; + newSeqCursor?: string; + newTimestamp?: string; + } + | undefined = + getNewMessages(jids, lastSeqCursor, botPrefix, limit) || { + messages: [], + newSeqCursor: '0', + }; + const messages = withSeqs(result.messages || []); + const lastSeq = + messages.length > 0 + ? String(messages[messages.length - 1].seq) + : String(lastSeqCursor || '0'); + return { + messages, + newSeqCursor: result.newSeqCursor || result.newTimestamp || lastSeq, + }; + }, + ), + getOpenWorkItem: vi.fn(() => undefined), + createProducedWorkItem: vi.fn((input) => ({ + id: 1, + group_folder: input.group_folder, + chat_jid: input.chat_jid, + agent_type: input.agent_type || 'claude-code', + status: 'produced', + start_seq: input.start_seq, + end_seq: input.end_seq, + result_payload: input.result_payload, + delivery_attempts: 0, + created_at: new Date().toISOString(), + updated_at: new Date().toISOString(), + delivered_at: null, + delivery_message_id: null, + last_error: null, + })), + markWorkItemDelivered: vi.fn(), + markWorkItemDeliveryRetry: vi.fn(), + isPairedRoomJid: vi.fn(() => false), + }; +}); vi.mock('./logger.js', () => ({ logger: { @@ -173,14 +258,14 @@ describe('createMessageRuntime', () => { expect(clearSession).toHaveBeenCalledWith(group.folder); expect(closeStdin).toHaveBeenCalledWith(chatJid, { runId: 'run-1', - reason: 'poisoned-session', + reason: 'poisoned-session-detected', }); expect(notifyIdle).not.toHaveBeenCalled(); expect(channel.sendMessage).toHaveBeenCalledWith( chatJid, 'An image in the conversation exceeds the dimension limit for many-image requests (2000px). Start a new session with fewer images.', ); - expect(lastAgentTimestamps[chatJid]).toBe('2026-03-18T09:00:00.000Z'); + expect(lastAgentTimestamps[chatJid]).toBe('1'); expect(saveState).toHaveBeenCalled(); }); @@ -548,7 +633,7 @@ describe('createMessageRuntime', () => { expect(channel.editMessage).toHaveBeenLastCalledWith( chatJid, 'progress-1', - '오래 걸리는 작업입니다.\n\n1시간 1분 10초', + '오래 걸리는 작업입니다.\n\n1시간 0초', ); } finally { vi.useRealTimers(); @@ -1153,7 +1238,7 @@ describe('createMessageRuntime', () => { chatJid, '중간 진행상황입니다.\n\n0초', ); - expect(lastAgentTimestamps[chatJid]).toBe('2026-03-19T00:00:00.000Z'); + expect(lastAgentTimestamps[chatJid]).toBe('1'); expect(saveState).toHaveBeenCalled(); }); diff --git a/src/message-runtime.ts b/src/message-runtime.ts index 9413b7a..cf23d56 100644 --- a/src/message-runtime.ts +++ b/src/message-runtime.ts @@ -8,11 +8,19 @@ import { import { getAllChats, getAllTasks, - getMessagesSince, - getNewMessages, + getLatestMessageSeqAtOrBefore, + getMessagesSinceSeq, + getNewMessagesBySeq, + getOpenWorkItem, + createProducedWorkItem, + markWorkItemDelivered, + markWorkItemDeliveryRetry, + isPairedRoomJid, + type WorkItem, } from './db.js'; import { DATA_DIR, isSessionCommandSenderAllowed } from './config.js'; import { GroupQueue, GroupRunContext } from './group-queue.js'; +import { filterProcessableMessages } from './bot-message-filter.js'; import { detectFallbackTrigger, getActiveProvider, @@ -31,7 +39,6 @@ import { isSessionCommandControlMessage, } from './session-commands.js'; import { shouldResetSessionOnAgentFailure } from './session-recovery.js'; -import { isTaskStatusControlMessage } from './task-scheduler.js'; import { Channel, NewMessage, RegisteredGroup } from './types.js'; import { logger } from './logger.js'; import path from 'path'; @@ -80,24 +87,77 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { } { let messageLoopRunning = false; - const filterOwnChannelMessages = (messages: NewMessage[]): NewMessage[] => - messages.filter((msg) => { - const channel = findChannel(deps.channels, msg.chat_jid); - if (channel?.isOwnMessage?.(msg)) { - return false; - } - if (msg.is_bot_message && isSessionCommandControlMessage(msg.content)) { - return false; - } - if (msg.is_bot_message && isTaskStatusControlMessage(msg.content)) { - return false; - } - return true; - }); - const getCurrentAvailableGroups = (): AvailableGroup[] => getAvailableGroups(deps.getRegisteredGroups()); + const normalizeStoredSeqCursor = ( + cursor: string | undefined, + chatJid?: string, + ): string => { + if (!cursor) return '0'; + if (/^\d+$/.test(cursor.trim())) return cursor.trim(); + return String(getLatestMessageSeqAtOrBefore(cursor, chatJid)); + }; + + const advanceLastAgentCursor = ( + chatJid: string, + cursorOrTimestamp: string | number, + ): void => { + const lastAgentTimestamps = deps.getLastAgentTimestamps(); + if (typeof cursorOrTimestamp === 'number') { + lastAgentTimestamps[chatJid] = String(cursorOrTimestamp); + } else { + lastAgentTimestamps[chatJid] = normalizeStoredSeqCursor( + cursorOrTimestamp, + chatJid, + ); + } + deps.saveState(); + }; + + const getProcessableMessages = ( + chatJid: string, + messages: Parameters[0], + channel?: Channel, + ) => + filterProcessableMessages( + messages, + isPairedRoomJid(chatJid), + channel?.isOwnMessage?.bind(channel), + ); + + const deliverOpenWorkItem = async ( + channel: Channel, + item: WorkItem, + ): Promise => { + try { + await channel.sendMessage(item.chat_jid, item.result_payload); + markWorkItemDelivered(item.id); + logger.info( + { + chatJid: item.chat_jid, + workItemId: item.id, + deliveryAttempts: item.delivery_attempts + 1, + }, + 'Delivered produced work item', + ); + return true; + } catch (err) { + const errorMessage = err instanceof Error ? err.message : String(err); + markWorkItemDeliveryRetry(item.id, errorMessage); + logger.warn( + { + chatJid: item.chat_jid, + workItemId: item.id, + deliveryAttempts: item.delivery_attempts + 1, + err, + }, + 'Failed to deliver produced work item', + ); + return false; + } + }; + const runAgent = async ( group: RegisteredGroup, prompt: string, @@ -447,60 +507,46 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { chatJid: string, context: GroupRunContext, ): Promise => { - const { runId, reason } = context; - const registeredGroups = deps.getRegisteredGroups(); - const group = registeredGroups[chatJid]; - if (!group) { - logger.warn( - { chatJid, runId, reason }, - 'Registered group missing for queued run', - ); - return true; - } + const { runId } = context; + const group = deps.getRegisteredGroups()[chatJid]; + if (!group) return true; const channel = findChannel(deps.channels, chatJid); if (!channel) { - logger.warn( - { chatJid, runId, reason }, - 'No channel owns JID, skipping messages', - ); + logger.warn({ chatJid }, 'No channel owns JID, skipping messages'); return true; } + const openWorkItem = getOpenWorkItem( + chatJid, + (group.agentType || 'claude-code') as 'claude-code' | 'codex', + ); + if (openWorkItem) { + const delivered = await deliverOpenWorkItem(channel, openWorkItem); + if (!delivered) return false; + } + const isMainGroup = group.isMain === true; - const lastAgentTimestamps = deps.getLastAgentTimestamps(); - const sinceTimestamp = lastAgentTimestamps[chatJid] || ''; - const missedMessages = filterOwnChannelMessages( - getMessagesSince(chatJid, sinceTimestamp, deps.assistantName), + const sinceSeqCursor = deps.getLastAgentTimestamps()[chatJid] || '0'; + const rawMissedMessages = getMessagesSinceSeq( + chatJid, + sinceSeqCursor, + deps.assistantName, + ); + const missedMessages = getProcessableMessages( + chatJid, + rawMissedMessages, + channel, ); if (missedMessages.length === 0) { - logger.info( - { - chatJid, - group: group.name, - groupFolder: group.folder, - runId, - reason, - }, - 'No pending messages for queued run', - ); + const lastIgnored = rawMissedMessages[rawMissedMessages.length - 1]; + if (lastIgnored) { + advanceLastAgentCursor(chatJid, lastIgnored.timestamp); + } return true; } - logger.info( - { - chatJid, - group: group.name, - groupFolder: group.folder, - runId, - reason, - messageCount: missedMessages.length, - sinceTimestamp, - }, - 'Loaded pending messages for queued run', - ); - const cmdResult = await handleSessionCommand({ missedMessages, isMainGroup, @@ -516,13 +562,11 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { runAgent(group, prompt, chatJid, runId, onOutput), closeStdin: () => deps.queue.closeStdin(chatJid, { - runId, reason: 'session-command', }), clearSession: () => deps.clearSession(group.folder), - advanceCursor: (timestamp) => { - lastAgentTimestamps[chatJid] = timestamp; - deps.saveState(); + advanceCursor: (cursorOrTimestamp) => { + advanceLastAgentCursor(chatJid, cursorOrTimestamp); }, formatMessages, isAdminSender: (msg) => isSessionCommandSenderAllowed(msg.sender), @@ -560,10 +604,12 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { } const prompt = formatMessages(missedMessages, deps.timezone); - const previousCursor = lastAgentTimestamps[chatJid] || ''; - lastAgentTimestamps[chatJid] = - missedMessages[missedMessages.length - 1].timestamp; - deps.saveState(); + const previousCursor = deps.getLastAgentTimestamps()[chatJid] || '0'; + const startSeq = missedMessages[0].seq ?? null; + const endSeq = missedMessages[missedMessages.length - 1].seq ?? null; + if (endSeq !== null) { + advanceLastAgentCursor(chatJid, endSeq); + } logger.info( { @@ -577,21 +623,40 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { ); let idleTimer: ReturnType | null = null; + let producedFinalText: string | null = null; + let followUpQueuedAt: number | null = null; + let followUpQueuedTextLength: number | null = null; + let followUpQueuedFilename: string | null = null; + let followUpNoOutputWarnTimer: ReturnType | null = null; + let hadError = false; let latestProgressText: string | null = null; let latestProgressRendered: string | null = null; let progressMessageId: string | null = null; let progressStartedAt: number | null = null; let progressTicker: ReturnType | null = null; + let finalOutputSentToUser = false; + let progressOutputSentToUser = false; + let latestModelProgressTextForFinalFallback: string | null = null; + let sawNonProgressOutput = false; + let producedDeliverySucceeded = true; + let isFirstLogicalTurn = true; + let poisonedSessionDetected = false; + const isClaudeCodeAgent = + (group.agentType || 'claude-code') === 'claude-code'; + const FOLLOW_UP_NO_OUTPUT_WARN_MS = 10_000; const resetIdleTimer = () => { if (idleTimer) clearTimeout(idleTimer); idleTimer = setTimeout(() => { + logger.debug( + { group: group.name, chatJid, runId }, + 'Idle timeout, closing agent stdin', + ); if (followUpQueuedAt !== null) { logger.warn( { - chatJid, group: group.name, - groupFolder: group.folder, + chatJid, runId, followUpQueuedAt: new Date(followUpQueuedAt).toISOString(), followUpQueuedTextLength, @@ -601,21 +666,9 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { 'Idle timeout reached while a queued follow-up still had no agent output', ); } - logger.info( - { chatJid, group: group.name, groupFolder: group.folder, runId }, - 'Idle timeout reached, closing active agent stdin', - ); - deps.queue.closeStdin(chatJid, { - runId, - reason: 'idle-timeout', - }); + deps.queue.closeStdin(chatJid, { reason: 'idle-timeout' }); }, deps.idleTimeout); }; - let followUpQueuedAt: number | null = null; - let followUpQueuedTextLength: number | null = null; - let followUpQueuedFilename: string | null = null; - let followUpNoOutputWarnTimer: ReturnType | null = null; - const FOLLOW_UP_NO_OUTPUT_WARN_MS = 10_000; const clearFollowUpNoOutputWarnTimer = () => { if (followUpNoOutputWarnTimer) { @@ -637,9 +690,8 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { if (followUpQueuedAt === null) return; logger.warn( { - chatJid, group: group.name, - groupFolder: group.folder, + chatJid, runId, followUpQueuedAt: new Date(followUpQueuedAt).toISOString(), followUpQueuedTextLength, @@ -663,9 +715,8 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { scheduleFollowUpNoOutputWarning(); logger.info( { - chatJid, group: group.name, - groupFolder: group.folder, + chatJid, runId, followUpQueuedTextLength, followUpQueuedFilename, @@ -678,9 +729,8 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { if (followUpQueuedAt === null) return; logger.info( { - chatJid, group: group.name, - groupFolder: group.folder, + chatJid, runId, followUpQueuedAt: new Date(followUpQueuedAt).toISOString(), followUpQueuedTextLength, @@ -693,19 +743,18 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { clearPendingFollowUpDiagnostics(); }; - const warnFollowUpEndedWithoutOutput = (reason: string) => { + const warnFollowUpEndedWithoutOutput = (reasonText: string) => { if (followUpQueuedAt === null) return; logger.warn( { - chatJid, group: group.name, - groupFolder: group.folder, + chatJid, runId, followUpQueuedAt: new Date(followUpQueuedAt).toISOString(), followUpQueuedTextLength, followUpQueuedFilename, followUpWaitMs: Date.now() - followUpQueuedAt, - reason, + reason: reasonText, }, 'Active agent ended a turn without any output after a queued follow-up', ); @@ -717,15 +766,6 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { resetIdleTimer(); }); - let hadError = false; - let finalOutputSentToUser = false; - let progressOutputSentToUser = false; - let latestModelProgressTextForFinalFallback: string | null = null; - let sawNonProgressOutput = false; - let poisonedSessionDetected = false; - const isClaudeCodeAgent = - (group.agentType || 'claude-code') === 'claude-code'; - const clearProgressTicker = () => { if (progressTicker) { clearInterval(progressTicker); @@ -738,6 +778,40 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { progressOutputSentToUser = false; latestModelProgressTextForFinalFallback = null; sawNonProgressOutput = false; + producedFinalText = null; + }; + + const flushProducedFinalText = async () => { + if (!producedFinalText) { + return; + } + + try { + const workItem = createProducedWorkItem({ + group_folder: group.folder, + chat_jid: chatJid, + agent_type: group.agentType || 'claude-code', + start_seq: isFirstLogicalTurn ? startSeq : null, + end_seq: isFirstLogicalTurn ? endSeq : null, + result_payload: producedFinalText, + }); + const delivered = await deliverOpenWorkItem(channel, workItem); + if (delivered) { + finalOutputSentToUser = true; + } else { + producedDeliverySucceeded = false; + } + } catch (err) { + producedDeliverySucceeded = false; + logger.warn( + { group: group.name, chatJid, runId, err }, + 'Failed to persist produced output for delivery', + ); + } finally { + producedFinalText = null; + latestModelProgressTextForFinalFallback = null; + isFirstLogicalTurn = false; + } }; const resetProgressState = () => { @@ -756,14 +830,13 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { const hours = Math.floor(elapsedSeconds / 3600); const minutes = Math.floor((elapsedSeconds % 3600) / 60); const seconds = elapsedSeconds % 60; - const elapsedLabel = - hours > 0 - ? `${hours}시간 ${minutes}분 ${seconds}초` - : minutes > 0 - ? `${minutes}분 ${seconds}초` - : `${seconds}초`; + const elapsedParts: string[] = []; - return `${text}\n\n${elapsedLabel}`; + if (hours > 0) elapsedParts.push(`${hours}시간`); + if (minutes > 0) elapsedParts.push(`${minutes}분`); + elapsedParts.push(`${seconds}초`); + + return `${text}\n\n${elapsedParts.join(' ')}`; }; const syncTrackedProgressMessage = async () => { @@ -817,10 +890,6 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { } if (progressStartedAt === null) { - // A fresh progress cycle after a prior final in the same active agent - // session represents a new logical turn (follow-up IPC message). Reset - // turn-scoped output flags so progress-only completion can still be - // promoted to a final message. resetTurnOutputState(); progressStartedAt = Date.now(); } @@ -845,44 +914,42 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { return; } - if (channel.sendAndTrack) { - try { - progressMessageId = await channel.sendAndTrack(chatJid, rendered); - } catch (err) { - logger.warn( - { - chatJid, - group: group.name, - groupFolder: group.folder, - runId, - err, - }, - 'Failed to send tracked progress message', - ); - return; - } - if (progressMessageId) { - logger.info( - { - chatJid, - group: group.name, - groupFolder: group.folder, - runId, - progressMessageId, - text, - }, - 'Created tracked progress message', - ); - latestProgressRendered = rendered; - ensureProgressTicker(); - progressOutputSentToUser = true; - return; - } + if (!channel.sendAndTrack) { + return; } - latestProgressRendered = rendered; - await channel.sendMessage(chatJid, rendered); - progressOutputSentToUser = true; + try { + progressMessageId = await channel.sendAndTrack(chatJid, rendered); + } catch (err) { + logger.warn( + { + chatJid, + group: group.name, + groupFolder: group.folder, + runId, + err, + }, + 'Failed to send tracked progress message', + ); + return; + } + + if (progressMessageId) { + logger.info( + { + chatJid, + group: group.name, + groupFolder: group.folder, + runId, + progressMessageId, + text, + }, + 'Created tracked progress message', + ); + latestProgressRendered = rendered; + ensureProgressTicker(); + progressOutputSentToUser = true; + } }; await channel.setTyping?.(chatJid, true); @@ -903,7 +970,7 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { deps.clearSession(group.folder); deps.queue.closeStdin(chatJid, { runId, - reason: 'poisoned-session', + reason: 'poisoned-session-detected', }); logger.warn( { chatJid, group: group.name, groupFolder: group.folder, runId }, @@ -931,10 +998,6 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { ); noteAgentOutputObserved(result.phase); if (result.phase === 'progress') { - // Detect new logical turn (follow-up IPC): if a final was already - // sent in this run, a new progress output means a follow-up turn - // has started. Reset turn-level state so the promotion logic at - // end-of-run works correctly for the new turn. if (finalOutputSentToUser || sawNonProgressOutput) { logger.info( { @@ -945,11 +1008,9 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { }, 'New logical turn detected (follow-up), resetting turn state', ); - finalOutputSentToUser = false; - sawNonProgressOutput = false; - progressOutputSentToUser = false; - latestModelProgressTextForFinalFallback = null; + resetTurnOutputState(); resetProgressState(); + isFirstLogicalTurn = false; await channel.setTyping?.(chatJid, true); } if (text) { @@ -965,9 +1026,8 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { if (text) { await finalizeProgressMessage(); - await channel.sendMessage(chatJid, text); - finalOutputSentToUser = true; - latestModelProgressTextForFinalFallback = null; + producedFinalText = text; + await flushProducedFinalText(); } else { logger.info( { @@ -992,7 +1052,6 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { } await channel.setTyping?.(chatJid, false); - if (!poisonedSessionDetected) { resetIdleTimer(); } @@ -1016,7 +1075,7 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { if ( output === 'success' && !hadError && - !finalOutputSentToUser && + !producedFinalText && !sawNonProgressOutput && latestModelProgressTextForFinalFallback ) { @@ -1029,29 +1088,29 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { }, 'Promoting last progress output to final message after agent completion', ); - await channel.sendMessage( - chatJid, - latestModelProgressTextForFinalFallback, - ); - finalOutputSentToUser = true; - latestModelProgressTextForFinalFallback = null; + producedFinalText = latestModelProgressTextForFinalFallback; + await flushProducedFinalText(); } clearProgressTicker(); if (idleTimer) clearTimeout(idleTimer); clearPendingFollowUpDiagnostics(); - deps.queue.setActivityTouch?.(chatJid, null); + deps.queue.setActivityTouch?.(chatJid, null); if (hadError) { - if (finalOutputSentToUser || progressOutputSentToUser) { + if ( + finalOutputSentToUser || + progressOutputSentToUser || + producedFinalText + ) { logger.warn( { chatJid, group: group.name, groupFolder: group.folder, runId }, - 'Agent error after conversational output was sent, skipping cursor rollback to prevent duplicates', + 'Agent error after output was produced, skipping cursor rollback to prevent duplicates', ); - return true; + return producedFinalText ? producedDeliverySucceeded : true; } - lastAgentTimestamps[chatJid] = previousCursor; + deps.getLastAgentTimestamps()[chatJid] = previousCursor; deps.saveState(); logger.warn( { chatJid, group: group.name, groupFolder: group.folder, runId }, @@ -1060,6 +1119,14 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { return false; } + if (!producedDeliverySucceeded) { + logger.warn( + { chatJid, group: group.name, groupFolder: group.folder, runId }, + 'Persisted produced output for delivery retry without rerunning agent', + ); + return false; + } + logger.info( { chatJid, @@ -1088,23 +1155,18 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { try { const registeredGroups = deps.getRegisteredGroups(); const jids = Object.keys(registeredGroups); - const { messages: rawMessages, newTimestamp } = getNewMessages( + const { messages, newSeqCursor } = getNewMessagesBySeq( jids, deps.getLastTimestamp(), deps.assistantName, ); - const messages = filterOwnChannelMessages(rawMessages); - if (rawMessages.length > 0) { + if (messages.length > 0) { logger.info({ count: messages.length }, 'New messages'); - deps.setLastTimestamp(newTimestamp); + deps.setLastTimestamp(newSeqCursor); deps.saveState(); - if (messages.length === 0) { - continue; - } - const messagesByGroup = new Map(); for (const msg of messages) { const existing = messagesByGroup.get(msg.chat_jid); @@ -1129,6 +1191,20 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { } const isMainGroup = group.isMain === true; + const processableGroupMessages = getProcessableMessages( + chatJid, + groupMessages, + channel, + ); + + if (processableGroupMessages.length === 0) { + const lastIgnored = groupMessages[groupMessages.length - 1]; + if (lastIgnored?.seq != null) { + advanceLastAgentCursor(chatJid, lastIgnored.seq); + } + continue; + } + const loopCmdMsg = groupMessages.find( (msg) => extractSessionCommand(msg.content, deps.triggerPattern) !== @@ -1155,7 +1231,7 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { !isMainGroup && group.requiresTrigger !== false; if (needsTrigger) { const allowlistCfg = loadSenderAllowlist(); - const hasTrigger = groupMessages.some( + const hasTrigger = processableGroupMessages.some( (msg) => deps.triggerPattern.test(msg.content.trim()) && (msg.is_from_me || @@ -1164,16 +1240,20 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { if (!hasTrigger) continue; } - const lastAgentTimestamps = deps.getLastAgentTimestamps(); - const allPending = filterOwnChannelMessages( - getMessagesSince( - chatJid, - lastAgentTimestamps[chatJid] || '', - deps.assistantName, - ), + const allPending = getMessagesSinceSeq( + chatJid, + deps.getLastAgentTimestamps()[chatJid] || '', + deps.assistantName, + ); + const processablePending = getProcessableMessages( + chatJid, + allPending, + channel, ); const messagesToSend = - allPending.length > 0 ? allPending : groupMessages; + processablePending.length > 0 + ? processablePending + : processableGroupMessages; const formatted = formatMessages(messagesToSend, deps.timezone); if (deps.queue.sendMessage(chatJid, formatted)) { @@ -1181,9 +1261,10 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { { chatJid, count: messagesToSend.length }, 'Piped messages to active agent', ); - lastAgentTimestamps[chatJid] = - messagesToSend[messagesToSend.length - 1].timestamp; - deps.saveState(); + const endSeq = messagesToSend[messagesToSend.length - 1].seq; + if (endSeq != null) { + advanceLastAgentCursor(chatJid, endSeq); + } channel .setTyping?.(chatJid, true) ?.catch((err) => @@ -1206,11 +1287,18 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { const recoverPendingMessages = (): void => { const registeredGroups = deps.getRegisteredGroups(); - const lastAgentTimestamps = deps.getLastAgentTimestamps(); for (const [chatJid, group] of Object.entries(registeredGroups)) { - const sinceTimestamp = lastAgentTimestamps[chatJid] || ''; - const pending = filterOwnChannelMessages( - getMessagesSince(chatJid, sinceTimestamp, deps.assistantName), + const sinceSeqCursor = deps.getLastAgentTimestamps()[chatJid] || ''; + const rawPending = getMessagesSinceSeq( + chatJid, + sinceSeqCursor, + deps.assistantName, + ); + const recoveryChannel = findChannel(deps.channels, chatJid); + const pending = getProcessableMessages( + chatJid, + rawPending, + recoveryChannel ?? undefined, ); if (pending.length > 0) { logger.info( @@ -1218,6 +1306,11 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): { 'Recovery: found unprocessed messages', ); deps.queue.enqueueMessageCheck(chatJid, group.folder); + } else if (rawPending.length > 0) { + const endSeq = rawPending[rawPending.length - 1].seq; + if (endSeq != null) { + advanceLastAgentCursor(chatJid, endSeq); + } } } };