Module 5: Structured Logging for AI Systems

6. Debugging Non-Deterministic Systems

Next →

Description

When a deterministic system fails, you can reproduce it: same input → same output → same error. When an LLM system fails, this isn't automatically true: the same input can produce different outputs. This capsule tackles the central challenge of AI debugging: how to capture enough context to reproduce a problematic request, and how to combine seed, temperature=0, and reproducibility logging to transform a non-deterministic system into something deterministic enough to be debuggable.

The challenge of non-deterministic debugging

Deterministic system:
→ User: "Error with input X"
→ Dev: "I reproduce with input X"
→ Result: Same error, reproducible, debuggable
→ Time to reproduce: 30 seconds

Non-deterministic LLM system:
→ User: "The response was weird with input Y"
→ Dev: "I run with input Y"
→ Result: Completely different response, normal
→ "Which model was used exactly? What temperature? Was there any accumulated context?"
→ "I don't remember, that was yesterday..."
→ Time to reproduce: impossible without logs

Without reproducibility logging:
→ The bug exists, but you can't reproduce it
→ You can't debug it
→ You can't write a test to prevent regressions
→ You don't know when it's "fixed"

With reproducibility logging:
→ The bug occurred
→ You have the exact prompt, model, temperature, seed
→ You can reproduce the exact context (or a very similar one)
→ You can experiment with fixes
→ You can write a test that captures the case

What to save to be able to reproduce

# src/reproducibility.py
from dataclasses import dataclass, field
from typing import Optional, List
import hashlib
import json

@dataclass
class LLMCallContext:
    """
    Complete context of an LLM call for reproducibility.
    Captures everything needed to re-run the request under similar conditions.
    """
    # Identification
    request_id: str
    
    # Model parameters
    model: str
    temperature: float
    max_tokens: int
    seed: Optional[int] = None
    
    # The prompt (careful with PII)
    messages: List[dict] = field(default_factory=list)
    
    # Result
    raw_response: Optional[str] = None
    finish_reason: Optional[str] = None  # "stop", "length", "content_filter"
    
    # Metrics
    input_tokens: int = 0
    output_tokens: int = 0
    duration_ms: float = 0.0
    
    @property
    def messages_hash(self) -> str:
        """Hash of the prompt for identification without exposing the content."""
        content = json.dumps(self.messages, sort_keys=True)
        return hashlib.sha256(content.encode()).hexdigest()[:16]
    
    @property
    def response_hash(self) -> Optional[str]:
        """Hash of the response to detect changes."""
        if self.raw_response is None:
            return None
        return hashlib.sha256(self.raw_response.encode()).hexdigest()[:16]
    
    def to_reproduction_script(self) -> str:
        """
        Generates a Python script that can re-run the request.
        Useful for offline debugging.
        """
        return f"""
# Reproduction of request {self.request_id}
# Automatically generated from the reproducibility log

from openai import OpenAI

client = OpenAI()

response = client.chat.completions.create(
    model="{self.model}",
    messages={json.dumps(self.messages, indent=4, ensure_ascii=False)},
    temperature={self.temperature},
    max_tokens={self.max_tokens},
    seed={self.seed},
)

print(response.choices[0].message.content)
"""

How and when to log for reproducibility

# src/llm_wrapper.py (with reproducibility logging)
import structlog
from src.reproducibility import LLMCallContext

log = structlog.get_logger()

def call_llm_with_reproducibility(
    client,
    model: str,
    messages: list,
    temperature: float = 0.0,
    max_tokens: int = 500,
    seed: Optional[int] = None,
    request_id: str = None,
    debug_mode: bool = False
) -> tuple:
    """
    LLM call with reproducibility logging.
    
    Always:
    - Hash of the prompt (to identify without exposing)
    - model, temperature, max_tokens, seed
    - finish_reason (truncated? stop?)
    
    Only on ERROR:
    - Truncated prompt (first 500 chars)
    
    Only in DEBUG mode:
    - Full prompt (careful with PII)
    """
    ctx = LLMCallContext(
        request_id=request_id or "unknown",
        model=model,
        temperature=temperature,
        max_tokens=max_tokens,
        seed=seed,
        messages=messages
    )
    
    start = time.time()
    
    try:
        response = client.chat.completions.create(
            model=model,
            messages=messages,
            temperature=temperature,
            max_tokens=max_tokens,
            seed=seed
        )
        
        ctx.raw_response = response.choices[0].message.content
        ctx.finish_reason = response.choices[0].finish_reason
        ctx.input_tokens = response.usage.prompt_tokens
        ctx.output_tokens = response.usage.completion_tokens
        ctx.duration_ms = (time.time() - start) * 1000
        
        # INFO: hash of the context for traceability without exposing content
        log.info(
            "llm_call_completed",
            model=ctx.model,
            temperature=ctx.temperature,
            seed=ctx.seed,
            messages_hash=ctx.messages_hash,
            response_hash=ctx.response_hash,
            finish_reason=ctx.finish_reason,
            input_tokens=ctx.input_tokens,
            output_tokens=ctx.output_tokens,
            duration_ms=round(ctx.duration_ms, 1)
        )
        
        # WARNING: if the response was truncated by max_tokens
        if ctx.finish_reason == "length":
            log.warning(
                "response_truncated",
                reason="max_tokens reached",
                max_tokens=ctx.max_tokens,
                output_tokens=ctx.output_tokens,
                messages_hash=ctx.messages_hash
            )
        
        # DEBUG: full prompt (only if enabled)
        if debug_mode:
            # Only the first 500 chars to reduce size even in debug
            prompt_preview = ""
            if messages:
                last_msg = messages[-1].get("content", "")
                prompt_preview = last_msg[:500]
                if len(last_msg) > 500:
                    prompt_preview += f"...[{len(last_msg)} total chars]"
            
            log.debug(
                "llm_reproducibility_context",
                model=ctx.model,
                temperature=ctx.temperature,
                seed=ctx.seed,
                max_tokens=ctx.max_tokens,
                prompt_preview=prompt_preview,
                response_preview=(ctx.raw_response or "")[:300]
            )
        
        return response, ctx
    
    except Exception as e:
        ctx.duration_ms = (time.time() - start) * 1000
        
        # ERROR: include more context because we need to debug
        prompt_preview = ""
        if messages:
            last_msg = messages[-1].get("content", "")
            prompt_preview = last_msg[:300]  # More context on error
        
        log.error(
            "llm_call_failed",
            error_type=type(e).__name__,
            error_message=str(e)[:300],
            model=ctx.model,
            temperature=ctx.temperature,
            seed=ctx.seed,
            messages_hash=ctx.messages_hash,
            prompt_preview=prompt_preview,  # On error: more context
            duration_ms=round(ctx.duration_ms, 1)
        )
        raise

seed: the parameter that (almost) makes the LLM deterministic

# What does seed do?
# When you specify seed, the model should produce the same response
# for the same input and the same parameters.
# OpenAI calls it "reproducibility" and the system_fingerprint property
# confirms when the model's underlying implementation didn't change.

import openai

response = openai.chat.completions.create(
    model="gpt-4o-mini",
    messages=[{"role": "user", "content": "What is the capital of France?"}],
    temperature=0.0,    # temperature=0 reduces variance
    seed=42             # seed makes the response reproducible
)

# system_fingerprint indicates the model version:
fingerprint = response.system_fingerprint
# "fp_13c70b9f70" — if this changes, the response may change even if seed is the same

# Log the fingerprint:
log.info("llm_call_completed",
    ...,
    seed=42,
    system_fingerprint=response.system_fingerprint
)
# If the fingerprint changes between two calls with the same seed,
# the response may have changed not because of your code but because of an
# update to the model on OpenAI's server.

# Important: seed does NOT guarantee 100% reproducibility
# → If system_fingerprint changes, the response may change
# → It's "best effort" according to OpenAI
# → For debugging it works very well, not for absolute guarantees

temperature: the variance control

# How temperature affects reproducibility:

# temperature=0.0: Completely greedy — always picks the most probable token
# → Very high reproducibility (almost always the same response)
# → Good for: classification, extraction, structured analysis
# → Bad for: creative generation, brainstorming

# temperature=0.3: Low but with some variance
# → Good for: summaries, responses with some flexibility
# → Moderate reproducibility

# temperature=0.7 (default for many models): High variance
# → For: creative generation
# → Low reproducibility — the same input can give very different responses

# temperature=1.0+: Very high variance, sometimes incoherent
# → Rarely useful in production

# RECOMMENDATION for analysis apps (like sentiment analysis):
# → temperature=0.0 for maximum consistency
# → Only use temperature > 0 if you genuinely need a variety of responses

response = client.chat.completions.create(
    model="gpt-4o-mini",
    messages=messages,
    temperature=0.0,   # For analysis: always 0.0
    seed=42,           # For debugging: always specify
    max_tokens=500
)

Complete debugging workflow with reproducibility logs

SCENARIO: A user reports that the sentiment analysis of their review
"The product arrived late but the support was excellent" 
was classified as "negative" when it should be "mixed".

STEP 1: The user reports the error with the request_id
→ User: "request_id: a7b3c9d2"

STEP 2: Search the logs
$ jq 'select(.request_id == "a7b3c9d2")' logs.json | jq -s 'sort_by(.timestamp)'

Output:
{"event": "request_started", "request_id": "a7b3c9d2", "timestamp": "..."}
{"event": "llm_call_completed", "request_id": "a7b3c9d2",
 "messages_hash": "abc123", "model": "gpt-4o-mini",
 "temperature": 0.7, "seed": null, "finish_reason": "stop",
 "input_tokens": 156, "output_tokens": 43, "timestamp": "..."}
{"event": "request_completed", "request_id": "a7b3c9d2",
 "result": {"sentiment": "negative"}, "timestamp": "..."}

STEP 3: Identify the problem
→ temperature=0.7 (high variance) — that explains the inconsistent result
→ No seed — we can't reproduce it exactly
→ The model generated "negative" in this run, but may generate "mixed" in another

STEP 4: Reproduce (with low temperature to stabilize)
$ python scripts/reproduce_request.py \
    --model "gpt-4o-mini" \
    --temperature 0.7 \
    --seed 42 \
    --messages-hash "abc123"

→ With temperature=0.7, the response varies. Confirmed: the system is unstable

STEP 5: Diagnosis
→ For sentiment analysis, temperature=0.7 is too high
→ Fix: change to temperature=0.0

STEP 6: Validate the fix
→ With temperature=0.0, the same input always gives "mixed"
→ Fix validated

STEP 7: Write the regression test
def test_mixed_sentiment_stable():
    """Input with mixed sentiments should give 'mixed', not 'negative'."""
    result = analyze_sentiment(
        "The product arrived late but the support was excellent"
    )
    assert result.sentiment == "mixed"

Reproduction script

# scripts/reproduce_from_logs.py
"""
Script that reads a request_id from the logs and generates the code
to reproduce the LLM call.

Usage: python scripts/reproduce_from_logs.py <request_id> [log_file]
"""
import json
import sys
from pathlib import Path

def find_llm_call_log(request_id: str, log_file: str = "logs/app.json") -> dict:
    """Searches for the LLM call log for a request_id."""
    with open(log_file) as f:
        for line in f:
            line = line.strip()
            if not line:
                continue
            try:
                entry = json.loads(line)
                if (entry.get("request_id") == request_id and
                    entry.get("event") == "llm_reproducibility_context"):
                    return entry
            except json.JSONDecodeError:
                pass
    return None

def generate_reproduction_script(log_entry: dict) -> str:
    """Generates a Python script to reproduce the call."""
    
    model = log_entry.get("model", "gpt-4o-mini")
    temperature = log_entry.get("temperature", 0.0)
    seed = log_entry.get("seed")
    max_tokens = log_entry.get("max_tokens", 500)
    prompt_preview = log_entry.get("prompt_preview", "[No prompt available]")
    
    seed_line = f"    seed={seed}," if seed is not None else "    # seed not available"
    
    return f'''#!/usr/bin/env python
"""
Reproduction of the request: {log_entry.get("request_id")}
Generated by: scripts/reproduce_from_logs.py
NOTE: The prompt is a preview — it may be truncated.
"""
from openai import OpenAI

client = OpenAI()

# NOTE: The full prompt may not be available if
# the log was generated with debug_mode=False.
# Use the real prompt for an exact reproduction.
prompt = """{prompt_preview}"""

response = client.chat.completions.create(
    model="{model}",
    messages=[{{"role": "user", "content": prompt}}],
    temperature={temperature},
    max_tokens={max_tokens},
{seed_line}
)

print("Response:", response.choices[0].message.content)
print("Finish reason:", response.choices[0].finish_reason)
'''

if __name__ == "__main__":
    request_id = sys.argv[1] if len(sys.argv) > 1 else None
    log_file = sys.argv[2] if len(sys.argv) > 2 else "logs/app.json"
    
    if not request_id:
        print("Usage: python reproduce_from_logs.py <request_id> [log_file]")
        sys.exit(1)
    
    entry = find_llm_call_log(request_id, log_file)
    
    if not entry:
        print(f"No reproducibility log found for request_id: {request_id}")
        print("Note: Reproducibility logs are only generated in debug_mode=True")
        sys.exit(1)
    
    script = generate_reproduction_script(entry)
    output_file = f"reproduce_{request_id}.py"
    
    with open(output_file, "w") as f:
        f.write(script)
    
    print(f"Reproduction script generated: {output_file}")
    print(f"Run: python {output_file}")

Exercises

Exercise 1: Identify why you can't reproduce

Given this log, explain why it's hard to reproduce the request exactly:

{"event": "llm_call_completed", "model": "gpt-4o", "temperature": 0.8,
 "seed": null, "finish_reason": "stop", "request_id": "z9x8w7v6"}
See solution

Three problems:

  1. temperature=0.8 is high — the model has a lot of variance in its responses. The same input can give very different outputs across different calls.

  2. seed=null — without a seed, there's no way to ask the model to try to reproduce the same result. The randomness is completely free.

  3. No prompt in the log — without the exact prompt, you can't even try to reproduce. You only have the hash.

To improve: use temperature=0.0 for deterministic analysis, always specify seed, and in debug mode log the prompt.

Exercise 2: Design the reproducibility logging policy

For an app with real users, define:

  1. What to log always?
  2. What to log only on ERROR?
  3. What only in DEBUG mode?
See guide

Always (INFO):

  • model, temperature, seed (if used)
  • messages_hash, response_hash
  • finish_reason, input_tokens, output_tokens

Only on ERROR (you need more context to debug):

  • First 300 chars of the prompt (may have PII → use with care or redact)
  • system_fingerprint (to correlate with model changes)
  • Full messages if the app has legal access and there's consent

Only in DEBUG mode (explicitly enabled):

  • Full prompt (with PII redaction)
  • Full response
  • The entire messages[] object

Exercise 3: finish_reason

Why is it important to log finish_reason?

See guide

finish_reason indicates why the model stopped generating:

  • "stop": finished normally — the expected case
  • "length": max_tokens was reached — the response was truncated, it may be incomplete. This can cause invalid JSON if the output is structured JSON.
  • "content_filter": the content was filtered by OpenAI's moderation
  • "tool_calls": the model wants to call a tool

If your app has JSON parsing errors and the finish_reason is "length", the cause is clear: increase max_tokens or truncate the input.

Summary

  • Reproducibility isn't determinism: we don't ask the LLM to be 100% predictable, but to capture enough context to get as close as possible
  • temperature=0.0 for analysis: maximum consistency, the same results in most cases
  • seed together with temperature=0.0: the most effective combination for reproducibility
  • system_fingerprint: lets you detect when the model changed on the server, not in your code
  • Always log: model, temperature, seed, messages_hash, finish_reason
  • On ERROR: more context (prompt preview) to be able to diagnose
  • The workflow: request_id → logs → params → reproduction script → diagnosis

Additional resources

  1. OpenAI — Reproducible outputs — Documentation for seed in OpenAI
  2. OpenAI API Reference — seed — The seed parameter
  3. Temperature in LLMs — How temperature works
  4. Debugging ML systems — Debugging techniques for ML systems
← Previous5. JSON Logs with structlogNext →7. Project: AI Logging System