Relationships
#2417 serve: server-login can't be traced: no request spans, and gcs-datastore push is unparented with an 81s gap in child spans
Opened by hammz · 9/23/2026· Shipped 9/28/2026
Description
swamp serve doesn't emit enough spans to explain a slow swamp auth server-login. In #2408 the POST /auth/device/token poll that returns the token took 88.3 s. The only span in the serve instance's traces that covers that time is a gcs-datastore push with no parent. About 81 s of that push has no child spans at all.
There are three gaps:
- No request spans. Over 7 days (4.8M spans), every span from
service.name = swamp-servehas kindinternal. There are no HTTP server spans, so/auth/info,/auth/deviceand/auth/device/tokennever appear. - No spans for the work in
handleDeviceToken. Nothing covers the upstreampollForToken/getUserInfo, the sync gate wait,mintServerToken(vault put, definition save, token resource write, datastore push, catalog read-back) orstoreAccessToken. No span name mentions login, auth, device or mint. The only token-related spans areswamp.access.token.listandswamp.access.token.rotate. - Untraced time inside
gcs-datastore push. The push is a root span (parent_span_idnull), so nothing links it to the request that triggered it. Most of its duration has no child span.
Evidence
Trace 7378ad76a022df64f1a52d18bb93c982, the only long-running span during the #2408 login:
| Time (UTC, 2026-09-23) | What |
|---|---|
| 15:21:54.6 | Client sends the poll that returns the token (from #2408) |
| 15:21:55.056 | gcs-datastore push starts: root span, files_pushed: 8, cas_retries: 0, fast_path_hit: false |
| 15:21:55.056 – 15:22:00.63 | 552 GCS getObject reads of _index/* shards |
| 15:22:00.63 – 15:23:21.497 | ~81 s with no child spans |
| 15:23:21.497 – 15:23:22.55 | 8 gcs-datastore pushFile plus putObject/putObjectCas/putObjectConditional (~0.6 s total) |
| 15:23:22.553 | Push ends (87.5 s) |
| 15:23:22.897 | Client receives 200 (from #2408) |
This push probably accounts for almost all of the 88 s in #2408. The traces can't show whether the 81 s went to the sync gate, a lock, or CPU work on the index. They also can't confirm that this push is the one mintServerToken started, because the push has no parent span. No swamp.lock.acquire span appears in this trace, so if the push waited on a lock, that wait isn't traced on this path.
APL used for the timeline:
['swamp-serve-traces']
| where trace_id == '7378ad76a022df64f1a52d18bb93c982' and name != 'gcs-datastore push'
| summarize spans=count(), busy=sum(duration) by bin(_time, 5s)Expected
- A server span for every HTTP request, with route and status, that is the parent of all work done for that request.
- Child spans for each phase of
handleDeviceToken: upstream poll, userinfo, sync gate wait, the mint and each of its sub-steps, andstoreAccessToken. - Spans (or span events) inside
gcs-datastore pushfor each phase between reading the index and uploading files, including any wait on a lock or on the sync gate. - Trace context passed from the request handler into the datastore push, so the push is not a root span.
Steps to reproduce
swamp auth server-login --server https://ops.swamp-club.com, then approve the code in the browser right away.- In the serve instance's traces (Axiom
swamp-serve-traces), look at the login window. No span names the request or the mint. The only long span is an unparentedgcs-datastore pushwith a large gap between its child spans.
Environment
- Server: ops.swamp-club.com in OAuth mode, sending traces to Axiom
swamp-serve-traces(service.versiondev, OpenTelemetry SDK 1.30.1) - Seen on 2026-09-23
- Related: #2408
Shipped
Click a lifecycle step above to view its details.
Sign in to post a ripple.