docs: document llm runtime logs

This commit is contained in:
Codex
2026-06-21 23:43:02 +08:00
parent ff128a8e91
commit cde8d1940c
2 changed files with 552 additions and 0 deletions
+17
View File
@@ -48,6 +48,23 @@ All API requests require the configured access key:
x-api-key: <API_ACCESS_KEY>
```
## LLM Runtime Logs
LLM calls emit regular server-side logs from `src/lib/llm/client.ts`. These logs
are intended for local development, customer demos, and production
troubleshooting.
Example:
```text
[llm:start] provider=deepseek model=deepseek-v4-pro task=article_optimizer
[llm:response] task=article_optimizer duration_ms=18342 raw={"title":"..."}
[llm:validated] task=article_optimizer ok=true
```
The `raw=` field is truncated to 4000 characters to avoid log explosions. API
keys, prompts, system messages, and environment secrets are not logged.
## Commands
```bash
@@ -0,0 +1,535 @@
# LLM Runtime Logging Implementation Plan
> **For agentic workers:** REQUIRED SUB-SKILL: Use superpowers:subagent-driven-development (recommended) or superpowers:executing-plans to implement this plan task-by-task. Steps use checkbox (`- [ ]`) syntax for tracking.
**Goal:** Add regular runtime logs for every LLM call so developers can confirm which provider/model/task ran, how long it took, what raw content came back, and whether schema validation passed.
**Architecture:** Centralize logging in `src/lib/llm/client.ts`, not in each workflow node. Extend the LLM input type with an optional `task` label, have `generateJson` log start/response/error information, and have `generateValidatedJson` log validation success or Zod summaries. Workflow modules only pass task names such as `fact_extractor`, `article_optimizer`, `quality_inspector`, and `targeted_rewriter`.
**Tech Stack:** TypeScript, OpenAI-compatible SDK, Zod, Vitest console spies, existing Next.js runtime.
---
## Scope
This plan adds normal application logs for LLM calls. It does not add persistent log storage, request IDs, OpenTelemetry, log levels, redaction beyond avoiding API keys, or UI display of logs.
## File Structure
- Modify: `src/lib/llm/client.ts`
- Add `task?: string` to `GenerateInput`.
- Add central log formatting helpers.
- Log `[llm:start]`, `[llm:response]`, `[llm:validated]`, and `[llm:error]`.
- Keep API keys out of logs.
- Keep raw response logging truncated to 4000 characters by default.
- Modify: `src/lib/workflow/fact-extractor.ts`
- Pass `task: "fact_extractor"` into `generateValidatedJson`.
- Modify: `src/lib/workflow/article-optimizer.ts`
- Pass `task: "article_optimizer"` into `generateValidatedJson`.
- Modify: `src/lib/workflow/quality-inspector.ts`
- Pass `task: "quality_inspector"` into `generateValidatedJson`.
- Modify: `src/lib/workflow/targeted-rewriter.ts`
- Pass `task: "targeted_rewriter"` into `generateValidatedJson`.
- Modify: `src/lib/llm/__tests__/client.test.ts`
- Add tests for start/response/validated/error logs, truncation, and Zod error summary.
- Modify: `src/lib/workflow/__tests__/llm-integration.test.ts`
- Assert workflow nodes pass the expected `task` labels.
- Modify: `README.md`
- Document expected runtime log lines and state that keys are never logged.
## Log Contract
Use exactly these prefixes:
```text
[llm:start] provider=deepseek model=deepseek-v4-pro task=article_optimizer
[llm:response] task=article_optimizer duration_ms=18342 raw={"title":"..."}
[llm:validated] task=article_optimizer ok=true
[llm:validated] task=article_optimizer ok=false zod_error="title: Invalid input: expected string, received number"
[llm:error] task=article_optimizer duration_ms=2001 message="LLM provider error: ..."
```
Rules:
- `provider` and `model` come from the effective provider status and model override.
- `task` defaults to `unknown` when not supplied.
- `duration_ms` is measured around the provider request in `generateJson`.
- `raw` is the original response text before `JSON.parse`, truncated to 4000 characters.
- Do not log prompts, system messages, API keys, or environment secrets.
- Validation logs live in `generateValidatedJson`, so all schema-backed workflow calls get a pass/fail log automatically.
## Task 1: Add Central LLM Runtime Logging
**Files:**
- Modify: `src/lib/llm/client.ts`
- Modify: `src/lib/llm/__tests__/client.test.ts`
- [ ] **Step 1: Add failing logging tests**
Append these tests to `src/lib/llm/__tests__/client.test.ts` inside `describe("generateValidatedJson", () => { ... })`:
```ts
it("logs validation success with the supplied task label", async () => {
const infoSpy = vi.spyOn(console, "info").mockImplementation(() => {});
process.env.LLM_PROVIDER = "deepseek";
process.env.DEEPSEEK_API_KEY = "test-key";
client.setGenerateJsonForValidation(async () => ({ value: "from-llm" }));
const result = await client.generateValidatedJson({
schema: z.object({ value: z.string() }),
prompt: "Return JSON.",
task: "article_optimizer",
});
expect(result).toEqual({ value: "from-llm" });
expect(infoSpy).toHaveBeenCalledWith(
"[llm:validated] task=article_optimizer ok=true",
);
});
it("logs validation failure with a compact Zod summary", async () => {
const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => {});
process.env.LLM_PROVIDER = "deepseek";
process.env.DEEPSEEK_API_KEY = "test-key";
client.setGenerateJsonForValidation(async () => ({ value: 42 }));
const result = await client.generateValidatedJson({
schema: z.object({ value: z.string() }),
prompt: "Return JSON.",
task: "fact_extractor",
});
expect(result).toBeNull();
expect(warnSpy).toHaveBeenCalledWith(
expect.stringContaining("[llm:validated] task=fact_extractor ok=false"),
);
expect(warnSpy).toHaveBeenCalledWith(
expect.stringContaining("value"),
);
});
```
Add this new `describe` block below the existing `describe("generateValidatedJson", ...)` block:
```ts
describe("generateJson logging", () => {
const originalProvider = process.env.LLM_PROVIDER;
const originalDeepSeekKey = process.env.DEEPSEEK_API_KEY;
afterEach(() => {
process.env.LLM_PROVIDER = originalProvider;
process.env.DEEPSEEK_API_KEY = originalDeepSeekKey;
client.setChatCompletionForTesting(null);
vi.restoreAllMocks();
});
it("logs provider, model, task, duration, and truncated raw response", async () => {
const infoSpy = vi.spyOn(console, "info").mockImplementation(() => {});
process.env.LLM_PROVIDER = "deepseek";
process.env.DEEPSEEK_API_KEY = "test-key";
const longContent = `{"value":"${"x".repeat(4100)}"}`;
client.setChatCompletionForTesting(async () => ({
choices: [{ message: { content: longContent } }],
}));
const result = await client.generateJson<{ value: string }>({
prompt: "Return JSON.",
task: "article_optimizer",
});
expect(result.value).toHaveLength(4100);
expect(infoSpy).toHaveBeenCalledWith(
"[llm:start] provider=deepseek model=deepseek-v4-pro task=article_optimizer",
);
const responseLog = infoSpy.mock.calls
.map((call) => call[0])
.find((line) => line.startsWith("[llm:response]"));
expect(responseLog).toContain("task=article_optimizer");
expect(responseLog).toContain("duration_ms=");
expect(responseLog).toContain("raw=");
expect(responseLog?.length).toBeLessThan(4200);
});
it("logs provider errors without leaking API keys", async () => {
const infoSpy = vi.spyOn(console, "info").mockImplementation(() => {});
const errorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
process.env.LLM_PROVIDER = "deepseek";
process.env.DEEPSEEK_API_KEY = "super-secret-key";
client.setChatCompletionForTesting(async () => {
throw new Error("upstream unavailable");
});
await expect(
client.generateJson({
prompt: "Return JSON.",
task: "quality_inspector",
}),
).rejects.toThrow("LLM provider error: upstream unavailable");
expect(infoSpy).toHaveBeenCalledWith(
"[llm:start] provider=deepseek model=deepseek-v4-pro task=quality_inspector",
);
const errorLog = errorSpy.mock.calls.map((call) => call[0]).join("\n");
expect(errorLog).toContain("[llm:error] task=quality_inspector");
expect(errorLog).not.toContain("super-secret-key");
});
});
```
- [ ] **Step 2: Run the tests to verify they fail**
Run:
```bash
npm test -- src/lib/llm/__tests__/client.test.ts
```
Expected: FAIL because `task`, `setChatCompletionForTesting`, and the log calls do not exist yet.
- [ ] **Step 3: Implement the logging support**
Modify `src/lib/llm/client.ts`.
Change `GenerateInput` to:
```ts
export interface GenerateInput {
system?: string;
prompt: string;
model?: string;
temperature?: number;
task?: string;
}
```
Add these types and helpers after `isLlmConfigured()`:
```ts
type ChatCompletionCreate = Awaited<
ReturnType<ReturnType<typeof createClient>["client"]["chat"]["completions"]["create"]>
>;
let chatCompletionForTesting:
| ((args: Parameters<ReturnType<typeof createClient>["client"]["chat"]["completions"]["create"]>[0]) => Promise<ChatCompletionCreate>)
| null = null;
export function setChatCompletionForTesting(
handler:
| ((args: Parameters<ReturnType<typeof createClient>["client"]["chat"]["completions"]["create"]>[0]) => Promise<ChatCompletionCreate>)
| null,
) {
chatCompletionForTesting = handler;
}
function getTask(input: GenerateInput) {
return input.task?.trim() || "unknown";
}
function truncateRaw(value: string, maxLength = 4000) {
return value.length > maxLength
? `${value.slice(0, maxLength)}...[truncated ${value.length - maxLength} chars]`
: value;
}
function summarizeZodError(error: z.ZodError) {
return error.issues
.slice(0, 5)
.map((issue) => {
const path = issue.path.length > 0 ? issue.path.join(".") : "<root>";
return `${path}: ${issue.message}`;
})
.join("; ");
}
function quoteLogValue(value: string) {
return JSON.stringify(value);
}
```
Replace the provider call inside `generateJson` with:
```ts
export async function generateJson<T>(input: GenerateInput): Promise<T> {
const task = getTask(input);
const startedAt = Date.now();
try {
const { client, model } = createClient();
const effectiveModel = input.model ?? model;
const status = getLlmProviderStatus();
console.info(
`[llm:start] provider=${status.provider} model=${effectiveModel} task=${task}`,
);
const request = {
model: effectiveModel,
temperature: input.temperature ?? 0.1,
response_format: { type: "json_object" as const },
messages: [
...(input.system ? [{ role: "system" as const, content: input.system }] : []),
{ role: "user" as const, content: input.prompt },
],
};
const response = chatCompletionForTesting
? await chatCompletionForTesting(request)
: await client.chat.completions.create(request);
const content = response.choices[0]?.message.content ?? "{}";
console.info(
`[llm:response] task=${task} duration_ms=${Date.now() - startedAt} raw=${truncateRaw(content)}`,
);
return JSON.parse(content) as T;
} catch (error) {
const normalized = normalizeLlmError(error);
console.error(
`[llm:error] task=${task} duration_ms=${Date.now() - startedAt} message=${quoteLogValue(normalized.message)}`,
);
throw normalized;
}
}
```
Change `generateValidatedJson` to:
```ts
export async function generateValidatedJson<T>({
schema,
...input
}: GenerateValidatedJsonInput<T>): Promise<T | null> {
const task = getTask(input);
if (!isLlmConfigured()) {
console.info(`[llm:validated] task=${task} ok=false reason=not_configured`);
return null;
}
try {
const generated = await generateJsonForValidation<unknown>(input);
const parsed = schema.safeParse(generated);
if (parsed.success) {
console.info(`[llm:validated] task=${task} ok=true`);
return parsed.data;
}
console.warn(
`[llm:validated] task=${task} ok=false zod_error=${quoteLogValue(summarizeZodError(parsed.error))}`,
);
return null;
} catch {
console.info(`[llm:validated] task=${task} ok=false reason=provider_error`);
return null;
}
}
```
- [ ] **Step 4: Run the client tests**
Run:
```bash
npm test -- src/lib/llm/__tests__/client.test.ts
```
Expected: PASS.
- [ ] **Step 5: Commit**
```bash
git add src/lib/llm/client.ts src/lib/llm/__tests__/client.test.ts
git commit -m "feat: add central llm runtime logging"
```
## Task 2: Add Workflow Task Labels
**Files:**
- Modify: `src/lib/workflow/fact-extractor.ts`
- Modify: `src/lib/workflow/article-optimizer.ts`
- Modify: `src/lib/workflow/quality-inspector.ts`
- Modify: `src/lib/workflow/targeted-rewriter.ts`
- Modify: `src/lib/workflow/__tests__/llm-integration.test.ts`
- [ ] **Step 1: Add failing workflow task-label assertions**
In `src/lib/workflow/__tests__/llm-integration.test.ts`, after each `toHaveBeenCalledOnce()` assertion, add the matching expectation.
For fact extraction:
```ts
expect(llmMocks.generateValidatedJson).toHaveBeenCalledWith(
expect.objectContaining({ task: "fact_extractor" }),
);
```
For article optimization:
```ts
expect(llmMocks.generateValidatedJson).toHaveBeenCalledWith(
expect.objectContaining({ task: "article_optimizer" }),
);
```
For targeted rewrite:
```ts
expect(llmMocks.generateValidatedJson).toHaveBeenCalledWith(
expect.objectContaining({ task: "targeted_rewriter" }),
);
```
In the `uses LLM quality checks to enrich non-failing deterministic checks` test, after the report assertions add:
```ts
expect(llmMocks.generateValidatedJson).toHaveBeenCalledWith(
expect.objectContaining({ task: "quality_inspector" }),
);
```
- [ ] **Step 2: Run workflow integration tests to verify they fail**
Run:
```bash
npm test -- src/lib/workflow/__tests__/llm-integration.test.ts
```
Expected: FAIL because the workflow calls do not pass `task` yet.
- [ ] **Step 3: Add task labels to workflow LLM calls**
In `src/lib/workflow/fact-extractor.ts`, update the `generateValidatedJson` call:
```ts
const llmCard = await generateValidatedJson({
schema: candidateFactCardSchema,
system: FACT_EXTRACTOR_SYSTEM_PROMPT,
prompt: buildFactExtractorPrompt(input),
temperature: 0.1,
task: "fact_extractor",
});
```
In `src/lib/workflow/article-optimizer.ts`, update the call:
```ts
const llmArticle = await generateValidatedJson({
schema: optimizedArticleSchema,
system: ARTICLE_OPTIMIZER_SYSTEM_PROMPT,
prompt: buildArticleOptimizerPrompt(input, factCard),
temperature: 0.2,
task: "article_optimizer",
});
```
In `src/lib/workflow/quality-inspector.ts`, update the call:
```ts
const llmPatch = await generateValidatedJson({
schema: llmQaPatchSchema,
system: QUALITY_INSPECTOR_SYSTEM_PROMPT,
prompt: buildQualityInspectorPrompt({
article: input.article,
factCard: input.factCard,
platform: input.platform,
deterministicChecks: deterministicReport.checks,
}),
temperature: 0.1,
task: "quality_inspector",
});
```
In `src/lib/workflow/targeted-rewriter.ts`, update the call:
```ts
const llmArticle = await generateValidatedJson({
schema: optimizedArticleSchema,
system: TARGETED_REWRITER_SYSTEM_PROMPT,
prompt: buildTargetedRewritePrompt({ article, factCard, failedChecks }),
temperature: 0.15,
task: "targeted_rewriter",
});
```
- [ ] **Step 4: Run workflow integration tests**
Run:
```bash
npm test -- src/lib/workflow/__tests__/llm-integration.test.ts
```
Expected: PASS.
- [ ] **Step 5: Commit**
```bash
git add src/lib/workflow/fact-extractor.ts src/lib/workflow/article-optimizer.ts src/lib/workflow/quality-inspector.ts src/lib/workflow/targeted-rewriter.ts src/lib/workflow/__tests__/llm-integration.test.ts
git commit -m "feat: label llm workflow tasks"
```
## Task 3: Document Runtime Logs And Verify Build
**Files:**
- Modify: `README.md`
- [ ] **Step 1: Add README logging section**
Add this section after the environment section in `README.md`:
```md
## LLM Runtime Logs
LLM calls emit regular server-side logs from `src/lib/llm/client.ts`. These
logs are intended for local development, customer demos, and production
troubleshooting.
Example:
```text
[llm:start] provider=deepseek model=deepseek-v4-pro task=article_optimizer
[llm:response] task=article_optimizer duration_ms=18342 raw={"title":"..."}
[llm:validated] task=article_optimizer ok=true
```
The `raw=` field is truncated to 4000 characters to avoid log explosions. API
keys, prompts, system messages, and environment secrets are not logged.
```
- [ ] **Step 2: Run full verification**
Run:
```bash
npm test
npm run build
```
Expected: both commands PASS.
- [ ] **Step 3: Optional manual smoke test**
With `npm run dev` running and a valid `DEEPSEEK_API_KEY`, submit one article through the UI.
Expected server logs include all of these task labels:
```text
task=fact_extractor
task=article_optimizer
task=quality_inspector
```
If QA hard-fails and rewrite runs, logs also include:
```text
task=targeted_rewriter
```
- [ ] **Step 4: Commit**
```bash
git add README.md
git commit -m "docs: document llm runtime logs"
```
## Self-Review
- Spec coverage: The plan logs provider, model, task, duration, raw truncated response, validation pass/fail, and Zod summaries centrally in `src/lib/llm/client.ts`. It does not log API keys, prompts, or secrets.
- Placeholder scan: The plan contains exact file paths, code snippets, commands, expected outcomes, and commit commands. It has no placeholder tasks.
- Type consistency: `task` is added to `GenerateInput`, so all existing `generateJson` and `generateValidatedJson` calls accept it. Workflow task labels match the user-requested examples and the test expectations.