diff --git a/background.js b/background.js index c0e8458..42ebf38 100644 --- a/background.js +++ b/background.js @@ -376,10 +376,21 @@ async function ensureContentScriptReadyOnTab(source, tabId, options = {}) { const start = Date.now(); let lastError = null; let logged = false; + let attempt = 0; + + console.log( + LOG_PREFIX, + `[ensureContentScriptReadyOnTab] start ${source} tab=${tabId}, timeout=${timeoutMs}ms, inject=${Array.isArray(inject) ? inject.join(',') : 'none'}` + ); while (Date.now() - start < timeoutMs) { + attempt += 1; const pong = await pingContentScriptOnTab(tabId); if (pong?.ok && (!pong.source || pong.source === source)) { + console.log( + LOG_PREFIX, + `[ensureContentScriptReadyOnTab] ready ${source} tab=${tabId} on attempt ${attempt} after ${Date.now() - start}ms` + ); await registerTab(source, tabId); return; } @@ -411,15 +422,27 @@ async function ensureContentScriptReadyOnTab(source, tabId, options = {}) { }); } catch (err) { lastError = err; + console.warn( + LOG_PREFIX, + `[ensureContentScriptReadyOnTab] inject attempt ${attempt} failed for ${source} tab=${tabId}: ${err?.message || err}` + ); } const pongAfterInject = await pingContentScriptOnTab(tabId); if (pongAfterInject?.ok && (!pongAfterInject.source || pongAfterInject.source === source)) { + console.log( + LOG_PREFIX, + `[ensureContentScriptReadyOnTab] ready after inject ${source} tab=${tabId} on attempt ${attempt} after ${Date.now() - start}ms` + ); await registerTab(source, tabId); return; } if (logMessage && !logged) { + console.warn( + LOG_PREFIX, + `[ensureContentScriptReadyOnTab] ${source} tab=${tabId} still not ready after ${Date.now() - start}ms` + ); await addLog(logMessage, 'warn'); logged = true; } @@ -458,27 +481,86 @@ function getContentScriptResponseTimeoutMs(message) { return 30000; } +function getMessageDebugLabel(source, message, tabId = null) { + const parts = [source || 'unknown', message?.type || 'UNKNOWN']; + if (Number.isInteger(message?.step)) { + parts.push(`step=${message.step}`); + } + if (Number.isInteger(tabId)) { + parts.push(`tab=${tabId}`); + } + return parts.join(' '); +} + +function summarizeMessageResultForDebug(result) { + if (result === undefined) return 'undefined'; + if (result === null) return 'null'; + if (typeof result !== 'object') return JSON.stringify(result); + + const summary = {}; + for (const key of ['ok', 'error', 'stopped', 'source', 'step']) { + if (key in result) summary[key] = result[key]; + } + if (result.payload && typeof result.payload === 'object') { + summary.payloadKeys = Object.keys(result.payload); + } + return JSON.stringify(summary); +} + function sendTabMessageWithTimeout(tabId, source, message, responseTimeoutMs = getContentScriptResponseTimeoutMs(message)) { return new Promise((resolve, reject) => { let settled = false; + const startedAt = Date.now(); + const debugLabel = getMessageDebugLabel(source, message, tabId); - const finalize = (callback) => (value) => { - if (settled) return; - settled = true; - clearTimeout(timer); - callback(value); - }; + console.log(LOG_PREFIX, `[sendTabMessageWithTimeout] dispatch ${debugLabel}, timeout=${responseTimeoutMs}ms`); const timer = setTimeout(() => { if (settled) return; settled = true; const seconds = Math.ceil(responseTimeoutMs / 1000); + console.warn(LOG_PREFIX, `[sendTabMessageWithTimeout] timeout ${debugLabel} after ${Date.now() - startedAt}ms`); reject(new Error(`Content script on ${source} did not respond in ${seconds}s. Try refreshing the tab and retry.`)); }, responseTimeoutMs); chrome.tabs.sendMessage(tabId, message) - .then(finalize(resolve)) - .catch(finalize(reject)); + .then((value) => { + const elapsed = Date.now() - startedAt; + if (settled) { + console.warn( + LOG_PREFIX, + `[sendTabMessageWithTimeout] late response ignored for ${debugLabel} after ${elapsed}ms: ${summarizeMessageResultForDebug(value)}` + ); + return; + } + + settled = true; + clearTimeout(timer); + console.log( + LOG_PREFIX, + `[sendTabMessageWithTimeout] response ${debugLabel} after ${elapsed}ms: ${summarizeMessageResultForDebug(value)}` + ); + resolve(value); + }) + .catch((error) => { + const elapsed = Date.now() - startedAt; + const errorMessage = error?.message || String(error); + if (settled) { + console.warn( + LOG_PREFIX, + `[sendTabMessageWithTimeout] late rejection ignored for ${debugLabel} after ${elapsed}ms: ${errorMessage}` + ); + return; + } + + settled = true; + clearTimeout(timer); + console.warn( + LOG_PREFIX, + `[sendTabMessageWithTimeout] rejection ${debugLabel} after ${elapsed}ms: ${errorMessage}` + ); + reject(error); + }); }); } @@ -687,14 +769,36 @@ async function sendToContentScriptResilient(source, message, options = {}) { const start = Date.now(); let lastError = null; let logged = false; + let attempt = 0; + const debugLabel = getMessageDebugLabel(source, message); + + console.log( + LOG_PREFIX, + `[sendToContentScriptResilient] start ${debugLabel}, totalTimeout=${timeoutMs}ms, retryDelay=${retryDelayMs}ms` + ); while (Date.now() - start < timeoutMs) { throwIfStopped(); + attempt += 1; try { - return await sendToContentScript(source, message); + console.log( + LOG_PREFIX, + `[sendToContentScriptResilient] attempt ${attempt} -> ${debugLabel}, elapsed=${Date.now() - start}ms` + ); + const result = await sendToContentScript(source, message); + console.log( + LOG_PREFIX, + `[sendToContentScriptResilient] success ${debugLabel} on attempt ${attempt} after ${Date.now() - start}ms` + ); + return result; } catch (err) { - if (!isRetryableContentScriptTransportError(err)) { + const retryable = isRetryableContentScriptTransportError(err); + console.warn( + LOG_PREFIX, + `[sendToContentScriptResilient] attempt ${attempt} failed for ${debugLabel}, retryable=${retryable}, elapsed=${Date.now() - start}ms: ${err?.message || err}` + ); + if (!retryable) { throw err; } @@ -1312,8 +1416,13 @@ const AUTO_RUN_BACKGROUND_COMPLETED_STEPS = new Set([4, 7, 8]); function waitForStepComplete(step, timeoutMs = 120000) { return new Promise((resolve, reject) => { throwIfStopped(); + if (stepWaiters.has(step)) { + console.warn(LOG_PREFIX, `[waitForStepComplete] replacing existing waiter for step ${step}`); + } + console.log(LOG_PREFIX, `[waitForStepComplete] register step ${step}, timeout=${timeoutMs}ms`); const timer = setTimeout(() => { stepWaiters.delete(step); + console.warn(LOG_PREFIX, `[waitForStepComplete] timeout for step ${step} after ${timeoutMs}ms`); reject(new Error(`Step ${step} timed out after ${timeoutMs / 1000}s`)); }, timeoutMs); @@ -1326,11 +1435,13 @@ function waitForStepComplete(step, timeoutMs = 120000) { function notifyStepComplete(step, payload) { const waiter = stepWaiters.get(step); + console.log(LOG_PREFIX, `[notifyStepComplete] step ${step}, hasWaiter=${Boolean(waiter)}`); if (waiter) waiter.resolve(payload); } function notifyStepError(step, error) { const waiter = stepWaiters.get(step); + console.warn(LOG_PREFIX, `[notifyStepError] step ${step}, hasWaiter=${Boolean(waiter)}, error=${error}`); if (waiter) waiter.reject(new Error(error)); } @@ -2309,9 +2420,13 @@ async function refreshOAuthUrlBeforeStep6(state) { } await addLog('步骤 6:正在刷新登录用的 CPA OAuth 链接...'); + console.log(LOG_PREFIX, '[refreshOAuthUrlBeforeStep6] preparing fresh OAuth via step 1'); const waitForFreshOAuth = waitForStepComplete(1, 120000); + console.log(LOG_PREFIX, '[refreshOAuthUrlBeforeStep6] executing step 1 for fresh OAuth'); await executeStep1(state); + console.log(LOG_PREFIX, '[refreshOAuthUrlBeforeStep6] step 1 execute returned, waiting for completion signal'); await waitForFreshOAuth; + console.log(LOG_PREFIX, '[refreshOAuthUrlBeforeStep6] step 1 completion signal received'); const latestState = await getState(); if (!latestState.oauthUrl) { diff --git a/content/utils.js b/content/utils.js index 2d95fb3..2595abf 100644 --- a/content/utils.js +++ b/content/utils.js @@ -256,13 +256,20 @@ function log(message, level = 'info') { */ function reportReady() { console.log(LOG_PREFIX, '内容脚本已就绪'); - chrome.runtime.sendMessage({ + const message = { type: 'CONTENT_SCRIPT_READY', source: SCRIPT_SOURCE, step: null, payload: {}, error: null, - }); + }; + Promise.resolve(chrome.runtime.sendMessage(message)) + .then((response) => { + console.log(LOG_PREFIX, 'CONTENT_SCRIPT_READY sent successfully', { response, url: location.href }); + }) + .catch((err) => { + console.error(LOG_PREFIX, 'CONTENT_SCRIPT_READY send failed', err?.message || err, { url: location.href }); + }); } /** @@ -273,13 +280,27 @@ function reportReady() { function reportComplete(step, data = {}) { console.log(LOG_PREFIX, `步骤 ${step} 已完成`, data); log(`步骤 ${step} 已成功完成`, 'ok'); - chrome.runtime.sendMessage({ + const message = { type: 'STEP_COMPLETE', source: SCRIPT_SOURCE, step, payload: data, error: null, - }); + }; + Promise.resolve(chrome.runtime.sendMessage(message)) + .then((response) => { + console.log(LOG_PREFIX, `STEP_COMPLETE sent successfully for step ${step}`, { + response, + url: location.href, + payloadKeys: Object.keys(data || {}), + }); + }) + .catch((err) => { + console.error(LOG_PREFIX, `STEP_COMPLETE send failed for step ${step}`, err?.message || err, { + url: location.href, + payloadKeys: Object.keys(data || {}), + }); + }); } /** @@ -290,13 +311,27 @@ function reportComplete(step, data = {}) { function reportError(step, errorMessage) { console.error(LOG_PREFIX, `步骤 ${step} 失败: ${errorMessage}`); log(`步骤 ${step} 失败:${errorMessage}`, 'error'); - chrome.runtime.sendMessage({ + const message = { type: 'STEP_ERROR', source: SCRIPT_SOURCE, step, payload: {}, error: errorMessage, - }); + }; + Promise.resolve(chrome.runtime.sendMessage(message)) + .then((response) => { + console.log(LOG_PREFIX, `STEP_ERROR sent successfully for step ${step}`, { + response, + url: location.href, + errorMessage, + }); + }) + .catch((err) => { + console.error(LOG_PREFIX, `STEP_ERROR send failed for step ${step}`, err?.message || err, { + url: location.href, + errorMessage, + }); + }); } /** diff --git a/content/vps-panel.js b/content/vps-panel.js index 0361931..0b7ca49 100644 --- a/content/vps-panel.js +++ b/content/vps-panel.js @@ -34,9 +34,23 @@ if (document.documentElement.getAttribute(VPS_PANEL_LISTENER_SENTINEL) !== '1') chrome.runtime.onMessage.addListener((message, sender, sendResponse) => { if (message.type === 'EXECUTE_STEP') { resetStopState(); + const startedAt = Date.now(); + console.log(LOG_PREFIX, `EXECUTE_STEP received for step ${message.step}`, { + url: location.href, + payloadKeys: Object.keys(message.payload || {}), + snapshot: getVpsPanelSnapshot(), + }); handleStep(message.step, message.payload).then(() => { + console.log(LOG_PREFIX, `EXECUTE_STEP resolved for step ${message.step} after ${Date.now() - startedAt}ms`, { + url: location.href, + snapshot: getVpsPanelSnapshot(), + }); sendResponse({ ok: true }); }).catch(err => { + console.error(LOG_PREFIX, `EXECUTE_STEP rejected for step ${message.step} after ${Date.now() - startedAt}ms: ${err?.message || err}`, { + url: location.href, + snapshot: getVpsPanelSnapshot(), + }); if (isStopError(err)) { log(`步骤 ${message.step}:已被用户停止。`, 'warn'); sendResponse({ stopped: true, error: err.message }); @@ -84,6 +98,63 @@ function getActionText(el) { .trim(); } +function getInlineTextSnippet(text, maxLength = 160) { + const normalized = (text || '').replace(/\s+/g, ' ').trim(); + if (!normalized) return ''; + if (normalized.length <= maxLength) return normalized; + return `${normalized.slice(0, maxLength)}...`; +} + +function getPageTextSnippet(maxLength = 240) { + const bodyText = document.body?.innerText || document.documentElement?.innerText || ''; + return getInlineTextSnippet(bodyText, maxLength); +} + +function getVpsPanelSnapshot() { + const authUrlEl = findAuthUrlElement(); + const oauthHeader = findCodexOAuthHeader(); + const managementKeyInput = findManagementKeyInput(); + const managementLoginButton = findManagementLoginButton(); + const rememberCheckbox = findRememberPasswordCheckbox(); + const oauthNavLink = findOAuthNavLink(); + + return { + url: location.href, + readyState: document.readyState, + title: getInlineTextSnippet(document.title || '', 80), + authUrlVisible: Boolean(authUrlEl), + authUrlText: getInlineTextSnippet(authUrlEl?.textContent || '', 120), + oauthHeaderVisible: Boolean(oauthHeader), + oauthHeaderText: getInlineTextSnippet(oauthHeader?.textContent || '', 120), + managementKeyVisible: Boolean(managementKeyInput), + managementLoginVisible: Boolean(managementLoginButton), + managementLoginText: getInlineTextSnippet(getActionText(managementLoginButton), 60), + rememberCheckboxVisible: Boolean(rememberCheckbox), + rememberCheckboxChecked: Boolean(rememberCheckbox?.checked), + oauthNavVisible: Boolean(oauthNavLink), + oauthNavText: getInlineTextSnippet(getActionText(oauthNavLink), 80), + bodySnippet: getPageTextSnippet(), + }; +} + +function getVpsPanelSnapshotSignature(snapshot) { + return JSON.stringify({ + readyState: snapshot.readyState, + title: snapshot.title, + authUrlVisible: snapshot.authUrlVisible, + authUrlText: snapshot.authUrlText, + oauthHeaderVisible: snapshot.oauthHeaderVisible, + oauthHeaderText: snapshot.oauthHeaderText, + managementKeyVisible: snapshot.managementKeyVisible, + managementLoginVisible: snapshot.managementLoginVisible, + rememberCheckboxVisible: snapshot.rememberCheckboxVisible, + rememberCheckboxChecked: snapshot.rememberCheckboxChecked, + oauthNavVisible: snapshot.oauthNavVisible, + oauthNavText: snapshot.oauthNavText, + bodySnippet: snapshot.bodySnippet, + }); +} + function parseUrlSafely(rawUrl) { if (!rawUrl) return null; try { @@ -210,17 +281,42 @@ async function ensureOAuthManagementPage(vpsPassword, step = 1, timeout = 45000) const start = Date.now(); let lastLoginAttemptAt = 0; let lastOauthNavAttemptAt = 0; + let lastSnapshotSignature = ''; + let lastSnapshotLogAt = 0; + + console.log(LOG_PREFIX, `[Step ${step}] ensureOAuthManagementPage start`, { + timeout, + url: location.href, + hasVpsPassword: Boolean(vpsPassword), + snapshot: getVpsPanelSnapshot(), + }); while (Date.now() - start < timeout) { throwIfStopped(); + const elapsed = Date.now() - start; + const snapshot = getVpsPanelSnapshot(); + const signature = getVpsPanelSnapshotSignature(snapshot); + if (signature !== lastSnapshotSignature || elapsed - lastSnapshotLogAt >= 5000) { + lastSnapshotSignature = signature; + lastSnapshotLogAt = elapsed; + console.log(LOG_PREFIX, `[Step ${step}] panel snapshot at ${elapsed}ms`, snapshot); + } const authUrlEl = findAuthUrlElement(); if (authUrlEl) { + console.log(LOG_PREFIX, `[Step ${step}] found visible auth URL after ${elapsed}ms`, { + url: location.href, + authUrlText: getInlineTextSnippet(authUrlEl.textContent || '', 120), + }); return { header: findCodexOAuthHeader(), authUrlEl }; } const oauthHeader = findCodexOAuthHeader(); if (oauthHeader) { + console.log(LOG_PREFIX, `[Step ${step}] found OAuth card header after ${elapsed}ms`, { + url: location.href, + headerText: getInlineTextSnippet(oauthHeader.textContent || '', 120), + }); return { header: oauthHeader, authUrlEl: null }; } @@ -234,12 +330,14 @@ async function ensureOAuthManagementPage(vpsPassword, step = 1, timeout = 45000) if ((managementKeyInput.value || '') !== vpsPassword) { await humanPause(350, 900); fillInput(managementKeyInput, vpsPassword); + console.log(LOG_PREFIX, `[Step ${step}] filled management key after ${elapsed}ms`); log(`步骤 ${step}:已填写 CPA 管理密钥。`); } const rememberCheckbox = findRememberPasswordCheckbox(); if (rememberCheckbox && !rememberCheckbox.checked) { simulateClick(rememberCheckbox); + console.log(LOG_PREFIX, `[Step ${step}] toggled remember checkbox after ${elapsed}ms`); log(`步骤 ${step}:已勾选 CPA 面板“记住密码”。`); await sleep(300); } @@ -248,6 +346,9 @@ async function ensureOAuthManagementPage(vpsPassword, step = 1, timeout = 45000) lastLoginAttemptAt = Date.now(); await humanPause(350, 900); simulateClick(managementLoginButton); + console.log(LOG_PREFIX, `[Step ${step}] clicked management login after ${elapsed}ms`, { + buttonText: getInlineTextSnippet(getActionText(managementLoginButton), 80), + }); log(`步骤 ${step}:已提交 CPA 管理登录。`); } @@ -260,6 +361,9 @@ async function ensureOAuthManagementPage(vpsPassword, step = 1, timeout = 45000) lastOauthNavAttemptAt = Date.now(); await humanPause(300, 800); simulateClick(oauthNavLink); + console.log(LOG_PREFIX, `[Step ${step}] clicked OAuth nav after ${elapsed}ms`, { + navText: getInlineTextSnippet(getActionText(oauthNavLink), 80), + }); log(`步骤 ${step}:已打开“OAuth 登录”导航。`); await sleep(1200); continue; @@ -268,6 +372,11 @@ async function ensureOAuthManagementPage(vpsPassword, step = 1, timeout = 45000) await sleep(250); } + console.error(LOG_PREFIX, `[Step ${step}] ensureOAuthManagementPage timeout after ${Date.now() - start}ms`, { + url: location.href, + snapshot: getVpsPanelSnapshot(), + }); + throw new Error('无法进入 CPA 的 OAuth 管理页面,请检查面板是否正常加载。URL: ' + location.href); } @@ -277,11 +386,22 @@ async function ensureOAuthManagementPage(vpsPassword, step = 1, timeout = 45000) async function step1_getOAuthLink(payload) { const { vpsPassword } = payload || {}; + console.log(LOG_PREFIX, '[Step 1] step1_getOAuthLink start', { + url: location.href, + hasVpsPassword: Boolean(vpsPassword), + snapshot: getVpsPanelSnapshot(), + }); log('步骤 1:正在等待 CPA 面板加载并进入 OAuth 页面...'); const { header, authUrlEl: existingAuthUrlEl } = await ensureOAuthManagementPage(vpsPassword, 1); let authUrlEl = existingAuthUrlEl; + console.log(LOG_PREFIX, '[Step 1] ensureOAuthManagementPage resolved', { + url: location.href, + hasHeader: Boolean(header), + hasExistingAuthUrl: Boolean(existingAuthUrlEl), + snapshot: getVpsPanelSnapshot(), + }); if (!authUrlEl) { const loginBtn = findOAuthCardLoginButton(header); @@ -290,10 +410,18 @@ async function step1_getOAuthLink(payload) { } if (loginBtn.disabled) { + console.log(LOG_PREFIX, '[Step 1] OAuth login button is disabled, waiting for auth URL', { + url: location.href, + buttonText: getInlineTextSnippet(getActionText(loginBtn), 80), + }); log('步骤 1:OAuth 登录按钮当前不可用,正在等待授权链接出现...'); } else { await humanPause(500, 1400); simulateClick(loginBtn); + console.log(LOG_PREFIX, '[Step 1] clicked OAuth login button and waiting for auth URL', { + url: location.href, + buttonText: getInlineTextSnippet(getActionText(loginBtn), 80), + }); log('步骤 1:已点击 OAuth 登录按钮,正在等待授权链接...'); } @@ -315,6 +443,10 @@ async function step1_getOAuthLink(payload) { } log(`步骤 1:已获取 OAuth 链接:${oauthUrl.slice(0, 80)}...`, 'ok'); + console.log(LOG_PREFIX, '[Step 1] reporting completion with oauthUrl', { + url: location.href, + oauthUrlPreview: oauthUrl.slice(0, 120), + }); reportComplete(1, { oauthUrl }); }