feat(telemetry): correlate logs with an x-request-id span - #1208
Open
bilhokista wants to merge 2 commits into
Open
feat(telemetry): correlate logs with an x-request-id span#1208bilhokista wants to merge 2 commits into
bilhokista wants to merge 2 commits into
Conversation
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Closes #1127.
Requirement 1 was already done
telemetry.rsalready configurestracing-subscriberwith.json()— in fact JSON is the default, withprettyandcompactas opt-ins viaLOG_FORMAT. I did not touch it.Requirement 2 was the whole gap
There was no request-id handling anywhere in the backend. Every log line stood alone, so two concurrent requests interleaved in the output with no way to tell which line belonged to which — the specific thing that makes an aggregator useful.
request_id_middlewarenow wraps each request in a span carryingrequest_id,methodandpath. Because it is a span rather than a field on individual events, every nestedinfo!/warn!/error!inside a handler inherits it without naming it, so existing log statements gain correlation with no edits.The id is also written back onto the request (so anything downstream that forwards headers continues the same trace instead of starting a new one) and echoed on the response, so a client can quote it in a bug report.
Two decisions worth review
An inbound id is reused, not overwritten. That is the point of the header: it is what lets one trace be followed across the proxy, this service, and whatever it calls. Generating a fresh id unconditionally would produce ids that correlate with nothing upstream.
But an inbound id is untrusted input, so it is validated. This is the part I would most like checked. The id is interpolated into log output, so accepting arbitrary header content would let a caller embed a newline and write something that reads like a separate log entry — log forging, in a system whose whole purpose here is to be indexed and trusted by Cloudwatch or Datadog. Accepted values are ASCII alphanumerics,
-and_, capped at 128 characters so a hostile client cannot bloat the logs one request at a time.A rejected value is replaced with a generated id rather than failing the request — a malformed header is not a reason to reject otherwise valid traffic.
Layer placement
The middleware is registered outermost of the existing layers, so a request rejected by rate limiting or the geo guard is still logged under a correlation id. Those are exactly the requests worth tracing, and placing it inside those layers would have left them uncorrelated.
Tests
Seven cases in
telemetry.rs:-/_\n,\r, tab, space, NULcafé,id/with/slashes,id;drop)Honest note on verification: I could not run
cargo testfor the crate — it needs the full dependency graph and sqlx's database or offline metadata. I lifted the two pure functions and all seven tests into a standalone file, stubbedUuid::v4, and compiled withrustc --test --edition 2021: compiles clean, all 7 pass.The middleware itself and the router wiring need CI. I have not been able to observe the span actually attaching to nested events at runtime, so that is the specific thing worth a reviewer's eye.
🤖 Generated with Claude Code
https://claude.ai/code/session_01CrfEY1tvXrbeMDAUzxfuk7