diff --git a/README.md b/README.md index e1afaef5..3ddc7e14 100644 --- a/README.md +++ b/README.md @@ -697,8 +697,9 @@ table has drifted from the gateway's. **Charged but not in this machine's journal** is the one to look at hardest: money left the account for a call this machine did not make — expected if the same key is used on another machine or by another BlockRun product, and worth investigating if not. Exit code `2` in that -case, so a scheduled check can alert on it. Rows still **pending pricing** are -excluded from the totals rather than counted as $0. +case, so a scheduled check can alert on it, and `1` when the ledger could not be +read in full, since the unread pages could hold exactly those charges. Rows still +**pending pricing** are excluded from the totals rather than counted as $0. Your per-call sum will always be less than your card statement by exactly the top-up fees, which are charged at purchase and never appear as ledger rows. That diff --git a/src/cli.ts b/src/cli.ts index de0d9b12..6d700d46 100644 --- a/src/cli.ts +++ b/src/cli.ts @@ -308,12 +308,12 @@ async function cmdReconcile(days: number): Promise { process.exit(1); } try { - const { reconcile, formatReconcile } = await import("./reconcile.js"); + const { reconcile, formatReconcile, reconcileExitCode } = await import("./reconcile.js"); const result = await reconcile(resolved.key, days); console.log(formatReconcile(result, days)); - // Money charged that this machine cannot account for is the one outcome - // worth a non-zero exit, so a scheduled check can alert on it. - process.exitCode = result.chargedNotRecorded.length > 0 ? 2 : 0; + // Non-zero so a scheduled check can alert: unaccounted charges, or a + // ledger read too short to rule them out. + process.exitCode = reconcileExitCode(result); } catch (error) { console.error(`✗ ${error instanceof Error ? error.message : String(error)}`); process.exit(1); diff --git a/src/reconcile.test.ts b/src/reconcile.test.ts index d5f1dc05..f7baa25f 100644 --- a/src/reconcile.test.ts +++ b/src/reconcile.test.ts @@ -18,8 +18,14 @@ * would report a number that changes on the next run. */ -import { describe, it, expect } from "vitest"; -import { joinRows, formatReconcile, type LocalRow } from "./reconcile.js"; +import { afterEach, describe, it, expect, vi } from "vitest"; +import { + joinRows, + formatReconcile, + loadGatewayRows, + reconcileExitCode, + type LocalRow, +} from "./reconcile.js"; import type { UsageRow } from "./api-key.js"; const local = (requestId: string, cost: number, model = "openai/gpt-4o-mini"): LocalRow => ({ @@ -130,3 +136,143 @@ describe("formatReconcile", () => { expect(out).toContain("0.000007"); }); }); + +describe("loadGatewayRows", () => { + // One ledger page as GET /v1/usage returns it. + const page = (ids: string[], nextCursor: string | null) => + new Response( + JSON.stringify({ + data: ids.map((id) => ({ + request_id: id, + timestamp: "2026-09-05T18:00:00Z", + endpoint: "/v1/chat/completions", + cost_usd: 0.01, + cost_state: "priced", + })), + next_cursor: nextCursor, + }), + { status: 200, headers: { "content-type": "application/json" } }, + ); + + afterEach(() => { + vi.unstubAllGlobals(); + }); + + it("follows the cursor to the last page, passing it back verbatim", async () => { + const fetchMock = vi + .fn() + .mockResolvedValueOnce(page(["a"], "opaque/cursor=1")) + .mockResolvedValueOnce(page(["b"], null)); + vi.stubGlobal("fetch", fetchMock); + + const r = await loadGatewayRows("brk_live_test", "2026-09-01T00:00:00.000Z"); + + expect(r?.rows.map((x) => x.requestId)).toEqual(["a", "b"]); + expect(new URL(fetchMock.mock.calls[1][0] as string).searchParams.get("cursor")).toBe( + "opaque/cursor=1", + ); + }); + + it("marks the ledger incomplete when a page after the first fails", async () => { + // Page 2 is lost. Page 1 alone reconciles "cleanly": every charge on the + // missing pages silently drops out of chargedNotRecorded, the finding this + // command exists to surface. + vi.stubGlobal( + "fetch", + vi + .fn() + .mockResolvedValueOnce(page(["a"], "c1")) + .mockResolvedValueOnce(new Response("upstream error", { status: 502 })), + ); + + const r = await loadGatewayRows("brk_live_test", "2026-09-01T00:00:00.000Z"); + + expect(r?.rows.map((x) => x.requestId)).toEqual(["a"]); + expect(r?.incomplete).toMatch(/page 2/); + }); + + it("marks the ledger incomplete when pages are left past the cap", async () => { + // Every page says there is more, each with a fresh cursor. Stopping at the + // cap is fine; passing what was read off as the whole ledger is not. + let n = 0; + const fetchMock = vi.fn().mockImplementation(async () => { + n++; + return page([`x${n}`], `c${n}`); + }); + vi.stubGlobal("fetch", fetchMock); + + const r = await loadGatewayRows("brk_live_test", "2026-09-01T00:00:00.000Z", 3); + + expect(fetchMock).toHaveBeenCalledTimes(3); + expect(r?.rows.map((x) => x.requestId)).toEqual(["x1", "x2", "x3"]); + expect(r?.incomplete).toMatch(/more than 3 pages/); + }); + + it("stops at a cursor it has already requested instead of reading that page again", async () => { + // Page 2 hands back the cursor that produced it. Following it would append + // page 2's rows on every pass until the cap and count those charges twice. + const fetchMock = vi + .fn() + .mockResolvedValueOnce(page(["a"], "c1")) + .mockResolvedValueOnce(page(["b"], "c1")) + .mockImplementation(async () => page(["b"], "c1")); + vi.stubGlobal("fetch", fetchMock); + + const r = await loadGatewayRows("brk_live_test", "2026-09-01T00:00:00.000Z", 5); + + expect(fetchMock).toHaveBeenCalledTimes(2); + expect(r?.rows.map((x) => x.requestId)).toEqual(["a", "b"]); + expect(r?.incomplete).toMatch(/stopped advancing after page 2/); + }); + + it("still returns undefined when the first page fails", async () => { + vi.stubGlobal("fetch", vi.fn().mockResolvedValue(new Response("", { status: 401 }))); + await expect(loadGatewayRows("brk_live_test", "2026-09-01T00:00:00.000Z")).resolves.toBe( + undefined, + ); + }); + + it("leaves a complete read unmarked", async () => { + vi.stubGlobal("fetch", vi.fn().mockResolvedValueOnce(page(["a"], null))); + const r = await loadGatewayRows("brk_live_test", "2026-09-01T00:00:00.000Z"); + expect(r?.incomplete).toBeUndefined(); + }); +}); + +describe("partial ledger", () => { + const partial = () => { + const r = joinRows([local("a", 0.01)], [remote("a", 0.01)]); + r.ledgerIncomplete = "page 2 of the ledger could not be read"; + return r; + }; + + it("says so before the totals it qualifies", () => { + const out = formatReconcile(partial(), 7); + expect(out).toContain("Partial ledger: page 2 of the ledger could not be read"); + expect(out.indexOf("Partial ledger")).toBeLessThan(out.indexOf("Gateway charged")); + }); + + it("calls only the gateway side short, since the journal still covers the window", () => { + // The journal total and recordedNotCharged come from the full local window; + // only the ledger side is missing pages. + const out = formatReconcile(partial(), 7); + expect(out).toMatch(/gateway total is\s+short/); + expect(out).toMatch(/recorded locally with no settled ledger row/); + expect(out).not.toMatch(/totals and lists below cover only/i); + }); + + it("does not exit 0, since unread pages can hide unrecorded charges", () => { + expect(reconcileExitCode(partial())).toBe(1); + }); + + it("keeps exit 2 for unrecorded charges, partial or not", () => { + const r = joinRows([], [remote("ghost", 2.43)]); + expect(reconcileExitCode(r)).toBe(2); + r.ledgerIncomplete = "page 2 of the ledger could not be read"; + expect(reconcileExitCode(r)).toBe(2); + }); + + it("exits 0 for a complete, clean reconciliation", () => { + expect(reconcileExitCode(joinRows([local("a", 0.01)], [remote("a", 0.01)]))).toBe(0); + }); +}); diff --git a/src/reconcile.ts b/src/reconcile.ts index c72fa982..8a5aec96 100644 --- a/src/reconcile.ts +++ b/src/reconcile.ts @@ -46,6 +46,8 @@ export type ReconcileResult = { unavailableDays: string[]; /** Journal entries with no request id at all — unreconcilable, not a mismatch. */ unkeyedLocalCount: number; + /** Why the ledger read stopped before its last page, if it did. */ + ledgerIncomplete?: string; }; /** Read journal entries written on or after `since`. */ @@ -91,24 +93,53 @@ export async function loadLocalRows(since: Date): Promise<{ rows: LocalRow[]; un return { rows, unkeyed }; } -/** Pull the whole ledger window, following the opaque cursor. */ +/** + * Pull the whole ledger window, following the opaque cursor. + * + * When the read stops early (a later page fails, the cursor stops advancing, or + * pages are left past `maxPages`) the rows read so far are kept, but + * `incomplete` says why. A short ledger looks clean on its own: every charge on + * the unread pages silently drops out of `chargedNotRecorded`. + */ export async function loadGatewayRows( apiKey: string, from: string, maxPages = 40, -): Promise<{ rows: UsageRow[]; unavailableDays: string[] } | undefined> { +): Promise<{ rows: UsageRow[]; unavailableDays: string[]; incomplete?: string } | undefined> { const rows: UsageRow[] = []; const unavailableDays = new Set(); + const requested = new Set(); let cursor: string | undefined; for (let page = 0; page < maxPages; page++) { const result = await fetchUsagePage(apiKey, { from, limit: 500, cursor }); - if (!result) return page === 0 ? undefined : { rows, unavailableDays: [...unavailableDays] }; + if (!result) { + if (page === 0) return undefined; + return { + rows, + unavailableDays: [...unavailableDays], + incomplete: `page ${page + 1} of the ledger could not be read`, + }; + } rows.push(...result.rows); result.unavailableDays.forEach((d) => unavailableDays.add(d)); - if (!result.nextCursor) break; + if (!result.nextCursor) return { rows, unavailableDays: [...unavailableDays] }; + // A cursor already requested leads back to a page already read. Following + // it would append the same rows again on every pass until `maxPages`. + if (requested.has(result.nextCursor)) { + return { + rows, + unavailableDays: [...unavailableDays], + incomplete: `the ledger's page cursor stopped advancing after page ${page + 1}`, + }; + } cursor = result.nextCursor; // opaque by contract — passed back, never parsed + requested.add(cursor); } - return { rows, unavailableDays: [...unavailableDays] }; + return { + rows, + unavailableDays: [...unavailableDays], + incomplete: `the ledger has more than ${maxPages} pages for this window; try fewer --days`, + }; } /** Amounts equal to the cent, allowing for float representation. */ @@ -171,7 +202,21 @@ export async function reconcile(apiKey: string, days: number): Promise 0) return 2; + if (r.ledgerIncomplete) return 1; + return 0; } const usd = (n: number): string => (Math.abs(n) < 0.01 ? `$${n.toFixed(6)}` : `$${n.toFixed(2)}`); @@ -182,6 +227,16 @@ export function formatReconcile(r: ReconcileResult, days: number): string { const mismatched = r.matched.filter((m) => Math.abs(m.deltaUsd) > CENT_EPSILON); out.push(`\nBlockRun reconciliation — last ${days} day${days === 1 ? "" : "s"}\n`); + if (r.ledgerIncomplete) { + // First, because it qualifies every number below. + // Only the gateway side is short. The journal still covers the whole window, + // so its total is complete and calls billed on unread pages land in + // recordedNotCharged rather than matched. + out.push(` ⚠ Partial ledger: ${r.ledgerIncomplete}.`); + out.push(` Only the ledger pages that were read are compared: the gateway total is`); + out.push(` short, charges on the unread pages are not checked, and calls billed on`); + out.push(` those pages show up as recorded locally with no settled ledger row.\n`); + } out.push( ` Gateway charged: ${usd(r.gatewayTotalUsd)} (${r.matched.length + r.chargedNotRecorded.length} settled calls)`, );