Browse Source

✨ feat: 完善代理日志输出

Pchen0 4 days ago
parent
commit
09f2b74cfa

+ 3 - 1
lib/Lepao/QgProxyManager.js

@@ -416,7 +416,9 @@ async function invalidateCurrent(reason, detail) {
 
 
 async function recordFallbackDirect(detail) {
 async function recordFallbackDirect(detail) {
     const d = typeof detail === 'object' && detail !== null ? detail : { message: String(detail || '') }
     const d = typeof detail === 'object' && detail !== null ? detail : { message: String(detail || '') }
-    logger.warn(`[QgProxy] 乐跑出站回退直连 reason=${JSON.stringify(d)}`)
+    const tid = d.trace_id || d.mq_task_id
+    const head = tid ? `[${tid}] ` : ''
+    logger.warn(`${head}[QgProxy] 乐跑出站回退直连 reason=${JSON.stringify(d)}`)
     await recordLog({
     await recordLog({
         event: 'fallback_direct',
         event: 'fallback_direct',
         detail: d
         detail: d

+ 6 - 11
lib/Lepao/Worker.js

@@ -78,19 +78,14 @@ class Worker {
     isCommonLepaoErrorMessage(msg) {
     isCommonLepaoErrorMessage(msg) {
         const m = String(msg || '')
         const m = String(msg || '')
         return (
         return (
-            m.includes('当天已乐跑成功') ||
-            m.includes('当前不在有效乐跑时间范围内') ||
-            // 登录失效/过期(多种文案变体)
-            m.includes('乐跑账号登录已过期') ||
+            m.includes('已乐跑成功') ||
+            m.includes('不在有效乐跑时间范围内') ||
             m.includes('登录已过期') ||
             m.includes('登录已过期') ||
             m.includes('登录信息失效') ||
             m.includes('登录信息失效') ||
             m.includes('登录失效') ||
             m.includes('登录失效') ||
             m.includes('登录状态异常') ||
             m.includes('登录状态异常') ||
-            m.includes('token已过期') ||
-            m.includes('token 过期') ||
-            m.includes('Token已过期') ||
-            m.includes('Token 过期') ||
-            // 兜底:出现“重新登录”通常也是登录态问题
+            m.includes('已达上限') ||
+            m.includes('次数不足') ||
             m.includes('请重新登录')
             m.includes('请重新登录')
         )
         )
     }
     }
@@ -440,7 +435,8 @@ class Worker {
                     timeout: this.httpTimeoutMs,
                     timeout: this.httpTimeoutMs,
                     logger: this.logger,
                     logger: this.logger,
                     outboundMode: ctx?.outboundMode || 'auto',
                     outboundMode: ctx?.outboundMode || 'auto',
-                    mqTaskId: ctx?.taskId
+                    mqTaskId: ctx?.taskId,
+                    traceId
                 }),
                 }),
                 name,
                 name,
                 this.httpTimeoutMs,
                 this.httpTimeoutMs,
@@ -465,7 +461,6 @@ class Worker {
                 if (failedByCode || failedByStatus) {
                 if (failedByCode || failedByStatus) {
                     const message = this.extractApiErrorMessage(name, result)
                     const message = this.extractApiErrorMessage(name, result)
                     const err = new Error(message)
                     const err = new Error(message)
-                    // 学习 Lepao.js:若明确提示重新登录,自动标记账号失效
                     if (message.includes('重新登录')) {
                     if (message.includes('重新登录')) {
                         await this.markLoginExpired(raw?.student_num)
                         await this.markLoginExpired(raw?.student_num)
                     }
                     }

+ 2 - 0
lib/Lepao/lepaoProxyLogDisplay.js

@@ -35,6 +35,8 @@ function summarizeLogRow(record) {
         if (d.code) lines.push(`错误码:${d.code}`)
         if (d.code) lines.push(`错误码:${d.code}`)
         if (d.status) lines.push(`HTTP:${d.status}`)
         if (d.status) lines.push(`HTTP:${d.status}`)
     } else if (event === 'fallback_direct') {
     } else if (event === 'fallback_direct') {
+        if (d.trace_id) lines.push(`任务 trace:${d.trace_id}`)
+        if (d.mq_task_id) lines.push(`MQ 任务 id:${d.mq_task_id}`)
         if (d.reason) lines.push(`触发原因:${d.reason}`)
         if (d.reason) lines.push(`触发原因:${d.reason}`)
         if (d.reason === 'exhausted_proxy_then_direct') {
         if (d.reason === 'exhausted_proxy_then_direct') {
             lines.push('多轮提取与经代理 POST 均未成功,已改直连接口')
             lines.push('多轮提取与经代理 POST 均未成功,已改直连接口')

+ 47 - 20
lib/Lepao/lepaoSchoolHttp.js

@@ -68,6 +68,15 @@ function briefUrlPath(fullUrl) {
     }
     }
 }
 }
 
 
+/** 与 Worker 日志对齐:先 traceId(如 1778232257819_dfpcft),再模块名,可选 MQ 任务 id */
+function lepaoHttpLogLabel(traceId, mqTaskId) {
+    let s = ''
+    if (traceId) s += `[${traceId}] `
+    s += '[lepaoSchoolHttp]'
+    if (mqTaskId) s += ` [${mqTaskId}]`
+    return s
+}
+
 function isQgProxyEligibleFailure(err) {
 function isQgProxyEligibleFailure(err) {
     if (!err) return false
     if (!err) return false
     const status = err.response?.status
     const status = err.response?.status
@@ -115,15 +124,15 @@ function isProxyTlsHandshakeReset(err) {
 async function logSchoolOutbound(logger, phase, url, axiosMerge, opts = {}) {
 async function logSchoolOutbound(logger, phase, url, axiosMerge, opts = {}) {
     if (!logger?.info) return
     if (!logger?.info) return
     const path = briefUrlPath(url)
     const path = briefUrlPath(url)
-    const taskPrefix = opts.mqTaskId ? ` [${opts.mqTaskId}]` : ''
+    const label = lepaoHttpLogLabel(opts.traceId, opts.mqTaskId)
     if (!axiosMerge || axiosMerge.proxy === false || !axiosMerge.proxy) {
     if (!axiosMerge || axiosMerge.proxy === false || !axiosMerge.proxy) {
-        logger.info(`[lepaoSchoolHttp]${taskPrefix} ${phase} POST 出站=直连 path=${path}`)
+        logger.info(`${label} ${phase} POST 出站=直连 path=${path}`)
         return
         return
     }
     }
     const conn = `${axiosMerge.proxy.host}:${axiosMerge.proxy.port}`
     const conn = `${axiosMerge.proxy.host}:${axiosMerge.proxy.port}`
     if (opts.skipQgSnapshot) {
     if (opts.skipQgSnapshot) {
         logger.info(
         logger.info(
-            `[lepaoSchoolHttp]${taskPrefix} ${phase} POST 出站=调试HTTP代理(非青果) 连接=${conn} path=${path}`
+            `${label} ${phase} POST 出站=调试HTTP代理(非青果) 连接=${conn} path=${path}`
         )
         )
         return
         return
     }
     }
@@ -132,7 +141,7 @@ async function logSchoolOutbound(logger, phase, url, axiosMerge, opts = {}) {
     const egress = snap?.proxyIp ?? '(暂无 proxy_ip)'
     const egress = snap?.proxyIp ?? '(暂无 proxy_ip)'
     const dl = snap?.deadline ?? '—'
     const dl = snap?.deadline ?? '—'
     logger.info(
     logger.info(
-        `[lepaoSchoolHttp]${taskPrefix} ${phase} POST 出站=HTTP代理 节点server=${serverRecord} 连接${conn} 出口IP(proxy_ip)=${egress} deadline=${dl} path=${path}`
+        `${label} ${phase} POST 出站=HTTP代理 节点server=${serverRecord} 连接${conn} 出口IP(proxy_ip)=${egress} deadline=${dl} path=${path}`
     )
     )
 }
 }
 
 
@@ -140,8 +149,15 @@ async function logSchoolOutbound(logger, phase, url, axiosMerge, opts = {}) {
  * 对 lepao.ctbu.edu.cn 的 POST:优先隧道代理;失败快速直连并记日志(隧道池出口由服务商后台切换)。
  * 对 lepao.ctbu.edu.cn 的 POST:优先隧道代理;失败快速直连并记日志(隧道池出口由服务商后台切换)。
  */
  */
 async function postLepaoSchool(url, data, options = {}) {
 async function postLepaoSchool(url, data, options = {}) {
-    const { headers = {}, timeout = 15000, logger = null, outboundMode = 'auto', mqTaskId = null } = options
-    const taskPrefix = mqTaskId ? `[${mqTaskId}] ` : ''
+    const {
+        headers = {},
+        timeout = 15000,
+        logger = null,
+        outboundMode = 'auto',
+        mqTaskId = null,
+        traceId = null
+    } = options
+    const logLabel = () => lepaoHttpLogLabel(traceId, mqTaskId)
 
 
     const doPost = async (qgProxyFragment, requestTimeout = timeout) => {
     const doPost = async (qgProxyFragment, requestTimeout = timeout) => {
         const outbound = buildAxiosOutboundConfig(qgProxyFragment)
         const outbound = buildAxiosOutboundConfig(qgProxyFragment)
@@ -154,20 +170,24 @@ async function postLepaoSchool(url, data, options = {}) {
 
 
     // 强制直连:策略 A 用(任务内固定出站,禁止中途切换)
     // 强制直连:策略 A 用(任务内固定出站,禁止中途切换)
     if (outboundMode === 'direct') {
     if (outboundMode === 'direct') {
-        await logSchoolOutbound(logger, '(强制直连)', url, { proxy: false }, { mqTaskId })
+        await logSchoolOutbound(logger, '(强制直连)', url, { proxy: false }, { mqTaskId, traceId })
         return doPost({ proxy: false })
         return doPost({ proxy: false })
     }
     }
 
 
     if (debugProxyEnabled()) {
     if (debugProxyEnabled()) {
         const dbg = debugProxyAxiosFragment()
         const dbg = debugProxyAxiosFragment()
-        await logSchoolOutbound(logger, 'Charles调试代理', url, dbg, { skipQgSnapshot: true })
-        logger?.info?.('[lepaoSchoolHttp] 使用本地调试代理 LEPAO_DEBUG_PROXY')
+        await logSchoolOutbound(logger, 'Charles调试代理', url, dbg, {
+            skipQgSnapshot: true,
+            mqTaskId,
+            traceId
+        })
+        logger?.info?.(`${logLabel()} 使用本地调试代理 LEPAO_DEBUG_PROXY`)
         return doPost(dbg)
         return doPost(dbg)
     }
     }
 
 
     const qgOn = await QgProxyManager.isOutboundProxyEnabled()
     const qgOn = await QgProxyManager.isOutboundProxyEnabled()
     if (!qgOn) {
     if (!qgOn) {
-        await logSchoolOutbound(logger, '(青果出站未启用)', url, { proxy: false }, { mqTaskId })
+        await logSchoolOutbound(logger, '(青果出站未启用)', url, { proxy: false }, { mqTaskId, traceId })
         return doPost({ proxy: false })
         return doPost({ proxy: false })
     }
     }
 
 
@@ -181,11 +201,12 @@ async function postLepaoSchool(url, data, options = {}) {
             err.retryable = true
             err.retryable = true
             throw err
             throw err
         }
         }
-        logger?.error?.(`[lepaoSchoolHttp] ${taskPrefix}青果提取多次重试仍失败,改直连: ${e0.message || e0}`)
-        await logSchoolOutbound(logger, '(青果提取异常→直连)', url, { proxy: false })
+        logger?.error?.(`${logLabel()} 青果提取多次重试仍失败,改直连: ${e0.message || e0}`)
+        await logSchoolOutbound(logger, '(青果提取异常→直连)', url, { proxy: false }, { mqTaskId, traceId })
         await QgProxyManager.recordFallbackDirect({
         await QgProxyManager.recordFallbackDirect({
             reason: 'qg_extract_error',
             reason: 'qg_extract_error',
             mq_task_id: mqTaskId,
             mq_task_id: mqTaskId,
+            trace_id: traceId,
             ...summarizeAxiosError(e0)
             ...summarizeAxiosError(e0)
         })
         })
         return doPost({ proxy: false })
         return doPost({ proxy: false })
@@ -201,19 +222,23 @@ async function postLepaoSchool(url, data, options = {}) {
     }
     }
 
 
     if (frag.proxy === false) {
     if (frag.proxy === false) {
-        logger?.warn?.(`[lepaoSchoolHttp] ${taskPrefix}无可用青果节点,对学校 POST 将直连`)
+        logger?.warn?.(`${logLabel()} 无可用青果节点,对学校 POST 将直连`)
         if (outboundMode === 'proxy') {
         if (outboundMode === 'proxy') {
             const err = new Error('代理模式无可用节点')
             const err = new Error('代理模式无可用节点')
             err.code = 'PROXY_REQUIRED_NO_NODE'
             err.code = 'PROXY_REQUIRED_NO_NODE'
             err.retryable = true
             err.retryable = true
             throw err
             throw err
         }
         }
-        await logSchoolOutbound(logger, '(无缓存节点→直连)', url, { proxy: false }, { mqTaskId })
-        await QgProxyManager.recordFallbackDirect({ reason: 'no_proxy_available', mq_task_id: mqTaskId })
+        await logSchoolOutbound(logger, '(无缓存节点→直连)', url, { proxy: false }, { mqTaskId, traceId })
+        await QgProxyManager.recordFallbackDirect({
+            reason: 'no_proxy_available',
+            mq_task_id: mqTaskId,
+            trace_id: traceId
+        })
         return doPost({ proxy: false })
         return doPost({ proxy: false })
     }
     }
 
 
-    await logSchoolOutbound(logger, '首次请求', url, frag, { mqTaskId })
+    await logSchoolOutbound(logger, '首次请求', url, frag, { mqTaskId, traceId })
     try {
     try {
         const proxyFirstTimeoutMs = 20000
         const proxyFirstTimeoutMs = 20000
         return await doPost(frag, proxyFirstTimeoutMs)
         return await doPost(frag, proxyFirstTimeoutMs)
@@ -226,7 +251,7 @@ async function postLepaoSchool(url, data, options = {}) {
         }
         }
         if (!isQgProxyEligibleFailure(e1)) throw e1
         if (!isQgProxyEligibleFailure(e1)) throw e1
         logger?.warn?.(
         logger?.warn?.(
-            `[lepaoSchoolHttp] ${taskPrefix}经代理首次请求失败,将直接回退直连。err=${e1.message || e1} ${JSON.stringify(
+            `${logLabel()} 经代理首次请求失败,将直接回退直连。err=${e1.message || e1} ${JSON.stringify(
                 summarizeAxiosError(e1)
                 summarizeAxiosError(e1)
             )}`
             )}`
         )
         )
@@ -234,23 +259,25 @@ async function postLepaoSchool(url, data, options = {}) {
         const tls1 = isProxyTlsHandshakeReset(e1)
         const tls1 = isProxyTlsHandshakeReset(e1)
         if (tls1) {
         if (tls1) {
             logger?.warn?.(
             logger?.warn?.(
-                `[lepaoSchoolHttp] ${taskPrefix}TLS 握手前经代理断开,隧道池模式直接直连(由服务商后台自动切换出口)`
+                `${logLabel()} TLS 握手前经代理断开,隧道池模式直接直连(由服务商后台自动切换出口)`
             )
             )
-            await logSchoolOutbound(logger, '(TLS隧道异常→直连)', url, { proxy: false }, { mqTaskId })
+            await logSchoolOutbound(logger, '(TLS隧道异常→直连)', url, { proxy: false }, { mqTaskId, traceId })
             await QgProxyManager.recordFallbackDirect({
             await QgProxyManager.recordFallbackDirect({
                 reason: 'tls_prefinish_reset_direct',
                 reason: 'tls_prefinish_reset_direct',
                 path: briefUrlPath(url),
                 path: briefUrlPath(url),
                 mq_task_id: mqTaskId,
                 mq_task_id: mqTaskId,
+                trace_id: traceId,
                 ...summarizeAxiosError(e1)
                 ...summarizeAxiosError(e1)
             })
             })
             return doPost({ proxy: false })
             return doPost({ proxy: false })
         }
         }
 
 
-        await logSchoolOutbound(logger, '(代理失败→直连)', url, { proxy: false }, { mqTaskId })
+        await logSchoolOutbound(logger, '(代理失败→直连)', url, { proxy: false }, { mqTaskId, traceId })
         await QgProxyManager.recordFallbackDirect({
         await QgProxyManager.recordFallbackDirect({
             reason: 'proxy_post_failed_then_direct',
             reason: 'proxy_post_failed_then_direct',
             path: briefUrlPath(url),
             path: briefUrlPath(url),
             mq_task_id: mqTaskId,
             mq_task_id: mqTaskId,
+            trace_id: traceId,
             ...summarizeAxiosError(e1)
             ...summarizeAxiosError(e1)
         })
         })
         return doPost({ proxy: false })
         return doPost({ proxy: false })