diff --git a/docs/configuration.md b/docs/configuration.md index 118e558..57b7a49 100644 --- a/docs/configuration.md +++ b/docs/configuration.md @@ -527,7 +527,8 @@ Cache tiles in a GCS bucket. `[tracing]` configures OpenTelemetry trace export over OTLP. It is off unless the section says otherwise, and it is independent of `[observer]`: metrics and -traces are switched on separately. +traces are switched on separately. With both on, the duration histograms carry +[trace exemplars](./tracing.md#trace-exemplars). ```toml [tracing] diff --git a/docs/http-endpoints.md b/docs/http-endpoints.md index 4f7a7c6..4ac3565 100644 --- a/docs/http-endpoints.md +++ b/docs/http-endpoints.md @@ -25,7 +25,7 @@ it, apart from `/metrics`. | `/collections/{collectionId}/tiles/{tileMatrixSetId}/{tileMatrix}/{tileRow}/{tileCol}` | A vector tile | | `/tileMatrixSets` | The [tiling schemes](./tile-matrix-sets.md) served | | `/tileMatrixSets/{tileMatrixSetId}` | One scheme's definition | -| `/metrics` | Prometheus metrics, when a Prometheus observer is configured. Cache metrics are listed under [Layered cache](./layered-cache.md#metrics). | +| `/metrics` | Prometheus metrics, when a Prometheus observer is configured. Answers in OpenMetrics when the scraper asks for it, which is what carries [trace exemplars](./tracing.md#trace-exemplars) — and which [respells some `le` labels](./tracing.md#changed-le-labels-and-pushed-metrics) whether or not tracing is on. Cache metrics are listed under [Layered cache](./layered-cache.md#metrics). | Full documentation on [OGC API - Tiles](./ogc-api-tiles.md), including content negotiation, caching and the conformance classes declared. diff --git a/docs/layered-cache.md b/docs/layered-cache.md index edada81..9fffcf2 100644 --- a/docs/layered-cache.md +++ b/docs/layered-cache.md @@ -175,6 +175,11 @@ The pool and the chain publish their own counters: > `shigola_cache_errors_total` (and `shigola_cache_tier_errors_total` per tier). Dashboards and alerts > referring to `errors` need updating. +With [tracing](./tracing.md) enabled, `shigola_cache_duration_seconds` and +`shigola_cache_tier_duration_seconds` also carry a +[trace exemplar](./tracing.md#trace-exemplars) — so a slow bucket on the per-tier +histogram is one click from the trace of the tier read that was slow. + ### Tier latency, and why it used to look identical everywhere `shigola_cache_tier_duration_seconds` buckets at **1-2-5 per decade from 100µs to 5 seconds**, and @@ -196,6 +201,13 @@ round number, that was this. identity, so `le` series from before the change do not line up with the ones after. A panel spanning the upgrade shows a discontinuity, and any alert threshold tuned against the old artifact values needs re-deriving against real ones. + +The `le` *values* then changed once more, separately, when the metrics route began negotiating +OpenMetrics: a boundary rendering as a whole number is now written `le="1.0"` rather than `le="1"`. +Both of these families are affected — +[which boundaries exactly](./tracing.md#changed-le-labels-and-pushed-metrics). That switch was made +for [trace exemplars](./tracing.md#trace-exemplars), but it is not conditional on them: the metrics +route negotiates OpenMetrics whenever the observer is enabled, tracing on or off. ::: ## Operating a layered cache diff --git a/docs/logging.md b/docs/logging.md index 4da288f..8637a8c 100644 --- a/docs/logging.md +++ b/docs/logging.md @@ -74,6 +74,11 @@ Loki with the trace id off the span: Both keys are flat, so `| json` yields the labels `trace_id` and `span_id` without a prefix. +The [duration histograms](./tracing.md#trace-exemplars) carry the same two names +as Prometheus exemplars, so a trace reached from a log line and one reached from +a latency spike are the same trace. Exemplars differ in one respect: they are +attached only for sampled traces, for the reason given there. + ### What is correlated, and what is not **Correlated:** cache tier read and promotion failures, PostGIS statement diff --git a/docs/tracing.md b/docs/tracing.md index 1b4eaa4..b06e23d 100644 --- a/docs/tracing.md +++ b/docs/tracing.md @@ -12,7 +12,8 @@ it. It is **off by default** and configured in its own `[tracing]` section. Tracing runs *alongside* the [Prometheus observer](#relationship-to-metrics) rather than replacing it, and puts its trace ids on -[log records](#relationship-to-logs). +[log records](#relationship-to-logs) and on the +[duration histograms](#trace-exemplars). ## What tracing answers that metrics cannot @@ -175,15 +176,139 @@ datasource wiring for both directions, and the sampling caveat are on the ## Relationship to metrics -Tracing and metrics are configured and switched on independently: `[tracing]` -and `[observer]` have nothing to say to each other. Metrics stay the Prometheus -observer's job. Nothing in the tracing path registers a Prometheus collector or +Tracing and metrics are switched on independently — `[tracing]` and `[observer]` +are separate sections and neither implies the other. Metrics stay the Prometheus +observer's job: nothing in the tracing path registers a Prometheus collector or installs an OpenTelemetry meter provider, so a build with tracing enabled -publishes exactly the metric families it published before — which Shigola's own +publishes exactly the metric families it published before, which Shigola's own test suite asserts rather than assuming. +With both enabled, though, the two signals are joined in one direction: the +duration histograms carry the active trace as a **Prometheus exemplar**. + Use both. Metrics tell you *that* something is slow across the whole fleet; -traces tell you *where*, for one request. +traces tell you *where*, for one request. Exemplars are what get you from the +first to the second without a search. + +### Trace exemplars + +Three families carry an exemplar on every observation made inside a **sampled** +trace, so a bucket in a Grafana histogram panel shows a dot you can click: + +| Family | The exemplar names | +|:---|:---| +| `shigola_cache_duration_seconds` | the cache operation as a whole | +| `shigola_cache_tier_duration_seconds` | that tier's own read, write or purge | +| `shigola_api_duration_seconds` | the request | + +Not every duration histogram is in that table. +`shigola_mvt_provider_sql_query_seconds` is measured inside its own query span +and still carries nothing, because the provider would have to import the +Prometheus observer to attach one — and that observer is compiled out entirely +under the `noPrometheusObserver` build tag. Its latency is still readable as the +duration of the query span itself, in the trace. + +The labels are `trace_id` and `span_id` — the same names the +[log records](./logging.md#trace-correlation) carry. + +`span_id` names the operation measured rather than the request, which is the +point on the per-tier family: a slow bucket there lands on the tier read that +was slow, on the one histogram whose +[whole purpose](./layered-cache.md#tier-latency-and-why-it-used-to-look-identical-everywhere) +is telling tiers apart. + +Nothing is attached to an observation made outside a trace, or inside an +unsampled one. The observation is recorded exactly as it would have been, with +no empty label — so a panel looks the same as before, minus the dots. + +### Wiring it up in Grafana + +Three things have to be true, and each fails quietly on its own. + +**The scraper must ask for OpenMetrics.** It is the only exposition format that +encodes exemplars; the classic Prometheus text format has no syntax for them and +drops them without a word. Prometheus asks for it by default, and Shigola's +`/metrics` answers in it — so this is normally already true, and worth checking +first if the dots never appear. + +**The server must store them.** Prometheus needs +`--enable-feature=exemplar-storage`; Mimir has its own equivalent. Without it +the exemplars are scraped and discarded. + +**The Prometheus datasource needs the link.** In its *Exemplars* section, add +one with the label name `trace_id` and the Tempo datasource as its target: + +```yaml +exemplarTraceIdDestinations: + - name: trace_id + datasourceUid: +``` + +Without it the exemplars still render as dots on the panel, with nothing behind +them. + +:::warning +**An exemplar is only ever a link, so unsampled traces are deliberately left +out.** Prometheus keeps one exemplar per bucket and overwrites it with the next +observation to land there, so the stored one is almost always the most recent — +and at the default `sample_ratio = 0.01` the most recent observation is almost +never sampled. Attaching them regardless would make clicking a bucket open +nothing roughly 99 times out of 100. This is the opposite of what +[log records](./logging.md#trace-correlation) do with the same trace, and for +the opposite reason: a log line's trace id still groups that request's lines +whether or not Tempo kept the trace. +::: + +### Changed `le` labels, and pushed metrics + +**`le` label values changed.** Under OpenMetrics a boundary that renders as a +whole number is written with a trailing `.0`, and a label value is part of a +series' identity — so `le="1"` is now `le="1.0"`, which Prometheus sees as a +different series. + +This section is on the tracing page because exemplars are why the format was +switched, but **the break is not conditional on tracing**. The metrics route +negotiates OpenMetrics whenever the observer is enabled; running with +`[tracing]` disabled — the default — gets you these renamed series and no +exemplars. + +| Family | Respelled boundaries | +|:---|:---| +| `shigola_cache_duration_seconds`, `shigola_cache_tier_duration_seconds` | `1`, `5` | +| `shigola_api_duration_seconds` | `1`, `5`, `10` | +| `shigola_cache_response_size_bytes`, `shigola_cache_tier_response_size_bytes` | `1024`, `5120`, `25600`, `102400`, `256000`, `512000` | +| `shigola_api_response_size_bytes` | `512000` | +| `shigola_mvt_provider_sql_query_seconds` | `1`, `5`, `20` | + +Three things about that table are worth reading twice. `2.5` is **not** in it — +it already contains a `.` — and nor are the megabyte boundaries, which render as +`1.048576e+06` and `5.24288e+06`, nor the provider family's `.1`, which renders +as `0.1`. The **response-size** families are in it even though they carry no +exemplars: the format is negotiated once per scrape, not per family. And so is +`shigola_mvt_provider_sql_query_seconds`, for the same reason — it carries no +exemplar either, and its `le` labels move regardless. + +:::warning +**It reaches past `le`, and past Shigola's own metrics.** The respelling belongs +to the encoder, not to histograms — it writes summary `quantile` labels through +the same formatter. The Go runtime's `go_gc_duration_seconds` is a summary, so +`quantile="0"` becomes `quantile="0.0"` and `quantile="1"` becomes +`quantile="1.0"`, on a metric Shigola never touches and every Go service +publishes. A dashboard pinned to either is affected. +::: + +Anything matching an exact `le` or `quantile` — a recording rule, a panel pinned +to one bucket — needs checking against the new spelling. It was the price of +exemplars being scrapeable at all. + +**Pushed metrics take a different path, and an unverified one.** A deployment +using the observer's `push_url` never reaches the exposition format above — the +push client sends protobuf, which *does* carry exemplars. Whether they are then +stored and re-exposed is the Pushgateway's own business, and Shigola does not +test it either way. `push_url` is in any case meant for +[ephemeral jobs](./cache-seeding-and-purging.md) rather than for the serving +path this section is about, so treat everything above as describing a scraped +deployment. ## Spans