From e2c6bababf8a500facbd7a0ee26f363314f5c32f Mon Sep 17 00:00:00 2001 From: Maksym Kacharaba Date: Sat, 7 Nov 2026 14:09:42 +0200 Subject: [PATCH] Add OpenTelemetry-ready tracing and metrics to the pipeline MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit UseTelemetry() records a span and a request-duration measurement per attempt, under the OpenTelemetry HTTP client semantic conventions. No dependency on OpenTelemetry, and there will not be one: spans go to System.Diagnostics.Activity and measurements to a Meter, both in the BCL and both the vendor-neutral seam collectors already subscribe to. Taking the SDK as a dependency would impose it on every consumer, including the ones exporting somewhere else or nowhere at all. One span per attempt rather than per call. That is what the conventions describe — a resend carries http.request.resend_count — and it is the only shape that separates a call that took four seconds because the server was slow from one that took four seconds because two tries failed and the backoff was waited out. A single span reports four seconds for both. Conventional attribute names throughout, because conformance is the feature: a dashboard built for HttpClient keeps working, and http.method instead of http.request.method is indistinguishable from no instrumentation to anything consuming it. The transport is the one addition, namespaced as runax.http.transport. Outermost stage, at Order 50. That is a correctness constraint rather than a preference: the correlation stage derives its id from Activity.Current, so a span started after it would leave the traceparent reaching the server naming a span that does not exist — breaking the join between client and server traces silently, since both halves look fine on their own. The histogram is in seconds as the convention specifies, and tagged with low-cardinality attributes only; url.full and the correlation id are deliberately absent, since each distinct id in a path would become its own time series. Failures are still measured, because a p99 that improves when slow calls start failing instead of completing is a graph that lies by omission. Credentials in a URL are stripped from url.full unconditionally, not as an option. Bodies are never recorded. Both for the reason the logging stage gives: a span attribute persists in a backend exactly the way a log line does. Co-Authored-By: Claude Opus 5 --- CHANGELOG.md | 47 ++- README.md | 6 +- ROADMAP.md | 7 +- docs/README.md | 6 +- docs/observability.md | 164 ++++++++ docs/pipeline.md | 8 +- .../IRunaxClientBuilder.cs | 24 ++ .../DependencyInjection/RunaxClientBuilder.cs | 12 + .../Pipeline/HttpMiddlewareOrder.cs | 12 + src/Runax.Http/Pipeline/RunaxHttpTelemetry.cs | 56 +++ .../Pipeline/TelemetryMiddleware.cs | 299 ++++++++++++++ src/Runax.Http/Pipeline/TelemetryOptions.cs | 32 ++ src/Runax.Http/README.md | 14 +- tests/Runax.Http.AotSmoke/Program.cs | 4 + .../Fakes/TelemetryRecorder.cs | 121 ++++++ tests/Runax.Http.Tests/TelemetryTests.cs | 376 ++++++++++++++++++ 16 files changed, 1175 insertions(+), 13 deletions(-) create mode 100644 docs/observability.md create mode 100644 src/Runax.Http/Pipeline/RunaxHttpTelemetry.cs create mode 100644 src/Runax.Http/Pipeline/TelemetryMiddleware.cs create mode 100644 src/Runax.Http/Pipeline/TelemetryOptions.cs create mode 100644 tests/Runax.Http.Tests/Fakes/TelemetryRecorder.cs create mode 100644 tests/Runax.Http.Tests/TelemetryTests.cs diff --git a/CHANGELOG.md b/CHANGELOG.md index 1e54491..3e1927b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,10 +6,52 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/), and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). All packages in the repository are versioned together. -## [Unreleased] +## [1.1.0] - 2026-11-07 ### Added +- **Observability** — `UseTelemetry()`, a pipeline stage that records a span and a request-duration + measurement per request, under the OpenTelemetry HTTP client semantic conventions. + - **No dependency on OpenTelemetry**, and there will not be one. Spans go to + `System.Diagnostics.Activity` and measurements to a `System.Diagnostics.Metrics.Meter`, both in + the base class library and both the vendor-neutral seam collectors already subscribe to. Taking + the SDK as a dependency would impose it on every consumer, including the ones exporting + somewhere else or nowhere. `RunaxHttpTelemetry.ActivitySourceName` and `MeterName` are the + constants to hand `AddSource` / `AddMeter`. + - **One span per attempt, not per call.** What the conventions describe — a resend carries + `http.request.resend_count` — and the only shape that separates a call that took four seconds + because the server was slow from one that took four seconds because two tries failed and the + backoff was waited out. A single span reports four seconds for both. + - Conventional attribute names throughout (`http.request.method`, `url.full`, `url.template`, + `server.address`, `http.response.status_code`, `error.type`), because conformance is the + feature: a dashboard built for `HttpClient` keeps working, and `http.method` instead of + `http.request.method` is indistinguishable from no instrumentation to anything consuming it. + The transport is the one addition, namespaced as `runax.http.transport`. + - Span named `{method} {url.template}` and never with the URL in it: a name carrying an id is one + operation per id, and a backend grouping by name ends up with a million groups of one. The + template comes from the contract rather than being parsed back out of a filled-in URL. + - `http.client.request.duration`, a histogram **in seconds** as the convention specifies — a unit + that differs from every other HTTP duration in the same backend cannot be compared with them. + Tagged with low-cardinality attributes only: `url.full` and the correlation id are deliberately + absent, since each distinct id in a path would become its own time series. A failed call is + still measured, because a p99 that improves when slow calls start failing instead of completing + is a graph that lies by omission. + - **Outermost stage** (`Order` 50, outside correlation's 100), and that ordering is a correctness + constraint rather than a preference: the correlation stage derives its id from + `Activity.Current`, so starting the span after it would leave the `traceparent` reaching the + server naming a span that does not exist — breaking the join between client and server traces + silently, since both halves look fine alone. It also means the span encloses the time the other + stages spend, including an auth stage fetching a token off a cold cache. + - Credentials in a URL are stripped from `url.full` unconditionally, not as an option: the + conventions require it, and a password in a span attribute is a password in a tracing backend's + search index. The query string is included by default, matching what the logging stage does with + the same information; `RecordQueryString = false` for an API that puts a key there. Bodies are + never recorded. + - Inert until something subscribes — `StartActivity` returns `null` with no listener and the + histogram skips an unsubscribed measurement — so this is safe to leave on in a library whose + consumers may have no collector. Tracing and metrics are separately disableable, since a span is + cheap to emit and expensive to store and a histogram is the reverse. + - AOT-safe with nothing to configure; the AOT smoke test publishes with the stage attached. - **`WithTotalTimeout`** — a budget for the whole call, retries and the waits between them included. `Timeout` bounds a single *attempt*, which reads like a call budget and is not one: the transport request carrying it is built once, before the retry loop, so every attempt gets the @@ -377,5 +419,6 @@ All packages in the repository are versioned together. - Community health files: contributing guide, code of conduct, security policy, issue and pull request templates, CODEOWNERS and Dependabot. -[Unreleased]: https://github.com/runax-software/runax-http/compare/v1.0.0...main +[Unreleased]: https://github.com/runax-software/runax-http/compare/v1.1.0...main +[1.1.0]: https://github.com/runax-software/runax-http/compare/v1.0.0...v1.1.0 [1.0.0]: https://github.com/runax-software/runax-http/releases/tag/v1.0.0 diff --git a/README.md b/README.md index f54d20a..42b918e 100644 --- a/README.md +++ b/README.md @@ -82,8 +82,10 @@ discriminates on the status, a JSON property or a header. Retries are built in a `WithRetry(3)`. The generated code never references a specific HTTP library. It builds a transport-neutral -request and hands it to `IHttpTransport`. Serialization, retries, logging and auth all sit -above that boundary, so they are written once rather than once per transport. +request and hands it to `IHttpTransport`. Serialization, retries, logging, auth and telemetry all +sit above that boundary, so they are written once rather than once per transport — and the +[observability](docs/observability.md) that `UseTelemetry()` emits follows the OpenTelemetry HTTP +conventions, tags whichever transport answered, and takes no dependency on OpenTelemetry to do it. ## Packages diff --git a/ROADMAP.md b/ROADMAP.md index 9aa3217..721b173 100644 --- a/ROADMAP.md +++ b/ROADMAP.md @@ -30,6 +30,11 @@ Ordered by what each item unblocks rather than by effort. Nothing here is a comm any trim or AOT warning and then runs the binary. - [x] **Per-package READMEs and docs** — one documentation page per concept, one README per shipped package. +- [x] **Observability** — tracing and metrics on the pipeline under the OpenTelemetry HTTP client + semantic conventions, with the active transport as a tag. One span per *attempt*, so a retried + call is distinguishable from a slow one. Emits to `ActivitySource` and `Meter` in the base + library, so the package takes no dependency on OpenTelemetry and stays inert until something + subscribes. Outermost stage, because the correlation id below it is derived from the span. ## Backlog @@ -40,8 +45,6 @@ Ordered by what each item unblocks rather than by effort. Nothing here is a comm transport rather than smoothed over. - [ ] **OpenAPI to interface** — generate the annotated interface from an OpenAPI document, so the hand-written interface is a starting point rather than the only option. -- [ ] **Observability** — OpenTelemetry-ready tracing and metrics on the pipeline, with the - active transport as a tag. - [ ] **Benchmarks (BenchmarkDotNet)** — guard per-call overhead and allocations against regressions, and quantify the cost of each transport. - [ ] **Runtime proxy fallback** — a `DispatchProxy`-based path for interfaces that aren't diff --git a/docs/README.md b/docs/README.md index b6cf6ba..30302ae 100644 --- a/docs/README.md +++ b/docs/README.md @@ -17,6 +17,7 @@ New to it? Read the [root README](../README.md) for the pitch, then | [Capabilities](capabilities.md) | What HTTP libraries disagree about, how a request's requirements are derived, and the rule that a transport may throw or degrade but never pretend | | [Retries](retries.md) | Turning them on, the backoff curve, `Retry-After`, and the three defaults that are safety decisions rather than taste | | [The request pipeline](pipeline.md) | Logging, authentication and correlation as transport-agnostic middleware; where it sits relative to retries, and what the logging stage refuses to write | +| [Observability](observability.md) | Spans and metrics under the OpenTelemetry HTTP semantic conventions, one span per attempt, the transport as a tag, and why the package takes no dependency on OpenTelemetry | | [Serialization](serialization.md) | `IContentSerializer`, why no serializer is registered by default, source-generated JSON, per-client overrides | | [Testing](testing.md) | `Runax.Http.TestKit`: a recording transport and a harness that stands up a real client without a socket, so you can assert on the request it built | | [Configuration](configuration.md) | Every option on both builders, ordering guarantees, reading from `IConfiguration`, and using the runtime without a container | @@ -42,6 +43,5 @@ New to it? Read the [root README](../README.md) for the pitch, then ## Not written yet Pages arrive with the features they describe, so there is nothing here that documents something you -cannot use. Still to come, tracked on the [roadmap](../ROADMAP.md): - -- **Observability** — waiting on the tracing and metrics work +cannot use. Everything currently shipped has a page; what is still to come is tracked on the +[roadmap](../ROADMAP.md). diff --git a/docs/observability.md b/docs/observability.md new file mode 100644 index 0000000..e0a38b1 --- /dev/null +++ b/docs/observability.md @@ -0,0 +1,164 @@ +# Observability + +Spans and metrics on every request, under the OpenTelemetry HTTP client semantic conventions, with +the active transport as a tag. + +```csharp +services.AddRunaxClient() + .UseTelemetry(); +``` + +That is the whole setup on the client side. Nothing is on by default, and nothing is exported until +you point a collector at it. + +## No dependency on OpenTelemetry + +The package does not reference OpenTelemetry, and it never will. Spans go to +`System.Diagnostics.Activity` and measurements to a `System.Diagnostics.Metrics.Meter` — both in the +base class library, both designed as the vendor-neutral seam that collectors subscribe to. A library +that took the SDK as a dependency would make every consumer take it too, including the ones who +export to something else entirely or to nothing at all. + +Subscribe by name: + +```csharp +builder.Services.AddOpenTelemetry() + .WithTracing(t => t.AddSource(RunaxHttpTelemetry.ActivitySourceName)) + .WithMetrics(m => m.AddMeter(RunaxHttpTelemetry.MeterName)); +``` + +Both names are `"Runax.Http"`. They are exposed as constants rather than documented strings so a +rename cannot silently unsubscribe you. + +Until something subscribes, both are inert: `ActivitySource.StartActivity` returns `null` with no +registered listener, and the histogram skips a measurement when its meter has no subscriber. An +unobserved client pays for a null check, which is why this is safe to leave switched on in a library +whose consumers may have no collector. + +## One span per attempt + +A call that retries twice produces three spans, not one. + +That is what the conventions describe — a resend carries `http.request.resend_count` — and it is the +only shape that can answer the question retries create. A call that took 4.2 seconds because the +server was slow and a call that took 4.2 seconds because two tries failed and the backoff was waited +out are different problems with different fixes. One span covering the whole call reports 4.2 seconds +for both. + +The attempts are tied together by their parent span, and by the correlation id if that stage is on. + +## Span attributes + +| Attribute | Example | Notes | +| --- | --- | --- | +| `http.request.method` | `GET` | Always known — the method comes from an enum, so `_OTHER` never applies | +| `url.full` | `https://api.example.com/v3/repos/runax/http?state=open` | Credentials stripped; query optional, see below | +| `url.scheme` | `https` | | +| `url.template` | `/repos/{owner}/{name}` | The low-cardinality endpoint name, taken from the contract | +| `server.address` | `api.example.com` | | +| `server.port` | `8443` | Only when it is not the default for the scheme | +| `http.response.status_code` | `200` | | +| `http.request.resend_count` | `1` | Absent on a first attempt, not zero | +| `error.type` | `503`, `System.Net.Sockets.SocketException` | The status for an HTTP error, the exception type for a failure that never got one | +| `runax.http.transport` | `httpclient` | The transport that answered | +| `runax.http.client` | `IRepositoryClient` | The contract that issued it | +| `runax.http.correlation_id` | `4bf92f…` | Present when `UseCorrelation()` is on | + +The span is named `{method} {url.template}` — `GET /repos/{owner}/{name}` — and its kind is +`Client`. The name deliberately does not contain the URL: a name with an id in it is one distinct +operation per id, and a backend that groups by operation name ends up with a million groups of one. + +**4xx and 5xx set the span status to `Error`.** The server may consider a 404 a perfectly good +answer; the caller that asked for the thing did not get it, and for a client span the conventions +take the caller's side. + +### Why the conventional names and not nicer ones + +Because conformance *is* the feature. A dashboard, alert or exemplar query built against +`HttpClient` keeps working when a call starts going through a Runax.Http client, and the attributes a +backend knows how to group by are the ones it was told to expect. `http.method` instead of +`http.request.method` is indistinguishable from no instrumentation at all to anything consuming it. + +The one addition is the transport, and it is namespaced under `runax.` for the same reason: inventing +an unprefixed attribute in someone else's namespace is how a convention rots. + +## Metrics + +One instrument: `http.client.request.duration`, a histogram, **in seconds**. + +Seconds because the convention says seconds. A histogram whose unit differs from every other HTTP +duration in the same backend cannot be compared with them, and comparison is most of what a duration +is for. + +Tags: `http.request.method`, `url.scheme`, `server.address`, `server.port`, `url.template`, +`http.response.status_code`, `error.type`, `runax.http.transport`, `runax.http.client`. + +**`url.full` is not among them, and neither is the correlation id.** Every distinct id in a path +would become its own time series, and a metric backend charges for those by the million. High +cardinality belongs on a span, where it is one record rather than one series. + +A failed call is still measured. A p99 that improves because slow calls started failing rather than +completing is a graph that lies by omission, so failures are recorded with `error.type` set and +remain separable from successes. + +## Where the stage sits + +Outermost — `Order` 50, outside correlation's 100. + +Two reasons, and the second is a correctness constraint rather than a preference: + +- The span has to enclose the time the other stages spend. An auth stage fetching a token off a cold + cache is part of how long the call took, and a span that starts after it under-reports. +- The correlation stage derives its id from `Activity.Current`. Start the span after correlation runs + and the `traceparent` header reaching the server names a span that does not exist — which breaks + the join between the client trace and the server's, silently, because both halves look fine on + their own. + +With both stages on, the `traceparent` the server receives carries the trace id of the span the +client actually recorded, which is what makes the two ends one trace. + +## The query string + +Recorded by default, matching what the [logging stage](pipeline.md#logging) does with the same +information — one library should not take two positions on it. + +Turn it off for an API that puts a key or a token in the query: + +```csharp +.UseTelemetry(o => o.RecordQueryString = false) +``` + +A trace is stored and searchable for as long as your retention allows, which makes it a worse place +for a secret than a log line. + +**Credentials in the URL are stripped unconditionally** and that is not configurable. The conventions +require it, and a password in a `url.full` attribute is a password in a tracing backend's search +index. + +Request and response bodies are never recorded, for the reasons the +[logging stage](pipeline.md#what-it-will-not-log-and-why-that-is-not-configurable) sets out. Span +attributes persist in a backend exactly the way log lines do. + +## Options + +| Option | Default | What it does | +| --- | --- | --- | +| `Tracing` | `true` | Start a span per attempt | +| `Metrics` | `true` | Record the duration histogram | +| `RecordQueryString` | `true` | Include the query in `url.full` | +| `RecordClientName` | `true` | Tag `runax.http.client` | + +Tracing and metrics are independently disableable, because the costs are not the same: a span per +request is cheap to emit and expensive to store, and a histogram is the reverse. + +## Native AOT + +`ActivitySource` and `Meter` need no reflection, so the stage is AOT-safe with nothing to configure. +The AOT smoke test publishes with this stage attached and asserts zero trim warnings — see +[Native AOT & trimming](aot.md). + +## Next + +- [The request pipeline](pipeline.md) — the stages this one wraps +- [Retries](retries.md) — why there is a span per attempt +- [Transports](transports.md) — what `runax.http.transport` names diff --git a/docs/pipeline.md b/docs/pipeline.md index 66094e2..2cccdb4 100644 --- a/docs/pipeline.md +++ b/docs/pipeline.md @@ -1,6 +1,6 @@ # The request pipeline -Logging, authentication and correlation, as middleware that works on every transport. +Logging, authentication, correlation and telemetry, as middleware that works on every transport. `DelegatingHandler` is the obvious place to put all three, and it only exists in `HttpClient`-land — so anything built on it cannot be reused for RestSharp or anything else. This is the replacement, @@ -13,6 +13,7 @@ Each stage is independently opt-in: ```csharp services.AddRunaxClient() + .UseTelemetry() .UseCorrelation() .UseLogging() .UseBearerToken(() => tokenCache.Current) @@ -53,7 +54,8 @@ Explicit, from `IHttpMiddleware.Order`. Lower runs first, meaning further from t | Stage | Order | Why there | | --- | --- | --- | -| Correlation | 100 | Outermost, so every stage inside — and every log line — sees the same id | +| Telemetry | 50 | Outermost. Its span has to enclose the time the other stages spend, and the correlation stage below reads the span as `Activity.Current` — reverse the two and the `traceparent` the server receives names a span that does not exist | +| Correlation | 100 | Inside telemetry, so its id can come from the span; outside everything else, so every stage and every log line sees the same id | | Logging | 200 | Inside correlation so it can report the id; outside auth so its elapsed time includes fetching a token, which is latency the caller really experiences | | Authentication | 300 | Innermost, so the token is attached as late as possible | @@ -195,6 +197,8 @@ Three things to know: ## Next +- [Observability](observability.md) — the telemetry stage in detail: attributes, metrics, and why + there is a span per attempt - [Retries](retries.md) — what the pipeline runs inside - [Capabilities](capabilities.md) — why a stage may only touch headers - [Architecture](architecture.md) — the boundary all of this sits above diff --git a/src/Runax.Http/DependencyInjection/IRunaxClientBuilder.cs b/src/Runax.Http/DependencyInjection/IRunaxClientBuilder.cs index 792f7e8..d8c73eb 100644 --- a/src/Runax.Http/DependencyInjection/IRunaxClientBuilder.cs +++ b/src/Runax.Http/DependencyInjection/IRunaxClientBuilder.cs @@ -174,6 +174,30 @@ IRunaxClientBuilder UseBearerToken( /// This builder. IRunaxClientBuilder UseCorrelation(Action? configure = null); + /// + /// Records an OpenTelemetry span and a request-duration measurement per attempt. + /// + /// + /// + /// Emitting only. Nothing here collects or exports anything, and the package takes no + /// dependency on OpenTelemetry — the span goes to and + /// the measurement to a , both of which are in + /// the base library. Point a collector at them by name: + /// + /// + /// builder.Services.AddOpenTelemetry() + /// .WithTracing(t => t.AddSource(RunaxHttpTelemetry.ActivitySourceName)) + /// .WithMetrics(m => m.AddMeter(RunaxHttpTelemetry.MeterName)); + /// + /// + /// Until something subscribes, both are inert — so this is safe to leave on in a library whose + /// consumers may not have a collector at all. + /// + /// + /// Turns tracing or metrics off, and adjusts what is recorded. + /// This builder. + IRunaxClientBuilder UseTelemetry(Action? configure = null); + /// Configures anything the named helpers do not cover. /// Applied to this client's options. /// This builder. diff --git a/src/Runax.Http/DependencyInjection/RunaxClientBuilder.cs b/src/Runax.Http/DependencyInjection/RunaxClientBuilder.cs index dd82ae8..63bf336 100644 --- a/src/Runax.Http/DependencyInjection/RunaxClientBuilder.cs +++ b/src/Runax.Http/DependencyInjection/RunaxClientBuilder.cs @@ -194,6 +194,18 @@ public IRunaxClientBuilder UseBearerToken(Func + public IRunaxClientBuilder UseTelemetry(Action? configure = null) + { + var options = new TelemetryOptions(); + configure?.Invoke(options); + + // The contract name is taken here rather than read off the request at run time, because + // this is the one place that knows it: ClientRequest carries what the method asked for, not + // which interface declared it. + return Use(new TelemetryMiddleware(options, typeof(TContract).Name)); + } + /// public IRunaxClientBuilder UseCorrelation(Action? configure = null) { diff --git a/src/Runax.Http/Pipeline/HttpMiddlewareOrder.cs b/src/Runax.Http/Pipeline/HttpMiddlewareOrder.cs index 7d14d44..6cb8d23 100644 --- a/src/Runax.Http/Pipeline/HttpMiddlewareOrder.cs +++ b/src/Runax.Http/Pipeline/HttpMiddlewareOrder.cs @@ -12,6 +12,18 @@ public static class HttpMiddlewareOrder /// /// Correlation, outermost, so every stage inside it — and every log line — sees the same id. /// + /// + /// The telemetry stage, outermost of the built-in stages. + /// + /// + /// Outside deliberately, and the one ordering here that is a + /// correctness constraint rather than a preference: the correlation stage derives its id from + /// the ambient , so the span has to have been started + /// before it runs. Reverse the two and the traceparent header reaching the server names + /// a span that does not exist. + /// + public const int Telemetry = 50; + public const int Correlation = 100; /// diff --git a/src/Runax.Http/Pipeline/RunaxHttpTelemetry.cs b/src/Runax.Http/Pipeline/RunaxHttpTelemetry.cs new file mode 100644 index 0000000..ba6ac20 --- /dev/null +++ b/src/Runax.Http/Pipeline/RunaxHttpTelemetry.cs @@ -0,0 +1,56 @@ +using System.Diagnostics; +using System.Diagnostics.Metrics; + +namespace Runax.Http.Pipeline; + +/// +/// The names and instruments Runax.Http emits telemetry under. +/// +/// +/// +/// Public because an OpenTelemetry setup has to name them: +/// +/// +/// builder.Services.AddOpenTelemetry() +/// .WithTracing(t => t.AddSource(RunaxHttpTelemetry.ActivitySourceName)) +/// .WithMetrics(m => m.AddMeter(RunaxHttpTelemetry.MeterName)); +/// +/// +/// Attribute names follow the OpenTelemetry HTTP client semantic conventions, so an existing +/// dashboard or alert built for HttpClient keeps working when a call starts going through a +/// Runax.Http client — the point of a convention being that you do not have to re-learn it per +/// library. The transport is the one addition, under a runax. prefix because inventing an +/// unprefixed attribute in someone else's namespace is how conventions rot. +/// +/// +public static class RunaxHttpTelemetry +{ + /// The name to add to a tracer. + public const string ActivitySourceName = "Runax.Http"; + + /// The name to add to a meter provider. + public const string MeterName = "Runax.Http"; + + /// + /// The request duration histogram, named and in the unit the HTTP semantic conventions + /// prescribe. + /// + /// + /// Seconds, not milliseconds. The convention says seconds, and a histogram whose unit differs + /// from every other HTTP duration in the same backend cannot be compared with them — which is + /// most of what you want a duration for. + /// + public const string RequestDurationInstrumentName = "http.client.request.duration"; + + internal static readonly ActivitySource ActivitySource = new(ActivitySourceName, ThisVersion); + + internal static readonly Meter Meter = new(MeterName, ThisVersion); + + internal static readonly Histogram RequestDuration = Meter.CreateHistogram( + RequestDurationInstrumentName, + unit: "s", + description: "Duration of an outbound HTTP request attempt."); + + private static string ThisVersion => + typeof(RunaxHttpTelemetry).Assembly.GetName().Version?.ToString() ?? "0.0.0"; +} diff --git a/src/Runax.Http/Pipeline/TelemetryMiddleware.cs b/src/Runax.Http/Pipeline/TelemetryMiddleware.cs new file mode 100644 index 0000000..92d865e --- /dev/null +++ b/src/Runax.Http/Pipeline/TelemetryMiddleware.cs @@ -0,0 +1,299 @@ +using System.Diagnostics; +using Runax.Http.Transports; + +namespace Runax.Http.Pipeline; + +/// +/// Records a span and a duration measurement for each request attempt, under the OpenTelemetry +/// HTTP client semantic conventions. +/// +/// +/// +/// One span per attempt, not per call. That is what the conventions describe — a resend +/// carries http.request.resend_count — and it is the only shape that can answer the question +/// retries create: whether a call was slow because the server was slow, or because the first two +/// tries failed and the backoff was waited out. A single span covering the lot reports the total and +/// hides which it was. +/// +/// +/// Outermost stage, before correlation. Two reasons, both about the stage below it: the span has to +/// enclose the time the other stages spend — an auth stage fetching a token off a cold cache is part +/// of how long the call took — and the correlation stage derives its id from +/// Activity.Current, which means the span has to exist before correlation +/// runs for the traceparent the server receives to name the span the client actually +/// recorded. Start the span later and the server's parent id points at nothing. +/// +/// +/// Nothing is recorded when nothing is listening: returns with no registered listener, and the histogram +/// is skipped when the meter is unsubscribed. An unobserved client pays for a null check. +/// +/// +public sealed class TelemetryMiddleware : IHttpMiddleware +{ + private readonly TelemetryOptions _options; + private readonly string? _clientName; + + /// Creates the stage. + /// What to record. Defaults to tracing and metrics both on. + /// + /// The contract this stage belongs to, tagged as runax.http.client. Supplied by + /// UseTelemetry(), which knows the contract type; omits the tag. + /// + public TelemetryMiddleware(TelemetryOptions? options = null, string? clientName = null) + { + _options = options ?? new TelemetryOptions(); + _clientName = clientName; + } + + /// + public int Order => HttpMiddlewareOrder.Telemetry; + + /// + public async Task InvokeAsync( + RequestContext context, + RequestPipelineStep continuation, + CancellationToken cancellationToken) + { + ArgumentNullException.ThrowIfNull(context); + ArgumentNullException.ThrowIfNull(continuation); + + var method = context.Method.ToString().ToUpperInvariant(); + var template = Template(context); + + using var activity = _options.Tracing + ? RunaxHttpTelemetry.ActivitySource.StartActivity( + SpanName(method, template), + ActivityKind.Client) + : null; + + // Hoisted out of the branches below so the measurement and the span agree on what they are + // describing even when one of the two is disabled. + var measure = _options.Metrics && RunaxHttpTelemetry.RequestDuration.Enabled; + + if (activity is not null) + Describe(activity, context, method, template); + + var started = Stopwatch.GetTimestamp(); + + try + { + var response = await continuation(context, cancellationToken).ConfigureAwait(false); + + Complete(activity, context, response.StatusCode); + + if (measure) + Record(context, method, template, started, response.StatusCode, errorType: null); + + return response; + } + catch (Exception exception) + { + // A cancelled call is still a measurement — a p99 that drops because slow calls are + // being cancelled rather than completing is a graph that lies by omission. It is + // labelled by its exception type like any other failure, which keeps it separable. + var errorType = exception.GetType().FullName; + + Fail(activity, context, exception, errorType); + + if (measure) + Record(context, method, template, started, statusCode: null, errorType); + + throw; + } + } + + /// + /// The path template, which is the low-cardinality name for the endpoint. + /// + /// + /// Taken from the contract rather than parsed back out of the URL, because the URL has the + /// placeholders already filled in and no reliable way to tell an id from a path segment. + /// Relative to the base address: a base address with a path prefix of its own does not appear + /// here, which keeps the value stable when the same contract is pointed at a different host. + /// + private static string? Template(RequestContext context) + { + var template = context.ClientRequest.Template; + + return string.IsNullOrEmpty(template) ? null : template; + } + + /// + /// GET /things/{id}, or just GET with no template. + /// + /// + /// The conventions are emphatic that a span name must be low cardinality, which rules out the + /// URL: a name containing an id produces one distinct operation per id, and a backend that + /// groups by name ends up with a million groups of one. + /// + private static string SpanName(string method, string? template) + => template is null ? method : $"{method} {template}"; + + private void Describe(Activity activity, RequestContext context, string method, string? template) + { + var uri = context.RequestUri; + + activity.SetTag("http.request.method", method); + activity.SetTag("url.full", Describe(uri, _options.RecordQueryString)); + + if (uri.IsAbsoluteUri) + { + activity.SetTag("url.scheme", uri.Scheme); + activity.SetTag("server.address", uri.Host); + + // Only when it is not the default for the scheme. Tagging 443 on every https request + // is a column of constants in every backend that stores it. + if (!uri.IsDefaultPort) + activity.SetTag("server.port", uri.Port); + } + + if (template is not null) + activity.SetTag("url.template", template); + + // Absent rather than zero on a first attempt, which is how the convention distinguishes + // "this is the original request" from "this is a resend that happens to be numbered 0". + if (context.Attempt > 1) + activity.SetTag("http.request.resend_count", context.Attempt - 1); + + activity.SetTag("runax.http.transport", context.Transport.Name); + + if (_options.RecordClientName && _clientName is not null) + activity.SetTag("runax.http.client", _clientName); + } + + private static void Complete(Activity? activity, RequestContext context, int statusCode) + { + if (activity is null) + return; + + activity.SetTag("http.response.status_code", statusCode); + Correlate(activity, context); + + // 4xx and 5xx are both errors for a client span. The server may consider a 404 a perfectly + // good answer; the caller that asked for the thing did not get it. + if (statusCode >= 400) + { + activity.SetTag("error.type", statusCode.ToString(System.Globalization.CultureInfo.InvariantCulture)); + activity.SetStatus(ActivityStatusCode.Error); + } + else + { + activity.SetStatus(ActivityStatusCode.Ok); + } + } + + /// + /// Tags the correlation id, if a correlation stage produced one. + /// + /// + /// Set on the way out rather than on the way in, because the stage that assigns the id runs + /// inside this one and there is nothing to read until it has. Usually the trace id in hex, in + /// which case the tag is redundant with the span's own identity — but a client with + /// PropagateTraceContext off, or its own GenerateId, sends something else + /// entirely, and then this is the only thing joining the span to the logs and to whatever the + /// server recorded under that header. + /// + private static void Correlate(Activity activity, RequestContext context) + { + if (context.CorrelationId is { Length: > 0 } id) + activity.SetTag("runax.http.correlation_id", id); + } + + private static void Fail( + Activity? activity, + RequestContext context, + Exception exception, + string? errorType) + { + if (activity is null) + return; + + activity.SetTag("error.type", errorType); + Correlate(activity, context); + activity.SetStatus(ActivityStatusCode.Error, exception.Message); + + // A transport failure may still have reached the server and come back with a status; an + // HttpApiException certainly did. Recording it keeps a failed span comparable with a + // successful one. + if (exception is HttpApiException api) + activity.SetTag("http.response.status_code", api.StatusCode); + } + + private void Record( + RequestContext context, + string method, + string? template, + long started, + int? statusCode, + string? errorType) + { + var uri = context.RequestUri; + + // TagList rather than an array: it keeps up to eight tags inline, so a measurement on a hot + // path does not allocate to describe itself. + var tags = new TagList + { + { "http.request.method", method }, + { "runax.http.transport", context.Transport.Name } + }; + + if (uri.IsAbsoluteUri) + { + tags.Add("url.scheme", uri.Scheme); + tags.Add("server.address", uri.Host); + + if (!uri.IsDefaultPort) + tags.Add("server.port", uri.Port); + } + + // url.full is deliberately absent. Every distinct id in a path would become its own time + // series, and a metric backend charges for those by the million. + if (template is not null) + tags.Add("url.template", template); + + if (statusCode is { } status) + { + tags.Add("http.response.status_code", status); + + if (status >= 400) + tags.Add("error.type", status.ToString(System.Globalization.CultureInfo.InvariantCulture)); + } + + if (errorType is not null) + tags.Add("error.type", errorType); + + if (_options.RecordClientName && _clientName is not null) + tags.Add("runax.http.client", _clientName); + + // Seconds, per the convention's unit. TotalSeconds off a Stopwatch timestamp, so the value + // keeps sub-millisecond resolution rather than being rounded through an integer. + RunaxHttpTelemetry.RequestDuration.Record( + Stopwatch.GetElapsedTime(started).TotalSeconds, + tags); + } + + /// + /// The URL as an attribute value, with any credentials in it removed. + /// + /// + /// Userinfo is stripped unconditionally — the conventions require it, and a password in a + /// url.full attribute is a password in a tracing backend's search index. The query string + /// is included by default, matching what the logging stage does with the same information; + /// turns it off for an API that puts a key + /// there. + /// + private static string Describe(Uri uri, bool includeQuery) + { + if (!uri.IsAbsoluteUri) + return uri.ToString(); + + var components = UriComponents.Scheme | UriComponents.Host | UriComponents.Port + | UriComponents.Path; + + if (includeQuery) + components |= UriComponents.Query; + + return uri.GetComponents(components, UriFormat.UriEscaped); + } +} diff --git a/src/Runax.Http/Pipeline/TelemetryOptions.cs b/src/Runax.Http/Pipeline/TelemetryOptions.cs new file mode 100644 index 0000000..d41e486 --- /dev/null +++ b/src/Runax.Http/Pipeline/TelemetryOptions.cs @@ -0,0 +1,32 @@ +namespace Runax.Http.Pipeline; + +/// What the telemetry stage records. +public sealed class TelemetryOptions +{ + /// Whether to start an per attempt. + public bool Tracing { get; set; } = true; + + /// Whether to record the request duration histogram. + public bool Metrics { get; set; } = true; + + /// + /// Whether url.full carries the query string. + /// + /// + /// On, matching what the logging stage does with the same information, so one library does not + /// take two positions on it. Turn it off for an API that puts a key or a token in the query — + /// a trace is stored and searchable for as long as your retention allows, which makes it a + /// worse place for a secret than a log line. + /// + public bool RecordQueryString { get; set; } = true; + + /// + /// Whether to tag the contract that issued the request. + /// + /// + /// On, under runax.http.client. Low cardinality by construction — there are as many + /// values as you have client interfaces — and it is the tag that answers "which of my clients + /// is slow", which `server.address` cannot when several clients share a host. + /// + public bool RecordClientName { get; set; } = true; +} diff --git a/src/Runax.Http/README.md b/src/Runax.Http/README.md index 4a0d6cb..039ee3b 100644 --- a/src/Runax.Http/README.md +++ b/src/Runax.Http/README.md @@ -261,12 +261,13 @@ every declaration — an operator needs a client that provably stops retrying du The safety defaults hold: a streamed body is still never retried, and a `POST` needs `AllowNonIdempotent = true` (a `[Retry]` on one without it is a build warning, since it would otherwise do nothing). -## Logging, auth and correlation +## Logging, auth, correlation and telemetry Middleware that works on every transport, each stage independently opt-in: ```csharp services.AddRunaxClient() + .UseTelemetry() // a span and a duration per attempt .UseCorrelation() // stable id per call, W3C traceparent .UseLogging() // a line per attempt .UseBearerToken(() => tokenCache.Current); // re-read on every attempt @@ -281,7 +282,9 @@ reach a retry. Anything that must *not* change between attempts — a correlatio `RequestContext`, which is created once per call. Neither position serves both on its own. Ordering is explicit, from `IHttpMiddleware.Order` rather than from where `Use…()` sits in the -chain: correlation outermost, then logging, then authentication closest to the wire. +chain: telemetry outermost, then correlation, then logging, then authentication closest to the wire. +Telemetry has to be outside correlation rather than beside it, because the correlation id is derived +from the span. The logging stage **never logs bodies**, and header values are off unless named. `Authorization`, `Proxy-Authorization`, `Cookie` and `Set-Cookie` are redacted to `***` even when named, and that @@ -289,6 +292,13 @@ cannot be turned off — an option that can print a bearer token into a log aggr eventually be used. Full reasoning in [docs/pipeline.md](https://github.com/runax-software/runax-http/blob/main/docs/pipeline.md). +`UseTelemetry()` records a span and an `http.client.request.duration` histogram under the +OpenTelemetry HTTP client semantic conventions, tagged with the transport that answered — one span +per *attempt*, so a retried call is distinguishable from a slow one. It emits to `ActivitySource` +and `Meter` in the base class library, so the package takes no dependency on OpenTelemetry and stays +inert until a collector subscribes to `RunaxHttpTelemetry.ActivitySourceName`. See +[docs/observability.md](https://github.com/runax-software/runax-http/blob/main/docs/observability.md). + ## What the generator catches Twenty-three diagnostics: a `{placeholder}` with no parameter, two `[Body]` parameters, an diff --git a/tests/Runax.Http.AotSmoke/Program.cs b/tests/Runax.Http.AotSmoke/Program.cs index 0094ccf..f9f5262 100644 --- a/tests/Runax.Http.AotSmoke/Program.cs +++ b/tests/Runax.Http.AotSmoke/Program.cs @@ -62,6 +62,10 @@ services.AddRunaxClient() .WithBaseAddress("https://api.example.com/v1") + // Telemetry included because the stage is the one that touches ActivitySource and Meter, and + // "AOT-safe" is a claim only a publish can check — neither type needs reflection, but a trim + // warning here would be invisible in a JIT build. + .UseTelemetry() .UseCorrelation() .UseBearerToken(() => "aot-token") .Use(new AotRecordingMiddleware(pipelineLog)); diff --git a/tests/Runax.Http.Tests/Fakes/TelemetryRecorder.cs b/tests/Runax.Http.Tests/Fakes/TelemetryRecorder.cs new file mode 100644 index 0000000..071fa70 --- /dev/null +++ b/tests/Runax.Http.Tests/Fakes/TelemetryRecorder.cs @@ -0,0 +1,121 @@ +using System.Diagnostics; +using System.Diagnostics.Metrics; +using Runax.Http.Pipeline; + +namespace Runax.Http.Tests.Fakes; + +/// +/// Subscribes to the library's and and keeps what +/// they emit. +/// +/// +/// +/// The real listener APIs rather than a seam of our own. The whole claim being tested is "an +/// OpenTelemetry setup will see this", and OpenTelemetry sees it through +/// and — a fake the middleware reported +/// to instead would prove the middleware talks to the fake. +/// +/// +/// Filtered to this source by name, so a test is not handed activities started by something else +/// in the process. +/// +/// +internal sealed class TelemetryRecorder : IDisposable +{ + private readonly ActivityListener _activities; + private readonly MeterListener _meters; + private readonly List _stopped = []; + private readonly List _measurements = []; + private readonly object _gate = new(); + + internal TelemetryRecorder() + { + _activities = new ActivityListener + { + ShouldListenTo = source => source.Name == RunaxHttpTelemetry.ActivitySourceName, + + // AllDataAndRecorded, not PropagationData: a sampler that declines leaves StartActivity + // returning an activity with no tags, and every attribute assertion would pass + // vacuously against it. + Sample = (ref ActivityCreationOptions _) + => ActivitySamplingResult.AllDataAndRecorded, + + ActivityStopped = activity => + { + lock (_gate) + _stopped.Add(activity); + } + }; + + ActivitySource.AddActivityListener(_activities); + + _meters = new MeterListener + { + InstrumentPublished = (instrument, listener) => + { + if (instrument.Meter.Name == RunaxHttpTelemetry.MeterName) + listener.EnableMeasurementEvents(instrument); + } + }; + + _meters.SetMeasurementEventCallback((instrument, value, tags, _) => + { + var copied = new Dictionary(StringComparer.Ordinal); + + foreach (var tag in tags) + copied[tag.Key] = tag.Value; + + lock (_gate) + _measurements.Add(new Measurement(instrument.Name, instrument.Unit, value, copied)); + }); + + _meters.Start(); + } + + /// Spans that have finished, oldest first. + internal IReadOnlyList Activities + { + get { lock (_gate) return [.. _stopped]; } + } + + /// The single span recorded, failing the test if there is not exactly one. + internal Activity Activity + { + get + { + var all = Activities; + all.Count.ShouldBe(1); + return all[0]; + } + } + + internal IReadOnlyList Measurements + { + get { lock (_gate) return [.. _measurements]; } + } + + internal Measurement Duration + { + get + { + var all = Measurements + .Where(m => m.Instrument == RunaxHttpTelemetry.RequestDurationInstrumentName) + .ToList(); + + all.Count.ShouldBe(1); + return all[0]; + } + } + + public void Dispose() + { + _activities.Dispose(); + _meters.Dispose(); + } + + internal sealed record Measurement( + string Instrument, + string? Unit, + double Value, + IReadOnlyDictionary Tags); +} diff --git a/tests/Runax.Http.Tests/TelemetryTests.cs b/tests/Runax.Http.Tests/TelemetryTests.cs new file mode 100644 index 0000000..c9f3839 --- /dev/null +++ b/tests/Runax.Http.Tests/TelemetryTests.cs @@ -0,0 +1,376 @@ +using System.Diagnostics; +using Microsoft.Extensions.DependencyInjection; +using Runax.Http.DependencyInjection; +using Runax.Http.Pipeline; +using Runax.Http.Retry; +using Runax.Http.Tests.Contracts; +using Runax.Http.Tests.Fakes; +using Runax.Http.Transports; + +namespace Runax.Http.Tests; + +/// +/// The spans and measurements the telemetry stage emits. +/// +/// +/// +/// Asserted against the attribute names from the OpenTelemetry HTTP client semantic conventions +/// rather than names of our own choosing, because conformance to those names is the entire value of +/// the feature: a dashboard built for HttpClient keeps working, and the attributes a backend +/// knows how to group by are the ones it is told to expect. A near-miss — http.method for +/// http.request.method — is indistinguishable from no instrumentation to anything consuming +/// it, and would pass a test that only checked "a tag is present". +/// +/// +/// These run serially against the rest of the suite, +/// because is process-wide: a listener added here +/// sees spans from a client another test built, and the counts below are exact. +/// +/// +[Collection(nameof(TelemetryTests))] +[CollectionDefinition(nameof(TelemetryTests), DisableParallelization = true)] +public class TelemetryTests +{ + private static (IRepositoryClient Client, RecordingTransport Transport) Build( + Func? respond = null, + Action>? configure = null, + Action? telemetry = null) + { + var transport = new RecordingTransport( + respond: respond ?? (_ => Responses.Json("""{"name":"n","stars":1}"""))); + + var services = new ServiceCollection(); + + var shared = services.AddRunaxHttp(); + shared.UseSystemTextJson(); + shared.AddTransport(transport); + shared.UseDefaultTransport(transport.Name); + + // One telemetry stage, configured here rather than by the caller adding a second one: + // two stages would each record a span and every exact count below would be off by one. + var client = services.AddRunaxClient(); + client.UseTelemetry(telemetry); + configure?.Invoke(client); + + return (services.BuildServiceProvider().GetRequiredService(), transport); + } + + private static object? Tag(Activity activity, string name) => activity.GetTagItem(name); + + /// The list endpoint needs an array; the default stub answers with an object. + private static TransportResponse Issues(TransportRequest _) => Responses.Json("[]"); + + [Fact] + public async Task A_span_is_named_by_method_and_template_not_by_url() + { + // The cardinality rule. "GET /repos/{owner}/{name}" groups every call to the endpoint; + // "GET /repos/runax/http" is one operation per repository, and a backend grouping by name + // ends up with a million groups of one. + using var recorder = new TelemetryRecorder(); + var (client, _) = Build(); + + await client.GetAsync("runax", "http"); + + recorder.Activity.DisplayName.ShouldBe("GET /repos/{owner}/{name}"); + recorder.Activity.Kind.ShouldBe(ActivityKind.Client); + } + + [Fact] + public async Task The_conventional_attributes_are_spelled_the_conventional_way() + { + using var recorder = new TelemetryRecorder(); + var (client, _) = Build(); + + await client.GetAsync("runax", "http"); + + var activity = recorder.Activity; + + Tag(activity, "http.request.method").ShouldBe("GET"); + Tag(activity, "url.full").ShouldBe("https://api.example.com/v3/repos/runax/http"); + Tag(activity, "url.scheme").ShouldBe("https"); + Tag(activity, "url.template").ShouldBe("/repos/{owner}/{name}"); + Tag(activity, "server.address").ShouldBe("api.example.com"); + Tag(activity, "http.response.status_code").ShouldBe(200); + activity.Status.ShouldBe(ActivityStatusCode.Ok); + } + + [Fact] + public async Task A_default_port_is_not_tagged() + { + // server.port on every https request is a column of 443s in whatever stores it. + using var recorder = new TelemetryRecorder(); + var (client, _) = Build(); + + await client.GetAsync("runax", "http"); + + Tag(recorder.Activity, "server.port").ShouldBeNull(); + } + + [Fact] + public async Task The_active_transport_is_a_tag() + { + // The roadmap item's specific ask, and the question the tag exists to answer: whether a + // latency change followed a transport swap. Above the IHttpTransport boundary, so it is the + // same tag whichever transport answers. + using var recorder = new TelemetryRecorder(); + var (client, transport) = Build(); + + await client.GetAsync("runax", "http"); + + Tag(recorder.Activity, "runax.http.transport").ShouldBe(transport.Name); + recorder.Duration.Tags["runax.http.transport"].ShouldBe(transport.Name); + } + + [Fact] + public async Task The_contract_is_a_tag() + { + using var recorder = new TelemetryRecorder(); + var (client, _) = Build(); + + await client.GetAsync("runax", "http"); + + Tag(recorder.Activity, "runax.http.client").ShouldBe(nameof(IRepositoryClient)); + } + + [Fact] + public async Task A_four_hundred_is_an_error_on_a_client_span() + { + // The server may consider a 404 a fine answer. The caller that asked for the thing did not + // get it, and the convention makes 4xx and 5xx errors for client spans on that basis. + using var recorder = new TelemetryRecorder(); + var (client, _) = Build(_ => Responses.Error(404)); + + await Should.ThrowAsync(() => client.GetAsync("runax", "nope")); + + var activity = recorder.Activity; + + activity.Status.ShouldBe(ActivityStatusCode.Error); + Tag(activity, "error.type").ShouldBe("404"); + Tag(activity, "http.response.status_code").ShouldBe(404); + } + + [Fact] + public async Task A_transport_failure_is_labelled_by_exception_type() + { + using var recorder = new TelemetryRecorder(); + + var (client, _) = Build(_ => throw new InvalidOperationException("socket gone")); + + await Should.ThrowAsync(() => client.GetAsync("runax", "http")); + + var activity = recorder.Activity; + + activity.Status.ShouldBe(ActivityStatusCode.Error); + Tag(activity, "error.type").ShouldNotBeNull(); + Tag(activity, "http.response.status_code").ShouldBeNull(); + } + + [Fact] + public async Task Each_attempt_gets_its_own_span_and_a_resend_is_numbered() + { + // One span per attempt is what the convention describes, and the only shape that separates + // "the server was slow" from "the first two tries failed and we waited out the backoff". + // A single span covering the lot reports the total and hides which it was. + using var recorder = new TelemetryRecorder(); + + var call = 0; + + var (client, _) = Build( + _ => call++ == 0 ? Responses.Error(503) : Responses.Json("""{"name":"n","stars":1}"""), + c => c.WithRetry(options => + { + options.MaxAttempts = 2; + options.Delay = TimeSpan.Zero; + options.UseJitter = false; + })); + + await client.GetAsync("runax", "http"); + + var activities = recorder.Activities; + + activities.Count.ShouldBe(2); + + // Absent on the first, not zero: that is how the convention distinguishes an original + // request from a resend that happens to be numbered 0. + Tag(activities[0], "http.request.resend_count").ShouldBeNull(); + Tag(activities[1], "http.request.resend_count").ShouldBe(1); + + Tag(activities[0], "http.response.status_code").ShouldBe(503); + Tag(activities[1], "http.response.status_code").ShouldBe(200); + + recorder.Measurements.Count.ShouldBe(2); + } + + [Fact] + public async Task The_duration_is_recorded_in_seconds_under_the_conventional_name() + { + // Seconds because the convention says seconds. A histogram in milliseconds cannot be + // compared with every other HTTP duration in the same backend, which is most of what a + // duration is for. + using var recorder = new TelemetryRecorder(); + var (client, _) = Build(); + + await client.GetAsync("runax", "http"); + + var duration = recorder.Duration; + + duration.Instrument.ShouldBe("http.client.request.duration"); + duration.Unit.ShouldBe("s"); + duration.Value.ShouldBeGreaterThan(0); + duration.Value.ShouldBeLessThan(60); + } + + [Fact] + public async Task The_measurement_carries_no_high_cardinality_tag() + { + // url.full on a metric is one time series per id in the path, and a metric backend bills + // for those by the million. The span is where the full URL belongs; the histogram is not. + using var recorder = new TelemetryRecorder(); + var (client, _) = Build(Issues); + + await client.ListIssuesAsync("runax", "http", "open", 2); + + var tags = recorder.Duration.Tags; + + // Keys.ShouldNotContain rather than ShouldNotContainKey: Shouldly only resolves the + // latter against IReadOnlyDictionary from net9.0 onwards, and this suite builds for net8.0. + tags.Keys.ShouldNotContain("url.full"); + tags.Keys.ShouldNotContain("runax.http.correlation_id"); + tags["url.template"].ShouldBe("/repos/{owner}/{name}/issues"); + tags["http.request.method"].ShouldBe("GET"); + tags["http.response.status_code"].ShouldBe(200); + } + + [Fact] + public async Task A_failed_call_is_still_measured() + { + // A p99 that improves because slow calls started failing rather than completing is a graph + // that lies by omission. + using var recorder = new TelemetryRecorder(); + var (client, _) = Build(_ => Responses.Error(503)); + + await Should.ThrowAsync(() => client.GetAsync("runax", "http")); + + recorder.Duration.Tags["error.type"].ShouldBe("503"); + } + + [Fact] + public async Task The_query_string_can_be_kept_out_of_the_span() + { + // A trace is stored and searchable for as long as retention allows, which makes it a worse + // place for an API key than a log line. Included by default to match what the logging stage + // does with the same information; off is one option away. + using var recorder = new TelemetryRecorder(); + + var (client, _) = Build(Issues, telemetry: o => o.RecordQueryString = false); + + await client.ListIssuesAsync("runax", "http", "open", 2); + + Tag(recorder.Activity, "url.full") + .ShouldBe("https://api.example.com/v3/repos/runax/http/issues"); + } + + [Fact] + public async Task The_query_string_is_recorded_by_default() + { + using var recorder = new TelemetryRecorder(); + + var (client, _) = Build(Issues); + + await client.ListIssuesAsync("runax", "http", "open", 2); + + var url = (string?)Tag(recorder.Activity, "url.full"); + + url.ShouldNotBeNull(); + url.ShouldContain("state=open"); + } + + [Fact] + public async Task Credentials_in_the_url_never_reach_a_span() + { + // Unconditional, not an option. The convention requires it, and a password in a url.full + // attribute is a password in a tracing backend's search index. + using var recorder = new TelemetryRecorder(); + + var (client, _) = Build(configure: c => c.Configure(options => + options.BaseAddress = new Uri("https://user:hunter2@api.example.com/v3/"))); + + await client.GetAsync("runax", "http"); + + var url = (string?)Tag(recorder.Activity, "url.full"); + + url.ShouldNotBeNull(); + url.ShouldNotContain("hunter2"); + url.ShouldStartWith("https://api.example.com/"); + } + + [Fact] + public async Task The_span_exists_before_correlation_runs_so_traceparent_names_it() + { + // The ordering constraint, and the reason the telemetry stage sits outside correlation + // rather than beside it. Correlation derives its id from Activity.Current; start the span + // after it and the traceparent reaching the server names a span that does not exist, which + // breaks the join between the client trace and the server's — silently, since both halves + // look fine on their own. + using var recorder = new TelemetryRecorder(); + + var (client, transport) = Build(configure: c => c.UseCorrelation()); + + await client.GetAsync("runax", "http"); + + var traceparent = transport.Last.Headers + .First(h => string.Equals(h.Key, "traceparent", StringComparison.OrdinalIgnoreCase)) + .Value; + + traceparent.ShouldContain(recorder.Activity.TraceId.ToHexString()); + } + + [Fact] + public async Task The_correlation_id_is_tagged_once_the_stage_below_has_assigned_it() + { + using var recorder = new TelemetryRecorder(); + + var (client, _) = Build(configure: c => c.UseCorrelation(o => o.PropagateTraceContext = false)); + + await client.GetAsync("runax", "http"); + + Tag(recorder.Activity, "runax.http.correlation_id").ShouldNotBeNull(); + } + + [Fact] + public async Task Tracing_and_metrics_are_separately_disableable() + { + using var recorder = new TelemetryRecorder(); + + var (client, _) = Build(telemetry: o => o.Tracing = false); + + await client.GetAsync("runax", "http"); + + recorder.Activities.ShouldBeEmpty(); + recorder.Duration.Value.ShouldBeGreaterThan(0); + } + + [Fact] + public async Task Metrics_can_be_off_with_tracing_left_on() + { + using var recorder = new TelemetryRecorder(); + + var (client, _) = Build(telemetry: o => o.Metrics = false); + + await client.GetAsync("runax", "http"); + + recorder.Measurements.ShouldBeEmpty(); + recorder.Activity.DisplayName.ShouldBe("GET /repos/{owner}/{name}"); + } + + [Fact] + public async Task A_client_with_nothing_listening_still_works() + { + // No recorder in scope. StartActivity returns null with no listener and the histogram is + // unsubscribed, so the stage has to do nothing without tripping over its own nulls — this + // is the path almost every consumer is on. + var (client, _) = Build(); + + (await client.GetAsync("runax", "http")).Name.ShouldBe("n"); + } +}