From 4117673c66366c57916064b7cfd5a4c0fa25bd57 Mon Sep 17 00:00:00 2001
From: Junjie <fallin.jie@qq.com>
Date: 星期六, 18 四月 2026 15:58:09 +0800
Subject: [PATCH] #算法日志
---
src/main/java/com/zy/core/utils/station/StationRerouteProcessor.java | 103 ++++++++++++++++++++++++++++++++++++++++++++-------
1 files changed, 88 insertions(+), 15 deletions(-)
diff --git a/src/main/java/com/zy/core/utils/station/StationRerouteProcessor.java b/src/main/java/com/zy/core/utils/station/StationRerouteProcessor.java
index a433445..83cce40 100644
--- a/src/main/java/com/zy/core/utils/station/StationRerouteProcessor.java
+++ b/src/main/java/com/zy/core/utils/station/StationRerouteProcessor.java
@@ -37,6 +37,7 @@
import com.zy.core.utils.station.model.RerouteExecutionResult;
import com.zy.core.utils.station.model.RerouteSceneType;
import com.zy.core.utils.WmsOperateUtils;
+import lombok.extern.slf4j.Slf4j;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Component;
@@ -47,12 +48,15 @@
import java.util.Map;
import java.util.Objects;
+@Slf4j
@Component
public class StationRerouteProcessor {
private static final int OUT_ORDER_DISPATCH_LIMIT_SECONDS = 2;
private static final long STATION_MOVE_RESET_WAIT_MS = 1000L;
private static final int RUN_BLOCK_DIRECT_REASSIGN_LIMIT_SECONDS = 8 * 60;
private static final int RUN_BLOCK_DIRECT_REASSIGN_NEAREST_CACHE_SECONDS = 60 * 60 * 24;
+ private static final long CHECK_STATION_OUT_ORDER_SLOW_THRESHOLD_MS = 200L;
+ private static final long EXECUTE_REROUTE_PLAN_SLOW_THRESHOLD_MS = 200L;
@Autowired
private WrkMastService wrkMastService;
@@ -150,16 +154,19 @@
}
public void checkStationOutOrder(BasDevp basDevp, StationObjModel stationObjModel) {
+ long totalStartMs = System.currentTimeMillis();
try {
if (basDevp == null || basDevp.getDevpNo() == null || stationObjModel == null || stationObjModel.getStationId() == null) {
return;
}
+ long runtimeStartMs = System.currentTimeMillis();
StationThread stationThread = (StationThread) SlaveConnection.get(SlaveType.Devp, basDevp.getDevpNo());
if (stationThread == null) {
return;
}
Map<Integer, StationProtocol> statusMap = stationThread.getStatusMap();
StationProtocol stationProtocol = statusMap == null ? null : statusMap.get(stationObjModel.getStationId());
+ long runtimeCostMs = System.currentTimeMillis() - runtimeStartMs;
if (stationProtocol == null
|| !stationProtocol.isAutoing()
|| !stationProtocol.isLoading()
@@ -169,17 +176,25 @@
return;
}
+ long loadWrkStartMs = System.currentTimeMillis();
WrkMast wrkMast = wrkMastService.selectByWorkNo(stationProtocol.getTaskNo());
+ long loadWrkCostMs = System.currentTimeMillis() - loadWrkStartMs;
if (wrkMast == null
|| !Objects.equals(wrkMast.getWrkSts(), WrkStsType.STATION_RUN.sts)
|| Objects.equals(stationProtocol.getStationId(), wrkMast.getStaNo())) {
return;
}
- if (stationOutboundDecisionSupport.shouldSkipOutOrderDispatchForExistingRoute(wrkMast.getWrkNo(), stationProtocol.getStationId())) {
+ long skipCheckStartMs = System.currentTimeMillis();
+ boolean skipForExistingRoute = stationOutboundDecisionSupport
+ .shouldSkipOutOrderDispatchForExistingRoute(wrkMast.getWrkNo(), stationProtocol.getStationId());
+ long skipCheckCostMs = System.currentTimeMillis() - skipCheckStartMs;
+ if (skipForExistingRoute) {
return;
}
+ long pathFactorStartMs = System.currentTimeMillis();
Double pathLenFactor = stationOutboundDecisionSupport.resolveOutboundPathLenFactor(wrkMast);
+ long pathFactorCostMs = System.currentTimeMillis() - pathFactorStartMs;
RerouteContext context = RerouteContext.create(
RerouteSceneType.OUT_ORDER,
basDevp,
@@ -193,7 +208,29 @@
.withSuppressDispatchGuard()
.withOutOrderDispatchLock()
.withResetSegmentCommandsBeforeDispatch();
- executeSharedReroute(context);
+ long rerouteStartMs = System.currentTimeMillis();
+ RerouteExecutionResult result = executeSharedReroute(context);
+ long rerouteCostMs = System.currentTimeMillis() - rerouteStartMs;
+ long totalCostMs = System.currentTimeMillis() - totalStartMs;
+ log.info("checkStationOutOrder profile, taskNo={}, stationId={}, deviceNo={}, batch={}, batchSeq={}, finalTargetStationId={}, pathLenFactor={}, runtimeCostMs={}ms, loadWrkCostMs={}ms, skipCheckCostMs={}ms, pathFactorCostMs={}ms, rerouteCostMs={}ms, totalCostMs={}ms, result={}",
+ stationProtocol.getTaskNo(),
+ stationProtocol.getStationId(),
+ stationObjModel.getDeviceNo(),
+ wrkMast.getBatch(),
+ wrkMast.getBatchSeq(),
+ wrkMast.getStaNo(),
+ pathLenFactor,
+ runtimeCostMs,
+ loadWrkCostMs,
+ skipCheckCostMs,
+ pathFactorCostMs,
+ rerouteCostMs,
+ totalCostMs,
+ result == null ? null : result.skipReason());
+ if (totalCostMs > CHECK_STATION_OUT_ORDER_SLOW_THRESHOLD_MS) {
+ log.warn("checkStationOutOrder slow, taskNo={}, stationId={}, totalCostMs={}ms, rerouteCostMs={}ms, loadWrkCostMs={}ms, pathFactorCostMs={}ms",
+ stationProtocol.getTaskNo(), stationProtocol.getStationId(), totalCostMs, rerouteCostMs, loadWrkCostMs, pathFactorCostMs);
+ }
} catch (Exception e) {
e.printStackTrace();
}
@@ -284,6 +321,7 @@
}
public RerouteDecision resolveSharedRerouteDecision(RerouteContext context) {
+ long startMs = System.currentTimeMillis();
if (context == null || context.wrkMast() == null || context.stationProtocol() == null) {
return RerouteDecision.skip("missing-runtime-dependency");
}
@@ -295,9 +333,13 @@
if (context.sceneType() == RerouteSceneType.IDLE_RECOVER
&& !Objects.equals(context.wrkMast().getWrkSts(), WrkStsType.STATION_RUN.sts)) {
Integer targetStationId = context.wrkMast().getStaNo();
- return targetStationId == null || Objects.equals(targetStationId, currentStationId)
+ RerouteDecision decision = targetStationId == null || Objects.equals(targetStationId, currentStationId)
? RerouteDecision.skip("same-station")
: RerouteDecision.proceed(targetStationId);
+ log.info("resolveSharedRerouteDecision profile, sceneType={}, taskNo={}, currentStationId={}, targetStationId={}, decision={}, decisionCostMs={}ms",
+ context.sceneType(), context.wrkMast().getWrkNo(), currentStationId, targetStationId,
+ decision.skip() ? decision.skipReason() : "proceed", System.currentTimeMillis() - startMs);
+ return decision;
}
OutOrderDispatchDecision dispatchDecision =
@@ -308,10 +350,15 @@
context.pathLenFactor()
);
Integer targetStationId = dispatchDecision == null ? null : dispatchDecision.getTargetStationId();
- if (targetStationId == null || Objects.equals(targetStationId, currentStationId)) {
- return RerouteDecision.skip("same-station");
- }
- return RerouteDecision.proceed(targetStationId, dispatchDecision);
+ RerouteDecision decision = targetStationId == null || Objects.equals(targetStationId, currentStationId)
+ ? RerouteDecision.skip("same-station")
+ : RerouteDecision.proceed(targetStationId, dispatchDecision);
+ log.info("resolveSharedRerouteDecision profile, sceneType={}, taskNo={}, currentStationId={}, targetStationId={}, decision={}, circle={}, decisionCostMs={}ms",
+ context.sceneType(), context.wrkMast().getWrkNo(), currentStationId, targetStationId,
+ decision.skip() ? decision.skipReason() : "proceed",
+ dispatchDecision != null && dispatchDecision.isCircle(),
+ System.currentTimeMillis() - startMs);
+ return decision;
}
public boolean shouldUseRunBlockDirectReassign(WrkMast wrkMast,
@@ -479,6 +526,7 @@
StationProtocol stationProtocol,
Integer taskNo,
Integer stationId) {
+ long startMs = System.currentTimeMillis();
boolean runBlockReroute = context.sceneType() == RerouteSceneType.RUN_BLOCK_REROUTE;
int currentTaskBufferCommandCount = countCurrentTaskBufferCommands(stationProtocol.getTaskBufferItems(), taskNo);
if (currentTaskBufferCommandCount > 0 && !runBlockReroute) {
@@ -490,40 +538,65 @@
taskNo,
currentTaskBufferCommandCount);
}
- if (!runBlockReroute
+ long suppressStartMs = System.currentTimeMillis();
+ boolean suppressDispatch = !runBlockReroute
&& context.checkSuppressDispatch()
&& stationMoveCoordinator != null
- && stationMoveCoordinator.shouldSuppressDispatch(taskNo, stationId, plan.command())) {
+ && stationMoveCoordinator.shouldSuppressDispatch(taskNo, stationId, plan.command());
+ long suppressCostMs = System.currentTimeMillis() - suppressStartMs;
+ if (suppressDispatch) {
return RerouteExecutionResult.skip("dispatch-suppressed");
}
- if (context.requireOutOrderDispatchLock()
- && !stationDispatchRuntimeStateSupport.tryAcquireOutOrderDispatchLock(taskNo, stationId, OUT_ORDER_DISPATCH_LIMIT_SECONDS)) {
+ long outOrderLockStartMs = System.currentTimeMillis();
+ boolean outOrderLockAcquired = !context.requireOutOrderDispatchLock()
+ || stationDispatchRuntimeStateSupport.tryAcquireOutOrderDispatchLock(taskNo, stationId, OUT_ORDER_DISPATCH_LIMIT_SECONDS);
+ long outOrderLockCostMs = System.currentTimeMillis() - outOrderLockStartMs;
+ if (!outOrderLockAcquired) {
return RerouteExecutionResult.skip("out-order-lock");
}
- if (!isBlank(context.executionLockKey())
- && !stationDispatchRuntimeStateSupport.tryAcquireLock(context.executionLockKey(), context.executionLockSeconds())) {
- return RerouteExecutionResult.skip("scene-lock");
+ long sceneLockStartMs = System.currentTimeMillis();
+ boolean sceneLockAcquired = isBlank(context.executionLockKey())
+ || stationDispatchRuntimeStateSupport.tryAcquireLock(context.executionLockKey(), context.executionLockSeconds());
+ long sceneLockCostMs = System.currentTimeMillis() - sceneLockStartMs;
+ if (!sceneLockAcquired) {
+ return RerouteExecutionResult.skip("scene-lock");
}
+ long resetCostMs = 0L;
if (context.resetSegmentCommandsBeforeDispatch()) {
+ long resetStartMs = System.currentTimeMillis();
stationDispatchRuntimeStateSupport.signalSegmentReset(taskNo, STATION_MOVE_RESET_WAIT_MS);
+ resetCostMs = System.currentTimeMillis() - resetStartMs;
}
int clearedCommandCount = 0;
+ long cancelSessionCostMs = 0L;
- // 鍏堝彇娑堟棫 session 骞惰褰曟柊 session锛屽啀鍏ラ槦鍛戒护锛岄伩鍏嶆秷璐圭嚎绋嬪湪 session 鍐欏叆 Redis 鍓嶅彇鍒板懡浠ゅ鑷磋矾鐢辨牎楠屽け璐ャ��
if (context.cancelSessionBeforeDispatch() && stationMoveCoordinator != null) {
+ long cancelSessionStartMs = System.currentTimeMillis();
stationMoveCoordinator.markCancelPending(taskNo, "reroute_pending");
stationMoveCoordinator.cancelSession(taskNo);
+ cancelSessionCostMs = System.currentTimeMillis() - cancelSessionStartMs;
}
+ long registerDispatchStartMs = System.currentTimeMillis();
preRegisterDispatchSession(context, plan);
+ long registerDispatchCostMs = System.currentTimeMillis() - registerDispatchStartMs;
+ long offerDispatchStartMs = System.currentTimeMillis();
boolean offered = offerDevpCommandWithDedup(context.dispatchDeviceNo(), plan.command(), plan.dispatchScene());
+ long offerDispatchCostMs = System.currentTimeMillis() - offerDispatchStartMs;
if (!offered) {
return RerouteExecutionResult.skip("dispatch-dedup");
}
applyRerouteDispatchEffects(context, plan, clearedCommandCount);
+ long totalCostMs = System.currentTimeMillis() - startMs;
+ log.info("executeReroutePlanWithTaskLock profile, sceneType={}, taskNo={}, stationId={}, suppressCostMs={}ms, outOrderLockCostMs={}ms, sceneLockCostMs={}ms, resetCostMs={}ms, cancelSessionCostMs={}ms, registerDispatchCostMs={}ms, offerDispatchCostMs={}ms, totalCostMs={}ms",
+ context.sceneType(), taskNo, stationId, suppressCostMs, outOrderLockCostMs, sceneLockCostMs, resetCostMs, cancelSessionCostMs, registerDispatchCostMs, offerDispatchCostMs, totalCostMs);
+ if (totalCostMs > EXECUTE_REROUTE_PLAN_SLOW_THRESHOLD_MS) {
+ log.warn("executeReroutePlanWithTaskLock slow, sceneType={}, taskNo={}, stationId={}, totalCostMs={}ms, resetCostMs={}ms, registerDispatchCostMs={}ms, offerDispatchCostMs={}ms",
+ context.sceneType(), taskNo, stationId, totalCostMs, resetCostMs, registerDispatchCostMs, offerDispatchCostMs);
+ }
return RerouteExecutionResult.dispatched(plan.command(), clearedCommandCount);
}
--
Gitblit v1.9.1