From 7d64dd4c2b0e6a4e7a9b34a92ea6ed9b27cf1c2d Mon Sep 17 00:00:00 2001 From: Adriano Dal Pastro Date: Wed, 29 Jul 2026 12:20:42 +0000 Subject: [PATCH] live(feed): l'allerta funzionava, la sua CAUSA era una riga cablata MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Il 29/07 il feed 5m di SKH01 e' ricaduto sul certificato in 6 giri orari su 8 (eta' 265->685 min, +60 a ogni giro = firma esatta del fallback): latenza d'uscita da ~1h a ~11h, book flat, nessuna posizione esposta. L'allerta del 26/07 ha segnalato 6/6, poi ha stampato un perche' che non aveva misurato — la nota "fetch pubblico KO" era cablata, identica in ogni caso, compreso quello in cui la coda fresca E' attaccata e il vecchio e' il certificato. E la causa vera non era recuperabile per costruzione: _fetch_recent_5m ingoia l'eccezione di pagina con un break e a prima pagina fallita ritorna un frame vuoto, indistinguibile da "il venue non ha barre". Cablato: livefeed.last_fetch_error() (registra E logga nel punto in cui l'errore viene ingoiato) -> book_report.skh_feed_errors -> allerta con la causa. Stesso buco chiuso sul ramo gemello "conto offline", che la ragione l'aveva gia' in mark_src e non la stampava mai. La causa del 29/07 resta IGNOTA e va citata cosi': una prima stesura la attribuiva a un rate limit per-IP come se fosse un fatto -> rimossa, sarebbe stato lo stesso difetto che stavo correggendo scritto meglio. Cron spostato al minuto :07 come ripiego da UNA osservazione, dichiarato tale. Test 11 -> 16 (incluso il caso a meta' paginazione: coda parziale attaccata, mancano le barre PIU' recenti). Book/pesi/config/strategia INVARIATI. Co-Authored-By: Claude Opus 5 (1M context) --- CLAUDE.md | 34 ++++++ docs/diary/2026-07-29-feed-skh-causa.md | 142 ++++++++++++++++++++++++ scripts/cron_book.sh | 6 + scripts/live/book_execute.py | 20 +++- src/live/book.py | 15 ++- src/live/livefeed.py | 60 +++++++++- tests/test_skh_feed_freshness.py | 116 ++++++++++++++++++- 7 files changed, 384 insertions(+), 9 deletions(-) create mode 100644 docs/diary/2026-07-29-feed-skh-causa.md diff --git a/CLAUDE.md b/CLAUDE.md index 4f73c31..51f6282 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -711,6 +711,40 @@ Prima ondata di ricerca onesta su BTC/ETH certificati (5 track, harness condivis **Scelta dichiarata: ALLERTA, NON blocca** — bloccare fermerebbe anche TP01 (nettato sullo stesso strumento) per un guasto di rete, e forzare SKH flat chiuderebbe posizioni buone su un glitch. Test `tests/test_skh_feed_freshness.py` (11 casi). Strategia/pesi/cadenza INVARIATI. + ⚠️ **SEGUITO 2026-07-29 — l'allerta ha funzionato, la sua CAUSA era una riga CABLATA.** Diario + `2026-07-29-feed-skh-causa.md`; test 11 → **16**. **Book/pesi/config/strategia INVARIATI.** + Il 29/07 (dopo il riavvio VPS delle 04:11) il feed e' ricaduto sul certificato in **6 giri orari + su 8** fra le 05:00 e le 12:00: eta' **265→685 min** (+60 a ogni giro = firma esatta del fallback) + → latenza d'uscita SKH01 da ~1h a **~11h**; book flat, nessuna posizione esposta. L'allerta ha + segnalato 6/6 — poi ha stampato un perche' che **non aveva misurato**: la nota *"fetch pubblico + KO"* era cablata, identica in ogni caso, **compreso quello in cui la coda fresca E' attaccata e il + vecchio e' il certificato stesso** (= feed-freeze 14/07 in altra veste). E la causa vera non era + recuperabile a posteriori **per costruzione**: `_fetch_recent_5m` ingoia l'eccezione di pagina con + un `break` e a prima pagina fallita ritorna un frame vuoto, indistinguibile da "il venue non ha + barre"; alle 12:14, a mano, `fresh_5m` rispondeva in 1.7s senza errori. + ✅ **Cablato:** `livefeed.last_fetch_error()` (+`_note_error`, registra E logga nel punto in cui + l'errore viene ingoiato) → `book_report.skh_feed_errors` (per asset) → allerta con la causa; e + stesso buco chiuso sul ramo gemello **"conto offline"**, che aveva gia' la ragione in `mark_src` + e non la stampava mai. Tre guasti ora distinti: eccezione / risposta vuota / **certificato + vecchio con coda attaccata**. Blindati anche il caso a **meta' paginazione** (coda parziale + attaccata: la paginazione va in avanti → mancano le barre PIU' RECENTI) e la non-sopravvivenza + della causa a una chiamata riuscita. + ⚠️ **La causa del 29/07 resta IGNOTA, e va citata cosi'.** Solo circostanziale: giri falliti + lunghi quanto i riusciti (**16-46s → errore immediato, non timeout**); finestra aperta col riavvio + ma non chiusa da esso (11:00 ok, 12:00 no); stesso giorno il percorso del **conto** (rete diversa + via `cerbero-mcp`, stesso venue a valle) dava `ReadTimeout/404/502`; i due percorsi falliscono **in + alternanza**, non insieme. Una prima stesura scriveva nei commenti "*rate limit Deribit per-IP + saturato da un altro progetto sulla stessa VPS*" **come fatto**: rimossa — sarebbe stato lo stesso + difetto che stavo correggendo, scritto meglio. **Cron spostato `0 * * * *` → `7 * * * *`** + (ipotesi contesa al minuto tondo): ripiego da **UNA** osservazione, costo zero, **dichiarato tale + in testa a `cron_book.sh`** perche' la riga di crontab vive fuori dal repo. + **REGOLE:** (a) **una nota di diagnosi cablata e' peggio di nessuna nota** — nessuna manda a + guardare i dati, una sbagliata manda sulla pista sbagliata e sembra una misura; (b) se un errore + si ingoia per non bloccare, **si registra nel punto in cui lo si ingoia** (non c'e' un secondo + momento buono: quando la diagnosi serve, il guasto e' rientrato); (c) un'allerta risponde a **due** + domande — *cosa* (decide) e *perche'* (ripara): misurare solo la prima costa un'intera occorrenza + del guasto; (d) distinguere guasti diversi **anche quando l'azione e' la stessa** (tre cause → tre + riparazioni); (e) una mitigazione da un'osservazione sola si applica pure, ma **si scrive che lo e'**. ✅ **FOLLOW-UP CHIUSO 2026-07-26 — la misura dedicata sugli INGRESSI e' fatta: NON e' un difetto, il verso e' LASCIARLO.** `scripts/research/r0726_skh_partial_entry.py`, test `tests/test_skh_partial_entry.py` (10), diario `2026-07-26-skh-partial-entry.md`. diff --git a/docs/diary/2026-07-29-feed-skh-causa.md b/docs/diary/2026-07-29-feed-skh-causa.md new file mode 100644 index 0000000..d8f93c2 --- /dev/null +++ b/docs/diary/2026-07-29-feed-skh-causa.md @@ -0,0 +1,142 @@ +# 2026-07-29 — L'allerta funzionava, la sua CAUSA era una riga cablata + +**Fatto operativo del giorno.** Il 29/07 il feed 5m che alimenta il segnale SKH01 e' ricaduto sul +feed certificato in **6 giri orari su 8** fra le 05:00 e le 12:00 UTC. L'allerta cablata il 26/07 ha +segnalato **ogni volta** — ha fatto esattamente il suo lavoro. Poi ha stampato una causa che non +aveva misurato. + +**Codice:** `src/live/livefeed.py` (`last_fetch_error`), `src/live/book.py` (`skh_feed_errors` nel +report), `scripts/live/book_execute.py` (allerta con la causa), `scripts/cron_book.sh` (nota sul +minuto). **Test:** `tests/test_skh_feed_freshness.py` (11 → **16**). **Book, pesi, config, strategia: +INVARIATI.** Nessuna posizione aperta durante l'incidente (book flat: TP01 risk-off, SKH01 flat). + +--- + +## 1. Cosa e' successo, misurato + +Dal log `logs/cron_book.log` (la VPS si e' riavviata alle **04:11 UTC**, kernel 6.8.0-134 → +6.8.0-136; il giro delle 04:00 non e' partito perche' la macchina era gia' giu' dalle 03:55): + +``` +giro (UTC) eta' ultima barra 5m durata del giro +05:00 265 min 46 s +06:00 325 24 +07:00 385 29 +08:00 445 26 +09:00 505 34 +10:00 565 25 +11:00 0 (fresco) 16 <- ma qui e' fallita la lettura del CONTO +12:00 685 25 +12:07 0 (fresco) 10 +``` + +L'eta' cresce di **60 minuti a ogni giro**: e' la firma esatta del fallback, cioe' l'ultima barra +resta quella del feed certificato (rebuild giornaliero delle 00:30) mentre l'orologio avanza. Al +picco la latenza d'uscita di SKH01 e' passata da **~1 ora a ~11 ore**. + +## 2. Cosa ha funzionato e cosa no + +**Ha funzionato:** l'instrumentazione del 26/07. `feed_age_minutes` → `skh_feed_age_min` → allerta +Telegram, 6 volte su 6, con la scelta dichiarata allora (**allerta, non blocca** — bloccare +fermerebbe anche il ribilancio di TP01, nettato sullo stesso strumento, per un guasto di rete). + +**Non ha funzionato:** la riga che diceva *perche'*. Era questa, **cablata**: + +```python +"nota": "fresh_5m e' ricaduto sul feed certificato (fetch pubblico KO)" +``` + +Non veniva da nessuna misura: veniva stampata identica in ogni caso, compreso quello in cui la coda +fresca **era** attaccata e il vecchio era il certificato stesso. E' una presunzione con l'aspetto di +un dato — la forma di difetto che questo progetto ha gia' pagato tre volte in docstring di +produzione (26/07, tre correzioni in due giorni). + +Peggio: la causa vera **non era recuperabile a posteriori**, per costruzione. In +`_fetch_recent_5m` l'eccezione di pagina viene ingoiata con un `break` e la funzione ritorna quel +che ha raccolto; se a fallire e' la **prima** pagina il risultato e' un DataFrame vuoto, che a valle +e' indistinguibile da "il venue non ha barre". Quando il guasto e' rientrato, non resta niente da +interrogare — e infatti alle 12:14, provando a mano, `fresh_5m` rispondeva in 1.7 s senza errori. + +## 3. La correzione: registrare la causa, non indovinarla + +`livefeed._LAST_ERROR` + `last_fetch_error()`. Il fallback resta **silenzioso come comportamento** +(mai operare a cieco > mai operare, scelta del 26/07 confermata): quello che smette di essere +silenzioso e' il **perche'**. La causa risale fino al report (`skh_feed_errors`, per asset) e fino +all'allerta, che ora dice cosa e' successo invece di ipotizzarlo. + +Tre guasti che prima erano la stessa riga, e ora sono tre righe diverse: + +| caso | cosa si vede oggi | +|---|---| +| eccezione al fetch (rete, rate limit, venue) | `RuntimeError: 429 ... (pagina 1, BTC/USD:BTC)` | +| risposta senza barre, nessuna eccezione | `nessuna barra restituita da BTC/USD:BTC (risposta vuota...)` | +| **coda attaccata, ma il certificato e' vecchio** | `coda fresca attaccata: il feed certificato stesso e' vecchio` | + +La terza riga e' quella che la nota cablata **negava**: e' il caso in cui il colpevole non e' la rete +ma il rebuild giornaliero, cioe' il feed-freeze del 14/07 in un'altra veste. + +⚠️ Il caso intermedio, che un test pigro salta: l'errore a **meta' paginazione**. La coda parziale +viene attaccata comunque — quindi il feed non e' "caduto", e' solo piu' vecchio del dovuto — e +siccome la paginazione va **in avanti**, cio' che manca sono le barre **piu' recenti**. E' proprio +il caso in cui l'eta' da sola direbbe poco. Blindato in +`test_causa_registrata_anche_con_coda_TRONCATA`. + +Blindato anche che la causa **non sopravviva a una chiamata riuscita**: un errore appiccicato +farebbe allertare su un guasto gia' rientrato, e un'allerta che grida senza motivo e' un'allerta che +si smette di leggere. + +## 4. Sull'onestà della diagnosi: la causa del 29/07 resta IGNOTA + +Ed e' importante scriverlo, perche' la tentazione era chiudere il cerchio con una spiegazione +plausibile. Cio' che si sa e' solo **circostanziale**: + +- i giri falliti durano quanto quelli riusciti (**16-46 s in entrambi gli stati**) → errore + **immediato**, non timeout; +- la finestra si apre subito dopo il **riavvio delle 04:11**, ma non si chiude con esso (alle 11:00 + funziona, alle 12:00 no); +- lo stesso giorno il percorso del **conto** — rete diversa, via `cerbero-mcp`, stesso venue a valle + — rispondeva `ReadTimeout(15s)` / `404` / `502`; +- i due percorsi falliscono **in alternanza**, non insieme (11:00 feed ok + conto ko; 12:00 conto ok + + feed ko). + +Ipotesi compatibili e **non distinguibili a posteriori**: rate limit per-IP del venue, contesa di +rete/CPU sulla VPS al minuto tondo, degrado post-riavvio. Una prima stesura di questa modifica +scriveva nei commenti "*la causa vera era il rate limit Deribit per-IP saturato da un altro progetto +sulla stessa VPS*" come se fosse un fatto: **rimossa**. Sarebbe stato lo stesso difetto della riga +che stavo correggendo, scritto meglio. + +## 5. Il ripiego sul cron, dichiarato come tale + +Il job e' stato spostato da `0 * * * *` a **`7 * * * *`** durante l'incidente (ultimo giro al minuto +tondo: 12:00; primo al :07: 12:07, riuscito). Motivo: l'ipotesi della contesa al minuto tondo, che e' +quando parte tutto il resto della macchina. + +⚠️ **Non e' un fix verificato: e' un ripiego da UNA osservazione**, preso perche' costa zero. Un +giro riuscito al :07 contro sei falliti al :00 non e' un esperimento — e' un punto. Se il feed torna +stantio anche al :07, l'ipotesi e' morta; e in entrambi i casi la risposta la dara' `skh_feed_errors` +alla prossima occorrenza, non un altro ragionamento. La nota sta in testa a `scripts/cron_book.sh`, +perche' la riga di crontab vive fuori dal repo e una mitigazione invisibile e' una mitigazione che +verra' rimossa per sbaglio. + +## 6. Sottoprodotto: anche "conto offline" diceva solo che era offline + +Stesso buco, altro ramo. Quando `online` e' falso la ragione c'e' gia' — sta in `mark_src` +(`"fallback close ()"`) — ma non veniva **mai** stampata: l'allerta diceva *"conto +offline, salto l'esecuzione"*, che e' vero e inutile. Ora l'allerta porta `mark_src` per asset. Il +comportamento (fermarsi, non operare a cieco) e' invariato. + +--- + +## Regole + +1. **Una nota di diagnosi cablata e' peggio di nessuna nota.** Nessuna nota manda a guardare i dati; + una nota sbagliata manda a guardare la pista sbagliata, e sembra una misura. +2. **Se un errore viene ingoiato per non bloccare, va registrato nello stesso punto in cui lo si + ingoia.** Fra il `break` e la fine dell'incidente non c'e' un secondo momento buono: quando la + diagnosi diventa urgente, il guasto e' gia' rientrato. +3. **Un'allerta risponde a due domande diverse — *cosa* e *perche'*.** La prima decide (si opera o + no), la seconda ripara. Misurare solo la prima costa un'intera occorrenza del guasto. +4. **Una mitigazione basata su un'osservazione sola si applica pure, ma si scrive che lo e'** — + altrimenti fra tre mesi e' una scelta di progetto di cui nessuno ricorda la fragilita'. +5. **Distinguere i guasti anche quando l'azione e' la stessa.** "Rete ko", "venue senza barre" e + "certificato vecchio" portano tutti a "non mi fido del segnale", ma a tre riparazioni diverse. diff --git a/scripts/cron_book.sh b/scripts/cron_book.sh index f164768..c8f0f80 100755 --- a/scripts/cron_book.sh +++ b/scripts/cron_book.sh @@ -4,6 +4,12 @@ # riconcilia al target NETTO corrente (se non cambia nulla -> HOLD). Il feed 5m fresco per il # segnale SKH e' preso IN MEMORIA dentro book_execute (livefeed.fresh_5m): NON tocca i dati # certificati su disco. Esecuzione reale gated da config/live.json (execution_enabled) + --execute. +# +# INSTALLATO AL MINUTO :07, NON :00 (`7 * * * *`, spostato il 2026-07-29 durante l'incidente del +# feed 5m). Motivo: IPOTESI di contesa al minuto tondo (l'ora esatta e' quando parte tutto il +# resto della VPS). ⚠️ NON e' un fix verificato — e' un ripiego da un'osservazione sola, preso +# perche' costa zero. Se il feed torna stantio anche al :07, l'ipotesi e' morta e la causa vera +# la dira' `skh_feed_errors` nel report (instrumentazione del 29/07, vedi src/live/livefeed.py). export PATH="/home/adriano/.local/bin:$PATH" cd /opt/docker/PythagorasGoal || exit 1 mkdir -p logs diff --git a/scripts/live/book_execute.py b/scripts/live/book_execute.py index ecc1817..952764a 100644 --- a/scripts/live/book_execute.py +++ b/scripts/live/book_execute.py @@ -106,20 +106,34 @@ def _run(): if skh_age is None: print(" ⚠️ freschezza feed SKH NON MISURATA (segnale su feed certificato?)") elif skh_age > max_skh_age: + # La CAUSA e' misurata (livefeed.last_fetch_error), non piu' presunta: fino al 29/07 questa + # nota diceva sempre "fetch pubblico KO" a prescindere — una presunzione stampata come se + # fosse una misura. Quel giorno il feed e' stato stantio in 6 giri orari su 8 (fino a 685 + # min) e la causa NON e' stata stabilita, proprio perche' l'unica riga disponibile era + # questa e non veniva dai dati. + errs = r.get("skh_feed_errors") or {} + causa = "; ".join(f"{a}: {e}" for a, e in sorted(errs.items())) if errs else \ + "coda fresca attaccata: il feed certificato stesso e' vecchio (rebuild giornaliero?)" print(f" ⚠️ FEED SKH STANTIO: ultima barra 5m di {skh_age:.0f} min fa " f"(soglia {max_skh_age:.0f}) -> le uscite SKH sono in ritardo, NON blocco.") + print(f" causa: {causa}") if do_execute: notify("⚠️ BOOK — feed SKH stantio (uscite in ritardo)", {"eta_min": round(skh_age), "soglia_min": round(max_skh_age), "effetto": "SL/TP di SKH01 rilevati in ritardo", - "nota": "fresh_5m e' ricaduto sul feed certificato (fetch pubblico KO)"}) + "causa": causa[:300]}) else: print(f" feed SKH : fresco ({skh_age:.0f} min)") if not r["online"]: - print(" conto non leggibile (offline) -> stop, non eseguo a cieco.") + # `online` e' falso quando il mark di BTC non viene da mainnet: la ragione sta in + # `mark_src` ("fallback close ()") ma non veniva MAI stampata, quindi + # l'allerta diceva solo "conto offline" — vero e inutile. Stesso buco del feed SKH. + srcs = "; ".join(f"{a['asset']}: {a.get('mark_src')}" for a in r["assets"]) + print(f" conto non leggibile (offline) -> stop, non eseguo a cieco.\n mark: {srcs}") if do_execute: - notify("⚠️ BOOK LIVE — conto offline", {"nota": "salto l'esecuzione, non opero a cieco"}) + notify("⚠️ BOOK LIVE — conto offline", {"nota": "salto l'esecuzione, non opero a cieco", + "mark": srcs[:300]}) return if r.get("pos_error"): # ONLINE ma posizione IGNOTA (read fallita -> assunta flat) diff --git a/src/live/book.py b/src/live/book.py index 309f9e2..b139b3a 100644 --- a/src/live/book.py +++ b/src/live/book.py @@ -194,16 +194,23 @@ def book_report(offline: bool = False, equity_override: float | None = None, cap = _cap(equity=equity, real_equity=sh.get("real_equity"), eq_fallback=sh.get("eq_fallback")) load5m = None feed_ages: dict[str, float | None] = {} + feed_errors: dict[str, str] = {} if live_feed: - from src.live.livefeed import feed_age_minutes, fresh_5m + from src.live.livefeed import feed_age_minutes, fresh_5m, last_fetch_error def load5m(a: str): """Wrapper che MISURA la freschezza del feed effettivamente usato per il segnale. `fresh_5m` ricade sul certificato in SILENZIO se il fetch pubblico fallisce: senza questa misura la latenza d'uscita di SKH01 passerebbe da ~1h a ~1 giorno senza che - nulla lo segnali (vedi feed_age_minutes).""" + nulla lo segnali (vedi feed_age_minutes). Raccoglie anche la CAUSA del fallback: + l'eta' dice CHE il feed e' vecchio, non PERCHE' — e senza il perche' la diagnosi + non e' rifacibile a posteriori, perche' quando la si prova il guasto e' rientrato + (29/07: 6 giri stantii su 8, causa mai stabilita -> vedi livefeed._LAST_ERROR).""" df = fresh_5m(a) feed_ages[a] = feed_age_minutes(df) + err = last_fetch_error() + if err is not None: + feed_errors[a] = err return df skh_error = None try: @@ -247,5 +254,9 @@ def book_report(offline: bool = False, equity_override: float | None = None, # e' stantio, il segnale netto e' sospetto. skh_feed_age_min=(max((v for v in feed_ages.values() if v is not None), default=None) if feed_ages else None), + # PERCHE' la coda fresca non e' stata attaccata, per asset ({} = nessun fallback). + # Accompagna skh_feed_age_min: senza, l'allerta puo' solo TIRARE A INDOVINARE la causa + # (ed e' esattamente cio' che faceva, con una nota cablata, fino al 29/07). + skh_feed_errors=dict(feed_errors), flat=all(abs(x["net_target"]) < FLAT_USD for x in assets), ) diff --git a/src/live/livefeed.py b/src/live/livefeed.py index d186aef..123bdd9 100644 --- a/src/live/livefeed.py +++ b/src/live/livefeed.py @@ -14,6 +14,7 @@ TP01 è giornaliero e gira bene sul feed certificato. """ from __future__ import annotations +import logging import time import pandas as pd @@ -25,6 +26,42 @@ from src.data.downloader import load_data DERIBIT_SYMBOL = {"BTC": "BTC/USD:BTC", "ETH": "ETH/USD:ETH"} SCHEMA = ["timestamp", "open", "high", "low", "close", "volume"] +_LOG = logging.getLogger(__name__) + +# CAUSA dell'ultimo fallback. Il fallback resta SILENZIOSO come comportamento (mai operare a cieco +# > mai operare, scelta del 26/07): quello che NON deve restare silenzioso e' il PERCHE'. +# +# Perche' esiste (2026-07-29): dopo il riavvio della VPS delle 04:11 UTC il feed e' ricaduto sul +# certificato in 6 giri orari su 8 fra le 05:00 e le 12:00 -> fino a 685 min di eta', cioe' la +# latenza d'uscita di SKH01 passata da ~1h a ~11h. L'allerta del 26/07 ha segnalato ogni volta +# (ha funzionato), ma la CAUSA non era recuperabile dai log: l'eccezione di pagina viene ingoiata +# con un `break` e `fresh_5m` ritorna il certificato senza lasciare traccia. L'unica riga sulla +# causa era CABLATA nell'allerta ("fetch pubblico KO") = una presunzione stampata come misura. +# ⚠️ La causa di QUEL giorno resta IGNOTA e tale deve restare scritta: le prove sono solo +# circostanziali (i giri falliti durano quanto quelli riusciti, 17-47s -> errore immediato, non +# timeout; nello stesso giorno il percorso del CONTO, rete diversa ma stesso venue a valle, dava +# ReadTimeout/404/502). Ipotesi non distinguibili a posteriori: rate limit per-IP del venue, +# contesa di rete/CPU sulla VPS al minuto tondo, degrado post-riavvio. +# Questa variabile serve a che la PROSSIMA occorrenza sia un dato e non un'ipotesi. +_LAST_ERROR: str | None = None + + +def last_fetch_error() -> str | None: + """Perche' l'ultima `fresh_5m` non ha attaccato una coda fresca COMPLETA. + + `None` = coda attaccata senza errori. Non-None = fallback al certificato **oppure** coda + troncata a meta' paginazione (la paginazione va in avanti: se cade a pagina N mancano le + barre piu' RECENTI, quindi in entrambi i casi il feed e' piu' vecchio di quanto sembri). + Chi decide guarda `feed_age_minutes`; questa dice il perche'.""" + return _LAST_ERROR + + +def _note_error(msg: str) -> None: + """Registra E logga la ragione del fallback. Non solleva: il chiamante prosegue sul certificato.""" + global _LAST_ERROR + _LAST_ERROR = msg + _LOG.warning("fresh_5m: coda fresca non attaccata, fallback al feed certificato — %s", msg) + def _fetch_recent_5m(symbol: str, lookback_days: int) -> pd.DataFrame: """Coda recente di 5m da Deribit pubblico (ccxt). Paginazione in avanti. Solo letture pubbliche.""" @@ -38,7 +75,12 @@ def _fetch_recent_5m(symbol: str, lookback_days: int) -> pd.DataFrame: guard += 1 try: r = ex.fetch_ohlcv(symbol, "5m", since=since, limit=1000) - except Exception: + except Exception as e: + # E' QUI che il guasto diventa invisibile: l'errore di pagina viene ingoiato e la + # funzione ritorna comunque cio' che ha raccolto finora. Se a fallire e' la PRIMA + # pagina il risultato e' un DataFrame VUOTO, che a valle e' indistinguibile da + # "Deribit non ha barre" — ed e' il ramo che il 29/07 ha cancellato la diagnosi. + _note_error(f"{type(e).__name__}: {e} (pagina {guard}, {symbol})") break r = [x for x in r if int(x[0]) >= since] if not r: @@ -94,13 +136,25 @@ def fresh_5m(asset: str, lookback_days: int = 12) -> pd.DataFrame: NB: il fallback e' SILENZIOSO per scelta (mai operare a cieco > mai operare). Chi esegue deve misurare la freschezza di cio' che riceve con `feed_age_minutes` — vedi book.book_report, che - la espone come `skh_feed_age_min`, e book_execute, che allerta.""" + la espone come `skh_feed_age_min`, e book_execute, che allerta. La RAGIONE del fallback resta + disponibile in `last_fetch_error()` fino alla chiamata successiva.""" + global _LAST_ERROR + _LAST_ERROR = None base = load_data(asset, "5m") sym = DERIBIT_SYMBOL.get(asset) if sym is None: + _note_error(f"nessun simbolo Deribit per l'asset {asset}") return base try: tail = _fetch_recent_5m(sym, lookback_days) - except Exception: + except Exception as e: + _note_error(f"{type(e).__name__}: {e} ({sym})") + return base + if tail is None or len(tail) == 0: + # Coda vuota senza eccezione propagata: o _fetch_recent_5m ha gia' registrato l'errore + # di pagina, o Deribit ha davvero risposto senza barre. Sono due guasti diversi e vanno + # detti diversi, senno' si ricade nel "non vedo = va tutto bene" gia' pagato due volte. + if _LAST_ERROR is None: + _note_error(f"nessuna barra restituita da {sym} (risposta vuota, nessuna eccezione)") return base return merge_tail(base, tail) diff --git a/tests/test_skh_feed_freshness.py b/tests/test_skh_feed_freshness.py index 22bc671..5ef7d86 100644 --- a/tests/test_skh_feed_freshness.py +++ b/tests/test_skh_feed_freshness.py @@ -1,12 +1,20 @@ """Test della misura di FRESCHEZZA del feed 5m usato dal segnale SKH01 (2026-07-26). Perche' esiste questo file: `src.live.livefeed.fresh_5m` ricade sul feed certificato **in -silenzio** se il fetch pubblico Deribit fallisce — non solleva, non logga. Il feed certificato si +silenzio** se il fetch pubblico Deribit fallisce — non solleva. Il feed certificato si rigenera una volta al giorno, quindi in quel caso la latenza d'uscita di SKH01 passa da ~1 ora a ~1 giorno senza che nulla lo segnali. Ed e' proprio la latenza d'uscita dove vive la qualita' del path live (misura del 2026-07-26: modellarla male sottostimava il book di +0.081 Sharpe FULL). I test blindano che la misura ci sia, sia corretta nei casi limite, e arrivi fino al report. + +AGGIUNTA 2026-07-29 — il fallback resta silenzioso come COMPORTAMENTO, ma non piu' come CAUSA. +Quel giorno il feed e' ricaduto sul certificato in 6 giri orari su 8 (fino a 685 min di eta') e +l'allerta incolpava il "fetch pubblico KO" solo perche' quella nota era CABLATA in book_execute: +la causa vera non e' mai stata stabilita, perche' l'eccezione era gia' stata ingoiata e a +guasto rientrato non c'era piu' niente da interrogare. I test in coda blindano che la ragione +venga REGISTRATA, che distingua guasti diversi, e che non sopravviva a una chiamata riuscita +(senno' l'allerta riporterebbe un guasto gia' rientrato). """ from __future__ import annotations @@ -21,6 +29,7 @@ sys.path.insert(0, str(ROOT)) pytest.importorskip("pandas") import pandas as pd # noqa: E402 +import src.live.livefeed as lf # noqa: E402 from src.live.livefeed import SCHEMA, feed_age_minutes, merge_tail # noqa: E402 @@ -87,6 +96,111 @@ def test_book_report_espone_la_chiave(monkeypatch): assert r["skh_feed_age_min"] is None +def _stub_certificato(monkeypatch): + """Feed 'certificato' finto e vecchio di 10 ore. Evita di leggere i 22MB reali da disco: + questi test riguardano la CAUSA del fallback, non i dati.""" + old = NOW - 10 * 60 * 60_000 + monkeypatch.setattr(lf, "load_data", lambda a, tf: _df([old - 300_000, old])) + + +def test_causa_registrata_quando_il_fetch_solleva(monkeypatch): + """La forma del guasto del 29/07: l'errore cade sulla PRIMA pagina. `_fetch_recent_5m` lo + ingoia con `break` e ritorna un frame vuoto, quindi `fresh_5m` non vede nessuna eccezione -> + senza registrazione esplicita la ragione sparisce e resta solo 'il feed e' vecchio'. + (Il 429 qui e' un errore d'esempio: la causa reale di quel giorno e' rimasta ignota.)""" + ccxt = pytest.importorskip("ccxt") + _stub_certificato(monkeypatch) + + class Boom: + def fetch_ohlcv(self, *a, **k): + raise RuntimeError("429 Too Many Requests") + + monkeypatch.setattr(ccxt, "deribit", lambda *a, **k: Boom()) + lf.fresh_5m("BTC") + err = lf.last_fetch_error() + assert err is not None, "la causa del fallback dev'essere registrata, non presunta" + assert "429" in err and "BTC/USD:BTC" in err, err + + +def test_causa_distingue_risposta_vuota_da_eccezione(monkeypatch): + """Deribit che risponde SENZA barre e Deribit che solleva sono guasti diversi (il primo non + e' un errore di rete). Se la nota fosse la stessa, la diagnosi ripartirebbe da zero.""" + ccxt = pytest.importorskip("ccxt") + _stub_certificato(monkeypatch) + + class Vuoto: + def fetch_ohlcv(self, *a, **k): + return [] + + monkeypatch.setattr(ccxt, "deribit", lambda *a, **k: Vuoto()) + lf.fresh_5m("BTC") + err = lf.last_fetch_error() + assert err is not None and "429" not in err, err + assert "vuota" in err or "nessuna barra" in err, err + + +def test_causa_registrata_anche_con_coda_TRONCATA(monkeypatch): + """Il caso intermedio, quello che un test pigro salta: l'errore cade a META' paginazione. + La coda parziale VIENE attaccata (meglio di niente) -> il feed non e' 'caduto', e' solo + piu' vecchio del dovuto. Siccome la paginazione va IN AVANTI, cio' che manca sono le barre + PIU' RECENTI: e' esattamente il caso in cui l'eta' da sola direbbe poco e la causa serve.""" + ccxt = pytest.importorskip("ccxt") + _stub_certificato(monkeypatch) + primo = NOW - 3 * 60 * 60_000 # coda attaccata, ma ferma a 3 ore fa + + class MezzaStrada: + def __init__(self): + self._servito = False + + def fetch_ohlcv(self, *a, **k): + if self._servito: + raise RuntimeError("ConnectionResetError alla seconda pagina") + self._servito = True + return [[primo, 1.0, 1.0, 1.0, 1.0, 1.0]] + + monkeypatch.setattr(ccxt, "deribit", lambda *a, **k: MezzaStrada()) + df = lf.fresh_5m("BTC") + err = lf.last_fetch_error() + assert err is not None and "pagina 2" in err, err + # la coda parziale c'e' davvero (l'ultima barra e' quella della pagina 1, non del certificato) + assert int(df["timestamp"].iloc[-1]) == primo + # ...e l'eta' resta fuori soglia: la causa spiega un feed vecchio, non ne salva uno. + assert feed_age_minutes(df, now_ms=NOW) == pytest.approx(175.0) + + +def test_causa_non_sopravvive_a_una_chiamata_riuscita(monkeypatch): + """Coda attaccata -> nessuna causa residua: un errore vecchio che resta appiccicato farebbe + allertare su un guasto gia' rientrato (rumore che spegne l'attenzione sull'allerta vera).""" + ccxt = pytest.importorskip("ccxt") + _stub_certificato(monkeypatch) + recente = NOW - 5 * 60_000 + + class Ok: + def __init__(self): + self._servito = False + + def fetch_ohlcv(self, *a, **k): + if self._servito: + return [] + self._servito = True + return [[recente, 1.0, 1.0, 1.0, 1.0, 1.0]] + + monkeypatch.setattr(ccxt, "deribit", lambda *a, **k: Ok()) + lf._LAST_ERROR = "residuo di una chiamata precedente" + df = lf.fresh_5m("BTC") + assert lf.last_fetch_error() is None, lf.last_fetch_error() + assert feed_age_minutes(df, now_ms=NOW) == pytest.approx(0.0) + + +def test_book_report_espone_le_cause(): + """La causa dev'essere nel report: senza, `book_execute` non puo' allertare con la ragione + vera e ricade sulla nota cablata — il difetto che ha tenuto nascosto il guasto del 29/07.""" + from src.live import book as bk + r = bk.book_report(offline=True, equity_override=600.0) + assert "skh_feed_errors" in r + assert r["skh_feed_errors"] == {}, "senza live_feed non c'e' nessun fallback da spiegare" + + def test_soglia_di_config_presente_e_sensata(): """La soglia dev'essere piu' larga della cadenza del cron (orario) e molto piu' stretta di un giorno, sennò non distingue 'fresco' da 'ricaduto sul certificato'."""