feat: 3

src/mcm26b/protocol/client.py

@@ -129,10 +129,13 @@ class SimulatorClient:
         self._seq = 0
         self._deadline: float | None = None          # 本地单调时钟截止
         self._server_deadline_ms: float | None = None  # 服务器时间戳交叉核对
+        self._enter_monotonic: float | None = None   # 实机计时起点（/enter 成功）
 
     # ------------------------------------------------------------ 公共动作 API
     def enter(self) -> dict:
-        response = self._call("/enter", self._payload("/enter"))
+        started = self.clock()
+        payload = self._payload("/enter")
+        response = self._call("/enter", payload)
         self.state.apply_enter(response)
         remaining = response["remaining_real_duration_s"]
         if not isinstance(remaining, (int, float)) or remaining <= 0:
@@ -140,9 +143,13 @@ class SimulatorClient:
         self._deadline = self.clock() + remaining
         self._server_deadline_ms = (response["real_timestamp_ms"]
                                     + remaining * 1000.0)
+        self._enter_monotonic = self.clock()
+        self._log_step("/enter", payload, response, started,
+                       predicted=CostBreakdown(0.0, 0.0, 0.0))
         return response
 
     def measure(self, position: Vec2, channel: int) -> MeasureOutcome:
+        started = self.clock()
         payload = self._payload("/measure", position=position, channel=channel)
         response = self._call("/measure", payload)
         predicted = self.state.apply_measure(payload, response,
@@ -154,10 +161,13 @@ class SimulatorClient:
         if result == DIRECTION:
             if not isinstance(svd, (int, float)) or isinstance(svd, bool):
                 raise ProtocolViolation("direction 响应缺少数值 svd_deg", body=response)
+        self._log_step("/measure", payload, response, started, result=result,
+                       predicted=predicted, channel=payload["channel"])
         return MeasureOutcome(result, float(svd) if svd is not None else None,
                               response["virtual_time_s"], predicted, response)
 
     def clear(self, position: Vec2, channel: int) -> ClearOutcome:
+        started = self.clock()
         payload = self._payload("/clear", position=position, channel=channel)
         response = self._call("/clear", payload)
         predicted = self.state.apply_clear(payload, response,
@@ -165,14 +175,20 @@ class SimulatorClient:
         result = response.get("clear_result")
         if result not in CLEAR_RESULTS:
             raise ProtocolViolation(f"clear_result 非法: {result!r}", body=response)
+        self._log_step("/clear", payload, response, started, result=result,
+                       predicted=predicted, channel=payload["channel"])
         return ClearOutcome(result, response["virtual_time_s"], predicted, response)
 
     def exit(self) -> ExitInfo:
-        response = self._call("/exit", self._payload("/exit"))
+        started = self.clock()
+        payload = self._payload("/exit")
+        response = self._call("/exit", payload)
         self.state.apply_exit(response)
         reason = response.get("exit_reason")
         if reason != EXIT_USER:
             raise ProtocolViolation(f"exit_reason 非法: {reason!r}", body=response)
+        self._log_step("/exit", payload, response, started,
+                       predicted=CostBreakdown(0.0, 0.0, 0.0))
         return ExitInfo(reason, response["virtual_time_s"], response)
 
     # ---------------------------------------------------------------- 预算控制
@@ -181,6 +197,34 @@ class SimulatorClient:
         """按本地单调时钟估计的剩余现实秒数（未 enter 时为 None）。"""
         return None if self._deadline is None else self._deadline - self.clock()
 
+    def _log_step(self, path: str, payload: dict, response: dict,
+                  started: float, *, result: str | None = None,
+                  predicted: CostBreakdown, channel: int | None = None) -> None:
+        """每步计时留档 [用户决策 2026-09-11]：实机墙钟耗时 + 比赛虚拟耗时分项
+        （移动=直线距离/5、切频道 1s、检测 5s、清除成功 5s/未发现 3s）。
+
+        step 事件不含 response 字段，不会混入 action_events / 虚拟时刻复算。
+        """
+        now = self.clock()
+        entry: dict = {"event": "step", "path": path,
+                       "request_id": payload["request_id"],
+                       "real_elapsed_s": round(now - started, 6),
+                       "virtual_time_s": response["virtual_time_s"],
+                       "virtual_cost": {"move_s": round(predicted.move_s, 6),
+                                        "switch_s": round(predicted.switch_s, 6),
+                                        "action_s": round(predicted.action_s, 6),
+                                        "total_s": round(predicted.total_s, 6)}}
+        if self._enter_monotonic is not None:
+            entry["real_since_enter_s"] = round(now - self._enter_monotonic, 6)
+        if "position" in payload:
+            entry["position"] = {"x": payload["position"]["x"],
+                                 "y": payload["position"]["y"]}
+        if channel is not None:
+            entry["channel"] = channel
+        if result is not None:
+            entry["result"] = result
+        self.log.append(entry)
+
     def _check_budget(self, path: str) -> None:
         if path == "/exit" or self._deadline is None:
             return