From Silent Deadlock to Observable Degradation: как бот пережил 7 часов проблем Finam API

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.

Оставьте первый комментарий

Отправить ответ

Ваш e-mail не будет опубликован.


*