book_execute: pos_after di nuovo nel jsonl, letta subito dopo il rebalance in un try (#39)

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>

scripts/live/book_execute.py

@@ -85,14 +85,16 @@ def log_event(rec: dict):
         f.write(json.dumps(rec) + "\n")
 
 
-def _registra_fill(f, *, asset: str, act: str, net: float, bar_ts, tp_frac: float, skh_sign: int):
+def _registra_fill(f, *, asset: str, act: str, net: float, bar_ts, tp_frac: float, skh_sign: int,
+                    pos_after: float | None = None):
     """Registra UN fill (print + log_event + notify). SUBITO dopo l'ordine, PRIMA di leggere la
     posizione risultante: un ordine eseguito non deve dipendere dalla lettura della posizione
     successiva per essere salvato (#23 — un 502 su `position_usd()` dopo un fill riuscito lo
     faceva sparire dal log, perche' la lettura veniva PRIMA del giro `for f in fills`).
 
-    `pos_after` e' sempre None qui: la posizione dopo il rebalance si legge (best-effort) DOPO
+    `pos_after` arriva dal chiamante (#39 — regressione di #23): nel ramo normale di `_run` si
-    aver registrato tutti i fill, in `_run` — vedi il commento li'."""
+    legge SUBITO dopo il rebalance, in un try che isola la lettura dalla registrazione dei fill;
+    resta None quando la lettura solleva o quando il passo e' un `RebalanceParziale` (a meta')."""
     print(f"      -> {f.side.upper()} {f.filled:.4f} @ ${f.price or 0:,.1f} fee {f.fee_usdc:.5f} "
           f"({'OK' if f.verified else 'NON VERIFICATO: ' + f.notes})")
     # `ts_utc` = ORA VERA del fill. Fino al 2026-08-23 qui c'era la data della
@@ -102,7 +104,7 @@ def _registra_fill(f, *, asset: str, act: str, net: float, bar_ts, tp_frac: floa
     log_event(dict(ts_utc=datetime.now(timezone.utc).isoformat(timespec="seconds"),
                    bar_ts=str(pd.Timestamp(bar_ts)), asset=asset, action=act,
                    side=f.side, filled=f.filled, price=f.price, fee=f.fee_usdc,
-                   verified=f.verified, notes=f.notes, net_target=net, pos_after=None,
+                   verified=f.verified, notes=f.notes, net_target=net, pos_after=pos_after,
                    tp_frac=tp_frac, skh_sign=skh_sign))
     det = dict(asset=asset, side=f.side, amount=round(f.filled, 4), price=round(f.price or 0, 1),
                fee=round(f.fee_usdc, 5), net=round(net, 0))
@@ -332,17 +334,22 @@ def _run():
                         _registra_fill(f, asset=asset, act=act, net=net, bar_ts=r["last_data"],
                                        tp_frac=a["tp_frac"], skh_sign=a["skh_sign"])
                     raise rp.causa
-                for f in fills:
+                # newpos si legge SUBITO dopo il rebalance, in un try che ISOLA la lettura dalla
-                    _registra_fill(f, asset=asset, act=act, net=net, bar_ts=r["last_data"],
+                # registrazione dei fill (#39, regressione di #23: dal merge di #23 pos_after era
-                                   tp_frac=a["tp_frac"], skh_sign=a["skh_sign"])
+                # sempre None, perche' la lettura restava un side-effect informativo dopo il ciclo
-                # newpos e' un RECONCILE informativo, letto DOPO aver registrato i fill (#23): se
+                # e il suo risultato non arrivava piu' a `_registra_fill`). Se solleva, i fill si
-                # questa lettura solleva, i fill sono gia' salvi (sopra), e non e' un guasto del
+                # registrano comunque, con pos_after=None — il vincolo #23 (un fill non si perde
-                # giro (isolamento) -> si segnala e si continua (disaster-SL sotto, comunque).
+                # per un reconcile mancato) resta: il try isola solo la LETTURA, non la scrittura.
                 try:
                     newpos = trader.position_usd(inst)
+                    pos_after = newpos
                     print(f"      reconcile: pos ${newpos:,.0f}")
                 except Exception as e:      # noqa: BLE001 — non e' un fill perso, e' un reconcile mancato
+                    pos_after = None
                     print(f"      reconcile: pos illeggibile ({type(e).__name__})")
+                for f in fills:
+                    _registra_fill(f, asset=asset, act=act, net=net, bar_ts=r["last_data"],
+                                   tp_frac=a["tp_frac"], skh_sign=a["skh_sign"], pos_after=pos_after)
             if do_execute:
                 ds = trader.ensure_disaster_sl(inst, sl_pct)   # bracket su posizione NETTA (adatta long/short)
                 stato = ds.get("state")

tests/test_book_u2.py

@@ -332,6 +332,94 @@ def test_position_usd_illeggibile_dopo_un_fill_non_perde_il_fill(tmp_path, monke
     assert righe[0]["asset"] == "BTC" and righe[0]["pos_after"] is None
 
 
+# ---------------------------------------------------------------------------
+# #39 — regressione di #23: pos_after finiva sempre None nel jsonl, anche quando il reconcile
+# leggeva la posizione senza problemi (la lettura era rimasta un side-effect informativo, il suo
+# risultato non arrivava piu' a `_registra_fill`).
+# ---------------------------------------------------------------------------
+def test_rebalance_ok_scrive_pos_after_dal_reconcile(tmp_path, monkeypatch, capsys):
+    """book_execute (#39): rebalance_signed e position_usd vanno a segno entrambi -> il record
+    di log_event ha pos_after = il valore letto dal reconcile, non None."""
+    mod = carica_script("scripts/live/book_execute.py")
+    monkeypatch.setattr(mod, "LOG_DIR", tmp_path)
+    monkeypatch.setattr(mod, "LOG", tmp_path / "book_executions.jsonl")
+
+    fill = Fill("BTC_USDC-PERPETUAL", "buy", 0.003, 0.003, 60000.0, 0.02, "o1", "filled", True, "")
+
+    class _TraderOk:
+        def set_open_cap(self, inst, cap_usd, mark):
+            pass
+
+        def rebalance_signed(self, inst, net, mark, min_usd=5.0):
+            return [fill] if inst.startswith("BTC") else []
+
+        def position_usd(self, inst):
+            return 500.0
+
+        def ensure_disaster_sl(self, inst, sl_pct):
+            return {"state": "ok", "stop": 1.0, "amount": 0.0}
+
+    canned = _canned_report()
+    monkeypatch.setattr(mod, "book_report", lambda **k: canned)
+    monkeypatch.setattr(mod, "notify", lambda t, d=None: None)
+    monkeypatch.setattr(mod, "DeribitTrader", lambda *a, **k: _TraderOk())
+    monkeypatch.setattr(mod, "load_config",
+                        lambda: dict(execution_enabled=True, min_order_usd=5.0,
+                                     disaster_sl_pct=0.30, max_data_age_days=2.0,
+                                     skh_feed_max_age_min=30.0))
+    monkeypatch.setattr(sys, "argv", ["book_execute.py", "--execute"])
+
+    mod._run()
+    out = capsys.readouterr().out
+    assert "reconcile: pos $500" in out
+
+    righe = [json.loads(l) for l in (tmp_path / "book_executions.jsonl").read_text().splitlines()]
+    assert len(righe) == 1
+    assert righe[0]["asset"] == "BTC" and righe[0]["pos_after"] == 500.0
+
+
+def test_position_usd_che_solleva_non_impedisce_il_fill_pos_after_none(tmp_path, monkeypatch, capsys):
+    """book_execute (#39): stesso scenario di sopra ma il reconcile solleva -> il fill si
+    registra comunque (vincolo #23), con pos_after None."""
+    mod = carica_script("scripts/live/book_execute.py")
+    monkeypatch.setattr(mod, "LOG_DIR", tmp_path)
+    monkeypatch.setattr(mod, "LOG", tmp_path / "book_executions.jsonl")
+
+    fill = Fill("BTC_USDC-PERPETUAL", "buy", 0.003, 0.003, 60000.0, 0.02, "o1", "filled", True, "")
+
+    class _TraderReconcileBoom:
+        def set_open_cap(self, inst, cap_usd, mark):
+            pass
+
+        def rebalance_signed(self, inst, net, mark, min_usd=5.0):
+            return [fill] if inst.startswith("BTC") else []
+
+        def position_usd(self, inst):
+            raise RuntimeError("api 500")
+
+        def ensure_disaster_sl(self, inst, sl_pct):
+            return {"state": "ok", "stop": 1.0, "amount": 0.0}
+
+    canned = _canned_report()
+    monkeypatch.setattr(mod, "book_report", lambda **k: canned)
+    monkeypatch.setattr(mod, "notify", lambda t, d=None: None)
+    monkeypatch.setattr(mod, "DeribitTrader", lambda *a, **k: _TraderReconcileBoom())
+    monkeypatch.setattr(mod, "load_config",
+                        lambda: dict(execution_enabled=True, min_order_usd=5.0,
+                                     disaster_sl_pct=0.30, max_data_age_days=2.0,
+                                     skh_feed_max_age_min=30.0))
+    monkeypatch.setattr(sys, "argv", ["book_execute.py", "--execute"])
+
+    mod._run()                     # non deve sollevare: il fill non e' perso
+    out = capsys.readouterr().out
+    assert "reconcile: pos illeggibile (RuntimeError)" in out
+
+    righe = [json.loads(l) for l in (tmp_path / "book_executions.jsonl").read_text().splitlines()]
+    assert len(righe) == 1
+    assert righe[0]["asset"] == "BTC" and righe[0]["filled"] == 0.003
+    assert righe[0]["pos_after"] is None
+
+
 # ---------------------------------------------------------------------------
 # Il formato delle righe stampate non e' cambiato: tradesdb.parse_cron_log deve continuare a
 # leggerlo, sia in un giro normale sia in un giro con RebalanceParziale (#23).