Refine Codex progress message tracking

This commit is contained in:
Eyejoker
2026-03-19 03:22:31 +09:00
parent 779d57c392
commit 29b78fc286
2 changed files with 245 additions and 53 deletions

View File

@@ -60,10 +60,12 @@ function makeChannel(chatJid: string): Channel {
name: 'discord', name: 'discord',
connect: vi.fn().mockResolvedValue(undefined), connect: vi.fn().mockResolvedValue(undefined),
sendMessage: vi.fn().mockResolvedValue(undefined), sendMessage: vi.fn().mockResolvedValue(undefined),
sendAndTrack: vi.fn().mockResolvedValue('progress-1'),
isConnected: vi.fn(() => true), isConnected: vi.fn(() => true),
ownsJid: vi.fn((jid: string) => jid === chatJid), ownsJid: vi.fn((jid: string) => jid === chatJid),
disconnect: vi.fn().mockResolvedValue(undefined), disconnect: vi.fn().mockResolvedValue(undefined),
setTyping: vi.fn().mockResolvedValue(undefined), setTyping: vi.fn().mockResolvedValue(undefined),
editMessage: vi.fn().mockResolvedValue(undefined),
}; };
} }
@@ -221,7 +223,8 @@ describe('createMessageRuntime', () => {
expect(notifyIdle).toHaveBeenCalledWith(chatJid, 'run-2'); expect(notifyIdle).toHaveBeenCalledWith(chatJid, 'run-2');
}); });
it('streams Codex progress as a normal room message and only marks idle after the turn settles', async () => { it('tracks Codex progress in one editable message and updates elapsed time every 10 seconds', async () => {
vi.useFakeTimers();
const chatJid = 'group@test'; const chatJid = 'group@test';
const group = makeGroup('codex'); const group = makeGroup('codex');
const channel = makeChannel(chatJid); const channel = makeChannel(chatJid);
@@ -248,6 +251,7 @@ describe('createMessageRuntime', () => {
newSessionId: 'session-progress', newSessionId: 'session-progress',
}); });
expect(notifyIdle).not.toHaveBeenCalled(); expect(notifyIdle).not.toHaveBeenCalled();
await vi.advanceTimersByTimeAsync(10_000);
await onOutput?.({ await onOutput?.({
status: 'success', status: 'success',
result: null, result: null,
@@ -283,25 +287,124 @@ describe('createMessageRuntime', () => {
clearSession: vi.fn(), clearSession: vi.fn(),
}); });
try {
const result = await runtime.processGroupMessages(chatJid, { const result = await runtime.processGroupMessages(chatJid, {
runId: 'run-progress', runId: 'run-progress',
reason: 'messages', reason: 'messages',
}); });
expect(result).toBe(true); expect(result).toBe(true);
expect(channel.sendMessage).toHaveBeenCalledWith( expect(channel.sendAndTrack).toHaveBeenCalledWith(
chatJid, chatJid,
'CI 상태 확인 중입니다.', 'CI 상태 확인 중입니다.\n\n0초',
); );
expect(channel.editMessage).toHaveBeenCalledWith(
chatJid,
'progress-1',
'CI 상태 확인 중입니다.\n\n10초',
);
expect(channel.sendMessage).not.toHaveBeenCalled();
expect(notifyIdle).toHaveBeenCalledTimes(1); expect(notifyIdle).toHaveBeenCalledTimes(1);
expect(notifyIdle).toHaveBeenCalledWith(chatJid, 'run-progress'); expect(notifyIdle).toHaveBeenCalledWith(chatJid, 'run-progress');
expect(persistSession).toHaveBeenCalledWith( expect(persistSession).toHaveBeenCalledWith(
group.folder, group.folder,
'session-progress', 'session-progress',
); );
} finally {
vi.useRealTimers();
}
});
it('formats longer Codex progress durations with minutes and hours', async () => {
vi.useFakeTimers();
const chatJid = 'group@test';
const group = makeGroup('codex');
const channel = makeChannel(chatJid);
vi.mocked(db.getMessagesSince).mockReturnValue([
{
id: 'msg-1',
chat_jid: chatJid,
sender: 'user@test',
sender_name: 'User',
content: 'hello',
timestamp: '2026-03-19T00:00:00.000Z',
},
]);
vi.mocked(agentRunner.runAgentProcess).mockImplementation(
async (_group, _input, _onProcess, onOutput) => {
await onOutput?.({
status: 'success',
phase: 'progress',
result: '오래 걸리는 작업입니다.',
newSessionId: 'session-long-progress',
});
await vi.advanceTimersByTimeAsync(70_000);
expect(channel.editMessage).toHaveBeenLastCalledWith(
chatJid,
'progress-1',
'오래 걸리는 작업입니다.\n\n1분 10초',
);
await vi.advanceTimersByTimeAsync(3_600_000);
await onOutput?.({
status: 'success',
result: null,
newSessionId: 'session-long-progress',
});
return {
status: 'success',
result: null,
newSessionId: 'session-long-progress',
};
},
);
const runtime = createMessageRuntime({
assistantName: 'Andy',
idleTimeout: 1_000,
pollInterval: 1_000,
timezone: 'UTC',
triggerPattern: /^@Andy\b/i,
channels: [channel],
queue: {
registerProcess: vi.fn(),
closeStdin: vi.fn(),
notifyIdle: vi.fn(),
} as any,
getRegisteredGroups: () => ({ [chatJid]: group }),
getSessions: () => ({}),
getLastTimestamp: () => '',
setLastTimestamp: vi.fn(),
getLastAgentTimestamps: () => ({}),
saveState: vi.fn(),
persistSession: vi.fn(),
clearSession: vi.fn(),
});
try {
const result = await runtime.processGroupMessages(chatJid, {
runId: 'run-long-progress',
reason: 'messages',
});
expect(result).toBe(true);
expect(channel.sendAndTrack).toHaveBeenCalledWith(
chatJid,
'오래 걸리는 작업입니다.\n\n0초',
);
expect(channel.editMessage).toHaveBeenLastCalledWith(
chatJid,
'progress-1',
'오래 걸리는 작업입니다.\n\n1시간 1분 10초',
);
} finally {
vi.useRealTimers();
}
}); });
it('keeps progress separate from the final Codex answer', async () => { it('keeps progress separate from the final Codex answer', async () => {
vi.useFakeTimers();
const chatJid = 'group@test'; const chatJid = 'group@test';
const group = makeGroup('codex'); const group = makeGroup('codex');
const channel = makeChannel(chatJid); const channel = makeChannel(chatJid);
@@ -326,6 +429,7 @@ describe('createMessageRuntime', () => {
result: '테스트를 돌리는 중입니다.', result: '테스트를 돌리는 중입니다.',
newSessionId: 'session-final', newSessionId: 'session-final',
}); });
await vi.advanceTimersByTimeAsync(10_000);
await onOutput?.({ await onOutput?.({
status: 'success', status: 'success',
phase: 'final', phase: 'final',
@@ -362,24 +466,31 @@ describe('createMessageRuntime', () => {
clearSession: vi.fn(), clearSession: vi.fn(),
}); });
try {
const result = await runtime.processGroupMessages(chatJid, { const result = await runtime.processGroupMessages(chatJid, {
runId: 'run-final', runId: 'run-final',
reason: 'messages', reason: 'messages',
}); });
expect(result).toBe(true); expect(result).toBe(true);
expect(channel.sendMessage).toHaveBeenNthCalledWith( expect(channel.sendAndTrack).toHaveBeenCalledWith(
1,
chatJid, chatJid,
'테스트를 돌리는 중입니다.', '테스트를 돌리는 중입니다.\n\n0초',
); );
expect(channel.sendMessage).toHaveBeenNthCalledWith( expect(channel.editMessage).toHaveBeenCalledWith(
2, chatJid,
'progress-1',
'테스트를 돌리는 중입니다.\n\n10초',
);
expect(channel.sendMessage).toHaveBeenCalledWith(
chatJid, chatJid,
'테스트가 끝났습니다.', '테스트가 끝났습니다.',
); );
expect(notifyIdle).toHaveBeenCalledTimes(1); expect(notifyIdle).toHaveBeenCalledTimes(1);
expect(notifyIdle).toHaveBeenCalledWith(chatJid, 'run-final'); expect(notifyIdle).toHaveBeenCalledWith(chatJid, 'run-final');
} finally {
vi.useRealTimers();
}
}); });
it('does not roll back when a streamed progress message was already posted before an error', async () => { it('does not roll back when a streamed progress message was already posted before an error', async () => {
@@ -451,9 +562,9 @@ describe('createMessageRuntime', () => {
}); });
expect(result).toBe(true); expect(result).toBe(true);
expect(channel.sendMessage).toHaveBeenCalledWith( expect(channel.sendAndTrack).toHaveBeenCalledWith(
chatJid, chatJid,
'중간 진행상황입니다.', '중간 진행상황입니다.\n\n0초',
); );
expect(lastAgentTimestamps[chatJid]).toBe('2026-03-19T00:00:00.000Z'); expect(lastAgentTimestamps[chatJid]).toBe('2026-03-19T00:00:00.000Z');
expect(saveState).toHaveBeenCalled(); expect(saveState).toHaveBeenCalled();

View File

@@ -93,7 +93,8 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): {
onOutput?: (output: AgentOutput) => Promise<void>, onOutput?: (output: AgentOutput) => Promise<void>,
): Promise<'success' | 'error'> => { ): Promise<'success' | 'error'> => {
const isMain = group.isMain === true; const isMain = group.isMain === true;
const isClaudeCodeAgent = (group.agentType || 'claude-code') === 'claude-code'; const isClaudeCodeAgent =
(group.agentType || 'claude-code') === 'claude-code';
const sessions = deps.getSessions(); const sessions = deps.getSessions();
const sessionId = sessions[group.folder]; const sessionId = sessions[group.folder];
@@ -121,10 +122,7 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): {
if (output.newSessionId) { if (output.newSessionId) {
deps.persistSession(group.folder, output.newSessionId); deps.persistSession(group.folder, output.newSessionId);
} }
if ( if (isClaudeCodeAgent && shouldResetSessionOnAgentFailure(output)) {
isClaudeCodeAgent &&
shouldResetSessionOnAgentFailure(output)
) {
resetSessionRequested = true; resetSessionRequested = true;
} }
await onOutput(output); await onOutput(output);
@@ -154,8 +152,7 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): {
if ( if (
isClaudeCodeAgent && isClaudeCodeAgent &&
(resetSessionRequested || (resetSessionRequested || shouldResetSessionOnAgentFailure(output))
shouldResetSessionOnAgentFailure(output))
) { ) {
deps.clearSession(group.folder); deps.clearSession(group.folder);
logger.warn( logger.warn(
@@ -207,11 +204,7 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): {
const lastAgentTimestamps = deps.getLastAgentTimestamps(); const lastAgentTimestamps = deps.getLastAgentTimestamps();
const sinceTimestamp = lastAgentTimestamps[chatJid] || ''; const sinceTimestamp = lastAgentTimestamps[chatJid] || '';
const missedMessages = filterOwnChannelMessages( const missedMessages = filterOwnChannelMessages(
getMessagesSince( getMessagesSince(chatJid, sinceTimestamp, deps.assistantName),
chatJid,
sinceTimestamp,
deps.assistantName,
),
); );
if (missedMessages.length === 0) { if (missedMessages.length === 0) {
@@ -318,6 +311,10 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): {
let idleTimer: ReturnType<typeof setTimeout> | null = null; let idleTimer: ReturnType<typeof setTimeout> | null = null;
let latestProgressText: string | null = null; let latestProgressText: string | null = null;
let latestProgressRendered: string | null = null;
let progressMessageId: string | null = null;
let progressStartedAt: number | null = null;
let progressTicker: ReturnType<typeof setInterval> | null = null;
const resetIdleTimer = () => { const resetIdleTimer = () => {
if (idleTimer) clearTimeout(idleTimer); if (idleTimer) clearTimeout(idleTimer);
@@ -337,15 +334,98 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): {
let finalOutputSentToUser = false; let finalOutputSentToUser = false;
let progressOutputSentToUser = false; let progressOutputSentToUser = false;
let poisonedSessionDetected = false; let poisonedSessionDetected = false;
const isClaudeCodeAgent = (group.agentType || 'claude-code') === 'claude-code'; const isClaudeCodeAgent =
(group.agentType || 'claude-code') === 'claude-code';
const clearProgressTicker = () => {
if (progressTicker) {
clearInterval(progressTicker);
progressTicker = 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}`);
if (seconds > 0 || elapsedParts.length === 0) {
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 () => {
await syncTrackedProgressMessage();
clearProgressTicker();
};
const sendProgressMessage = async (text: string) => { const sendProgressMessage = async (text: string) => {
if (!text || text === latestProgressText) { if (!text || text === latestProgressText) {
return; return;
} }
if (progressStartedAt === null) {
progressStartedAt = Date.now();
}
latestProgressText = text; latestProgressText = text;
await channel.sendMessage(chatJid, text); const rendered = renderProgressMessage(text);
if (progressMessageId && channel.editMessage) {
await syncTrackedProgressMessage();
progressOutputSentToUser = true;
return;
}
if (channel.sendAndTrack) {
progressMessageId = await channel.sendAndTrack(chatJid, rendered);
if (progressMessageId) {
latestProgressRendered = rendered;
ensureProgressTicker();
progressOutputSentToUser = true;
return;
}
}
latestProgressRendered = rendered;
await channel.sendMessage(chatJid, rendered);
progressOutputSentToUser = true; progressOutputSentToUser = true;
}; };
@@ -399,9 +479,12 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): {
} }
if (text) { if (text) {
await finalizeProgressMessage();
await channel.sendMessage(chatJid, text); await channel.sendMessage(chatJid, text);
finalOutputSentToUser = true; finalOutputSentToUser = true;
} }
} else {
await finalizeProgressMessage();
} }
await channel.setTyping?.(chatJid, false); await channel.setTyping?.(chatJid, false);
@@ -426,6 +509,8 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): {
hadError = true; hadError = true;
} }
clearProgressTicker();
if (idleTimer) clearTimeout(idleTimer); if (idleTimer) clearTimeout(idleTimer);
if (hadError) { if (hadError) {
@@ -612,11 +697,7 @@ export function createMessageRuntime(deps: MessageRuntimeDeps): {
for (const [chatJid, group] of Object.entries(registeredGroups)) { for (const [chatJid, group] of Object.entries(registeredGroups)) {
const sinceTimestamp = lastAgentTimestamps[chatJid] || ''; const sinceTimestamp = lastAgentTimestamps[chatJid] || '';
const pending = filterOwnChannelMessages( const pending = filterOwnChannelMessages(
getMessagesSince( getMessagesSince(chatJid, sinceTimestamp, deps.assistantName),
chatJid,
sinceTimestamp,
deps.assistantName,
),
); );
if (pending.length > 0) { if (pending.length > 0) {
logger.info( logger.info(