Личный проект: центральный сервис BanHub держит список банов для тестового флота из 13 Windows RDP-серверов на DigitalRuby.IPBan, синхронизируя его между ними. Но он с самого начала знал только «забанен / не забанен» - никогда «на сколько». Лестница эскалации бана (BanTime=3 дня, 30 дней, навсегда) целиком живёт внутри каждого экземпляра IPBan и наружу не отдаётся. Это молчание аукнулось не абстрактно: за ним пряталась настоящая гонка в синхронизации, о которой пойдёт речь ниже.
Это стало настоящей проблемой не абстрактно, а на живых данных. IP, перенесённые при миграции массовым импортом (клиенты разом получали весь файл банов целиком, а не по одному новому адресу за раз), оказались молчаливо истолкованы как рецидивисты. Они тихо забрались на терминальную, фактически бессрочную ступень лестницы - незаметно для меня, пока не понадобилось проверить, что лестница вообще работает.
Предыдущие части серии про BanHub - мою систему централизованного бана IP для флота Windows-серверов:
Часть А: сделать длительность бана видимой
Подтвердил находку реальной выдержкой из лога:
2026-08-30 00:05:29.2277|INFO|IPBan|Ban duration 30.00:00:00 expired for ip 212.192.252.57
2026-08-30 00:05:29.2277|WARN|IPBan|Preparing ip address 212.192.252.57 for next ban time 9999.00:00:00
2026-08-30 00:23:30.8556|WARN|IPBan|Banning ip address: 68.154.116.65, ..., duration: 3.00:00:00Это подтвердило сразу две вещи. Во-первых, терминальная ступень лестницы (00:00:00:00) в собственном логе IPBan действительно репортится как 9999.00:00:00 («навсегда»). Во-вторых, стал понятен нужный формат строки лога для новой фичи мониторинга: вытащить duration: из строки Banning ip address: при каждом реальном бане и передать её на центральный сервер, чтобы показывать на дашборде длительность для каждого бана отдельно.
Одна важная деталь, которую стоило учесть заранее: имя файла лога меняется каждые сутки - новый файл создаётся в начале дня. Поэтому в реализации всегда используется «какой из файлов logfile* имеет самый свежий LastWriteTime«, а не фиксированное имя.
Фича вышла в релиз: скрипт синхронизации теперь при каждом реальном бане ищет в текущем логе строку Banning ip address: <IP>, ... и отправляет duration вместе с action=add; дашборд показывает длительность рядом с каждым баном, красным - если это терминальная ступень 9999....
Массовый разбан
С работающими данными о длительности стало видно масштаб: 3012 IP из миграции застряли забаненными навсегда. Одноразовый скрипт убрал их из файла банов и добавил 3012 событий remove с тегом source=migration-cleanup, сократив файл с 3074 до 62 настоящих записей.
Шторм, который спровоцировала гонка синхронизации - вживую, через несколько минут
«Кажется сейчас происходит следующее - бан и сразу разбан, проверь что пошло не так» - симптом, о котором сообщили почти сразу после массовой чистки. Масштаб при первом же взгляде на живые логи оказался куда серьёзнее единичного бага: это был активный, самоподдерживающийся шторм прямо в моменте - 5+ событий добавления/удаления в секунду одновременно на нескольких серверах. Фикс выкатил раньше, чем сел писать разбор происходящего - живое продакшн-влияние было приоритетнее объяснений.
Корневая причина - гонка в синхронизации дельт. Функция синхронизации дельт для клиента считала «добавленные» и «удалённые» IP за окно since независимо, без взаимной сверки между двумя списками. У одного из серверов маркер since оказался достаточно устаревшим, чтобы предшествовать сразу двум событиям: и исходному импорту при миграции, и сегодняшней чистке. На следующей синхронизации оба таймстампа независимо прошли фильтр «ts > since» - поэтому один и тот же IP попал сразу и в список added (старый импорт при миграции), и в список removed (сегодняшняя чистка). Клиент записал этот IP одновременно в ban.txt и unban.txt в одном и том же цикле.
IPBan забанил и тут же разбанил его; оба действия вызвали свои собственные хуки ProcessToRunOn*. Хуки протолкнули оба события обратно на центральный сервер - включая совершенно новое событие добавления. Оно разошлось на остальные 12 серверов на их следующей синхронизации, и каждый сервер повторял тот же цикл заново. Так гонка в синхронизации дельт превратилась в самоподдерживающуюся цепную реакцию по всему флоту, работающую на топливе самого же протокола синхронизации.
Фактический измеренный масштаб: 3 реальных IP (86.62.71.40, 86.57.222.22, 45.141.233.85), 172 лишних события примерно за 10 минут, пик - несколько в секунду, задело почти каждый сервер флота.
Фикс: переписал функцию синхронизации дельт так, чтобы каждый IP давал ровно одно, самое свежее событие по всей истории, и попадал ровно в один из двух списков - в тот, которому соответствует это самое свежее событие, никогда в оба сразу. Выкатил и подтвердил вживую: активность шторма упала до нуля за секунды.
Уборка после инцидента: отдельно исключил и migration-seed, и migration-cleanup из графика «банов в день» на дашборде - иначе разовый скачок на 3000 IP (и его же зачистка) навсегда искажали бы месяц истории графика.
Другой шторм, найденный позже: когда несколько серверов охотятся на одного атакующего
Отдельно, уже после того как история выше была закрыта, нашёлся структурно другой баг того же семейства - «флап»-петля, но по совсем иной причине.
До фикса функция добавления IP в центральный список тихо ничего не делала, если второй или третий сервер заявлял права на IP, уже забаненный первым сервером. В итоге только истечение локального бана у первого заявителя могло разбанить IP на весь флот - даже если остальные серверы прямо сейчас, в реальном времени, продолжали заново обнаруживать и банить того же атакующего в рамках всё ещё идущей атаки.
Каждый такой сервер тут же перебанивал IP заново, а система (по-прежнему отслеживающая только первый источник) снова считала его уже обработанным. Получилась ещё одна гонка, только другого рода: несколько источников соревновались за право снять один и тот же бан. Цикл повторялся на реальных IP (86.57.222.22, 45.141.233.85, 86.62.71.40 в конце августа, повторно несколько дней спустя, затем 94.26.88.225/94.26.88.226 ещё через день).
Фикс: набор заявителей на каждый IP (ip_claims.json, {ip: [источник, ...]}) - общий IP реально покидает список банов только после того, как все независимые заявители его отозвали. Реализовано через единую функцию withBanAndClaimsLock(), которая всегда берёт блокировку файла заявок, потом файла банов, в этом фиксированном порядке, будучи единственным местом в коде, которое вообще трогает обе блокировки - структурно исключает дедлок самим порядком вызова, а не дисциплиной программиста.
Протестировал вживую от начала до конца на одноразовых тестовых серверах и IP из тестового диапазона RFC 5737: цикл заявить/удержать/отпустить, отзыв заявки при удалённом самоуничтожении сервера через releaseSourceClaims(), принудительное снятие через дашборд администратора. Всё убрано после теста, без остаточных тестовых записей.
Итог
Два структурно разных бага проявлялись одинаково: «баны и разбаны скачут туда-сюда». Оба - результат работы самого протокола синхронизации, а не единичной опечатки: один - от независимого, несинхронизированного расчёта двух списков за один и тот же временной интервал, второй - от отсутствия модели «несколько источников имеют право удерживать один и тот же бан одновременно». Разово почищенные 3012 IP стали спусковым крючком для первого, а не его причиной - причина ждала своего часа с самого начала архитектуры синхронизации дельт.
Выводы
- Массовая одноразовая операция над данными - это нагрузочный тест для кода синхронизации, который иначе никогда не увидел бы такого сценария. 3012 событий разом за одну операцию - именно то, что обнажило гонку, невидимую при обычном органическом трафике по одному-два события за раз.
- «Добавлено» и «удалено» за один и тот же интервал времени нельзя считать независимо друг от друга, если один и тот же ключ (в данном случае IP) в принципе может оказаться в обоих множествах - нужна взаимная сверка или единый источник истины по последнему событию.
- Цепные реакции в распределённых системах питаются собственным протоколом синхронизации - обратная связь по хукам на изменение состояния, которая в норме полезна (мгновенно распространить новый бан), становится каналом усиления бага, как только на вход попадают уже испорченные данные.
- «Несколько независимых источников имеют право требовать одно и то же состояние» - отдельная модель данных, которую нельзя получить бесплатно от простого «забанен / не забанен». Набор заявителей и снятие только при полном согласии всех - относительно небольшая, но принципиально другая структура данных.
- Порядок захвата нескольких блокировок должен быть зафиксирован в одном месте кода, а не полагаться на дисциплину каждого места, которое их использует - тогда дедлок исключается конструктивно, а не проверкой на код-ревью.
Строите систему синхронизации состояния между независимыми узлами и подозреваете, что где-то в ней прячется гонка вроде этой - пишите, обсудим.