sandbox box freezes a possibly-45-minute-old installation token, so any role run over ~15 min dies with 401

[wrenrichley]

Summary

A role's GitHub installation token is snapshotted into the sandbox box at prep time and never refreshed for the life of the run. Because the identity registry hands out cached tokens that may already be 45 minutes old, any role run longer than ~15 minutes can outlive its own credential and dies with 401 Bad credentials.

Observed on bookwright#181 (ticket 45167), twice, 2026-08-09.

The arithmetic

• A GitHub App installation token lives 60 minutes (GitHub-fixed).
• v4/identity.py:181 reuses a cached token until it is within _REFRESH_SAFETY_SECONDS of expiry:

if cached is not None and cached.expires_at - now > _REFRESH_SAFETY_SECONDS:
    return cached.token

with _REFRESH_SAFETY_SECONDS = 900 (identity.py:77). ⇒ a handed-out token may already be 45 minutes old.

• v4/sandbox_clone.py::prepare_sandbox_clone takes that role_token and freezes it into the box — inlined into the origin URL via tokenized_origin_url(), and forwarded as GH_TOKEN on the subprocess env via _default_runner.
• Nothing re-points it during the run. The docstring's "the origin re-point runs EVERY call" means every prep, not every minute of a live role.

⇒ 45 min of age + a 35 min run = 80 min against a 60 min TTL. The token expires roughly 15 minutes into the run, and every GitHub call after that 401s.

Evidence

Every Implementing run on bookwright, most recent first:

issue	duration	outcome
181	35 min	error (401 Bad credentials)
181	35 min	needs_help (ProviderAuthError)
226	9 min	clean
225	7 min	clean
225	20 min	clean
224	7 min	clean
201	16 min	clean
188	9 min	clean
53	7 min	clean
64	6 min	clean

Every clean run is ≤20 minutes. Both failures are 35. No counterexample in ten runs.

Why it presents as a mystery

The failure is indistinguishable from a broken credential, and by the time anyone investigates, the credential tests healthy — the daemon has re-minted it. I verified all of the following after the failure and all passed:

• claude -p inside the container → ok, exit 0 (rules out the Anthropic path)
• container vs host clock → 0 seconds drift (rules out JWT skew)
• all five App JWTs against GET /app → planner, reviewer, fixer, worker, orchestrator all OK
• GET /repos/jeffrichley/bookwright/installation + token mint for all five → all installed, all minting

So the diagnostic surface lies: the credential is valid, and the run still failed, because the run was using a copy that had since expired. The worker's own escalation guessed "the container's Compose-mounted secret is likely also stale on the host side" — that is wrong, and it sent me looking in the wrong place first.

Why the margin is the wrong shape

_REFRESH_SAFETY_SECONDS = 900 is generous for the daemon's own sub-second API calls — the consumer finishes in milliseconds, so 15 minutes of headroom is enormous.

It is meaningless for a subprocess that copies the token and runs for half an hour. The margin is sized against the moment of handoff rather than against the consumer's lifetime, and those are different quantities whenever the consumer is a long-lived box.

Suggested fix

Force a fresh mint for any token destined for a sandbox box — bypass the cache on the dispatch path, so the box always starts with a full 60 minutes. That bounds the failure to "role runs longer than an hour" instead of "role runs longer than fifteen minutes," and it does not couple an identity constant to worker behaviour.

Alternatives considered:

• Raise _REFRESH_SAFETY_SECONDS to exceed max role runtime — works, but makes an identity-layer constant depend on how long the slowest role happens to take, and silently re-breaks when a ticket gets bigger.
• Re-point origin mid-run — the box is isolated by design; this fights the sandbox rather than working with it.

Acceptance criteria

A test that would fail on today's code: mint a token, advance a clock past its expiry, and assert that the token handed to prepare_sandbox_clone is freshly minted rather than the cached one. Asserting only that "a token is passed" passes on the broken code — the bug is the token's age, not its presence.

Worth also asserting the property directly: for any role dispatch, token.expires_at - now >= max_expected_role_runtime.

Blast radius

Not bookwright-specific. Any project, any role, any run over ~15 minutes — and it worsens as specs grow, since longer specs mean longer Worker runs. bookwright#181 carries a 1,255-line spec, which is why it is the first ticket to hit it reliably.

[wrenrichley]

Scope correction from the filer — this is real, but it is not the explanation for bookwright#181

I filed this while investigating bookwright#181 and presented it as the cause of that ticket's failures. That was overstated, and the ticket has since failed twice more in ways this issue does not explain.

What still stands, unchanged: the arithmetic. A 60-minute installation token, _REFRESH_SAFETY_SECONDS = 900 permitting a 45-minute-old token at handoff, and prepare_sandbox_clone freezing that token into the box for the life of the run. 45 + 35 > 60. Any role run over ~15 minutes can outlive its own credential. That is a genuine defect independent of #181 and worth fixing on its own terms.

What does not stand: the claim that this explains #181. Of four attempts, exactly one surfaced the GitHub 401 this issue describes. Two surfaced ProviderAuthError from the Anthropic path — a different credential system that this token has nothing to do with — and all of them died at a suspiciously consistent 34–35 minutes.

The duration table in the original report is still accurate and still interesting, but I over-read it. Clean runs ≤20 min and failures at 35 min is consistent with token expiry; it is equally consistent with anything else that trips at a fixed wall-clock point. I had one mechanism that fit and stopped looking.

Two things I checked afterwards that a reader of this issue should know:

1. RateLimitEvent is not a signal. It appears exactly once in every worker log, including all the clean runs. I briefly treated its presence in a failing run as evidence; the positive control killed that.
2. The ProviderAuthError on the Anthropic side is a classification, not a diagnosis. providers/anthropic_sdk.py:74 pattern-matches any exception beginning "Claude Code returned an error result" and declares an auth failure, then the escalation tells the operator the Compose-mounted secret is probably stale. I verified it is not — claude -p inside the container returns ok, exit 0, and all five App JWTs authenticate. That message cost me an hour in the wrong place and deserves its own issue.

Recommended disposition: keep this open and fix it on its arithmetic. Do not close it when #181's real cause is found, and do not treat fixing it as fixing #181.

[wrenrichley]

Root cause confirmed — this is not speculative any more

bookwright#181 (ticket 45167) has now failed four worker attempts in a
perfectly alternating pattern, and the GitHub arm of it resolves to the
_REFRESH_SAFETY_SECONDS = 900 reuse window with minute-level precision.

The measurement

All times UTC, from /foreman/logs/transitions.jsonl and
/foreman/logs/worker/45167__*.log.

box prep (execute_started)	duration	outcome
14:05:50	~35 min	needs_help — Anthropic ProviderAuthError
14:43:33	~35 min	error — GitHub 401 Bad credentials
17:04:30	34m17s	needs_help — Anthropic ProviderAuthError
17:39:05	26m12s	error — GitHub 401 Bad credentials

FOREMAN_OUTCOME for both failures:

"summary":"worker raised: 401 {\"message\": \"Bad credentials\", \"documentation_url\": \"https://docs.github.com/rest\", \"status\": \"401\"}"

Note the preceding line in each log: ResultMessage(subtype=success, has_output=True). The role did all of its work. It died on a GitHub API
call at the very end.

The arithmetic

A GitHub App installation token lives 60 minutes.
IdentityRegistry.get_role_token (v4/identity.py:181) returns the cached
token whenever cached.expires_at - now > 900, so a box can be handed a
token with as little as 15 minutes of life remaining. The role holds it
as GH_TOKEN for the whole run and has no refresh path.

Second pair, worked through:

• 17:04:30 — worker box preps. The prior worker token (minted 14:43,
  expired 15:43) is long dead, so this mints fresh: valid until ~18:04:30.
• 17:38:47 — run ends in needs_help (the Anthropic arm).
• 17:39:05 — retry box preps. Cached token has 25m25s left.
  25m > 15m ⇒ reused, not re-minted.
• 18:05:17 — 401 Bad credentials.

The token expired at ~18:04:30. The failure landed at 18:05:17 — 47
seconds later.

First pair is the same shape with more slack burned: token minted 14:05:50
(expires 15:05:50), retry preps 14:43:33 with 22 min left, reused, run takes
~35 min, Failed at 15:18:22 — 12.5 minutes past expiry.

Why only #181

The failure needs run_duration > token_remaining_life. #181 is the
longest-running ticket on the board (26–35 min/attempt). Every shorter
bookwright ticket this weekend — #224, #225, #226 — finished well inside the
margin and merged clean. This is not a bookwright#181 bug; it is a
substrate bug that only long tickets are slow enough to trip.

Falsifiable prediction, which all four attempts satisfy: a first attempt
(fresh 60-min token) never 401s; only a retry launched 15–45 minutes after
the previous box prep does.

Consequence for the fix

The instrumentation this issue originally proposed (log expires_at at box
prep) is now confirmatory rather than diagnostic. The real defect is that
the safety window is measured against nothing. 900s was chosen to cover
"a little API traffic," but the token's consumer is a role subprocess whose
lifetime is 25–40 minutes — two to three times the margin. Any margin
shorter than the maximum role runtime leaves this failure reachable.

I'm not picking the replacement value here — that's an operator decision,
and there are at least two shapes (raise the margin above the role timeout,
or mint unconditionally per box prep and skip the cache for the dispatch
path). Flagging both, and that the current value cannot be correct at any
role runtime above 15 minutes.

Second, separate defect in the same logs

The Anthropic arm is its own bug and should not be folded into this one.
Every first attempt logs:

[stderr] Caught SDK auth-error pattern ('Claude Code returned an error result: success'); refreshed=False; retrying once

_SDK_AUTH_ERROR_PREFIX = "Claude Code returned an error result"
(providers/anthropic_sdk.py:74) matched a message whose subtype is
success. A prefix match is classifying a successful-but-empty result
as an auth failure. Filing separately rather than widening this issue.