From
Silent Deadlock to Observable Degradation: как бот пережил 7 часов
проблем Finam API
В прошлой
статье «Silent deadlock» (25 апреля) бот научился сам сообщать, что
застрял. Главный урок был простой: тишина — это тоже состояние. Если бот
молчит — про это надо уведомлять, а не считать «всё хорошо».
Между той статьёй и этой случилось два важных события. Первое — 27
апреля Finam API ушёл в семичасовой outage. Второе — у нас был кейс, где
плановая ревью-консенсус-подпись на gRPC-плане оказалась не финалом, а
промежуточной точкой. Оба заставили доработать систему — не
функциональный код, а её способность вести себя адекватно, когда что-то
идёт не так.
Recap: silent deadlock
13 дней молчания — это main story прошлой статьи. Бот жив, мониторинг
зелёный, на бирже 5 позиций, в учёте 0 активных спредов. Никаких ошибок.
Помог только ручной аудит.
Stage 1 — это detector: бот каждые 10 минут проверяет invariant
broker > 0 AND active == 0 и пишет в
bot_health_log (миграция 034). Не починка, а сигнал.
Главное — silent deadlock больше не сможет молчать 13 дней.
Эта таблица понадобилась снова — но уже для другого инцидента.
27 апреля: семь часов тишины
Finam
В ночь на 27 апреля Finam API ушёл в outage. Не падал в 500 сразу —
отвечал envoy’ной заглушкой “no healthy upstream”, т.е. транспорт
работал, gRPC-handshake проходил, а полезные данные не возвращал.
Длилось около пяти часов в обычные ночи; на этот раз — семь.
В нормальной ситуации бот перезагружает chain каждый час: запрашивает
у Finam список опционов, обновляет внутренний chain object. Реализация в
src/bin/options_bot/main.rs:196-228:
if last_chain_reload.elapsed().as_secs() > chain_reload_secs {
match tokio::time::timeout(Duration::from_secs(15), fetch_option_chain(&sdk, &args.underlying)).await {
Ok(Ok(new_chain)) => {
chain = new_chain;
last_chain_reload = std::time::Instant::now(); // only here
}
Ok(Err(e)) => warn!("Chain reload failed: {}", e), // last_chain_reload UNCHANGED
Err(_) => warn!("Chain reload timed out (15s)"), // last_chain_reload UNCHANGED
}
}
Тонкость в комментариях. last_chain_reload обновляется
только в success-ветке. На timeout или error — не трогается. Это значит
на следующей итерации main loop (через 30 секунд) бот опять видит “час
прошёл с последнего reload” и опять делает запрос. И ещё. И ещё.
Получался retry-storm: за пятичасовой outage бот мог сделать сотни
безуспешных попыток перезагрузить chain; для семичасового окна baseline
оценивался примерно в 840 попыток. Лог-spam закрывал реальные warning от
других подсистем. И — менее очевидное — бот добавлял трафик на endpoint,
который и так уже не справлялся.
Money loss это не давало (quality gate блокирует свежие входы при
stale chain), но visibility страдала: оператор видел только лавину
одинаковых WARN’ов и не понимал, насколько устарел chain в данный
момент.
BUG-125: что изменилось
Фикс выкатили 28 апреля. Изменения чисто на стороне retry discipline
и observability — без новых dependencies и без
trying-to-fix-the-internet.
Cooldown (M1). Failure-ветки теперь обновляют
отдельный last_attempt Instant (300 секунд cooldown).
Логика “пора делать reload” стала двойной: пройти час с последнего
успеха (stale) И пройти 5 минут с последней попытки
(cooled_down). Pure-функция в новом модуле
chain_reload.rs:
pub fn should_reload_chain(
last_success: Instant,
last_attempt: Instant,
now: Instant,
cfg: &ChainReloadConfig,
) -> bool {
let stale = now.duration_since(last_success) > cfg.interval;
let cooled_down = now.duration_since(last_attempt) > cfg.cooldown;
stale && cooled_down
}
Эффект померили на 30 апреля во время следующего семичасового outage:
39 попыток вместо ~840 — то есть в 21 раз меньше
нагрузки на degraded endpoint и в 21 раз меньше log spam.
Before BUG-125 (5h outage 2026-04-27):
reload --> success: wait 1h, then reload
|
+-> fail/timeout: 30s loop -> reload -> fail -> 30s loop -> ...
(~840 attempts, log spam)
After BUG-125 (7h outage 2026-04-30):
reload --> success: wait 1h, then reload
|
+-> fail/timeout: wait 5min cooldown -> reload -> ...
(39 attempts, x21 less)
Chain age severity (M3). Бот теперь знает, насколько
устарел chain. Три уровня:
| Severity | Threshold | Action |
|---|---|---|
| Info | < 90 minutes | normal log line |
| Warn | 90-180 minutes | warn + write chain_stale row in bot_health_log |
| Error | > 180 minutes | error + escalation marker |
Escalation rate-limited до 15-минутной каденции — чтобы не залить
bot_health_log одинаковыми записями подряд. Между outage-периодами
таблица остаётся чистой.
Post-deploy monitoring. Параллельно запустили
systemd timer (bug-125-watch.timer, каждые 30 минут): берёт
счётчики из journald + bot_health_log + forced_action_log за последние
30 минут, пишет markdown-отчёт в
/home/sergey/finam-rs-bot/reports/. Дешёвый способ
верифицировать, что фикс работает в реальных условиях, а не только на
нашей синтетике.
Финальная верификация — through outage, не вокруг него. С 02:08 до
09:17 30 апреля Finam опять отдавал “no healthy upstream”; за 11 часов
наблюдения бот:
| Метрика | Цель | Факт |
|---|---|---|
| Chain reload failed / день | < 100 | 2 (~4/day extrapolated) |
| forced_action_log growth | < 2x baseline | 0 forced actions |
| chain_stale escalation cadence | 15-min | 14 entries, 15-16min spaced |
| Cooldown attempts | observable | 39 vs ~840 baseline (×21) |
| Bot survives | no panic, no loss | 3 spreads preserved, alive |
BUG-125 закрыт 30 апреля 09:17 MSK.
Что стало лучше
Техническая суть простая: бот не «чинит интернет», но умеет
деградировать управляемо. Меньше retry noise. Есть явный сигнал
stale/degraded state. Outage стал наблюдаемым, а не silent.
Главное — паттерн закрепился. После Stage 1 detector’а (BUG-123) и
cooldown/escalation (BUG-125) бот стал писать в
bot_health_log несколько разных типов событий. Один раз
сделанная инфраструктура (миграция 034 + helper
log_bot_health) переиспользуется без появления новых таблиц
на каждый кейс. Следующие похожие сигналы — clock drift, P2 margin gate,
T-53 quote-delayed — можно вести через ту же модель: один health log,
разные reason.
Что изменилось в
engineering process
Параллельно с BUG-125 шёл другой кейс — план T-53 для миграции трёх
hardcoded зависимостей (GO, trading hours, clock drift) на gRPC SDK
Finam. План прошёл 6 раундов codex-ревью и получил CONSENSUS 25 апреля.
Казалось, готово к реализации.
И тут вмешался P0 empirical probe — небольшой одноразовый бинарь,
который должен был просто подтвердить, что gRPC-эндпоинт
get_asset_params действительно возвращает margin. Probe
вернул verdict DEFER: на weekend OTM-страйки приходили
tradeable=false / “Quote delayed”, а захардкоженный GO=3619
RUB оказался composite (по портфелю), а не per-symbol baseline. Прямое
сравнение API-данных с этим числом было apples-to-oranges.
После DEFER понадобилось ещё 4 раунда ревью.
| Round | Date | Verdict | Что нашёл codex |
|---|---|---|---|
| v6 | 25 апреля | CONSENSUS | (initial 6-round arc closed) |
| v7 | 1 мая | NEEDS REVISION | probe не реализует ATM-selection; per-symbol comparator невозможен |
| v8 | 1 мая | NEEDS REVISION | timeout/reconnect только в shadow-runner, не в production wrapper’ах |
| v9 | 1 мая | NEEDS REVISION | grep DoD узкий; NotFound variant без явного fail-closed mapping |
| v10 | 1 мая | APPROVED | (план готов к старту) |
Каждое из этих findings — реальный edge case, который легко мог
доехать до продакшена без отдельного empirical gate. И каждое ловилось
не одним проходом, а несколькими.
Урок похож на прошлый, но на другом уровне: APPROVED плана — не
финал. Сам approved plan нуждается в empirical gate’ах: P0 probe для
эмпирической валидации, shadow-run для real-data сравнения, observation
window для накопления статистики. Только после этих гейтов можно
говорить об устойчивом deployment.
Если собрать оба сюжета вместе, получается одна линия:
[ Silent Deadlock ] no signal, manual audit, 13-day starvation
|
| BUG-123 Stage 1 detector
v
[ Observable bot ] bot_health_log row when broker>0 AND active==0
|
| BUG-125 chain reload resilience
v
[ Observable degradation ] cooldown + chain_age severity + stale escalation
|
| T-53 (in progress)
v
[ Empirical gates ] P0 probe -> P0.6 -> P0.5 shadow -> production flag
Каждый шаг — про другой угол того же вопроса: насколько быстро бот
сам понимает, что у него не так, и насколько уверенно мы знаем, что
внесённое изменение действительно работает.
Что дальше
В понедельник 4 мая стартует P0.6 — weekday probe с orderbook-first
выбором ATM/near-ATM ликвидных контрактов. Если PASS — начинается
реализация P0.5 shadow-runner. Деплой на archbook 7 мая EOD, 3 trading
days observation (8, 11, 12 мая — да, 11 мая считается, потому что MOEX
FORTS работает несмотря на федеральный выходной), gate decision 13
мая.
Параллельно бот продолжает работать в LIVE: 3 спреда на CRM6@RTSX,
риск 347R из 1000R бюджета, signal SellVol. С момента закрытия BUG-125 —
без рестартов, без warning’ов.
Бот двигается от «торгует» к «торгует и объясняет своё состояние».
Silent deadlock больше не сможет молчать. Outage больше не будет
невидимым. И каждый APPROVED план дальше будет проходить через empirical
gate’ы прежде чем коснуться trading-path.
Отправить ответ