diff --git a/src/lib/fetch-utils.ts b/src/lib/fetch-utils.ts index 085dc22..01553b9 100644 --- a/src/lib/fetch-utils.ts +++ b/src/lib/fetch-utils.ts @@ -74,6 +74,21 @@ export class SSELineBuffer { } } +// ─── Structured logging helper ───────────────────────────────────────── + +const LOG_PREFIX = "[fetch-utils]"; + +function logProxy(method: string, msg: string, extra?: Record): void { + const ts = new Date().toISOString().slice(11, 23); + const parts = [`${LOG_PREFIX} ${ts}`, `method=${method}`, msg]; + if (extra) { + for (const [k, v] of Object.entries(extra)) { + parts.push(`${k}=${v ?? "null"}`); + } + } + console.log(parts.join(" ")); +} + // ─── Error sanitization (prevent leaking upstream details) ────────────── /** @@ -140,17 +155,22 @@ export async function fetchWithRetry( usedProxy = false; } + const proxyShort = init.proxy ? init.proxy.replace(/https?:\/\//, "").replace(/@.*/, "@***") : "direct"; + logProxy("fetchWithRetry", `attempt=${attempt + 1}/3 proxy=${proxyShort}`, { context }); + try { response = await fetch(url, init); if (response.ok) { if (usedProxy && proxyPool && proxyPool.size > 0) { proxyPool.markSuccess(); } + logProxy("fetchWithRetry", `success attempt=${attempt + 1} status=${response.status}`, { context }); return { response }; } // Non-2xx — mark proxy as failed and retry lastError = new Error(`Upstream returned ${response.status}`); + logProxy("fetchWithRetry", `non-2xx attempt=${attempt + 1} status=${response.status}`, { context }); if (usedProxy && proxyPool && proxyPool.size > 0 && init.proxy) { proxyPool.markFailed(); usedProxy = false; @@ -165,6 +185,7 @@ export async function fetchWithRetry( // Log the actual error so operators can diagnose const ctx = context ? `[${context}] ` : ""; const errMsg = err instanceof Error ? err.message : String(err); + logProxy("fetchWithRetry", `failed attempt=${attempt + 1} err=${errMsg}`, { context }); console.warn(`${ctx}fetch attempt ${attempt + 1}/3 failed: ${errMsg}`); } } @@ -172,10 +193,12 @@ export async function fetchWithRetry( // All attempts exhausted — classify the last error if (!response) { const err = lastError ?? new Error("All connection attempts failed"); + logProxy("fetchWithRetry", "exhausted all retries", { context }); return { errorClassification: classifyFetchErrorSafe(err) }; } // Non-2xx but we have a response — pass it along (caller handles it) + logProxy("fetchWithRetry", `returning non-2xx response status=${response.status}`, { context }); return { response }; } @@ -237,6 +260,7 @@ export async function fetchWithSessionRetry( ): Promise { // Fallback when no session pool is available if (!sessionPool) { + logProxy("fetchWithSessionRetry", "no session pool — direct fetch", { context, sessionId: sessionId.slice(0, 8) }); try { const response = await fetch(url, init); return { response }; @@ -258,17 +282,35 @@ export async function fetchWithSessionRetry( init.proxy = proxyUrl; } + const proxyShort = init.proxy + ? init.proxy.replace(/https?:\/\//, "").replace(/@.*/, "@***") + : "direct"; + logProxy("fetchWithSessionRetry", `attempt=${attempt + 1}/${maxRetries} proxy=${proxyShort}`, { + context, + sessionId: sessionId.slice(0, 8), + }); + try { const response = await fetch(url, init); if (response.ok) { sessionPool.markSuccess(sessionId); + logProxy("fetchWithSessionRetry", `success attempt=${attempt + 1} status=${response.status}`, { + context, + sessionId: sessionId.slice(0, 8), + proxy: proxyShort, + }); return { response }; } // Non-2xx — mark session failed and retry lastError = new Error(`Upstream returned ${response.status}`); const rotated = sessionPool.markFailed(sessionId); + logProxy("fetchWithSessionRetry", `non-2xx attempt=${attempt + 1} status=${response.status} rotated=${rotated}`, { + context, + sessionId: sessionId.slice(0, 8), + proxy: proxyShort, + }); const ctx = context ? `[${context}] ` : ""; console.warn( @@ -278,9 +320,14 @@ export async function fetchWithSessionRetry( } catch (err) { lastError = err; const rotated = sessionPool.markFailed(sessionId); + const errMsg = err instanceof Error ? err.message : String(err); + logProxy("fetchWithSessionRetry", `failed attempt=${attempt + 1} err=${errMsg} rotated=${rotated}`, { + context, + sessionId: sessionId.slice(0, 8), + proxy: proxyShort, + }); const ctx = context ? `[${context}] ` : ""; - const errMsg = err instanceof Error ? err.message : String(err); console.warn( `${ctx}fetchWithSessionRetry attempt ${attempt + 1}/${maxRetries} ` + `failed: ${errMsg}${rotated ? " (rotated proxy)" : ""}`, @@ -289,6 +336,10 @@ export async function fetchWithSessionRetry( } // All attempts exhausted — release session and classify last error + logProxy("fetchWithSessionRetry", "exhausted all retries — releasing session", { + context, + sessionId: sessionId.slice(0, 8), + }); sessionPool.release(sessionId); const err = lastError ?? new Error("All session proxy attempts failed"); return { errorClassification: classifyFetchErrorSafe(err) }; diff --git a/src/lib/proxy-pool.ts b/src/lib/proxy-pool.ts index 82d7a1b..05a04e7 100644 --- a/src/lib/proxy-pool.ts +++ b/src/lib/proxy-pool.ts @@ -19,6 +19,19 @@ export interface ProxyEntry { // --- ProxyPool --------------------------------------------------------------- +const POOL_PREFIX = "[proxy-pool]"; + +function logPool(msg: string, extra?: Record): void { + const ts = new Date().toISOString().slice(11, 23); + const parts = [`${POOL_PREFIX} ${ts}`, msg]; + if (extra) { + for (const [k, v] of Object.entries(extra)) { + parts.push(`${k}=${v ?? "null"}`); + } + } + console.log(parts.join(" ")); +} + export class ProxyPool { private proxies: ProxyEntry[] = []; private currentIndex = 0; @@ -71,11 +84,7 @@ export class ProxyPool { this.currentIndex = 0; this.failures.clear(); - if (this.proxies.length > 0) { - console.log( - `[proxy-pool] Loaded ${this.proxies.length} proxies from ${filePath}`, - ); - } + logPool(`loaded ${this.proxies.length} proxies from ${filePath}`); } /** @@ -112,7 +121,9 @@ export class ProxyPool { getProxyUrl(): string | null { const entry = this.getCurrent(); if (!entry) return null; - return this.formatProxyUrl(entry); + const url = this.formatProxyUrl(entry); + logPool(`getProxyUrl -> ${entry.host}:${entry.port}`, { index: this.currentIndex }); + return url; } /** Build a `http://user:pass@host:port` URL from an entry. */ @@ -131,8 +142,11 @@ export class ProxyPool { */ rotate(): ProxyEntry | null { if (this.proxies.length === 0) return null; + const oldIndex = this.currentIndex; this.currentIndex = (this.currentIndex + 1) % this.proxies.length; - return this.proxies[this.currentIndex] ?? null; + const entry = this.proxies[this.currentIndex] ?? null; + logPool(`rotate ${oldIndex} -> ${this.currentIndex}`, { host: entry?.host }); + return entry; } /** @@ -152,6 +166,7 @@ export class ProxyPool { this.failures.set(key, count); const th = threshold ?? this.failureThreshold; + logPool(`markFailed ${key} (${count}/${th})`); if (count >= th) { console.warn( `[proxy-pool] Proxy ${key} failed ${count}/${th} times -- skipping`, @@ -164,7 +179,9 @@ export class ProxyPool { const entry = this.getCurrent(); if (!entry) return true; const key = `${entry.host}:${entry.port}`; - return (this.failures.get(key) ?? 0) >= (threshold ?? this.failureThreshold); + const failed = (this.failures.get(key) ?? 0) >= (threshold ?? this.failureThreshold); + if (failed) logPool(`isFailed true for ${key}`); + return failed; } /** Reset the failure counter for the current proxy. */ @@ -172,6 +189,7 @@ export class ProxyPool { const entry = this.getCurrent(); if (!entry) return; this.failures.delete(`${entry.host}:${entry.port}`); + logPool(`markSuccess ${entry.host}:${entry.port}`); } /** Set the failure count that triggers a permanent skip. */ @@ -215,6 +233,7 @@ export class SessionProxyPool { if (poolOrPath) this.pool.load(poolOrPath); } this.failureThreshold = 3; + logPool(`SessionProxyPool created, poolSize=${this.pool.size}`); } /** Number of available proxies in the underlying pool. */ @@ -240,6 +259,7 @@ export class SessionProxyPool { const existing = this.sessions.get(sessionId); if (existing !== undefined) { + logPool(`acquire existing session=${sessionId.slice(0, 8)} proxyIndex=${existing.proxyIndex}`); return this.formatProxyUrlAtIndex(existing.proxyIndex); } @@ -255,6 +275,8 @@ export class SessionProxyPool { } usedBy.add(sessionId); + const entry = this.poolEntryAtIndex(index); + logPool(`acquire session=${sessionId.slice(0, 8)} -> proxyIndex=${index} host=${entry?.host} activeSessions=${this.activeSessions}`); return this.formatProxyUrlAtIndex(index); } @@ -262,6 +284,8 @@ export class SessionProxyPool { getProxyUrl(sessionId: string): string | null { const info = this.sessions.get(sessionId); if (!info) return null; + const entry = this.poolEntryAtIndex(info.proxyIndex); + logPool(`getProxyUrl session=${sessionId.slice(0, 8)} proxyIndex=${info.proxyIndex} host=${entry?.host}`); return this.formatProxyUrlAtIndex(info.proxyIndex); } @@ -277,6 +301,8 @@ export class SessionProxyPool { } this.sessions.delete(sessionId); + const entry = this.poolEntryAtIndex(info.proxyIndex); + logPool(`release session=${sessionId.slice(0, 8)} proxyIndex=${info.proxyIndex} host=${entry?.host} activeSessions=${this.activeSessions}`); } /** @@ -292,9 +318,12 @@ export class SessionProxyPool { if (!info) return false; info.failures += 1; + logPool(`markFailed session=${sessionId.slice(0, 8)} proxyIndex=${info.proxyIndex} failures=${info.failures}/${this.failureThreshold}`); + if (info.failures < this.failureThreshold) return false; const oldIndex = info.proxyIndex; + const oldEntry = this.poolEntryAtIndex(oldIndex); // Mark in underlying pool (public API only works on currentIndex) const savedIdx = (this.pool as any).currentIndex as number; @@ -314,6 +343,7 @@ export class SessionProxyPool { if (newIndex === -1 || newIndex === oldIndex) { // Single-proxy pool or none available — reset failures, stay put this.sessions.set(sessionId, { proxyIndex: oldIndex, failures: 0 }); + logPool(`markFailed no alternative, staying on oldIndex=${oldIndex} host=${oldEntry?.host}`); return false; } @@ -326,6 +356,8 @@ export class SessionProxyPool { } newUsedBy.add(sessionId); + const newEntry = this.poolEntryAtIndex(newIndex); + logPool(`markFailed rotated session=${sessionId.slice(0, 8)} ${oldEntry?.host} -> ${newEntry?.host}`); return true; } @@ -334,6 +366,7 @@ export class SessionProxyPool { const info = this.sessions.get(sessionId); if (!info) return; info.failures = 0; + logPool(`markSuccess session=${sessionId.slice(0, 8)} proxyIndex=${info.proxyIndex}`); } // -- Internals ---------------------------------------------------------------- @@ -362,12 +395,14 @@ export class SessionProxyPool { for (let i = 0; i < this.pool.size; i++) { const count = this.proxyUsage.get(i)?.size ?? 0; + logPool(`pickLeastUsed proxy[${i}] count=${count}`); if (count < bestCount) { bestCount = count; bestIndex = i; } } + logPool(`pickLeastUsed selected index=${bestIndex} count=${bestCount}`); return bestIndex; }