Compare commits
6 Commits
822ac34c0e
...
a9095d95a8
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
a9095d95a8 | ||
|
|
4d3ab20378 | ||
|
|
5d60df8122 | ||
|
|
2612e8a6ca | ||
|
|
2be6c8db8d | ||
|
|
f9b1e74838 |
@@ -765,8 +765,10 @@ If folder is omitted, the host generates one automatically.`,
|
||||
name: z.string().describe('Display name for the room'),
|
||||
room_mode: z
|
||||
.enum(['single', 'tribunal'])
|
||||
.default('single')
|
||||
.describe('single=owner only, tribunal=owner/reviewer roles enabled'),
|
||||
.default('tribunal')
|
||||
.describe(
|
||||
'single=owner only, tribunal=owner/reviewer roles enabled (default)',
|
||||
),
|
||||
owner_agent_type: z
|
||||
.enum(['claude-code', 'codex'])
|
||||
.optional()
|
||||
@@ -831,7 +833,7 @@ If folder is omitted, the host generates one automatically.`,
|
||||
type: 'assign_room',
|
||||
jid: args.jid,
|
||||
name: args.name,
|
||||
room_mode: args.room_mode || 'single',
|
||||
room_mode: args.room_mode || 'tribunal',
|
||||
owner_agent_type: args.owner_agent_type,
|
||||
reviewer_agent_type: args.reviewer_agent_type,
|
||||
arbiter_agent_type: args.arbiter_agent_type,
|
||||
|
||||
135
src/claude-usage-backoff.test.ts
Normal file
135
src/claude-usage-backoff.test.ts
Normal file
@@ -0,0 +1,135 @@
|
||||
/**
|
||||
* Regression tests for the Claude usage-API 429 `Retry-After` backoff.
|
||||
*
|
||||
* Root cause this guards against: the usage poller used to retry every
|
||||
* MIN_FETCH_INTERVAL_MS (60s), but the endpoint hands back a longer rate-limit
|
||||
* window (e.g. `retry-after: 93`). Retrying mid-cooldown re-trips the limit, so
|
||||
* the 429s never clear. The fix records a `cooldownUntil` from the header and
|
||||
* refuses to call the API until that window closes.
|
||||
*/
|
||||
import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest';
|
||||
|
||||
vi.mock('./logger.js', () => ({
|
||||
logger: { info: vi.fn(), warn: vi.fn(), error: vi.fn(), debug: vi.fn() },
|
||||
}));
|
||||
|
||||
vi.mock('./config.js', () => ({ DATA_DIR: '/tmp/ejclaw-usage-backoff-data' }));
|
||||
|
||||
const { getAllTokensMock } = vi.hoisted(() => ({ getAllTokensMock: vi.fn() }));
|
||||
vi.mock('./token-rotation.js', () => ({
|
||||
getAllTokens: getAllTokensMock,
|
||||
getCurrentToken: () => null,
|
||||
getConfiguredClaudeTokens: () => [],
|
||||
}));
|
||||
|
||||
const { readJsonFileMock } = vi.hoisted(() => ({ readJsonFileMock: vi.fn() }));
|
||||
vi.mock('./utils.js', async () => {
|
||||
const actual =
|
||||
await vi.importActual<typeof import('./utils.js')>('./utils.js');
|
||||
return { ...actual, readJsonFile: readJsonFileMock, writeJsonFile: vi.fn() };
|
||||
});
|
||||
|
||||
afterEach(() => {
|
||||
vi.resetModules();
|
||||
vi.clearAllMocks();
|
||||
vi.unstubAllGlobals();
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
function makeResponse(
|
||||
status: number,
|
||||
headers: Record<string, string> = {},
|
||||
): Response {
|
||||
return {
|
||||
status,
|
||||
ok: status >= 200 && status < 300,
|
||||
headers: { get: (k: string) => headers[k.toLowerCase()] ?? null },
|
||||
json: async () => ({}),
|
||||
} as unknown as Response;
|
||||
}
|
||||
|
||||
describe('parseRetryAfterMs', () => {
|
||||
it('parses delta-seconds', async () => {
|
||||
const { parseRetryAfterMs } = await import('./claude-usage.js');
|
||||
expect(parseRetryAfterMs('93')).toBe(93_000);
|
||||
expect(parseRetryAfterMs('0')).toBe(0);
|
||||
});
|
||||
|
||||
it('parses an HTTP-date relative to now', async () => {
|
||||
vi.useFakeTimers();
|
||||
vi.setSystemTime(new Date('2026-06-20T00:00:00Z'));
|
||||
const { parseRetryAfterMs } = await import('./claude-usage.js');
|
||||
expect(parseRetryAfterMs('Sat, 20 Jun 2026 00:00:30 GMT')).toBe(30_000);
|
||||
});
|
||||
|
||||
it('returns null for missing or junk values', async () => {
|
||||
const { parseRetryAfterMs } = await import('./claude-usage.js');
|
||||
expect(parseRetryAfterMs(null)).toBeNull();
|
||||
expect(parseRetryAfterMs('soon')).toBeNull();
|
||||
});
|
||||
});
|
||||
|
||||
describe('Claude usage 429 Retry-After backoff', () => {
|
||||
beforeEach(() => {
|
||||
readJsonFileMock.mockReturnValue({}); // start from an empty disk cache
|
||||
getAllTokensMock.mockReturnValue([
|
||||
{
|
||||
index: 0,
|
||||
token: 'sk-ant-oat01-testTokenAAAAAAAA',
|
||||
masked: 'sk-ant-oat01-test...AAAA',
|
||||
isActive: true,
|
||||
isRateLimited: false,
|
||||
},
|
||||
]);
|
||||
});
|
||||
|
||||
it('records a cooldown on 429 and skips the next fetch within the window', async () => {
|
||||
const fetchMock = vi.fn(async () =>
|
||||
makeResponse(429, { 'retry-after': '93' }),
|
||||
);
|
||||
vi.stubGlobal('fetch', fetchMock);
|
||||
|
||||
const { fetchAllClaudeUsage } = await import('./claude-usage.js');
|
||||
|
||||
const first = await fetchAllClaudeUsage();
|
||||
expect(fetchMock).toHaveBeenCalledTimes(1);
|
||||
expect(first[0].usageRateLimited).toBe(true);
|
||||
expect(first[0].usage).toBeNull();
|
||||
|
||||
// Immediate re-call: cooldown gate must hold, no second network call.
|
||||
const second = await fetchAllClaudeUsage();
|
||||
expect(fetchMock).toHaveBeenCalledTimes(1);
|
||||
expect(second[0].usageRateLimited).toBe(true);
|
||||
});
|
||||
|
||||
it('keeps backing off after the 60s throttle elapses but before the cooldown closes', async () => {
|
||||
// This is the core regression: a 93s Retry-After must outlast the 60s
|
||||
// MIN_FETCH_INTERVAL throttle. Without the cooldown the poller would refetch
|
||||
// at ~60s — mid rate-limit window — and re-trip the 429 forever.
|
||||
vi.useFakeTimers();
|
||||
vi.setSystemTime(new Date('2026-06-20T00:00:00Z'));
|
||||
|
||||
const fetchMock = vi
|
||||
.fn()
|
||||
.mockResolvedValueOnce(makeResponse(429, { 'retry-after': '93' }))
|
||||
.mockResolvedValueOnce(makeResponse(200));
|
||||
vi.stubGlobal('fetch', fetchMock);
|
||||
|
||||
const { fetchAllClaudeUsage } = await import('./claude-usage.js');
|
||||
|
||||
await fetchAllClaudeUsage();
|
||||
expect(fetchMock).toHaveBeenCalledTimes(1);
|
||||
|
||||
// +70s: past the 60s throttle, still inside the ~98s cooldown → no refetch.
|
||||
vi.setSystemTime(Date.now() + 70_000);
|
||||
const held = await fetchAllClaudeUsage();
|
||||
expect(fetchMock).toHaveBeenCalledTimes(1);
|
||||
expect(held[0].usageRateLimited).toBe(true);
|
||||
|
||||
// +100s total: cooldown window closed → poller is allowed to fetch again.
|
||||
vi.setSystemTime(Date.now() + 30_000);
|
||||
const resumed = await fetchAllClaudeUsage();
|
||||
expect(fetchMock).toHaveBeenCalledTimes(2);
|
||||
expect(resumed[0].usageRateLimited).toBe(false);
|
||||
});
|
||||
});
|
||||
@@ -55,6 +55,30 @@ interface UsageCacheEntry {
|
||||
fetchedAt: number;
|
||||
/** Timestamp of last API *attempt* including failures (use for throttling). */
|
||||
lastAttemptAt?: number;
|
||||
/**
|
||||
* HTTP status of the most recent *failed* attempt (e.g. 429), cleared on a
|
||||
* successful fetch. Used so the dashboard can render a live error indicator
|
||||
* instead of a stale value.
|
||||
*/
|
||||
lastErrorStatus?: number;
|
||||
/**
|
||||
* Epoch-ms before which we MUST NOT retry, derived from a 429 `Retry-After`
|
||||
* header (or a default backoff when the header is absent). Cleared on a
|
||||
* successful fetch. Without this we re-poll every MIN_FETCH_INTERVAL_MS (60s)
|
||||
* even though the endpoint's rate-limit window is longer (~90s+), so the
|
||||
* cooldown never clears and the 429s become self-sustaining.
|
||||
*/
|
||||
cooldownUntil?: number;
|
||||
}
|
||||
|
||||
/**
|
||||
* Outcome of a usage fetch. `rateLimited` is true when the most recent attempt
|
||||
* hit a 429 — callers use it to surface an error in the UI rather than the
|
||||
* last cached value.
|
||||
*/
|
||||
export interface UsageFetchResult {
|
||||
usage: ClaudeUsageData | null;
|
||||
rateLimited: boolean;
|
||||
}
|
||||
|
||||
let usageDiskCache: Record<string, UsageCacheEntry> = {};
|
||||
@@ -117,11 +141,35 @@ export function getUsageCacheReadKeys(
|
||||
// resolution — at worst the gate fires ~60s after a window crosses 95%.
|
||||
const MIN_FETCH_INTERVAL_MS = 60_000;
|
||||
|
||||
// Small margin added on top of a server-provided Retry-After so we wait until
|
||||
// just *after* the cooldown window closes rather than racing its edge.
|
||||
const RATE_LIMIT_MARGIN_MS = 5_000;
|
||||
// Fallback cooldown when a 429 carries no usable Retry-After header.
|
||||
const DEFAULT_RATE_LIMIT_COOLDOWN_MS = 5 * 60_000;
|
||||
|
||||
/**
|
||||
* Parse an HTTP `Retry-After` header into milliseconds from now.
|
||||
* Accepts either a delta-seconds integer ("93") or an HTTP-date.
|
||||
* Returns null when the header is missing or unparseable.
|
||||
*/
|
||||
export function parseRetryAfterMs(header: string | null): number | null {
|
||||
if (!header) return null;
|
||||
const trimmed = header.trim();
|
||||
if (/^\d+$/.test(trimmed)) {
|
||||
return Number(trimmed) * 1000;
|
||||
}
|
||||
const dateMs = Date.parse(trimmed);
|
||||
if (Number.isFinite(dateMs)) {
|
||||
return Math.max(0, dateMs - Date.now());
|
||||
}
|
||||
return null;
|
||||
}
|
||||
|
||||
async function fetchUsageForToken(
|
||||
token: string,
|
||||
accountIndex?: number,
|
||||
refreshAttempted = false,
|
||||
): Promise<ClaudeUsageData | null> {
|
||||
): Promise<UsageFetchResult> {
|
||||
loadUsageDiskCache();
|
||||
|
||||
// Return cached data if attempted recently (avoid API rate-limit)
|
||||
@@ -150,13 +198,54 @@ async function fetchUsageForToken(
|
||||
cached = usageDiskCache[writeKey];
|
||||
saveUsageDiskCache();
|
||||
}
|
||||
|
||||
/**
|
||||
* Record this attempt's timestamp (and error status) at the write key,
|
||||
* creating the entry if it does not exist yet. Recording even when there is
|
||||
* no prior cached usage is what makes the MIN_FETCH_INTERVAL_MS throttle
|
||||
* apply to *failures* too — without it an empty cache means every dashboard
|
||||
* refresh hits the API, which itself sustains the very 429s we then report.
|
||||
*/
|
||||
const recordAttempt = (
|
||||
errorStatus?: number,
|
||||
cooldownUntil?: number,
|
||||
): void => {
|
||||
const now = Date.now();
|
||||
const entry: UsageCacheEntry = usageDiskCache[writeKey] ?? {
|
||||
usage: {},
|
||||
fetchedAt: 0,
|
||||
};
|
||||
entry.lastAttemptAt = now;
|
||||
entry.lastErrorStatus = errorStatus;
|
||||
entry.cooldownUntil = cooldownUntil;
|
||||
usageDiskCache[writeKey] = entry;
|
||||
saveUsageDiskCache();
|
||||
};
|
||||
|
||||
// Honour an active rate-limit cooldown from a prior 429's Retry-After. This
|
||||
// is what actually breaks the self-sustaining 429 loop: the endpoint hands
|
||||
// back a ~90s+ window, so retrying on the 60s MIN_FETCH_INTERVAL would keep
|
||||
// hitting it mid-cooldown and never recover.
|
||||
if (
|
||||
!refreshAttempted &&
|
||||
cached?.cooldownUntil &&
|
||||
Date.now() < cached.cooldownUntil
|
||||
) {
|
||||
return { usage: null, rateLimited: true };
|
||||
}
|
||||
|
||||
const lastAttempt = cached?.lastAttemptAt ?? cached?.fetchedAt ?? 0;
|
||||
if (
|
||||
!refreshAttempted &&
|
||||
cached &&
|
||||
Date.now() - lastAttempt < MIN_FETCH_INTERVAL_MS
|
||||
) {
|
||||
return cached.usage;
|
||||
// Within the throttle window: replay the last outcome without an API call.
|
||||
// On a 429 we report rateLimited and DO NOT serve the stale value.
|
||||
if (cached.lastErrorStatus === 429) {
|
||||
return { usage: null, rateLimited: true };
|
||||
}
|
||||
return { usage: cached.usage ?? null, rateLimited: false };
|
||||
}
|
||||
const controller = new AbortController();
|
||||
const timer = setTimeout(() => controller.abort(), FETCH_TIMEOUT_MS);
|
||||
@@ -208,29 +297,31 @@ async function fetchUsageForToken(
|
||||
? 'Claude usage API: token expired or invalid (401)'
|
||||
: 'Claude usage API: forbidden — token missing required scope (403)',
|
||||
);
|
||||
if (cached) {
|
||||
cached.lastAttemptAt = Date.now();
|
||||
saveUsageDiskCache();
|
||||
}
|
||||
return cached?.usage ?? null;
|
||||
recordAttempt(res.status);
|
||||
return { usage: cached?.usage ?? null, rateLimited: false };
|
||||
}
|
||||
if (res.status === 429) {
|
||||
const staleMs = cached ? Date.now() - cached.fetchedAt : 0;
|
||||
const retryAfterMs = parseRetryAfterMs(res.headers.get('retry-after'));
|
||||
const cooldownMs = retryAfterMs ?? DEFAULT_RATE_LIMIT_COOLDOWN_MS;
|
||||
const cooldownUntil = Date.now() + cooldownMs + RATE_LIMIT_MARGIN_MS;
|
||||
logger.warn(
|
||||
{
|
||||
account: accountIndex != null ? accountIndex + 1 : '?',
|
||||
tokenKey: legacyTokenCacheKey(token),
|
||||
cacheKey: writeKey,
|
||||
staleMinutes: Math.round(staleMs / 60_000),
|
||||
retryAfterSec:
|
||||
retryAfterMs != null ? Math.round(retryAfterMs / 1000) : null,
|
||||
cooldownSec: Math.round(cooldownMs / 1000),
|
||||
},
|
||||
'Claude usage API: rate limited (429), returning cached data',
|
||||
'Claude usage API: rate limited (429)',
|
||||
);
|
||||
// Record attempt time so we don't retry for MIN_FETCH_INTERVAL_MS
|
||||
if (cached) {
|
||||
cached.lastAttemptAt = Date.now();
|
||||
saveUsageDiskCache();
|
||||
}
|
||||
return cached?.usage ?? null;
|
||||
// Back off until the server-provided Retry-After window closes (plus a
|
||||
// margin) so we stop re-tripping the limit. Surfaces a 429 indicator and
|
||||
// does NOT serve the stale value.
|
||||
recordAttempt(429, cooldownUntil);
|
||||
return { usage: null, rateLimited: true };
|
||||
}
|
||||
if (!res.ok) {
|
||||
logger.warn(
|
||||
@@ -242,11 +333,8 @@ async function fetchUsageForToken(
|
||||
},
|
||||
`Claude usage API: unexpected status ${res.status}`,
|
||||
);
|
||||
if (cached) {
|
||||
cached.lastAttemptAt = Date.now();
|
||||
saveUsageDiskCache();
|
||||
}
|
||||
return cached?.usage ?? null;
|
||||
recordAttempt(res.status);
|
||||
return { usage: cached?.usage ?? null, rateLimited: false };
|
||||
}
|
||||
|
||||
const data = (await res.json()) as UsageApiResponse;
|
||||
@@ -258,12 +346,14 @@ async function fetchUsageForToken(
|
||||
seven_day_opus: mapWindow(data.seven_day_opus),
|
||||
};
|
||||
|
||||
// Persist to disk cache — success: update both fetchedAt and lastAttemptAt
|
||||
// Persist to disk cache — success: update fetchedAt + lastAttemptAt and
|
||||
// clear any prior error status.
|
||||
const now = Date.now();
|
||||
usageDiskCache[writeKey] = {
|
||||
usage: result,
|
||||
fetchedAt: now,
|
||||
lastAttemptAt: now,
|
||||
lastErrorStatus: undefined,
|
||||
};
|
||||
saveUsageDiskCache();
|
||||
|
||||
@@ -278,7 +368,7 @@ async function fetchUsageForToken(
|
||||
'Claude usage API: fetched successfully',
|
||||
);
|
||||
|
||||
return result;
|
||||
return { usage: result, rateLimited: false };
|
||||
} catch (err) {
|
||||
if ((err as Error).name === 'AbortError') {
|
||||
logger.warn(
|
||||
@@ -301,11 +391,8 @@ async function fetchUsageForToken(
|
||||
);
|
||||
}
|
||||
// Record attempt time so we back off on persistent failures
|
||||
if (cached) {
|
||||
cached.lastAttemptAt = Date.now();
|
||||
saveUsageDiskCache();
|
||||
}
|
||||
return cached?.usage ?? null;
|
||||
recordAttempt();
|
||||
return { usage: cached?.usage ?? null, rateLimited: false };
|
||||
} finally {
|
||||
clearTimeout(timer);
|
||||
}
|
||||
@@ -329,7 +416,7 @@ export async function fetchClaudeUsage(): Promise<ClaudeUsageData | null> {
|
||||
logger.debug('No Claude OAuth token available for usage check');
|
||||
return null;
|
||||
}
|
||||
return fetchUsageForToken(token, undefined);
|
||||
return (await fetchUsageForToken(token, undefined)).usage;
|
||||
}
|
||||
|
||||
export interface ClaudeAccountProfile {
|
||||
@@ -471,6 +558,11 @@ export interface ClaudeAccountUsage {
|
||||
isActive: boolean;
|
||||
isRateLimited: boolean;
|
||||
usage: ClaudeUsageData | null;
|
||||
/**
|
||||
* True when the most recent usage-API attempt for this account hit a 429.
|
||||
* The dashboard renders a "429" indicator instead of a stale value.
|
||||
*/
|
||||
usageRateLimited?: boolean;
|
||||
}
|
||||
|
||||
/**
|
||||
@@ -484,7 +576,7 @@ export async function fetchAllClaudeUsage(): Promise<ClaudeAccountUsage[]> {
|
||||
const credsToken = readCredentialsAccessToken(0);
|
||||
const token = credsToken || getConfiguredClaudeTokens()[0];
|
||||
if (!token) return [];
|
||||
const usage = await fetchUsageForToken(token, 0);
|
||||
const { usage, rateLimited } = await fetchUsageForToken(token, 0);
|
||||
return [
|
||||
{
|
||||
index: 0,
|
||||
@@ -492,6 +584,7 @@ export async function fetchAllClaudeUsage(): Promise<ClaudeAccountUsage[]> {
|
||||
isActive: true,
|
||||
isRateLimited: false,
|
||||
usage,
|
||||
usageRateLimited: rateLimited,
|
||||
},
|
||||
];
|
||||
}
|
||||
@@ -505,13 +598,17 @@ export async function fetchAllClaudeUsage(): Promise<ClaudeAccountUsage[]> {
|
||||
// by token-refresh.ts, so it always carries the full scope set.
|
||||
const credsToken = readCredentialsAccessToken(t.index);
|
||||
const tokenForFetch = credsToken || t.token;
|
||||
const usage = await fetchUsageForToken(tokenForFetch, t.index);
|
||||
const { usage, rateLimited } = await fetchUsageForToken(
|
||||
tokenForFetch,
|
||||
t.index,
|
||||
);
|
||||
results.push({
|
||||
index: t.index,
|
||||
masked: t.masked,
|
||||
isActive: t.isActive,
|
||||
isRateLimited: t.isRateLimited,
|
||||
usage,
|
||||
usageRateLimited: rateLimited,
|
||||
});
|
||||
}
|
||||
return results;
|
||||
|
||||
@@ -133,6 +133,44 @@ describe('dashboard Claude usage rows', () => {
|
||||
});
|
||||
});
|
||||
|
||||
it('marks a rate-limited account with a 429 error and does not fall back to a cached value', () => {
|
||||
const cachedAccounts: ClaudeAccountUsage[] = [
|
||||
{
|
||||
index: 0,
|
||||
masked: 'tok-a',
|
||||
isActive: true,
|
||||
isRateLimited: false,
|
||||
usage: {
|
||||
five_hour: {
|
||||
utilization: 0.4,
|
||||
resets_at: '2026-03-24T04:00:00+09:00',
|
||||
},
|
||||
seven_day: {
|
||||
utilization: 0.7,
|
||||
resets_at: '2026-03-29T04:00:00+09:00',
|
||||
},
|
||||
},
|
||||
},
|
||||
];
|
||||
const liveAccounts: ClaudeAccountUsage[] = [
|
||||
{
|
||||
index: 0,
|
||||
masked: 'tok-a',
|
||||
isActive: true,
|
||||
isRateLimited: false,
|
||||
usage: null,
|
||||
usageRateLimited: true,
|
||||
},
|
||||
];
|
||||
|
||||
const merged = mergeClaudeDashboardAccounts(liveAccounts, cachedAccounts);
|
||||
// The 429 must win over the cached value — no stale fallback.
|
||||
expect(merged[0].usage).toBeNull();
|
||||
|
||||
const rows = buildClaudeUsageRows(merged);
|
||||
expect(rows[0]).toMatchObject({ h5pct: -1, d7pct: -1, error: '429' });
|
||||
});
|
||||
|
||||
it('preserves the last successful usage per account instead of collapsing to one cache entry', () => {
|
||||
const cachedAccounts: ClaudeAccountUsage[] = [
|
||||
{
|
||||
|
||||
@@ -7,6 +7,8 @@ export type UsageRow = {
|
||||
h5reset: string;
|
||||
d7pct: number;
|
||||
d7reset: string;
|
||||
/** When set, the renderer shows this text (e.g. "429") in place of the bars. */
|
||||
error?: string;
|
||||
};
|
||||
|
||||
export function formatResetRemaining(value: string | number): string {
|
||||
@@ -42,7 +44,11 @@ export function mergeClaudeDashboardAccounts(
|
||||
|
||||
return liveAccounts.map((account) => ({
|
||||
...account,
|
||||
usage: account.usage || cachedByIndex.get(account.index)?.usage || null,
|
||||
// On a 429 we deliberately do NOT fall back to the last cached value —
|
||||
// the dashboard surfaces a "429" indicator instead.
|
||||
usage: account.usageRateLimited
|
||||
? null
|
||||
: account.usage || cachedByIndex.get(account.index)?.usage || null,
|
||||
}));
|
||||
}
|
||||
|
||||
@@ -75,6 +81,7 @@ export function buildClaudeUsageRows(
|
||||
: Math.round(d7.utilization * 100)
|
||||
: -1,
|
||||
d7reset: d7 ? formatResetRemaining(d7.resets_at) : '',
|
||||
error: account.usageRateLimited ? '429' : undefined,
|
||||
};
|
||||
});
|
||||
}
|
||||
|
||||
@@ -149,7 +149,9 @@ describe('initializeDatabaseSchema', () => {
|
||||
};
|
||||
for (let version = 1; version <= 15; version += 1) {
|
||||
database
|
||||
.prepare('INSERT INTO schema_migrations (version, name) VALUES (?, ?)')
|
||||
.prepare(
|
||||
'INSERT INTO schema_migrations (version, name) VALUES (?, ?)',
|
||||
)
|
||||
.run(version, collidedNames[version] ?? `legacy_${version}`);
|
||||
}
|
||||
// Precondition: the collided database is missing the progress columns.
|
||||
|
||||
@@ -194,7 +194,7 @@ export function assignRoomInDatabase(
|
||||
input: AssignRoomInput,
|
||||
): (RegisteredGroup & { jid: string }) | undefined {
|
||||
const existing = getStoredRoomSettingsRowFromDatabase(database, chatJid);
|
||||
const roomMode = input.roomMode || existing?.roomMode || 'single';
|
||||
const roomMode = input.roomMode || existing?.roomMode || 'tribunal';
|
||||
const ownerAgentType =
|
||||
input.ownerAgentType || existing?.ownerAgentType || OWNER_AGENT_TYPE;
|
||||
const folder = resolveAssignedRoomFolder(
|
||||
|
||||
@@ -1131,7 +1131,7 @@ describe('assign_room success', () => {
|
||||
});
|
||||
});
|
||||
|
||||
it('assign_room auto-fills missing folder for single rooms without exposing trigger metadata', async () => {
|
||||
it('assign_room auto-fills missing folder and defaults to tribunal without exposing trigger metadata', async () => {
|
||||
await processTaskIpc(
|
||||
{
|
||||
type: 'assign_room',
|
||||
@@ -1146,7 +1146,7 @@ describe('assign_room success', () => {
|
||||
const group = getRegisteredGroup('partial@g.us');
|
||||
expect(group).toBeDefined();
|
||||
expect(group!.folder).toMatch(/^grp_whatsapp_/);
|
||||
expect(getStoredRoomSettings('partial@g.us')?.roomMode).toBe('single');
|
||||
expect(getStoredRoomSettings('partial@g.us')?.roomMode).toBe('tribunal');
|
||||
});
|
||||
|
||||
it('assign_room preserves an existing tribunal room mode when room_mode is omitted', async () => {
|
||||
|
||||
@@ -6,6 +6,7 @@ vi.mock('./db.js', () => ({
|
||||
getLastHumanMessageSender: vi.fn(() => '216851709744513024'),
|
||||
getLatestTurnNumber: vi.fn(() => 0),
|
||||
getPairedTaskById: vi.fn(),
|
||||
getPairedTurnOutputs: vi.fn(() => []),
|
||||
insertPairedTurnOutput: vi.fn(),
|
||||
refreshPairedTaskExecutionLease: vi.fn(() => true),
|
||||
releasePairedTaskExecutionLease: vi.fn(),
|
||||
@@ -239,6 +240,96 @@ describe('createPairedExecutionLifecycle completion handling', () => {
|
||||
expect(outputs).toEqual([]);
|
||||
});
|
||||
|
||||
it('delivers the held owner answer and a notice when the reviewer Codex is unavailable', async () => {
|
||||
const outputs: AgentOutput[] = [];
|
||||
|
||||
vi.mocked(db.getPairedTurnOutputs).mockReturnValue([
|
||||
{
|
||||
id: 1,
|
||||
task_id: 'paired-task-reviewer-down',
|
||||
turn_number: 1,
|
||||
role: 'owner',
|
||||
output_text: 'TASK_DONE\n\n원하시던 .env 위치는 여기에 있습니다.',
|
||||
created_at: '2026-04-09T00:00:00.000Z',
|
||||
},
|
||||
]);
|
||||
|
||||
vi.mocked(db.getPairedTaskById).mockReturnValue({
|
||||
id: 'paired-task-reviewer-down',
|
||||
chat_jid: 'group@test',
|
||||
group_folder: 'test-group',
|
||||
owner_service_id: 'claude',
|
||||
reviewer_service_id: 'codex-main',
|
||||
title: null,
|
||||
source_ref: 'HEAD',
|
||||
plan_notes: null,
|
||||
round_trip_count: 1,
|
||||
review_requested_at: '2026-04-09T00:00:00.000Z',
|
||||
status: 'completed',
|
||||
arbiter_verdict: 'escalate',
|
||||
arbiter_requested_at: null,
|
||||
completion_reason: 'reviewer_codex_unavailable',
|
||||
created_at: '2026-04-09T00:00:00.000Z',
|
||||
updated_at: '2026-04-09T00:00:01.000Z',
|
||||
});
|
||||
|
||||
const lifecycle = createPairedExecutionLifecycle({
|
||||
pairedExecutionContext: {
|
||||
task: {
|
||||
id: 'paired-task-reviewer-down',
|
||||
chat_jid: 'group@test',
|
||||
group_folder: 'test-group',
|
||||
owner_service_id: 'claude',
|
||||
reviewer_service_id: 'codex-main',
|
||||
title: null,
|
||||
source_ref: 'HEAD',
|
||||
plan_notes: null,
|
||||
round_trip_count: 1,
|
||||
review_requested_at: '2026-04-09T00:00:00.000Z',
|
||||
status: 'in_review',
|
||||
arbiter_verdict: null,
|
||||
arbiter_requested_at: null,
|
||||
completion_reason: null,
|
||||
created_at: '2026-04-09T00:00:00.000Z',
|
||||
updated_at: '2026-04-09T00:00:00.000Z',
|
||||
},
|
||||
workspace: null,
|
||||
envOverrides: {},
|
||||
},
|
||||
pairedTurnIdentity: {
|
||||
turnId:
|
||||
'paired-task-reviewer-down:2026-04-09T00:00:00.000Z:reviewer-turn',
|
||||
taskId: 'paired-task-reviewer-down',
|
||||
taskUpdatedAt: '2026-04-09T00:00:00.000Z',
|
||||
intentKind: 'reviewer-turn',
|
||||
role: 'reviewer',
|
||||
},
|
||||
completedRole: 'reviewer',
|
||||
chatJid: 'group@test',
|
||||
runId: 'run-reviewer-down',
|
||||
enqueueMessageCheck: vi.fn(),
|
||||
onOutput: async (output) => {
|
||||
outputs.push(output);
|
||||
},
|
||||
log,
|
||||
});
|
||||
|
||||
lifecycle.markStatus('failed');
|
||||
lifecycle.updateSummary({
|
||||
errorText:
|
||||
'auth-expired: All Codex rotation accounts unavailable; re-auth required before launching Codex',
|
||||
});
|
||||
await lifecycle.asyncFinalize();
|
||||
|
||||
const texts = outputs.map((o) =>
|
||||
o.output?.visibility === 'public' ? o.output.text : o.result,
|
||||
);
|
||||
expect(texts).toEqual([
|
||||
'원하시던 .env 위치는 여기에 있습니다.',
|
||||
'ℹ️ 리뷰어 일시 사용 불가 — 리뷰 없이 owner 답변으로 진행했습니다.',
|
||||
]);
|
||||
});
|
||||
|
||||
it('releases an owner turn interrupted by a human message without counting an owner failure', async () => {
|
||||
const enqueueMessageCheck = vi.fn();
|
||||
vi.mocked(db.getPairedTaskById).mockReturnValue({
|
||||
|
||||
@@ -5,6 +5,7 @@ import {
|
||||
getLastHumanMessageSender,
|
||||
getLatestTurnNumber,
|
||||
getPairedTaskById,
|
||||
getPairedTurnOutputs,
|
||||
insertPairedTurnOutput,
|
||||
refreshPairedTaskExecutionLease,
|
||||
releasePairedTaskExecutionLease,
|
||||
@@ -14,7 +15,10 @@ import {
|
||||
completePairedExecutionContext,
|
||||
type PreparedPairedExecutionContext,
|
||||
} from './paired-execution-context.js';
|
||||
import { parseVisibleVerdict } from './paired-verdict.js';
|
||||
import {
|
||||
parseVisibleVerdict,
|
||||
stripLeadingStatusLine,
|
||||
} from './paired-verdict.js';
|
||||
import { resolvePairedFollowUpQueueAction } from './message-agent-executor-rules.js';
|
||||
import { enqueuePairedFollowUpAfterEvent } from './message-runtime-follow-up.js';
|
||||
import type { PairedTurnIdentity } from './paired-turn-identity.js';
|
||||
@@ -91,6 +95,17 @@ export function resolveOwnerNextStepNotice(
|
||||
}
|
||||
}
|
||||
|
||||
function getLatestOwnerAnswer(taskId: string): string | null {
|
||||
const outputs = getPairedTurnOutputs(taskId);
|
||||
for (let i = outputs.length - 1; i >= 0; i -= 1) {
|
||||
const output = outputs[i];
|
||||
if (output.role !== 'owner') continue;
|
||||
const text = stripLeadingStatusLine(output.output_text ?? '').trim();
|
||||
if (text.length > 0) return text;
|
||||
}
|
||||
return null;
|
||||
}
|
||||
|
||||
async function notifyPairedCompletionIfNeeded(args: {
|
||||
task: PairedTaskRecord | null | undefined;
|
||||
chatJid: string;
|
||||
@@ -116,6 +131,24 @@ async function notifyPairedCompletionIfNeeded(args: {
|
||||
return;
|
||||
}
|
||||
|
||||
// Reviewer (Codex) was unavailable, so the turn ended before the reviewer
|
||||
// could approve. Instead of stopping silently, deliver the owner's already
|
||||
// produced answer and tell the user the review was skipped — otherwise the
|
||||
// user sees nothing at all (the owner answer is held until review completes).
|
||||
if (
|
||||
task.status === 'completed' &&
|
||||
task.completion_reason === 'reviewer_codex_unavailable'
|
||||
) {
|
||||
const ownerAnswer = getLatestOwnerAnswer(task.id);
|
||||
if (ownerAnswer) {
|
||||
await emit(ownerAnswer);
|
||||
}
|
||||
await emit(
|
||||
'ℹ️ 리뷰어 일시 사용 불가 — 리뷰 없이 owner 답변으로 진행했습니다.',
|
||||
);
|
||||
return;
|
||||
}
|
||||
|
||||
// Owner turn: surface the next routing step so the ending is unambiguous.
|
||||
if (args.completedRole !== 'owner') return;
|
||||
const notice = resolveOwnerNextStepNotice(task);
|
||||
|
||||
@@ -12,7 +12,7 @@ import {
|
||||
resolveReviewerFailureSignal,
|
||||
} from './paired-completion-signals.js';
|
||||
import { resolveCanonicalSourceRef } from './paired-source-ref.js';
|
||||
import { parseVisibleVerdict } from './paired-verdict.js';
|
||||
import { parseReviewerVerdict } from './paired-verdict.js';
|
||||
import type { PairedTask } from './types.js';
|
||||
|
||||
/**
|
||||
@@ -60,7 +60,7 @@ export function handleFailedReviewerExecution(args: {
|
||||
}
|
||||
|
||||
if (summary) {
|
||||
const verdict = parseVisibleVerdict(summary);
|
||||
const verdict = parseReviewerVerdict(summary);
|
||||
const signal = resolveReviewerFailureSignal({
|
||||
visibleVerdict: verdict,
|
||||
});
|
||||
@@ -191,7 +191,7 @@ export function handleReviewerCompletion(args: {
|
||||
}): void {
|
||||
const { task, taskId, summary } = args;
|
||||
const now = new Date().toISOString();
|
||||
const verdict = parseVisibleVerdict(summary);
|
||||
const verdict = parseReviewerVerdict(summary);
|
||||
const signal = resolveReviewerCompletionSignal({
|
||||
visibleVerdict: verdict,
|
||||
roundTripCount: task.round_trip_count,
|
||||
|
||||
@@ -104,6 +104,34 @@ describe('paired execution routing loop guards', () => {
|
||||
);
|
||||
});
|
||||
|
||||
it('treats a reviewer PROCEED as approval and routes to owner finalize', () => {
|
||||
// Regression: Codex reviewers approve with an arbiter-style "PROCEED" line.
|
||||
// It used to parse as 'continue' (a change request), so the reviewer's
|
||||
// approval bounced the task back to active and owner↔reviewer ping-ponged
|
||||
// (owner TASK_DONE ↔ reviewer PROCEED) until the deadlock cap. A PROCEED
|
||||
// approval must move the task to merge_ready so the owner can finalize.
|
||||
vi.mocked(db.getPairedTaskById).mockReturnValue(
|
||||
buildPairedTask({
|
||||
status: 'in_review',
|
||||
source_ref: 'approved-ref',
|
||||
}),
|
||||
);
|
||||
|
||||
completePairedExecutionContext({
|
||||
taskId: 'task-1',
|
||||
role: 'reviewer',
|
||||
status: 'succeeded',
|
||||
summary: 'PROCEED\n위치와 첨부는 맞습니다.',
|
||||
});
|
||||
|
||||
expect(db.updatePairedTask).toHaveBeenCalledWith(
|
||||
'task-1',
|
||||
expect.objectContaining({
|
||||
status: 'merge_ready',
|
||||
}),
|
||||
);
|
||||
});
|
||||
|
||||
it('clears stale owner loop state when reviewer approval is recovered from a failed run', () => {
|
||||
vi.mocked(db.getPairedTaskById).mockReturnValue(
|
||||
buildPairedTask({
|
||||
|
||||
@@ -2,7 +2,9 @@ import { describe, expect, it } from 'vitest';
|
||||
|
||||
import {
|
||||
classifyArbiterVerdict,
|
||||
parseReviewerVerdict,
|
||||
parseVisibleVerdict,
|
||||
stripLeadingStatusLine,
|
||||
} from './paired-verdict.js';
|
||||
|
||||
describe('paired verdict parser', () => {
|
||||
@@ -80,6 +82,51 @@ describe('paired verdict parser', () => {
|
||||
).toBe('continue');
|
||||
});
|
||||
|
||||
it('treats a reviewer PROCEED line as an approval (DONE)', () => {
|
||||
expect(parseReviewerVerdict('PROCEED\n위치와 첨부는 맞습니다.')).toBe(
|
||||
'done',
|
||||
);
|
||||
expect(parseReviewerVerdict('**PROCEED**\n최종 답변 내용 맞습니다.')).toBe(
|
||||
'done',
|
||||
);
|
||||
expect(
|
||||
parseReviewerVerdict(
|
||||
['검토 결과를 정리합니다.', 'PROCEED', '확정합니다.'].join('\n'),
|
||||
),
|
||||
).toBe('done');
|
||||
});
|
||||
|
||||
it('does not upgrade non-approval reviewer verdicts', () => {
|
||||
// REVISE / RESET / plain prose remain a change request ('continue').
|
||||
expect(parseReviewerVerdict('REVISE\n이 부분을 고쳐주세요')).toBe(
|
||||
'continue',
|
||||
);
|
||||
expect(parseReviewerVerdict('RESET\n방향을 다시 잡읍시다')).toBe(
|
||||
'continue',
|
||||
);
|
||||
expect(parseReviewerVerdict('추가 수정이 필요합니다')).toBe('continue');
|
||||
// Documented reviewer tokens still parse to their own verdicts.
|
||||
expect(parseReviewerVerdict('TASK_DONE\n승인합니다')).toBe('task_done');
|
||||
expect(parseReviewerVerdict('DONE_WITH_CONCERNS\n우려가 있습니다')).toBe(
|
||||
'done_with_concerns',
|
||||
);
|
||||
// "PROCEED" mentioned in prose, not as the leading verdict, is ignored.
|
||||
expect(
|
||||
parseReviewerVerdict('리뷰어가 PROCEED 했는지 확인이 필요합니다'),
|
||||
).toBe('continue');
|
||||
});
|
||||
|
||||
it('strips a leading status line for direct delivery', () => {
|
||||
expect(stripLeadingStatusLine('TASK_DONE\n\n실제 답변입니다.')).toBe(
|
||||
'실제 답변입니다.',
|
||||
);
|
||||
expect(stripLeadingStatusLine('STEP_DONE\n다음 내용')).toBe('다음 내용');
|
||||
// No leading status token → text is returned untouched.
|
||||
expect(stripLeadingStatusLine('그냥 본문입니다.\n둘째 줄')).toBe(
|
||||
'그냥 본문입니다.\n둘째 줄',
|
||||
);
|
||||
});
|
||||
|
||||
it('classifies arbiter verdicts from leading visible lines', () => {
|
||||
expect(classifyArbiterVerdict('PROCEED\ncontinue')).toBe('proceed');
|
||||
expect(classifyArbiterVerdict('**VERDICT: REVISE**\nfix it')).toBe(
|
||||
|
||||
@@ -69,6 +69,64 @@ export function parseVisibleVerdict(
|
||||
return 'continue';
|
||||
}
|
||||
|
||||
/**
|
||||
* Remove a leading status/verdict marker line (e.g. "TASK_DONE", "STEP_DONE")
|
||||
* from owner output so a held answer can be shown to the user directly without
|
||||
* the internal status token. Only strips when the very first non-empty line is
|
||||
* a recognised marker; otherwise returns the text untouched.
|
||||
*/
|
||||
export function stripLeadingStatusLine(text: string): string {
|
||||
const lines = text.split('\n');
|
||||
let firstNonEmpty = 0;
|
||||
while (firstNonEmpty < lines.length && lines[firstNonEmpty].trim() === '') {
|
||||
firstNonEmpty += 1;
|
||||
}
|
||||
if (
|
||||
firstNonEmpty >= lines.length ||
|
||||
!parseVisibleVerdictLine(lines[firstNonEmpty].trim())
|
||||
) {
|
||||
return text;
|
||||
}
|
||||
const remainder = lines.slice(firstNonEmpty + 1);
|
||||
while (remainder.length > 0 && remainder[0].trim() === '') {
|
||||
remainder.shift();
|
||||
}
|
||||
return remainder.join('\n').trim();
|
||||
}
|
||||
|
||||
const REVIEWER_APPROVAL_LINE =
|
||||
/^\*{0,2}(?:VERDICT\s*[:—-]\s*)?PROCEED(?:\*{0,2})?\b/i;
|
||||
|
||||
/**
|
||||
* Reviewers — especially the Codex reviewer — approve a turn with an
|
||||
* arbiter-style "PROCEED" line instead of the documented TASK_DONE. Plain
|
||||
* parseVisibleVerdict() does not know "PROCEED" and maps it to 'continue',
|
||||
* which resolveReviewerCompletionSignal() treats as a change request. So an
|
||||
* *approving* reviewer silently re-opens the owner turn and the two roles
|
||||
* ping-pong (owner TASK_DONE ↔ reviewer PROCEED) until the deadlock cap fires —
|
||||
* the user sees a burst of near-identical messages that then just stops.
|
||||
*
|
||||
* Treat a leading PROCEED as an approval (equivalent to DONE) so the state
|
||||
* machine routes to owner finalize and the task actually completes after one
|
||||
* round instead of looping. Only PROCEED is upgraded; REVISE/RESET/plain text
|
||||
* stay 'continue' (a genuine change request).
|
||||
*/
|
||||
export function parseReviewerVerdict(
|
||||
summary: string | null | undefined,
|
||||
): VisibleVerdict {
|
||||
const verdict = parseVisibleVerdict(summary);
|
||||
if (verdict !== 'continue' || !summary) return verdict;
|
||||
const cleaned = stripInternalBlocks(summary).trim();
|
||||
if (!cleaned) return verdict;
|
||||
for (const line of leadingVisibleLines(
|
||||
cleaned,
|
||||
VISIBLE_VERDICT_SCAN_LINE_LIMIT,
|
||||
)) {
|
||||
if (REVIEWER_APPROVAL_LINE.test(line)) return 'done';
|
||||
}
|
||||
return verdict;
|
||||
}
|
||||
|
||||
export function classifyArbiterVerdict(
|
||||
summary: string | null | undefined,
|
||||
): ArbiterVerdictResult {
|
||||
|
||||
@@ -480,6 +480,13 @@ export function renderUsageTable(
|
||||
|
||||
const renderRows = (rows: UsageRow[]) => {
|
||||
for (const row of rows) {
|
||||
if (row.error) {
|
||||
// Live error (e.g. 429) — show the indicator in both columns instead
|
||||
// of a bar or a stale value.
|
||||
const cell = row.error.padEnd(6);
|
||||
lines.push(`${padName(row.name)}${cell} ${cell}`);
|
||||
continue;
|
||||
}
|
||||
const h5 =
|
||||
row.h5pct >= 0
|
||||
? `${bar(row.h5pct)}${String(row.h5pct).padStart(3)}%`
|
||||
|
||||
Reference in New Issue
Block a user