fix(e2e): fix stale lock recovery and improve lock debugging - #1612
Conversation
Two bugs prevented stale e2e lock recovery from working with the live
GitHub API:
1. APIErrorDetail was missing the Message field, so GitHub's 422
response ("name already exists on this account") was not included
in the error string. This caused isRepoAlreadyExists to never match
for the live client, making tryCreateLock return an error instead of
(false, nil) for existing repos.
2. In acquireOrg, when tryCreateLock returned an error, the code
skipped tryReclaimStaleLock entirely (via continue). Now stale lock
recovery runs even when tryCreateLock fails with an unexpected error.
Also adds logging throughout the lock management code:
- Log DeleteRepo failures instead of silently discarding them
- Log each step of lock acquisition (create attempt, write, race loss)
- Include staleLockTimeout value in stale lock log messages
Signed-off-by: Ryan Bean <rbean@redhat.com>
Assisted-by: Claude Opus 4.6 <noreply@anthropic.com>
Signed-off-by: Ralph Bean <rbean@redhat.com>
Site previewPreview: https://fded991a-site.fullsend-ai.workers.dev Commit: |
ReviewFindingsNo findings. All three fixes verified against the diff:
Secondary rate limit detection by response body ( Previous runReviewFindingsNo findings. All three fixes verified against the diff:
Secondary rate limit detection by response body ( Previous run (2)ReviewNo findings. Previous run (3)ReviewNo findings. Previous runReviewFindingsNo findings. All three fixes verified against the diff:
Secondary rate limit detection by response body ( Previous run (2)ReviewNo findings. Previous run (3)ReviewNo findings. |
![fullsend-ai-review[bot]](https://avatars.githubusercontent.com/in/3478501?s=60&v=4){kind=small}
fullsend-ai-review
Bot
added
the
ready-for-merge
GitHub's secondary rate limit can return 403 without a Retry-After header. The previous code only retried 403 responses that had a Retry-After header, so these "body-only" secondary rate limits were treated as permission errors and not retried. Now isRetryable reads the 403 response body and checks for "secondary rate limit" text. When detected, retryDelay uses a 60-second minimum backoff (plus exponential), matching GitHub's recommendation. For non-rate-limit 403s (permission denied), the body is preserved and returned to the caller without retry — no behavior change for those. Signed-off-by: Ryan Bean <rbean@redhat.com> Assisted-by: Claude Opus 4.6 <noreply@anthropic.com> Signed-off-by: Ralph Bean <rbean@redhat.com>
fullsend-ai-review
Bot
added
ready-for-merge
When retries are exhausted, include the method, path, last delay, and Retry-After header value (if present) in the error message. This makes rate limit failures visible in e2e test logs without adding a logger dependency to the HTTP layer. Signed-off-by: Ryan Bean <rbean@redhat.com> Assisted-by: Claude Opus 4.6 <noreply@anthropic.com> Signed-off-by: Ralph Bean <rbean@redhat.com>
fullsend-ai-review
Bot
added
ready-for-merge
waynesun09
left a comment
waynesun09
left a comment
There was a problem hiding this comment.
Review Squad Report — 5 agents (claude-coder x2, claude-researcher, gemini-code-review, cursor-code-review)
Findings: 6 MEDIUM, 6 LOW, 3 INFO (after dedup from 40+ raw findings, 7 false positives removed)
The root cause fix (APIErrorDetail.Message field) and stale lock recovery logic are correct. The 6 MEDIUM findings are all hardening suggestions — none block the fix. Strongest consensus items (4/5 agents agreed):
- Stale lock recovery should be gated on 422 errors, not all errors
DeleteRepofailure handling should be consistent betweenacquireLockandtryReclaimStaleLock
| return true, nil | ||
| } | ||
| // Check body for secondary rate limit without Retry-After header. | ||
| data, _ := io.ReadAll(resp.Body) |
There was a problem hiding this comment.
[MEDIUM] Unbounded io.ReadAll + swallowed error (3/5 agents flagged)
Two issues on this line:
-
Unbounded read —
io.ReadAll(resp.Body)has no size limit. A malformed or proxy-intercepted 403 with a large body could exhaust memory. -
Swallowed error — the read error is discarded (
_ =). If the body read fails (connection reset),datais empty/partial,strings.Containsreturns false, and(false, data)is returned. The caller replacesresp.Bodywith this corrupt data, causingcheckStatusto produce a confusing "unexpected end of JSON" error instead of surfacing the actual network problem.
Suggestion:
data, readErr := io.ReadAll(io.LimitReader(resp.Body, 1<<16)) // 64KB max
if readErr != nil {
return false, nil
}There was a problem hiding this comment.
Fixed in 1b0e866. LimitReader at 64KB and return false, nil on read error so the caller doesn't get corrupt data.
| } | ||
| // Check body for secondary rate limit without Retry-After header. | ||
| data, _ := io.ReadAll(resp.Body) | ||
| if strings.Contains(string(data), "secondary rate limit") { |
There was a problem hiding this comment.
[MEDIUM] Case-sensitive substring match is fragile
strings.Contains(string(data), "secondary rate limit") is case-sensitive. If GitHub changes the casing or phrasing (e.g., "Secondary Rate Limit", "secondary_rate_limit"), this detection silently fails and the 403 is treated as a permanent permission error — no retry.
Suggestion:
if strings.Contains(strings.ToLower(string(data)), "secondary rate limit") {There was a problem hiding this comment.
Folded into the same fix — strings.ToLower before the match now.
| // returns "422 Validation Failed" without "already exists" in | ||
| // the top-level message). Still attempt stale lock recovery. | ||
| if token != "" { | ||
| if reclaimed := tryReclaimStaleLock(ctx, client, token, org, runID, logf); reclaimed { |
There was a problem hiding this comment.
[MEDIUM] Stale lock recovery called on any error type — wastes API quota (4/5 agents flagged, strongest consensus)
When tryCreateLock returns an error (rate limit, auth failure, network timeout), this unconditionally calls tryReclaimStaleLock, which issues 2-3 more API calls that will likely also fail. This wastes API quota and could accelerate rate limit exhaustion. tryReclaimStaleLock degrades gracefully (returns false), so it's not a correctness bug — just unnecessary work.
Same pattern repeats at line 122.
Suggestion — gate on error type so only 422s trigger stale recovery:
var apiErr *github.APIError
if token != "" && errors.As(err, &apiErr) && apiErr.StatusCode == http.StatusUnprocessableEntity {
if reclaimed := tryReclaimStaleLock(ctx, client, token, org, runID, logf); reclaimed {
return org, nil
}
}There was a problem hiding this comment.
Agreed, gated on 422 via errors.As in 1b0e866. Both sites in acquireOrg now check apiErr.StatusCode == 422 before attempting stale recovery.
| logf("[org-pool] %s lock is stale (age: %s > %s), deleting stale lock repo", org, age.Round(time.Second), staleLockTimeout) | ||
| if delErr := client.DeleteRepo(ctx, org, lockRepo); delErr != nil { | ||
| logf("[org-pool] Warning: failed to delete stale lock repo %s/%s: %v", org, lockRepo, delErr) | ||
| return false |
There was a problem hiding this comment.
[MEDIUM] Inconsistent DeleteRepo error handling vs acquireLock (4/5 agents flagged)
Here in tryReclaimStaleLock, a DeleteRepo failure causes immediate return false, abandoning the org. But in acquireLock (lines 84-87), the same failure is logged and tryCreateLock still runs. This inconsistency means:
- If another runner concurrently deletes the stale repo,
DeleteReporeturns 404 here, andtryReclaimStaleLockgives up even thoughtryCreateLockwould succeed. - In
acquireLock, the same scenario correctly falls through totryCreateLock.
Suggestion — check if the error is a 404 (repo already gone) and proceed in that case:
if delErr := client.DeleteRepo(ctx, org, lockRepo); delErr != nil {
if !forge.IsNotFound(delErr) {
logf("[org-pool] Warning: failed to delete stale lock repo %s/%s: %v", org, lockRepo, delErr)
return false
}
logf("[org-pool] Stale lock repo %s/%s already deleted", org, lockRepo)
}There was a problem hiding this comment.
Good catch — forge.IsNotFound already exists so this was easy. 1b0e866 now lets 404 fall through to tryCreateLock.
| @@ -156,6 +191,10 @@ func retryDelay(resp *http.Response, attempt int) time.Duration { | |||
| return time.Duration(secs) * time.Second | |||
There was a problem hiding this comment.
[MEDIUM] Retry-After header parsed without upper bound
strconv.Atoi(ra) has no sanity check. A malformed response with Retry-After: 999999999 would cause the client to sleep for ~31 years. While unlikely from GitHub directly, a misconfigured proxy could produce this.
Suggestion — cap at a reasonable max:
if secs, err := strconv.Atoi(ra); err == nil && secs > 0 && secs <= 300 {
return time.Duration(secs) * time.Second
}Address review feedback on #1612: - Bound io.ReadAll with LimitReader (64KB) and handle read errors in isRetryable to avoid unbounded memory use and corrupt body passthrough - Use case-insensitive match for secondary rate limit body detection - Cap Retry-After header at 300s to prevent unreasonable sleep durations - Gate stale lock recovery on 422 errors only — rate limits, auth failures, and network errors would just waste more API quota - Allow 404 on DeleteRepo in tryReclaimStaleLock so concurrent runners that already cleaned up the stale lock don't block re-creation Assisted-by: Claude claude-opus-4-6 <noreply@anthropic.com> Signed-off-by: Ralph Bean <rbean@redhat.com>
fullsend-ai-review
Bot
added
ready-for-merge
waynesun09
left a comment
waynesun09
left a comment
There was a problem hiding this comment.
All 6 findings from the previous review have been addressed:
io.LimitReaderbounds the body read inisRetryablereadErrcheck added after body read- Case-insensitive
strings.ToLower()for secondary rate limit detection Retry-Afterclamped tosecs > 0 && secs <= 300- Stale lock reclaim gated on
apiErr.StatusCode == 422 forge.IsNotFoundguard added intryReclaimStaleLock
Retry logic is solid, error handling is well-scoped. LGTM.
2 participants
Summary
APIErrorDetailwas missing theMessagefield, so GitHub's 422 "name already exists on this account" was never included in the error string.isRepoAlreadyExists()never matched for the live client, causingtryCreateLockto return an error instead of(false, nil)for existing repos.acquireOrgskippedtryReclaimStaleLockwhentryCreateLockreturned an error (thecontinuejumped past the stale check). Now stale lock recovery runs even whentryCreateLockfails with an unexpected error._ =), each step of lock acquisition, and stale lock threshold values.Test plan
make go-testpassesmake go-vetpassesmake lintpassesTestAPIError_ErrorStringWithDetailsvalidates error detail messages are included inError()output🤖 Generated with Claude Code