Skip to content

Commit 255635d

Browse files
V48 Gate 3 (implementation-only): write raw LLM wire I/O to ~/.bitcode/logs/executions/ID for every call, including failures
A larger repo (6274 files) hit a 413 request_too_large on the very first Setup-phase call, but there was no way to see the literal request that triggered it: the existing prompt sidecar (writePromptIO) only fires on success and writes a flattened/truncated prompt string under /tmp. writeRawLLMIO writes the literal request (system+user messages, config) at call time and the literal response or raw error at completion, one JSON file per LLM call, under ~/.bitcode/logs/executions/{runId}/ so it survives past /tmp getting cleared. Wired into logLLMSubstepStart/Success/Error so every call is covered regardless of the DIAG_* verbosity flags — the error path especially, since that's exactly when you need to see what was sent over the wire. Guarded off under NODE_ENV=test so jest's mocked LLM calls don't litter the developer's home directory.
1 parent df9d2d0 commit 255635d

3 files changed

Lines changed: 107 additions & 4 deletions

File tree

packages/agent-generics/src/diagnostics/instrumentation.ts

Lines changed: 48 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,6 @@
11
// Diagnostics instrumentation utilities (formerly named hooks)
22
import type { Execution } from '@bitcode/execution-generics/Execution';
3-
import { log, writePromptIO, writeStepTraceJSON } from '@bitcode/logger';
3+
import { log, writePromptIO, writeStepTraceJSON, writeRawLLMIO } from '@bitcode/logger';
44
import { DIAG_ENABLED, DIAG_TRACES, DIAG_FULL_TRACES, DIAG_FULL_PROMPTS, DIAG_TRACE_MAX, DIAG_WRITE_PROMPT_IO, DIAG_WRITE_STEP_TRACES } from './config';
55
import { collectExecutionTrace, summarizeExecutionTrace } from './trace';
66

@@ -45,6 +45,14 @@ function maybeLogDiagnosticsBanner() {
4545
} catch {}
4646
}
4747

48+
// The literal wire-call correlation key for the raw LLM I/O sidecar — the
49+
// full execution path (which already encodes phase/agent/step/failsafe/
50+
// gen-N/generation) plus the sequence, so concurrent or repeated calls
51+
// within the same agent never collide.
52+
function rawLLMPathKey(ctx: ReturnType<typeof getCtx>): string {
53+
return [...(ctx.path || []), ctx.sequence].filter(Boolean).join(':');
54+
}
55+
4856
export async function logLLMSubstepStart(
4957
execution: Execution,
5058
sequence: string,
@@ -54,8 +62,21 @@ export async function logLLMSubstepStart(
5462
llmConfig?: { model?: string; provider?: string }
5563
) {
5664
maybeLogDiagnosticsBanner();
57-
if (!(DIAG_ENABLED || DIAG_FULL_PROMPTS || DIAG_TRACES)) return;
5865
const ctx = getCtx(execution, sequence);
66+
67+
// Always attempt the raw wire-exchange sidecar (its own env gate, default
68+
// on) — independent of the DIAG_* verbosity flags below, since this is a
69+
// local-debugging artifact meant to survive even when nothing else logs.
70+
writeRawLLMIO({
71+
executionId: String(ctx.correlationId || ''),
72+
pathKey: rawLLMPathKey(ctx),
73+
kind: 'request',
74+
provider: (llmConfig as any)?.provider,
75+
model: llmConfig?.model,
76+
content: { systemPrompt, userPrompt, combinedPrompt, ...ctx },
77+
}).catch(() => {});
78+
79+
if (!(DIAG_ENABLED || DIAG_FULL_PROMPTS || DIAG_TRACES)) return;
5980
log('[llm substep] start', 'debug', {
6081
...ctx,
6182
systemLen: systemPrompt.length,
@@ -83,6 +104,16 @@ export async function logLLMSubstepSuccess(
83104
) {
84105
maybeLogDiagnosticsBanner();
85106
const ctx = getCtx(execution, sequence);
107+
108+
writeRawLLMIO({
109+
executionId: String(ctx.correlationId || ''),
110+
pathKey: rawLLMPathKey(ctx),
111+
kind: 'response',
112+
provider: output?.metadata?.provider,
113+
model: output?.metadata?.model,
114+
content: { content: output?.content, usage: output?.usage, metadata: output?.metadata },
115+
}).catch(() => {});
116+
86117
if (DIAG_ENABLED || DIAG_FULL_PROMPTS || DIAG_TRACES) {
87118
log('[llm substep] success', 'debug', {
88119
...ctx,
@@ -138,8 +169,22 @@ export function logLLMSubstepError(
138169
err: unknown,
139170
durationMs?: number
140171
) {
141-
if (!DIAG_ENABLED) return;
142172
const ctx = getCtx(execution, sequence);
173+
174+
// The raw sidecar is the whole point on the failure path — a 413/400/etc.
175+
// from the provider is exactly the case where you need to see the literal
176+
// request that triggered it, and DIAG_ENABLED (verbose console logging)
177+
// being off shouldn't suppress that.
178+
writeRawLLMIO({
179+
executionId: String(ctx.correlationId || ''),
180+
pathKey: rawLLMPathKey(ctx),
181+
kind: 'error',
182+
provider: ctx.provider,
183+
model: ctx.model,
184+
content: err,
185+
}).catch(() => {});
186+
187+
if (!DIAG_ENABLED) return;
143188
const message = err instanceof Error ? err.message : String(err);
144189
log('[llm substep] error', 'error', {
145190
...ctx,

packages/logger/src/index.ts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1 +1 @@
1-
export { log, writePromptIO, writeStepTraceJSON } from './logger';
1+
export { log, writePromptIO, writeStepTraceJSON, writeRawLLMIO } from './logger';

packages/logger/src/logger.ts

Lines changed: 58 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -237,6 +237,64 @@ export async function writePromptIO(opts: {
237237
}
238238
}
239239

240+
// ------------------------------------------------------------
241+
// Raw LLM wire I/O writer (local debugging utility)
242+
//
243+
// Unlike writePromptIO (a flattened-prompt sidecar under /tmp, success-only,
244+
// intended for quick tailing), this writes the literal request payload and
245+
// the literal response/error for every LLM call — including failures like a
246+
// 413 request_too_large — to a per-run directory under the user's home
247+
// directory, so it survives past /tmp getting cleared and is easy to find.
248+
// ------------------------------------------------------------
249+
250+
const RAW_LLM_LOG_BASE_DIR = joinPath(os.homedir(), '.bitcode', 'logs', 'executions');
251+
let __rawLLMIOSeq = 0;
252+
253+
export async function writeRawLLMIO(opts: {
254+
executionId?: string;
255+
pathKey: string;
256+
kind: 'request' | 'response' | 'error';
257+
provider?: string;
258+
model?: string;
259+
content: unknown;
260+
}): Promise<string | undefined> {
261+
try {
262+
const enabledEnv = String(process?.env?.BITCODE_WRITE_RAW_LLM_IO ?? '1').toLowerCase();
263+
if (enabledEnv === '0' || enabledEnv === 'false') return undefined;
264+
// Never litter the developer's home directory from a test run — jest
265+
// exercises this same LLM-substep code path with mocked LLMs.
266+
if (process?.env?.NODE_ENV === 'test') return undefined;
267+
268+
const runDir = joinPath(RAW_LLM_LOG_BASE_DIR, sanitizeId(opts.executionId || 'run'));
269+
try { await fs.mkdir(runDir, { recursive: true }); } catch {}
270+
271+
const safe = (s: any) => String(s || '').toLowerCase().replace(/[^a-z0-9-_]+/g, '-').slice(0, 160) || 'na';
272+
const seq = String(++__rawLLMIOSeq).padStart(5, '0');
273+
const filename = joinPath(runDir, `${seq}-${safe(opts.pathKey)}.${opts.kind}.json`);
274+
275+
const payload = opts.kind === 'error'
276+
? {
277+
timestamp: new Date().toISOString(),
278+
provider: opts.provider,
279+
model: opts.model,
280+
error: opts.content instanceof Error
281+
? { name: opts.content.name, message: opts.content.message, stack: opts.content.stack }
282+
: opts.content,
283+
}
284+
: {
285+
timestamp: new Date().toISOString(),
286+
provider: opts.provider,
287+
model: opts.model,
288+
content: opts.content,
289+
};
290+
291+
await fs.writeFile(filename, JSON.stringify(payload, null, 2), 'utf8');
292+
return filename;
293+
} catch {
294+
return undefined;
295+
}
296+
}
297+
240298
// ------------------------------------------------------------
241299
// Step Trace sidecar writer (debug utility)
242300
// ------------------------------------------------------------

0 commit comments

Comments
 (0)