diff --git a/scripts/live/book_execute.py b/scripts/live/book_execute.py index 5413107..20be21a 100644 --- a/scripts/live/book_execute.py +++ b/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 - aver registrato tutti i fill, in `_run` — vedi il commento li'.""" + `pos_after` arriva dal chiamante (#39 — regressione di #23): nel ramo normale di `_run` si + 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: - _registra_fill(f, asset=asset, act=act, net=net, bar_ts=r["last_data"], - tp_frac=a["tp_frac"], skh_sign=a["skh_sign"]) - # newpos e' un RECONCILE informativo, letto DOPO aver registrato i fill (#23): se - # questa lettura solleva, i fill sono gia' salvi (sopra), e non e' un guasto del - # giro (isolamento) -> si segnala e si continua (disaster-SL sotto, comunque). + # newpos si legge SUBITO dopo il rebalance, in un try che ISOLA la lettura dalla + # registrazione dei fill (#39, regressione di #23: dal merge di #23 pos_after era + # sempre None, perche' la lettura restava un side-effect informativo dopo il ciclo + # e il suo risultato non arrivava piu' a `_registra_fill`). Se solleva, i fill si + # registrano comunque, con pos_after=None — il vincolo #23 (un fill non si perde + # 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") diff --git a/tests/test_book_u2.py b/tests/test_book_u2.py index 32fc1a6..7e777c1 100644 --- a/tests/test_book_u2.py +++ b/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).