S077 · The 3 Pillars — Metrics, Logs, Traces

#!/usr/bin/env python3
"""three_pillars.py — instrument a Flask service with metrics, logs, traces.
 
Run:
  pip install flask opentelemetry-api opentelemetry-sdk \\
              opentelemetry-instrumentation-flask \\
              opentelemetry-exporter-otlp-proto-grpc \\
              prometheus-client
  python three_pillars.py
  curl http://localhost:5000/order/42
 
To view telemetry:
  - Metrics: http://localhost:5000/metrics (Prometheus format)
  - Logs: printed to stdout with trace_id correlation
  - Traces: printed to stdout (in real setup: OTLP -> Jaeger)
"""
from __future__ import annotations
 
import logging
import random
import time
import uuid
 
from flask import Flask, jsonify, request
 
# --- Metrics via prometheus_client ---
from prometheus_client import Counter, Histogram, generate_latest, CONTENT_TYPE_LATEST
 
REQUESTS = Counter(
    "http_requests_total",
    "Count of HTTP requests",
    ["method", "endpoint", "status"],
)
LATENCY = Histogram(
    "http_request_duration_seconds",
    "Latency of HTTP requests",
    ["endpoint"],
    buckets=(0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1.0, 2.5, 5.0),
)
 
# --- OpenTelemetry tracing (in-memory / console exporter) ---
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import (
    ConsoleSpanExporter, SimpleSpanProcessor,
)
 
trace.set_tracer_provider(TracerProvider())
trace.get_tracer_provider().add_span_processor(
    SimpleSpanProcessor(ConsoleSpanExporter())
)
tracer = trace.get_tracer(__name__)
 
 
# --- Logging with trace-id correlation ---
class TraceContextFilter(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        span = trace.get_current_span()
        ctx = span.get_span_context()
        record.trace_id = format(ctx.trace_id, "032x") if ctx.trace_id else "-"
        record.span_id = format(ctx.span_id, "016x") if ctx.span_id else "-"
        return True
 
 
handler = logging.StreamHandler()
handler.setFormatter(logging.Formatter(
    "%(asctime)s %(levelname)-5s [trace=%(trace_id)s span=%(span_id)s] "
    "%(name)s: %(message)s"
))
handler.addFilter(TraceContextFilter())
log = logging.getLogger("orders")
log.addHandler(handler)
log.setLevel(logging.INFO)
 
 
# --- Simulated backends ---
def db_lookup(order_id: int) -> dict:
    with tracer.start_as_current_span("db.lookup") as span:
        span.set_attribute("db.order_id", order_id)
        time.sleep(random.uniform(0.005, 0.05))
        if order_id == 500:
            span.set_attribute("db.status", "not_found")
            raise LookupError(f"order {order_id} not found")
        return {"order_id": order_id, "total": random.randint(10, 500)}
 
 
def payment_check(order: dict) -> bool:
    with tracer.start_as_current_span("payment.check") as span:
        span.set_attribute("payment.amount", order["total"])
        # Simulate 'slow days' — 10% of calls
        delay = 2.0 if random.random() < 0.1 else random.uniform(0.01, 0.1)
        time.sleep(delay)
        span.set_attribute("payment.slow", delay > 1.0)
        return True
 
 
# --- HTTP handlers ---
app = Flask(__name__)
 
 
@app.route("/order/<int:order_id>")
def get_order(order_id: int):
    endpoint = "/order/<id>"
    start = time.time()
    request_id = request.headers.get("X-Request-Id", str(uuid.uuid4())[:8])
    log.info("received order request order_id=%d req_id=%s", order_id, request_id)
 
    with tracer.start_as_current_span("handle_order") as span:
        span.set_attribute("http.request_id", request_id)
        span.set_attribute("order.id", order_id)
        try:
            order = db_lookup(order_id)
            payment_check(order)
            status = "200"
            log.info("order served order_id=%d total=%d", order_id, order["total"])
            response = jsonify(order)
        except LookupError as e:
            status = "404"
            log.warning("order not found order_id=%d err=%s", order_id, str(e))
            response = jsonify({"error": str(e)}), 404
        except Exception as e:  # noqa: BLE001
            status = "500"
            log.exception("order failed order_id=%d", order_id)
            span.record_exception(e)
            response = jsonify({"error": "internal"}), 500
 
    # Metrics update
    REQUESTS.labels(method="GET", endpoint=endpoint, status=status).inc()
    LATENCY.labels(endpoint=endpoint).observe(time.time() - start)
    return response
 
 
@app.route("/metrics")
def metrics():
    return generate_latest(), 200, {"Content-Type": CONTENT_TYPE_LATEST}
 
 
if __name__ == "__main__":
    print("→ visit http://127.0.0.1:5000/order/42")
    print("→ or a slow one: for i in {1..20}; do curl -s /order/$i > /dev/null; done")
    print("→ metrics: http://127.0.0.1:5000/metrics")
    app.run(host="127.0.0.1", port=5000, debug=False)