chore(日志): 服务端高频轮询日志降噪

-history timing 降debug；status无变化降debug；/history /list免INFO；stale-check合并单行；心跳常规响应降debug
2026-09-11 21:22:41 +08:00
parent db7cd22ed1
commit 037a689316
5 changed files with 26 additions and 50 deletions
@@ -128,7 +128,9 @@ public class RequestTraceFilter extends OncePerRequestFilter {
        return !(normalized.contains("/heartbeat")
                || normalized.contains("/progress")
                || normalized.contains("/poll")
-                || normalized.contains("/status"));
+                || normalized.contains("/status")
+                || normalized.contains("/history")
+                || normalized.contains("/list"));
    }

    private static String firstNonBlank(String... values) {
@@ -94,7 +94,6 @@ public class DeleteBrandStaleTaskService {
        }
        try (lockHandle) {
            long startedAt = System.currentTimeMillis();
-            log.info("[stale-check] scan started thread={}", Thread.currentThread().getName());
            failStaleDeleteBrandTasks();
            ProductRiskStaleCheckStats stats = failStaleProductRiskResolveTasks();
            PriceTrackStaleCheckStats priceTrackStats = failStalePriceTrackTasks();
@@ -105,46 +104,14 @@ public class DeleteBrandStaleTaskService {
            runModuleStaleCheck("brand", brandTaskService::failStaleRunningTasks);
            runModuleStaleCheck("appearance-patent", appearancePatentTaskService::finalizeStaleTasks);
            runModuleStaleCheck("similar-asin", similarAsinTaskService::finalizeStaleTasks);
-            log.info("[stale-check] product-risk summary scanned={} finalized={} failed={} skipped={} elapsedMs={} thread={}",
-                    stats.scannedTaskCount,
-                    stats.finalizedTaskCount,
-                    stats.failedTaskCount,
-                    stats.skippedTaskCount,
-                    System.currentTimeMillis() - startedAt,
-                    Thread.currentThread().getName());
-            log.info("[stale-check] price-track summary scanned={} finalized={} failed={} skipped={} elapsedMs={} thread={}",
-                    priceTrackStats.scannedTaskCount,
-                    priceTrackStats.finalizedTaskCount,
-                    priceTrackStats.failedTaskCount,
-                    priceTrackStats.skippedTaskCount,
-                    System.currentTimeMillis() - startedAt,
-                    Thread.currentThread().getName());
-            log.info("[stale-check] shop-match summary scanned={} finalized={} failed={} skipped={} elapsedMs={} thread={}",
-                    shopMatchStats.scannedTaskCount,
-                    shopMatchStats.finalizedTaskCount,
-                    shopMatchStats.failedTaskCount,
-                    shopMatchStats.skippedTaskCount,
-                    System.currentTimeMillis() - startedAt,
-                    Thread.currentThread().getName());
-            log.info("[stale-check] patrol-delete summary scanned={} finalized={} failed={} skipped={} elapsedMs={} thread={}",
-                    patrolDeleteStats.scannedTaskCount,
-                    patrolDeleteStats.finalizedTaskCount,
-                    patrolDeleteStats.failedTaskCount,
-                    patrolDeleteStats.skippedTaskCount,
-                    System.currentTimeMillis() - startedAt,
-                    Thread.currentThread().getName());
-            log.info("[stale-check] query-asin summary scanned={} finalized={} failed={} skipped={} elapsedMs={} thread={}",
-                    queryAsinStats.scannedTaskCount,
-                    queryAsinStats.finalizedTaskCount,
-                    queryAsinStats.failedTaskCount,
-                    queryAsinStats.skippedTaskCount,
-                    System.currentTimeMillis() - startedAt,
-                    Thread.currentThread().getName());
-            log.info("[stale-check] withdraw summary scanned={} finalized={} failed={} skipped={} elapsedMs={} thread={}",
-                    withdrawStats.scannedTaskCount,
-                    withdrawStats.finalizedTaskCount,
-                    withdrawStats.failedTaskCount,
-                    withdrawStats.skippedTaskCount,
+            // 周期每 2 分钟一轮，各模块 summary 合并为单行，避免定期刷屏
+            log.info("[stale-check] summary product-risk(s={} f={} x={}/{} p={}) price-track(s={} f={} x={}/{} p={}) shop-match(s={} f={} x={}/{} p={}) patrol-delete(s={} f={} x={}/{} p={}) query-asin(s={} f={} x={}/{} p={}) withdraw(s={} f={} x={}/{} p={}) elapsedMs={} thread={}",
+                    stats.scannedTaskCount, stats.finalizedTaskCount, stats.failedTaskCount, stats.skippedTaskCount,
+                    priceTrackStats.scannedTaskCount, priceTrackStats.finalizedTaskCount, priceTrackStats.failedTaskCount, priceTrackStats.skippedTaskCount,
+                    shopMatchStats.scannedTaskCount, shopMatchStats.finalizedTaskCount, shopMatchStats.failedTaskCount, shopMatchStats.skippedTaskCount,
+                    patrolDeleteStats.scannedTaskCount, patrolDeleteStats.finalizedTaskCount, patrolDeleteStats.failedTaskCount, patrolDeleteStats.skippedTaskCount,
+                    queryAsinStats.scannedTaskCount, queryAsinStats.finalizedTaskCount, queryAsinStats.failedTaskCount, queryAsinStats.skippedTaskCount,
+                    withdrawStats.scannedTaskCount, withdrawStats.finalizedTaskCount, withdrawStats.failedTaskCount, withdrawStats.skippedTaskCount,
                    System.currentTimeMillis() - startedAt,
                    Thread.currentThread().getName());
        }
@@ -207,7 +207,7 @@ public class PriceTrackTaskService {
        long resultRowsLoadedAt = System.nanoTime();
        if (entities.isEmpty()) {
            vo.setItems(List.of());
-            log.info("[price-track] history timing userId={} rows=0 totalMs={} resultQueryMs={} taskQueryMs=0 jobQueryMs=0 buildMs=0",
+            log.debug("[price-track] history timing userId={} rows=0 totalMs={} resultQueryMs={} taskQueryMs=0 jobQueryMs=0 buildMs=0",
                    userId, elapsedMs(startedAt, resultRowsLoadedAt), elapsedMs(startedAt, resultRowsLoadedAt));
            return vo;
        }
@@ -236,7 +236,7 @@ public class PriceTrackTaskService {
        }
        vo.setItems(items);
        long finishedAt = System.nanoTime();
-        log.info("[price-track] history timing userId={} rows={} tasks={} jobs={} totalMs={} resultQueryMs={} taskQueryMs={} jobQueryMs={} buildMs={}",
+        log.debug("[price-track] history timing userId={} rows={} tasks={} jobs={} totalMs={} resultQueryMs={} taskQueryMs={} jobQueryMs={} buildMs={}",
                userId,
                entities.size(),
                taskById.size(),
@@ -2130,8 +2130,14 @@ public class PriceTrackTaskService {
            log.warn("[price-track] compact result json failed: {}", ex.getMessage());
        }
        fileTaskMapper.updateById(task);
-        log.warn("[price-track] status updated from latest rows taskId={} oldStatus={} newStatus={} ok={} fail={} allDone={} errorMessage={}",
+        // 轮询期间可能频繁触发状态回写：无变化且无失败时降为 debug，避免刷屏
+        if (!oldStatus.equals(task.getStatus()) || ok > 0 || fail > 0 || task.getErrorMessage() != null) {
+            log.info("[price-track] status updated taskId={} oldStatus={} newStatus={} ok={} fail={} allDone={} errorMessage={}",
                    task.getId(), oldStatus, task.getStatus(), ok, fail, allDone, task.getErrorMessage());
+        } else {
+            log.debug("[price-track] status unchanged taskId={} status={} ok={} fail={}",
+                    task.getId(), task.getStatus(), ok, fail);
+        }
        cleanupTaskCacheIfTerminal(task.getId(), task.getStatus());
        if ("SUCCESS".equals(task.getStatus()) || "FAILED".equals(task.getStatus())) {
            priceTrackLoopRunService.syncLoopRunAfterChildTerminal(task.getId());
@@ -106,7 +106,7 @@ public class TaskHeartbeatService {
        if (brandResult != null) {
            return brandResult;
        }
-        log.warn("[task-heartbeat] task not found taskId={} fileFound=false brandFound=false", taskId);
+        log.debug("[task-heartbeat] task not found (normal polling) taskId={} fileFound=false brandFound=false", taskId);
        return TaskHeartbeatVo.notAlive(null, null, "task not found");
    }

@@ -163,7 +163,7 @@ public class TaskHeartbeatService {
            log.info("[task-interrupted] brand task not in running/pending, skipped taskId={} status={}", taskId, status);
            return TaskHeartbeatVo.notAlive(MODULE_BRAND, status, "task is not running");
        }
-        log.warn("[task-interrupted] task not found taskId={}", taskId);
+        log.debug("[task-interrupted] task not found (normal polling) taskId={}", taskId);
        return TaskHeartbeatVo.notAlive(null, null, "task not found");
    }

@@ -187,7 +187,7 @@ public class TaskHeartbeatService {
        }
        String status = task.getStatus();
        if (!STATUS_RUNNING.equals(status)) {
-            log.warn("[task-heartbeat] file task is not running taskId={} actualUserId={} moduleType={} status={}",
+            log.debug("[task-heartbeat] file task is not running (normal polling) taskId={ actualUserId={} moduleType={} status={}",
                    task.getId(), task.getUserId(), moduleType, status);
            return TaskHeartbeatVo.notAlive(moduleType, status, "task is not running");
        }
@@ -171,7 +171,8 @@ public class TransientPayloadStorageService {
        // 同一个 pointer 可能被多个 biz_task_chunk / biz_task_scope_state 行共享。
        // 删之前先反查一次，确认没有别的行还在引用，再真正落地物理删除。
        if (isStillReferenced(pointer, value)) {
-            log.info("[transient-payload] skip delete, still referenced pointer={}", pointer);
+            // 常规高频路径：引用未清零属正常状态，降为 debug 避免刷屏
+            log.debug("[transient-payload] skip delete, still referenced pointer={}", pointer);
            return;
        }
        if (pointer.startsWith(LOCAL_POINTER_PREFIX)) {