chore(logging): 降噪 PDD 同步与发单消费者常态日志

将无新单/全跳过的处理完成日志降到 debug，并压缩 decisions 详情，避免 app 日志被按日切碎。 Co-authored-by: Cursor <cursoragent@cursor.com>
2026-09-15 13:48:30 +08:00
parent 40c51e1d8e
commit 40278a68fc
5 changed files with 111 additions and 48 deletions
@@ -17,7 +17,7 @@ import {
  publishWorkOrderRealtimeChange,
 } from '../realtime/realtime-event-service.js'
 import { nowIso } from '../../utils/time.js'
-import { logInfo, logIntegration, logWarn } from '../../utils/logger.js'
+import { logDebug, logInfo, logIntegration, logWarn } from '../../utils/logger.js'
 import { createHttpError } from '../../utils/http.js'
 import type { OrderItemRow, OrderRow, TaskRow } from '../../types/repository/rows.js'

@@ -211,21 +211,14 @@ export async function upsertOrderFromSource(
      source: `${sourceLabel}_order_upsert`,
      autoOnly: true,
    })
-    logInfo('[order-consumer-router]', '来源订单消费者分流完成', {
+    logDebug('[order-consumer-router]', '来源订单消费者分流完成（履约未就绪）', {
      source: sourceLabel,
      orderId: order.id,
      platformOrderId: order.platform_order_id,
-      fulfillment: {
-        result: 'blocked',
-        reason: readiness.blockReason,
-        detail: readiness.reason,
-        orderItemIds: configuredOrderItems.map((item) => item.id),
-      },
-      workerPlatform: {
-        createdCount: workOrderSync.createdCount,
-        skippedCount: workOrderSync.skippedCount,
-        decisions: workOrderSync.decisions,
-      },
+      fulfillmentResult: 'blocked',
+      fulfillmentReason: readiness.blockReason || readiness.reason,
+      workerCreatedCount: workOrderSync.createdCount,
+      workerSkippedCount: workOrderSync.skippedCount,
    })
    publishSourceOrderRealtimeChanges(order.id, workOrderSync.created)
    return {
@@ -353,33 +346,61 @@ function logOrderConsumerOutcome({
    source: sourceLabel,
    orderId: order.id,
    platformOrderId: order.platform_order_id,
-    fulfillment: {
-      configuredOrderItemIds: Array.from(configuredItemIds),
-      taskIds: tasks.map((task) => task.id),
-      taskCount: tasks.length,
-      missingItems: missingFulfillmentItems,
-    },
-    workerPlatform: {
-      createdCount: workerCreatedCount,
-      skippedCount: workerSkippedCount,
-      decisions: workerDecisions,
-    },
-    dualConsumedOrderItemIds,
-    unhandledOrderItems,
+    fulfillmentTaskCount: tasks.length,
+    fulfillmentConfiguredCount: configuredItemIds.size,
+    fulfillmentMissingCount: missingFulfillmentItems.length,
+    workerCreatedCount,
+    workerSkippedCount,
+    workerSkipReasons: summarizeWorkerDecisionReasons(workerDecisions),
+    dualConsumedCount: dualConsumedOrderItemIds.length,
+    unhandledCount: unhandledOrderItems.length,
+  }
+
+  const hasSignal =
+    workerCreatedCount > 0 ||
+    tasks.length > 0 ||
+    missingFulfillmentItems.length > 0 ||
+    dualConsumedOrderItemIds.length > 0
+
+  // 常态 PDD 重拉：无履约任务、工单全跳过，仅 debug；避免 decisions 大对象撑爆日志文件。
+  if (hasSignal) {
+    logInfo('[order-consumer-router]', '来源订单消费者分流完成', detail)
+  } else {
+    logDebug('[order-consumer-router]', '来源订单消费者分流完成', detail)
  }

-  logInfo('[order-consumer-router]', '来源订单消费者分流完成', detail)
  if (missingFulfillmentItems.length > 0) {
-    logWarn('[order-consumer-router]', '已配置履约的订单项存在任务缺口', detail)
+    logWarn('[order-consumer-router]', '已配置履约的订单项存在任务缺口', {
+      ...detail,
+      missingItems: missingFulfillmentItems.slice(0, 5),
+    })
  }
  if (dualConsumedOrderItemIds.length > 0) {
-    logWarn('[order-consumer-router]', '同一订单项被履约与发单平台消费者同时接收', detail)
+    logWarn('[order-consumer-router]', '同一订单项被履约与发单平台消费者同时接收', {
+      ...detail,
+      dualConsumedOrderItemIds: dualConsumedOrderItemIds.slice(0, 20),
+    })
  }
+  // 「未匹配接单规则」对大量 PDD 商品是常态，降到 debug；真正的缺口用上面的 missing 告警。
  if (unhandledOrderItems.length > 0) {
-    logWarn('[order-consumer-router]', '订单项未被履约或发单平台消费者接收', detail)
+    logDebug('[order-consumer-router]', '订单项未被履约或发单平台消费者接收', {
+      ...detail,
+      unhandledSkuCodes: unhandledOrderItems
+        .slice(0, 10)
+        .map((item) => String(item.skuCode || item.skuName || item.orderItemId)),
+    })
  }
 }

+function summarizeWorkerDecisionReasons(decisions: Array<Record<string, unknown>>) {
+  const counts: Record<string, number> = {}
+  for (const decision of decisions) {
+    const reason = String(decision.reason || decision.result || 'unknown').trim() || 'unknown'
+    counts[reason] = (counts[reason] || 0) + 1
+  }
+  return Object.keys(counts).length > 0 ? JSON.stringify(counts) : ''
+}
+
 function resolveOrderItemRouteDiagnostic(item: OrderItemRow) {
  const snapshot = parseOrderItemSnapshot(item.item_snapshot_json) || {}
  const sendCode =
@@ -25,7 +25,7 @@ import {
 import { findExistingPlatformOrderIds } from '../../../repositories/order-repo.js'
 import { notifyPddCookieExpired } from '../../notification/domain-notifications.js'
 import { upsertOrderFromSource } from '../../order/order-service.js'
-import { logError, logInfo, logWarn } from '../../../utils/logger.js'
+import { logDebug, logError, logInfo, logWarn } from '../../../utils/logger.js'

 export interface SyncStoreOrdersOptions {
  pageNumber?: number | undefined
@@ -44,6 +44,8 @@ export interface SyncStoreResult {
  total: number
  fetchedCount: number
  upsertedCount: number
+  /** 本轮判定为库内未见过的新单数量（用于日志降噪，不等于 upsert 次数）。 */
+  newOrderCount: number
  ignoredCount: number
  failedCount: number
  pagesFetched: number
@@ -108,6 +110,7 @@ export async function syncStoreOrders(
      total: 0,
      fetchedCount: 0,
      upsertedCount: 0,
+      newOrderCount: 0,
      ignoredCount: 0,
      failedCount: 0,
      pagesFetched: 0,
@@ -136,6 +139,7 @@ export async function syncStoreOrders(
  let totalReported = 0
  let totalFetched = 0
  let totalUpserted = 0
+  let totalNewOrders = 0
  let totalIgnored = 0
  let totalFailed = 0

@@ -179,6 +183,7 @@ export async function syncStoreOrders(

      const existingCountOnPage = existingOrderSns.size
      const newCountOnPage = pageOrderSns.length - existingCountOnPage
+      totalNewOrders += Math.max(0, newCountOnPage)

      const doUpsert = options.upsertFn || upsertOrderFromSource

@@ -205,7 +210,9 @@ export async function syncStoreOrders(
        }
      }

-      logInfo(
+      // 本页无新单时降到 debug，避免每 20s 一轮把日志打满。
+      const pageLog = newCountOnPage > 0 || totalFailed > 0 ? logInfo : logDebug
+      pageLog(
        '[pdd-sync]',
        `店铺 ${shopName} 第 ${currentPage} 页处理完成 (本页拉取: ${items.length}, 新单: ${newCountOnPage}, 库中已有: ${existingCountOnPage})`,
        {
@@ -269,12 +276,15 @@ export async function syncStoreOrders(
      totalOrders: totalReported,
    }).catch(() => null)

-    logInfo('[pdd-sync]', `店铺 ${shopName} 同步完成 (共拉取 ${pagesFetched} 页)`, {
+    // 仅「真正新单 / 失败 / 多页回填」打 info；常态触达旧单后停页的空跑降到 debug。
+    const storeDoneLog = totalNewOrders > 0 || totalFailed > 0 || pagesFetched > 1 ? logInfo : logDebug
+    storeDoneLog('[pdd-sync]', `店铺 ${shopName} 同步完成 (共拉取 ${pagesFetched} 页)`, {
      shopId,
      total: totalReported,
      pagesFetched,
      fetchedCount: totalFetched,
      upsertedCount: totalUpserted,
+      newOrderCount: totalNewOrders,
      ignoredCount: totalIgnored,
      failedCount: totalFailed,
    })
@@ -285,6 +295,7 @@ export async function syncStoreOrders(
      total: totalReported,
      fetchedCount: totalFetched,
      upsertedCount: totalUpserted,
+      newOrderCount: totalNewOrders,
      ignoredCount: totalIgnored,
      failedCount: totalFailed,
      pagesFetched,
@@ -319,6 +330,7 @@ export async function syncStoreOrders(
      total: totalReported,
      fetchedCount: totalFetched,
      upsertedCount: totalUpserted,
+      newOrderCount: totalNewOrders,
      ignoredCount: totalIgnored,
      failedCount: totalFailed,
      pagesFetched,
@@ -4,7 +4,7 @@
 */

 import type { JsonObject } from '../../types/json.js'
-import { logInfo } from '../../utils/logger.js'
+import { logDebug, logInfo } from '../../utils/logger.js'
 import { syncAllPddStores } from '../platforms/pdd/pdd-sync-service.js'
 import { getPddSourcesConfig } from '../platforms/pdd/pdd-source-config-service.js'

@@ -39,24 +39,29 @@ export async function runPddOrderSyncJob(job: JsonObject) {
  const failedCount = syncResult.results.filter((r) => Boolean(r.error)).length
  const totalUpserted = syncResult.results.reduce((acc, r) => acc + r.upsertedCount, 0)
  const totalFetched = syncResult.results.reduce((acc, r) => acc + r.fetchedCount, 0)
+  const totalNewOrders = syncResult.results.reduce((acc, r) => acc + r.newOrderCount, 0)

-  logInfo('[pdd-order-sync-job]', '拼多多定时拉单执行完成', {
+  const jobLog = totalNewOrders > 0 || failedCount > 0 ? logInfo : logDebug
+  jobLog('[pdd-order-sync-job]', '拼多多定时拉单执行完成', {
    storeCount: syncResult.storeCount,
    syncedCount: syncResult.syncedCount,
    okCount,
    failedCount,
    totalFetched,
    totalUpserted,
+    totalNewOrders,
  })

  return {
    ok: failedCount === 0,
    status: failedCount > 0 ? (okCount > 0 ? 'partial_error' : 'failed') : 'ok',
-    message: `已同步 ${syncResult.syncedCount} 个店铺，拉取 ${totalFetched} 单，入库/更新 ${totalUpserted} 单${failedCount > 0 ? `，失败 ${failedCount} 个店铺` : ''}`,
+    message: `已同步 ${syncResult.syncedCount} 个店铺，拉取 ${totalFetched} 单，新单 ${totalNewOrders}，入库/更新 ${totalUpserted} 单${failedCount > 0 ? `，失败 ${failedCount} 个店铺` : ''}`,
    accountCount: syncResult.storeCount,
    checkedCount: syncResult.syncedCount,
    okCount,
    failedCount,
-    asset: totalUpserted,
+    asset: totalNewOrders,
+    totalUpserted,
+    totalNewOrders,
  }
 }
@@ -1,4 +1,4 @@
-import { logError, logInfo, logWarn } from '../../utils/logger.js'
+import { logDebug, logError, logInfo, logWarn } from '../../utils/logger.js'
 import { createHttpError } from '../../utils/http.js'
 import type { JsonObject } from '../../types/json.js'
 import { getScheduledJobById, getScheduledJobsConfig } from './config-service.js'
@@ -147,10 +147,15 @@ async function runJob(job: JsonObject, { manual = false }: { manual?: boolean }
      lastFailedCount: Number(summary.failedCount || 0),
      lastManual: manual,
    })
-    logInfo('[scheduler]', '定时任务执行完成', {
+    const status = String(summary.status || 'ok')
+    const failedCount = Number(summary.failedCount || 0)
+    // 成功且无失败的周期空跑降到 debug（PDD 约 20s 一轮），手动触发与失败仍保留 info。
+    const isQuietSuccess = !manual && status === 'ok' && failedCount <= 0 && job.type !== 'data_retention'
+    const doneLog = isQuietSuccess ? logDebug : logInfo
+    doneLog('[scheduler]', '定时任务执行完成', {
      jobId,
      type: job.type,
-      status: String(summary.status || 'ok'),
+      status,
      ...(job.type === 'data_retention'
        ? {
            rawPayloadRows: Number(summary.rawPayloadRows || 0),
@@ -20,7 +20,7 @@ import type { JsonObject } from '../../types/json.js'
 import type { OrderItemRow, OrderRow } from '../../types/repository/rows.js'
 import { generateWorkOrderNo, randomId } from '../../utils/random.js'
 import { nowIso } from '../../utils/time.js'
-import { logInfo, logWarn } from '../../utils/logger.js'
+import { logDebug, logInfo, logWarn } from '../../utils/logger.js'
 import { safeParseJson } from '../admin/admin-query-utils.js'
 import { createWorkOrderMaterialAdminNotification } from '../admin/admin-notification-service.js'
 import {
@@ -272,23 +272,29 @@ export async function syncWorkerOrdersForSourceOrder(
    }
  }

-  logInfo('[worker-order-consumer]', '发单平台消费者处理完成', {
+  const summary = {
    source: options.source || 'source_order',
    orderId: order.id,
    platformOrderId: order.platform_order_id,
    orderItemCount: orderItems.length,
    createdCount: created.length,
    skippedCount: skipped.length,
-    decisions,
-  })
+    skipReasons: formatDecisionReasonCounts(skipped),
+  }
+
+  // 常态「全跳过」每轮 PDD upsert 都会触发，降到 debug，避免日志按天被切碎。
+  if (created.length > 0) {
+    logInfo('[worker-order-consumer]', '发单平台消费者处理完成', summary)
+  } else {
+    logDebug('[worker-order-consumer]', '发单平台消费者无新建工单', summary)
+  }

  const failedDecisions = decisions.filter((decision) => decision.result === 'failed')
  if (failedDecisions.length > 0) {
    logWarn('[worker-order-consumer]', '发单平台消费者存在未成功落库的订单项', {
-      source: options.source || 'source_order',
-      orderId: order.id,
-      platformOrderId: order.platform_order_id,
-      decisions: failedDecisions,
+      ...summary,
+      failedCount: failedDecisions.length,
+      failedReasons: formatDecisionReasonCounts(failedDecisions),
    })
  }

@@ -323,3 +329,17 @@ function buildWorkerConsumerDecision(
    ...detail,
  }
 }
+
+function formatDecisionReasonCounts(decisions: Array<Record<string, unknown>>) {
+  const counts = summarizeDecisionReasons(decisions)
+  return Object.keys(counts).length > 0 ? JSON.stringify(counts) : ''
+}
+
+function summarizeDecisionReasons(decisions: Array<Record<string, unknown>>) {
+  const counts: Record<string, number> = {}
+  for (const decision of decisions) {
+    const reason = String(decision.reason || decision.result || 'unknown').trim() || 'unknown'
+    counts[reason] = (counts[reason] || 0) + 1
+  }
+  return counts
+}