HTTP Trace Metrics Guide

This guide explains the HTTP request lifecycle tracing metrics available in AIPerf, which provide granular timing information at the transport layer for performance analysis and debugging.

Overview

AIPerf captures detailed timing information throughout the HTTP request lifecycle using the aiohttp tracing system. These metrics follow industry-standard conventions from k6 load testing and the HAR (HTTP Archive) specification, making them familiar and compatible with existing performance analysis tools.

Key characteristics:

• Trace metrics are captured using time.perf_counter_ns() for nanosecond precision during measurement
• When exported, timestamps are converted to wall-clock time (time.time_ns()) for correlation with logs and external systems
• The naming convention uses the http_req_ prefix to match k6’s metric naming

Enabling trace timing output:

To display HTTP trace timing metrics in the console output, use the --show-trace-timing flag:

$
aiperf profile ... --show-trace-timing

This displays a separate table with the HTTP trace timing breakdown after the main metrics table.

Request Lifecycle

The HTTP request lifecycle breaks down into distinct phases, each measured independently:

Request Lifecycle ────────────────────────────────────────────────────────────────────────────────────►
    │                 │                 │                │                    │                       │
    │◄─dns_lookup_ns─►│◄─connecting_ns─►│◄─ sending_ns ─►│◄──── waiting_ns ──►│◄──── receiving_ns ───►│
    │                 │                 │                │                |   │                       │
dns resolution     TCP+TLS      request send     request_send_end     first body chunk      last body chunk
(cache miss)      handshake     (last chunk)     (ready for server)   (response starts)     (response complete)
    │                 │                                                   │
    └─ dns_cache_hit (skip lookup)                                        └── response_headers_received
                      │
                      └─ connection_reused_ns (skip TCP/TLS)

Metric Reference

Connection Phase Metrics

These metrics capture the time spent establishing a connection before the HTTP request can be sent. They are specific to the aiohttp HTTP client.

Request/Response Phase Metrics

These core timing metrics measure the actual HTTP request and response transfer. They are available for any HTTP client that populates the base trace data model.

Data Size Metrics

Key Relationships

Duration Metric

The http_req_duration metric is measured directly from timestamps for maximum accuracy:

http_req_duration = response_receive_end_perf_ns - request_send_start_perf_ns

This measures from when the request started being sent to when the response was fully received/finalized. Conceptually this covers sending + waiting + receiving, but the direct measurement is more accurate than summing components.

Total Connection Overhead

Connection overhead combines all pre-request setup time:

http_req_connection_overhead = http_req_blocked + http_req_dns_lookup + http_req_connecting

Total Time Formula

The http_req_total metric sums all 6 timing phases for a reconcilable breakdown:

http_req_total = http_req_blocked + http_req_dns_lookup + http_req_connecting
               + http_req_sending + http_req_waiting + http_req_receiving

Important Distinctions

• TTFB vs TTFT: http_req_waiting measures Time to First Byte (specifically, the first body byte after headers), not Time to First Token. The server sends HTTP headers first, then body content. For LLM APIs, the first body byte may contain protocol overhead before actual tokens appear. Use the time_to_first_token metric for LLM-specific timing that measures when the first actual token content is received.

• Connection reuse: When http_req_connection_reused = 1, both http_req_dns_lookup and http_req_connecting will be 0 since no new connection was established.

HTTP Total Time vs Request Latency

You may notice that http_req_total can be larger than request_latency. This is expected behavior — the two metrics measure different things:

Why http_req_total > request_latency:

For streaming LLM responses (SSE), the HTTP stream typically ends with:

[content chunk 1]  ─► included in both metrics
[content chunk 2]  ─► included in both metrics
[content chunk N]  ─► request_latency ends here (last actual token)
[usage info]       ─► http_req_total includes this
[DONE]             ─► http_req_total and http_req_duration end here (last network chunk)

The request_latency metric excludes trailing metadata ([DONE] markers, usage statistics) because those don’t represent meaningful content delivery. The HTTP trace metrics include all network traffic.

Which metric should I use?

Accessing Trace Data

Enabling HTTP Trace Export

By default, raw HTTP trace data is not included in profile_export.jsonl to keep file sizes small. The computed metrics (http_req_duration, http_req_waiting, etc.) are always available regardless of this setting.

To include the full trace data (timestamps, chunks, headers, socket info), use the --export-http-trace flag:

$
aiperf profile ... --export-http-trace

Export Levels

The --export-http-trace flag works with records or raw export levels:

Example with both flags:

$
aiperf profile ... --export-level records --export-http-trace

Output Format

When exported to profile_export.jsonl, trace data uses wall-clock timestamps (nanoseconds since epoch) for cross-system correlation. The trace data is included in each record:

1
{
2
  "metadata": { "x_request_id": "9568f1d7-10e9-4d42-bb69-b06c87caae9f", "..." : "..." },
3
  "metrics": {
4
    "http_req_duration": {"value": 37421.26, "unit": "ms"},
5
    "http_req_waiting": {"value": 4473.26, "unit": "ms"},
6
    "http_req_blocked": {"value": 0.0, "unit": "ms"},
7
    "..." : "..."
8
  },
9
  "trace_data": {
10
    "trace_type": "aiohttp",
11
    "request_send_start_ns": 1768309400341882300,
12
    "request_headers": {"Host": "localhost:8000", "Content-Type": "application/json", "...": "..."},
13
    "request_headers_sent_ns": 1768309400342515706,
14
    "request_chunks": [[1768309400342549481, 91586]],
15
    "request_send_end_ns": 1768309400342549481,
16
    "request_chunks_count": 1,
17
    "request_bytes_total": 91586,
18
    "response_status_code": 200,
19
    "response_reason": "OK",
20
    "response_receive_start_ns": 1768309404815807889,
21
    "response_headers": {"Content-Type": "text/event-stream; charset=utf-8", "...": "..."},
22
    "response_headers_received_ns": 1768309400369701553,
23
    "response_chunks": [[1768309404815807889, 565], [1768309405191294711, 268], "..."],
24
    "response_chunks_count": 42,
25
    "response_bytes_total": 16384,
26
    "response_receive_end_ns": 1768309437763141384,
27
    "sending_ns": 667181,
28
    "waiting_ns": 4473258408,
29
    "receiving_ns": 32947333495,
30
    "duration_ns": 37421259084,
31
    "tcp_connect_start_ns": 1768309400341999707,
32
    "tcp_connect_end_ns": 1768309400342480993,
33
    "connecting_ns": 481286,
34
    "dns_cache_hit_ns": 1768309400342023726,
35
    "local_ip": "127.0.0.1",
36
    "local_port": 48362,
37
    "remote_ip": "127.0.0.1",
38
    "remote_port": 8000
39
  },
40
  "error": null
41
}

Trace Data Fields

The trace_data object contains both raw timestamps and computed durations:

Raw Timestamps (wall-clock nanoseconds):

Chunk Aggregates (always available):

Chunk Data (only with --export-http-trace, transport-layer granularity):

Computed Durations (nanoseconds):

Request/Response Metadata:

Connection Info (aiohttp only):

Common Use Cases

Identifying Connection Pool Saturation

If http_req_blocked is consistently high, your connection pool is exhausted. Consider:

• Increasing the connection pool size
• Reducing the number of concurrent requests
• Investigating slow responses that hold connections

Detecting DNS Issues

If http_req_dns_lookup is high:

• DNS resolution is slow
• Consider using DNS caching or a faster resolver
• Check if DNS TTLs are appropriate

Measuring Server Processing Time

http_req_waiting (TTFB) isolates server-side latency:

• Low sending + High waiting = Server is the bottleneck
• High receiving = Large response or slow network throughput

Analyzing Connection Efficiency

Track http_req_connection_reused aggregated values:

• Values close to 1.0 (100% reuse) indicate efficient keep-alive usage
• Low reuse rates suggest connection churn, adding overhead via DNS lookups and TCP/TLS handshakes

Chunk-Level Analysis

When --export-http-trace is enabled, the request_chunks and response_chunks arrays provide transport-layer granularity useful for:

• Analyzing streaming response patterns from LLM APIs
• Debugging chunked transfer encoding issues
• Understanding network-level timing variations

Aggregate fields (request_chunks_count, request_bytes_total, response_chunks_count, response_bytes_total) are always available regardless of the export flag.

Standards Compliance

AIPerf trace metrics align with industry standards for compatibility with existing tools:

HAR Specification Notes

Per the HAR 1.2 specification:

• blocked, dns, connect use -1 when not applicable (AIPerf uses 0 or null)
• send, wait, receive are required non-negative values
• time (duration) equals the sum of all applicable timing phases
• ssl timing is included within connect for backwards compatibility

k6 Metric Differences

The k6 http_req_tls_handshaking metric is not separated in AIPerf. TLS time is combined with TCP connection time in http_req_connecting because aiohttp’s tracing API provides a combined measurement via on_connection_create_start/end events.

Quick Reference

Related Documentation

• Working with Profile Export Files - How to parse and analyze AIPerf output files
• Source: trace_models.py - Trace data model definitions
• Source: http_trace_metrics.py - HTTP trace metric implementations