Skip to main content
← Back to list
01Issue
FeatureShippedSwamp CLIPublic
Assigneeshammz

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:

  1. No request spans. Over 7 days (4.8M spans), every span from service.name = swamp-serve has kind internal. There are no HTTP server spans, so /auth/info, /auth/device and /auth/device/token never appear.
  2. No spans for the work in handleDeviceToken. Nothing covers the upstream pollForToken/getUserInfo, the sync gate wait, mintServerToken (vault put, definition save, token resource write, datastore push, catalog read-back) or storeAccessToken. No span name mentions login, auth, device or mint. The only token-related spans are swamp.access.token.list and swamp.access.token.rotate.
  3. Untraced time inside gcs-datastore push. The push is a root span (parent_span_id null), 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, and storeAccessToken.
  • Spans (or span events) inside gcs-datastore push for 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

  1. swamp auth server-login --server https://ops.swamp-club.com, then approve the code in the browser right away.
  2. 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 unparented gcs-datastore push with a large gap between its child spans.

Environment

  • Server: ops.swamp-club.com in OAuth mode, sending traces to Axiom swamp-serve-traces (service.version dev, OpenTelemetry SDK 1.30.1)
  • Seen on 2026-09-23
  • Related: #2408
02Bog Flow
✓OPEN✓TRIAGED✓IN PROGRESS✓SHIPPED+ 1 MOREASSIGNED+ 5 MOREREVIEW+ 11 MOREPR_MERGED+ 2 MORESESSION_SUMMARIZED

Shipped

9/28/2026, 8:06:57 PM

Click a lifecycle step above to view its details.

03Sludge Pulse
hammz assigned hammz9/28/2026, 7:10:57 PM

Sign in to post a ripple.