audit: alert delivery, provider robustness, backtester NaN/cache guards (Batches C+E+F)

2026-08-04 Fable 5 QA audit. Three batches sharing one test file, all
verified by runnable repros before fixing, all gated below.

Batch C — telegram alert delivery (verified by h4 harness):
- Failed breach rescan shrinks the cooldown to 30 s instead of
  silencing the symbol for 5 min; breach during cooldown is PARKED and
  fired on the first tick after expiry (was dropped forever).
- Level cache keyed symbol→TF (M5 scans no longer wipe H1/H4 swing
  levels within minutes); breach labels TF-qualified.
- Markdown alert sends get a plain-text fallback (mirroring _safe_edit);
  fingerprint commits only when a message actually landed.
- Per-key asyncio.Lock closes the dedup TOCTOU between auto-scan and
  breach sends (forced-interleave repro produced duplicate alerts).
- _start_scheduler respawns dead per-TF loops (was all-or-nothing).
- Clean WS close now backs off (was a zero-delay reconnect hot loop);
  backoff resets only after a connection that received ticks; TD
  iter_ticks fires on_connect on the first RECEIVED frame (invalid key
  can no longer pin the backoff at minimum).
- Scan-failure logs carry the real traceback (was "NoneType: None").

Batch E — providers (verified by h5 harness):
- fetch_range: 3 consecutive chunk ERRORS raise instead of returning
  silently truncated history (verified 731-day silent gap repro; also
  covers 429 storms); pagination no-progress guard; head-truncation
  ERROR log.
- Single-flight per (symbol,TF): 4 concurrent scans = 1 API call (was
  4); cache records requested depth so a longer-lookback call refetches.
- Multi-bar forming/future tail fully dropped (was iloc[:-1] once).
- Oanda: malformed candles skipped, never 0.0-defaulted; cleaning drops
  non-positive-price rows BEFORE OHLC repair; inf returns neutralized so
  one corrupt bar can no longer disarm the whole 10-sigma filter.

Batch F — backtester internals (verified by h6 harness):
- NaN bar in a trailing window exits at the last valid bar (was NaN R
  poisoning every metric); static-path TIMEOUT NaN guard;
  compute_metrics excludes non-finite R loudly. Zero real-data exposure
  (0 NaN rows in all 10 Oanda parquets) — defensive.
- fetch_history ERROR-logs pre-2026-07-08 cache files (cleaned-bars era)
  when loaded for raw-path resolution.

Gates: suite 333/333 green; pinned M15 12mo book reproduced identically
(397 trades, +78.7111R) after E and after F; M5 HEAD-config baseline
reproduced identically (556 trades, +97.5604R) after F.

Claude-Session: https://claude.ai/code/session_01UnZkzeFcTu9agFg8BDh2tn
This commit is contained in:
Harwinder Sekhon
2026-08-04 20:02:57 -04:00
parent 18e4fd0403
commit 99eb268cf3
6 changed files with 1117 additions and 141 deletions
+204 -61
View File
@@ -600,6 +600,45 @@ def _commit_alert(key: str, report: SignalReport) -> None:
_last_alert_setup.pop(key, None)
# Per-key locks serializing the _should_alert → send → _commit_alert
# window. The auto-scan loop and a concurrent breach handler share the
# "XAU/USD_15min" dedup key; without the lock both pass _should_alert
# while the other's send is still awaiting Telegram, and the same signal
# goes out twice (2026-08-04 audit H36). Per-key rather than one global
# lock so a slow send on one timeframe cannot head-of-line-block another
# timeframe's alert. Keys are symbol × TF, so the dict stays tiny.
_alert_locks: Dict[str, asyncio.Lock] = {}
def _alert_lock(key: str) -> asyncio.Lock:
lock = _alert_locks.get(key)
if lock is None:
lock = _alert_locks[key] = asyncio.Lock()
return lock
async def _send_alert(bot, chat_id: int, text: str) -> bool:
"""Markdown alert send with a plain-text fallback on parse failures,
mirroring _safe_edit (2026-08-04 audit H35 — alert paths previously
dropped the message on a BadRequest with only a warning logged).
Returns True when a message reached the chat by either attempt."""
try:
await bot.send_message(chat_id, text, parse_mode=ParseMode.MARKDOWN)
return True
except BadRequest as exc:
logger.warning(f"Markdown alert failed for chat {chat_id} ({exc}); "
f"retrying as plain text")
try:
await bot.send_message(chat_id, text)
return True
except Exception as exc2:
logger.warning(f"Failed to send alert to chat {chat_id}: {exc2}")
return False
except Exception as exc:
logger.warning(f"Failed to send alert to chat {chat_id}: {exc}")
return False
# ── Candle-boundary scheduler ────────────────────────────────────────
_autoscan_chats: Set[int] = set()
@@ -644,7 +683,13 @@ async def _scan_timeframe(
reports: List[SignalReport] = []
for i, result in enumerate(results):
if isinstance(result, Exception):
logger.exception(f"Auto-scan failed for {SCAN_PAIRS[i]} {tf.value}: {result}")
# gather(return_exceptions=True) means there is no active
# exception here — logger.exception would log "NoneType: None"
# instead of the real stack; pass the instance explicitly.
logger.error(
f"Auto-scan failed for {SCAN_PAIRS[i]} {tf.value}: {result}",
exc_info=result,
)
else:
reports.append(result)
@@ -653,36 +698,51 @@ async def _scan_timeframe(
_update_level_cache(reports)
actionable = [
candidates = [
r for r in reports
if r.final_signal != SignalStrength.NEUTRAL # same gate as breach path
and _passes_quality(r.signal_quality)
and _should_alert(f"{r.symbol}_{tf.value}", r)
]
sent_ok: Set[int] = set()
for chat_id in _signal_targets():
for i, report in enumerate(actionable):
for report in candidates:
key = f"{report.symbol}_{tf.value}"
# The lock spans check → send → commit so a concurrent breach
# handler on the same key cannot double-alert (H36).
async with _alert_lock(key):
if not _should_alert(key, report):
continue
detail = format_signal_message(report)
try:
await bot.send_message(chat_id, detail, parse_mode=ParseMode.MARKDOWN)
sent_ok.add(i)
except Exception as exc:
logger.warning(f"Failed to send signal for chat {chat_id}: {exc}")
# Commit fingerprints only for alerts that reached at least one target;
# a fully failed send stays eligible for the next scan.
for i, report in enumerate(actionable):
if i in sent_ok:
_commit_alert(f"{report.symbol}_{tf.value}", report)
delivered = False
for chat_id in _signal_targets():
if await _send_alert(bot, chat_id, detail):
delivered = True
# Commit only when the alert reached at least one target;
# a fully failed send stays eligible for the next scan.
if delivered:
_commit_alert(key, report)
# ── WebSocket level-breach monitor ──────────────────────────────────
_level_cache: Dict[str, Dict[str, float]] = {}
_level_cache_ts: Dict[str, float] = {}
# Level cache keyed symbol → timeframe → {level_name: price}, with a
# matching per-TF write timestamp. Keyed per TF (2026-08-04 audit H34)
# because every scan path writes here — the M5/M15/H1/H4 boundary loops,
# the breach rescan, the manual Scan-All button — and a single flat dict
# meant the last writer wiped the other timeframes' swing/EMA levels
# within minutes. Breach checks scan the union of all fresh TF entries.
_level_cache: Dict[str, Dict[str, Dict[str, float]]] = {}
_level_cache_ts: Dict[str, Dict[str, float]] = {}
_LEVEL_CACHE_TTL = 3600
_last_prices: Dict[str, float] = {}
_last_price_ts: Dict[str, float] = {}
_scan_cooldowns: Dict[str, float] = {}
# Breaches are edge-triggered (only the crossing tick fires), so one that
# lands while the symbol is inside the rescan cooldown would otherwise be
# dropped forever (H33b). Park it here; the tick loop fires it once the
# cooldown expires. symbol → (price, level_name, recorded_at).
_pending_breach: Dict[str, tuple] = {}
# A failed breach rescan shrinks the just-set cooldown to this retry
# window instead of silencing the symbol for the full cooldown (H33a).
_BREACH_RETRY_SECONDS = 30
_cfg = PlatformConfig()
_WS_COOLDOWN = _cfg.ws_cooldown_seconds
@@ -691,6 +751,8 @@ _breach_tasks: Set[asyncio.Task] = set()
def _update_level_cache(reports: List[SignalReport]) -> None:
"""Each report updates only its own timeframe's slot — an M5 scan can
no longer overwrite the H1/H4 swing levels (H34)."""
now = time.time()
for r in reports:
if r.primary_analysis and r.primary_analysis.key_levels:
@@ -699,26 +761,31 @@ def _update_level_cache(reports: List[SignalReport]) -> None:
if k in _LEVEL_KEYS
}
if levels:
_level_cache[r.symbol] = levels
_level_cache_ts[r.symbol] = now
tf = r.primary_analysis.timeframe
_level_cache.setdefault(r.symbol, {})[tf] = levels
_level_cache_ts.setdefault(r.symbol, {})[tf] = now
def _check_level_breach(symbol: str, price: float) -> Optional[str]:
levels = _level_cache.get(symbol)
if not levels:
return None
cache_age = time.time() - _level_cache_ts.get(symbol, 0)
if cache_age > _LEVEL_CACHE_TTL:
"""Scan the union of every fresh timeframe's levels; returns
'<tf> <level_name>' (e.g. '15min swing_high_1') on a crossing so the
alert label says which timeframe's level broke."""
per_tf = _level_cache.get(symbol)
if not per_tf:
return None
last = _last_prices.get(symbol)
if last is None:
return None
for name, level in levels.items():
if (last < level <= price) or (last > level >= price):
return name
now = time.time()
ts_map = _level_cache_ts.get(symbol, {})
for tf, levels in per_tf.items():
if now - ts_map.get(tf, 0) > _LEVEL_CACHE_TTL:
continue # stale TF entry — skip, fresher TFs still count
for name, level in levels.items():
if (last < level <= price) or (last > level >= price):
return f"{tf} {name}"
return None
@@ -733,9 +800,17 @@ def _cleanup_cooldowns() -> None:
async def _handle_breach(bot, pair_symbol: str, price: float, level_name: str) -> None:
now = time.time()
if now - _scan_cooldowns.get(pair_symbol, 0) < _WS_COOLDOWN:
# Park the crossing instead of dropping it — price holding beyond
# the level never re-fires the edge trigger, so without this the
# breach would be lost forever (H33b). The tick loop fires it
# once the cooldown expires; a newer crossing overwrites it.
_pending_breach[pair_symbol] = (price, level_name, now)
return
# Early-set on purpose: this is what stops concurrent breach tasks
# from stacking rescans. The failure path below rolls it back.
_scan_cooldowns[pair_symbol] = now
_pending_breach.pop(pair_symbol, None) # this crossing is being handled
display = PAIR_INFO.get(pair_symbol, {}).get("display", pair_symbol)
label = level_name.replace("_", " ").title()
logger.info(f"Level breach: {display} crossed {label} at {price} — rescanning M15")
@@ -745,29 +820,42 @@ async def _handle_breach(bot, pair_symbol: str, price: float, level_name: str) -
_update_level_cache([report])
except Exception:
logger.exception(f"Breach scan failed for {display}")
# Shrink the just-set cooldown to a short retry window so a
# transient fetch error doesn't silence the symbol for the full
# cooldown (H33a); the floor bounds the retry rate while the
# provider stays down. Re-park the breach so the tick loop
# retries it (setdefault: a newer crossing recorded meanwhile
# wins over this stale one).
retry = min(_BREACH_RETRY_SECONDS, _WS_COOLDOWN)
_scan_cooldowns[pair_symbol] = now - _WS_COOLDOWN + retry
_pending_breach.setdefault(pair_symbol, (price, level_name, now))
return
# Alert only when the rescan produced an actionable, changed signal —
# same gates as the auto-scanner, so a breach can't spam the channel.
if (report.final_signal == SignalStrength.NEUTRAL
or not _passes_quality(report.signal_quality)
or not _should_alert(f"{pair_symbol}_{Timeframe.M15.value}", report)):
or not _passes_quality(report.signal_quality)):
return
header = (
f"⚡ *LEVEL BREAK* — {_escape_md(display)} crossed "
f"*{_escape_md(label)}* @ `{_fmt_price(price)}`\n\n"
)
sent = False
for chat_id in _signal_targets():
key = f"{pair_symbol}_{Timeframe.M15.value}"
# Lock spans check → send → commit; without it this handler and an
# in-flight M15 auto-scan both pass _should_alert and double-alert
# the same signal (H36).
async with _alert_lock(key):
if not _should_alert(key, report):
return
header = (
f"⚡ *LEVEL BREAK* — {_escape_md(display)} crossed "
f"*{_escape_md(label)}* @ `{_fmt_price(price)}`\n\n"
)
detail = header + format_signal_message(report)
try:
await bot.send_message(chat_id, detail, parse_mode=ParseMode.MARKDOWN)
sent = True
except Exception as exc:
logger.warning(f"Failed to send breach alert to chat {chat_id}: {exc}")
if sent:
_commit_alert(f"{pair_symbol}_{Timeframe.M15.value}", report)
sent = False
for chat_id in _signal_targets():
if await _send_alert(bot, chat_id, detail):
sent = True
if sent:
_commit_alert(key, report)
def _breach_task_done(task: asyncio.Task) -> None:
@@ -799,13 +887,16 @@ async def _ws_monitor(bot) -> None:
backoff = 1
while _feed_active():
got_tick = False
try:
def _on_connect() -> None:
nonlocal backoff
backoff = 1
async for pair_symbol, price in dp.iter_ticks(
SCAN_PAIRS, on_connect=_on_connect):
async for pair_symbol, price in dp.iter_ticks(SCAN_PAIRS):
if not got_tick:
# Reset backoff only once the connection actually
# produced data — resetting on connect let a
# rejected key or accept-then-close server pin the
# backoff at minimum forever (H38a/H38b).
got_tick = True
backoff = 1
if not _feed_active():
break
@@ -814,11 +905,32 @@ async def _ws_monitor(bot) -> None:
_last_price_ts[pair_symbol] = time.time()
if breached:
# A fresh crossing supersedes any parked one.
_pending_breach.pop(pair_symbol, None)
task = asyncio.create_task(
_handle_breach(bot, pair_symbol, price, breached)
)
_breach_tasks.add(task)
task.add_done_callback(_breach_task_done)
elif pair_symbol in _pending_breach:
pend = _pending_breach[pair_symbol]
if time.time() - pend[2] > _LEVEL_CACHE_TTL:
# Ancient parked breach (feed gap/weekend) — an
# alert about an hours-old crossing would only
# mislead; the level cache it came from is stale
# anyway.
_pending_breach.pop(pair_symbol)
elif (time.time() - _scan_cooldowns.get(pair_symbol, 0)
>= _WS_COOLDOWN):
# Crossing parked during the cooldown: fire it now
# that the window expired — the edge trigger alone
# would have dropped it forever (H33b).
_pending_breach.pop(pair_symbol)
task = asyncio.create_task(
_handle_breach(bot, pair_symbol, pend[0], pend[1])
)
_breach_tasks.add(task)
task.add_done_callback(_breach_task_done)
_cleanup_cooldowns()
@@ -828,6 +940,16 @@ async def _ws_monitor(bot) -> None:
logger.exception(f"WebSocket error, reconnecting in {backoff}s")
await asyncio.sleep(backoff)
backoff = min(backoff * 2, 60)
else:
# Clean server close: the async-for ended without raising.
# This must back off and log like the error path — silently
# reconnecting with zero delay hot-loops against a server
# that accepts and immediately closes (H38a).
if _feed_active():
logger.warning(
f"WebSocket closed cleanly, reconnecting in {backoff}s")
await asyncio.sleep(backoff)
backoff = min(backoff * 2, 60)
logger.info("WebSocket monitor stopped")
@@ -870,15 +992,25 @@ _ws_task: Optional[asyncio.Task] = None
def _start_scheduler(bot) -> None:
global _ws_task
alive = [t for t in _autoscan_tasks if not t.done()]
if not alive:
_autoscan_tasks.clear()
for tf, interval in _AUTOSCAN_LOOPS:
_autoscan_tasks.append(
asyncio.create_task(_candle_loop(bot, tf, interval))
)
# Per-TF respawn (2026-08-04 audit H37): drop finished loop tasks and
# recreate only the missing ones. The old all-or-nothing alive check
# left a single dead TF loop unmonitored forever while its siblings
# lived — and with the channel feed active, /autoscan never reaches
# _stop_scheduler, so nothing short of a process restart recovered it.
_autoscan_tasks[:] = [t for t in _autoscan_tasks if not t.done()]
alive_names = {t.get_name() for t in _autoscan_tasks}
started = []
for tf, interval in _AUTOSCAN_LOOPS:
name = f"candle_loop_{tf.name}"
if name in alive_names:
continue
_autoscan_tasks.append(
asyncio.create_task(_candle_loop(bot, tf, interval), name=name)
)
started.append(tf.name)
if started:
logger.info("Candle-boundary scheduler started (%s)",
"/".join(tf.name for tf, _ in _AUTOSCAN_LOOPS))
"/".join(started))
if _ws_task is None or _ws_task.done():
_ws_task = asyncio.create_task(_ws_monitor(bot))
@@ -1006,9 +1138,16 @@ def _status_text() -> str:
lines.append("\n_No live prices yet (WS not streaming)_")
cached_pairs = len(_level_cache)
cached_levels = sum(len(v) for v in _level_cache.values())
cached_levels = sum(
len(levels) for per_tf in _level_cache.values()
for levels in per_tf.values()
)
if cached_levels:
oldest_age = time.time() - min(_level_cache_ts.values()) if _level_cache_ts else 0
all_ts = [
ts for per_tf in _level_cache_ts.values()
for ts in per_tf.values()
]
oldest_age = time.time() - min(all_ts) if all_ts else 0
lines.append(f"\n*Level Cache:* {cached_levels} levels across {cached_pairs} pairs (oldest {oldest_age:.0f}s)")
else:
lines.append("\n*Level Cache:* empty — breach alerts start after first candle scan")
@@ -1311,7 +1450,11 @@ async def _post_init(app: Application) -> None:
logger.error(f"Initial scan failed for {SCAN_PAIRS[i]}: {r}")
if init_reports:
_update_level_cache(init_reports)
logger.info(f"Level cache populated: {sum(len(v) for v in _level_cache.values())} levels")
n_levels = sum(
len(levels) for per_tf in _level_cache.values()
for levels in per_tf.values()
)
logger.info(f"Level cache populated: {n_levels} levels")
except Exception:
logger.exception("Initial scan failed — WS will wait for first candle scan")