03 — Logging, Metrics, and Tracing

The three pillars of observability are logs, metrics, and traces. A production C++ service that emits all three is legible to on-call engineers, SRE dashboards, and to your future self at 2am on a Saturday. A service that emits none is a black box everyone will resent. Phase 6 is when you learn to instrument. This is one of the highest-leverage skills you can add — wiring it in takes a day, being unable to means teams will never trust your code.

The three pillars, cleanly

Pillar

Question it answers

Cardinality

Storage

Logs

“What exactly happened on this one request?”

High (one row per event)

Loki / Elastic / stdout → aggregator

Metrics

“How is the system behaving in aggregate?”

Low (a few labels)

Prometheus / Mimir / VictoriaMetrics

Traces

“Where did the 400ms go across services?”

Sampled

Jaeger / Tempo / Honeycomb

An immature service emits one pillar (usually printf logs). A mature service emits all three, and — crucially — correlates them via a shared trace ID. Your P6.2 acceptance criterion is exactly this: the same request produces a log line, updates a metric, and shows up as a span, all joinable by trace_id.

Logging: spdlog

spdlog is the C++ logging library. Not “a” — “the.” It is header-only or compiled, supports async logging, multiple sinks, structured (JSON) formatters, and log levels. If you install one dependency in Phase 6, install this one.

Minimal async setup with rotating file sink:

#include <spdlog/spdlog.h>
#include <spdlog/async.h>
#include <spdlog/sinks/rotating_file_sink.h>
#include <spdlog/sinks/stdout_color_sinks.h>

spdlog::init_thread_pool(8192, 1);  // queue size, 1 worker thread
auto file_sink = std::make_shared<spdlog::sinks::rotating_file_sink_mt>(
    "logs/miniserve.log", 1024 * 1024 * 50, 10);  // 50MB × 10 files
auto stdout_sink = std::make_shared<spdlog::sinks::stdout_color_sink_mt>();
auto logger = std::make_shared<spdlog::async_logger>(
    "miniserve",
    spdlog::sinks_init_list{file_sink, stdout_sink},
    spdlog::thread_pool(),
    spdlog::async_overflow_policy::overrun_oldest);
spdlog::register_logger(logger);
spdlog::set_default_logger(logger);
spdlog::set_level(spdlog::level::info);
spdlog::set_pattern(R"({"ts":"%Y-%m-%dT%H:%M:%S.%e%z","lvl":"%l","logger":"%n","msg":"%v","tid":%t})");

Things to note:

  • Async is not free. The thread pool decouples log formatting from your hot path, but if you overflow the queue faster than the worker drains it, you either block (block policy) or drop (overrun_oldest). Pick per service; for user-facing services, dropping is safer than blocking.

  • Rotating file sink avoids the classic “log ate the disk” pager. 50MB × 10 = 500MB ceiling.

  • JSON pattern is what your Loki/ELK pipeline actually wants. Do not ship a service with printf-style logs in 2026 — log aggregators cannot parse them cleanly.

  • Log levels. trace and debug off in prod. info for lifecycle. warn for recoverable. error for user-visible failures. critical for “page someone.” Do not invent your own levels.

Structured logging with fields

spdlog does not have named fields natively — you format them in yourself:

spdlog::info(R"({{"event":"predict","model":"{}","latency_us":{},"trace_id":"{}"}})",
             model, latency_us, trace_id);

Uglier than Go’s zap or Rust’s tracing, but functional. Wrap it in a helper. The alternative is quill (newer C++20 async logger with a nicer structured API); consider it if you find yourself writing many such helpers.

Metrics: prometheus-cpp

Prometheus is the metrics standard. prometheus-cpp is the C++ client library. Install via vcpkg or Homebrew. It exposes a /metrics HTTP endpoint that Prometheus scrapes.

The four metric types you need:

Type

Meaning

Example

Counter

Monotonic-increasing

requests_total

Gauge

Up-and-down

models_loaded

Histogram

Bucketed distribution

request_latency_seconds

Summary

Client-side quantile

Rarely worth it; prefer histogram + histogram_quantile()

Minimal setup:

#include <prometheus/exposer.h>
#include <prometheus/registry.h>
#include <prometheus/counter.h>
#include <prometheus/histogram.h>

auto registry = std::make_shared<prometheus::Registry>();
auto& req_counter = prometheus::BuildCounter()
    .Name("miniserve_requests_total")
    .Help("Total inference requests.")
    .Register(*registry);
auto& latency_hist = prometheus::BuildHistogram()
    .Name("miniserve_request_latency_seconds")
    .Help("Inference latency distribution.")
    .Register(*registry);

auto& c = req_counter.Add({{"model","resnet50"},{"status","ok"}});
auto& h = latency_hist.Add({{"model","resnet50"}},
    prometheus::Histogram::BucketBoundaries{0.001,0.005,0.01,0.05,0.1,0.5,1.0});

c.Increment();
h.Observe(0.023);

prometheus::Exposer exposer{"0.0.0.0:9091"};
exposer.RegisterCollectable(registry);

Histogram bucket design is the one place you must think. Bad buckets = useless p99. Rule of thumb: bucket edges roughly logarithmically covering the range you actually see. If your service does ~5ms typical and ~500ms tail, use {0.001, 0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1.0}. Prometheus’s histogram_quantile(0.99, ...) interpolates within buckets; garbage buckets → garbage p99.

The RED and USE methods

Two naming conventions worth knowing. Pick RED for services, USE for resources.

  • RED (Weaveworks): Rate, Errors, Duration. For every endpoint expose _total, _errors_total, _duration_seconds.

  • USE (Brendan Gregg): Utilization, Saturation, Errors. For every resource (CPU, memory, queue) expose these three.

Your P6.2 dashboards will be RED for endpoints and USE for the request queue + model pool.

Tracing: OpenTelemetry C++

OpenTelemetry (OTel) is the vendor-neutral tracing standard. The C++ SDK went 1.0 in 2022 and is production-grade as of 2026 (traces stable, metrics stable, logs stable). Install via vcpkg (vcpkg install opentelemetry-cpp) with the OTLP feature turned on.

A span is a timed unit of work. A trace is a tree of spans sharing a trace_id. Context propagation is how spans in one process link to spans in another (via traceparent HTTP header or gRPC metadata).

Minimal OTLP-gRPC tracer setup:

#include <opentelemetry/exporters/otlp/otlp_grpc_exporter.h>
#include <opentelemetry/sdk/trace/tracer_provider.h>
#include <opentelemetry/sdk/trace/simple_processor.h>
#include <opentelemetry/trace/provider.h>

namespace trace_sdk = opentelemetry::sdk::trace;
namespace otlp = opentelemetry::exporter::otlp;

otlp::OtlpGrpcExporterOptions opts;
opts.endpoint = "0.0.0.0:4317";  // OTel collector
auto exporter = std::make_unique<otlp::OtlpGrpcExporter>(opts);
auto processor = std::make_unique<trace_sdk::BatchSpanProcessor>(
    std::move(exporter), trace_sdk::BatchSpanProcessorOptions{});
auto provider = opentelemetry::nostd::shared_ptr<opentelemetry::trace::TracerProvider>(
    new trace_sdk::TracerProvider(std::move(processor)));
opentelemetry::trace::Provider::SetTracerProvider(provider);

auto tracer = provider->GetTracer("miniserve", "0.1.0");
auto span = tracer->StartSpan("predict");
// ... work ...
span->SetAttribute("model", "resnet50");
span->End();

Things that trip people up:

  • Use OTLP-gRPC, not Jaeger/Zipkin native exporters. OTLP is the future; Jaeger’s own agent has been deprecated in favor of accepting OTLP directly.

  • BatchSpanProcessor, not SimpleSpanProcessor for prod. Simple = one gRPC call per span = your /predict latency now includes tracing round-trip. Batch = periodic flush.

  • Sampling. At 10K RPS, sampling everything is expensive and useless. Use ParentBased(TraceIdRatioBased(0.01)) — sample 1% by default, keep parent decision if downstream.

  • Context propagation across gRPC is not automatic in C++ yet. You must inject/extract via a client interceptor. The opentelemetry-cpp-contrib repo has grpc interceptors — use them, don’t write your own.

Correlating the three pillars

The magic sauce: every log line and every metric label carries the current trace_id. Then a Grafana dashboard can jump from a p99 latency spike → the exact traces in that bucket → the logs for those traces. This is the workflow SREs live inside.

Implementation sketch:

auto span = tracer->StartSpan("predict");
auto trace_id = span->GetContext().trace_id();
char hex[33];
trace_id.ToLowerBase16(hex);
spdlog::info(R"({{"event":"predict_start","trace_id":"{}"}})", std::string(hex, 32));
// ... metrics.Increment() with a low-cardinality label, NOT trace_id itself
// ... work
span->End();

Never put trace_id as a Prometheus label. Prometheus explodes at high label cardinality — one time series per unique label combination. Trace IDs are unbounded. Log the trace_id; keep metric labels low-cardinality (endpoint, model, status).

A single service, wired end to end

For P6.2, your main() initialization order is:

  1. Load config.

  2. Init spdlog (before anything else logs).

  3. Init prometheus registry + expose /metrics on a separate port.

  4. Init OTel tracer + OTLP exporter.

  5. Install gRPC/HTTP interceptors that create spans and update metrics per RPC.

  6. Start service, log “ready”, enter run loop.

Drop this scaffolding into your Phase 6 template repo and copy it into every new service you write. This is the sort of thing that separates “toy” from “shippable.”

What most people get wrong

  • Logging inside hot loops synchronously. A single unbuffered printf per RPC costs microseconds. spdlog async fixes this; know why.

  • High-cardinality metric labels (user_id, trace_id, request UUID). Kills Prometheus. Use logs for high-cardinality, metrics for aggregate.

  • Sampling traces at 100% under load and then complaining OTel is slow. Sample. 1% is a reasonable default; head-based sampling with parent-based is even better.

  • Not exporting /metrics on a separate port. If your public port goes down, so does your ability to see it went down. Bind metrics to :9091 on localhost and let Prometheus scrape via a sidecar or SSH tunnel.