Monitoring and observability · Intermediate

Instrument a service: metrics, logs and request ids

4 min read

Why it matters

Monitoring and observability appeared in 72% of the DevOps job descriptions we read. When a user says "the app is slow", you need data to answer where and why within minutes. That data exists only if the service was instrumented when it was built.

The concept

The three signals:

  • Metrics: numbers over time, cheap to store and query. Counters (requests, errors), gauges (queue depth) and histograms (latency distribution). Good for dashboards and alerts.

  • Logs: detailed records of events. Structured (JSON) logs can be searched and aggregated.

  • Traces: the path of one request through many services, with timings per step. OpenTelemetry is the open standard for producing them.

Tie them together with a request id (or trace id) that appears in every log line and is returned to the caller, so a user's complaint leads straight to the logs for that request.

For request-driven services, start with the RED method: Rate, Errors and Duration per endpoint.

Worked example: a fare estimate service

service.py
"""A tiny service instrumented with the three signals: metrics, structured logs and request ids."""
import json
import logging
import random
import time
import uuid

from fastapi import FastAPI, Request
from prometheus_client import Counter, Histogram, make_asgi_app

REQUESTS = Counter("http_requests_total", "HTTP requests", ["route", "status"])
LATENCY = Histogram("http_request_duration_seconds", "Request latency", ["route"],
                    buckets=[0.05, 0.1, 0.25, 0.5, 1, 2.5])

logging.basicConfig(level=logging.INFO, format="%(message)s")
log = logging.getLogger("fares")
app = FastAPI()
app.mount("/metrics", make_asgi_app())                # Prometheus scrapes this endpoint


@app.middleware("http")
async def observe(request: Request, call_next):
    request_id = request.headers.get("x-request-id", str(uuid.uuid4()))
    start = time.perf_counter()
    response = await call_next(request)
    elapsed = time.perf_counter() - start
    route = request.scope.get("route").path if request.scope.get("route") else "unmatched"
    REQUESTS.labels(route=route, status=str(response.status_code)).inc()
    LATENCY.labels(route=route).observe(elapsed)
    log.info(json.dumps({"event": "request", "request_id": request_id, "route": route,
                         "status": response.status_code, "duration_ms": round(elapsed * 1000, 1)}))
    response.headers["x-request-id"] = request_id
    return response


@app.get("/fare-estimate")
def fare_estimate(miles: float):
    time.sleep(random.uniform(0.01, 0.08))            # simulated work
    return {"miles": miles, "estimate": round(3.0 + 2.8 * miles, 2)}

Run it with uvicorn service:app, call /fare-estimate?miles=2.5 a few times and once with miles=x, then open /metrics/:

metrics
http_requests_total{route="/fare-estimate",status="200"} 3.0
http_requests_total{route="/fare-estimate",status="422"} 1.0
http_request_duration_seconds_bucket{le="0.1",route="/fare-estimate"} 4.0
http_request_duration_seconds_count{route="/fare-estimate"} 4.0

and each request logs one searchable line:

log-line
{"event": "request", "request_id": "3be83576-225e-487d-bf8e-e9da16b4f5d3", "route": "/fare-estimate", "status": 200, "duration_ms": 50.6}

Useful PromQL queries once Prometheus scrapes it:

queries.promql
sum by (route) (rate(http_requests_total[5m]))                                           # rate
sum(rate(http_requests_total{status=~"5.."}[5m])) / sum(rate(http_requests_total[5m]))     # error ratio
histogram_quantile(0.95, sum by (le) (rate(http_request_duration_seconds_bucket[5m])))     # p95 latency

Labels use the route template (/fare-estimate), never the raw URL with values in it, so the number of time series stays bounded.

Common mistakes

  • High-cardinality labels such as user ids or full URLs. Each value creates a new time series and can overwhelm the monitoring system.

  • Averages for latency. Averages hide the slow tail users feel; use percentiles from histograms.

  • Unstructured logs. print("error!!") cannot be searched or aggregated. Log JSON with consistent fields.

  • Logging secrets or personal data. Log ids, not tokens or phone numbers.

Interview angle

"How would you find out why an endpoint got slow?" Start from dashboards (rate, errors, p95 and p99 latency per route), narrow the time and route, jump to traces for slow requests, then to logs by request id. Mention what instrumentation you would add if it is missing.

Practice task

  1. Run Prometheus locally with a scrape job for the service and graph the p95 latency.

  2. Add an in_progress gauge for concurrent requests.

  3. Add OpenTelemetry tracing with the FastAPI instrumentation and view traces in Jaeger.

Further reading