diff --git a/FORK.md b/FORK.md index 827afe10..7fa1ef4b 100644 --- a/FORK.md +++ b/FORK.md @@ -75,6 +75,44 @@ Two details worth keeping if this is ever rewritten: - `pollTracker` now selects `HNR_HISTORY_POLLS` snapshots instead of 1. Only the HnR check reads the extra rows; every other comparison still uses `previousSnapshot`. +## Only credential failures pause a tracker (2.8.9-homelab.7) + +Upstream auto-pauses a tracker after `POLL_FAILURE_THRESHOLD` (4) consecutive failures, whatever +the cause, and a paused tracker only resumes when someone clicks Resume. Two details make that far +more fragile than it looks: + +- A failed poll leaves `lastPolledAt` untouched, so a failing tracker is permanently "overdue" and + is retried on **every 5-minute scheduler tick**, not on the hourly poll interval. +- Four ticks is therefore **20 minutes**. Any outage longer than that pauses the tracker for good. + +On 2026-08-16 a home internet outage did exactly that to all six trackers at once. Nothing resumed +them. The container stayed up the whole time, so the container-level health check stayed green and +the fault went unnoticed for **33.5 hours** — during which the MyAnonaMouse balance hit its 99,999 +point cap and burned roughly 5,000 points, about 10 GiB of upload credit. + +`src/lib/poll-failure-policy.ts` inverts the default. Only a failure a human must actually fix — +`Authentication failed`, `Session expired`, `Invalid credentials` — can set `pausedAt`. Everything +else keeps counting failures, so the UI still shows the fault, but is retried forever under +exponential backoff: 5m, 10m, 20m, 40m, then hourly. Connectivity problems now heal by themselves +within an hour of the network returning. + +Details worth keeping in a rewrite: + +- Classification runs on the **output of `sanitizeNetworkError`**, not the raw error, so it matches + a small fixed set of phrases rather than guessing at driver-specific text. The unclassified + fallback `"Poll failed"` is deliberately transient — that is what the real outage produced, and + treating an unknown error as permanent is what caused the incident. +- Rate-limit and IP-ban errors are transient but jump **straight to the 60-minute cap**, since + retrying at the normal cadence is what provokes them. +- On the transient path `pausedAt` is set to the **column reference** (`paused_at = paused_at`), a + no-op self-assign. It must never be a literal, which would clobber a genuine pause. +- The backoff gate lives in the `pollAllTrackers` overdue filter, keyed off `lastErrorAt`. Without + it, removing the pause would mean retrying every 5 minutes forever. + +The dashboard side of this incident is fixed separately, in the homelab repo — a heartbeat sender +that alerts on **snapshot staleness** rather than container liveness, since liveness was never the +thing worth watching. + ## Workflow edits (the main sync-conflict surface) `.github/workflows/release.yml` is patched. Upstream's version **cannot publish from a fork** — diff --git a/package.json b/package.json index 3dc925e2..f2ca87f2 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "private-tracker-tracker", - "version": "2.8.9-homelab.6", + "version": "2.8.9-homelab.7", "description": "Self-hosted dashboard for monitoring private tracker stats over time", "license": "GPL-3.0", "repository": { diff --git a/src/lib/__tests__/circuit-breaker.test.ts b/src/lib/__tests__/circuit-breaker.test.ts index b8102b4a..32a9332f 100644 --- a/src/lib/__tests__/circuit-breaker.test.ts +++ b/src/lib/__tests__/circuit-breaker.test.ts @@ -361,7 +361,36 @@ describe("pollTracker: failure path — consecutiveFailures increment", () => { const arg = (failureSetCall as unknown[])[0] as Record // consecutiveFailures must be an actual Drizzle SQL expression, not a literal number expect(arg.consecutiveFailures).toBeInstanceOf(SQL) - // pausedAt must also be a Drizzle SQL expression (CASE … END), not a raw value + // "Connection refused" is transient, so pausedAt must be left exactly as it + // is: a self-assign of the column, never a literal that could clobber it. + // A transient failure must never be able to pause a tracker, because that + // is how a brief outage blinded all six trackers on 2026-08-16. + const { trackers } = await import("@/lib/db/schema") + expect(arg.pausedAt).toBe(trackers.pausedAt) + expect(arg.pausedAt).not.toBeInstanceOf(SQL) + }) + + it("uses the CASE expression to pause only on a credential failure", async () => { + ;(db.select as ReturnType).mockReturnValue( + mockSelectOnce([makeTrackerRow({ consecutiveFailures: 3 })]) + ) + // sanitizeNetworkError is mocked to an identity here, so throw the phrase + // it would really produce. A dead session is the one class of failure a + // human actually has to fix, so it is allowed to pause the tracker. + mockFailureAdapter("Session expired") + const updateChain = mockUpdateChain([ + { consecutiveFailures: POLL_FAILURE_THRESHOLD, pausedAt: new Date() }, + ]) + + await pollTracker(1, MOCK_KEY, false) + + const failureSetCall = updateChain.set.mock.calls.find((call: unknown[]) => { + const arg = call[0] as Record + return arg.lastError !== undefined + }) + expect(failureSetCall).toBeDefined() + const arg = (failureSetCall as unknown[])[0] as Record + expect(arg.lastError).toBe("Session expired") expect(arg.pausedAt).toBeInstanceOf(SQL) }) diff --git a/src/lib/__tests__/poll-failure-policy.test.ts b/src/lib/__tests__/poll-failure-policy.test.ts new file mode 100644 index 00000000..d836f20e --- /dev/null +++ b/src/lib/__tests__/poll-failure-policy.test.ts @@ -0,0 +1,111 @@ +import { describe, expect, it } from "vitest" +import { + isPermanentPollFailure, + isRateLimitFailure, + isWithinRetryBackoff, + POLL_RETRY_BASE_MS, + POLL_RETRY_MAX_MS, + pollRetryDelayMs, +} from "@/lib/poll-failure-policy" + +describe("isPermanentPollFailure", () => { + it.each(["Authentication failed", "Session expired", "Invalid credentials"])( + "treats %s as permanent", + (msg) => { + expect(isPermanentPollFailure(msg)).toBe(true) + } + ) + + // These are exactly the messages the 2026-08-16 outage produced. If any of + // them ever pauses a tracker again, monitoring can blind itself on a blip. + it.each([ + "Poll failed", + "Request timed out", + "Connection refused", + "Host not found", + "Host unreachable", + "Connection reset", + "Proxy connection failed", + "API returned 500", + ])("treats %s as transient", (msg) => { + expect(isPermanentPollFailure(msg)).toBe(false) + }) + + it("handles null and empty messages", () => { + expect(isPermanentPollFailure(null)).toBe(false) + expect(isPermanentPollFailure(undefined)).toBe(false) + expect(isPermanentPollFailure("")).toBe(false) + }) +}) + +describe("isRateLimitFailure", () => { + it("detects tracker-side throttling", () => { + expect(isRateLimitFailure("IP temporarily banned by tracker")).toBe(true) + expect(isRateLimitFailure("rate limit exceeded")).toBe(true) + expect(isRateLimitFailure("Request timed out")).toBe(false) + }) +}) + +describe("pollRetryDelayMs", () => { + it("doubles per failure up to the cap", () => { + expect(pollRetryDelayMs(1)).toBe(POLL_RETRY_BASE_MS) + expect(pollRetryDelayMs(2)).toBe(POLL_RETRY_BASE_MS * 2) + expect(pollRetryDelayMs(3)).toBe(POLL_RETRY_BASE_MS * 4) + expect(pollRetryDelayMs(4)).toBe(POLL_RETRY_BASE_MS * 8) + expect(pollRetryDelayMs(5)).toBe(POLL_RETRY_MAX_MS) + }) + + it("never exceeds the cap, even for absurd failure counts", () => { + expect(pollRetryDelayMs(500)).toBe(POLL_RETRY_MAX_MS) + expect(Number.isFinite(pollRetryDelayMs(500))).toBe(true) + }) + + it("returns zero when there are no failures", () => { + expect(pollRetryDelayMs(0)).toBe(0) + expect(pollRetryDelayMs(-3)).toBe(0) + }) + + it("sends rate-limit failures straight to the cap", () => { + expect(pollRetryDelayMs(1, "IP temporarily banned by tracker")).toBe(POLL_RETRY_MAX_MS) + }) +}) + +describe("isWithinRetryBackoff", () => { + const now = Date.UTC(2026, 7, 17, 12, 0, 0) + + it("is never in backoff with a clean record", () => { + expect( + isWithinRetryBackoff({ consecutiveFailures: 0, lastErrorAt: new Date(now) }, now) + ).toBe(false) + }) + + it("blocks a retry inside the window and allows it after", () => { + const tracker = { + consecutiveFailures: 3, // 20 minute backoff + lastError: "Request timed out", + lastErrorAt: new Date(now - 19 * 60_000), + } + expect(isWithinRetryBackoff(tracker, now)).toBe(true) + expect(isWithinRetryBackoff({ ...tracker, lastErrorAt: new Date(now - 21 * 60_000) }, now)).toBe( + false + ) + }) + + it("stays due when lastErrorAt is missing or unparseable", () => { + expect(isWithinRetryBackoff({ consecutiveFailures: 3, lastErrorAt: null }, now)).toBe(false) + expect(isWithinRetryBackoff({ consecutiveFailures: 3, lastErrorAt: "nonsense" }, now)).toBe( + false + ) + }) + + it("recovers within an hour of a long outage ending", () => { + // 40 consecutive failures pins the delay at the 60 minute cap, so the + // tracker still gets an attempt every hour and heals on its own. + const tracker = { + consecutiveFailures: 40, + lastError: "Poll failed", + lastErrorAt: new Date(now - 61 * 60_000), + } + expect(isWithinRetryBackoff(tracker, now)).toBe(false) + }) +}) diff --git a/src/lib/poll-failure-policy.ts b/src/lib/poll-failure-policy.ts new file mode 100644 index 00000000..c3bfafc2 --- /dev/null +++ b/src/lib/poll-failure-policy.ts @@ -0,0 +1,87 @@ +// src/lib/poll-failure-policy.ts +// +// Functions: isPermanentPollFailure, isRateLimitFailure, pollRetryDelayMs +// +// Decides whether a failed poll should permanently stop a tracker, or merely +// slow it down. +// +// Background: the circuit breaker used to auto-pause any tracker after +// POLL_FAILURE_THRESHOLD consecutive failures, regardless of cause, and a +// paused tracker only resumes when a human clicks Resume. Since a failed poll +// leaves lastPolledAt untouched, a failing tracker is retried on every 5-minute +// scheduler tick, so four failures take only ~20 minutes to accumulate. A home +// internet outage of twenty minutes was therefore enough to permanently +// disable monitoring for every tracker at once, which is exactly what happened +// on 2026-08-16: all six trackers paused, nothing resumed them, and the fault +// went unnoticed for 33.5 hours because the container itself stayed up. +// +// The fix inverts the default. Only a failure a human must actually fix -- bad +// or expired credentials -- pauses a tracker. Everything else is assumed +// transient and retried forever under exponential backoff, so connectivity +// problems heal by themselves once the network returns. + +/** + * Failures that will never resolve on their own, because they need someone to + * supply a new credential. Matched against the output of sanitizeNetworkError, + * which has already normalised the raw error into a fixed set of phrases. + */ +const PERMANENT_FAILURES = [ + "Authentication failed", + "Session expired", + "Invalid credentials", +] as const + +/** + * Backoff bounds. The base matches the scheduler tick, so the first retry is + * unchanged from the old behaviour and only sustained failure slows down. The + * cap is the default poll interval -- during a long outage a tracker retries + * hourly, which is frequent enough to recover promptly and quiet enough not to + * hammer a tracker that may be rate-limiting us. + */ +export const POLL_RETRY_BASE_MS = 5 * 60 * 1000 +export const POLL_RETRY_MAX_MS = 60 * 60 * 1000 + +export function isPermanentPollFailure(message: string | null | undefined): boolean { + if (!message) return false + return PERMANENT_FAILURES.some((phrase) => message.includes(phrase)) +} + +/** + * A tracker that is rate-limiting or IP-banning us is transient -- it clears on + * its own -- but retrying at the normal cadence is what caused it. These jump + * straight to the maximum backoff instead of ramping up to it. + */ +export function isRateLimitFailure(message: string | null | undefined): boolean { + if (!message) return false + return /IP temporarily banned|rate.?limit/i.test(message) +} + +/** + * Exponential backoff for a tracker that keeps failing transiently. + * 1 failure -> 5m, 2 -> 10m, 3 -> 20m, 4 -> 40m, 5 or more -> 60m. + */ +export function pollRetryDelayMs( + consecutiveFailures: number, + lastError?: string | null +): number { + if (consecutiveFailures <= 0) return 0 + if (isRateLimitFailure(lastError)) return POLL_RETRY_MAX_MS + // clamp the exponent before shifting so a large failure count can't overflow + const steps = Math.min(consecutiveFailures - 1, 20) + return Math.min(POLL_RETRY_BASE_MS * 2 ** steps, POLL_RETRY_MAX_MS) +} + +/** + * True when a tracker is still inside its backoff window and should be skipped + * this cycle. A tracker with no recorded failures is always due. + */ +export function isWithinRetryBackoff( + tracker: { consecutiveFailures: number; lastError?: string | null; lastErrorAt?: Date | string | null }, + now: number +): boolean { + if (tracker.consecutiveFailures <= 0) return false + if (!tracker.lastErrorAt) return false + const lastErrorAt = new Date(tracker.lastErrorAt).getTime() + if (!Number.isFinite(lastErrorAt)) return false + return now - lastErrorAt < pollRetryDelayMs(tracker.consecutiveFailures, tracker.lastError) +} diff --git a/src/lib/tracker-scheduler.ts b/src/lib/tracker-scheduler.ts index 884d37aa..10ba1fef 100644 --- a/src/lib/tracker-scheduler.ts +++ b/src/lib/tracker-scheduler.ts @@ -31,6 +31,11 @@ import { localDateStr } from "@/lib/formatters" import { POLL_INTERVAL_DEFAULT } from "@/lib/limits" import { log } from "@/lib/logger" import { dispatchNotifications } from "@/lib/notifications/dispatch" +import { + isPermanentPollFailure, + isWithinRetryBackoff, + pollRetryDelayMs, +} from "@/lib/poll-failure-policy" import { maskUsername } from "@/lib/privacy" import { recordDatabaseSize } from "@/lib/server-data" import { HNR_HISTORY_POLLS } from "@/lib/tracker-events" @@ -452,13 +457,20 @@ export async function pollTracker( try { const now = new Date() + // Only a failure a human has to fix may stop polling for good. Transient + // failures (timeouts, DNS, refused connections, an unclassified "Poll + // failed") keep their failure count for visibility and backoff, but never + // set pausedAt -- otherwise a brief outage permanently blinds monitoring. + const permanent = isPermanentPollFailure(message) const [updated] = await db .update(trackers) .set({ lastError: message, lastErrorAt: now, consecutiveFailures: sql`${trackers.consecutiveFailures} + 1`, - pausedAt: sql`CASE WHEN ${trackers.consecutiveFailures} + 1 >= ${POLL_FAILURE_THRESHOLD} THEN ${now.toISOString()}::timestamp ELSE ${trackers.pausedAt} END`, + pausedAt: permanent + ? sql`CASE WHEN ${trackers.consecutiveFailures} + 1 >= ${POLL_FAILURE_THRESHOLD} THEN ${now.toISOString()}::timestamp ELSE ${trackers.pausedAt} END` + : trackers.pausedAt, updatedAt: now, }) .where(eq(trackers.id, trackerId)) @@ -479,13 +491,16 @@ export async function pollTracker( `Tracker ${trackerId} auto-paused after ${updated.consecutiveFailures} consecutive failures` ) } else if (updated) { + const retryInMs = pollRetryDelayMs(updated.consecutiveFailures, message) log.info( { trackerId, consecutiveFailures: updated.consecutiveFailures, threshold: POLL_FAILURE_THRESHOLD, + permanent, + retryInMinutes: Math.round(retryInMs / 60_000), }, - `Poll failure ${updated.consecutiveFailures}/${POLL_FAILURE_THRESHOLD} for tracker ${trackerId}` + `Poll failure ${updated.consecutiveFailures} for tracker ${trackerId}, retrying in ${Math.round(retryInMs / 60_000)}m` ) } } catch (dbError) { @@ -608,6 +623,24 @@ export async function pollAllTrackers(encryptionKey: Buffer): Promise { ) return false } + // A failed poll leaves lastPolledAt untouched, so a failing tracker stays + // permanently overdue and would otherwise be retried on every 5-minute + // tick. Space the retries out instead, so a long outage costs a handful of + // attempts per hour rather than twelve. + if (isWithinRetryBackoff(tracker, now)) { + log.debug( + { + tracker: tracker.name, + consecutiveFailures: tracker.consecutiveFailures, + lastError: tracker.lastError, + retryInMinutes: Math.round( + pollRetryDelayMs(tracker.consecutiveFailures, tracker.lastError) / 60_000 + ), + }, + "skipping tracker inside retry backoff" + ) + return false + } const lastPoll = tracker.lastPolledAt?.getTime() ?? 0 return now - lastPoll >= globalIntervalMs - BATCH_TOLERANCE_MS })