Careeroza

Observability and Tracing

What to Log for Every LLM Call

  • request ID (message._request_id), conversation ID, user ID (hashed)
  • model, prompt version, effort setting
  • input, output and cache tokens; cost; latency; stop_reason
  • retrieved document IDs and scores; tool calls with inputs and results
  • user feedback (thumbs up/down), escalation to human

A trace groups everything one request did into nested spans (retrieve → model call → tool → model call). Tools: Langfuse, LangSmith, Arize Phoenix, Helicone, or plain OpenTelemetry into Grafana or Datadog.

Example

Example

A tiny tracer built with a context manager. Durations are fixed numbers so the output is repeatable; real code would use time.perf_counter().

from contextlib import contextmanager

SPANS, stack = [], []
FAKE_MS = {"retrieve": 42, "rerank": 95, "llm_call": 1840, "tool:get_order": 60, "llm_call#2": 910}

@contextmanager
def span(name, **attrs):
    stack.append(name)
    SPANS.append((len(stack) - 1, name, FAKE_MS.get(name, 0), attrs))
    try:
        yield
    finally:
        stack.pop()

with span("chat_request", conversation="c-981", prompt="support_v7"):
    with span("retrieve", k=30):
        pass
    with span("rerank", kept=4):
        pass
    with span("llm_call", model="claude-sonnet-5-5", in_tok=3100, out_tok=60, stop="tool_use"):
        pass
    with span("tool:get_order", order_id="SE1042"):
        pass
    with span("llm_call#2", model="claude-sonnet-5-5", in_tok=3300, out_tok=140, stop="end_turn"):
        pass

total = sum(ms for depth, _, ms, _ in SPANS if depth == 1)
for depth, name, ms, attrs in SPANS:
    shown = total if depth == 0 else ms
    print("  " * depth + f"{name:<{22 - 2 * depth}} {shown:>5} ms  {attrs}")

Output

chat_request            2947 ms  {'conversation': 'c-981', 'prompt': 'support_v7'}
  retrieve                42 ms  {'k': 30}
  rerank                  95 ms  {'kept': 4}
  llm_call              1840 ms  {'model': 'claude-sonnet-5-5', 'in_tok': 3100, 'out_tok': 60, 'stop': 'tool_use'}
  tool:get_order          60 ms  {'order_id': 'SE1042'}
  llm_call#2             910 ms  {'model': 'claude-sonnet-5-5', 'in_tok': 3300, 'out_tok': 140, 'stop': 'end_turn'}

OpenTelemetry

from opentelemetry import trace
tracer = trace.get_tracer("shopease.assistant")

def answer(question: str) -> str:
    with tracer.start_as_current_span("llm_call") as s:
        resp = client.messages.create(model="claude-sonnet-5-5", max_tokens=1000,
                                      messages=[{"role": "user", "content": question}])
        s.set_attribute("gen_ai.request.model", "claude-sonnet-5-5")
        s.set_attribute("gen_ai.usage.input_tokens", resp.usage.input_tokens)
        s.set_attribute("gen_ai.usage.output_tokens", resp.usage.output_tokens)
        s.set_attribute("request_id", resp._request_id)
        return next(b.text for b in resp.content if b.type == "text")