Feature Proposal: Per-Phase Request Metrics (TaskResult.metrics)

[o-nnerb]

Status: implemented and closed. The proposal shipped in #380, and its follow-ups in #385, #386 and #387. What is left is in three pull requests that were still open when this was closed: #391 (a monitor hears the cache and revalidation transactions), #393 (emitting to swift-metrics) and #394 (the benchmark package). What follows describes what shipped, then what came after it, and the last section lists what did not.

Overview

TaskResult<Element> carried head: ResponseHead and payload: Element — no timing data. On Darwin, URLSessionTaskMetrics already measures DNS/connect/TLS/TTFB, but Internals.URLSessionClient never collected it. On the NIO side, async-http-client exposed nothing equivalent: its only public hooks (http1_1/http2ConnectionDebugInitializer) fire after TCP connect and the TLS handshake are done, and the resolver was a closed enum.

TaskResult.metrics adds the same shape from both executors. It had two parts, the second blocked on the first.

Part 1 — async-http-client fork (shipped in 1.39.1)

request-dl/async-http-client#15 went further than the first sketch (a single HTTPConnectionMetrics value):

• HTTPClientTransactionMetrics, delivered once per transaction (one per redirect hop, in order, also for transactions that fail) through HTTPClientResponseDelegate.didCollectMetrics(task:_:), with a default no-op so existing delegates are unaffected. It is delivered before didFinishRequest, and also on the error paths.
• Dates: fetch start, queued, request start/end, response start/end. Byte counts: request header/body sent (on the wire and before encoding), response header/body received and the body after decoding. error.
• Connection: id, HTTP/1.1 or HTTP/2, isReused, local/remote address, isProxyConnection, tlsVersion, tlsCipherSuite (Network.framework only), and the DNS / connect / TLS intervals (only on the first transaction of a connection).
• HTTPClient.Configuration.collectDNSMetrics (default false): on POSIX, SwiftNIO's default resolver cannot be observed, so reporting DNS replaces it with the fork's own getaddrinfo-based one. It has no effect on Network.framework, which reports DNS itself.

1.39.0 used tls_protocol_version_t without an @available, which failed to build on macOS, iOS, tvOS and watchOS in CI. 1.39.1 adds it, and this package now requires from: "1.39.1".

Part 2 — RequestDL (#380)

let result = try await DataTask { ... }.result()

for transaction in result.metrics?.transactions ?? [] {
    print(transaction.url, transaction.connection?.isReused)
}

• TaskResult.metrics: RequestMetrics? — optional: nil for a MockedTask, which has nothing to measure. The first draft of this proposal made it non-optional. (A response served from the cache was nil here too in Add per-transaction request metrics to TaskResult (#340) #380; since Report cache hits and revalidations as transactions with a source #387 it carries a transaction with source .cache, see below.)
• RequestMetrics.transactions: [Transaction], one per exchange, plus fetchInterval. Transaction and Connection mirror what both executors report with portable types (Date, String addresses, UInt16 cipher suite, a TLSVersion enum with no NIOSSL dependency, Interval in place of Duration, which needs macOS 13). Anything not reached or not observable is nil, never zero. RequestMetrics, Transaction and Connection are Equatable; Transaction compares its error by type and String(reflecting:), since Error is not Equatable.
• URLSession: TaskDelegate implements urlSession(_:task:didFinishCollecting:) and converts every URLSessionTaskTransactionMetrics. An exchange answered from URLSession's own cache has connection == nil. URLSession only reports an error for the whole task, so runExchange and resumeDownload record the failure on the transaction of the task that failed, matched by taskIdentifier, in either order against didFinishCollecting.
• NIO: the response receivers, including resumed-download continuations, implement didCollectMetrics(task:_:).
• A transport-agnostic Internals.RequestMetricsCollector travels SessionTask → RawTask → AsyncResponse → TaskResult. The modifiers that remap the payload carry it unchanged.
• Session.collectDNSMetrics(_:) opts into DNS timing under NIO/POSIX, off by default, because it changes how host names are resolved for every request of the session. It is part of the pooled-client cache key.
• TaskResult.init(head:payload:) is unchanged and TaskResultPrimitive is untouched.

Semantics

TaskResult.metrics is read when asked for. For a DataTask the body is already collected, so it is complete; for DownloadTask's TaskResult<AsyncBytes> the last transaction only ends once the body has been consumed. fetchInterval is the time of a fetch that completed: nil while the last transaction has not finished or failed.

Differences between executors that remain: queued comes from AsyncHTTPClient only; tlsCipherSuite is known to URLSession and Network.framework only; the header byte counts are nil for HTTP/2.

Shipped after #380

• #385: RequestMonitor.request(_:didCollect:) reports each RequestMetrics.Transaction of an execution to a monitor, whether the request ends well or not. This is the way to read the phases of a request that fails as a whole, which throws and has no TaskResult. AsyncHTTPClient reports a transaction before the execution ends; URLSession reports it once its task is done, which can be after the final RequestState, and only reports an error for the task as a whole.
• #386: tests of the Network.framework path (nioTransportServices): cipher suite, DNS without the opt-in, the order of the phases, a reused connection.
• #387: a response served from the cache, and the conditional request that asks whether the cache still holds, are transactions of their own with a source (.network, .cache, .revalidation), so they are no longer an absence of metrics. A revalidation comes first, then the cached response it confirmed, or the request that followed it. A MockedTask still has none.
• #391 (open): a RequestMonitor is told about those cache and revalidation transactions as well, from where the cache answers, since no executor reports them.
• #393 (open): emitting to swift-metrics. Session.metricsFactory(_:) opts a session in, per session and not ambient, and each execution reports its duration and the bytes sent and received, labelled by method, host, status class and, on failure, the error type, never the URL. It has no protocol-version label, for the URLSession reason below.
• #394 (open): a benchmark package, Benchmarks/, to measure what the fork's metrics cost, replacing the harness that was lost.

What did not ship

• Metrics on the thrown error of a request that fails. A request that fails as a whole throws, so there is no TaskResult to read metrics from, and nothing attaches them to the thrown error. A RequestMonitor does hear them since Report request metrics to a RequestMonitor, whether the request ends well or not #385, but a caller that only awaits the task does not. Transaction.error is only visible when a body fails after the response head, or when a download continued from a failed attempt. Needs its own API decision.
• HTTP version from URLSession. Internals.ResponseHead.init(_ response: HTTPURLResponse) still fixes the version at 1.1. negotiatedProtocol now carries the real one, but the metrics arrive after the head, so it is not a drop-in.
• A protocol-version label in what is emitted to swift-metrics (Report what each request measured to a swift-metrics factory #393), for the reason in the previous point: the URLSession executor still reports a nominal 1.1. Emitting itself is in Report what each request measured to a swift-metrics factory #393, still open, and swift-metrics is not a dependency until it lands.
• Cost on small requests: about 3% more CPU per request, on macOS only. The harness of Add a benchmark package for what the fork's metrics cost #394, rewritten, ran 8 rounds at full size (the first left out), the same AsyncHTTPClient client against the fork at 1.38.2 and at 1.39.1, interleaved, with the server in a process of its own. Ratio new/old, 95% interval over the 7 rounds: bulk downloads (16 × 256 MiB) 1.009 ± 0.031 in throughput and 1.004 ± 0.031 in CPU per request; bulk uploads (8 × 128 MiB) 1.002 ± 0.031 and 0.994 ± 0.058; 60 000 small GETs, 32 at a time, 0.989 ± 0.021 in throughput and 1.032 ± 0.028 in CPU per request (7.52 s to 7.75 s). So no detectable cost on bulk transfers, as before, and on small requests a CPU cost small enough to be hard to see, but whose interval now excludes 1 (six of the seven rounds were above 1). The earlier estimate for small requests was 5-10% against 15-20% of noise; the noise between rounds was 1-7% this time. Limits: one machine, the client and the server sharing its 8 cores and not otherwise idle; macOS, where the earlier measurement was Linux, so it is not known whether the 3% holds there; and the client does not consume the metrics (no collectDNSMetrics, no delegate), so this is the cost of the counters the fork always keeps, not of using them.
• Known limit: a failure before the exchange had a task (connection refused), after a manual body redirect, can land on an earlier hop's transaction if that hop's metrics arrive late. Noted in the code; not reproduced in a test.
• API choices to revisit: RequestMetrics, Transaction and Connection have public memberwise inits, which freezes their field lists. Hashable was not added.

Milestone: 4.5.0