import { APIConnectionError, APIStatusError } from '#/llm-adapter/contract/errors'; import { TOOL_SELECT_FLAG_ENV } from '#/agent/toolSelect/flag'; import type { StreamedMessagePart, ToolDescription as Tool } from '#human/llm/message'; import { emptyUsage } from '#human/llm/usage'; import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'; import { IAgentLLMRequesterService, type AgentLLMRequestFinish, } from '#/agent/llmRequester/llmRequester'; import { IAgentProfileService } from '#/agent/profile/profile'; import type { ILogger as Logger, LogPayload } from '#/_base/log/log'; import { configServices, createTestAgent, llmGenerateServices, logServices, requesterFromGenerateFn, telemetryServices, type TestAgentContext, } from '../../harness'; import { recordingTelemetry, type TelemetryRecord } from '../../app/telemetry/stubs'; interface CapturedLogEntry { readonly level: 'error' | 'warn' | 'info' | 'debug'; readonly message: string; readonly payload: LogPayload | undefined; } function captureLogs(): { logger: Logger; entries: CapturedLogEntry[] } { const entries: CapturedLogEntry[] = []; const capture = (level: CapturedLogEntry['level']) => (message: string, payload?: LogPayload) => { entries.push({ level, message, payload }); }; const logger: Logger = { error: capture('error'), warn: capture('warn'), info: capture('info'), debug: capture('debug'), child: () => logger, }; return { logger, entries }; } describe('LLMRequester service migration coverage', () => { describe('wire observability records', () => { let ctx: TestAgentContext; let llmRequester: IAgentLLMRequesterService; const requestTools: readonly Tool[] = [ { name: 'Lookup', description: 'Look up a short test value.', parameters: { type: 'object', properties: { query: { type: 'string' }, }, required: ['query'], additionalProperties: false, }, }, { name: 'DeferredLookup', description: 'Loaded on demand, not sent in top-level tools.', parameters: { type: 'object', properties: {}, }, deferred: true, }, ]; beforeEach(() => { vi.stubEnv(TOOL_SELECT_FLAG_ENV, '1'); ctx = createTestAgent(); llmRequester = ctx.get(IAgentLLMRequesterService); }); afterEach(async () => { vi.unstubAllEnvs(); try { await ctx.expectResumeMatches(); } finally { await ctx.dispose(); } }); it('records one tools snapshot per unique provider-visible tool table and one request per outbound call', async () => { ctx.configure({ modelCapabilities: { image_in: false, video_in: false, audio_in: false, thinking: false, tool_use: true, max_context_tokens: 128_000, dynamically_loaded_tools: true, }, }); ctx.mockNextResponse({ type: 'text', text: 'first response' }); await llmRequester.request({ messages: [userMessage('first direct request')], systemPrompt: 'request-specific system', tools: requestTools, source: { type: 'operation', requestKind: 'direct_test', logFields: { turnStep: '7.2', droppedCount: 3 }, }, }); ctx.mockNextResponse({ type: 'text', text: 'second response' }); await llmRequester.request({ messages: [userMessage('second direct request')], systemPrompt: 'request-specific system', tools: requestTools, source: { type: 'operation', requestKind: 'direct_test', logFields: { turnStep: '7.3' }, }, }); const snapshots = wireEvents(ctx, 'llm.tools_snapshot'); expect(snapshots).toHaveLength(1); const snapshotArgs = snapshots[0]?.args as Record | undefined; expect(snapshots[0]?.args).toMatchObject({ hash: expect.any(String), tools: [ { name: 'Lookup', description: 'Look up a short test value.', parameters: requestTools[0]!.parameters, }, ], }); expect(JSON.stringify(snapshots[0]?.args)).not.toContain('DeferredLookup'); const requests = wireEvents(ctx, 'llm.request'); expect(requests).toHaveLength(2); expect(requests[0]?.args).toMatchObject({ kind: 'loop', provider: 'openai', model: 'mock-model', modelAlias: 'mock-model', thinkingEffort: 'off', toolSelect: true, toolsHash: snapshotArgs?.['hash'], messageCount: 1, systemPromptHash: expect.any(String), systemPrompt: 'request-specific system', turnStep: '7.2', droppedCount: 3, }); expect(requests[1]?.args).toMatchObject({ toolsHash: snapshotArgs?.['hash'], messageCount: 1, turnStep: '7.3', }); }); it('records the resolved Kimi thinking keep default when thinking is enabled', async () => { ctx.configure({ modelCapabilities: { image_in: false, video_in: false, audio_in: false, thinking: true, tool_use: true, max_context_tokens: 1_000_000, }, }); ctx.get(IAgentProfileService).update({ thinkingLevel: 'high' }); ctx.mockNextResponse({ type: 'text', text: 'thinking response' }); await llmRequester.request(); expect(wireEvents(ctx, 'llm.request')).toHaveLength(1); expect(wireEvents(ctx, 'llm.request')[0]?.args).toMatchObject({ thinkingEffort: 'on', thinkingKeep: 'all', }); }); it('records the env-forced Kimi effort used by the provider', async () => { await ctx.dispose(); vi.stubEnv('KIMI_MODEL_THINKING_EFFORT', 'max'); ctx = createTestAgent(); llmRequester = ctx.get(IAgentLLMRequesterService); ctx.configure({ modelCapabilities: { image_in: false, video_in: false, audio_in: false, thinking: true, tool_use: true, max_context_tokens: 1_000_000, }, }); const profile = ctx.get(IAgentProfileService); profile.update({ thinkingLevel: 'high' }); expect(profile.data().thinkingLevel).toBe('on'); expect(profile.resolveModelContext().thinkingLevel).toBe('max'); ctx.mockNextResponse({ type: 'text', text: 'forced thinking response' }); await llmRequester.request(); expect(wireEvents(ctx, 'llm.request')).toHaveLength(1); expect(wireEvents(ctx, 'llm.request')[0]?.args).toMatchObject({ thinkingEffort: 'max', }); }); it('records strict projection resends as separate outbound requests', async () => { await ctx.dispose(); let calls = 0; ctx = createTestAgent( llmGenerateServices(requesterFromGenerateFn(async () => { calls += 1; if (calls === 1) { throw new APIStatusError(400, 'tool_use ids must be unique'); } return { id: 'strict-response', message: { role: 'assistant', content: [{ type: 'text', text: 'strict ok' }], toolCalls: [], }, usage: emptyUsage(), finishReason: 'completed', rawFinishReason: 'stop', }; })), ); llmRequester = ctx.get(IAgentLLMRequesterService); await llmRequester.request(); const requests = wireEvents(ctx, 'llm.request'); expect(requests).toHaveLength(2); expect((requests[0]?.args as Record | undefined)?.['projection']).toBeUndefined(); expect(requests[1]?.args).toMatchObject({ projection: 'strict' }); }); }); describe('tool-call deltas', () => { let ctx: TestAgentContext; let profile: IAgentProfileService; beforeEach(() => { ctx = createTestAgent(); profile = ctx.get(IAgentProfileService); profile.update({ activeToolNames: ['Lookup'] }); }); afterEach(async () => { try { await ctx.expectResumeMatches(); } finally { await ctx.dispose(); } }); it('preserves indexed tool-call deltas through AgentLoopService protocol events', async () => { await ctx.rpc.setPermission({ mode: 'auto' }); await ctx.rpc.registerTool({ name: 'Lookup', description: 'Look up a short test value.', parameters: { type: 'object', properties: { query: { type: 'string' }, }, required: ['query'], additionalProperties: false, }, }); ctx.mockNextProviderResponse({ parts: [ { type: 'tool_call_part', argumentsPart: '{"query"', index: 0 }, { type: 'function', id: 'call_lookup', name: 'Lookup', arguments: null, _streamIndex: 0, }, { type: 'tool_call_part', argumentsPart: ':"moon"}', index: 0 }, ], finishReason: 'tool_calls', }); await ctx.rpc.prompt({ input: [{ type: 'text', text: 'Look up moon' }] }); await ctx.untilToolCall({ content: 'moon-result', output: 'moon-result', }); expect(protocolEvents(ctx, 'tool.call.delta').map((event) => event.args)).toEqual([ { time: expect.any(Number), agentId: 'main', turnId: 0, toolCallId: 'call_lookup', name: 'Lookup', argumentsPart: undefined }, { time: expect.any(Number), agentId: 'main', turnId: 0, toolCallId: 'call_lookup', name: 'Lookup', argumentsPart: '{"query"' }, { time: expect.any(Number), agentId: 'main', turnId: 0, toolCallId: 'call_lookup', name: 'Lookup', argumentsPart: ':"moon"}' }, ]); expect(protocolEvents(ctx, 'toolCall').at(-1)?.args).toEqual({ turnId: 0, toolCallId: 'call_lookup', args: { query: 'moon' }, }); ctx.mockNextResponse({ type: 'text', text: 'The lookup result is moon-result.' }); await ctx.untilTurnEnd(); }); }); describe('request failure logging', () => { let ctx: TestAgentContext | undefined; afterEach(async () => { if (ctx === undefined) return; try { await ctx.expectResumeMatches(); } finally { await ctx.dispose(); ctx = undefined; } }); it('logs request failures without request payloads or stacks', async () => { const entries: unknown[] = []; const logger: Logger = { warn: (_message: string, payload?: LogPayload) => entries.push(payload), error: () => undefined, info: () => undefined, debug: () => undefined, child: () => logger, }; ctx = createTestAgent( llmGenerateServices(requesterFromGenerateFn(async () => { throw new Error('temporary provider failure'); })), logServices(logger), ); const llmRequester = ctx.get(IAgentLLMRequesterService); await expect( llmRequester.request({ source: { type: 'operation', requestKind: 'direct_test', logFields: { turnStep: '0.1' }, }, }), ).rejects.toMatchObject({ message: 'temporary provider failure' }); expect(entries).toEqual([ expect.objectContaining({ requestKind: 'direct_test', turnStep: '0.1', model: expect.any(String), errorName: 'Error', errorMessage: 'temporary provider failure', }), ]); expect(JSON.stringify(entries)).not.toContain('messages'); expect(JSON.stringify(entries)).not.toContain('stack'); }); it('fails a retryable provider error on the first attempt — retries are the loop\u2019s concern', async () => { let calls = 0; ctx = createTestAgent( llmGenerateServices(requesterFromGenerateFn(async () => { calls += 1; throw new APIConnectionError('terminated'); })), ); const llmRequester = ctx.get(IAgentLLMRequesterService); await expect(llmRequester.request()).rejects.toMatchObject({ name: 'APIConnectionError', }); expect(calls).toBe(1); }); it('tracks api_error with the v1 wire shape (model id, alias, protocol, status code)', async () => { const records: TelemetryRecord[] = []; ctx = createTestAgent( llmGenerateServices(requesterFromGenerateFn(async () => { throw new APIStatusError(429, 'rate limited'); })), telemetryServices(recordingTelemetry(records)), ); const llmRequester = ctx.get(IAgentLLMRequesterService); await expect(llmRequester.request()).rejects.toMatchObject({ name: 'APIStatusError', }); expect(records).toContainEqual({ event: 'api_error', properties: expect.objectContaining({ error_type: 'rate_limit', agent_id: 'main', model: 'mock-model', alias: 'mock-model', provider_type: 'kimi', protocol: 'openai', retryable: expect.any(Boolean), duration_ms: expect.any(Number), status_code: 429, }), }); }); it('tags api_error with turn_id and request_kind from the request source', async () => { const records: TelemetryRecord[] = []; ctx = createTestAgent( llmGenerateServices(requesterFromGenerateFn(async () => { throw new APIConnectionError('terminated'); })), telemetryServices(recordingTelemetry(records)), ); const llmRequester = ctx.get(IAgentLLMRequesterService); await expect( llmRequester.request({ source: { type: 'turn', turnId: 3, step: 1 } }), ).rejects.toMatchObject({ name: 'APIConnectionError' }); await expect( llmRequester.request({ source: { type: 'operation', turnId: 7, requestKind: 'full_compaction' }, }), ).rejects.toMatchObject({ name: 'APIConnectionError' }); expect(records).toContainEqual({ event: 'api_error', properties: expect.objectContaining({ error_type: 'network', turn_id: 3, request_kind: 'turn', }), }); expect(records).toContainEqual({ event: 'api_error', properties: expect.objectContaining({ error_type: 'network', turn_id: 7, request_kind: 'full_compaction', }), }); }); }); describe('request timing and budget', () => { let ctx: TestAgentContext; let llmRequester: IAgentLLMRequesterService; let profile: IAgentProfileService; let requestMaxTokens: unknown; let logEntries: CapturedLogEntry[]; beforeEach(() => { requestMaxTokens = undefined; const { logger, entries } = captureLogs(); logEntries = entries; ctx = createTestAgent( llmGenerateServices(requesterFromGenerateFn(async (_provider, _systemPrompt, _tools, _messages, callbacks, options) => { requestMaxTokens = options?.maxCompletionTokens; await callbacks?.onMessagePart?.({ type: 'text', text: 'timed' }); return { id: 'response-1', message: { role: 'assistant', content: [{ type: 'text', text: 'timed' }], toolCalls: [], }, usage: emptyUsage(), finishReason: 'completed', rawFinishReason: 'stop', }; })), configServices(() => ({ defaultModel: 'deepseek/deepseek-v4-flash', providers: { deepseek: { type: 'openai', apiKey: 'test-key', baseUrl: 'https://api.deepseek.example/v1', }, }, models: { 'deepseek/deepseek-v4-flash': { provider: 'deepseek', model: 'deepseek-v4-flash', maxContextSize: 1_000_000, maxOutputSize: 384_000, capabilities: ['tool_use'], }, }, })), logServices(logger), ); llmRequester = ctx.get(IAgentLLMRequesterService); profile = ctx.get(IAgentProfileService); profile.update({ modelAlias: 'deepseek/deepseek-v4-flash', systemPrompt: 'system', thinkingLevel: 'off', }); }); afterEach(async () => { try { await ctx.expectResumeMatches(); } finally { await ctx.dispose(); } }); it('emits stream timing and applies the model output budget through IAgentLLMRequesterService', async () => { const { parts, finish } = await collectLLMRequest((onPart) => llmRequester.request(undefined, onPart), ); expect(requestMaxTokens).toBe(384_000); expect(wireEvents(ctx, 'llm.request')[0]?.args).toMatchObject({ maxTokens: 384_000, }); expect(parts).toContainEqual({ type: 'text', text: 'timed' }); expect(finish).toMatchObject({ usage: emptyUsage(), model: 'deepseek/deepseek-v4-flash', providerMessageId: 'response-1', providerFinishReason: 'completed', rawFinishReason: 'stop', }); expect(finish.timing).toEqual( expect.objectContaining({ firstTokenLatencyMs: expect.any(Number), streamDurationMs: expect.any(Number), }), ); }); it('logs successful LLM responses with caller-provided request fields', async () => { await collectLLMRequest((onPart) => llmRequester.request( { source: { type: 'operation', requestKind: 'direct_test', logFields: { turnStep: '0.1' }, }, }, onPart, ), ); const responseLogs = logEntries.filter((entry) => entry.message === 'llm response'); expect(responseLogs).toHaveLength(1); const payload = responseLogs[0]?.payload as Record; expect(payload).toMatchObject({ requestKind: 'direct_test', turnStep: '0.1', ttftMs: expect.any(Number), streamDurationMs: expect.any(Number), outputTokens: expect.any(Number), serverDecodeMs: expect.any(Number), clientConsumeMs: expect.any(Number), }); expect(payload).not.toHaveProperty('requestBuildMs'); expect(payload).not.toHaveProperty('serverFirstTokenMs'); }); it('applies a per-request output budget override', async () => { await llmRequester.request({ maxOutputSize: 123_000 }); expect(requestMaxTokens).toBe(123_000); }); it('carries kosong decode accounting and leaves the TTFT split undefined without a dispatch boundary', async () => { const { finish } = await collectLLMRequest((onPart) => llmRequester.request(undefined, onPart), ); const timing = finish.timing; expect(timing?.firstTokenLatencyMs).toBeGreaterThanOrEqual(0); expect(timing?.serverDecodeMs).toBeGreaterThanOrEqual(0); expect(timing?.clientConsumeMs).toBeGreaterThanOrEqual(0); expect(timing?.requestBuildMs).toBeUndefined(); expect(timing?.serverFirstTokenMs).toBeUndefined(); }); }); describe('per-turn intent handoff', () => { let ctx: TestAgentContext; let llmRequester: IAgentLLMRequesterService; let capturedCacheKey: unknown; beforeEach(() => { capturedCacheKey = undefined; ctx = createTestAgent( llmGenerateServices(requesterFromGenerateFn(async (_provider, _systemPrompt, _tools, _messages, _callbacks, options) => { capturedCacheKey = options?.cacheKey; return { id: 'response-1', message: { role: 'assistant', content: [{ type: 'text', text: 'intent' }], toolCalls: [], }, usage: emptyUsage(), finishReason: 'completed', rawFinishReason: 'stop', }; })), ); llmRequester = ctx.get(IAgentLLMRequesterService); }); afterEach(async () => { try { await ctx.expectResumeMatches(); } finally { await ctx.dispose(); } }); it('forwards the session id as the per-turn cache-key intent', async () => { await llmRequester.request(); expect(capturedCacheKey).toBe('test-session'); }); }); }); type ProtocolEvent = Extract< TestAgentContext['allEvents'][number], { readonly type: '[rpc]' } >; type WireEvent = Extract< TestAgentContext['allEvents'][number], { readonly type: '[wire]' } >; function protocolEvents( ctx: TestAgentContext, eventName: string, ): readonly ProtocolEvent[] { return ctx.allEvents.filter( (event): event is ProtocolEvent => event.type === '[rpc]' && event.event === eventName, ); } function wireEvents( ctx: TestAgentContext, eventName: string, ): readonly WireEvent[] { return ctx.allEvents.filter( (event): event is WireEvent => event.type === '[wire]' && event.event === eventName, ); } function userMessage(text: string) { return { role: 'user' as const, content: [{ type: 'text' as const, text }], toolCalls: [] }; } async function collectLLMRequest( request: (onPart: (part: StreamedMessagePart) => void) => Promise, ): Promise<{ parts: StreamedMessagePart[]; finish: AgentLLMRequestFinish }> { const parts: StreamedMessagePart[] = []; const finish = await request((part) => { parts.push(part); }); return { parts, finish }; }