feat(safety-sell): dcy-017 워치독 소유권 가시화 — snapshot 상태 + 발동 로깅 (BAT-021)

전략 이탈로 슬롯이 내부 청산 루틴(워치독) 소유로 넘어간 상태가 무성이라 운영자가 인지할 수 없던 문제(issue #12)를 가시화한다. 거버넌스: 전부 change-req (신규 REQ 없음, dcy-017 OQ-3; Redis 미채택). - REQ-034/021: WatchdogStore.last_seen + snapshot RPC 응답에 holding 슬롯 워치독 상태(expired/last_seen) read-only 동봉(best-effort) - REQ-032: trex-core slots 가 expired 슬롯을 WATCHDOG-OWNED(전략 이탈) 표시 - REQ-037/038/039: safety-sell 워치독 소유 진입(WARN)/이탈(INFO) + 발동 (forced_close·stop_loss=WARN, take_profit·market_close=INFO) 로그 + in-process 카운터(SafetySellService.counters), 구조화 필드(slot_id/ portfolio_id/reason/phase/instance_key). per-tick 스킵은 카운터만 - REQ-042: runtime-flows/interface-contract 정합 best-effort 격리(NFR-1): 모든 가시화는 예외 격리 — 워치독 판정·청산 불변. dcy-016 억제 읽기로 관측이 워치독을 리셋하지 않음(비침습). 검증: 단위 335 passed/34 skipped, 인프라 게이트(PG+RabbitMQ) 369 passed, ruff clean. 신규 test_safety_sell_visibility(6) + snapshot watchdog(1) + CLI(1). BAT-021 rc. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
2026-06-08 17:10:26 +09:00
parent d09b93195f
commit 6d7bca1460
26 changed files with 1022 additions and 10 deletions
@@ -168,6 +168,7 @@ def make_snapshot_rpc_handler(
    pause_store: Optional[PauseStore] = None,
    default_total_slots: int = 10,
    watchdog_store: Optional[WatchdogStore] = None,
+    watchdog_timeout_sec: int = 120,
    killswitch_store=None,
 ):
    """Build the RPC handler for `trex.snapshot.req` (REQ-028).
@@ -225,7 +226,9 @@ def make_snapshot_rpc_handler(
                trading_date=day,
                killswitch_store=killswitch_store,
            )
-            return RpcResponse(payload=envelope.to_dict())
+            payload = envelope.to_dict()
+            _attach_watchdog(payload, slot_repo, day, watchdog_store, watchdog_timeout_sec)
+            return RpcResponse(payload=payload)

        # --- BAT-007 legacy stub-shape path ---
        view_raw = str(body.get("view") or "all")
@@ -236,7 +239,7 @@ def make_snapshot_rpc_handler(
        if strategy_filter is not None:
            slots = [s for s in slots if s.strategy_id == strategy_filter]
        cap = slot_service.compute_slot_capacity(day, max(1, len(slot_repo.list_slots(day))))
-        return RpcResponse(payload={
+        payload = {
            "view": view_raw,
            "strategy_id": strategy_filter,
            "trading_date": day.isoformat(),
@@ -248,11 +251,40 @@ def make_snapshot_rpc_handler(
                "total_slots": cap.total_slots,
                "scarcity_ratio": cap.scarcity_ratio,
            },
-        })
+        }
+        _attach_watchdog(payload, slot_repo, day, watchdog_store, watchdog_timeout_sec)
+        return RpcResponse(payload=payload)

    return handler


+def _attach_watchdog(payload, slot_repo, day, watchdog_store, timeout_sec) -> None:
+    """Attach holding-slot watchdog state to a snapshot response (dcy-017/REQ-034).
+
+    `watchdog` = list of {slot_id, portfolio_id, symbol, expired, last_seen} for
+    holding slots — lets `trex-core slots` surface watchdog ownership (strategy
+    absence). Best-effort: any failure leaves the response unchanged (FR-4)."""
+    if watchdog_store is None:
+        return
+    try:
+        states = []
+        for s in slot_repo.list_slots(day):
+            if s.status is not SlotState.HOLDING:
+                continue
+            sid = str(s.slot_id)
+            last = watchdog_store.last_seen(sid)
+            states.append({
+                "slot_id": sid,
+                "portfolio_id": s.portfolio_id,
+                "symbol": s.symbol,
+                "expired": watchdog_store.is_expired(sid, timeout_sec),
+                "last_seen": last.isoformat() if last else None,
+            })
+        payload["watchdog"] = states
+    except Exception:  # noqa: BLE001 - visibility must never break the response
+        return
+
+
 # ---- pause/resume RPC handler (REQ-032 AC-4) --------------------------------

 def make_pause_rpc_handler(pause_store: PauseStore):
@@ -56,18 +56,72 @@ class SafetySellService:
        broker: BrokerPort,
        watchdog: WatchdogStore,
        config: SafetySellConfig,
+        instance_key: str = "default",
    ) -> None:
        self._repo = slot_repo
        self._svc = slot_service
        self._broker = broker
        self._watchdog = watchdog
        self._cfg = config
+        self._instance_key = instance_key  # dcy-017 FR-5: multi-instance label
        self._last_liquidation_date: date_cls | None = None
        self._last_forced_close_at: datetime | None = None
        self._last_price_check_at: datetime | None = None
        # BAT-014 / REQ-052: per-slot retry cooldown for persistent rejection.
        self._last_attempt: dict = {}     # slot_id -> last sell-attempt datetime
        self._attempt_count: dict = {}    # slot_id -> consecutive attempt count
+        # dcy-017 / REQ-037 (issue #12): watchdog-ownership visibility.
+        self._owned: set = set()          # holding slot_ids currently watchdog-owned
+        self.counters: dict[str, int] = {}  # phase/event counters (in-process metrics)
+
+    # ----------------------------------------------- dcy-017 visibility helpers
+    def _count(self, key: str) -> None:
+        self.counters[key] = self.counters.get(key, 0) + 1
+
+    # WARN-level fire reasons (attention events); others log at INFO.
+    _WARN_REASONS = frozenset({"forced_close_at", "stop_loss"})
+
+    def _log_fire(self, slot: Slot, reason: str) -> None:
+        """Visibility for an actual safety-sell fire (dcy-017 FR-1, OQ-2)."""
+        self._count(f"fire:{reason}")
+        level = logging.WARNING if reason in self._WARN_REASONS else logging.INFO
+        _log.log(
+            level,
+            "safety-sell fired: phase=%s slot=%s portfolio_id=%s reason=%s instance_key=%s",
+            reason, slot.slot_id, slot.portfolio_id, reason, self._instance_key,
+        )
+
+    def _update_ownership(self, now: datetime) -> None:
+        """Log watchdog-ownership entry (strategy absent) / exit (returned).
+
+        dcy-017 FR-1: WARN on entry (a holding slot's strategy went silent so the
+        safety net now owns it), INFO on exit. Counters track both. Best-effort —
+        never raises into the tick (NFR-1)."""
+        try:
+            if self._in_grace():
+                return  # no expiry judgement during grace (REQ-034)
+            current = {
+                s.slot_id for s in self._holding(now) if self._watchdog_expired(s)
+            }
+            by_id = {s.slot_id: s for s in self._holding(now)}
+            for sid in current - self._owned:
+                self._count("owned:enter")
+                s = by_id.get(sid)
+                _log.warning(
+                    "watchdog ownership entered (strategy absent): slot=%s "
+                    "portfolio_id=%s phase=watchdog_owned instance_key=%s",
+                    sid, (s.portfolio_id if s else None), self._instance_key,
+                )
+            for sid in self._owned - current:
+                self._count("owned:exit")
+                _log.info(
+                    "watchdog ownership released (strategy returned): slot=%s "
+                    "phase=watchdog_released instance_key=%s",
+                    sid, self._instance_key,
+                )
+            self._owned = current
+        except Exception:  # noqa: BLE001 - visibility must not break the tick
+            return

    @property
    def base_tick_sec(self) -> float:
@@ -155,6 +209,7 @@ class SafetySellService:
            if self._in_cooldown(s.slot_id, now):
                continue  # REQ-052: persistent-rejection backoff
            if self._attempt_sell(s, "forced_close_at", now):
+                self._log_fire(s, "forced_close_at")
                fired.append(s.slot_id)
        return fired

@@ -184,9 +239,11 @@ class SafetySellService:
                continue  # unavailable — skip, retry next tick (no false trigger)
            if s.stop_loss_price is not None and price <= s.stop_loss_price:
                if self._attempt_sell(s, "stop_loss", now):
+                    self._log_fire(s, "stop_loss")
                    fired.append(s.slot_id)
            elif s.take_profit_price is not None and price >= s.take_profit_price:
                if self._attempt_sell(s, "take_profit", now):
+                    self._log_fire(s, "take_profit")
                    fired.append(s.slot_id)
        return fired

@@ -205,6 +262,7 @@ class SafetySellService:
        fired = []
        for s in self._holding(now):  # watchdog/grace ignored (AC-2/AC-6)
            if self._safe_sell(s, "market_close_liquidation"):
+                self._log_fire(s, "market_close_liquidation")
                fired.append(s.slot_id)
        self._last_liquidation_date = today
        return fired
@@ -214,6 +272,7 @@ class SafetySellService:
        """One worker tick — market-close, then cadence-gated forced_close + prices."""
        now = now or datetime.now(tz=timezone.utc)
        self._prune_cooldown(now)  # REQ-052 FR-4: drop state for non-holding slots
+        self._update_ownership(now)  # dcy-017 FR-1: watchdog ownership enter/exit visibility
        try:
            self.check_market_close(now)
        except Exception:  # noqa: BLE001
@@ -13,6 +13,7 @@ is needed.
 from __future__ import annotations

 from datetime import datetime, timezone
+from typing import Optional


 class WatchdogStore:
@@ -26,6 +27,12 @@ class WatchdogStore:
        """Record that slot_id appeared in a snapshot RPC response."""
        self._store[slot_id] = datetime.now(tz=timezone.utc)

+    def last_seen(self, slot_id: str) -> Optional[datetime]:
+        """Return the last time slot_id was seen, or None if never (dcy-017).
+
+        Read-only accessor for watchdog-ownership visibility (REQ-034)."""
+        return self._store.get(slot_id)
+
    def is_expired(self, slot_id: str, timeout_sec: int) -> bool:
        """Return True if slot_id has not been seen for longer than timeout_sec.

@@ -121,13 +121,18 @@ def _cmd_slots(args, cfg, rpc) -> int:
    resp = rpc(topology.snapshot_queue(instance), payload,
               correlation_id=str(uuid.uuid4()), timeout=args.timeout)
    assets = resp.get("assets", [])
+    # dcy-017: holding-slot watchdog state (strategy-absent ownership).
+    owned = {w.get("portfolio_id"): w for w in resp.get("watchdog", []) if w.get("expired")}
    if args.json:
        _emit(resp, as_json=True)
    else:
-        print(f"instance={instance} view={view} count={len(assets)}")
+        print(f"instance={instance} view={view} count={len(assets)} "
+              f"watchdog_owned={len(owned)}")
        for a in assets:
-            print(f"  {a.get('asset_id')}\t{a.get('symbol')}\tqty={a.get('asset_quantity')}\t"
-                  f"strategy={a.get('active_strategy_id')}")
+            pid = a.get("asset_id")
+            tag = "  [WATCHDOG-OWNED: strategy absent]" if pid in owned else ""
+            print(f"  {pid}\t{a.get('symbol')}\tqty={a.get('asset_quantity')}\t"
+                  f"strategy={a.get('active_strategy_id')}{tag}")
    return 0


@@ -202,6 +202,7 @@ class Daemon:
            broker=self.broker,
            watchdog=self.watchdog,
            config=config.safety_sell,
+            instance_key=config.instance_key,
        )

    # ------------------------------------------------------------ buy symbol resolve
@@ -267,6 +268,7 @@ class Daemon:
            pause_store=self.pause_store,
            default_total_slots=self.config.total_slots,
            watchdog_store=self.watchdog,
+            watchdog_timeout_sec=self.config.safety_sell.watchdog_timeout_sec,
            killswitch_store=self.killswitch_store,
        )
        transport.consume_rpc_forever(