Files
cloud-ip-validator/analysis/2026-10-02_08-56_1026-addresses_mass-check-analysis.md
T
ayurishchevandClaude Sonnet 5.5 0532baff09 Keep one address per validator; fix heartbeat handling and queue clear
A mass check on 2026-10-02 stalled 7 of 20 validators and sent 42
addresses to fail without a single check. A validator busy with slow
checks went silent, was marked unreachable, and its next heartbeat put it
back to idle while it still held the address; it was handed a second one,
whose association never ran (the in-flight guard was keyed by validator),
and both waited for their leases to expire.

- Heartbeat/re-register return an unreachable validator to assigned when
  it still holds an address, else idle.
- A validator is released only from the address it currently holds
  (ReleaseFIP, RequeueOrFail, MarkFIPOccupied, FreeValidator); an
  unreachable validator stays unreachable until its next heartbeat, so a
  dead validator is no longer handed a new address every lease period.
- ClaimNextQueued refuses a validator that still has an address; a
  ReconcileValidators pass on every tick repairs rows that disagree with
  the queue.
- Association guard is keyed by address, not validator.
- The agent sends heartbeats from their own goroutine.
- Clear queue / delete: detach only floating IPs of unfinished rows (done,
  failed and occupied rows kept their fip_id and made a clear issue >1000
  sequential cloud calls: 256 s), at most 8 in parallel; the operation no
  longer dies with the client connection (10 minute limit).

Includes the incident analysis and the plan under analysis/ and
docs/changes/, and rebuilt bin/control-api and bin/validator-agent.

Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
2026-10-02 14:42:12 +03:00

168 lines
15 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# Аналитический разбор массовой проверки: 1026 адресов
> Время отчёта: 2026-10-02 08:56 UTC · Данные: снимок БД control-api на 08:46:53 UTC и лог control-api за 4 часа до остановки
> Проверено адресов: **1026** (984 завершены `done` + 42 завершены `failed`) из 6440 в очереди
> Окно прогона: 07:14:58 – 08:46:53 UTC (1 ч 32 мин). Остановлен вручную в 08:53:46 UTC.
## 1. Остановка проверок
- Проверки остановлены в 08:53:46 UTC операцией «Очистить всё» (`POST /api/v1/admin/ips/clear`).
- После остановки: очередь пуста, все 20 валидаторов `idle`, последняя выдача адреса в 08:53:43, новых выдач нет.
Реестр с историей адресов сохранён (6445 записей).
- Отвязка Floating IP с портов валидаторов при очистке: 13 зависших привязок снято прямым опросом портов
(`detached floating ip from validator port`), ещё 8 привязок, завершавшихся во время очистки, система сняла сама
(`address removed during association`). Состояние портов в самом OpenStack на момент отчёта не проверялось.
- **Первая попытка очистки не сработала.** Очистка шла дольше таймаута клиента (120 с) и оборвалась: 600 отвязок завершились
с ошибкой `context canceled`, ничего не удалилось, проверки продолжались. Повторная очистка без таймаута выполнялась 256 с.
- **Причина долгой очистки (дефект кода, не исправлен):** у завершённых адресов (`done`) в БД остаётся `fip_id`, и очистка
последовательно отвязывает все такие FIP, хотя они уже свободны (более 1000 вызовов OpenStack по ~0,2 с).
## 2. Итоги прогона
| Показатель | Значение |
|---|---|
| Адресов в очереди | 6440 |
| Завершено | 1026 (984 `done` + 42 `failed`) |
| `pass` | 227 (23% от завершённых) |
| `partial` | 757 (77%) |
| `fail` | 42 (все `failed`, вердикта по существу нет, см. раздел 4) |
| Остались в очереди / в работе на момент снимка | 5392 в очереди, 22 в работе |
Пропускная способность по 10-минутным окнам (завершено адресов за минуту): 07:10 — 5,8; 07:20 — 13,4; 07:30 — 11,6;
07:40 — 10,1; 07:50 — 10,6; 08:00 — 9,4; 08:10 — 9,7; 08:20 — 10,5; 08:30 — 10,6; 08:40 — 6,7 (окно неполное).
Цикл одного адреса (от выдачи валидатору до итога): минимум 65 с, медиана 85 с, p90 100 с, p99 115 с, максимум 125 с,
среднее 84 с (по 984 адресам `done`). Для 20 валидаторов это теоретически ~14 адресов в минуту; фактически ~10,4,
потеря около 27% из-за залипших валидаторов (раздел 4).
## 3. Фактура по накопившимся ошибкам
### 3.1. Классы ошибок (с 07:10)
В логе control-api за 4 часа на уровне `ERROR` только один вид сообщений: 41 ошибка привязки Floating IP.
| Ошибка / событие | Число | Что это |
|---|---|---|
| `lease expired` (возврат адреса по истечении лизинга) | 198 | Валидатор не подхватил задание за время лизинга. Затронуто минимум 77 адресов (часть событий без привязки к адресу) |
| Привязка FIP: `409 Cannot associate floating IP … fixed IP already has a floating IP` | 41 | На порту валидатора уже висит другой FIP. Порты: v1 — 13, v7 — 6, v13 — 6, v3 — 5, v12 — 5, v16 — 4, v17 — 2 |
| `validator_unreachable` | 7 | По одному разу: v1 и v12 (07:18:03), v13 (07:33:53), v3 (07:34:33), v7 (07:40:03), v16 (07:42:33), v17 (08:17:53) |
| `site_unreachable` | 5 | rxmsk (08:09, 08:45) и misha-v (08:09, 08:20, 08:45) |
| «Очистить всё»: `context canceled` | 600 | Последствие обрыва первой очистки (08:49), см. раздел 1 |
Чего не было: **провалов self-check — 0 из 1015** результатов; все 1015 прошли способом `control_api` (запасной `ip_echo`
не понадобился). Событий `fip_occupied` — 0, адресов `occupied` — 0.
Журнал событий за прогон: `self_check_result` 2030 (по две записи на адрес), `fip_associated` 1120, `config_received` 1015,
`aggregated` 1004, `retry_or_fail` 239 (198 лизинг + 41 привязка), `lease_expired` 198, `validator_unreachable` 7,
`site_unreachable` 5.
### 3.2. По валидаторам
| Валидатор | Завершено (`done`) | `failed` | Сбросов лизинга | `unreachable` |
|---|---|---|---|---|
| vkiplab-v1 | 2 | 17 | 49 | 1 |
| vkiplab-v12 | 2 | 13 | 51 | 1 |
| vkiplab-v13 | 13 | 10 | 41 | 1 |
| vkiplab-v16 | 38 | 2 | 19 | 1 |
| vkiplab-v7 | 36 | 0 | 21 | 1 |
| vkiplab-v17 | 50 | 0 | 10 | 1 |
| vkiplab-v3 | 50 | 0 | 7 | 1 |
| остальные 13 (v2, v4–v6, v8–v11, v14, v15, v18–v20) | 60–63 | 0 | 0 | 0 |
(Сбросы лизинга и `unreachable` в таблице — только за прогон, с 07:10. У v14, v18 и v2 в истории БД есть сбросы лизинга
за 1 октября, к этому прогону они не относятся.)
- **v1 и v12** не подхватили ни одного задания после 07:17 (последний подхват 07:17:29 и 07:17:26).
- **v13** — после 07:33:16.
- **v7, v16, v17, v3** залипали временно и затем восстановились; механизм восстановления не выяснен.
### 3.3. 42 адреса `fail`
- По валидаторам: v1 — 17, v12 — 13, v13 — 10, v16 — 2. Все 42 исчерпали повторы: `retry_count` = 4 и `attempt_number` = 4 у каждого.
- Причины неудачных попыток по этим адресам: 143 сброса лизинга и 25 ошибок привязки `409`.
- **Ни одной проверки по ним не выполнено** (в таблице проверок у этих адресов 0 записей): адреса не получили вердикта,
и `fail` здесь не характеризует сами адреса.
- Появлялись равномерно с 07:31 до 08:46 (4–10 за 10 минут).
- Подсети: 37.139.x, 79.137.x, 83.166.x и другие, без концентрации.
## 4. Причины
Подтверждены по БД и логам control-api. Логи агентов на самих валидаторах не изучались.
**Причина 1. Валидатор получает два адреса сразу и застревает.** Два дефекта вместе:
- Heartbeat (`queries_validators.go`) возвращает валидатор из `unreachable` в `idle`, не проверяя, что за ним числится адрес.
Адрес с долгими внешними проверками (3–4 таймаута по 10 с) блокирует агента больше 30 с (порог
`heartbeat_timeout_seconds`), control-api помечает валидатор недоступным, затем возвращает в `idle` занятым.
- При завершении старого адреса `ReleaseFIP` (`queries_ipqueue.go`) освобождает валидатор по его имени, а не по адресу.
- Подтверждение: **35 двойных выдач** (два адреса одному валидатору с интервалом ~5 с) в логе: v1 — 10, v12 — 9, v7 — 6,
v13 — 4, v17 — 3, v16 — 2, v3 — 1. Из 1265 выдач в логе.
**Причина 2. Регрессия моей правки с параллельной привязкой.** Защита от дублей в `orchestrator.go:149` ключуется по
валидатору (`assign:<validator>`). Вторая выдача того же валидатора пропускает привязку, и адрес стоит в `assigning_fip`
до истечения лизинга. В БД у валидатора одно поле `current_ip_id`, оно указывает на последний выданный адрес, агент по нему
получает пустое задание, лизинг истекает, валидатор берёт новый адрес, и круг повторяется. Ошибки `409` — следствие: на
порту остаётся FIP первого адреса, привязать второй нельзя.
**Причина 3. Агент молчит во время долгих проверок.** Heartbeat отправляется только между заданиями; адреса с несколькими
таймаутами ведут к `unreachable` (пусковой механизм причины 1). Пример: v1 проверял `37.139.32.1`, v12 — `37.139.32.4`;
у обоих проваливались все четыре внешних HTTPS-цели (~40 с таймаутов), в 07:18:03 оба помечены `unreachable`.
**Дефект очистки.** См. раздел 1: отвязка всех `done`-адресов последовательно.
## 5. Результаты проверок самих адресов
**Почему 77% `partial`:** 735 адресов проваливают только исходящие HTTPS, ещё 22 — исходящие и входящие.
| Цель (egress HTTPS) | Адресов с провалом (из 984) |
|---|---|
| `packages.ubuntu.com` | 698 (71%) |
| `repo.almalinux.org/almalinux/` | 304 (31%) |
| `github.com` | 251 (26%) |
| `hub.docker.com` | 17 (2%) |
Число провалов на один `partial`-адрес: 1 — 392 адреса, 2 — 202, 3 — 136, 4 и больше — 27.
По подсетям (доля адресов с провалом цели):
| Подсеть | Адресов | `packages.ubuntu.com` | `repo.almalinux.org` | `github.com` | `hub.docker.com` | Доля `partial` |
|---|---|---|---|---|---|---|
| 83.166.x | 435 | 80% | 53% | 42% | 0% | 92% |
| 37.139.x | 418 | 62% | 11% | 10% | 4% | 63% |
| 79.137.x | 109 | 66% | 19% | 18% | 0% | 68% |
| 5.188.x | 22 | 59% | 0% | 0% | 0% | 59% |
- `packages.ubuntu.com` проваливается у всех подсетей и во все окна. Доля проваленных строк egress для этой цели по 10-минутным
окнам выросла с 26% до 40% (строки включают HTTPS и ICMP, поэтому реальная доля HTTPS вдвое выше).
- Доля `partial` почти одинакова у всех валидаторов (72–84%; v1 — 100% по 2 адресам, v12 — 50% по 2): причина в самом адресе
или во внешнем ресурсе, а не в валидаторе.
- Провалы `repo.almalinux.org` и `github.com` сильно зависят от подсети (83.166.x — 53% и 42%, 37.139.x — 11% и 10%).
- Успешные HTTPS-проверки: медиана 200 мс, p90 6707 мс (много ответов близко к таймауту 10 с).
**Входящие проверки.** Провалы только у `inbound-site-1` (33 пробы из 2934) и `inbound-site-3` (50 из 2931); `inbound-site-2` — 0 из 2952,
`inbound-site-4` — 1 из 2952. Провалы всплесками в 08:00, 08:20 и 08:40 по ICMP, SSH и TCP 22; у 20 адресов упали все пробы
одной площадки. Пробер rxmsk и misha-v в эти же минуты отмечены `unreachable`. Причина недоступности проберов не выяснена.
## 6. Рекомендации
1. **Исправить оркестратор** (до повторного запуска): защита от дублей по адресу, `unreachable` → `assigned` вместо `idle`,
освобождение валидатора только по текущему адресу, heartbeat агента в отдельном потоке.
2. **Исправить очистку:** отвязывать только действительно привязанные FIP (без `fip_released_at`) и параллельно.
3. **Перепроверить 42 адреса** после исправления: вердикта по существу они не получили. Все `fail` с причиной «lease expired» считать недействительными.
4. **Решить по `packages.ubuntu.com`:** 71% `partial` и 10 с таймаута на каждый такой адрес; если ресурс нестабилен, убрать или заменить.
5. **Проверить причины `site_unreachable`** у проберов (возможна перегрузка при большой очереди).
6. Проверить в OpenStack, что порты валидаторов свободны от Floating IP.
## 7. Что не проверено
- Состояние портов и Floating IP в самом OpenStack.
- Логи агентов `validator-agent` на валидаторах и логи проберов (причины блокировок heartbeat подтверждены по времени и
событиям control-api, не по логам агентов).
- Почему залипшие v7, v16, v17, v3 восстановились.
- Причины провалов внешних HTTPS-целей (ресурс, сеть облака или фильтрация) и недоступности проберов.
## 8. Источники данных
- Снимок БД control-api: `.backup` на 08:46:53 UTC (таблицы `ip_queue`, `checks`, `events`, `validators`, `sites`).
- Лог контейнера control-api за 4 часа до остановки (1504 строки) и за период очистки.
- Статус и результат очистки: HTTP 200 за 256,7 с.