diff --git a/actions/setup/js/add_labels.cjs b/actions/setup/js/add_labels.cjs index 983bd050914..4dfcb5eda78 100644 --- a/actions/setup/js/add_labels.cjs +++ b/actions/setup/js/add_labels.cjs @@ -23,6 +23,7 @@ const { createAuthenticatedGitHubClient } = require("./handler_auth.cjs"); const { resolveRepoIssueTarget, loadTemporaryIdMapFromResolved } = require("./temporary_id.cjs"); const { MAX_LABELS } = require("./constants.cjs"); const { createCountGatedHandler } = require("./handler_scaffold.cjs"); +const { withRetry, RATE_LIMIT_RETRY_CONFIG } = require("./error_recovery.cjs"); /** * Main handler factory for add_labels @@ -167,12 +168,17 @@ const main = createCountGatedHandler({ } try { - await githubClient.rest.issues.addLabels({ - owner: repoParts.owner, - repo: repoParts.repo, - issue_number: itemNumber, - labels: uniqueLabels, - }); + await withRetry( + () => + githubClient.rest.issues.addLabels({ + owner: repoParts.owner, + repo: repoParts.repo, + issue_number: itemNumber, + labels: uniqueLabels, + }), + RATE_LIMIT_RETRY_CONFIG, + `add_labels to ${contextType} #${itemNumber} in ${itemRepo}` + ); core.info(`Successfully added ${uniqueLabels.length} labels to ${contextType} #${itemNumber} in ${itemRepo}`); return { diff --git a/actions/setup/js/add_labels.test.cjs b/actions/setup/js/add_labels.test.cjs index 38c5ae2f380..ea6f1df6f0b 100644 --- a/actions/setup/js/add_labels.test.cjs +++ b/actions/setup/js/add_labels.test.cjs @@ -13,6 +13,7 @@ describe("add_labels", () => { info: () => {}, warning: () => {}, error: () => {}, + debug: () => {}, messages: [], infos: [], warnings: [], @@ -314,7 +315,7 @@ describe("add_labels", () => { ); expect(result.success).toBe(false); - expect(result.error.includes("API Error")).toBe(true); + expect(result.error).toContain("API Error: Not found"); }); it("should deduplicate labels", async () => { diff --git a/actions/setup/js/create_issue.cjs b/actions/setup/js/create_issue.cjs index 4679478961f..481abbdd467 100644 --- a/actions/setup/js/create_issue.cjs +++ b/actions/setup/js/create_issue.cjs @@ -14,7 +14,7 @@ const { createAuthenticatedGitHubClient } = require("./handler_auth.cjs"); const { removeDuplicateTitleFromDescription } = require("./remove_duplicate_title.cjs"); const { getErrorMessage } = require("./error_helpers.cjs"); const { ERR_VALIDATION } = require("./error_codes.cjs"); -const { withRetry } = require("./error_recovery.cjs"); +const { withRetry, RATE_LIMIT_RETRY_CONFIG } = require("./error_recovery.cjs"); const { renderTemplateFromFile } = require("./messages_core.cjs"); const { createExpirationLine, addExpirationToFooter } = require("./ephemerals.cjs"); const { MAX_SUB_ISSUES, getSubIssueCount } = require("./sub_issue_helpers.cjs"); @@ -585,7 +585,7 @@ async function main(config = {}) { labels, assignees, }), - { initialDelayMs: 15000, maxDelayMs: 45000, jitterMs: 10000 }, + RATE_LIMIT_RETRY_CONFIG, `create_issue in ${qualifiedItemRepo}` ); diff --git a/actions/setup/js/error_recovery.cjs b/actions/setup/js/error_recovery.cjs index 688fa2f9a99..96a5ab9edd2 100644 --- a/actions/setup/js/error_recovery.cjs +++ b/actions/setup/js/error_recovery.cjs @@ -8,6 +8,7 @@ const { getErrorMessage } = require("./error_helpers.cjs"); const { ERR_API } = require("./error_codes.cjs"); +const { logRetryEvent } = require("./github_rate_limit_logger.cjs"); /** * Configuration for retry behavior @@ -33,6 +34,25 @@ const DEFAULT_RETRY_CONFIG = { shouldRetry: isTransientError, }; +/** + * Retry configuration for GitHub API rate-limit scenarios. + * Uses longer delays to handle installation token exhaustion during burst windows. + * + * Backoff sequence (approximate — jitter of up to 5 s is added per retry): + * ~30 s → ~60 s → ~120 s → ~240 s → ~240 s (capped) + * + * Note: The first actual retry sleep = initialDelayMs * backoffMultiplier = 15 000 * 2 = 30 000 ms. + * @type {RetryConfig} + */ +const RATE_LIMIT_RETRY_CONFIG = { + maxRetries: 5, + initialDelayMs: 15000, // 15 s × backoffMultiplier(2) = 30 s first retry + maxDelayMs: 240000, // 4-minute cap + backoffMultiplier: 2, + jitterMs: 5000, // Up to 5 s of jitter to spread concurrent retries + shouldRetry: isTransientError, +}; + /** * Determine if an error is transient and worth retrying * @param {any} error - The error to check @@ -80,6 +100,61 @@ function sleep(ms) { return new Promise(resolve => setTimeout(resolve, ms)); } +/** + * Extract the Retry-After delay in milliseconds from a GitHub API rate-limit error. + * + * Only applies when the response status indicates a rate-limit condition: + * - HTTP 429 (Too Many Requests) + * - HTTP 403 with `x-ratelimit-remaining: 0` (GitHub secondary rate limit) + * + * In those cases GitHub returns one of two headers: + * - `retry-after` – integer seconds to wait (per RFC 6585) + * - `x-ratelimit-reset` – Unix timestamp (seconds) when the quota resets + * + * For any other status (5xx transient errors, etc.) returns null so normal + * exponential backoff applies. + * + * @param {any} error - The error object from a failed GitHub API call + * @returns {number|null} Milliseconds to wait, or null if not a rate-limit response + */ +function getRetryAfterMs(error) { + // Octokit surfaces response headers via error.response.headers or error.headers + const status = error?.response?.status ?? error?.status ?? null; + const headers = error?.response?.headers ?? error?.headers ?? null; + if (!headers) return null; + + // Only honour rate-limit headers for genuine rate-limit responses. + // GitHub uses 429 for primary rate limits and 403 for secondary rate limits + // (the latter always sets x-ratelimit-remaining to "0"). + const remainingHeader = headers["x-ratelimit-remaining"]; + const isRateLimitStatus = status === 429 || (status === 403 && remainingHeader != null && parseInt(remainingHeader, 10) === 0); + + if (!isRateLimitStatus) return null; + + // retry-after: number of seconds (highest priority) + const retryAfter = headers["retry-after"]; + if (retryAfter != null) { + const seconds = parseInt(retryAfter, 10); + if (!isNaN(seconds) && seconds > 0) { + return seconds * 1000; + } + } + + // x-ratelimit-reset: Unix timestamp — derive wait time from clock delta + const resetAt = headers["x-ratelimit-reset"]; + if (resetAt != null) { + const resetTimestampMs = parseInt(resetAt, 10) * 1000; + if (!isNaN(resetTimestampMs)) { + const waitMs = resetTimestampMs - Date.now(); + if (waitMs > 0) { + return waitMs; + } + } + } + + return null; +} + /** * Execute an operation with retry logic and exponential backoff * @template T @@ -100,6 +175,7 @@ async function withRetry(operation, config = {}, operationName = "operation") { const jitter = fullConfig.jitterMs > 0 ? Math.floor(Math.random() * fullConfig.jitterMs) : 0; const delayWithJitter = delay + jitter; core.info(`Retry attempt ${attempt}/${fullConfig.maxRetries} for ${operationName} after ${delayWithJitter}ms delay`); + logRetryEvent(lastError, operationName, attempt, delayWithJitter); await sleep(delayWithJitter); } @@ -140,8 +216,21 @@ async function withRetry(operation, config = {}, operationName = "operation") { // Log the retry attempt core.warning(`${operationName} failed (attempt ${attempt + 1}/${fullConfig.maxRetries + 1}): ${errorMsg}`); - // Calculate next delay with exponential backoff - delay = Math.min(delay * fullConfig.backoffMultiplier, fullConfig.maxDelayMs); + // Calculate next delay: honour Retry-After header when present, otherwise + // use exponential backoff. Either way the result is capped at maxDelayMs. + const retryAfterMs = getRetryAfterMs(error); + if (retryAfterMs !== null) { + const cappedDelay = Math.min(retryAfterMs, fullConfig.maxDelayMs); + if (cappedDelay < retryAfterMs) { + core.info(`Retry-After header detected for ${operationName}: server requested ${retryAfterMs}ms wait, capped to ${cappedDelay}ms (maxDelayMs)`); + } else { + core.info(`Retry-After header detected for ${operationName}: next retry will wait ${cappedDelay}ms`); + } + delay = cappedDelay; + } else { + // Calculate next delay with exponential backoff + delay = Math.min(delay * fullConfig.backoffMultiplier, fullConfig.maxDelayMs); + } } } @@ -266,8 +355,10 @@ module.exports = { withRetry, sleep, isTransientError, + getRetryAfterMs, enhanceError, createValidationError, createOperationError, DEFAULT_RETRY_CONFIG, + RATE_LIMIT_RETRY_CONFIG, }; diff --git a/actions/setup/js/error_recovery.test.cjs b/actions/setup/js/error_recovery.test.cjs index 32a0823f555..761bd5435d6 100644 --- a/actions/setup/js/error_recovery.test.cjs +++ b/actions/setup/js/error_recovery.test.cjs @@ -1,6 +1,7 @@ // @ts-check -import { describe, it, expect, beforeEach, vi } from "vitest"; +import { describe, it, expect, beforeEach, afterEach, vi } from "vitest"; +import fs from "fs"; // Mock @actions/core global.core = { @@ -10,7 +11,7 @@ global.core = { debug: vi.fn(), }; -import { withRetry, isTransientError, enhanceError, createValidationError, createOperationError, DEFAULT_RETRY_CONFIG } from "./error_recovery.cjs"; +import { withRetry, isTransientError, getRetryAfterMs, enhanceError, createValidationError, createOperationError, DEFAULT_RETRY_CONFIG, RATE_LIMIT_RETRY_CONFIG } from "./error_recovery.cjs"; describe("error_recovery", () => { beforeEach(() => { @@ -333,4 +334,164 @@ describe("error_recovery", () => { expect(DEFAULT_RETRY_CONFIG.shouldRetry).toBe(isTransientError); }); }); + + describe("RATE_LIMIT_RETRY_CONFIG", () => { + it("should have 5 retries", () => { + expect(RATE_LIMIT_RETRY_CONFIG.maxRetries).toBe(5); + }); + + it("should have initialDelayMs producing 30s first retry sleep", () => { + // First retry sleep = initialDelayMs * backoffMultiplier + const firstRetrySleep = RATE_LIMIT_RETRY_CONFIG.initialDelayMs * RATE_LIMIT_RETRY_CONFIG.backoffMultiplier; + expect(firstRetrySleep).toBe(30000); + }); + + it("should cap delay at 240s", () => { + expect(RATE_LIMIT_RETRY_CONFIG.maxDelayMs).toBe(240000); + }); + + it("should use isTransientError as shouldRetry", () => { + expect(RATE_LIMIT_RETRY_CONFIG.shouldRetry).toBe(isTransientError); + }); + }); + + describe("getRetryAfterMs", () => { + it("should return null when error has no response headers", () => { + expect(getRetryAfterMs(new Error("Some error"))).toBeNull(); + expect(getRetryAfterMs(null)).toBeNull(); + expect(getRetryAfterMs(undefined)).toBeNull(); + }); + + it("should return null when status is not a rate-limit status", () => { + // 5xx errors should not use Retry-After from x-ratelimit-reset + const error502 = { response: { status: 502, headers: { "x-ratelimit-reset": String(Math.floor((Date.now() + 120000) / 1000)) } } }; + expect(getRetryAfterMs(error502)).toBeNull(); + // 403 without x-ratelimit-remaining: 0 is not a rate-limit response + const error403 = { response: { status: 403, headers: { "retry-after": "60", "x-ratelimit-remaining": "100" } } }; + expect(getRetryAfterMs(error403)).toBeNull(); + }); + + it("should extract retry-after seconds from response headers on 429", () => { + const error = { response: { status: 429, headers: { "retry-after": "60" } } }; + expect(getRetryAfterMs(error)).toBe(60000); + }); + + it("should extract retry-after seconds from top-level headers on 429", () => { + const error = { status: 429, headers: { "retry-after": "30" } }; + expect(getRetryAfterMs(error)).toBe(30000); + }); + + it("should prefer response.headers over top-level headers on 429", () => { + const error = { + response: { status: 429, headers: { "retry-after": "60" } }, + headers: { "retry-after": "30" }, + }; + expect(getRetryAfterMs(error)).toBe(60000); + }); + + it("should return null for zero or negative retry-after on 429", () => { + expect(getRetryAfterMs({ response: { status: 429, headers: { "retry-after": "0" } } })).toBeNull(); + expect(getRetryAfterMs({ response: { status: 429, headers: { "retry-after": "-1" } } })).toBeNull(); + }); + + it("should fall back to x-ratelimit-reset when retry-after is absent on 429", () => { + const futureTimestamp = Math.floor((Date.now() + 120000) / 1000); // 2 min from now + const error = { response: { status: 429, headers: { "x-ratelimit-reset": String(futureTimestamp) } } }; + const result = getRetryAfterMs(error); + // Should be roughly 120s (allow ±5s for test timing) + expect(result).toBeGreaterThan(115000); + expect(result).toBeLessThan(125000); + }); + + it("should use x-ratelimit-reset for 403 with x-ratelimit-remaining: 0 (secondary rate limit)", () => { + const futureTimestamp = Math.floor((Date.now() + 60000) / 1000); // 1 min from now + const error = { + response: { + status: 403, + headers: { "x-ratelimit-remaining": "0", "x-ratelimit-reset": String(futureTimestamp) }, + }, + }; + const result = getRetryAfterMs(error); + expect(result).toBeGreaterThan(55000); + expect(result).toBeLessThan(65000); + }); + + it("should return null when x-ratelimit-reset is in the past on 429", () => { + const pastTimestamp = Math.floor((Date.now() - 60000) / 1000); + const error = { response: { status: 429, headers: { "x-ratelimit-reset": String(pastTimestamp) } } }; + expect(getRetryAfterMs(error)).toBeNull(); + }); + + it("should return null for non-numeric retry-after on 429", () => { + const error = { response: { status: 429, headers: { "retry-after": "not-a-number" } } }; + expect(getRetryAfterMs(error)).toBeNull(); + }); + }); + + describe("withRetry with Retry-After header", () => { + let appendSpy, existsSpy, mkdirSpy; + + beforeEach(() => { + existsSpy = vi.spyOn(fs, "existsSync").mockReturnValue(true); + mkdirSpy = vi.spyOn(fs, "mkdirSync").mockImplementation(() => undefined); + appendSpy = vi.spyOn(fs, "appendFileSync").mockImplementation(() => undefined); + }); + + afterEach(() => { + existsSpy.mockRestore(); + mkdirSpy.mockRestore(); + appendSpy.mockRestore(); + }); + + it("should use Retry-After delay instead of backoff when header is present on 429", async () => { + const retryAfterError = { + message: "rate limit exceeded", + response: { status: 429, headers: { "retry-after": "1" } }, // 1s for test speed + }; + const operation = vi.fn().mockRejectedValueOnce(retryAfterError).mockResolvedValue("success"); + + const result = await withRetry(operation, { maxRetries: 2, initialDelayMs: 10, backoffMultiplier: 2, jitterMs: 0 }, "test-operation"); + + expect(result).toBe("success"); + // The delay used should be 1000ms (from Retry-After: 1) rather than 20ms (10 * 2) + expect(core.info).toHaveBeenCalledWith(expect.stringContaining("Retry-After header detected for test-operation: next retry will wait 1000ms")); + }); + + it("should fall back to exponential backoff for non-rate-limit errors (502)", async () => { + const transientError = { + message: "502 bad gateway", + response: { status: 502, headers: { "x-ratelimit-reset": String(Math.floor((Date.now() + 120000) / 1000)) } }, + }; + const operation = vi.fn().mockRejectedValueOnce(transientError).mockResolvedValue("success"); + + const result = await withRetry(operation, { maxRetries: 2, initialDelayMs: 10, backoffMultiplier: 2, jitterMs: 0 }, "test-operation"); + + expect(result).toBe("success"); + // Normal backoff: 10 * 2 = 20ms — NOT the 120s reset header + expect(core.info).toHaveBeenCalledWith(expect.stringContaining("after 20ms delay")); + expect(core.info).not.toHaveBeenCalledWith(expect.stringContaining("Retry-After header detected")); + }); + + it("should write a JSONL retry entry to the rate-limit log file on each retry", async () => { + const error = { + message: "rate limit exceeded", + response: { + status: 429, + headers: { "x-ratelimit-remaining": "0", "x-ratelimit-limit": "5000", "retry-after": "1" }, + }, + }; + const operation = vi.fn().mockRejectedValueOnce(error).mockResolvedValue("ok"); + + await withRetry(operation, { maxRetries: 2, initialDelayMs: 10, backoffMultiplier: 2, jitterMs: 0 }, "test-log-op"); + + // appendFileSync should have been called once (one retry) + expect(appendSpy).toHaveBeenCalledOnce(); + const entry = JSON.parse(appendSpy.mock.calls[0][1].trimEnd()); + expect(entry.source).toBe("retry"); + expect(entry.operation).toBe("test-log-op"); + expect(entry.attempt).toBe(1); + expect(entry.status).toBe(429); + expect(entry.remaining).toBe(0); + }); + }); }); diff --git a/actions/setup/js/github_rate_limit_logger.cjs b/actions/setup/js/github_rate_limit_logger.cjs index 4959c4a4c17..a5287d235fc 100644 --- a/actions/setup/js/github_rate_limit_logger.cjs +++ b/actions/setup/js/github_rate_limit_logger.cjs @@ -153,6 +153,46 @@ async function fetchAndLogRateLimit(github, operation = "fetch") { } } +/** + * Log a retry attempt to the JSONL log file, capturing any rate-limit headers + * present in the error response so that retry storms can be correlated with + * quota exhaustion in post-run analysis. + * + * Call this from {@link withRetry} immediately before sleeping on a retry attempt. + * + * @param {any} error - The error that triggered the retry + * @param {string} operation - Human-readable name of the failing operation + * @param {number} attempt - Retry attempt number (1-based; 1 = first retry) + * @param {number} delayMs - How long the caller will sleep before the next try + */ +function logRetryEvent(error, operation, attempt, delayMs) { + const headers = error?.response?.headers ?? error?.headers ?? {}; + const status = error?.response?.status ?? error?.status ?? null; + + /** @type {Record} */ + const entry = { + timestamp: new Date().toISOString(), + source: "retry", + operation, + attempt, + delay_ms: delayMs, + }; + + if (status != null) entry.status = status; + + const remaining = headers["x-ratelimit-remaining"]; + const limit = headers["x-ratelimit-limit"]; + const reset = headers["x-ratelimit-reset"]; + const resource = headers["x-ratelimit-resource"]; + + if (remaining !== undefined) entry.remaining = parseInt(remaining, 10); + if (limit !== undefined) entry.limit = parseInt(limit, 10); + if (reset) entry.reset = parseResetTimestamp(reset); + if (resource) entry.resource = resource; + + appendEntry(entry); +} + /** * Wrap a github object (as provided by actions/github-script) so that every * `github.rest.*.*()` call automatically logs rate-limit headers from the @@ -225,6 +265,7 @@ function createRateLimitAwareGithub(github) { module.exports = { logRateLimitFromResponse, fetchAndLogRateLimit, + logRetryEvent, createRateLimitAwareGithub, GITHUB_RATE_LIMITS_JSONL_PATH, }; diff --git a/actions/setup/js/github_rate_limit_logger.test.cjs b/actions/setup/js/github_rate_limit_logger.test.cjs index eea782cc148..56857125c40 100644 --- a/actions/setup/js/github_rate_limit_logger.test.cjs +++ b/actions/setup/js/github_rate_limit_logger.test.cjs @@ -20,7 +20,7 @@ global.core = mockCore; // Module import // --------------------------------------------------------------------------- -const { logRateLimitFromResponse, fetchAndLogRateLimit, createRateLimitAwareGithub, GITHUB_RATE_LIMITS_JSONL_PATH } = await import("./github_rate_limit_logger.cjs?" + Date.now()); +const { logRateLimitFromResponse, fetchAndLogRateLimit, logRetryEvent, createRateLimitAwareGithub, GITHUB_RATE_LIMITS_JSONL_PATH } = await import("./github_rate_limit_logger.cjs?" + Date.now()); // --------------------------------------------------------------------------- // logRateLimitFromResponse @@ -400,3 +400,102 @@ describe("createRateLimitAwareGithub", () => { expect(endpointObj.merge).toHaveBeenCalledWith({ owner: "o", repo: "r", ref: "main", per_page: 100 }); }); }); + +// --------------------------------------------------------------------------- +// logRetryEvent +// --------------------------------------------------------------------------- + +describe("logRetryEvent", () => { + let existsSpy, mkdirSpy, appendSpy; + + beforeEach(() => { + existsSpy = vi.spyOn(fs, "existsSync").mockReturnValue(true); + mkdirSpy = vi.spyOn(fs, "mkdirSync").mockImplementation(() => undefined); + appendSpy = vi.spyOn(fs, "appendFileSync").mockImplementation(() => undefined); + vi.clearAllMocks(); + existsSpy.mockReturnValue(true); + }); + + afterEach(() => { + existsSpy.mockRestore(); + mkdirSpy.mockRestore(); + appendSpy.mockRestore(); + }); + + it("writes a retry JSONL entry with source=retry", () => { + const error = { message: "rate limit exceeded" }; + logRetryEvent(error, "issues.create", 1, 30000); + + expect(appendSpy).toHaveBeenCalledOnce(); + const entry = JSON.parse(appendSpy.mock.calls[0][1].trimEnd()); + expect(entry.source).toBe("retry"); + expect(entry.operation).toBe("issues.create"); + expect(entry.attempt).toBe(1); + expect(entry.delay_ms).toBe(30000); + expect(typeof entry.timestamp).toBe("string"); + }); + + it("includes HTTP status when present in error", () => { + const error = { response: { status: 429, headers: {} } }; + logRetryEvent(error, "issues.create", 1, 15000); + + const entry = JSON.parse(appendSpy.mock.calls[0][1].trimEnd()); + expect(entry.status).toBe(429); + }); + + it("includes rate-limit headers from the error response when present", () => { + const resetSeconds = 1700000000; + const error = { + response: { + status: 429, + headers: { + "x-ratelimit-limit": "5000", + "x-ratelimit-remaining": "0", + "x-ratelimit-reset": String(resetSeconds), + "x-ratelimit-resource": "core", + }, + }, + }; + + logRetryEvent(error, "lock-issue", 2, 60000); + + const entry = JSON.parse(appendSpy.mock.calls[0][1].trimEnd()); + expect(entry.limit).toBe(5000); + expect(entry.remaining).toBe(0); + expect(entry.reset).toBe(new Date(resetSeconds * 1000).toISOString()); + expect(entry.resource).toBe("core"); + }); + + it("also reads headers from top-level error.headers", () => { + const error = { + status: 429, + headers: { "x-ratelimit-remaining": "10", "x-ratelimit-limit": "5000" }, + }; + + logRetryEvent(error, "add-labels", 1, 30000); + + const entry = JSON.parse(appendSpy.mock.calls[0][1].trimEnd()); + expect(entry.remaining).toBe(10); + expect(entry.limit).toBe(5000); + }); + + it("omits optional fields when error has no response headers", () => { + logRetryEvent(new Error("network timeout"), "create-issue", 3, 120000); + + const entry = JSON.parse(appendSpy.mock.calls[0][1].trimEnd()); + expect(entry.source).toBe("retry"); + expect(entry.status).toBeUndefined(); + expect(entry.remaining).toBeUndefined(); + expect(entry.limit).toBeUndefined(); + expect(entry.reset).toBeUndefined(); + expect(entry.resource).toBeUndefined(); + }); + + it("writes valid JSONL (ends with newline, no embedded newlines)", () => { + logRetryEvent({}, "test-op", 1, 5000); + + const content = appendSpy.mock.calls[0][1]; + expect(content).toMatch(/\n$/); + expect(content.trimEnd()).not.toContain("\n"); + }); +}); diff --git a/actions/setup/js/lock-issue.cjs b/actions/setup/js/lock-issue.cjs index 996789903fd..ba63fb14dcf 100644 --- a/actions/setup/js/lock-issue.cjs +++ b/actions/setup/js/lock-issue.cjs @@ -9,6 +9,7 @@ const { getErrorMessage } = require("./error_helpers.cjs"); const { ERR_NOT_FOUND } = require("./error_codes.cjs"); +const { withRetry, RATE_LIMIT_RETRY_CONFIG } = require("./error_recovery.cjs"); async function main() { // Log actor and event information for debugging @@ -30,11 +31,16 @@ async function main() { try { // Check if issue is already locked core.info(`Checking if issue #${issueNumber} is already locked`); - const { data: issue } = await github.rest.issues.get({ - owner, - repo, - issue_number: issueNumber, - }); + const { data: issue } = await withRetry( + () => + github.rest.issues.get({ + owner, + repo, + issue_number: issueNumber, + }), + RATE_LIMIT_RETRY_CONFIG, + `get issue #${issueNumber}` + ); // Skip locking if this is a pull request (PRs cannot be locked via issues API) if (issue.pull_request) { @@ -52,11 +58,16 @@ async function main() { core.info(`Locking issue #${issueNumber} for agent workflow execution`); // Lock the issue without providing a lock_reason parameter - await github.rest.issues.lock({ - owner, - repo, - issue_number: issueNumber, - }); + await withRetry( + () => + github.rest.issues.lock({ + owner, + repo, + issue_number: issueNumber, + }), + RATE_LIMIT_RETRY_CONFIG, + `lock issue #${issueNumber}` + ); core.info(`✅ Successfully locked issue #${issueNumber}`); // Set output to indicate the issue was locked and needs to be unlocked diff --git a/actions/setup/js/lock-issue.test.cjs b/actions/setup/js/lock-issue.test.cjs index 0b58fe91509..2289ca41480 100644 --- a/actions/setup/js/lock-issue.test.cjs +++ b/actions/setup/js/lock-issue.test.cjs @@ -56,20 +56,22 @@ const mockCore = { debug: vi.fn(), info: vi.fn(), warning: vi.fn(), error: vi.fn }), it("should handle API errors gracefully", async () => { mockGithub.rest.issues.get.mockResolvedValue({ data: { number: 42, locked: !1 } }); - const apiError = new Error("API rate limit exceeded"); + const apiError = new Error("Not authorized"); (mockGithub.rest.issues.lock.mockRejectedValue(apiError), await eval(`(async () => { ${lockIssueScript}; await main(); })()`), expect(mockGithub.rest.issues.lock).toHaveBeenCalled(), - expect(mockCore.error).toHaveBeenCalledWith("Failed to lock issue: API rate limit exceeded"), - expect(mockCore.setFailed).toHaveBeenCalledWith(`${ERR_NOT_FOUND}: Failed to lock issue #42: API rate limit exceeded`), + expect(mockCore.error).toHaveBeenCalledWith(expect.stringContaining("Failed to lock issue:")), + expect(mockCore.error).toHaveBeenCalledWith(expect.stringContaining("Not authorized")), + expect(mockCore.setFailed).toHaveBeenCalledWith(expect.stringContaining(`Failed to lock issue #42:`)), expect(mockCore.setOutput).toHaveBeenCalledWith("locked", "false")); }), it("should handle non-Error exceptions", async () => { (mockGithub.rest.issues.get.mockResolvedValue({ data: { number: 42, locked: !1 } }), mockGithub.rest.issues.lock.mockRejectedValue("String error"), await eval(`(async () => { ${lockIssueScript}; await main(); })()`), - expect(mockCore.error).toHaveBeenCalledWith("Failed to lock issue: String error"), - expect(mockCore.setFailed).toHaveBeenCalledWith(`${ERR_NOT_FOUND}: Failed to lock issue #42: String error`), + expect(mockCore.error).toHaveBeenCalledWith(expect.stringContaining("Failed to lock issue:")), + expect(mockCore.error).toHaveBeenCalledWith(expect.stringContaining("String error")), + expect(mockCore.setFailed).toHaveBeenCalledWith(expect.stringContaining(`Failed to lock issue #42:`)), expect(mockCore.setOutput).toHaveBeenCalledWith("locked", "false")); }), it("should work with different issue numbers", async () => { diff --git a/actions/setup/js/rate_limit_helpers.cjs b/actions/setup/js/rate_limit_helpers.cjs index 52c74e73723..52ed8fc0b12 100644 --- a/actions/setup/js/rate_limit_helpers.cjs +++ b/actions/setup/js/rate_limit_helpers.cjs @@ -1,7 +1,8 @@ // @ts-check /// -const { fetchAndLogRateLimit } = require("./github_rate_limit_logger.cjs"); +const { fetchAndLogRateLimit, logRateLimitFromResponse } = require("./github_rate_limit_logger.cjs"); +const { getErrorMessage } = require("./error_helpers.cjs"); /** * Minimum rate limit remaining before we skip further operations. @@ -9,6 +10,12 @@ const { fetchAndLogRateLimit } = require("./github_rate_limit_logger.cjs"); */ const MIN_RATE_LIMIT_REMAINING = 100; +/** + * Percentage of remaining quota below which a warning is emitted. + * E.g. 20 means a warning is logged when < 20 % of the total quota remains. + */ +const LOW_RATE_LIMIT_THRESHOLD_PERCENT = 20; + /** * Check the current rate limit and determine if we should continue. * Returns the remaining requests count, or -1 if we couldn't check. @@ -44,8 +51,41 @@ async function checkRateLimit(github, operation = "rate_limit_check") { return { ok: true, remaining }; } +/** + * Check rate-limit headroom and emit a warning when the remaining quota + * falls below {@link LOW_RATE_LIMIT_THRESHOLD_PERCENT} percent of the total. + * + * This is a lightweight observability call – it does not block execution. + * + * @param {any} github - GitHub REST client + * @param {string} [operation="rate_limit_headroom"] - Label used in log messages + * @returns {Promise<{remaining: number, limit: number, percentRemaining: number}>} + */ +async function checkRateLimitHeadroom(github, operation = "rate_limit_headroom") { + try { + const response = await github.rest.rateLimit.get(); + const { data } = response; + logRateLimitFromResponse(response, operation); + const { remaining, limit } = data.rate; + const percentRemaining = limit > 0 ? Math.floor((remaining / limit) * 100) : 100; + + if (percentRemaining < LOW_RATE_LIMIT_THRESHOLD_PERCENT) { + core.warning(`⚠️ Rate-limit headroom low: ${remaining}/${limit} requests remaining (${percentRemaining}%) [${operation}]. Safe-output writes may be rate-limited.`); + } else { + core.info(`ℹ️ Rate-limit headroom: ${remaining}/${limit} requests remaining (${percentRemaining}%) [${operation}]`); + } + + return { remaining, limit, percentRemaining }; + } catch (err) { + core.warning(`Could not check rate-limit headroom for ${operation}: ${getErrorMessage(err)}`); + return { remaining: -1, limit: -1, percentRemaining: -1 }; + } +} + module.exports = { MIN_RATE_LIMIT_REMAINING, + LOW_RATE_LIMIT_THRESHOLD_PERCENT, getRateLimitRemaining, checkRateLimit, + checkRateLimitHeadroom, }; diff --git a/actions/setup/js/rate_limit_helpers.test.cjs b/actions/setup/js/rate_limit_helpers.test.cjs index 61511e2c564..fdb380df7e5 100644 --- a/actions/setup/js/rate_limit_helpers.test.cjs +++ b/actions/setup/js/rate_limit_helpers.test.cjs @@ -1,5 +1,6 @@ // @ts-check -import { describe, it, expect, beforeEach, vi } from "vitest"; +import { describe, it, expect, beforeEach, afterEach, vi } from "vitest"; +import fs from "fs"; // Mock core global (needed by github_rate_limit_logger.cjs) const mockCore = { @@ -80,4 +81,113 @@ describe("rate_limit_helpers", () => { expect(MIN_RATE_LIMIT_REMAINING).toBe(100); }); }); + + describe("LOW_RATE_LIMIT_THRESHOLD_PERCENT", () => { + it("should be 20", async () => { + const { LOW_RATE_LIMIT_THRESHOLD_PERCENT } = await import("./rate_limit_helpers.cjs"); + expect(LOW_RATE_LIMIT_THRESHOLD_PERCENT).toBe(20); + }); + }); + + describe("checkRateLimitHeadroom", () => { + it("should return remaining, limit, and percentRemaining", async () => { + const { checkRateLimitHeadroom } = await import("./rate_limit_helpers.cjs"); + mockGithub.rest.rateLimit.get.mockResolvedValue({ + data: { + rate: { remaining: 4000, limit: 5000, used: 1000 }, + resources: {}, + }, + }); + const result = await checkRateLimitHeadroom(mockGithub, "test"); + expect(result.remaining).toBe(4000); + expect(result.limit).toBe(5000); + expect(result.percentRemaining).toBe(80); + }); + + it("should log info when headroom is above threshold", async () => { + const { checkRateLimitHeadroom } = await import("./rate_limit_helpers.cjs"); + mockGithub.rest.rateLimit.get.mockResolvedValue({ + data: { + rate: { remaining: 4000, limit: 5000, used: 1000 }, + resources: {}, + }, + }); + await checkRateLimitHeadroom(mockGithub, "test"); + expect(mockCore.info).toHaveBeenCalledWith(expect.stringContaining("Rate-limit headroom: 4000/5000")); + expect(mockCore.warning).not.toHaveBeenCalled(); + }); + + it("should emit warning when headroom is below threshold", async () => { + const { checkRateLimitHeadroom } = await import("./rate_limit_helpers.cjs"); + mockGithub.rest.rateLimit.get.mockResolvedValue({ + data: { + rate: { remaining: 500, limit: 5000, used: 4500 }, + resources: {}, + }, + }); + await checkRateLimitHeadroom(mockGithub, "test"); + expect(mockCore.warning).toHaveBeenCalledWith(expect.stringContaining("Rate-limit headroom low: 500/5000")); + }); + + it("should return -1 values and warn with error details on error", async () => { + const { checkRateLimitHeadroom } = await import("./rate_limit_helpers.cjs"); + mockGithub.rest.rateLimit.get.mockRejectedValue(new Error("API error")); + const result = await checkRateLimitHeadroom(mockGithub, "test"); + expect(result.remaining).toBe(-1); + expect(result.limit).toBe(-1); + expect(result.percentRemaining).toBe(-1); + expect(mockCore.warning).toHaveBeenCalledWith(expect.stringContaining("Could not check rate-limit headroom")); + expect(mockCore.warning).toHaveBeenCalledWith(expect.stringContaining("API error")); + }); + + it("should use Math.floor so 19.9% triggers warning (not Math.round which would give 20%)", async () => { + const { checkRateLimitHeadroom } = await import("./rate_limit_helpers.cjs"); + // 199/1000 = 19.9% — Math.floor gives 19, Math.round would give 20 (and skip the warning) + mockGithub.rest.rateLimit.get.mockResolvedValue({ + data: { + rate: { remaining: 199, limit: 1000, used: 801 }, + resources: {}, + }, + }); + await checkRateLimitHeadroom(mockGithub, "test"); + expect(mockCore.warning).toHaveBeenCalledWith(expect.stringContaining("Rate-limit headroom low:")); + }); + it("should write the quota snapshot to the JSONL log file when response has rate-limit headers", async () => { + const { checkRateLimitHeadroom } = await import("./rate_limit_helpers.cjs"); + + // Provide rate-limit headers so logRateLimitFromResponse can write an entry + mockGithub.rest.rateLimit.get.mockResolvedValue({ + data: { + rate: { remaining: 3000, limit: 5000, used: 2000 }, + resources: {}, + }, + headers: { + "x-ratelimit-limit": "5000", + "x-ratelimit-remaining": "3000", + "x-ratelimit-reset": "1700000000", + "x-ratelimit-resource": "core", + }, + }); + + const existsSpy = vi.spyOn(fs, "existsSync").mockReturnValue(true); + const mkdirSpy = vi.spyOn(fs, "mkdirSync").mockImplementation(() => undefined); + const appendSpy = vi.spyOn(fs, "appendFileSync").mockImplementation(() => undefined); + + try { + await checkRateLimitHeadroom(mockGithub, "pre-flight-check"); + + expect(appendSpy).toHaveBeenCalledOnce(); + const entry = JSON.parse(appendSpy.mock.calls[0][1].trimEnd()); + expect(entry.source).toBe("response_headers"); + expect(entry.operation).toBe("pre-flight-check"); + expect(entry.remaining).toBe(3000); + expect(entry.limit).toBe(5000); + expect(entry.resource).toBe("core"); + } finally { + existsSpy.mockRestore(); + mkdirSpy.mockRestore(); + appendSpy.mockRestore(); + } + }); + }); }); diff --git a/actions/setup/js/safe_output_handler_manager.cjs b/actions/setup/js/safe_output_handler_manager.cjs index 7887e590951..e9fd0baae2f 100644 --- a/actions/setup/js/safe_output_handler_manager.cjs +++ b/actions/setup/js/safe_output_handler_manager.cjs @@ -24,6 +24,7 @@ const { createManifestLogger, ensureManifestExists, extractCreatedItemFromResult const { loadCustomSafeOutputJobTypes, loadCustomSafeOutputScriptHandlers, loadCustomSafeOutputActionHandlers, isStagedMode } = require("./safe_output_helpers.cjs"); const { emitSafeOutputActionOutputs } = require("./safe_outputs_action_outputs.cjs"); const { listCommentMemoryFiles, COMMENT_MEMORY_DIR } = require("./comment_memory_helpers.cjs"); +const { checkRateLimitHeadroom } = require("./rate_limit_helpers.cjs"); const nodePath = require("path"); const fs = require("fs"); @@ -1171,6 +1172,11 @@ async function main() { // In staged mode, pass null so no items are logged (nothing is actually created). const logCreatedItem = isStaged ? null : createManifestLogger(); + // Pre-check: log a warning when the installation token's rate-limit headroom is low. + // This surfaces quota pressure before writes start so it is visible in the job log + // even if no individual write fails. The check is best-effort – failures are non-fatal. + await checkRateLimitHeadroom(github, "safe_outputs_pre_check"); + // Process all messages in order of appearance const processingResult = await processMessages(messageHandlers, allMessages, logCreatedItem);