本地检测问题日志代码

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) {

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,
+      });
+    });
 }
 
 /**

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 });
 }