Latency Analysis & Optimization Questions

The formats

• JSON (JavaScript Object Notation): text-based, human-readable, self-describing (field names travel with every record), no schema required to parse.
• Protobuf (Protocol Buffers): binary, schema-defined via a .proto file with numbered fields, compact and fast to encode/decode since field names aren't repeated in every record.
• MessagePack: binary, with essentially the same flexible, schema-less data model as JSON (maps, arrays, strings, numbers) but binary-encoded, so it's a fast drop-in for JSON without requiring a schema.
• Avro: binary, schema-defined, but the schema travels with the data (or via a shared schema registry) rather than being baked into generated code, which makes it well suited to systems where the schema evolves independently of any one consumer, common in data-engineering pipelines.

Impact on latency and throughput

Binary formats generally cost less CPU to encode and decode than JSON's text parsing, and they produce smaller payloads since numbers and repeated field names aren't spelled out as text. Both effects matter directly: less CPU time is less time on the request's critical path, and a smaller payload means less time spent transferring it over the network, which compounds at high request rates or with large payloads. JSON's overhead is usually a non-issue for low-volume or human-facing APIs, where readability and the ability to curl and eyeball a response are worth more than the CPU/network savings.

Worked example

Take one small event record: {"user_id": 48213, "event": "click", "ts": 1699999999}. Encoded compactly:

JSON:        49 bytes  (spells out "user_id", "event", "ts" as literal text every time)
MessagePack: 32 bytes  (binary, same schema-less model as JSON)
Protobuf:    17 bytes  (binary, numbered field tags instead of field names, schema-defined)
Avro:        14 bytes  (binary, no per-field tags at all, relies entirely on the shared schema)

JSON is roughly 2.9x the size of Protobuf and 3.5x the size of Avro here, because it repeats the field names on every single record; the binary formats spend zero bytes on that, and Avro saves a further two bytes over Protobuf by dropping per-field tags too, relying entirely on the shared schema for field identity. On the CPU side, a quick decode-time comparison (200,000 iterations in Python) showed JSON's parser taking about 830ns per record versus MessagePack's about 210ns, roughly a 4x gap from skipping text tokenization; the exact multiplier varies by language and library, but the direction (binary formats decode faster) holds broadly.

When to change format

Switch when serialization or payload size shows up as a real, measured chunk of your critical path, visible as CPU time in a profiler or a trace span, or as a meaningful fraction of your bandwidth budget, not preemptively. Also consider switching when you need first-class schema evolution across many independently-deployed services (Protobuf and Avro both support adding or deprecating fields safely via field numbering or a schema registry), which JSON and MessagePack don't provide on their own.

Trade-offs

• CPU cost: binary formats are cheaper to parse; JSON's text parsing has real, measurable overhead at high volume.
• Payload size: binary formats are smaller (no repeated field names, compact number encoding); this maps directly to network transfer time.
• Schema evolution: Protobuf and Avro have built-in field versioning; JSON and MessagePack have no enforced contract, compatibility is a team convention, not a guarantee.
• Developer ergonomics: JSON is directly readable and debuggable with generic tools; Protobuf and Avro need generated code or a schema registry and are opaque on the wire; MessagePack sits in between, binary but with JSON's exact data model, so no schema to maintain but also no schema-based safety.

Framing

The goal is an observability strategy that lets engineers find and fix latency problems across many services written in different languages, owned by different teams, without missing the signal or drowning in cost.

Distributed tracing

Adopt a vendor-neutral tracing standard, OpenTelemetry (a common API and set of language libraries for emitting traces, metrics, and logs in a compatible format), so every service, regardless of language, produces spans that share the same trace ID and can be stitched into one end-to-end view of a request's path.

Sampling strategies: head vs tail

• Head-based sampling decides whether to trace a request at its very first hop, for example "trace 1% of requests." It's cheap and simple, but samples blind to outcome, meaning most sampled traces end up being the boring, fast, successful ones, exactly the requests that don't need debugging.
• Tail-based sampling defers the sampling decision until the request finishes, so it can specifically keep traces for slow or failed requests, the ones that actually matter for latency debugging, and discard fast, successful ones at a much higher rate. The trade-off is it needs to buffer every span for a request somewhere until the decision is made, which costs more infrastructure, a collector layer holding spans in memory, than head-based sampling.
• A common practical approach combines both: low-rate head-based sampling for baseline statistical visibility, plus tail-based sampling specifically for anything exceeding a latency threshold or returning an error, giving both the aggregate picture and guaranteed visibility into the cases that actually need debugging.

Span enrichment

Attach high-value, low-cardinality attributes to spans, such as service name, endpoint, status code, region, and tenant tier, so traces can be filtered and aggregated meaningfully. Avoid attaching genuinely high-cardinality values, raw user IDs or full request bodies, directly as span attributes; that belongs in logs correlated to the trace, not the trace's indexed metadata.

Correlating traces with metrics and logs

Propagate the trace ID into log lines, structured logging with a trace_id field, and expose it as an exemplar on relevant histogram metrics, many metrics backends support attaching a sample trace ID to a specific histogram bucket. That way, an engineer looking at a metric spike, "p99 jumped at 14:32," can click through to an actual example trace from that moment, and from that trace's logs, rather than manually correlating timestamps across three separate tools.

Storage, retention, and query performance

Full-fidelity trace storage at scale gets expensive fast. A common pattern is short full-fidelity retention, days, for interactive debugging, with a downsampled or aggregated form, such as span-duration histograms per service and endpoint computed and stored, not the raw spans, kept for longer-term trend analysis, weeks to months, since most trace-level debugging happens within days of an incident, not months later.

Balancing observability detail vs cost

• Every extra span, attribute, or sampled trace has a real cost: storage, ingestion, and query-time cost. The strategy should default to answering the specific latency questions the team actually asks, where does time go per hop, which requests are outliers, what changed before a regression, rather than maximal instrumentation for its own sake.
• Tail-based sampling is the single highest-leverage cost control here: it keeps overall trace volume low while still guaranteeing the slow and failed requests that actually drive latency investigations are never missed.

Why throughput and latency can pull in opposite directions

Latency is how long one request takes; throughput is how many requests the system completes per second. Techniques that raise throughput often do so by making individual requests wait so they can be processed more efficiently in bulk, which raises the latency of any single request even as the system does more work per second overall.

Concrete examples where increasing throughput worsens latency

• Batching: a service that waits up to 20ms to collect a batch of 50 database writes before sending them together cuts per-write overhead and raises writes per second, but a single write that arrives alone is now stuck waiting up to 20ms for the batch to fill or time out, versus being sent in under a millisecond by itself.
• Queueing: adding a queue in front of a fixed-size worker pool smooths bursts and keeps throughput high right up to the pool's capacity, but every request now waits in line behind whatever is ahead of it; that wait grows sharply as utilization approaches 100%.
• A small connection pool: reusing a small set of database connections avoids the cost of opening a new connection per request, which is good for throughput, but once every connection is busy, new requests queue for a free one, adding wait time under load.
• Parallelism with shared resources: running more worker threads increases throughput on a multi-core box, but once threads start contending for the same lock, disk, or downstream connection, individual request latency rises from contention even as aggregate throughput keeps climbing.

The math behind the tail turning up

wait_time ≈ service_time × utilization / (1 − utilization)

For example, with a fixed service_time of 10ms: at 50% utilization, wait_time ≈ 10 × 0.5 / 0.5 = 10ms of queueing on top of the 10ms of actual work. At 90% utilization, wait_time ≈ 10 × 0.9 / 0.1 = 90ms, nine times the queueing delay for less than double the load. That's the hockey stick: going from 50% to 90% utilization only doubles the work rate but multiplies the queueing wait by 9x.

Utilization here is arrival rate divided by service rate. At low utilization, wait time is small; as utilization climbs past roughly 70-80%, wait time rises steeply (the "hockey stick" curve) because there is less and less slack left to absorb bursts. Pushing utilization toward 100% to maximize throughput is a latency trap.

Choosing parameters for a service with both interactive and background traffic

• Give interactive requests their own worker pool and connection pool, sized so utilization stays well under 70% even at peak, keeping their queueing delay small.
• Run background jobs on a separate pool, or a lower-priority queue, so a burst of batch work cannot steal capacity from interactive requests; if they must share infrastructure, use priority queues so interactive requests always jump the line.
• Batch and pool aggressively for the background path (larger batch windows, bigger connection pools, more parallelism), since individual job latency does not matter there, only overall throughput.
• Size batch windows for anything on the interactive path (5-10ms, say) as a small fraction of the latency budget, not a value tuned purely for throughput.

Signals for CPU-bound

• CPU utilization (user + system time) is high or near 100% across cores, and the run queue (threads ready to run but waiting for a free core) is longer than the number of available cores.
• iowait is low: the CPU isn't idle waiting on disk or network, it's genuinely busy computing.
• Throughput improves when you add cores or optimize the hot code path, but not when you just add more concurrent connections.

Signals for I/O-bound

• iowait is elevated: the CPU is frequently idle while waiting on disk or network operations to complete.
• Disk or network queue depth is high, or syscall tracing shows a large share of time inside read/write/connect calls.
• Requests are slow even though CPU utilization looks unremarkable or even low.

Tools and metrics to check

• top / vmstat: the us (user), sy (system), and id (idle) columns give a quick CPU-vs-idle split; mpstat -P ALL breaks this down per core, useful when one core is saturated while others are idle (a concurrency/parallelism problem, not a raw compute problem).
• iostat -x: disk %util and average wait time per I/O operation.
• Network metrics: throughput, retransmits, connection resets, which signal network-level stalls rather than local disk I/O.
• strace -c: a summary of time spent per syscall, useful to see whether a process is dominated by I/O syscalls versus CPU-heavy work.
• Flamegraphs and other CPU profiling tools can confirm which specific code is consuming CPU once you already know you're CPU-bound; that deeper profiling workflow is its own topic, here the goal is just to establish CPU-bound vs I/O-bound first.

Actions for each diagnosis

• CPU-bound: optimize the hot code path (an algorithmic or serialization-format improvement usually beats just adding hardware), or scale out horizontally if the workload is legitimately compute-heavy and correctly provisioned; batching or deduplicating repeated work also reduces total CPU spent per unit of useful output.
• I/O-bound: increase concurrency so other work can proceed while one request waits on I/O (as long as the downstream isn't already saturated), add caching to avoid the I/O entirely for repeat requests, tune connection pooling and keep-alive to cut reconnect overhead, and check whether the I/O itself (disk, network, or a downstream dependency) is saturated, in which case the fix is capacity or dependency-side, not something you can code around locally.
• Mixed signals (moderate CPU and moderate iowait together) often point somewhere else entirely, like lock contention or garbage collection, and are worth investigating as their own category rather than forcing them into a CPU-vs-I/O split.

Plausible hidden causes

Instrumented spans only measure the time a library explicitly wrapped. Roughly 700ms is unaccounted for, which points at delay happening outside what any span is timing:

1. Queuing before the traced work even starts. Time spent in a listen/accept queue, a load balancer queue, or a thread-pool/executor queue before a handler begins running is invisible to a span that only starts its clock once the handler executes.
2. CPU scheduling delay (off-CPU time). A thread can be runnable but not actually running because the CPU is busy with something else, another tenant, garbage collection, or kernel work. A span reports wall-clock duration, but if the underlying instrumentation doesn't distinguish "doing work" from "waiting to be scheduled," a big gap between a span's reported CPU time and its wall-clock time is exactly this.
3. Blocking calls that happen outside the traced boundary. DNS resolution, a TLS handshake, or waiting to check out a connection from a pool typically happen before an RPC client library's span even starts, so they're silently absorbed into the gap.
4. Garbage collection or other stop-the-world pauses on any of the hosts involved, which stall the whole process regardless of which span happens to be "active" at that moment.
5. Retries not reflected proportionally. A span might report only the final, successful attempt's duration, hiding one or two earlier failed or slow attempts that also consumed wall-clock time.

Three experiments/probes to surface the missing delay

1. Instrument the queueing boundary explicitly. Add a timestamp at the earliest possible point (e.g., when the load balancer or reverse proxy accepts the connection, or when a request enters the process) and compare it against when the handler's own span actually starts. This directly measures accept-to-dispatch queuing delay that current spans skip entirely.
2. Kernel-level off-CPU analysis. Use strace -T -f on the process to see per-syscall wait time (a lot of time in futex calls means lock contention; time in connect/read means I/O waits), or an eBPF-based tool (eBPF lets you attach lightweight tracing/profiling programs to running kernel events without changing kernel code) (like an off-CPU profiler) to directly measure how long threads sat runnable but not scheduled on a core. Checking perf sched or the kernel's scheduler run-queue stats tells you whether the host itself is CPU-oversubscribed.
3. Instrument the client library's connection lifecycle. Turn on debug metrics or logging for "time spent acquiring a connection from the pool," and separately time DNS resolution and the TLS handshake. A cold client, or one whose pooled connections keep expiring, can pay these costs on every request without any of it showing up as a traced RPC span.

Running all three against the same time window narrows which bucket (pre-dispatch queuing, CPU scheduling, or connection-lifecycle overhead) actually accounts for most of the missing ~700ms, rather than guessing.