[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:25,718 [INFO] from c.h.e.a.o.a.v.EssChargeV2Adapter-line:167 - charge force charge robotCodes:
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,011 [INFO] from c.h.e.a.s.k.EssKubotStationHandleLoadContainer-line:104 - station: CS-01 location: CS-01-003-01 switch to back by non-robot
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,012 [INFO] from c.h.e.a.s.k.EssKubotStationHandleCallRobot-line:86 - station: CS-01 location code: LT_CACHE_SHELF_ENTRY:POINT:5169:10596 call robot
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,012 [INFO] from c.h.e.a.s.k.EssKubotStationHandleLoadContainer-line:152 - station: CS-01 load ok, because location: CS-01-003-01 has the container
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,012 [INFO] from c.h.e.a.s.k.EssKubotStationHandleLoadContainer-line:104 - station: CS-01 location: CS-01-003-02 switch to back by non-robot
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,012 [INFO] from c.h.e.a.s.k.EssKubotStationHandleLoadContainer-line:152 - station: CS-01 load ok, because location: CS-01-003-02 has the container
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,012 [INFO] from c.h.e.a.s.k.EssKubotStationHandleLoadContainer-line:104 - station: CS-01 location: CS-01-002-03 switch to back by non-robot
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,012 [INFO] from c.h.e.a.s.k.EssKubotStationHandleLoadContainer-line:152 - station: CS-01 load ok, because location: CS-01-002-03 has the container
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,012 [INFO] from c.h.e.a.s.k.EssKubotStationHandleLoadContainer-line:104 - station: CS-01 location: CS-01-002-01 switch to back by non-robot
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,012 [INFO] from c.h.e.a.s.k.EssKubotStationHandleLoadContainer-line:152 - station: CS-01 load ok, because location: CS-01-002-01 has the container
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,012 [INFO] from c.h.e.a.s.k.EssKubotStationHandleLoadContainer-line:104 - station: CS-01 location: CS-01-002-02 switch to back by non-robot
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,012 [INFO] from c.h.e.a.s.k.EssKubotStationHandleLoadContainer-line:152 - station: CS-01 load ok, because location: CS-01-002-02 has the container
[application-ess-core-dispatcher-77] 2025-09-24 10:50:44,012 [INFO] from c.h.eventp.common.FileUtils-line:27 - create file-/hairou/data/map-model/202509241050-244.dat .
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,012 [INFO] from c.h.eventp.common.FileUtils-line:27 - create file-/hairou/data/ess-model/202509241050-9958.dat .
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,023 [INFO] from c.h.e.a.tms.EssWmsTaskProcessor-line:264 - wmsTask[TMS]: 79388591-17c1-4ff0-ae02-66607bfe9e63 is created, taskType: TMS, priority: 0, groupPriority: 0, destinationCodes: [HAI-003-004-02], wmsStationCodes: [LA_SHELF_STORAGE]
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,023 [INFO] from c.h.e.a.tms.EssWmsTaskProcessor-line:264 - wmsTask[TMS]: 31405265-e658-4e99-8101-8fed33ba6ab8 is created, taskType: TMS, priority: 0, groupPriority: 0, destinationCodes: [HAI-003-004-03], wmsStationCodes: [LA_SHELF_STORAGE]
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,023 [INFO] from c.h.e.a.tms.EssWmsTaskProcessor-line:264 - wmsTask[TMS]: f13b351c-2d54-4868-bd2e-5969ceb3ab95 is created, taskType: TMS, priority: 0, groupPriority: 0, destinationCodes: [HAI-001-004-01], wmsStationCodes: [LA_SHELF_STORAGE]
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,024 [INFO] from callback.EventCallbackHandler-line:888 - produce callback: 1844111992709120000 message: {"eventCode":"CALLBACK_OF_TASK_CANCELLED","taskGroupCode":"taskGroupCode-001","taskCode":"f13b351c-2d54-4868-bd2e-5969ceb3ab95","taskStatus":"CANCELLED","taskTemplateCode":"","updateTime":1758682244023,"containerCode":"A000000022","callId":"1844111992709120000"}
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,024 [INFO] from c.h.e.a.tms.EssWmsTaskProcessor-line:264 - wmsTask[TMS]: 49adc30f-1c03-4c9a-8d54-44f8bf490b71 is created, taskType: TMS, priority: 0, groupPriority: 0, destinationCodes: [HAI-001-004-01], wmsStationCodes: [LA_SHELF_STORAGE]
[application-ess-pinned-dispatcher-556] 2025-09-24 10:50:44,024 [INFO] from callback.CallbackActor-line:223 - update lastCallbackId: 1844111992709120000
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,024 [INFO] from c.h.e.a.tms.EssWmsTaskProcessor-line:264 - wmsTask[TMS]: d480d65c-f888-498a-8461-29d35934b1ae is created, taskType: TMS, priority: 0, groupPriority: 0, destinationCodes: [HAI-002-004-01], wmsStationCodes: [LA_SHELF_STORAGE]
[application-ess-pinned-dispatcher-556] 2025-09-24 10:50:44,024 [INFO] from callback.CallbackActor-line:149 - send http://10.241.7.51:9046/callback/task/cancel retry: 0 callbackId: 1844111992709120000 data {"eventCode":"CALLBACK_OF_TASK_CANCELLED","taskGroupCode":"taskGroupCode-001","taskCode":"f13b351c-2d54-4868-bd2e-5969ceb3ab95","taskStatus":"CANCELLED","taskTemplateCode":"","updateTime":1758682244023,"containerCode":"A000000022","callId":"1844111992709120000"}
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:44,024 [INFO] from c.h.e.a.tms.EssWmsTaskProcessor-line:264 - wmsTask[TMS]: da90de7c-a8c4-4aa4-8ed9-622be0a58ef8 is created, taskType: TMS, priority: 0, groupPriority: 0, destinationCodes: [HAI-003-004-01], wmsStationCodes: [LA_SHELF_STORAGE]
[application-ess-pinned-dispatcher-556] 2025-09-24 10:50:44,060 [INFO] from callback.CallbackActor-line:149 - send http://10.241.7.51:9046/callback/task/cancel retry: 1 callbackId: 1844111992709120000 data {"eventCode":"CALLBACK_OF_TASK_CANCELLED","taskGroupCode":"taskGroupCode-001","taskCode":"f13b351c-2d54-4868-bd2e-5969ceb3ab95","taskStatus":"CANCELLED","taskTemplateCode":"","updateTime":1758682244023,"containerCode":"A000000022","callId":"1844111992709120000"}
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,070 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:256 - 10.204.51.88:6020 tag CS-01-002-01 send command: mode LIGHT, color RED, text JH42920250924-0004, number 10, created time 1758682244070.
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,070 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:261 - 10.204.51.88:6020 send bytes: [0, 4, 0, -1, 15, 8, 17, 16, 0, 0, 0, 1, 0, 16, 1, 0, 0, 0, 0, 0]
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,078 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:195 - 10.204.51.88:6020 send command finish, cost: 8ms.
[application-ess-pinned-dispatcher-556] 2025-09-24 10:50:44,093 [INFO] from callback.CallbackActor-line:149 - send http://10.241.7.51:9046/callback/task/cancel retry: 2 callbackId: 1844111992709120000 data {"eventCode":"CALLBACK_OF_TASK_CANCELLED","taskGroupCode":"taskGroupCode-001","taskCode":"f13b351c-2d54-4868-bd2e-5969ceb3ab95","taskStatus":"CANCELLED","taskTemplateCode":"","updateTime":1758682244023,"containerCode":"A000000022","callId":"1844111992709120000"}
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,098 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:256 - 10.204.51.88:6020 tag CS-01-002-03 send command: mode LIGHT, color RED, text JH42920250924-0004, number 5, created time 1758682244098.
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,098 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:261 - 10.204.51.88:6020 send bytes: [0, 6, 0, -1, 15, 8, 17, 16, 0, 0, 0, 0, 5, 16, 1, 0, 0, 0, 0, 0]
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,108 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:195 - 10.204.51.88:6020 send command finish, cost: 10ms.
[application-ess-pinned-dispatcher-556] 2025-09-24 10:50:44,123 [INFO] from callback.CallbackActor-line:149 - send http://10.241.7.51:9046/callback/task/cancel retry: 3 callbackId: 1844111992709120000 data {"eventCode":"CALLBACK_OF_TASK_CANCELLED","taskGroupCode":"taskGroupCode-001","taskCode":"f13b351c-2d54-4868-bd2e-5969ceb3ab95","taskStatus":"CANCELLED","taskTemplateCode":"","updateTime":1758682244023,"containerCode":"A000000022","callId":"1844111992709120000"}
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,128 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:256 - 10.204.51.88:6020 tag CS-01-003-02 send command: mode LIGHT, color RED, text JH42920250924-0004, number 5, created time 1758682244128.
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,128 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:261 - 10.204.51.88:6020 send bytes: [0, 8, 0, -1, 15, 8, 17, 16, 0, 0, 0, 0, 5, 16, 1, 0, 0, 0, 0, 0]
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,138 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:195 - 10.204.51.88:6020 send command finish, cost: 10ms.
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,158 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:256 - 10.204.51.88:6020 tag CS-01-002-03 send command: mode LIGHT, color RED, text JH42920250924-0004, number 5, created time 1758682244158.
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,158 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:261 - 10.204.51.88:6020 send bytes: [0, 6, 0, -1, 15, 8, 17, 16, 0, 0, 0, 0, 5, 16, 1, 0, 0, 0, 0, 0]
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,168 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:195 - 10.204.51.88:6020 send command finish, cost: 10ms.
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,188 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:256 - 10.204.51.88:6020 tag CS-01-003-01 send command: mode LIGHT, color RED, text JH42920250924-0004, number 10, created time 1758682244188.
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,188 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:261 - 10.204.51.88:6020 send bytes: [0, 7, 0, -1, 15, 8, 17, 16, 0, 0, 0, 1, 0, 16, 1, 0, 0, 0, 0, 0]
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,198 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:195 - 10.204.51.88:6020 send command finish, cost: 10ms.
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,218 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:256 - 10.204.51.88:6020 tag CS-01-002-02 send command: mode LIGHT, color RED, text JH42920250924-0004, number 5, created time 1758682244218.
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,218 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:261 - 10.204.51.88:6020 send bytes: [0, 5, 0, -1, 15, 8, 17, 16, 0, 0, 0, 0, 5, 16, 1, 0, 0, 0, 0, 0]
[application-ess-pinned-dispatcher-549] 2025-09-24 10:50:44,228 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:195 - 10.204.51.88:6020 send command finish, cost: 10ms.
[application-ess-pinned-dispatcher-563] 2025-09-24 10:50:45,119 [INFO] from c.h.e.a.solver.AlgoMcCallSolver-line:151 - agv: kubot-1 call for task CS-01:call-1844111992696083712 to destination: LT_CACHE_SHELF_ENTRY:POINT:5169:10596
[application-ess-pinned-dispatcher-563] 2025-09-24 10:50:45,119 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:154 - mc v2 version: 1.0 solve cost 1ms useSameActor: false,cost 1 ms, solutions count: 1
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:45,120 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:4059 - Robot #1 work state update from OTHER to WORKING
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:45,120 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:1386 - Robot #1 assigned tasks: [CS-01:call-1844111992696083712#0] after update , updateCount 1 when robot state is IDLE, update task mode is PUSH_COVER.
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:45,121 [INFO] from c.h.e.a.o.algo.v2.EssMcV2Adapter-line:226 - assign task done cost ms: 2, current sequence: 16207 next sequence: 16207
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:45,269 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14361 plan cost 2ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:45,269 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:2186 - Robot #1 update path for task: CS-01:call-1844111992696083712#0 then lock points: [POINT:6454:2881#270, POINT:6454:3371#270, POINT:6454:3698#270, POINT:6454:4248#270, POINT:6454:4798#270, POINT:6454:5248#270, POINT:6454:5698#270, POINT:6454:6248#270, POINT:6454:6798#270, POINT:6454:7248#270, POINT:6454:7698#270, POINT:6454:8248#270, POINT:6454:8798#270, POINT:6454:9292#270, POINT:6454:9787#270, POINT:6454:10281#270, POINT:6454:10596#270], lock container theta: [],intended destinations: [LT_CACHE_SHELF_ENTRY:POINT:5169:10596#0],dest point: POINT:5169:10596 is move finished: false.
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:45,270 [INFO] from c.h.e.a.o.algo.v2.EssPpV2Adapter-line:58 - update path done cost ms: 1, current sequence: 16209 next sequence: 16209
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:48,368 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16221
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:48,368 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14374 plan cost 0ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:48,369 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:2186 - Robot #1 update path for task: CS-01:call-1844111992696083712#0 then lock points: [POINT:6454:3371#270, POINT:6454:3698#270, POINT:6454:4248#270, POINT:6454:4798#270, POINT:6454:5248#270, POINT:6454:5698#270, POINT:6454:6248#270, POINT:6454:6798#270, POINT:6454:7248#270, POINT:6454:7698#270, POINT:6454:8248#270, POINT:6454:8798#270, POINT:6454:9292#270, POINT:6454:9787#270, POINT:6454:10281#270, POINT:6454:10596#270, POINT:6454:10596#180, POINT:5964:10596#180], lock container theta: [],intended destinations: [LT_CACHE_SHELF_ENTRY:POINT:5169:10596#0],dest point: POINT:5169:10596 is move finished: false.
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:48,369 [INFO] from c.h.e.a.o.algo.v2.EssPpV2Adapter-line:58 - update path done cost ms: 1, current sequence: 16226 next sequence: 16226
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:48,818 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16226
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:48,819 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14376 plan cost 1ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:48,819 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:2186 - Robot #1 update path for task: CS-01:call-1844111992696083712#0 then lock points: [POINT:6454:3698#270, POINT:6454:4248#270, POINT:6454:4798#270, POINT:6454:5248#270, POINT:6454:5698#270, POINT:6454:6248#270, POINT:6454:6798#270, POINT:6454:7248#270, POINT:6454:7698#270, POINT:6454:8248#270, POINT:6454:8798#270, POINT:6454:9292#270, POINT:6454:9787#270, POINT:6454:10281#270, POINT:6454:10596#270, POINT:6454:10596#180, POINT:5964:10596#180, POINT:5689:10596#180], lock container theta: [],intended destinations: [LT_CACHE_SHELF_ENTRY:POINT:5169:10596#0],dest point: POINT:5169:10596 is move finished: false.
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:48,819 [INFO] from c.h.e.a.o.algo.v2.EssPpV2Adapter-line:58 - update path done cost ms: 0, current sequence: 16231 next sequence: 16231
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:49,237 [INFO] from c.h.ess.actor.robot.EssRobotBus-line:133 - [Robot #1] current point: [POINT:6454:3698#270]
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:49,267 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16231
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:49,518 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14379 plan cost 1ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:49,519 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:2186 - Robot #1 update path for task: CS-01:call-1844111992696083712#0 then lock points: [POINT:6454:4248#270, POINT:6454:4798#270, POINT:6454:5248#270, POINT:6454:5698#270, POINT:6454:6248#270, POINT:6454:6798#270, POINT:6454:7248#270, POINT:6454:7698#270, POINT:6454:8248#270, POINT:6454:8798#270, POINT:6454:9292#270, POINT:6454:9787#270, POINT:6454:10281#270, POINT:6454:10596#270, POINT:6454:10596#180, POINT:5964:10596#180, POINT:5689:10596#180, POINT:5169:10596#180], lock container theta: [],intended destinations: [LT_CACHE_SHELF_ENTRY:POINT:5169:10596#0],dest point: POINT:5169:10596 is move finished: true.
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:49,519 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:3140 - Robot #1 try action: prepare-load at location: LT_CACHE_SHELF_ENTRY:POINT:5169:10596 for task: CS-01:call-1844111992696083712 locked true then executing
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:49,519 [INFO] from c.h.e.a.o.algo.v2.EssPpV2Adapter-line:58 - update path done cost ms: 1, current sequence: 16236 next sequence: 16236
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:49,767 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16234
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:49,768 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16221
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:49,768 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14380 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:50,017 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16238
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:50,018 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14381 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:50,218 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14382 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:50,468 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16241
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:50,468 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14383 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:50,717 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16244
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:50,717 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14384 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:50,969 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14385 plan cost 1ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:51,218 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16247
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:51,218 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14386 plan cost 0ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:51,237 [INFO] from c.h.ess.actor.robot.EssRobotBus-line:133 - [Robot #1] current point: [POINT:6454:6248#270]
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:51,318 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16238
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:51,418 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16248
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:51,419 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14387 plan cost 1ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:51,667 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16252
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:51,668 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14388 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:51,918 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14389 plan cost 1ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:52,167 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16255
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:52,168 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14390 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:52,417 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16256
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:52,418 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14391 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:52,668 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14392 plan cost 1ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:52,867 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16252
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:52,917 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16259
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:52,918 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14393 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:53,167 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14394 plan cost 0ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:53,238 [INFO] from c.h.ess.actor.robot.EssRobotBus-line:133 - [Robot #1] current point: [POINT:6454:9292#270]
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:53,368 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16262
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:53,369 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14395 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:53,618 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14396 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:53,868 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14397 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:54,118 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16267
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:54,118 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14398 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:54,368 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16262
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:54,368 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14399 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:54,619 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14400 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:54,868 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14401 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:55,118 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16272
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:55,118 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14402 plan cost 0ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:55,238 [INFO] from c.h.ess.actor.robot.EssRobotBus-line:133 - [Robot #1] current point: [POINT:6454:10281#270]
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:55,367 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14403 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:55,618 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14404 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:55,768 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16270
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:55,768 [INFO] from c.h.e.a.o.a.v.EssChargeV2Adapter-line:167 - charge force charge robotCodes:
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:55,868 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14405 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:56,118 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14406 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:56,368 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14407 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:56,568 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14408 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:56,818 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14409 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:57,068 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14410 plan cost 0ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:50:57,238 [INFO] from c.h.ess.actor.robot.EssRobotBus-line:133 - [Robot #1] current point: [POINT:6454:10596#270]
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:57,318 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14411 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:57,567 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14412 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:57,768 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14413 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:58,018 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14414 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:58,268 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14415 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:58,518 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14416 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:58,768 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14417 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:59,018 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14418 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:59,267 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14419 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:50:59,517 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16289
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:59,517 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14420 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:50:59,768 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14421 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:00,019 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14422 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:00,268 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14423 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:00,518 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14424 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:00,567 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16289
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:00,718 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14425 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:00,967 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14426 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:01,218 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14427 plan cost 0ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:01,238 [INFO] from c.h.ess.actor.robot.EssRobotBus-line:133 - [Robot #1] current point: [POINT:6454:10596#180]
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:01,468 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14428 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:01,718 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14429 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:01,918 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14430 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:02,117 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16296
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:02,168 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16302
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:02,168 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14431 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:02,418 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16303
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:02,418 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14432 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:02,668 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14433 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:02,917 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14434 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:03,168 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14435 plan cost 0ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:03,237 [INFO] from c.h.ess.actor.robot.EssRobotBus-line:133 - [Robot #1] current point: [POINT:5689:10596#180]
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:03,418 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14436 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:03,668 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16303
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:03,668 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14437 plan cost 0ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:03,864 [INFO] from c.h.e.a.s.k.EssKubotStationHandleEndAction-line:185 - station: CS-01 robot: kubot-1 end action: prepare-load SUCCEEDED for task: CS-01:call-1844111992696083712 at location: LT_CACHE_SHELF_ENTRY:POINT:5169:10596
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:03,864 [INFO] from c.h.e.a.s.k.s.c.EssKubotGreyBoxCacheShelfStation-line:642 - station: CS-01 after call robot: kubot-1 ready to scanOrLoad at CS-01-002-01
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:03,864 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:3369 - Robot #1 end action: prepare-load at location LT_CACHE_SHELF_ENTRY:POINT:5169:10596, change state to IDLE belongLocation: CS-01-002-01 assignedTasks: [CS-01:call-1844111992696083712#0, CS-01:scan-1844112013513463040#0], action task: CS-01:call-1844111992696083712#0,lastStationCode: CS-01
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:03,865 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:3464 - Robot #1 drive task finished action: prepare-load, transport task: CS-01:call-1844111992696083712 driveTaskCount: 1 currentIndex: 0 state: FINISHED, rest of tasks: [CS-01:scan-1844112013513463040#0], paused: false
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:03,917 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16310
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:03,919 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14438 plan cost 1ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:03,919 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:2186 - Robot #1 update path for task: CS-01:scan-1844112013513463040#0 then lock points: [POINT:5169:10596#180, POINT:4526:10596#180, POINT:4026:10596#180, POINT:3671:10596#180, POINT:3316:10596#180], lock container theta: [],intended destinations: [CS-01-002-01#0],dest point: POINT:3316:10596 is move finished: true.
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:03,919 [INFO] from c.h.e.a.o.algo.v2.EssPpV2Adapter-line:58 - update path done cost ms: 0, current sequence: 16320 next sequence: 16320
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:03,919 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:3140 - Robot #1 try action: scan at location: CS-01-002-01 for task: CS-01:scan-1844112013513463040 locked true then executing
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:04,168 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14439 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:04,368 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14440 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:04,618 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14441 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:04,868 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14442 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:05,118 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14443 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:05,217 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16310
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:05,237 [INFO] from c.h.ess.actor.robot.EssRobotBus-line:133 - [Robot #1] current point: [POINT:5169:10596#180]
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:05,368 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14444 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:05,618 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14445 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:05,868 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14446 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:06,118 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14447 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:06,368 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14448 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:06,568 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14449 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:06,768 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16331
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:06,768 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16325
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:06,768 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14450 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:07,019 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14451 plan cost 1ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:07,238 [INFO] from c.h.ess.actor.robot.EssRobotBus-line:133 - [Robot #1] current point: [POINT:4526:10596#180]
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:07,267 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14452 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:07,467 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16334
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:07,468 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14453 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:07,668 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14454 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:07,918 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14455 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:08,168 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16339
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:08,168 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14456 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:08,317 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16332
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:08,368 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14457 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:08,618 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14458 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:08,868 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14459 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:09,118 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14460 plan cost 1ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:09,237 [INFO] from c.h.ess.actor.robot.EssRobotBus-line:133 - [Robot #1] current point: [POINT:3671:10596#180]
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:09,318 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16344
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:09,318 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14461 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:09,568 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14462 plan cost 0ms
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:09,818 [INFO] from c.h.e.a.o.EssObserverManager-line:897 - build all env points at sequence 16342
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:09,818 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14463 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:10,068 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14464 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:10,318 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14465 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:10,518 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14466 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:10,768 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14467 plan cost 0ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:10,927 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:3613 - Robot #1 scan result is A000000032
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:10,928 [INFO] from c.h.e.a.s.k.EssKubotStationHandleEndAction-line:185 - station: CS-01 robot: kubot-1 end action: scan SUCCEEDED for task: CS-01:scan-1844112013513463040 at location: CS-01-002-01
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:10,928 [INFO] from c.h.e.a.s.k.EssKubotBaseStationWithHandleScan-line:312 - station: CS-01 after scan robot: kubot-1 wait load at location: CS-01-002-01
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:10,928 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:3369 - Robot #1 end action: scan at location CS-01-002-01, change state to AWAITING belongLocation: CS-01-002-01 assignedTasks: [CS-01:scan-1844112013513463040#0, CS-01:load-1844112020920603904#0], action task: CS-01:scan-1844112013513463040#0,lastStationCode: CS-01
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:10,928 [INFO] from callback.EventCallbackHandler-line:888 - produce callback: 1844112020920664064 message: {"eventCode":"CALLBACK_OF_TOTE_SCAN_BY_ROBOT","taskGroupCode":"","taskCode":"CS-01:scan-1844112013513463040","taskStatus":"FINISHED","taskTemplateCode":"","actionCode":"scan","robotCode":"kubot-1","containerCode":"A000000032","trayLevel":0,"stationCode":"CS-01","locationCode":"CS-01-002-01","updateTime":1758682270928,"callId":"1844112020920664064"}
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:10,929 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:3464 - Robot #1 drive task finished action: scan, transport task: CS-01:scan-1844112013513463040 driveTaskCount: 1 currentIndex: 0 state: FINISHED, rest of tasks: [CS-01:load-1844112020920603904#0], paused: false
[application-ess-pinned-dispatcher-556] 2025-09-24 10:51:10,929 [INFO] from callback.CallbackActor-line:223 - update lastCallbackId: 1844112020920664064
[application-ess-pinned-dispatcher-556] 2025-09-24 10:51:10,929 [INFO] from callback.CallbackActor-line:131 - ignore callbackId: 1844112020920664064
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:10,931 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:3140 - Robot #1 try action: load at location: CS-01-002-01 for task: CS-01:load-1844112020920603904 locked true then executing
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:11,018 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14468 plan cost 1ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:11,237 [INFO] from c.h.ess.actor.robot.EssRobotBus-line:133 - [Robot #1] current point: [POINT:3316:10596#180]
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:11,268 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14469 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:11,468 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14470 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:11,718 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14471 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:11,918 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14472 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:12,168 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14473 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:12,368 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14474 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:12,618 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14475 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:12,868 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14476 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:13,118 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14477 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:13,318 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14478 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:13,568 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14479 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:13,818 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14480 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:14,018 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14481 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:14,268 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14482 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:14,518 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14483 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:14,718 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14484 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:14,968 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14485 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:15,219 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14486 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:15,468 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14487 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:15,718 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14488 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:15,918 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14489 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:16,168 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14490 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:16,418 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14491 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:16,668 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14492 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:16,868 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14493 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:17,118 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14494 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:17,368 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14495 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:17,568 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14496 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:17,818 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14497 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:18,068 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14498 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:18,318 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14499 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:18,568 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14500 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:18,818 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14501 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:19,068 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14502 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:19,268 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14503 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:19,518 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14504 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:19,768 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14505 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:19,968 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14506 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:20,168 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14507 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:20,368 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14508 plan cost 0ms
[application-ess-core-dispatcher-77] 2025-09-24 10:51:20,498 [INFO] from c.h.e.a.r.d.EssDeliveryPersist-line:276 - map-model sync redisState from pos=243 endPos=250
[application-ess-pinned-dispatcher-546] 2025-09-24 10:51:20,508 [INFO] from c.h.e.a.r.d.EssDeliveryPersist-line:276 - ess-model sync redisState from pos=9957 endPos=10001
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:20,618 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14509 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:20,868 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14510 plan cost 0ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:21,118 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14511 plan cost 1ms
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:21,368 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14512 plan cost 1ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:21,432 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:3885 - Robot #1 TAKE container op finished: A000000032 to: 64, container count: 1
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:21,435 [INFO] from c.h.e.a.s.k.EssKubotStationHandleEndAction-line:185 - station: CS-01 robot: kubot-1 end action: load SUCCEEDED for task: CS-01:load-1844112020920603904 at location: CS-01-002-01
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:21,435 [INFO] from c.h.e.a.s.k.EssKubotStationHandleEndAction-line:113 - station: CS-01 container: A000000032 is move from location: CS-01-002-01 to robot
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:21,435 [INFO] from c.h.e.a.s.k.s.c.EssKubotGreyBoxCacheShelfStation-line:408 - station: CS-01 group: info total: 12 backCount: 4 outCount: 0
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:21,436 [INFO] from c.h.e.a.s.k.s.c.EssKubotGreyBoxCacheShelfStation-line:415 - station: CS-01 after load robot: kubot-1 ready to scanOrLoad at CS-01-003-02
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:21,436 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:3369 - Robot #1 end action: load at location CS-01-002-01, change state to IDLE belongLocation: CS-01-003-02 assignedTasks: [CS-01:load-1844112020920603904#0, CS-01:scan-1844112031939040512#0], action task: CS-01:load-1844112020920603904#0,lastStationCode: CS-01
[application-ess-pinned-dispatcher-556] 2025-09-24 10:51:21,437 [INFO] from callback.CallbackActor-line:223 - update lastCallbackId: 1844112031939100672
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:21,436 [INFO] from callback.EventCallbackHandler-line:888 - produce callback: 1844112031939100672 message: {"eventCode":"CALLBACK_OF_TOTE_LOADED_BY_ROBOT","taskGroupCode":"taskGroupCode-001","taskCode":"79388591-17c1-4ff0-ae02-66607bfe9e63","taskStatus":"PENDING","taskTemplateCode":"","actionCode":"load","robotCode":"kubot-1","containerCode":"A000000032","trayLevel":64,"stationCode":"CS-01","locationCode":"CS-01-002-01","updateTime":1758682281436,"callId":"1844112031939100672"}
[application-ess-pinned-dispatcher-556] 2025-09-24 10:51:21,437 [INFO] from callback.CallbackActor-line:149 - send http://10.241.7.51:9046/callback/tote/loaded retry: 0 callbackId: 1844112031939100672 data {"eventCode":"CALLBACK_OF_TOTE_LOADED_BY_ROBOT","taskGroupCode":"taskGroupCode-001","taskCode":"79388591-17c1-4ff0-ae02-66607bfe9e63","taskStatus":"PENDING","taskTemplateCode":"","actionCode":"load","robotCode":"kubot-1","containerCode":"A000000032","trayLevel":64,"stationCode":"CS-01","locationCode":"CS-01-002-01","updateTime":1758682281436,"callId":"1844112031939100672"}
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:21,437 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:3464 - Robot #1 drive task finished action: load, transport task: CS-01:load-1844112020920603904 driveTaskCount: 1 currentIndex: 0 state: FINISHED, rest of tasks: [CS-01:scan-1844112031939040512#0], paused: false
[application-ess-pinned-dispatcher-549] 2025-09-24 10:51:21,459 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:256 - 10.204.51.88:6020 tag CS-01-002-01 send command: mode FLASH, color RED, text , number 0, created time 1758682281459.
[application-ess-pinned-dispatcher-549] 2025-09-24 10:51:21,459 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:261 - 10.204.51.88:6020 send bytes: [0, 4, 0, -1, 15, 8, 33, 16, 0, 0, 0, 0, 0, 16, 1, 0, 0, 0, 0, 0]
[application-ess-pinned-dispatcher-549] 2025-09-24 10:51:21,466 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:195 - 10.204.51.88:6020 send command finish, cost: 7ms.
[application-ess-pinned-dispatcher-549] 2025-09-24 10:51:21,476 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:256 - 10.204.51.88:6020 tag CS-01-002-01 send command: mode DARK, color RED, text , number 0, created time 1758682281476.
[application-ess-pinned-dispatcher-549] 2025-09-24 10:51:21,476 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:261 - 10.204.51.88:6020 send bytes: [0, 4, 0, -1, 15, 8, 0, 16, 0, 0, 0, 0, 0, 16, 1, 0, 0, 0, 0, 0]
[application-ess-pinned-dispatcher-549] 2025-09-24 10:51:21,486 [INFO] from c.h.e.a.e.p.rybo.EssPtlRyboActor-line:195 - 10.204.51.88:6020 send command finish, cost: 10ms.
[application-ess-pinned-dispatcher-556] 2025-09-24 10:51:21,495 [INFO] from callback.CallbackActor-line:163 - recv retry: 0 callbackId: 1844112031939100672 cost ms: 58 data: {"code":0,"msg":"success","data":null}
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:21,569 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14513 plan cost 1ms
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:21,570 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:2186 - Robot #1 update path for task: CS-01:scan-1844112031939040512#0 then lock points: [POINT:3316:10596#180, POINT:3671:10596#180, POINT:4026:10596#180], lock container theta: [],intended destinations: [CS-01-003-02#0],dest point: POINT:4026:10596 is move finished: true.
[application-ess-pinned-dispatcher-550] 2025-09-24 10:51:21,572 [INFO] from c.h.e.a.o.algo.v2.EssPpV2Adapter-line:58 - update path done cost ms: 3, current sequence: 16412 next sequence: 16412
[application-ess-pinned-dispatcher-545] 2025-09-24 10:51:21,572 [INFO] from c.h.e.a.r.kubot.EssKubotEntity-line:3140 - Robot #1 try action: scan at location: CS-01-003-02 for task: CS-01:scan-1844112031939040512 locked true then executing
[application-ess-pinned-dispatcher-562] 2025-09-24 10:51:21,818 [INFO] from c.h.e.a.o.algo.v2.EssAlgoV2Actor-line:96 - round 14514 plan cost 0ms分析一下这个日志