Improve logging, rate limiting, and error handling (#29)

* feat: apply local user changes and fixes

* ;D

* Clean up PR #28: Remove duplicate code lines and unnecessary file

- Remove pullrequest.md (PR notes file not needed in repo)
- Fix duplicate lines in account-manager.js:
  - rateLimitResetTime assignment
  - saveToDisk() calls in markRateLimited and markInvalid
  - invalidReason/invalidAt assignments
  - double return statement in discoverProject

Original PR by M2noa: fix sticky accs, 500s, logging updates, and rate limit handling

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: M2noa <226494568+M2noa@users.noreply.github.com>
Co-Authored-By: Claude <noreply@anthropic.com>

* chore: replace console.log with logger methods for consistency

- Replace all console.log calls with logger.warn/debug in:
  - src/cloudcode-client.js (4 places)
  - src/format/thinking-utils.js (7 places)

This ensures consistent logging behavior with the new logger utility,
respecting --debug mode for verbose output.

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude <noreply@anthropic.com>

---------

Co-authored-by: M1noa <minoa@minoa.cat>
Co-authored-by: M2noa <226494568+M2noa@users.noreply.github.com>
Co-authored-by: Claude <noreply@anthropic.com>
This commit is contained in:
Badri Narayanan S
2026-01-01 14:35:06 +05:30
committed by GitHub
parent d05fb64e29
commit 1d91bc0d30
11 changed files with 351 additions and 108 deletions

1
.gitignore vendored
View File

@@ -12,6 +12,7 @@ log.txt
# IDE # IDE
.vscode/ .vscode/
.idea/ .idea/
.history/
# Local config (may contain tokens) # Local config (may contain tokens)
.claude/ .claude/

View File

@@ -20,6 +20,7 @@ import {
import { refreshAccessToken } from './oauth.js'; import { refreshAccessToken } from './oauth.js';
import { formatDuration } from './utils/helpers.js'; import { formatDuration } from './utils/helpers.js';
import { getAuthStatus } from './db/database.js'; import { getAuthStatus } from './db/database.js';
import { logger } from './utils/logger.js';
export class AccountManager { export class AccountManager {
#accounts = []; #accounts = [];
@@ -63,19 +64,19 @@ export class AccountManager {
this.#currentIndex = 0; this.#currentIndex = 0;
} }
console.log(`[AccountManager] Loaded ${this.#accounts.length} account(s) from config`); logger.info(`[AccountManager] Loaded ${this.#accounts.length} account(s) from config`);
// If config exists but has no accounts, fall back to Antigravity database // If config exists but has no accounts, fall back to Antigravity database
if (this.#accounts.length === 0) { if (this.#accounts.length === 0) {
console.log('[AccountManager] No accounts in config. Falling back to Antigravity database'); logger.warn('[AccountManager] No accounts in config. Falling back to Antigravity database');
await this.#loadDefaultAccount(); await this.#loadDefaultAccount();
} }
} catch (error) { } catch (error) {
if (error.code === 'ENOENT') { if (error.code === 'ENOENT') {
// No config file - use single account from Antigravity database // No config file - use single account from Antigravity database
console.log('[AccountManager] No config file found. Using Antigravity database (single account mode)'); logger.info('[AccountManager] No config file found. Using Antigravity database (single account mode)');
} else { } else {
console.error('[AccountManager] Failed to load config:', error.message); logger.error('[AccountManager] Failed to load config:', error.message);
} }
// Fall back to default account // Fall back to default account
await this.#loadDefaultAccount(); await this.#loadDefaultAccount();
@@ -106,10 +107,10 @@ export class AccountManager {
token: authData.apiKey, token: authData.apiKey,
extractedAt: Date.now() extractedAt: Date.now()
}); });
console.log(`[AccountManager] Loaded default account: ${this.#accounts[0].email}`); logger.info(`[AccountManager] Loaded default account: ${this.#accounts[0].email}`);
} }
} catch (error) { } catch (error) {
console.error('[AccountManager] Failed to load default account:', error.message); logger.error('[AccountManager] Failed to load default account:', error.message);
// Create empty account list - will fail on first request // Create empty account list - will fail on first request
this.#accounts = []; this.#accounts = [];
} }
@@ -158,10 +159,9 @@ export class AccountManager {
for (const account of this.#accounts) { for (const account of this.#accounts) {
if (account.isRateLimited && account.rateLimitResetTime && account.rateLimitResetTime <= now) { if (account.isRateLimited && account.rateLimitResetTime && account.rateLimitResetTime <= now) {
account.isRateLimited = false;
account.rateLimitResetTime = null; account.rateLimitResetTime = null;
cleared++; cleared++;
console.log(`[AccountManager] Rate limit expired for: ${account.email}`); logger.success(`[AccountManager] Rate limit expired for: ${account.email}`);
} }
} }
@@ -185,7 +185,7 @@ export class AccountManager {
// So we clear both. // So we clear both.
account.rateLimitResetTime = null; account.rateLimitResetTime = null;
} }
console.log('[AccountManager] Reset all rate limits for optimistic retry'); logger.warn('[AccountManager] Reset all rate limits for optimistic retry');
} }
/** /**
@@ -218,7 +218,7 @@ export class AccountManager {
const position = idx + 1; const position = idx + 1;
const total = this.#accounts.length; const total = this.#accounts.length;
console.log(`[AccountManager] Using account: ${account.email} (${position}/${total})`); logger.info(`[AccountManager] Using account: ${account.email} (${position}/${total})`);
// Persist the change (don't await to avoid blocking) // Persist the change (don't await to avoid blocking)
this.saveToDisk(); this.saveToDisk();
@@ -309,17 +309,32 @@ export class AccountManager {
return { account: stickyAccount, waitMs: 0 }; return { account: stickyAccount, waitMs: 0 };
} }
// Check if we should wait for current account // Current account is rate-limited or invalid.
// CHECK IF OTHERS ARE AVAILABLE before deciding to wait.
// We prefer switching to an available neighbor over waiting for the sticky one,
// to avoid "erroring forever" / tight retry loops on short rate limits.
const available = this.getAvailableAccounts();
if (available.length > 0) {
// Found a free account! Switch immediately.
const nextAccount = this.pickNext();
if (nextAccount) {
logger.info(`[AccountManager] Switched to new account (failover): ${nextAccount.email}`);
return { account: nextAccount, waitMs: 0 };
}
}
// No other accounts available. Now checking if we should wait for current account.
const waitInfo = this.shouldWaitForCurrentAccount(); const waitInfo = this.shouldWaitForCurrentAccount();
if (waitInfo.shouldWait) { if (waitInfo.shouldWait) {
console.log(`[AccountManager] Waiting ${formatDuration(waitInfo.waitMs)} for sticky account: ${waitInfo.account.email}`); logger.info(`[AccountManager] Waiting ${formatDuration(waitInfo.waitMs)} for sticky account: ${waitInfo.account.email}`);
return { account: null, waitMs: waitInfo.waitMs }; return { account: null, waitMs: waitInfo.waitMs };
} }
// Current account unavailable for too long, switch to next available // Current account unavailable for too long/invalid, and no others available?
// pickNext will likely return null or loop, but we defer to standard logic.
const nextAccount = this.pickNext(); const nextAccount = this.pickNext();
if (nextAccount) { if (nextAccount) {
console.log(`[AccountManager] Switched to new account for cache: ${nextAccount.email}`); logger.info(`[AccountManager] Switched to new account for cache: ${nextAccount.email}`);
} }
return { account: nextAccount, waitMs: 0 }; return { account: nextAccount, waitMs: 0 };
} }
@@ -337,7 +352,7 @@ export class AccountManager {
const cooldownMs = resetMs || this.#settings.cooldownDurationMs || DEFAULT_COOLDOWN_MS; const cooldownMs = resetMs || this.#settings.cooldownDurationMs || DEFAULT_COOLDOWN_MS;
account.rateLimitResetTime = Date.now() + cooldownMs; account.rateLimitResetTime = Date.now() + cooldownMs;
console.log( logger.warn(
`[AccountManager] Rate limited: ${email}. Available in ${formatDuration(cooldownMs)}` `[AccountManager] Rate limited: ${email}. Available in ${formatDuration(cooldownMs)}`
); );
@@ -357,13 +372,13 @@ export class AccountManager {
account.invalidReason = reason; account.invalidReason = reason;
account.invalidAt = Date.now(); account.invalidAt = Date.now();
console.log( logger.error(
`[AccountManager] ⚠ Account INVALID: ${email}` `[AccountManager] ⚠ Account INVALID: ${email}`
); );
console.log( logger.error(
`[AccountManager] Reason: ${reason}` `[AccountManager] Reason: ${reason}`
); );
console.log( logger.error(
`[AccountManager] Run 'npm run accounts' to re-authenticate this account` `[AccountManager] Run 'npm run accounts' to re-authenticate this account`
); );
@@ -392,7 +407,7 @@ export class AccountManager {
} }
if (soonestAccount) { if (soonestAccount) {
console.log(`[AccountManager] Shortest wait: ${formatDuration(minWait)} (account: ${soonestAccount.email})`); logger.info(`[AccountManager] Shortest wait: ${formatDuration(minWait)} (account: ${soonestAccount.email})`);
} }
return minWait === Infinity ? DEFAULT_COOLDOWN_MS : minWait; return minWait === Infinity ? DEFAULT_COOLDOWN_MS : minWait;
@@ -425,9 +440,9 @@ export class AccountManager {
account.invalidReason = null; account.invalidReason = null;
await this.saveToDisk(); await this.saveToDisk();
} }
console.log(`[AccountManager] Refreshed OAuth token for: ${account.email}`); logger.success(`[AccountManager] Refreshed OAuth token for: ${account.email}`);
} catch (error) { } catch (error) {
console.error(`[AccountManager] Failed to refresh token for ${account.email}:`, error.message); logger.error(`[AccountManager] Failed to refresh token for ${account.email}:`, error.message);
// Mark account as invalid (credentials need re-auth) // Mark account as invalid (credentials need re-auth)
this.markInvalid(account.email, error.message); this.markInvalid(account.email, error.message);
throw new Error(`AUTH_INVALID: ${account.email}: ${error.message}`); throw new Error(`AUTH_INVALID: ${account.email}: ${error.message}`);
@@ -508,11 +523,11 @@ export class AccountManager {
return data.cloudaicompanionProject.id; return data.cloudaicompanionProject.id;
} }
} catch (error) { } catch (error) {
console.log(`[AccountManager] Project discovery failed at ${endpoint}:`, error.message); logger.warn(`[AccountManager] Project discovery failed at ${endpoint}:`, error.message);
} }
} }
console.log(`[AccountManager] Using default project: ${DEFAULT_PROJECT_ID}`); logger.info(`[AccountManager] Using default project: ${DEFAULT_PROJECT_ID}`);
return DEFAULT_PROJECT_ID; return DEFAULT_PROJECT_ID;
} }
@@ -571,7 +586,7 @@ export class AccountManager {
await writeFile(this.#configPath, JSON.stringify(config, null, 2)); await writeFile(this.#configPath, JSON.stringify(config, null, 2));
} catch (error) { } catch (error) {
console.error('[AccountManager] Failed to save config:', error.message); logger.error('[AccountManager] Failed to save config:', error.message);
} }
} }

View File

@@ -26,6 +26,7 @@ import {
import { cacheSignature } from './format/signature-cache.js'; import { cacheSignature } from './format/signature-cache.js';
import { formatDuration, sleep } from './utils/helpers.js'; import { formatDuration, sleep } from './utils/helpers.js';
import { isRateLimitError, isAuthError } from './errors.js'; import { isRateLimitError, isAuthError } from './errors.js';
import { logger } from './utils/logger.js';
/** /**
* Check if an error is a rate limit error (429 or RESOURCE_EXHAUSTED) * Check if an error is a rate limit error (429 or RESOURCE_EXHAUSTED)
@@ -102,14 +103,14 @@ function parseResetTime(responseOrError, errorText = '') {
const seconds = parseInt(retryAfter, 10); const seconds = parseInt(retryAfter, 10);
if (!isNaN(seconds)) { if (!isNaN(seconds)) {
resetMs = seconds * 1000; resetMs = seconds * 1000;
console.log(`[CloudCode] Retry-After header: ${seconds}s`); logger.debug(`[CloudCode] Retry-After header: ${seconds}s`);
} else { } else {
// Try parsing as HTTP date // Try parsing as HTTP date
const date = new Date(retryAfter); const date = new Date(retryAfter);
if (!isNaN(date.getTime())) { if (!isNaN(date.getTime())) {
resetMs = date.getTime() - Date.now(); resetMs = date.getTime() - Date.now();
if (resetMs > 0) { if (resetMs > 0) {
console.log(`[CloudCode] Retry-After date: ${retryAfter}`); logger.debug(`[CloudCode] Retry-After date: ${retryAfter}`);
} else { } else {
resetMs = null; resetMs = null;
} }
@@ -124,7 +125,7 @@ function parseResetTime(responseOrError, errorText = '') {
const resetTimestamp = parseInt(ratelimitReset, 10) * 1000; const resetTimestamp = parseInt(ratelimitReset, 10) * 1000;
resetMs = resetTimestamp - Date.now(); resetMs = resetTimestamp - Date.now();
if (resetMs > 0) { if (resetMs > 0) {
console.log(`[CloudCode] x-ratelimit-reset: ${new Date(resetTimestamp).toISOString()}`); logger.debug(`[CloudCode] x-ratelimit-reset: ${new Date(resetTimestamp).toISOString()}`);
} else { } else {
resetMs = null; resetMs = null;
} }
@@ -138,7 +139,7 @@ function parseResetTime(responseOrError, errorText = '') {
const seconds = parseInt(resetAfter, 10); const seconds = parseInt(resetAfter, 10);
if (!isNaN(seconds) && seconds > 0) { if (!isNaN(seconds) && seconds > 0) {
resetMs = seconds * 1000; resetMs = seconds * 1000;
console.log(`[CloudCode] x-ratelimit-reset-after: ${seconds}s`); logger.debug(`[CloudCode] x-ratelimit-reset-after: ${seconds}s`);
} }
} }
} }
@@ -148,20 +149,46 @@ function parseResetTime(responseOrError, errorText = '') {
if (!resetMs) { if (!resetMs) {
const msg = (responseOrError instanceof Error ? responseOrError.message : errorText) || ''; const msg = (responseOrError instanceof Error ? responseOrError.message : errorText) || '';
// Try to extract "quotaResetDelay" first (e.g. "754.431528ms" or "1.5s")
// This is Google's preferred format for rate limit reset delay
const quotaDelayMatch = msg.match(/quotaResetDelay[:\s"]+(\d+(?:\.\d+)?)(ms|s)/i);
if (quotaDelayMatch) {
const value = parseFloat(quotaDelayMatch[1]);
const unit = quotaDelayMatch[2].toLowerCase();
resetMs = unit === 's' ? Math.ceil(value * 1000) : Math.ceil(value);
logger.debug(`[CloudCode] Parsed quotaResetDelay from body: ${resetMs}ms`);
}
// Try to extract "quotaResetTimeStamp" (ISO format like "2025-12-31T07:00:47Z")
if (!resetMs) {
const quotaTimestampMatch = msg.match(/quotaResetTimeStamp[:\s"]+(\d{4}-\d{2}-\d{2}T[\d:.]+Z?)/i);
if (quotaTimestampMatch) {
const resetTime = new Date(quotaTimestampMatch[1]).getTime();
if (!isNaN(resetTime)) {
resetMs = resetTime - Date.now();
// Even if expired or 0, we found a timestamp, so rely on it.
// But if it's negative, it means "now", so treat as small wait.
logger.debug(`[CloudCode] Parsed quotaResetTimeStamp: ${quotaTimestampMatch[1]} (Delta: ${resetMs}ms)`);
}
}
}
// Try to extract "retry-after-ms" or "retryDelay" - check seconds format first (e.g. "7739.23s") // Try to extract "retry-after-ms" or "retryDelay" - check seconds format first (e.g. "7739.23s")
// Added stricter regex to avoid partial matches
if (!resetMs) {
const secMatch = msg.match(/(?:retry[-_]?after[-_]?ms|retryDelay)[:\s"]+([\d\.]+)(?:s\b|s")/i); const secMatch = msg.match(/(?:retry[-_]?after[-_]?ms|retryDelay)[:\s"]+([\d\.]+)(?:s\b|s")/i);
if (secMatch) { if (secMatch) {
resetMs = Math.ceil(parseFloat(secMatch[1]) * 1000); resetMs = Math.ceil(parseFloat(secMatch[1]) * 1000);
console.log(`[CloudCode] Parsed retry seconds from body (precise): ${resetMs}ms`); logger.debug(`[CloudCode] Parsed retry seconds from body (precise): ${resetMs}ms`);
}
} }
if (!resetMs) { if (!resetMs) {
// Check for ms (explicit "ms" suffix or implicit if no suffix) // Check for ms (explicit "ms" suffix or implicit if no suffix)
// Rejects "s" suffix or floats (handled above)
const msMatch = msg.match(/(?:retry[-_]?after[-_]?ms|retryDelay)[:\s"]+(\d+)(?:\s*ms)?(?![\w.])/i); const msMatch = msg.match(/(?:retry[-_]?after[-_]?ms|retryDelay)[:\s"]+(\d+)(?:\s*ms)?(?![\w.])/i);
if (msMatch) { if (msMatch) {
resetMs = parseInt(msMatch[1], 10); resetMs = parseInt(msMatch[1], 10);
console.log(`[CloudCode] Parsed retry-after-ms from body: ${resetMs}ms`); logger.debug(`[CloudCode] Parsed retry-after-ms from body: ${resetMs}ms`);
} }
} }
@@ -170,7 +197,7 @@ function parseResetTime(responseOrError, errorText = '') {
const secMatch = msg.match(/retry\s+(?:after\s+)?(\d+)\s*(?:sec|s\b)/i); const secMatch = msg.match(/retry\s+(?:after\s+)?(\d+)\s*(?:sec|s\b)/i);
if (secMatch) { if (secMatch) {
resetMs = parseInt(secMatch[1], 10) * 1000; resetMs = parseInt(secMatch[1], 10) * 1000;
console.log(`[CloudCode] Parsed retry seconds from body: ${secMatch[1]}s`); logger.debug(`[CloudCode] Parsed retry seconds from body: ${secMatch[1]}s`);
} }
} }
@@ -191,7 +218,7 @@ function parseResetTime(responseOrError, errorText = '') {
resetMs = parseInt(durationMatch[6], 10) * 1000; resetMs = parseInt(durationMatch[6], 10) * 1000;
} }
if (resetMs) { if (resetMs) {
console.log(`[CloudCode] Parsed duration from body: ${formatDuration(resetMs)}`); logger.debug(`[CloudCode] Parsed duration from body: ${formatDuration(resetMs)}`);
} }
} }
} }
@@ -204,7 +231,7 @@ function parseResetTime(responseOrError, errorText = '') {
if (!isNaN(resetTime)) { if (!isNaN(resetTime)) {
resetMs = resetTime - Date.now(); resetMs = resetTime - Date.now();
if (resetMs > 0) { if (resetMs > 0) {
console.log(`[CloudCode] Parsed ISO reset time: ${isoMatch[1]}`); logger.debug(`[CloudCode] Parsed ISO reset time: ${isoMatch[1]}`);
} else { } else {
resetMs = null; resetMs = null;
} }
@@ -213,6 +240,16 @@ function parseResetTime(responseOrError, errorText = '') {
} }
} }
// SANITY CHECK: Enforce strict minimums for found rate limits
// If we found a reset time, but it's very small (e.g. < 1s) or negative,
// explicitly bump it up to avoid "Available in 0s" loops.
if (resetMs !== null) {
if (resetMs < 1000) {
logger.debug(`[CloudCode] Reset time too small (${resetMs}ms), enforcing 2s buffer`);
resetMs = 2000;
}
}
return resetMs; return resetMs;
} }
@@ -290,7 +327,7 @@ export async function sendMessage(anthropicRequest, accountManager) {
// Handle waiting for sticky account // Handle waiting for sticky account
if (!account && waitMs > 0) { if (!account && waitMs > 0) {
console.log(`[CloudCode] Waiting ${formatDuration(waitMs)} for sticky account...`); logger.info(`[CloudCode] Waiting ${formatDuration(waitMs)} for sticky account...`);
await sleep(waitMs); await sleep(waitMs);
accountManager.clearExpiredLimits(); accountManager.clearExpiredLimits();
account = accountManager.getCurrentStickyAccount(); account = accountManager.getCurrentStickyAccount();
@@ -311,7 +348,7 @@ export async function sendMessage(anthropicRequest, accountManager) {
// Wait for reset (applies to both single and multi-account modes) // Wait for reset (applies to both single and multi-account modes)
const accountCount = accountManager.getAccountCount(); const accountCount = accountManager.getAccountCount();
console.log(`[CloudCode] All ${accountCount} account(s) rate-limited. Waiting ${formatDuration(allWaitMs)}...`); logger.warn(`[CloudCode] All ${accountCount} account(s) rate-limited. Waiting ${formatDuration(allWaitMs)}...`);
await sleep(allWaitMs); await sleep(allWaitMs);
accountManager.clearExpiredLimits(); accountManager.clearExpiredLimits();
account = accountManager.pickNext(); account = accountManager.pickNext();
@@ -328,7 +365,7 @@ export async function sendMessage(anthropicRequest, accountManager) {
const project = await accountManager.getProjectForAccount(account, token); const project = await accountManager.getProjectForAccount(account, token);
const payload = buildCloudCodeRequest(anthropicRequest, project); const payload = buildCloudCodeRequest(anthropicRequest, project);
console.log(`[CloudCode] Sending request for model: ${model}`); logger.debug(`[CloudCode] Sending request for model: ${model}`);
// Try each endpoint // Try each endpoint
let lastError = null; let lastError = null;
@@ -346,11 +383,11 @@ export async function sendMessage(anthropicRequest, accountManager) {
if (!response.ok) { if (!response.ok) {
const errorText = await response.text(); const errorText = await response.text();
console.log(`[CloudCode] Error at ${endpoint}: ${response.status} - ${errorText}`); logger.warn(`[CloudCode] Error at ${endpoint}: ${response.status} - ${errorText}`);
if (response.status === 401) { if (response.status === 401) {
// Auth error - clear caches and retry with fresh token // Auth error - clear caches and retry with fresh token
console.log('[CloudCode] Auth error, refreshing token...'); logger.warn('[CloudCode] Auth error, refreshing token...');
accountManager.clearTokenCache(account.email); accountManager.clearTokenCache(account.email);
accountManager.clearProjectCache(account.email); accountManager.clearProjectCache(account.email);
continue; continue;
@@ -358,7 +395,7 @@ export async function sendMessage(anthropicRequest, accountManager) {
if (response.status === 429) { if (response.status === 429) {
// Rate limited on this endpoint - try next endpoint first (DAILY → PROD) // Rate limited on this endpoint - try next endpoint first (DAILY → PROD)
console.log(`[CloudCode] Rate limited at ${endpoint}, trying next endpoint...`); logger.debug(`[CloudCode] Rate limited at ${endpoint}, trying next endpoint...`);
const resetMs = parseResetTime(response, errorText); const resetMs = parseResetTime(response, errorText);
// Keep minimum reset time across all 429 responses // Keep minimum reset time across all 429 responses
if (!lastError?.is429 || (resetMs && (!lastError.resetMs || resetMs < lastError.resetMs))) { if (!lastError?.is429 || (resetMs && (!lastError.resetMs || resetMs < lastError.resetMs))) {
@@ -369,6 +406,11 @@ export async function sendMessage(anthropicRequest, accountManager) {
if (response.status >= 400) { if (response.status >= 400) {
lastError = new Error(`API error ${response.status}: ${errorText}`); lastError = new Error(`API error ${response.status}: ${errorText}`);
// If it's a 5xx error, wait a bit before trying the next endpoint
if (response.status >= 500) {
logger.warn(`[CloudCode] ${response.status} error, waiting 1s before retry...`);
await sleep(1000);
}
continue; continue;
} }
} }
@@ -380,14 +422,14 @@ export async function sendMessage(anthropicRequest, accountManager) {
// Non-thinking models use regular JSON // Non-thinking models use regular JSON
const data = await response.json(); const data = await response.json();
console.log('[CloudCode] Response received'); logger.debug('[CloudCode] Response received');
return convertGoogleToAnthropic(data, anthropicRequest.model); return convertGoogleToAnthropic(data, anthropicRequest.model);
} catch (endpointError) { } catch (endpointError) {
if (is429Error(endpointError)) { if (is429Error(endpointError)) {
throw endpointError; // Re-throw to trigger account switch throw endpointError; // Re-throw to trigger account switch
} }
console.log(`[CloudCode] Error at ${endpoint}:`, endpointError.message); logger.warn(`[CloudCode] Error at ${endpoint}:`, endpointError.message);
lastError = endpointError; lastError = endpointError;
} }
} }
@@ -396,7 +438,7 @@ export async function sendMessage(anthropicRequest, accountManager) {
if (lastError) { if (lastError) {
// If all endpoints returned 429, mark account as rate-limited // If all endpoints returned 429, mark account as rate-limited
if (lastError.is429) { if (lastError.is429) {
console.log(`[CloudCode] All endpoints rate-limited for ${account.email}`); logger.warn(`[CloudCode] All endpoints rate-limited for ${account.email}`);
accountManager.markRateLimited(account.email, lastError.resetMs); accountManager.markRateLimited(account.email, lastError.resetMs);
throw new Error(`Rate limited: ${lastError.errorText}`); throw new Error(`Rate limited: ${lastError.errorText}`);
} }
@@ -406,15 +448,22 @@ export async function sendMessage(anthropicRequest, accountManager) {
} catch (error) { } catch (error) {
if (is429Error(error)) { if (is429Error(error)) {
// Rate limited - already marked, continue to next account // Rate limited - already marked, continue to next account
console.log(`[CloudCode] Account ${account.email} rate-limited, trying next...`); logger.info(`[CloudCode] Account ${account.email} rate-limited, trying next...`);
continue; continue;
} }
if (isAuthInvalidError(error)) { if (isAuthInvalidError(error)) {
// Auth invalid - already marked, continue to next account // Auth invalid - already marked, continue to next account
console.log(`[CloudCode] Account ${account.email} has invalid credentials, trying next...`); logger.warn(`[CloudCode] Account ${account.email} has invalid credentials, trying next...`);
continue; continue;
} }
// Non-rate-limit error: throw immediately // Non-rate-limit error: throw immediately
// UNLESS it's a 500 error, then we treat it as a "soft" failure for this account and try the next one
if (error.message.includes('API error 5') || error.message.includes('500') || error.message.includes('503')) {
logger.warn(`[CloudCode] Account ${account.email} failed with 5xx error, trying next...`);
accountManager.pickNext(); // Force advance to next account
continue;
}
throw error; throw error;
} }
} }
@@ -502,7 +551,7 @@ async function parseThinkingSSEResponse(response, originalModel) {
} }
} }
} catch (e) { } catch (e) {
console.log('[CloudCode] SSE parse warning:', e.message, 'Raw:', jsonText.slice(0, 100)); logger.debug('[CloudCode] SSE parse warning:', e.message, 'Raw:', jsonText.slice(0, 100));
} }
} }
} }
@@ -516,10 +565,10 @@ async function parseThinkingSSEResponse(response, originalModel) {
}; };
const partTypes = finalParts.map(p => p.thought ? 'thought' : (p.functionCall ? 'functionCall' : 'text')); const partTypes = finalParts.map(p => p.thought ? 'thought' : (p.functionCall ? 'functionCall' : 'text'));
console.log('[CloudCode] Response received (SSE), part types:', partTypes); logger.debug('[CloudCode] Response received (SSE), part types:', partTypes);
if (finalParts.some(p => p.thought)) { if (finalParts.some(p => p.thought)) {
const thinkingPart = finalParts.find(p => p.thought); const thinkingPart = finalParts.find(p => p.thought);
console.log('[CloudCode] Thinking signature length:', thinkingPart?.thoughtSignature?.length || 0); logger.debug('[CloudCode] Thinking signature length:', thinkingPart?.thoughtSignature?.length || 0);
} }
return convertGoogleToAnthropic(accumulatedResponse, originalModel); return convertGoogleToAnthropic(accumulatedResponse, originalModel);
@@ -553,7 +602,7 @@ export async function* sendMessageStream(anthropicRequest, accountManager) {
// Handle waiting for sticky account // Handle waiting for sticky account
if (!account && waitMs > 0) { if (!account && waitMs > 0) {
console.log(`[CloudCode] Waiting ${formatDuration(waitMs)} for sticky account...`); logger.info(`[CloudCode] Waiting ${formatDuration(waitMs)} for sticky account...`);
await sleep(waitMs); await sleep(waitMs);
accountManager.clearExpiredLimits(); accountManager.clearExpiredLimits();
account = accountManager.getCurrentStickyAccount(); account = accountManager.getCurrentStickyAccount();
@@ -574,7 +623,7 @@ export async function* sendMessageStream(anthropicRequest, accountManager) {
// Wait for reset (applies to both single and multi-account modes) // Wait for reset (applies to both single and multi-account modes)
const accountCount = accountManager.getAccountCount(); const accountCount = accountManager.getAccountCount();
console.log(`[CloudCode] All ${accountCount} account(s) rate-limited. Waiting ${formatDuration(allWaitMs)}...`); logger.warn(`[CloudCode] All ${accountCount} account(s) rate-limited. Waiting ${formatDuration(allWaitMs)}...`);
await sleep(allWaitMs); await sleep(allWaitMs);
accountManager.clearExpiredLimits(); accountManager.clearExpiredLimits();
account = accountManager.pickNext(); account = accountManager.pickNext();
@@ -591,7 +640,7 @@ export async function* sendMessageStream(anthropicRequest, accountManager) {
const project = await accountManager.getProjectForAccount(account, token); const project = await accountManager.getProjectForAccount(account, token);
const payload = buildCloudCodeRequest(anthropicRequest, project); const payload = buildCloudCodeRequest(anthropicRequest, project);
console.log(`[CloudCode] Starting stream for model: ${model}`); logger.debug(`[CloudCode] Starting stream for model: ${model}`);
// Try each endpoint for streaming // Try each endpoint for streaming
let lastError = null; let lastError = null;
@@ -607,7 +656,7 @@ export async function* sendMessageStream(anthropicRequest, accountManager) {
if (!response.ok) { if (!response.ok) {
const errorText = await response.text(); const errorText = await response.text();
console.log(`[CloudCode] Stream error at ${endpoint}: ${response.status} - ${errorText}`); logger.warn(`[CloudCode] Stream error at ${endpoint}: ${response.status} - ${errorText}`);
if (response.status === 401) { if (response.status === 401) {
// Auth error - clear caches and retry // Auth error - clear caches and retry
@@ -618,7 +667,7 @@ export async function* sendMessageStream(anthropicRequest, accountManager) {
if (response.status === 429) { if (response.status === 429) {
// Rate limited on this endpoint - try next endpoint first (DAILY → PROD) // Rate limited on this endpoint - try next endpoint first (DAILY → PROD)
console.log(`[CloudCode] Stream rate limited at ${endpoint}, trying next endpoint...`); logger.debug(`[CloudCode] Stream rate limited at ${endpoint}, trying next endpoint...`);
const resetMs = parseResetTime(response, errorText); const resetMs = parseResetTime(response, errorText);
// Keep minimum reset time across all 429 responses // Keep minimum reset time across all 429 responses
if (!lastError?.is429 || (resetMs && (!lastError.resetMs || resetMs < lastError.resetMs))) { if (!lastError?.is429 || (resetMs && (!lastError.resetMs || resetMs < lastError.resetMs))) {
@@ -628,20 +677,27 @@ export async function* sendMessageStream(anthropicRequest, accountManager) {
} }
lastError = new Error(`API error ${response.status}: ${errorText}`); lastError = new Error(`API error ${response.status}: ${errorText}`);
// If it's a 5xx error, wait a bit before trying the next endpoint
if (response.status >= 500) {
logger.warn(`[CloudCode] ${response.status} stream error, waiting 1s before retry...`);
await sleep(1000);
}
continue; continue;
} }
// Stream the response - yield events as they arrive // Stream the response - yield events as they arrive
yield* streamSSEResponse(response, anthropicRequest.model); yield* streamSSEResponse(response, anthropicRequest.model);
console.log('[CloudCode] Stream completed'); logger.debug('[CloudCode] Stream completed');
return; return;
} catch (endpointError) { } catch (endpointError) {
if (is429Error(endpointError)) { if (is429Error(endpointError)) {
throw endpointError; // Re-throw to trigger account switch throw endpointError; // Re-throw to trigger account switch
} }
console.log(`[CloudCode] Stream error at ${endpoint}:`, endpointError.message); logger.warn(`[CloudCode] Stream error at ${endpoint}:`, endpointError.message);
lastError = endpointError; lastError = endpointError;
} }
} }
@@ -650,7 +706,7 @@ export async function* sendMessageStream(anthropicRequest, accountManager) {
if (lastError) { if (lastError) {
// If all endpoints returned 429, mark account as rate-limited // If all endpoints returned 429, mark account as rate-limited
if (lastError.is429) { if (lastError.is429) {
console.log(`[CloudCode] All endpoints rate-limited for ${account.email}`); logger.warn(`[CloudCode] All endpoints rate-limited for ${account.email}`);
accountManager.markRateLimited(account.email, lastError.resetMs); accountManager.markRateLimited(account.email, lastError.resetMs);
throw new Error(`Rate limited: ${lastError.errorText}`); throw new Error(`Rate limited: ${lastError.errorText}`);
} }
@@ -660,15 +716,22 @@ export async function* sendMessageStream(anthropicRequest, accountManager) {
} catch (error) { } catch (error) {
if (is429Error(error)) { if (is429Error(error)) {
// Rate limited - already marked, continue to next account // Rate limited - already marked, continue to next account
console.log(`[CloudCode] Account ${account.email} rate-limited, trying next...`); logger.info(`[CloudCode] Account ${account.email} rate-limited, trying next...`);
continue; continue;
} }
if (isAuthInvalidError(error)) { if (isAuthInvalidError(error)) {
// Auth invalid - already marked, continue to next account // Auth invalid - already marked, continue to next account
console.log(`[CloudCode] Account ${account.email} has invalid credentials, trying next...`); logger.warn(`[CloudCode] Account ${account.email} has invalid credentials, trying next...`);
continue; continue;
} }
// Non-rate-limit error: throw immediately // Non-rate-limit error: throw immediately
// UNLESS it's a 500 error, then we treat it as a "soft" failure for this account and try the next one
if (error.message.includes('API error 5') || error.message.includes('500') || error.message.includes('503')) {
logger.warn(`[CloudCode] Account ${account.email} failed with 5xx stream error, trying next...`);
accountManager.pickNext(); // Force advance to next account
continue;
}
throw error; throw error;
} }
} }
@@ -880,14 +943,14 @@ async function* streamSSEResponse(response, originalModel) {
} }
} catch (parseError) { } catch (parseError) {
console.log('[CloudCode] SSE parse error:', parseError.message); logger.warn('[CloudCode] SSE parse error:', parseError.message);
} }
} }
} }
// Handle no content received // Handle no content received
if (!hasEmittedStart) { if (!hasEmittedStart) {
console.log('[CloudCode] WARNING: No content parts received, emitting empty message'); logger.warn('[CloudCode] No content parts received, emitting empty message');
yield { yield {
type: 'message_start', type: 'message_start',
message: { message: {
@@ -998,13 +1061,13 @@ export async function fetchAvailableModels(token) {
if (!response.ok) { if (!response.ok) {
const errorText = await response.text(); const errorText = await response.text();
console.log(`[CloudCode] fetchAvailableModels error at ${endpoint}: ${response.status}`); logger.warn(`[CloudCode] fetchAvailableModels error at ${endpoint}: ${response.status}`);
continue; continue;
} }
return await response.json(); return await response.json();
} catch (error) { } catch (error) {
console.log(`[CloudCode] fetchAvailableModels failed at ${endpoint}:`, error.message); logger.warn(`[CloudCode] fetchAvailableModels failed at ${endpoint}:`, error.message);
} }
} }

View File

@@ -5,6 +5,7 @@
import { MIN_SIGNATURE_LENGTH, GEMINI_SKIP_SIGNATURE } from '../constants.js'; import { MIN_SIGNATURE_LENGTH, GEMINI_SKIP_SIGNATURE } from '../constants.js';
import { getCachedSignature } from './signature-cache.js'; import { getCachedSignature } from './signature-cache.js';
import { logger } from '../utils/logger.js';
/** /**
* Convert Anthropic role to Google role * Convert Anthropic role to Google role
@@ -101,7 +102,7 @@ export function convertContentToParts(content, isClaudeModel = false, isGeminiMo
if (!signature && block.id) { if (!signature && block.id) {
signature = getCachedSignature(block.id); signature = getCachedSignature(block.id);
if (signature) { if (signature) {
console.log('[ContentConverter] Restored signature from cache for:', block.id); logger.debug(`[ContentConverter] Restored signature from cache for: ${block.id}`);
} }
} }

View File

@@ -18,6 +18,7 @@ import {
needsThinkingRecovery, needsThinkingRecovery,
closeToolLoopForThinking closeToolLoopForThinking
} from './thinking-utils.js'; } from './thinking-utils.js';
import { logger } from '../utils/logger.js';
/** /**
* Convert Anthropic Messages API request to the format expected by Cloud Code * Convert Anthropic Messages API request to the format expected by Cloud Code
@@ -81,7 +82,7 @@ export function convertAnthropicToGoogle(anthropicRequest) {
// Claude models handle this differently and don't need this recovery // Claude models handle this differently and don't need this recovery
let processedMessages = messages; let processedMessages = messages;
if (isGeminiModel && isThinking && needsThinkingRecovery(messages)) { if (isGeminiModel && isThinking && needsThinkingRecovery(messages)) {
console.log('[RequestConverter] Applying thinking recovery for Gemini'); logger.debug('[RequestConverter] Applying thinking recovery for Gemini');
processedMessages = closeToolLoopForThinking(messages); processedMessages = closeToolLoopForThinking(messages);
} }
@@ -105,7 +106,7 @@ export function convertAnthropicToGoogle(anthropicRequest) {
// SAFETY: Google API requires at least one part per content message // SAFETY: Google API requires at least one part per content message
// This happens when all thinking blocks are filtered out (unsigned) // This happens when all thinking blocks are filtered out (unsigned)
if (parts.length === 0) { if (parts.length === 0) {
console.log('[RequestConverter] WARNING: Empty parts array after filtering, adding placeholder'); logger.warn('[RequestConverter] WARNING: Empty parts array after filtering, adding placeholder');
parts.push({ text: '' }); parts.push({ text: '' });
} }
@@ -150,9 +151,9 @@ export function convertAnthropicToGoogle(anthropicRequest) {
const thinkingBudget = thinking?.budget_tokens; const thinkingBudget = thinking?.budget_tokens;
if (thinkingBudget) { if (thinkingBudget) {
thinkingConfig.thinking_budget = thinkingBudget; thinkingConfig.thinking_budget = thinkingBudget;
console.log('[RequestConverter] Claude thinking enabled with budget:', thinkingBudget); logger.debug(`[RequestConverter] Claude thinking enabled with budget: ${thinkingBudget}`);
} else { } else {
console.log('[RequestConverter] Claude thinking enabled (no budget specified)'); logger.debug('[RequestConverter] Claude thinking enabled (no budget specified)');
} }
googleRequest.generationConfig.thinkingConfig = thinkingConfig; googleRequest.generationConfig.thinkingConfig = thinkingConfig;
@@ -162,7 +163,8 @@ export function convertAnthropicToGoogle(anthropicRequest) {
includeThoughts: true, includeThoughts: true,
thinkingBudget: thinking?.budget_tokens || 16000 thinkingBudget: thinking?.budget_tokens || 16000
}; };
console.log('[RequestConverter] Gemini thinking enabled with budget:', thinkingConfig.thinkingBudget); logger.debug(`[RequestConverter] Gemini thinking enabled with budget: ${thinkingConfig.thinkingBudget}`);
googleRequest.generationConfig.thinkingConfig = thinkingConfig; googleRequest.generationConfig.thinkingConfig = thinkingConfig;
} }
@@ -201,12 +203,12 @@ export function convertAnthropicToGoogle(anthropicRequest) {
}); });
googleRequest.tools = [{ functionDeclarations }]; googleRequest.tools = [{ functionDeclarations }];
console.log('[RequestConverter] Tools:', JSON.stringify(googleRequest.tools).substring(0, 300)); logger.debug(`[RequestConverter] Tools: ${JSON.stringify(googleRequest.tools).substring(0, 300)}`);
} }
// Cap max tokens for Gemini models // Cap max tokens for Gemini models
if (isGeminiModel && googleRequest.generationConfig.maxOutputTokens > GEMINI_MAX_OUTPUT_TOKENS) { if (isGeminiModel && googleRequest.generationConfig.maxOutputTokens > GEMINI_MAX_OUTPUT_TOKENS) {
console.log(`[RequestConverter] Capping Gemini max_tokens from ${googleRequest.generationConfig.maxOutputTokens} to ${GEMINI_MAX_OUTPUT_TOKENS}`); logger.debug(`[RequestConverter] Capping Gemini max_tokens from ${googleRequest.generationConfig.maxOutputTokens} to ${GEMINI_MAX_OUTPUT_TOKENS}`);
googleRequest.generationConfig.maxOutputTokens = GEMINI_MAX_OUTPUT_TOKENS; googleRequest.generationConfig.maxOutputTokens = GEMINI_MAX_OUTPUT_TOKENS;
} }

View File

@@ -4,6 +4,7 @@
*/ */
import { MIN_SIGNATURE_LENGTH } from '../constants.js'; import { MIN_SIGNATURE_LENGTH } from '../constants.js';
import { logger } from '../utils/logger.js';
/** /**
* Check if a part is a thinking block * Check if a part is a thinking block
@@ -95,7 +96,7 @@ function filterContentArray(contentArray) {
} }
// Drop unsigned thinking blocks // Drop unsigned thinking blocks
console.log('[ThinkingUtils] Dropping unsigned thinking block'); logger.debug('[ThinkingUtils] Dropping unsigned thinking block');
} }
return filtered; return filtered;
@@ -152,7 +153,7 @@ export function removeTrailingThinkingBlocks(content) {
} }
if (endIndex < content.length) { if (endIndex < content.length) {
console.log('[ThinkingUtils] Removed', content.length - endIndex, 'trailing unsigned thinking blocks'); logger.debug('[ThinkingUtils] Removed', content.length - endIndex, 'trailing unsigned thinking blocks');
return content.slice(0, endIndex); return content.slice(0, endIndex);
} }
@@ -187,7 +188,7 @@ export function restoreThinkingSignatures(content) {
} }
if (filtered.length < originalLength) { if (filtered.length < originalLength) {
console.log(`[ThinkingUtils] Dropped ${originalLength - filtered.length} unsigned thinking block(s)`); logger.debug(`[ThinkingUtils] Dropped ${originalLength - filtered.length} unsigned thinking block(s)`);
} }
return filtered; return filtered;
@@ -241,7 +242,7 @@ export function reorderAssistantContent(content) {
} }
if (droppedEmptyBlocks > 0) { if (droppedEmptyBlocks > 0) {
console.log(`[ThinkingUtils] Dropped ${droppedEmptyBlocks} empty text block(s)`); logger.debug(`[ThinkingUtils] Dropped ${droppedEmptyBlocks} empty text block(s)`);
} }
const reordered = [...thinkingBlocks, ...textBlocks, ...toolUseBlocks]; const reordered = [...thinkingBlocks, ...textBlocks, ...toolUseBlocks];
@@ -251,7 +252,7 @@ export function reorderAssistantContent(content) {
const originalOrder = content.map(b => b?.type || 'unknown').join(','); const originalOrder = content.map(b => b?.type || 'unknown').join(',');
const newOrder = reordered.map(b => b?.type || 'unknown').join(','); const newOrder = reordered.map(b => b?.type || 'unknown').join(',');
if (originalOrder !== newOrder) { if (originalOrder !== newOrder) {
console.log('[ThinkingUtils] Reordered assistant content'); logger.debug('[ThinkingUtils] Reordered assistant content');
} }
} }
@@ -455,7 +456,7 @@ export function closeToolLoopForThinking(messages) {
content: [{ type: 'text', text: '[Tool call was interrupted.]' }] content: [{ type: 'text', text: '[Tool call was interrupted.]' }]
}); });
console.log('[ThinkingUtils] Applied thinking recovery for interrupted tool'); logger.debug('[ThinkingUtils] Applied thinking recovery for interrupted tool');
} else { } else {
// For tool loops: add synthetic messages to close the loop // For tool loops: add synthetic messages to close the loop
const syntheticText = state.toolResultCount === 1 const syntheticText = state.toolResultCount === 1
@@ -474,7 +475,7 @@ export function closeToolLoopForThinking(messages) {
content: [{ type: 'text', text: '[Continue]' }] content: [{ type: 'text', text: '[Continue]' }]
}); });
console.log('[ThinkingUtils] Applied thinking recovery for tool loop'); logger.debug('[ThinkingUtils] Applied thinking recovery for tool loop');
} }
return modified; return modified;

View File

@@ -5,17 +5,42 @@
import app from './server.js'; import app from './server.js';
import { DEFAULT_PORT } from './constants.js'; import { DEFAULT_PORT } from './constants.js';
import { logger } from './utils/logger.js';
import path from 'path';
import os from 'os';
// Parse command line arguments
const args = process.argv.slice(2);
const isDebug = args.includes('--debug') || process.env.DEBUG === 'true';
// Initialize logger
logger.setDebug(isDebug);
if (isDebug) {
logger.debug('Debug mode enabled');
}
const PORT = process.env.PORT || DEFAULT_PORT; const PORT = process.env.PORT || DEFAULT_PORT;
// Home directory for account storage
const HOME_DIR = os.homedir();
const CONFIG_DIR = path.join(HOME_DIR, '.antigravity-claude-proxy');
app.listen(PORT, () => { app.listen(PORT, () => {
console.log(` // Clear console for a clean start
console.clear();
logger.log(`
╔══════════════════════════════════════════════════════════════╗ ╔══════════════════════════════════════════════════════════════╗
║ Antigravity Claude Proxy Server ║ ║ Antigravity Claude Proxy Server ║
╠══════════════════════════════════════════════════════════════╣ ╠══════════════════════════════════════════════════════════════╣
║ ║ ║ ║
║ Server running at: http://localhost:${PORT} ║ Server running at: http://localhost:${PORT}
║ ║ ║ ║
║ Control: ║
║ --debug Enable debug logging ║
║ Ctrl+C Stop server ║
║ ║
║ Endpoints: ║ ║ Endpoints: ║
║ POST /v1/messages - Anthropic Messages API ║ ║ POST /v1/messages - Anthropic Messages API ║
║ GET /v1/models - List available models ║ ║ GET /v1/models - List available models ║
@@ -23,6 +48,9 @@ app.listen(PORT, () => {
║ GET /account-limits - Account status & quotas ║ ║ GET /account-limits - Account status & quotas ║
║ POST /refresh-token - Force token refresh ║ ║ POST /refresh-token - Force token refresh ║
║ ║ ║ ║
║ Configuration: ║
║ Storage: ${CONFIG_DIR}
║ ║
║ Usage with Claude Code: ║ ║ Usage with Claude Code: ║
║ export ANTHROPIC_BASE_URL=http://localhost:${PORT} ║ export ANTHROPIC_BASE_URL=http://localhost:${PORT}
║ export ANTHROPIC_API_KEY=dummy ║ ║ export ANTHROPIC_API_KEY=dummy ║
@@ -37,4 +65,9 @@ app.listen(PORT, () => {
║ ║ ║ ║
╚══════════════════════════════════════════════════════════════╝ ╚══════════════════════════════════════════════════════════════╝
`); `);
logger.success(`Server started successfully on port ${PORT}`);
if (isDebug) {
logger.warn('Running in DEBUG mode - verbose logs enabled');
}
}); });

View File

@@ -14,6 +14,7 @@ import {
OAUTH_CONFIG, OAUTH_CONFIG,
OAUTH_REDIRECT_URI OAUTH_REDIRECT_URI
} from './constants.js'; } from './constants.js';
import { logger } from './utils/logger.js';
/** /**
* Generate PKCE code verifier and challenge * Generate PKCE code verifier and challenge
@@ -156,7 +157,7 @@ export function startCallbackServer(expectedState, timeoutMs = 120000) {
}); });
server.listen(OAUTH_CONFIG.callbackPort, () => { server.listen(OAUTH_CONFIG.callbackPort, () => {
console.log(`[OAuth] Callback server listening on port ${OAUTH_CONFIG.callbackPort}`); logger.info(`[OAuth] Callback server listening on port ${OAUTH_CONFIG.callbackPort}`);
}); });
// Timeout after specified duration // Timeout after specified duration
@@ -192,18 +193,18 @@ export async function exchangeCode(code, verifier) {
if (!response.ok) { if (!response.ok) {
const error = await response.text(); const error = await response.text();
console.error('[OAuth] Token exchange failed:', response.status, error); logger.error(`[OAuth] Token exchange failed: ${response.status} ${error}`);
throw new Error(`Token exchange failed: ${error}`); throw new Error(`Token exchange failed: ${error}`);
} }
const tokens = await response.json(); const tokens = await response.json();
if (!tokens.access_token) { if (!tokens.access_token) {
console.error('[OAuth] No access token in response:', tokens); logger.error('[OAuth] No access token in response:', tokens);
throw new Error('No access token received'); throw new Error('No access token received');
} }
console.log('[OAuth] Token exchange successful, access_token length:', tokens.access_token?.length); logger.info(`[OAuth] Token exchange successful, access_token length: ${tokens.access_token?.length}`);
return { return {
accessToken: tokens.access_token, accessToken: tokens.access_token,
@@ -259,7 +260,7 @@ export async function getUserEmail(accessToken) {
if (!response.ok) { if (!response.ok) {
const errorText = await response.text(); const errorText = await response.text();
console.error('[OAuth] getUserEmail failed:', response.status, errorText); logger.error(`[OAuth] getUserEmail failed: ${response.status} ${errorText}`);
throw new Error(`Failed to get user info: ${response.status}`); throw new Error(`Failed to get user info: ${response.status}`);
} }
@@ -303,7 +304,7 @@ export async function discoverProjectId(accessToken) {
return data.cloudaicompanionProject.id; return data.cloudaicompanionProject.id;
} }
} catch (error) { } catch (error) {
console.log(`[OAuth] Project discovery failed at ${endpoint}:`, error.message); logger.warn(`[OAuth] Project discovery failed at ${endpoint}:`, error.message);
} }
} }

View File

@@ -11,6 +11,7 @@ import { forceRefresh } from './token-extractor.js';
import { REQUEST_BODY_LIMIT } from './constants.js'; import { REQUEST_BODY_LIMIT } from './constants.js';
import { AccountManager } from './account-manager.js'; import { AccountManager } from './account-manager.js';
import { formatDuration } from './utils/helpers.js'; import { formatDuration } from './utils/helpers.js';
import { logger } from './utils/logger.js';
const app = express(); const app = express();
@@ -36,11 +37,11 @@ async function ensureInitialized() {
await accountManager.initialize(); await accountManager.initialize();
isInitialized = true; isInitialized = true;
const status = accountManager.getStatus(); const status = accountManager.getStatus();
console.log(`[Server] Account pool initialized: ${status.summary}`); logger.success(`[Server] Account pool initialized: ${status.summary}`);
} catch (error) { } catch (error) {
initError = error; initError = error;
initPromise = null; // Allow retry on failure initPromise = null; // Allow retry on failure
console.error('[Server] Failed to initialize account manager:', error.message); logger.error('[Server] Failed to initialize account manager:', error.message);
throw error; throw error;
} }
})(); })();
@@ -98,7 +99,14 @@ function parseError(error) {
// Request logging middleware // Request logging middleware
app.use((req, res, next) => { app.use((req, res, next) => {
console.log(`[${new Date().toISOString()}] ${req.method} ${req.path}`); // Skip logging for event logging batch unless in debug mode
if (req.path === '/api/event_logging/batch') {
if (logger.isDebugEnabled) {
logger.debug(`[${req.method}] ${req.path}`);
}
} else {
logger.info(`[${req.method}] ${req.path}`);
}
next(); next();
}); });
@@ -369,7 +377,7 @@ app.get('/v1/models', async (req, res) => {
const models = await listModels(token); const models = await listModels(token);
res.json(models); res.json(models);
} catch (error) { } catch (error) {
console.error('[API] Error listing models:', error); logger.error('[API] Error listing models:', error);
res.status(500).json({ res.status(500).json({
type: 'error', type: 'error',
error: { error: {
@@ -404,7 +412,7 @@ app.post('/v1/messages', async (req, res) => {
// Optimistic Retry: If ALL accounts are rate-limited, reset them to force a fresh check. // Optimistic Retry: If ALL accounts are rate-limited, reset them to force a fresh check.
// If we have some available accounts, we try them first. // If we have some available accounts, we try them first.
if (accountManager.isAllRateLimited()) { if (accountManager.isAllRateLimited()) {
console.log('[Server] All accounts rate-limited. Resetting state for optimistic retry.'); logger.warn('[Server] All accounts rate-limited. Resetting state for optimistic retry.');
accountManager.resetAllRateLimits(); accountManager.resetAllRateLimits();
} }
@@ -448,16 +456,16 @@ app.post('/v1/messages', async (req, res) => {
temperature temperature
}; };
console.log(`[API] Request for model: ${request.model}, stream: ${!!stream}`); logger.info(`[API] Request for model: ${request.model}, stream: ${!!stream}`);
// Debug: Log message structure to diagnose tool_use/tool_result ordering // Debug: Log message structure to diagnose tool_use/tool_result ordering
if (process.env.DEBUG) { if (logger.isDebugEnabled) {
console.log('[API] Message structure:'); logger.debug('[API] Message structure:');
messages.forEach((msg, i) => { messages.forEach((msg, i) => {
const contentTypes = Array.isArray(msg.content) const contentTypes = Array.isArray(msg.content)
? msg.content.map(c => c.type || 'text').join(', ') ? msg.content.map(c => c.type || 'text').join(', ')
: (typeof msg.content === 'string' ? 'text' : 'unknown'); : (typeof msg.content === 'string' ? 'text' : 'unknown');
console.log(` [${i}] ${msg.role}: ${contentTypes}`); logger.debug(` [${i}] ${msg.role}: ${contentTypes}`);
}); });
} }
@@ -481,7 +489,7 @@ app.post('/v1/messages', async (req, res) => {
res.end(); res.end();
} catch (streamError) { } catch (streamError) {
console.error('[API] Stream error:', streamError); logger.error('[API] Stream error:', streamError);
const { errorType, errorMessage } = parseError(streamError); const { errorType, errorMessage } = parseError(streamError);
@@ -499,13 +507,13 @@ app.post('/v1/messages', async (req, res) => {
} }
} catch (error) { } catch (error) {
console.error('[API] Error:', error); logger.error('[API] Error:', error);
let { errorType, statusCode, errorMessage } = parseError(error); let { errorType, statusCode, errorMessage } = parseError(error);
// For auth errors, try to refresh token // For auth errors, try to refresh token
if (errorType === 'authentication_error') { if (errorType === 'authentication_error') {
console.log('[API] Token might be expired, attempting refresh...'); logger.warn('[API] Token might be expired, attempting refresh...');
try { try {
accountManager.clearProjectCache(); accountManager.clearProjectCache();
accountManager.clearTokenCache(); accountManager.clearTokenCache();
@@ -516,11 +524,11 @@ app.post('/v1/messages', async (req, res) => {
} }
} }
console.log(`[API] Returning error response: ${statusCode} ${errorType} - ${errorMessage}`); logger.warn(`[API] Returning error response: ${statusCode} ${errorType} - ${errorMessage}`);
// Check if headers have already been sent (for streaming that failed mid-way) // Check if headers have already been sent (for streaming that failed mid-way)
if (res.headersSent) { if (res.headersSent) {
console.log('[API] Headers already sent, writing error as SSE event'); logger.warn('[API] Headers already sent, writing error as SSE event');
res.write(`event: error\ndata: ${JSON.stringify({ res.write(`event: error\ndata: ${JSON.stringify({
type: 'error', type: 'error',
error: { type: errorType, message: errorMessage } error: { type: errorType, message: errorMessage }
@@ -542,6 +550,9 @@ app.post('/v1/messages', async (req, res) => {
* Catch-all for unsupported endpoints * Catch-all for unsupported endpoints
*/ */
app.use('*', (req, res) => { app.use('*', (req, res) => {
if (logger.isDebugEnabled) {
logger.debug(`[API] 404 Not Found: ${req.method} ${req.originalUrl}`);
}
res.status(404).json({ res.status(404).json({
type: 'error', type: 'error',
error: { error: {

View File

@@ -11,6 +11,7 @@ import {
ANTIGRAVITY_AUTH_PORT ANTIGRAVITY_AUTH_PORT
} from './constants.js'; } from './constants.js';
import { getAuthStatus } from './db/database.js'; import { getAuthStatus } from './db/database.js';
import { logger } from './utils/logger.js';
// Cache for the extracted token // Cache for the extracted token
let cachedToken = null; let cachedToken = null;
@@ -55,22 +56,22 @@ async function getTokenData() {
try { try {
const dbData = getAuthStatus(); const dbData = getAuthStatus();
if (dbData?.apiKey) { if (dbData?.apiKey) {
console.log('[Token] Got fresh token from SQLite database'); logger.info('[Token] Got fresh token from SQLite database');
return dbData; return dbData;
} }
} catch (err) { } catch (err) {
console.log('[Token] DB extraction failed, trying HTML page...'); logger.warn('[Token] DB extraction failed, trying HTML page...');
} }
// Fallback to HTML page // Fallback to HTML page
try { try {
const pageData = await extractChatParams(); const pageData = await extractChatParams();
if (pageData?.apiKey) { if (pageData?.apiKey) {
console.log('[Token] Got token from HTML page (may be stale)'); logger.warn('[Token] Got token from HTML page (may be stale)');
return pageData; return pageData;
} }
} catch (err) { } catch (err) {
console.log('[Token] HTML page extraction failed:', err.message); logger.warn(`[Token] HTML page extraction failed: ${err.message}`);
} }
throw new Error( throw new Error(

114
src/utils/logger.js Normal file
View File

@@ -0,0 +1,114 @@
/**
* Logger Utility
*
* Provides structured logging with colors and debug support.
* Simple ANSI codes used to avoid dependencies.
*/
const COLORS = {
RESET: '\x1b[0m',
BRIGHT: '\x1b[1m',
DIM: '\x1b[2m',
RED: '\x1b[31m',
GREEN: '\x1b[32m',
YELLOW: '\x1b[33m',
BLUE: '\x1b[34m',
MAGENTA: '\x1b[35m',
CYAN: '\x1b[36m',
WHITE: '\x1b[37m',
GRAY: '\x1b[90m'
};
class Logger {
constructor() {
this.isDebugEnabled = false;
}
/**
* Set debug mode
* @param {boolean} enabled
*/
setDebug(enabled) {
this.isDebugEnabled = !!enabled;
}
/**
* Get current timestamp string
*/
getTimestamp() {
return new Date().toISOString();
}
/**
* Format and print a log message
* @param {string} level
* @param {string} color
* @param {string} message
* @param {...any} args
*/
print(level, color, message, ...args) {
// Format: [TIMESTAMP] [LEVEL] Message
const timestamp = `${COLORS.GRAY}[${this.getTimestamp()}]${COLORS.RESET}`;
const levelTag = `${color}[${level}]${COLORS.RESET}`;
console.log(`${timestamp} ${levelTag} ${message}`, ...args);
}
/**
* Standard info log
*/
info(message, ...args) {
this.print('INFO', COLORS.BLUE, message, ...args);
}
/**
* Success log
*/
success(message, ...args) {
this.print('SUCCESS', COLORS.GREEN, message, ...args);
}
/**
* Warning log
*/
warn(message, ...args) {
this.print('WARN', COLORS.YELLOW, message, ...args);
}
/**
* Error log
*/
error(message, ...args) {
this.print('ERROR', COLORS.RED, message, ...args);
}
/**
* Debug log - only prints if debug mode is enabled
*/
debug(message, ...args) {
if (this.isDebugEnabled) {
this.print('DEBUG', COLORS.MAGENTA, message, ...args);
}
}
/**
* Direct log (for raw output usually) - proxied to console.log but can be enhanced
*/
log(message, ...args) {
console.log(message, ...args);
}
/**
* Print a section header
*/
header(title) {
console.log(`\n${COLORS.BRIGHT}${COLORS.CYAN}=== ${title} ===${COLORS.RESET}\n`);
}
}
// Export a singleton instance
export const logger = new Logger();
// Export class if needed for multiple instances
export { Logger };