Skip to content

Commit 6bdef57

Browse files
codeaholicguycodeaholicguy
committed
feat(cli): surface polling-loop errors and add diagnostic logging
1 parent 3f2b339 commit 6bdef57

3 files changed

Lines changed: 315 additions & 16 deletions

File tree

‎package-lock.json‎

Lines changed: 15 additions & 2 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎packages/cli/src/__tests__/commands/channel.test.ts‎

Lines changed: 248 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,248 @@
1+
import { describe, it, expect, beforeEach, afterEach, jest } from '@jest/globals';
2+
import type { AgentAdapter, AgentInfo, ConversationMessage } from '@ai-devkit/agent-manager';
3+
import { AgentStatus } from '@ai-devkit/agent-manager';
4+
import type { TelegramAdapter } from '@ai-devkit/channel-connector';
5+
import { ui } from '../../util/terminal-ui';
6+
7+
jest.mock('../../util/terminal-ui', () => ({
8+
ui: {
9+
text: jest.fn(),
10+
info: jest.fn(),
11+
success: jest.fn(),
12+
warning: jest.fn(),
13+
error: jest.fn(),
14+
},
15+
}));
16+
17+
// Imported AFTER mocks so the module under test picks up the mocked ui
18+
// eslint-disable-next-line @typescript-eslint/no-var-requires
19+
const { startOutputPolling } = require('../../commands/channel');
20+
21+
const POLL_INTERVAL_MS = 2000;
22+
23+
function makeAgent(overrides: Partial<AgentInfo> = {}): AgentInfo {
24+
return {
25+
name: 'test-agent',
26+
type: 'claude',
27+
status: AgentStatus.RUNNING,
28+
summary: 'session',
29+
pid: 12345,
30+
projectPath: '/tmp/proj',
31+
sessionId: 'session-1',
32+
lastActive: new Date(),
33+
sessionFilePath: '/tmp/session.jsonl',
34+
...overrides,
35+
};
36+
}
37+
38+
function makeMessage(overrides: Partial<ConversationMessage> = {}): ConversationMessage {
39+
return {
40+
role: 'assistant',
41+
content: 'agent reply',
42+
timestamp: new Date(),
43+
...overrides,
44+
} as ConversationMessage;
45+
}
46+
47+
describe('startOutputPolling', () => {
48+
let agentAdapter: jest.Mocked<Pick<AgentAdapter, 'getConversation'>>;
49+
let telegram: { sendMessage: jest.Mock<(chatId: string, text: string) => Promise<void>> };
50+
let chatIdRef: { value: string | null };
51+
let interval: NodeJS.Timeout | null;
52+
53+
beforeEach(() => {
54+
jest.useFakeTimers();
55+
agentAdapter = { getConversation: jest.fn() };
56+
telegram = { sendMessage: jest.fn(() => Promise.resolve()) };
57+
chatIdRef = { value: null };
58+
interval = null;
59+
jest.clearAllMocks();
60+
});
61+
62+
afterEach(() => {
63+
if (interval) clearInterval(interval);
64+
jest.useRealTimers();
65+
});
66+
67+
it('seeds lastMessageCount from initial getConversation so existing messages are not re-sent', async () => {
68+
const existing = [makeMessage({ content: 'old' })];
69+
agentAdapter.getConversation.mockReturnValueOnce(existing);
70+
71+
interval = startOutputPolling(
72+
telegram as unknown as TelegramAdapter,
73+
agentAdapter as unknown as AgentAdapter,
74+
makeAgent(),
75+
chatIdRef,
76+
);
77+
78+
chatIdRef.value = '419354621';
79+
80+
// Tick: getConversation returns same single message → no new messages
81+
agentAdapter.getConversation.mockReturnValueOnce(existing);
82+
await jest.advanceTimersByTimeAsync(POLL_INTERVAL_MS);
83+
84+
expect(telegram.sendMessage).not.toHaveBeenCalled();
85+
});
86+
87+
it('skips ticks when no chat is authorized yet', async () => {
88+
agentAdapter.getConversation.mockReturnValue([]);
89+
interval = startOutputPolling(
90+
telegram as unknown as TelegramAdapter,
91+
agentAdapter as unknown as AgentAdapter,
92+
makeAgent(),
93+
{ value: null },
94+
);
95+
96+
await jest.advanceTimersByTimeAsync(POLL_INTERVAL_MS * 3);
97+
98+
// Only the initial seed call — no per-tick getConversation since we early-return
99+
expect(agentAdapter.getConversation).toHaveBeenCalledTimes(1);
100+
expect(telegram.sendMessage).not.toHaveBeenCalled();
101+
});
102+
103+
it('skips ticks when agent has no sessionFilePath', async () => {
104+
const agent = makeAgent({ sessionFilePath: undefined });
105+
interval = startOutputPolling(
106+
telegram as unknown as TelegramAdapter,
107+
agentAdapter as unknown as AgentAdapter,
108+
agent,
109+
{ value: '419354621' },
110+
);
111+
112+
await jest.advanceTimersByTimeAsync(POLL_INTERVAL_MS * 3);
113+
114+
// Initial seed is gated by sessionFilePath too, so getConversation never called
115+
expect(agentAdapter.getConversation).not.toHaveBeenCalled();
116+
expect(telegram.sendMessage).not.toHaveBeenCalled();
117+
});
118+
119+
it('sends new assistant messages to Telegram', async () => {
120+
agentAdapter.getConversation.mockReturnValueOnce([]); // initial seed
121+
interval = startOutputPolling(
122+
telegram as unknown as TelegramAdapter,
123+
agentAdapter as unknown as AgentAdapter,
124+
makeAgent(),
125+
chatIdRef,
126+
);
127+
128+
chatIdRef.value = '419354621';
129+
agentAdapter.getConversation.mockReturnValueOnce([
130+
makeMessage({ role: 'assistant', content: 'reply A' }),
131+
makeMessage({ role: 'assistant', content: 'reply B' }),
132+
]);
133+
134+
await jest.advanceTimersByTimeAsync(POLL_INTERVAL_MS);
135+
136+
expect(telegram.sendMessage).toHaveBeenCalledTimes(2);
137+
expect(telegram.sendMessage).toHaveBeenCalledWith('419354621', 'reply A');
138+
expect(telegram.sendMessage).toHaveBeenCalledWith('419354621', 'reply B');
139+
});
140+
141+
it('skips messages with role "user"', async () => {
142+
agentAdapter.getConversation.mockReturnValueOnce([]);
143+
interval = startOutputPolling(
144+
telegram as unknown as TelegramAdapter,
145+
agentAdapter as unknown as AgentAdapter,
146+
makeAgent(),
147+
chatIdRef,
148+
);
149+
150+
chatIdRef.value = '419354621';
151+
agentAdapter.getConversation.mockReturnValueOnce([
152+
makeMessage({ role: 'user', content: 'inbound — already delivered to terminal' }),
153+
makeMessage({ role: 'assistant', content: 'outbound' }),
154+
]);
155+
156+
await jest.advanceTimersByTimeAsync(POLL_INTERVAL_MS);
157+
158+
expect(telegram.sendMessage).toHaveBeenCalledTimes(1);
159+
expect(telegram.sendMessage).toHaveBeenCalledWith('419354621', 'outbound');
160+
});
161+
162+
it('skips messages with empty/missing content', async () => {
163+
agentAdapter.getConversation.mockReturnValueOnce([]);
164+
interval = startOutputPolling(
165+
telegram as unknown as TelegramAdapter,
166+
agentAdapter as unknown as AgentAdapter,
167+
makeAgent(),
168+
chatIdRef,
169+
);
170+
171+
chatIdRef.value = '419354621';
172+
agentAdapter.getConversation.mockReturnValueOnce([
173+
makeMessage({ role: 'assistant', content: '' }),
174+
makeMessage({ role: 'assistant', content: undefined as unknown as string }),
175+
makeMessage({ role: 'assistant', content: 'has content' }),
176+
]);
177+
178+
await jest.advanceTimersByTimeAsync(POLL_INTERVAL_MS);
179+
180+
expect(telegram.sendMessage).toHaveBeenCalledTimes(1);
181+
expect(telegram.sendMessage).toHaveBeenCalledWith('419354621', 'has content');
182+
});
183+
184+
it('does not crash if getConversation throws (agent terminated)', async () => {
185+
agentAdapter.getConversation.mockReturnValueOnce([]); // seed
186+
interval = startOutputPolling(
187+
telegram as unknown as TelegramAdapter,
188+
agentAdapter as unknown as AgentAdapter,
189+
makeAgent(),
190+
chatIdRef,
191+
);
192+
193+
chatIdRef.value = '419354621';
194+
195+
agentAdapter.getConversation.mockImplementationOnce(() => {
196+
throw new Error('ENOENT: no such file');
197+
});
198+
await jest.advanceTimersByTimeAsync(POLL_INTERVAL_MS);
199+
200+
expect(telegram.sendMessage).not.toHaveBeenCalled();
201+
expect(ui.error).not.toHaveBeenCalled(); // getConversation throws stay silent
202+
203+
// Loop must keep running — next tick succeeds
204+
agentAdapter.getConversation.mockReturnValueOnce([
205+
makeMessage({ content: 'recovered' }),
206+
]);
207+
await jest.advanceTimersByTimeAsync(POLL_INTERVAL_MS);
208+
209+
expect(telegram.sendMessage).toHaveBeenCalledTimes(1);
210+
expect(telegram.sendMessage).toHaveBeenCalledWith('419354621', 'recovered');
211+
});
212+
213+
it('logs ui.error when sendMessage throws but keeps loop alive', async () => {
214+
agentAdapter.getConversation.mockReturnValueOnce([]);
215+
interval = startOutputPolling(
216+
telegram as unknown as TelegramAdapter,
217+
agentAdapter as unknown as AgentAdapter,
218+
makeAgent(),
219+
chatIdRef,
220+
);
221+
222+
chatIdRef.value = '419354621';
223+
telegram.sendMessage.mockRejectedValueOnce(new Error('Telegram down'));
224+
225+
const initialBatch = [
226+
makeMessage({ content: 'first message — fails' }),
227+
makeMessage({ content: 'second message — succeeds' }),
228+
];
229+
agentAdapter.getConversation.mockReturnValueOnce(initialBatch);
230+
231+
await jest.advanceTimersByTimeAsync(POLL_INTERVAL_MS);
232+
233+
expect(telegram.sendMessage).toHaveBeenCalledTimes(2);
234+
expect(ui.error).toHaveBeenCalledWith(
235+
expect.stringContaining('Failed to send agent response to Telegram: Telegram down'),
236+
);
237+
238+
// Next tick: conversation grows by one — failed message is NOT retried
239+
// (lastMessageCount already advanced) but the new message flows.
240+
agentAdapter.getConversation.mockReturnValueOnce([
241+
...initialBatch,
242+
makeMessage({ content: 'next-tick reply' }),
243+
]);
244+
await jest.advanceTimersByTimeAsync(POLL_INTERVAL_MS);
245+
246+
expect(telegram.sendMessage.mock.calls.some(c => c[1] === 'next-tick reply')).toBe(true);
247+
});
248+
});

‎packages/cli/src/commands/channel.ts‎

Lines changed: 52 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -99,43 +99,81 @@ function setupInputHandler(
9999
});
100100
}
101101

102-
function startOutputPolling(
102+
export function startOutputPolling(
103103
telegram: TelegramAdapter,
104104
agentAdapter: AgentAdapter,
105105
agent: AgentInfo,
106106
chatIdRef: { value: string | null },
107107
): NodeJS.Timeout {
108108
let lastMessageCount = 0;
109109

110+
debug(`startOutputPolling: sessionFilePath=${agent.sessionFilePath ?? 'null'}`);
111+
110112
if (agent.sessionFilePath) {
111113
try {
112114
const existing = agentAdapter.getConversation(agent.sessionFilePath);
113115
lastMessageCount = existing.length;
114-
} catch {
115-
// Session file might not exist yet
116+
debug(`Initial conversation length: ${lastMessageCount}`);
117+
} catch (error: unknown) {
118+
debug(`Initial getConversation threw: ${getErrorMessage(error)}`);
116119
}
117120
}
118121

122+
let tickCount = 0;
123+
let lastReportedLength = lastMessageCount;
124+
119125
return setInterval(async () => {
120-
if (!chatIdRef.value || !agent.sessionFilePath) return;
126+
tickCount += 1;
127+
128+
if (!chatIdRef.value) {
129+
if (tickCount % 15 === 1) {
130+
debug(`poll skip: no authorized chat yet (tick ${tickCount})`);
131+
}
132+
return;
133+
}
134+
if (!agent.sessionFilePath) {
135+
if (tickCount % 15 === 1) {
136+
debug(`poll skip: agent has no sessionFilePath (tick ${tickCount})`);
137+
}
138+
return;
139+
}
121140

141+
let newMessages;
122142
try {
123143
const conversation = agentAdapter.getConversation(agent.sessionFilePath);
124-
const newMessages = conversation.slice(lastMessageCount);
144+
newMessages = conversation.slice(lastMessageCount);
145+
if (conversation.length !== lastReportedLength) {
146+
debug(`Conversation length changed: ${lastReportedLength} -> ${conversation.length} (lastMessageCount=${lastMessageCount}, new=${newMessages.length})`);
147+
lastReportedLength = conversation.length;
148+
}
125149
lastMessageCount = conversation.length;
150+
} catch (error: unknown) {
151+
debug(`getConversation threw: ${getErrorMessage(error)}`);
152+
return;
153+
}
126154

127-
if (newMessages.length > 0) {
128-
debug(`Polled ${newMessages.length} new message(s) from agent conversation`);
155+
if (newMessages.length > 0) {
156+
debug(`Polled ${newMessages.length} new message(s) from agent conversation`);
157+
}
158+
159+
for (const msg of newMessages) {
160+
const contentType = typeof msg.content;
161+
const contentLen = msg.content ? String(msg.content).length : 0;
162+
debug(`message: role=${msg.role}, contentType=${contentType}, length=${contentLen}`);
163+
164+
if (msg.role === 'user' || !msg.content) {
165+
debug(`skipping message (role=${msg.role}, hasContent=${Boolean(msg.content)})`);
166+
continue;
129167
}
130168

131-
for (const msg of newMessages) {
132-
if (msg.role !== 'user' && msg.content) {
133-
await telegram.sendMessage(chatIdRef.value, msg.content);
134-
debug(`Sent agent response to Telegram (role: ${msg.role}, length: ${msg.content.length})`);
135-
}
169+
try {
170+
await telegram.sendMessage(chatIdRef.value, msg.content);
171+
debug(`Sent agent response to Telegram (role: ${msg.role}, length: ${contentLen})`);
172+
} catch (error: unknown) {
173+
const message = getErrorMessage(error);
174+
ui.error(`Failed to send agent response to Telegram: ${message}`);
175+
debug(`sendMessage failed: ${message}`);
136176
}
137-
} catch {
138-
// Agent may have terminated — check later
139177
}
140178
}, AGENT_POLL_INTERVAL_MS);
141179
}

0 commit comments

Comments
 (0)