Open a log file from a typical LLM app and you'll see lines like Calling model... done in 2.3s. That tells you nothing about which feature spent the tokens, which request failed, or whether the line above it just printed your API key. JSON logging for LLM apps fixes both problems with one small formatter: every call becomes a record with the same fields, and secrets get scrubbed before anything is written.
Below is a standard-library Python version I ran on 2026-10-29, the output it produced, and the cases it still gets wrong. The wrong cases matter more than the working ones.
What fields should every LLM log line have?
Six, at minimum. They let you answer the questions you'll actually ask at 11 p.m.
| Field | Why you need it |
|---|---|
request_id | Joins the log line to a user report, a retry, or a trace |
model | Costs and failure rates differ by model |
input_tokens, output_tokens | The basis for cost per feature; get these from the API response, not your own estimate |
latency_ms | Spots slow calls and timeouts |
ok | Failure rate without parsing error text |
feature | Which part of your app made the call |
Notice what's missing: the prompt and the response. That's deliberate. Metadata is cheap, safe and enough for cost and reliability work. If you want to turn token counts into rupees per feature, the usage log cost script reads exactly this kind of record.
The formatter and redaction code
This is the whole module. It uses only logging, json and re.
import json, logging, re, sys, time, uuid
PATTERNS = [
(re.compile(r"sk-[A-Za-z0-9_-]{16,}"), "[REDACTED_KEY]"),
(re.compile(r"(?i)bearer\s+[A-Za-z0-9._~+/=-]{12,}"), "Bearer [REDACTED_TOKEN]"),
(re.compile(r"\b[\w.+-]+@[\w-]+\.[\w.-]+\b"), "[REDACTED_EMAIL]"),
(re.compile(r"\b[A-Z]{5}[0-9]{4}[A-Z]\b"), "[REDACTED_PAN]"),
]
SENSITIVE_KEYS = {"api_key", "authorization", "password", "token", "secret"}
def redact(value):
if isinstance(value, str):
for pattern, repl in PATTERNS:
value = pattern.sub(repl, value)
return value
if isinstance(value, dict):
return {k: "[REDACTED]" if k.lower() in SENSITIVE_KEYS else redact(v)
for k, v in value.items()}
if isinstance(value, (list, tuple)):
return [redact(v) for v in value]
return value
class JsonFormatter(logging.Formatter):
def format(self, record):
entry = {
"ts": time.strftime("%Y-%m-%dT%H:%M:%S", time.gmtime(record.created)) + "Z",
"level": record.levelname,
"event": redact(record.getMessage()),
}
entry.update(redact(getattr(record, "fields", {})))
if record.exc_info:
entry["error"] = redact(self.formatException(record.exc_info).splitlines()[-1])
return json.dumps(entry, ensure_ascii=False)
Two design choices worth copying. Redaction runs inside the formatter, so a developer who forgets to scrub a value before logging it is still covered. And only the last line of an exception goes into error; full tracebacks can contain local values and request bodies, so send those to a separate, access-controlled channel if you need them.
A thin helper keeps call sites short and the field names consistent:
def log_llm_call(logger, *, model, input_tokens, output_tokens, started,
ok=True, request_id=None, **extra):
logger.info("llm_call", extra={"fields": {
"request_id": request_id or uuid.uuid4().hex[:12],
"model": model,
"input_tokens": input_tokens,
"output_tokens": output_tokens,
"latency_ms": round((time.monotonic() - started) * 1000),
"ok": ok,
**extra,
}})
Pass started=time.monotonic() from just before the API call. Take the token counts from the usage block the API returns.
What does the output look like?
I ran a test script with a normal call, a message and fields containing fake secrets, and an exception. The keys and addresses are invented. Output, verbatim:
{"ts": "2026-10-29T12:22:10Z", "level": "INFO", "event": "llm_call", "request_id": "req-0001", "model": "example-model", "input_tokens": 812, "output_tokens": 240, "latency_ms": 52, "ok": true, "feature": "digest"}
{"ts": "2026-10-29T12:22:10Z", "level": "INFO", "event": "calling API with key [REDACTED_KEY] and Authorization: Bearer [REDACTED_TOKEN]", "api_key": "[REDACTED]", "user_email": "[REDACTED_EMAIL]", "note": "PAN [REDACTED_PAN] on file"}
{"ts": "2026-10-29T12:22:10Z", "level": "ERROR", "event": "llm_call_failed", "request_id": "req-0002", "ok": false, "error": "RuntimeError: upstream 401 for key [REDACTED_KEY]"}
The sk- key in the message, the bearer token, the email, the PAN-shaped string, the api_key field and the key inside the exception text were all scrubbed. The latency_ms of 52 comes from a 50 ms sleep in the test. One line per call, valid JSON, so jq or any log shipper can read it.
What does it still miss?
This is the part to read twice. I fed it two more strings:
token=AKIAIOSFODNN7EXAMPLE
my key is abcdef0123456789abcdef0123456789
Both came out unchanged. The first is the documented example format of an AWS access key ID; the second is a bare 32-character hex string, the shape many vendors use for keys. My patterns only know sk- prefixes, bearer tokens, emails and the PAN layout, so anything else walks through.
You can add patterns, and you should for the vendors you use. But you'll never list every format, and a broad pattern like "any 32 hex characters" will redact request IDs and hashes you want to keep. So treat the formatter as a net under the trapeze:
- Never pass secrets to a log call in the first place. Load them from the environment and keep them out of f-strings.
- Run a secret scanner on the repo and in CI; the API key leak prevention checklist covers that.
- If a key does show up in a log, rotate it. Redacting later doesn't help copies already shipped elsewhere.
Redaction here is about log hygiene. If you also need to strip personal data before text goes to a model, that is a different job; see PII redaction before LLM calls.
When should I log prompt and response text?
Only on purpose. A workable policy for a small team:
| Situation | Log content? |
|---|---|
| Normal successful call | No, metadata only |
| Failed or timed-out call | Yes, redacted, so you can reproduce it |
| Quality investigation | A small random sample for a limited window |
| Anything with regulated or customer data | Ask what you're allowed to retain before logging it |
Set a retention period on the log store, and write down who can read it. Logs outlive the product decision that created them.
What can you do with the logs once you have them?
Answer "which feature costs the most" with a script that reads the log from standard input. This one skips lines that aren't JSON, such as startup banners, and groups by feature:
import json, sys
from collections import defaultdict
totals = defaultdict(lambda: {"calls": 0, "failed": 0, "in": 0, "out": 0, "ms": 0})
for line in sys.stdin:
try:
rec = json.loads(line)
except json.JSONDecodeError:
continue
if rec.get("event") != "llm_call":
continue
t = totals[rec.get("feature", "unknown")]
t["calls"] += 1
t["failed"] += 0 if rec.get("ok", True) else 1
t["in"] += rec.get("input_tokens", 0)
t["out"] += rec.get("output_tokens", 0)
t["ms"] += rec.get("latency_ms", 0)
for name, t in sorted(totals.items(), key=lambda kv: -(kv[1]["in"] + kv[1]["out"])):
print(name, t["calls"], t["failed"], t["in"], t["out"], t["ms"] // t["calls"])
I ran it on seven invented calls across three features (plus one non-JSON startup line). The token counts are made up for the test and the latencies are synthetic, so read the shape, not the numbers:
feature calls failed in_tok out_tok avg_ms
support 3 0 4342 1218 80
digest 3 1 2407 473 53
tagging 1 0 210 18 20
On real logs this table is where decisions come from. support uses about twice the tokens of digest, so it's the first place to trim context. digest has a failed call, so check its error lines. A feature you didn't know was calling a model shows up as unknown, which is a prompt to add the field.
Where do these logs go next?
On a small VPS, write to stdout and let systemd or Docker capture it, as in systemd vs Docker for Python AI workers. journalctl -o cat -u your-agent | jq 'select(.ok == false)' will list failures (an untested one-liner; adjust the unit name). When you want traces across tool calls and retries, move up to self-hosted Langfuse or OpenTelemetry for LLM calls. Keep the JSON logs either way; they're what you'll grep when the tracing UI is down.



