fix(scheduler): stop a GitHub rate limit from holding the scheduler lock (#443)

A scheduled sync took the module level scheduler lock and held it for the
whole run. When GitHub's primary rate limit ran out, the Octokit throttling
plugin slept for the full window inside the request (the report shows
"Waiting 3263s before retry"), up to three times per repository, so the run
never finished. Every following tick logged "Scheduler is already running,
skipping this cycle" and nothing synced until the container was restarted,
with the repositories that had already failed left as "failed" and needing a
manual retry.

The throttle handler now decides what to do based on how far away the reset
is. Waits up to 120 seconds are slept off inside the request as before.
Anything longer records the reset on a new in-memory gate
(src/lib/rate-limit-gate.ts), publishes the existing rate-limit event with the
reset time and fails the request instead of sleeping.

The scheduler reads that gate before each batch and before each repository, in
the auto-mirror loop, the sync loop and the boot auto-start loop. When the
gate is up it logs once, stops the run and releases the lock as usual, and it
writes nextRun as the reset plus one minute so the next tick resumes at the
reset rather than at the schedule's own next slot. A repository whose attempt
failed only because of the rate limit is put back to the status it had before
the attempt, so it is picked up by the next run instead of waiting for a
manual retry.

Fixes #437
This commit is contained in:
ARUNAVO RAY authored and GitHub committed 2026-09-22 23:00:53 +05:30
1 parent 23431266cf
commit 261a9729e2
6 files changed
+747 -11

No files matched your search

@@ -0,0 +1,62 @@
import { describe, expect, test } from "bun:test";
import {
RATE_LIMIT_FAST_FAIL_THRESHOLD_SECONDS,
decideRateLimitRetry,
} from "@/lib/github";
// The decision the Octokit throttling plugin's onRateLimit handler makes,
// pulled out of the handler so the policy can be checked without a client.
describe("decideRateLimitRetry", () => {
const maxRetries = 3;
test("short waits are still retried inside the request", () => {
expect(decideRateLimitRetry({ retryAfter: 5, retryCount: 0, maxRetries })).toBe("retry");
expect(decideRateLimitRetry({ retryAfter: 60, retryCount: 2, maxRetries })).toBe("retry");
expect(
decideRateLimitRetry({
retryAfter: RATE_LIMIT_FAST_FAIL_THRESHOLD_SECONDS,
retryCount: 0,
maxRetries,
})
).toBe("retry");
});
test("short waits stop once the retries are used up", () => {
expect(decideRateLimitRetry({ retryAfter: 30, retryCount: 3, maxRetries })).toBe("give-up");
expect(decideRateLimitRetry({ retryAfter: 30, retryCount: 9, maxRetries })).toBe("give-up");
});
test("a wait past the threshold fails fast on the first hit, whatever the retry count", () => {
// The reporter's log showed a 3263s wait, which used to be slept off
// inside the scheduler lock three times over (issue #437).
expect(decideRateLimitRetry({ retryAfter: 3263, retryCount: 0, maxRetries })).toBe("fail-fast");
expect(decideRateLimitRetry({ retryAfter: 3263, retryCount: 2, maxRetries })).toBe("fail-fast");
expect(
decideRateLimitRetry({
retryAfter: RATE_LIMIT_FAST_FAIL_THRESHOLD_SECONDS + 1,
retryCount: 0,
maxRetries,
})
).toBe("fail-fast");
});
test("search endpoints get their extra retries for short waits only", () => {
const searchRetries = 5;
expect(decideRateLimitRetry({ retryAfter: 10, retryCount: 4, maxRetries: searchRetries })).toBe("retry");
expect(decideRateLimitRetry({ retryAfter: 10, retryCount: 5, maxRetries: searchRetries })).toBe("give-up");
expect(decideRateLimitRetry({ retryAfter: 900, retryCount: 0, maxRetries: searchRetries })).toBe("fail-fast");
});
test("the threshold is configurable for callers that want a different budget", () => {
expect(
decideRateLimitRetry({ retryAfter: 45, retryCount: 0, maxRetries, thresholdSeconds: 30 })
).toBe("fail-fast");
expect(
decideRateLimitRetry({ retryAfter: 45, retryCount: 0, maxRetries, thresholdSeconds: 600 })
).toBe("retry");
});
test("the default threshold keeps waits to two minutes", () => {
expect(RATE_LIMIT_FAST_FAIL_THRESHOLD_SECONDS).toBe(120);
});
});
+82 -4
View File
@@ -8,6 +8,11 @@ import {
applyConditionalRequests,
conditionalRequestTokenScope,
} from "@/lib/github-conditional-requests";
import {
clearRateLimit,
markRateLimited,
rateLimitGateKey,
} from "@/lib/rate-limit-gate";
// Conditionally import rate limit manager (not available in test environment)
let RateLimitManager: any = null;
let publishEvent: any = null;
@@ -29,6 +34,46 @@ const MyOctokit: any = (Octokit as any)?.plugin?.call
? (Octokit as any).plugin(throttling)
: (Octokit as any);
/**
* Longest wait a request may sleep through inside the throttling plugin.
* A primary rate limit resets at a fixed time that is often tens of minutes
* away; sleeping that long inside the request holds the scheduler lock for the
* whole run (issue #437), so anything longer is handed to the rate limit gate
* and the request fails fast instead.
*/
export const RATE_LIMIT_FAST_FAIL_THRESHOLD_SECONDS = 120;
export type RateLimitRetryAction = "retry" | "fail-fast" | "give-up";
/**
* What the throttle handler should do with a primary rate limit. Pure, so the
* policy can be tested without standing up Octokit.
*
* - "retry": short wait, sleep it off inside the request as before.
* - "fail-fast": the reset is too far out to wait for; pause the source and
* let the caller fail so the scheduler can end its run and come back.
* - "give-up": short waits were retried to the limit and got nowhere.
*/
export function decideRateLimitRetry({
retryAfter,
retryCount,
maxRetries,
thresholdSeconds = RATE_LIMIT_FAST_FAIL_THRESHOLD_SECONDS,
}: {
retryAfter: number;
retryCount: number;
maxRetries: number;
thresholdSeconds?: number;
}): RateLimitRetryAction {
if (retryAfter > thresholdSeconds) {
return "fail-fast";
}
if (retryCount < maxRetries) {
return "retry";
}
return "give-up";
}
/**
* Throttling and rate-limit handling shared by every Octokit this module
* builds, authenticated or anonymous. `userId` is optional: without it the
@@ -45,10 +90,23 @@ function githubThrottleOptions(userId?: string) {
) => {
const isSearch = options.url.includes("/search/");
const maxRetries = isSearch ? 5 : 3; // Search endpoints get more retries
const action = decideRateLimitRetry({ retryAfter, retryCount, maxRetries });
const resetAt = new Date(Date.now() + retryAfter * 1000);
if (action === "fail-fast") {
// Record the reset for the whole source, not just this request: every
// other call on the same token would run into the same wall.
markRateLimited(rateLimitGateKey(userId), resetAt);
console.warn(
`[GitHub] Rate limit hit for ${options.method} ${options.url}. ` +
`The limit resets in ${retryAfter}s, over the ${RATE_LIMIT_FAST_FAIL_THRESHOLD_SECONDS}s a request may wait, ` +
`so this request fails now and GitHub work pauses until ${resetAt.toISOString()}.`,
);
} else {
console.warn(
`[GitHub] Rate limit hit for ${options.method} ${options.url}. Retry ${retryCount + 1}/${maxRetries}`,
);
}
// Update rate limit status and notify UI (if available)
if (userId && RateLimitManager) {
@@ -69,21 +127,28 @@ function githubThrottleOptions(userId?: string) {
retryAfter,
retryCount,
endpoint: options.url,
message: `Rate limit hit. Waiting ${retryAfter}s before retry ${retryCount + 1}/${maxRetries}...`,
resetAt: resetAt.toISOString(),
willRetry: action === "retry",
message:
action === "fail-fast"
? `Rate limit exceeded. GitHub work is paused until ${resetAt.toISOString()} and resumes automatically.`
: `Rate limit hit. Waiting ${retryAfter}s before retry ${retryCount + 1}/${maxRetries}...`,
},
});
}
// Retry with exponential backoff
if (retryCount < maxRetries) {
// Short waits are still slept off inside the request.
if (action === "retry") {
console.log(`[GitHub] Waiting ${retryAfter}s before retry...`);
return true;
}
// Max retries reached
if (action === "give-up") {
console.error(
`[GitHub] Max retries (${maxRetries}) reached for ${options.url}`,
);
}
return false;
},
onSecondaryRateLimit: async (
@@ -170,6 +235,19 @@ export function createGitHubClient(
throttle: githubThrottleOptions(userId),
});
// A response that still has budget means the limit is over, whatever reset
// time was recorded earlier. Open the gate so the scheduler resumes at once
// instead of sitting out the rest of a stale window. Some tests stub Octokit
// without the hook system; skip wiring in that case.
if (typeof (octokit as any)?.hook?.after === "function") {
octokit.hook.after("request", async (response: any) => {
const remaining = Number(response?.headers?.["x-ratelimit-remaining"]);
if (Number.isFinite(remaining) && remaining > 0) {
clearRateLimit(rateLimitGateKey(userId));
}
});
}
// Add rate limit tracking hooks if userId is provided and RateLimitManager is available
if (userId && RateLimitManager) {
octokit.hook.after("request", async (response: any, _options: any) => {
+156
View File
@@ -0,0 +1,156 @@
import { describe, expect, test, beforeEach } from "bun:test";
import {
TOKENLESS_RATE_LIMIT_KEY,
clearAllRateLimits,
clearRateLimit,
isRateLimitError,
markRateLimited,
rateLimitGateKey,
rateLimitedUntil,
} from "@/lib/rate-limit-gate";
describe("rate limit gate keys", () => {
beforeEach(() => {
clearAllRateLimits();
});
test("a user id is its own key and an empty one falls back to the tokenless key", () => {
expect(rateLimitGateKey("user-1")).toBe("user-1");
expect(rateLimitGateKey(" user-2 ")).toBe("user-2");
expect(rateLimitGateKey("")).toBe(TOKENLESS_RATE_LIMIT_KEY);
expect(rateLimitGateKey(" ")).toBe(TOKENLESS_RATE_LIMIT_KEY);
expect(rateLimitGateKey(undefined)).toBe(TOKENLESS_RATE_LIMIT_KEY);
expect(rateLimitGateKey(null)).toBe(TOKENLESS_RATE_LIMIT_KEY);
});
test("keys do not interfere with each other", () => {
const resetAt = new Date(Date.now() + 600_000);
markRateLimited("user-1", resetAt);
expect(rateLimitedUntil("user-1")?.getTime()).toBe(resetAt.getTime());
expect(rateLimitedUntil("user-2")).toBeNull();
expect(rateLimitedUntil(TOKENLESS_RATE_LIMIT_KEY)).toBeNull();
});
});
describe("rate limit gate state", () => {
beforeEach(() => {
clearAllRateLimits();
});
test("an unknown key is not limited", () => {
expect(rateLimitedUntil("user-1")).toBeNull();
});
test("a recorded reset is reported until it passes, then forgotten", () => {
const now = new Date("2026-01-01T09:00:00.000Z");
const resetAt = new Date("2026-01-01T09:30:00.000Z");
markRateLimited("user-1", resetAt);
expect(rateLimitedUntil("user-1", now)?.toISOString()).toBe(resetAt.toISOString());
const afterReset = new Date("2026-01-01T09:30:00.001Z");
expect(rateLimitedUntil("user-1", afterReset)).toBeNull();
// Reading past the reset drops the entry, so the gate opens on its own.
expect(rateLimitedUntil("user-1", now)).toBeNull();
});
test("a reset exactly at the current time is already over", () => {
const now = new Date("2026-01-01T09:00:00.000Z");
markRateLimited("user-1", now);
expect(rateLimitedUntil("user-1", now)).toBeNull();
});
test("the furthest reset wins", () => {
const now = new Date("2026-01-01T09:00:00.000Z");
const nearer = new Date("2026-01-01T09:10:00.000Z");
const further = new Date("2026-01-01T09:45:00.000Z");
markRateLimited("user-1", nearer);
markRateLimited("user-1", further);
expect(rateLimitedUntil("user-1", now)?.toISOString()).toBe(further.toISOString());
// A later call reporting a nearer reset must not shorten the pause.
markRateLimited("user-1", nearer);
expect(rateLimitedUntil("user-1", now)?.toISOString()).toBe(further.toISOString());
});
test("epoch milliseconds are accepted and nonsense is ignored", () => {
const now = new Date("2026-01-01T09:00:00.000Z");
const resetAt = new Date("2026-01-01T09:20:00.000Z");
markRateLimited("user-1", resetAt.getTime());
expect(rateLimitedUntil("user-1", now)?.toISOString()).toBe(resetAt.toISOString());
markRateLimited("user-2", Number.NaN);
markRateLimited("user-3", new Date("not a date"));
expect(rateLimitedUntil("user-2", now)).toBeNull();
expect(rateLimitedUntil("user-3", now)).toBeNull();
});
test("clearRateLimit opens one key and clearAllRateLimits opens every key", () => {
const resetAt = new Date(Date.now() + 600_000);
markRateLimited("user-1", resetAt);
markRateLimited("user-2", resetAt);
clearRateLimit("user-1");
expect(rateLimitedUntil("user-1")).toBeNull();
expect(rateLimitedUntil("user-2")).not.toBeNull();
clearAllRateLimits();
expect(rateLimitedUntil("user-2")).toBeNull();
});
});
describe("isRateLimitError", () => {
test("recognises Octokit's primary rate limit refusal", () => {
const error = Object.assign(
new Error("API rate limit exceeded for user ID 1234."),
{ status: 403 }
);
expect(isRateLimitError(error)).toBe(true);
});
test("recognises the secondary rate limit and 429", () => {
const secondary = Object.assign(
new Error("You have exceeded a secondary rate limit."),
{ status: 403 }
);
expect(isRateLimitError(secondary)).toBe(true);
const tooManyRequests = Object.assign(new Error("Too Many Requests"), { status: 429 });
expect(isRateLimitError(tooManyRequests)).toBe(true);
});
test("reads the status off a nested response when the error does not carry one", () => {
const error = Object.assign(new Error("Too Many Requests"), {
response: { status: 429 },
});
expect(isRateLimitError(error)).toBe(true);
});
test("recognises a rate limit that was re-thrown with only its message", () => {
// gitea.ts wraps mirror failures in a plain Error, so no status survives
// to the scheduler.
const wrapped = new Error(
"Failed to mirror repository: API rate limit exceeded for user ID 1234."
);
expect(isRateLimitError(wrapped)).toBe(true);
});
test("ignores everything else", () => {
expect(isRateLimitError(null)).toBe(false);
expect(isRateLimitError(undefined)).toBe(false);
expect(isRateLimitError(new Error("Repository not found in Gitea"))).toBe(false);
expect(
isRateLimitError(Object.assign(new Error("Bad credentials"), { status: 401 }))
).toBe(false);
// A 404 body that happens to mention the phrase is not a refusal to serve.
expect(
isRateLimitError(
Object.assign(new Error("see the rate limit documentation"), { status: 404 })
)
).toBe(false);
});
});
+114
View File
@@ -0,0 +1,114 @@
/**
* In-memory gate for source rate limits (issue #437).
*
* A GitHub primary rate limit resets at a fixed time that can be close to an
* hour away. Sleeping through that window inside an Octokit request holds the
* scheduler lock for the whole run, and every following tick logs "Scheduler
* is already running, skipping this cycle" until the process restarts.
*
* The throttle handler records the reset here and fails the request instead of
* sleeping. The scheduler reads the gate between batches and between
* repositories, ends the run early and schedules the next one just after the
* reset, so nothing is stuck and the lock is released as usual.
*
* The state is process local on purpose: it is a coordination hint for the
* work running right now, not durable state. RateLimitManager
* (src/lib/rate-limit-manager.ts) still persists the per-user numbers.
*/
/** Gate key for clients built without a user, such as tokenless public sources. */
export const TOKENLESS_RATE_LIMIT_KEY = "anonymous";
/** Reset time (epoch ms) per key, for the keys that are currently limited. */
const resetTimesByKey = new Map<string, number>();
/**
* The gate key for a user. Clients created without a userId share one key, so
* a tokenless source that runs into the anonymous limit still pauses.
*/
export function rateLimitGateKey(userId?: string | null): string {
const trimmed = typeof userId === "string" ? userId.trim() : "";
return trimmed === "" ? TOKENLESS_RATE_LIMIT_KEY : trimmed;
}
/**
* Record that this key is rate limited until `resetAt`. A reset that is
* further out than the one already recorded wins: two endpoints can report
* different windows and the work has to wait for the later one.
*/
export function markRateLimited(key: string, resetAt: Date | number): void {
const resetMs = resetAt instanceof Date ? resetAt.getTime() : resetAt;
if (!Number.isFinite(resetMs)) {
return;
}
const current = resetTimesByKey.get(key);
if (current !== undefined && current >= resetMs) {
return;
}
resetTimesByKey.set(key, resetMs);
}
/**
* The reset time while the key is still rate limited, otherwise null. A reset
* that has passed is forgotten on read, so the gate opens on its own.
*/
export function rateLimitedUntil(key: string, now: Date = new Date()): Date | null {
const resetMs = resetTimesByKey.get(key);
if (resetMs === undefined) {
return null;
}
if (resetMs <= now.getTime()) {
resetTimesByKey.delete(key);
return null;
}
return new Date(resetMs);
}
/** Open the gate for one key, for example after a request came back with budget left. */
export function clearRateLimit(key: string): void {
resetTimesByKey.delete(key);
}
/** Open the gate for every key. Used by tests and by a full restart of the scheduler. */
export function clearAllRateLimits(): void {
resetTimesByKey.clear();
}
/**
* Whether an error is a rate limit refusal from the source.
*
* Octokit raises 403 with "rate limit" in the message for the primary and
* secondary limits and 429 for too many requests. Callers in between re-throw
* some of those with only the message (gitea.ts wraps mirror failures in a
* plain Error), so the message alone has to be enough when no status survived.
*/
export function isRateLimitError(error: unknown): boolean {
if (!error) {
return false;
}
const candidate = error as { status?: unknown; response?: { status?: unknown }; message?: unknown };
const rawStatus = candidate.status ?? candidate.response?.status;
const status = typeof rawStatus === "number" ? rawStatus : undefined;
if (status === 429) {
return true;
}
const message =
typeof candidate.message === "string" ? candidate.message : String(error);
const mentionsRateLimit = /rate limit/i.test(message);
if (!mentionsRateLimit) {
return false;
}
// With a status attached, only the two GitHub uses of the phrase count.
// Without one the error has been re-thrown along the way, and the message is
// all that is left to go on.
return status === undefined || status === 403;
}
+153 -3
View File
@@ -1,5 +1,10 @@
import { describe, test, expect, mock, beforeEach } from "bun:test";
import { repoStatusEnum } from "@/types/Repository";
import {
clearAllRateLimits,
markRateLimited,
rateLimitGateKey,
} from "@/lib/rate-limit-gate";
import type { Repository } from "./db/schema";
// ---------------------------------------------------------------------------
@@ -188,7 +193,11 @@ const configsTable = { __table: "configs" } as any;
let configRows: any[] = [];
let orgRows: any[] = [];
let repoRows: any[] = [];
// Rows the unprojected repository selects return: the auto-mirror and sync
// pools. Empty for the discovery scenarios, filled by the rate limit ones.
let poolRows: any[] = [];
let orgUpdates: Array<Record<string, any>> = [];
let configUpdates: Array<Record<string, any>> = [];
let repoInsertAttempts = 0;
const publicOnlySource = {
@@ -212,6 +221,8 @@ const orgRepoListings = new Map<string, any[]>();
const mockListOrganizationRepositories = mock(async (name: string) =>
orgRepoListings.get(name) ?? []
);
const mockMirrorRepositoryToDestination = mock(async () => {});
const mockSyncRepositoryOnDestination = mock(async () => {});
const mockCreateSourceProviderFromSource = mock(() => ({
listRepositories: mockListRepositories,
listStarredRepositories: mockListStarredRepositories,
@@ -230,7 +241,7 @@ if (isChild) {
if (table === configsTable) return Promise.resolve(configRows);
if (table === organizationsTable) return Promise.resolve(orgRows);
if (table === repositoriesTable) {
return Promise.resolve(fields ? repoRows : []);
return Promise.resolve(fields ? repoRows : poolRows);
}
return Promise.resolve([]);
},
@@ -262,6 +273,7 @@ if (isChild) {
set: (data: any) => ({
where: (_cond: any) => {
if (table === organizationsTable) orgUpdates.push(data);
if (table === configsTable) configUpdates.push(data);
return Promise.resolve();
},
}),
@@ -305,8 +317,8 @@ if (isChild) {
}));
mock.module("@/lib/mirror-dispatch", () => ({
mirrorRepositoryToDestination: mock(async () => {}),
syncRepositoryOnDestination: mock(async () => {}),
mirrorRepositoryToDestination: mockMirrorRepositoryToDestination,
syncRepositoryOnDestination: mockSyncRepositoryOnDestination,
}));
}
@@ -400,8 +412,11 @@ describe.skipIf(!isChild)("Scheduler public-only sources (WP4)", () => {
}),
];
repoRows = [];
poolRows = [];
orgUpdates = [];
configUpdates = [];
repoInsertAttempts = 0;
clearAllRateLimits();
orgRepoListings.clear();
mockListRepositories.mockClear();
mockListStarredRepositories.mockClear();
@@ -496,3 +511,138 @@ describe.skipIf(!isChild)("Scheduler public-only sources (WP4)", () => {
expect(consoleLines.some((line) => line.includes("already tracked") && line.includes("pinned-org"))).toBe(true);
});
});
// ---------------------------------------------------------------------------
// Rate limit gate (issue #437).
//
// A scheduled run used to sit inside Octokit until the GitHub limit reset,
// which held the scheduler lock for the whole run: every later tick logged
// "Scheduler is already running, skipping this cycle" and nothing synced until
// the container was restarted. The throttle handler now records the reset on
// the gate and fails the request, and the run below has to notice that and
// stop by itself.
// ---------------------------------------------------------------------------
function makeSyncRow(name: string, overrides: Record<string, any> = {}): any {
return {
id: `repo-${name}`,
userId: "user-1",
sourceId: "source-public",
name,
fullName: `pinned-org/${name}`,
normalizedFullName: `pinned-org/${name}`,
owner: "pinned-org",
organization: "pinned-org",
sourceProvider: "github",
sourceUrl: "https://github.com",
status: "mirrored",
isStarred: false,
isForked: false,
isPrivate: false,
visibility: "public",
mirroredLocation: `gitea-org/${name}`,
lastMirrored: null,
errorMessage: null,
forkedFrom: null,
createdAt: new Date(0),
updatedAt: new Date(0),
...overrides,
};
}
describe.skipIf(!isChild)("Scheduler rate limit gate (#437)", () => {
let consoleLines: string[];
beforeEach(() => {
consoleLines = [];
const capture = mock((...args: unknown[]) => {
consoleLines.push(args.map((arg) => (typeof arg === "string" ? arg : String(arg))).join(" "));
}) as any;
console.log = capture;
console.warn = capture;
console.error = capture;
configRows = [makeSchedulerConfig()];
orgRows = [];
repoRows = [];
poolRows = [];
orgUpdates = [];
configUpdates = [];
repoInsertAttempts = 0;
orgRepoListings.clear();
mockListOrganizationRepositories.mockClear();
mockMirrorRepositoryToDestination.mockClear();
mockSyncRepositoryOnDestination.mockClear();
clearAllRateLimits();
});
test("a run that starts rate limited is skipped and comes back just after the reset", async () => {
const resetAt = new Date(Date.now() + 45 * 60 * 1000);
markRateLimited(rateLimitGateKey("user-1"), resetAt);
poolRows = [makeSyncRow("alpha"), makeSyncRow("beta")];
await schedulerLoop();
expect(mockSyncRepositoryOnDestination).not.toHaveBeenCalled();
expect(
consoleLines.some(
(line) => line.includes("rate limited until") && line.includes("skipping this run")
)
).toBe(true);
const nextRun = configUpdates.at(-1)?.scheduleConfig?.nextRun as Date;
expect(nextRun).toBeInstanceOf(Date);
expect(nextRun.getTime()).toBe(resetAt.getTime() + 60_000);
});
test("a rate limit hit mid-run stops the sync loop and leaves the rest for the next run", async () => {
const resetAt = new Date(Date.now() + 45 * 60 * 1000);
orgRows = [makeOrgRow()];
orgRepoListings.set("pinned-org", [makeGitRepo("existing")]);
poolRows = [makeSyncRow("alpha"), makeSyncRow("beta"), makeSyncRow("gamma")];
// Stands in for the throttle handler: discovery runs into the limit and
// records the reset instead of sleeping through it.
mockListOrganizationRepositories.mockImplementationOnce(async () => {
markRateLimited(rateLimitGateKey("user-1"), resetAt);
throw Object.assign(new Error("API rate limit exceeded for user ID 1."), { status: 403 });
});
await schedulerLoop();
// The run reached the sync phase and then stopped without syncing anything.
expect(consoleLines.some((line) => line.includes("Syncing 3 repositories for user user-1"))).toBe(true);
expect(mockSyncRepositoryOnDestination).not.toHaveBeenCalled();
expect(
consoleLines.some(
(line) =>
line.includes("rate limited until") &&
line.includes("leaving 3 repositories to sync on the next run")
)
).toBe(true);
// The lock is released, so the next tick is free to run.
expect(consoleLines.some((line) => line.includes("already running"))).toBe(false);
const nextRun = configUpdates.at(-1)?.scheduleConfig?.nextRun as Date;
expect(nextRun.getTime()).toBe(resetAt.getTime() + 60_000);
});
test("the gate only logs once per run", async () => {
markRateLimited(rateLimitGateKey("user-1"), new Date(Date.now() + 45 * 60 * 1000));
poolRows = [makeSyncRow("alpha")];
await schedulerLoop();
const gateLines = consoleLines.filter((line) => line.includes("rate limited until"));
expect(gateLines).toHaveLength(1);
});
test("a run that is not rate limited syncs every repository as before", async () => {
poolRows = [makeSyncRow("alpha"), makeSyncRow("beta")];
await schedulerLoop();
expect(mockSyncRepositoryOnDestination).toHaveBeenCalledTimes(2);
expect(consoleLines.some((line) => line.includes("rate limited until"))).toBe(false);
expect(consoleLines.some((line) => line.includes("Completed scheduled sync for user user-1"))).toBe(true);
});
});
+180 -4
View File
@@ -26,6 +26,7 @@ import { loadOrganizationForkPolicies, orgForkSkipDecision, resolveOrganizationS
import { createMirrorJob } from '@/lib/helpers';
import { getNextScheduledRun, isCronExpression, normalizeTimezone } from '@/lib/utils/schedule-utils';
import { resetStuckMirrorStatuses } from '@/lib/stuck-status-recovery';
import { isRateLimitError, rateLimitGateKey, rateLimitedUntil } from '@/lib/rate-limit-gate';
import type { SourceRecord } from '@/lib/sources';
let schedulerInterval: NodeJS.Timeout | null = null;
@@ -86,6 +87,103 @@ async function persistScheduleRunState(config: any, currentTime: Date, forceEnab
return nextRun;
}
/** Head start the next run gets after a rate limit reset, so the window is really over. */
const RATE_LIMIT_RESUME_MARGIN_MS = 60 * 1000;
/**
* Watches the rate limit gate for one run.
*
* A run used to sit inside Octokit until the limit reset, which held the
* scheduler lock for up to an hour per repository and left every later tick
* logging "Scheduler is already running" (issue #437). The throttle handler
* now records the reset instead of sleeping, and the loops below ask this
* watcher between batches and between repositories whether to stop. Only the
* first stop is logged, so a long batch loop does not repeat itself.
*/
function createRateLimitWatcher(userId: string) {
const key = rateLimitGateKey(userId);
let logged = false;
return {
/** The reset time when the source is paused, otherwise null. */
check(describeEffect: () => string): Date | null {
const until = rateLimitedUntil(key);
if (!until) {
return null;
}
if (!logged) {
logged = true;
console.warn(
`[Scheduler] Source is rate limited until ${until.toISOString()} for user ${userId}, ${describeEffect()}`
);
}
return until;
},
/** The reset time without logging, for the next run calculation. */
current(): Date | null {
return rateLimitedUntil(key);
},
};
}
/**
* Bring the next run forward to just after the rate limit reset.
*
* Without this the run that stopped early would keep the schedule's own
* nextRun, so a daily cron would leave the remaining repositories untouched
* for a day even though the limit is back minutes later.
*/
async function persistRateLimitedNextRun(config: any, currentTime: Date, resetAt: Date): Promise<Date> {
const scheduleConfig = config.scheduleConfig || {};
const nextRun = new Date(resetAt.getTime() + RATE_LIMIT_RESUME_MARGIN_MS);
await db.update(configs).set({
scheduleConfig: {
...scheduleConfig,
lastRun: currentTime,
nextRun,
},
updatedAt: new Date(),
}).where(eq(configs.id, config.id));
console.log(
`[Scheduler] Next sync for user ${config.userId} moved to ${nextRun.toISOString()} to resume after the rate limit reset`
);
return nextRun;
}
/**
* Put a repository back to the status it had before an attempt that only
* failed because of a rate limit.
*
* The mirror and sync paths write "failed" on any error, which leaves the row
* waiting for a manual retry. A rate limit is not a repository failure, and
* the scheduler already re-syncs "failed", "mirrored", "synced" and "pending"
* rows, so restoring the previous status is enough for the run after the reset
* to pick the repository up on its own.
*/
async function restoreRepositoryAfterRateLimit(
repo: { id: string; fullName: string; status: string },
phase: string
): Promise<void> {
try {
await db.update(repositories).set({
status: repo.status,
updatedAt: new Date(),
}).where(eq(repositories.id, repo.id));
console.warn(
`[Scheduler] ${repo.fullName} hit the source rate limit during ${phase}; ` +
`left it as "${repo.status}" so it is retried after the reset instead of needing a manual retry`
);
} catch (error) {
console.error(`[Scheduler] Failed to restore the status of ${repo.fullName} after a rate limit:`, error);
}
}
/**
* Auto-discovery: import new repositories from every enabled source. Shared
* by the scheduled-sync phase and the boot auto-start phase. A failing
@@ -390,6 +488,7 @@ function dropDuplicateRowsForPass<T extends { fullName: string; sourceId?: strin
async function runScheduledSync(config: any): Promise<void> {
const userId = config.userId;
const rateLimit = createRateLimitWatcher(userId);
console.log(`[Scheduler] Running scheduled sync for user ${userId}`);
try {
@@ -408,6 +507,15 @@ async function runScheduledSync(config: any): Promise<void> {
console.log(`[Scheduler] Using schedule source for user ${userId}: ${String(source)} (timezone=${timezone})`);
await persistScheduleRunState(config, currentTime);
// A rate limit left open by an earlier run (or by the boot auto-start)
// would fail every source call here. Skip the whole run and come back
// just after the reset instead of burning a tick on failures.
const pausedAtStart = rateLimit.check(() => 'skipping this run');
if (pausedAtStart) {
await persistRateLimitedNextRun(config, currentTime, pausedAtStart);
return;
}
// Auto-discovery: Check for new repositories on every enabled source
if (scheduleConfig.autoImport !== false) {
console.log(`[Scheduler] Checking for new source repositories for user ${userId}...`);
@@ -529,11 +637,20 @@ async function runScheduledSync(config: any): Promise<void> {
const batchSize = scheduleConfig.batchSize || 10;
const pauseBetweenBatches = scheduleConfig.pauseBetweenBatches || 2000;
for (let i = 0; i < reposNeedingMirror.length; i += batchSize) {
const remaining = reposNeedingMirror.length - i;
if (rateLimit.check(() => `leaving ${remaining} repositories to auto-mirror on the next run`)) {
break;
}
const batch = reposNeedingMirror.slice(i, Math.min(i + batchSize, reposNeedingMirror.length));
console.log(`[Scheduler] Auto-mirror batch ${Math.floor(i / batchSize) + 1} of ${Math.ceil(reposNeedingMirror.length / batchSize)} (${batch.length} repos)`);
await Promise.all(
batch.map(async (repo) => {
if (rateLimit.check(() => `leaving ${remaining} repositories to auto-mirror on the next run`)) {
return;
}
try {
const repository: Repository = {
...repo,
@@ -570,6 +687,10 @@ async function runScheduledSync(config: any): Promise<void> {
await mirrorRepositoryToDestination({ octokit: await resolveOctokit(repo), repository, config });
console.log(`[Scheduler] Auto-mirrored repository: ${repo.fullName}`);
} catch (error) {
if (isRateLimitError(error)) {
await restoreRepositoryAfterRateLimit(repo, 'auto-mirror');
return;
}
console.error(`[Scheduler] Failed to auto-mirror repository ${repo.fullName}:`, error);
}
})
@@ -650,6 +771,10 @@ async function runScheduledSync(config: any): Promise<void> {
if (reposToSync.length === 0) {
console.log(`[Scheduler] No repositories to sync for user ${userId}`);
const pausedAfterMirror = rateLimit.current();
if (pausedAfterMirror) {
await persistRateLimitedNextRun(config, currentTime, pausedAfterMirror);
}
return;
}
@@ -660,7 +785,11 @@ async function runScheduledSync(config: any): Promise<void> {
const pauseBetweenBatches = scheduleConfig.pauseBetweenBatches || 5000;
const concurrent = scheduleConfig.concurrent ?? false;
for (let i = 0; i < reposToSync.length; i += batchSize) {
syncBatches: for (let i = 0; i < reposToSync.length; i += batchSize) {
if (rateLimit.check(() => `leaving ${reposToSync.length - i} repositories to sync on the next run`)) {
break;
}
const batch = reposToSync.slice(i, i + batchSize);
if (concurrent) {
@@ -670,8 +799,11 @@ async function runScheduledSync(config: any): Promise<void> {
);
} else {
// Process batch sequentially
for (const repo of batch) {
await syncSingleRepository(config, repo);
for (let j = 0; j < batch.length; j++) {
if (rateLimit.check(() => `leaving ${reposToSync.length - i - j} repositories to sync on the next run`)) {
break syncBatches;
}
await syncSingleRepository(config, batch[j]);
}
}
@@ -681,6 +813,15 @@ async function runScheduledSync(config: any): Promise<void> {
}
}
// A run that stopped on the rate limit comes back just after the reset,
// not at the schedule's own next slot, so the repositories it left behind
// are not held for a whole cron period.
const pausedUntil = rateLimit.current();
if (pausedUntil) {
await persistRateLimitedNextRun(config, currentTime, pausedUntil);
return;
}
console.log(`[Scheduler] Completed scheduled sync for user ${userId}`);
} catch (error) {
console.error(`[Scheduler] Error during scheduled sync for user ${userId}:`, error);
@@ -706,6 +847,14 @@ async function syncSingleRepository(config: any, repo: any): Promise<void> {
await syncRepositoryOnDestination({ config, repository });
console.log(`[Scheduler] Successfully synced repository ${repo.fullName}`);
} catch (error) {
// The sync path claimed the row as "syncing" and the failure handler below
// it wrote "failed". A rate limit is not the repository's fault, so put the
// row back where it was and let the run after the reset retry it.
if (isRateLimitError(error)) {
await restoreRepositoryAfterRateLimit(repo, 'sync');
return;
}
console.error(`[Scheduler] Failed to sync repository ${repo.fullName}:`, error);
// Update repository status to failed
@@ -790,6 +939,12 @@ async function performInitialAutoStart(): Promise<void> {
console.log(`[Scheduler] Auto-starting for user ${config.userId}...`);
// Auto-start runs outside the scheduler lock, but it mirrors the same
// repositories and must stop on a rate limit too: otherwise it keeps
// failing every repository in turn and hands the scheduler a pile of
// rows marked "failed" (issue #437).
const rateLimit = createRateLimitWatcher(config.userId);
try {
// Step 1: Import repositories from every enabled source
console.log(`[Scheduler] Step 1: Importing repositories from the configured sources for user ${config.userId}...`);
@@ -883,11 +1038,20 @@ async function performInitialAutoStart(): Promise<void> {
// Process repositories in batches
const batchSize = config.scheduleConfig?.batchSize || 5;
for (let i = 0; i < reposNeedingMirror.length; i += batchSize) {
const remaining = reposNeedingMirror.length - i;
if (rateLimit.check(() => `leaving ${remaining} repositories for the first scheduled run`)) {
break;
}
const batch = reposNeedingMirror.slice(i, Math.min(i + batchSize, reposNeedingMirror.length));
console.log(`[Scheduler] Processing batch ${Math.floor(i / batchSize) + 1} of ${Math.ceil(reposNeedingMirror.length / batchSize)} (${batch.length} repos)`);
await Promise.all(
batch.map(async (repo) => {
if (rateLimit.check(() => `leaving ${remaining} repositories for the first scheduled run`)) {
return;
}
try {
const repository: Repository = {
...repo,
@@ -907,6 +1071,10 @@ async function performInitialAutoStart(): Promise<void> {
});
console.log(`[Scheduler] Successfully mirrored repository: ${repo.fullName}`);
} catch (error) {
if (isRateLimitError(error)) {
await restoreRepositoryAfterRateLimit(repo, 'auto-start mirror');
return;
}
console.error(`[Scheduler] Failed to mirror repository ${repo.fullName}:`, error);
}
})
@@ -927,7 +1095,15 @@ async function performInitialAutoStart(): Promise<void> {
// Update the schedule config to indicate we've run
const currentTime = new Date();
const nextRun = await persistScheduleRunState(config, currentTime, true);
let nextRun = await persistScheduleRunState(config, currentTime, true);
// A rate limit that stopped the initial mirror also moves the first
// scheduled run to just after the reset, so the repositories left
// behind are not held for a whole schedule period.
const pausedUntil = rateLimit.current();
if (pausedUntil) {
nextRun = await persistRateLimitedNextRun(config, currentTime, pausedUntil);
}
console.log(`[Scheduler] Auto-start completed for user ${config.userId}, next sync at ${nextRun.toISOString()}`);