reliability: low reasoning_effort, retry-with-backoff, LLM call logging

- send top-level reasoning_effort: "low" (LLM_REASONING_EFFORT) to cut the qwen3.8-27b CoT ~85%, so content is no longer truncated to null -> the ~50% 502s
- new env: LLM_MAX_TOKENS (default 4000, per-call opts.maxTokens still overrides), LLM_REASONING_EFFORT (default "low", off/empty omits the field)
- chat() retries up to 3 attempts: timeout/abort, 5xx, network errors (ECONNRESET/ECONNREFUSED/socket closed), null/empty content; backoff 2s->3s (2000*1.5^(n-1), +/-20% jitter); 4xx throws immediately
- logging: '[llm] chat ok' {ms, finishReason} on success; '[llm] chat failed' {attempts, lastStatus, message, totalMs} on final failure
- tests: 12 in llm.test.ts (retry success/failure, no 4xx retry, null-content retry, logging spies); AGENTS.md env table + gotchas updated
This commit is contained in:
2026-10-11 13:46:18 +00:00
parent 612de2fc40
commit 3297658c81
3 changed files with 395 additions and 63 deletions
+157 -22
View File
@@ -1,4 +1,4 @@
import { describe, expect, it } from 'vitest';
import { afterEach, describe, expect, it, vi } from 'vitest';
import { createLlmClient, DEFAULT_MAX_TOKENS } from './llm';
function json(body: unknown) {
@@ -10,42 +10,88 @@ function json(body: unknown) {
} as unknown as Response;
}
function httpError(status: number, text = 'upstream down') {
return {
ok: false,
status,
text: async () => text,
json: async () => ({}),
} as unknown as Response;
}
afterEach(() => {
vi.restoreAllMocks();
});
describe('createLlmClient (injectable transport)', () => {
it('chat posts model+messages to {base}/chat/completions and returns content', async () => {
const calls: { url: string; init?: RequestInit }[] = [];
const sent: { url: string; init?: RequestInit }[] = [];
const transport = async (url: string, init?: RequestInit) => {
calls.push({ url, init });
sent.push({ url, init });
return json({ choices: [{ message: { content: 'hello back' } }] });
};
const llm = createLlmClient({ transport, apiBase: 'http://x/v1/', model: 'm1' });
const out = await llm.chat([{ role: 'user', content: 'hi' }], { maxTokens: 10, temperature: 0.5 });
expect(out).toBe('hello back');
expect(calls[0].url).toBe('http://x/v1/chat/completions'); // trailing slash normalized
const body = JSON.parse(calls[0].init!.body as string);
expect(sent[0].url).toBe('http://x/v1/chat/completions'); // trailing slash normalized
const body = JSON.parse(sent[0].init!.body as string);
// The wire key is `max_tokens` (snake_case), never camelCase `maxTokens`.
expect(body).toEqual({
model: 'm1',
messages: [{ role: 'user', content: 'hi' }],
temperature: 0.5,
max_tokens: 10,
reasoning_effort: 'low',
});
// No auth header: the live vLLM endpoint requires no API key.
expect(calls[0].init!.headers).toEqual({ 'content-type': 'application/json' });
expect(sent[0].init!.headers).toEqual({ 'content-type': 'application/json' });
});
it('chat uses a generous default max_tokens when the caller omits it', async () => {
const calls: { url: string; init?: RequestInit }[] = [];
const sent: { url: string; init?: RequestInit }[] = [];
const transport = async (url: string, init?: RequestInit) => {
calls.push({ url, init });
sent.push({ url, init });
return json({ choices: [{ message: { content: 'ok' } }] });
};
const llm = createLlmClient({ transport, apiBase: 'http://x/v1', model: 'm1' });
await llm.chat([{ role: 'user', content: 'hi' }]);
const body = JSON.parse(calls[0].init!.body as string);
const body = JSON.parse(sent[0].init!.body as string);
expect(body.max_tokens).toBe(DEFAULT_MAX_TOKENS);
expect(body.max_tokens).toBe(4000);
});
it('chat sends reasoning_effort "low" by default', async () => {
const sent: { url: string; init?: RequestInit }[] = [];
const transport = async (url: string, init?: RequestInit) => {
sent.push({ url, init });
return json({ choices: [{ message: { content: 'ok' } }] });
};
const llm = createLlmClient({ transport, apiBase: 'http://x/v1', model: 'm1' });
await llm.chat([{ role: 'user', content: 'hi' }]);
const body = JSON.parse(sent[0].init!.body as string);
expect(body.reasoning_effort).toBe('low');
});
it('chat omits reasoning_effort when it is "off" or empty', async () => {
const sent: { url: string; init?: RequestInit }[] = [];
const transport = async (url: string, init?: RequestInit) => {
sent.push({ url, init });
return json({ choices: [{ message: { content: 'ok' } }] });
};
for (const effort of ['off', 'OFF', '']) {
sent.length = 0;
const llm = createLlmClient({
transport,
apiBase: 'http://x/v1',
model: 'm1',
reasoningEffort: effort,
});
await llm.chat([{ role: 'user', content: 'hi' }]);
const body = JSON.parse(sent[0].init!.body as string);
expect(body.reasoning_effort, `effort=${JSON.stringify(effort)}`).toBeUndefined();
}
});
it('listModels returns data[].id from GET {base}/models', async () => {
const transport = async (url: string) => {
expect(url).toBe('http://x/v1/models');
@@ -55,21 +101,110 @@ describe('createLlmClient (injectable transport)', () => {
expect(await llm.listModels()).toEqual(['a', 'b']);
});
it('chat throws on non-2xx with the HTTP status in the message', async () => {
const transport = async () =>
({
ok: false,
status: 503,
text: async () => 'upstream down',
json: async () => ({}),
} as unknown as Response);
const llm = createLlmClient({ transport, apiBase: 'http://x/v1', model: 'm' });
await expect(llm.chat([{ role: 'user', content: 'hi' }])).rejects.toThrow(/HTTP 503/);
it('chat retries 5xx and succeeds once the transport recovers (500, 500 → 200)', async () => {
const sent: { url: string; init?: RequestInit }[] = [];
const transport = async (url: string, init?: RequestInit) => {
sent.push({ url, init });
if (sent.length < 3) return httpError(500);
return json({ choices: [{ message: { content: 'recovered' } }] });
};
const llm = createLlmClient({ transport, apiBase: 'http://x/v1', model: 'm', retryBaseDelayMs: 1 });
const out = await llm.chat([{ role: 'user', content: 'hi' }]);
expect(out).toBe('recovered');
expect(sent).toHaveLength(3); // two failures, then success on the third attempt
});
it('chat throws when the response has no content', async () => {
const transport = async () => json({ choices: [] });
const llm = createLlmClient({ transport, apiBase: 'http://x/v1', model: 'm' });
it('chat gives up after exactly 3 attempts when the transport always returns 5xx', async () => {
const sent: { url: string; init?: RequestInit }[] = [];
const transport = async (url: string, init?: RequestInit) => {
sent.push({ url, init });
return httpError(500, 'still down');
};
const llm = createLlmClient({ transport, apiBase: 'http://x/v1', model: 'm', retryBaseDelayMs: 1 });
await expect(llm.chat([{ role: 'user', content: 'hi' }])).rejects.toThrow(/HTTP 500/);
expect(sent).toHaveLength(3);
});
it('chat does not retry on 4xx (deterministic client error → first attempt only)', async () => {
const sent: { url: string; init?: RequestInit }[] = [];
const transport = async (url: string, init?: RequestInit) => {
sent.push({ url, init });
return httpError(400, 'bad request');
};
const llm = createLlmClient({ transport, apiBase: 'http://x/v1', model: 'm', retryBaseDelayMs: 1 });
await expect(llm.chat([{ role: 'user', content: 'hi' }])).rejects.toThrow(/HTTP 400/);
expect(sent).toHaveLength(1);
});
it('chat retries a null content (truncation) and then succeeds (null → content)', async () => {
const sent: { url: string; init?: RequestInit }[] = [];
const transport = async (url: string, init?: RequestInit) => {
sent.push({ url, init });
if (sent.length === 1) return json({ choices: [{ message: { content: null } }] });
return json({ choices: [{ message: { content: 'real content' } }] });
};
const llm = createLlmClient({ transport, apiBase: 'http://x/v1', model: 'm', retryBaseDelayMs: 1 });
const out = await llm.chat([{ role: 'user', content: 'hi' }]);
expect(out).toBe('real content');
expect(sent).toHaveLength(2);
});
it('chat rejects with the HTTP status after 3 attempts when 5xx never recovers', async () => {
const sent: { url: string; init?: RequestInit }[] = [];
const transport = async (url: string, init?: RequestInit) => {
sent.push({ url, init });
return httpError(503);
};
const llm = createLlmClient({ transport, apiBase: 'http://x/v1', model: 'm', retryBaseDelayMs: 1 });
await expect(llm.chat([{ role: 'user', content: 'hi' }])).rejects.toThrow(/HTTP 503/);
expect(sent).toHaveLength(3);
});
it('chat rejects with a content error after 3 attempts when content is never present', async () => {
const sent: { url: string; init?: RequestInit }[] = [];
const transport = async (url: string, init?: RequestInit) => {
sent.push({ url, init });
return json({ choices: [] });
};
const llm = createLlmClient({ transport, apiBase: 'http://x/v1', model: 'm', retryBaseDelayMs: 1 });
await expect(llm.chat([{ role: 'user', content: 'hi' }])).rejects.toThrow(/no choices/);
expect(sent).toHaveLength(3);
});
it('chat logs one line on success and one on final failure', async () => {
const logSpy = vi.spyOn(console, 'log');
const errorSpy = vi.spyOn(console, 'error');
const okTransport = async () =>
json({ choices: [{ message: { content: 'ok' }, finish_reason: 'stop' }] });
const okLlm = createLlmClient({ transport: okTransport, apiBase: 'http://x/v1', model: 'm' });
await okLlm.chat([{ role: 'user', content: 'hi' }]);
expect(logSpy).toHaveBeenCalledWith(
'[llm] chat ok',
expect.objectContaining({ ms: expect.any(Number), finishReason: 'stop' }),
);
const failSent: { url: string; init?: RequestInit }[] = [];
const failTransport = async (url: string, init?: RequestInit) => {
failSent.push({ url, init });
return httpError(502, 'bad gateway');
};
const failLlm = createLlmClient({
transport: failTransport,
apiBase: 'http://x/v1',
model: 'm',
retryBaseDelayMs: 1,
});
await expect(failLlm.chat([{ role: 'user', content: 'hi' }])).rejects.toThrow(/HTTP 502/);
expect(failSent).toHaveLength(3);
expect(errorSpy).toHaveBeenCalledWith(
'[llm] chat failed',
expect.objectContaining({
attempts: 3,
lastStatus: 502,
message: expect.stringContaining('HTTP 502'),
totalMs: expect.any(Number),
}),
);
});
});
+221 -36
View File
@@ -1,18 +1,28 @@
// Thin OpenAI chat-completions client over native fetch (mirrors mesh-bot/src/llm).
// The transport is injectable so unit tests and the deterministic e2e stub can
// replace the network call. Config is read from env, never hardcoded:
// LLM_API_BASE (default https://ai.kkhost.pl/v1 — a vLLM endpoint, no API key)
// LLM_MODEL (default qwen3.8-27b — a vLLM *reasoning* model)
// LLM_TIMEOUT_MS (default 180000 — the 27B reasoning model can be slow)
// LLM_API_BASE (default https://ai.kkhost.pl/v1 — a vLLM endpoint, no API key)
// LLM_MODEL (default qwen3.8-27b — a vLLM *reasoning* model)
// LLM_TIMEOUT_MS (default 180000 — the 27B reasoning model can be slow)
// LLM_MAX_TOKENS (default 4000 — max *output* tokens per request)
// LLM_REASONING_EFFORT (default "low" — sent as top-level `reasoning_effort`;
// empty or "off" omits the field entirely)
//
// The live model is a REASONING model: it emits its chain-of-thought in the
// response's `reasoning` field and the final answer in `content`. It therefore
// needs a generous `max_tokens` budget to finish thinking before writing
// `content` — a too-small budget makes it run out mid-reasoning and return a
// null `content`. We always send an explicit, generous `max_tokens` (the
// OpenAI/vLLM wire key — NOT camelCase `maxTokens`, which the server ignores)
// and read only `choices[0].message.content`, ignoring `reasoning`. No auth
// header is added (the endpoint requires no key).
// response's `reasoning` field and the final answer in `content`. Sending
// top-level `reasoning_effort: "low"` cuts the CoT by ~85% (~4000 →
// ~400–600 tokens), so it fits comfortably inside the `max_tokens` budget and
// `content` comes back populated. (Other knobs misbehave on this build:
// "minimal" produced MORE CoT than "low", `chat_template_kwargs:
// {enable_thinking:false}` intermittently emits invalid JSON, and `/no_think`
// is silently ignored.) We read only `choices[0].message.content`, ignoring
// `reasoning`. No auth header is added (the endpoint requires no key).
//
// Reliability: `chat()` retries transient failures — timeout/abort, HTTP 5xx,
// network errors, and null/empty `content` (truncation safety net) — with up
// to 3 total attempts and 2s→3s backoff (±20% jitter). HTTP 4xx is a
// deterministic client error and throws immediately, with no retry. Every
// call is logged: one line on success, one on final failure.
export interface ChatMessage {
role: 'system' | 'user' | 'assistant';
@@ -36,14 +46,29 @@ export const DEFAULT_BASE = 'https://ai.kkhost.pl/v1';
export const DEFAULT_MODEL = 'qwen3.8-27b';
/**
* Generous token budget for every chat request. The live qwen3.8-27b is a
* Default max *output* tokens per chat request. The live qwen3.8-27b is a
* reasoning model: it spends `reasoning_tokens` on its chain-of-thought before
* writing the final answer into `content`. A small budget makes it run out
* mid-reasoning and return a null `content`, so we give it room to finish both.
* `max_tokens` is always set in the request body, even when a caller omits it.
* writing the final answer into `content`. With `reasoning_effort: "low"` a
* realistic turn uses ~800–1100 output tokens, so 4000 is ~4× headroom while
* staying under the upstream ~90s proxy wall. `max_tokens` is always set in the
* request body (the vLLM/OpenAI wire key — NOT camelCase `maxTokens`, which the
* server ignores), even when a caller omits it.
*/
export const DEFAULT_MAX_TOKENS = 4000;
/**
* Default for `LLM_REASONING_EFFORT`. Sending top-level `reasoning_effort:
* "low"` to the vLLM model cuts its chain-of-thought by ~85%, which is what
* keeps `content` from being truncated to null.
*/
export const DEFAULT_REASONING_EFFORT = 'low';
/** Total attempts `chat()` makes before giving up (1 initial + 2 retries). */
export const MAX_ATTEMPTS = 3;
/** Base retry backoff: retry 1 waits 2000ms, retry 2 waits 3000ms, each ±20% jitter. */
const RETRY_BASE_DELAY_MS = 2000;
const fetchTransport: Transport = (url, init) => fetch(url, init);
export interface LlmClientDeps {
@@ -51,6 +76,91 @@ export interface LlmClientDeps {
apiBase?: string;
model?: string;
timeoutMs?: number;
maxTokens?: number;
reasoningEffort?: string;
/**
* Base delay (ms) for the retry backoff, overriding RETRY_BASE_DELAY_MS.
* Mostly useful in tests to keep the suite fast.
*/
retryBaseDelayMs?: number;
}
/** parseInt with a fallback for unset/empty/malformed values. */
function envInt(name: string, fallback: number): number {
const raw = process.env[name]?.trim();
if (!raw) return fallback;
const n = parseInt(raw, 10);
return Number.isFinite(n) && n > 0 ? n : fallback;
}
/** Trimmed env value, or undefined when unset/empty. */
function envStr(name: string): string | undefined {
const raw = process.env[name]?.trim();
return raw ? raw : undefined;
}
function sleep(ms: number): Promise<void> {
return new Promise((resolve) => setTimeout(resolve, ms));
}
/** Backoff before retry `n` (1-based): `2000 * 1.5^(n-1)`, ±20% jitter. */
function backoffDelay(retry: number, baseMs: number): number {
const base = baseMs * 1.5 ** (retry - 1);
return base * (0.8 + Math.random() * 0.4);
}
/** Network-level error codes that mark a transient failure. */
const RETRYABLE_NET_CODES = new Set([
'ECONNRESET',
'ECONNREFUSED',
'ECONNABORTED',
'EPIPE',
'EHOSTUNREACH',
'ENETUNREACH',
'ETIMEDOUT',
'EAI_AGAIN',
'UND_ERR_CONNECT_TIMEOUT',
'UND_ERR_SOCKET',
'UND_ERR_REQ_SOCKET',
'UND_ERR_REQ_RETRY',
]);
/** True for a timeout/abort (an AbortSignal that fired, a TimeoutError, or AbortError). */
function isTimeoutOrAbort(err: unknown): boolean {
let e: unknown = err;
for (let i = 0; i < 3 && e; i++) {
if (e instanceof Error && (e.name === 'TimeoutError' || e.name === 'AbortError')) return true;
e = (e as { cause?: unknown })?.cause;
}
return false;
}
/** True for a transient network failure (ECONNRESET / ECONNREFUSED / socket closed / …). */
function isNetworkError(err: unknown): boolean {
let e: unknown = err;
let msg = '';
for (let i = 0; i < 3 && e; i++) {
if (e instanceof Error) {
msg += ` ${e.message}`;
const code = (e as Error & { code?: string }).code;
if (code && RETRYABLE_NET_CODES.has(code)) return true;
} else {
msg += ` ${String(e)}`;
}
e = (e as { cause?: unknown })?.cause;
}
return /socket closed|socket hang up|connection reset|connection refused|other side closed|fetch failed/i.test(
msg,
);
}
/** One transport attempt, classified as success / retryable / fatal. */
interface Attempt {
status?: number;
error?: Error;
retryable: boolean;
content?: string;
finishReason?: string | null;
}
export function createLlmClient(deps: LlmClientDeps = {}): LlmClient {
@@ -61,36 +171,111 @@ export function createLlmClient(deps: LlmClientDeps = {}): LlmClient {
deps.timeoutMs ? String(deps.timeoutMs) : (process.env.LLM_TIMEOUT_MS ?? '180000'),
10,
);
const maxTokens = deps.maxTokens ?? envInt('LLM_MAX_TOKENS', DEFAULT_MAX_TOKENS);
const effort = deps.reasoningEffort ?? envStr('LLM_REASONING_EFFORT') ?? DEFAULT_REASONING_EFFORT;
// "off" (case-insensitive) or empty disables the thinking knob entirely.
const sendEffort = effort !== '' && effort.toLowerCase() !== 'off';
const retryBaseMs = deps.retryBaseDelayMs ?? RETRY_BASE_DELAY_MS;
/**
* One POST to /chat/completions. Classifies the outcome:
* - success → content + finish_reason
* - retryable → timeout/abort, HTTP 5xx, network error, null/empty content
* - fatal → HTTP 4xx (deterministic client error) or an unexpected throw
*/
async function attemptOnce(payload: string, signal: AbortSignal): Promise<Attempt> {
let res: Response;
try {
res = await transport(`${apiBase}/chat/completions`, {
method: 'POST',
// No auth header: the ai.kkhost.pl vLLM endpoint requires no API key.
headers: { 'content-type': 'application/json' },
body: payload,
signal,
});
} catch (err) {
const e = err instanceof Error ? err : new Error(String(err));
// The transport threw: our AbortSignal fired (timeout/abort) or a
// network-level failure (ECONNRESET / ECONNREFUSED / socket closed).
return { error: e, retryable: signal.aborted || isTimeoutOrAbort(e) || isNetworkError(e) };
}
async function chat(messages: ChatMessage[], opts: ChatOptions = {}): Promise<string> {
const payload: Record<string, unknown> = { model, messages };
if (opts.temperature != null) payload.temperature = opts.temperature;
// Always send an explicit, generous `max_tokens` (the vLLM/OpenAI wire key —
// camelCase `maxTokens` is ignored by the server) so the reasoning model has
// room to finish `reasoning` before emitting `content`.
payload.max_tokens = opts.maxTokens ?? DEFAULT_MAX_TOKENS;
const res = await transport(`${apiBase}/chat/completions`, {
method: 'POST',
// No auth header: the ai.kkhost.pl vLLM endpoint requires no API key.
headers: { 'content-type': 'application/json' },
body: JSON.stringify(payload),
signal: AbortSignal.timeout(timeoutMs),
});
if (!res.ok) {
const text = await res.text().catch(() => '');
throw new Error(`chat failed: HTTP ${res.status} ${text.slice(0, 200)}`);
return {
status: res.status,
error: new Error(`chat failed: HTTP ${res.status} ${text.slice(0, 200)}`),
// 4xx is a deterministic client error → do not retry; 5xx is retryable.
retryable: res.status >= 500 && res.status < 600,
};
}
// Reasoning models also return their chain-of-thought in a separate
// `reasoning` field. We deliberately ignore it and use only the final
// answer, which lives in `content`.
const body = (await res.json()) as {
choices?: { message?: { content?: string; reasoning?: string | null } }[];
choices?: {
finish_reason?: string | null;
message?: { content?: string; reasoning?: string | null };
}[];
};
// The reasoning model can exhaust its output budget on the CoT and return
// a null `content` — treat that as a retryable truncation, not a success.
const content = body.choices?.[0]?.message?.content;
if (typeof content !== 'string') {
throw new Error('chat failed: no choices[0].message.content in response');
if (typeof content !== 'string' || content === '') {
return {
status: res.status,
error: new Error('chat failed: no choices[0].message.content in response'),
retryable: true,
};
}
return content;
return {
status: res.status,
retryable: false,
content,
finishReason: body.choices?.[0]?.finish_reason ?? null,
};
}
async function chat(messages: ChatMessage[], opts: ChatOptions = {}): Promise<string> {
const payload: Record<string, unknown> = {
model,
messages,
// The wire key is `max_tokens` (snake_case) — camelCase is ignored by the
// server. With `reasoning_effort: "low"` the CoT fits inside this budget,
// so `content` comes back populated.
max_tokens: opts.maxTokens ?? maxTokens,
};
if (opts.temperature != null) payload.temperature = opts.temperature;
if (sendEffort) payload.reasoning_effort = effort;
const totalStart = Date.now();
let lastStatus: number | undefined;
let lastError: Error = new Error('chat failed: no attempt completed');
for (let attempt = 1; attempt <= MAX_ATTEMPTS; attempt++) {
const out = await attemptOnce(JSON.stringify(payload), AbortSignal.timeout(timeoutMs));
if (out.status !== undefined) lastStatus = out.status;
if (out.error) lastError = out.error;
if (out.content !== undefined) {
console.log('[llm] chat ok', {
ms: Date.now() - totalStart,
finishReason: out.finishReason ?? null,
});
return out.content;
}
// Give up on a non-retryable failure, or when the last attempt is spent.
if (!out.retryable || attempt === MAX_ATTEMPTS) {
console.error('[llm] chat failed', {
attempts: attempt,
lastStatus,
message: lastError.message,
totalMs: Date.now() - totalStart,
});
throw lastError;
}
await sleep(backoffDelay(attempt, retryBaseMs));
}
// Unreachable: every loop path returns or throws.
throw lastError;
}
async function listModels(): Promise<string[]> {