DevOps · lesson 8 of 8

Beginner

1 What DevOps Actually Is, Measured From a Real Repo

Intermediate

Also part of DevOps

DevOps intermediate Lesson 8 of 8

Also part of: System Design Monitoring & Observability

Observability Synthesis: Logs, Metrics, Traces, and Alerts as One Signal

Generate structured logs, aggregate them into metrics, fire an alert off a real threshold breach, and use a trace ID to walk straight back from the alert to the log lines that explain it.

By SkillByExample · Published Sep 14, 2026

devops observability monitoring

An alert fires from a number. The number came from a log file. A trace ID is what lets you walk backward from one to the other.

One log format, two services

Fifty simulated requests hit a frontend, which calls a backend inventory lookup — every log line carries the same trace_id across both services, and every seventh request’s backend call is deliberately slow and failing:

# .scratch/generate_logs.py (excerpt)
for i in range(1, 51):
    trace_id = f"trace-{i:03d}"
    backend_fails = i % 7 == 0
    backend_latency = random.randint(400, 600) if backend_fails else random.randint(20, 60)
    backend_status = 500 if backend_fails else 200

    lines.append({"trace_id": trace_id, "service": "frontend", "span": "handle_request",
                  "latency_ms": frontend_latency + backend_latency, "status": 500 if backend_fails else 200})
    lines.append({"trace_id": trace_id, "service": "backend", "span": "query_inventory",
                  "latency_ms": backend_latency, "status": backend_status})

$ py generate_logs.py
Wrote 100 log lines across 50 requests to logs.jsonl
$ head -n 2 logs.jsonl
{"trace_id": "trace-001", "service": "frontend", "span": "handle_request", "latency_ms": 42, "status": 200}
{"trace_id": "trace-001", "service": "backend", "span": "query_inventory", "latency_ms": 27, "status": 200}

This is the raw layer — one JSON line per event, nothing aggregated yet. Everything below is computed from exactly this file.

Metrics: aggregating the raw logs

A metric is just an aggregation over many log lines — here, error rate and latency percentiles across every frontend-facing request:

# .scratch/compute_metrics.py (excerpt)
errors = [e for e in frontend_entries if e["status"] >= 500]
latencies = sorted(e["latency_ms"] for e in frontend_entries)

def percentile(sorted_vals, pct):
    idx = int(len(sorted_vals) * pct) - 1
    return sorted_vals[max(idx, 0)]

error_rate = len(errors) / total
p95 = percentile(latencies, 0.95)

$ py compute_metrics.py
Requests: 50
Error rate: 7/50 = 14.0%
p50 latency: 49ms
p95 latency: 497ms

Seven failures out of fifty — exactly the i % 7 == 0 pattern built into the log generator — now shows up as a 14.0% error rate and a p95 latency nearly ten times the typical request.

Alerts: a threshold on the metric

An alert is nothing more than a rule checked against a metric — but a useful one also carries forward exactly which raw events triggered it:

# .scratch/check_alerts.py (excerpt)
if error_rate > ERROR_RATE_THRESHOLD:
    trace_ids = ", ".join(e["trace_id"] for e in errors)
    print(f"ALERT: error rate {error_rate:.1%} exceeds {ERROR_RATE_THRESHOLD:.0%} threshold")
    print(f"  Implicated traces: {trace_ids}")

$ py check_alerts.py
ALERT: error rate 14.0% exceeds 5% threshold
  Implicated traces: trace-007, trace-014, trace-021, trace-028, trace-035, trace-042, trace-049
ALERT: p95 latency 497ms exceeds 300ms threshold

Two alerts fired from the same seven bad requests — one on the count of failures, one on how slow they were. Notice the error-rate alert didn’t just say “something’s wrong”: it printed the exact trace IDs behind the breach.

Tracing: walking back to the raw logs

The alert handed over trace-007. A trace is just every log line sharing that ID, ordered by which service handled it:

# .scratch/trace_lookup.py
for line in open("logs.jsonl"):
    entry = json.loads(line)
    if entry["trace_id"] == target:
        print(f"  [{entry['service']:<8}] {entry['span']:<16} {entry['latency_ms']:>4}ms  status={entry['status']}")

$ py trace_lookup.py trace-007
  [frontend] handle_request    419ms  status=500
  [backend ] query_inventory   408ms  status=500

The full path from alert to root cause, in four steps: the alert (14.0% error rate) came from a metric (aggregated logs), the metric came from raw log lines, and the trace ID the alert surfaced leads straight back to the two specific log lines — frontend and backend — that show 408 of the frontend’s 419ms was spent waiting on a backend call that itself failed. Four “different” observability signals, one underlying JSON Lines file.

Practice

1. Lower the error-rate alert threshold to 0.10 (10%). Does the alert message change?

Change ERROR_RATE_THRESHOLD = 0.05 to 0.10 in check_alerts.py and rerun. The alert still fires — 14.0% exceeds 10% — since the real error rate (14.0%) is unchanged; only the threshold in the comparison moves. This is worth trying with 0.20 too, which stops the alert from firing at all, to see the exact point where 14.0% stops being “an incident” by this rule’s definition.

2. Change the failure pattern from every 7th request to every 4th, and see how the metrics shift.

Change i % 7 == 0 to i % 4 == 0 in generate_logs.py and regenerate. With roughly 12 failures out of 50 instead of 7, rerunning compute_metrics.py shows a error rate near 24% instead of 14.0% — more frequent failures raise the error rate roughly proportionally, since it’s a direct count over the same total request volume.

3. Add a p50 latency alert with a threshold of 40ms. Does it fire against the current data?

P50_LATENCY_THRESHOLD_MS = 40
if p50 > P50_LATENCY_THRESHOLD_MS:
    print(f"ALERT: p50 latency {p50}ms exceeds {P50_LATENCY_THRESHOLD_MS}ms threshold")

With p50 at 49ms (from the earlier compute_metrics.py run), this fires too — but a p50 alert firing means the median request is slow, not just the slow tail the p95 alert already caught. That’s a meaningfully different signal: p95 breaching alone usually means “a subset of requests are having a bad time,” while p50 breaching means “typical requests are already degraded.”

4. Look up a trace ID that was NOT in the alert's implicated list, like `trace-010`. What does it show?

$ py trace_lookup.py trace-010
  [frontend] handle_request     71ms  status=200
  [backend ] query_inventory    58ms  status=200

A healthy trace — fast backend call, 200 status on both spans. Comparing a healthy trace side by side with trace-007’s failing one is often more diagnostically useful than looking at the bad trace alone, since it shows exactly what “normal” looks like for the same code path.

5. Modify `trace_lookup.py` to also print the total time across all spans for that trace, and compare it to the frontend span's own latency.

spans = [json.loads(line) for line in open("logs.jsonl") if json.loads(line)["trace_id"] == target]
total = sum(s["latency_ms"] for s in spans)
frontend_latency = next(s["latency_ms"] for s in spans if s["service"] == "frontend")
print(f"  Total span time: {total}ms, frontend-reported latency: {frontend_latency}ms")

Total span time: 827ms, frontend-reported latency: 419ms

The naive sum (827ms) is nearly double the frontend’s own reported latency (419ms) — not because the trace took 827ms in wall-clock time, but because the backend span’s 408ms is already included inside the frontend’s 419ms, and summing both counts that overlap twice. This is a real, common mistake in hand-rolled tracing: a child span’s duration is nested inside its parent’s, not sequential after it, so naively summing every span in a trace overstates the actual time a request took. Real tracing systems track each span’s start and end timestamps precisely so total wall-clock time can be computed from the outermost span alone, rather than by summing durations that already overlap.

Frequently Asked Questions

What's the difference between logs, metrics, and traces?

Logs are individual, detailed records of what happened — one line per event. Metrics are numbers aggregated from many events over time — an error rate or a latency percentile. Traces connect the individual log entries or spans that belong to one specific request across multiple services, showing the path that request actually took.

Why do all three come from the same underlying data in this lesson?

Because in a real system they usually do — a metrics pipeline is often just aggregated logs, and a trace is often just log lines correlated by a shared identifier. Treating them as three separate tools obscures that they're three different views of the same signal, which is exactly why an alert (built from metrics) can hand you a trace ID that leads straight back to the log lines (raw data) that explain it.

What is a trace ID and why does every log line need one?

A trace ID is a unique identifier generated when a request starts and passed along to every service that request touches. Without it, log lines from different services during an incident are just a pile of timestamps with no way to tell which ones belong to the same request — the trace ID is what turns disconnected log lines into a reconstructable path.

Why did the alert fire on error rate AND p95 latency separately, from the same seven failing requests?

Because they measure different aspects of the same underlying failures — error rate counts how many requests failed outright, while p95 latency measures how slow the slowest 5% of requests were, and the same slow, failing backend calls that raised the error rate also happened to be slow enough to drag the p95 latency number up. Two alerts firing on the same root cause isn't redundant noise; it's two independent confirmations of the same real problem.

Does this replace using an actual APM tool like Datadog, Grafana, or Honeycomb?

No — those tools do this at production scale with real-time ingestion, storage, and query performance this lesson's scripts don't attempt. What they don't change is the underlying relationship this lesson demonstrates: a metric is an aggregation of raw events, an alert is a threshold on a metric, and a trace ID is what lets you jump from an aggregated signal back to the specific raw events that caused it.