Files

T

Codex cde8d1940c docs: document llm runtime logs

2026-06-21 23:43:02 +08:00

17 KiB

Raw Permalink Blame History

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:

[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", () => { ... }):

  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:

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:
```
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:

export interface GenerateInput {
  system?: string;
  prompt: string;
  model?: string;
  temperature?: number;
  task?: string;
}

Add these types and helpers after isLlmConfigured():

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:

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:

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:

npm test -- src/lib/llm/__tests__/client.test.ts

Expected: PASS.

Step 5: Commit

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:

    expect(llmMocks.generateValidatedJson).toHaveBeenCalledWith(
      expect.objectContaining({ task: "fact_extractor" }),
    );

For article optimization:

    expect(llmMocks.generateValidatedJson).toHaveBeenCalledWith(
      expect.objectContaining({ task: "article_optimizer" }),
    );

For targeted rewrite:

    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:

    expect(llmMocks.generateValidatedJson).toHaveBeenCalledWith(
      expect.objectContaining({ task: "quality_inspector" }),
    );

Step 2: Run workflow integration tests to verify they fail

Run:
```
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:

  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:

  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:

  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:

  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:

npm test -- src/lib/workflow/__tests__/llm-integration.test.ts

Expected: PASS.

Step 5: Commit

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:

## 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:
```
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:
```
task=fact_extractor
task=article_optimizer
task=quality_inspector
```
If QA hard-fails and rewrite runs, logs also include:
```
task=targeted_rewriter
```

Step 4: Commit

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.

17 KiB Raw Permalink Blame History

LLM Runtime Logging Implementation Plan

Scope

File Structure

Log Contract

Task 1: Add Central LLM Runtime Logging

Task 2: Add Workflow Task Labels

Task 3: Document Runtime Logs And Verify Build

Self-Review

17 KiB

Raw Permalink Blame History