179 lines
10 KiB
Markdown
179 lines
10 KiB
Markdown
# Деградация каденции sync-vault вечером 2026-09-18
|
||
|
||
Связано: `family/documents/vault-sync/2026-09-18-window-cap-silent-tick-undercount.md`,
|
||
`family/documents/vault-sync/2026-09-14-cron-api-timeout-sync-outage.md`
|
||
|
||
## Что замечено
|
||
|
||
Начиная с ~15:00 UTC 2026-09-18 длительность LLM-раунда задачи `sync-vault`
|
||
(job_id `29851c413903`, prompt-задача `bash /opt/data/sync-vault.sh`) выросла с
|
||
обычных 6–11 с до 150–1250 с. Сам скрипт при этом отрабатывает нормально — растёт
|
||
именно ожидание ответа провайдера до вызова инструмента.
|
||
|
||
Замер по `executions.db`, окно 2026-09-17 22:00 → 2026-09-18 22:00 UTC:
|
||
|
||
| час UTC | тиков | non-completed | суммарно агент-секунд |
|
||
|---|---|---|---|
|
||
| 22–14 | 12/час | 0 | 100–400 |
|
||
| 15:00 | 12 | 1 (`unknown`) | 968 |
|
||
| 16:00 | 10 | 0 | 1227 |
|
||
| 17:00 | 8 | 1 (`failed`) | 2799 |
|
||
| 18:00 | 6 | 0 | 1210 |
|
||
| 19:00 | 5 | 0 | 2359 |
|
||
| 20:00 | 12 | 0 | 686 |
|
||
| 21:00 | 9 | 1 (`running`) | 1247 |
|
||
|
||
Длительности за сутки: n=265, медиана 10,9 с, p90 148 с, максимум 1254,8 с.
|
||
Раундов >120 с — 30, все приходятся на 09:35 UTC и позже.
|
||
|
||
Пропущенные тики (17:00 — 8, 18:00 — 6, 19:00 — 5 вместо 12) — это не пропуск
|
||
диспетчера: claim предыдущего запуска держится, пока висит LLM-раунд, поэтому
|
||
слоты 5-минутной сетки выпадают (механика описана в заметке 2026-09-14).
|
||
|
||
## Ошибки за сутки
|
||
|
||
- `2026-09-18T15:55:45` — `unknown`, «Scheduler restarted after this execution's owner
|
||
exited before a durable terminal state» (раунд 512,9 с). Лог `/tmp/vault-sync.log`
|
||
при этом **не** обнулялся (первая строка по-прежнему 2026-09-15 11:35:19) —
|
||
перезапуска контейнера не было, перезапустился владелец исполнения.
|
||
- `2026-09-18T17:55:33` — `failed`, `RuntimeError: Request timed out.` (1254,8 с = 20,9 мин).
|
||
- `2026-09-18T21:55:59` — `running` (этот самый тик; скрипт вызван в 22:00:43,
|
||
то есть собственный раунд тоже занял ~4,7 мин).
|
||
|
||
## Состояние данных (проверено 2026-09-18 22:01 UTC)
|
||
|
||
Ручной прогон `cd /opt/data && bash /opt/data/sync-vault.sh` → exit 0,
|
||
`Pushed ✓` по всем трём фазам (syncthing / taiga-vault / syncthing-out).
|
||
|
||
- bare `/vault.git` = `/vault` = `/obsidian-syncthing` = `49776108afb3a683149ebcabf1f61ab951926bfc`
|
||
- `git status --porcelain` пуст в обоих клонах
|
||
- молчащих тиков в окне лога 09-15 11:35:19 → 09-18 22:00:43: 20 из 965 (2,1 %)
|
||
(метод с капом окна по следующему тику)
|
||
- максимальный разрыв в логе за вечер — 17,3 мин (21:43:24 → 22:00:43), порог 30 мин не превышен
|
||
|
||
**Потерь данных нет:** git-синк идемпотентен, все три репозитория на одном коммите,
|
||
рабочие каталоги чистые. Вечерняя деградация — потеря каденции (~50 % запусков
|
||
в 17:00–19:00), а не потеря содержимого.
|
||
|
||
## Обновление 2026-09-18 22:12 UTC
|
||
|
||
Продолжение эпизода, прерывистое (чередование нормы и длинных раундов):
|
||
|
||
| тик UTC | длительность раунда |
|
||
|---|---|
|
||
| 21:40:58 | 591 с |
|
||
| 21:56:00 | 326 с |
|
||
| 22:05:00 | 7 с (норма) |
|
||
| 22:10:01 | >140 с (активный на момент записи) |
|
||
|
||
Пропущены слоты 21:45 / 21:50 / 21:55 и 22:00 — claim долгих раундов держал
|
||
5-минутную сетку. Скрипт на 22:10-тике вызван в 22:12:23: все три фазы
|
||
`Pushed ✓`, изменений нет.
|
||
|
||
Состояние данных (2026-09-18 22:12 UTC): `/vault.git` = `/vault` =
|
||
`/obsidian-syncthing` = `5e2ffd5`, `git status --porcelain` пуст в обоих клонах.
|
||
|
||
## Обновление 2026-09-18 22:17 UTC (плановый прогон cron)
|
||
|
||
Эпизод не закончился, но и не ухудшился: сохраняется чередование нормы и длинных
|
||
раундов (окно ~150–180 с).
|
||
|
||
| тик UTC | длительность раунда |
|
||
|---|---|
|
||
| 22:05:00 | 6,4 с (норма) |
|
||
| 22:10:01 | 183,1 с |
|
||
| 22:15:01 | ~140 с (скрипт вызван в 22:17:21) |
|
||
|
||
Ручной плановый прогон `bash /opt/data/sync-vault.sh` (тик 22:15) → exit 0,
|
||
`Pushed ✓` по всем трём фазам, изменений нет («Already up to date.»).
|
||
|
||
Состояние данных (2026-09-18 22:17 UTC): `/vault.git` = `/vault` =
|
||
`/obsidian-syncthing` = `4281e91`, `git status --porcelain` пуст в обоих клонах.
|
||
|
||
Сводка по окну лога 09-15 11:35:19 → 09-18 22:17:21: 968 тиков, 23
|
||
молчащих/неуспешных (2,4 %); за вечер максимум разрыва лога — 17,3 мин
|
||
(21:43:24 → 22:00:43), порог 30 мин не превышен. Потерь данных нет.
|
||
|
||
## Обновление 2026-09-18 22:30 UTC (плановый прогон cron)
|
||
|
||
Деградация сохраняется, характер тот же (чередование коротких и длинных раундов,
|
||
без ухудшения длительностей):
|
||
|
||
| тик UTC | длительность раунда |
|
||
|---|---|
|
||
| 22:20:02 | 292,8 с |
|
||
| 22:25:02 | 148,8 с |
|
||
| 22:30:03 | этот тик (скрипт вызван в 22:30:0x, exit 0) |
|
||
|
||
Скрипт: exit 0, `Pushed ✓` по всем трём фазам, изменений в данных нет
|
||
(«Already up to date.»).
|
||
|
||
Состояние данных (2026-09-18 22:30 UTC): `/vault.git` = `/vault` =
|
||
`/obsidian-syncthing` = `1dec7bd`, `git status --porcelain` пуст в обоих клонах.
|
||
|
||
Сводка по окну лога 09-15 11:35:19 → 09-18 22:30:06: 971 тик, 20 молчащих
|
||
(2,06 %) + 3 non-completed; максимальный разрыв лога за вечер по-прежнему
|
||
17,3 мин (21:43:24 → 22:00:43), порог 30 мин не превышен. Потерь данных нет.
|
||
|
||
## Обновление 2026-09-18 22:43 UTC (плановый прогон cron)
|
||
|
||
Тик 22:40:04, скрипт вызван в 22:42:25 (собственный раунд ~140 с — снова длинный).
|
||
Между 22:35:08 и 22:42:25 разрыв лога 7,3 мин — это задержка длинного раунда, а не
|
||
пропуск тика (строка `[syncthing] Pushed ✓` для тика 22:35 в логе есть).
|
||
|
||
Скрипт: exit 0, `Pushed ✓` по всем трём фазам, изменений в данных нет
|
||
(«Already up to date.»); этот прогон дополнительно запушил настоящую заметку
|
||
(коммит `[main 438eaad] ... 2026-09-18-evening-cadence-degradation.md`).
|
||
|
||
Состояние данных (2026-09-18 22:43 UTC): `/vault.git` = `/vault` =
|
||
`/obsidian-syncthing` = `438eaad`, `git status --porcelain` пуст в обоих клонах.
|
||
|
||
Сводка по окну лога 09-15 11:35:19 → 09-18 22:42:25: **973 тика, 20 молчащих
|
||
(2,06 %) + 3 non-completed** — новых молчащих тиков с 18:55 UTC нет.
|
||
|
||
Уточнение к предыдущему разделу: 17,3 мин — это максимум для позднего вечера;
|
||
за весь день 09-18 максимальный разрыв лога **19,3 мин** (16:55:29 → 17:14:47),
|
||
далее 18,1 мин (18:02:38 → 18:20:44). Порог 30 мин не превышен, потерь данных нет.
|
||
|
||
## Обновление 2026-09-18 23:47 UTC (плановый прогон cron) — деградация, похоже, закончилась
|
||
|
||
Длительности раундов с 23:20 UTC вернулись к норме, пять тиков подряд без длинных
|
||
раундов (последний длинный — 23:15:08, 141 с):
|
||
|
||
| тик UTC | длительность раунда |
|
||
|---|---|
|
||
| 22:40:04 | 662,0 с |
|
||
| 22:55:06 | 157,2 с |
|
||
| 23:00:06 | 7,1 с (норма) |
|
||
| 23:05:07 | 14,9 с |
|
||
| 23:10:07 | 153,0 с |
|
||
| 23:15:08 | 141,0 с |
|
||
| 23:20:08 | 16,4 с |
|
||
| 23:25:09 | 8,4 с |
|
||
| 23:30:09 | 10,3 с |
|
||
| 23:35:10 | 6,5 с |
|
||
| 23:40:10 | 10,3 с |
|
||
|
||
Эпизод суммарно: ~14:35 → 23:17 UTC (≈8 ч 40 мин), чередование нормы и раундов
|
||
150–1250 с, 2 non-completed (15:55 `unknown`, 17:55 `failed RuntimeError: Request
|
||
timed out.`), потеря каденции примерно вдвое в пиковые часы.
|
||
|
||
Ручной прогон `bash /opt/data/sync-vault.sh` (тик 23:45) → exit 0, `Pushed ✓`
|
||
по всем трём фазам, изменений в данных нет («Already up to date.»).
|
||
|
||
Состояние данных (2026-09-18 23:47 UTC): `/vault.git` = `/vault` =
|
||
`/obsidian-syncthing` = `1e6ab836`, `git status --porcelain` пуст в обоих клонах.
|
||
|
||
Сводка по окну лога 09-15 11:35:19 → 09-18 23:47:32: 985 тиков, 20 молчащих
|
||
(2,03 %) + 2 non-completed; новых молчащих тиков с 18:55 UTC нет.
|
||
Максимальный разрыв лога за сутки 09-18 по-прежнему 19,3 мин (16:55:29 → 17:14:47),
|
||
порог 30 мин не превышен, потерь данных нет.
|
||
|
||
## Что делать
|
||
|
||
Вмешательство в конфиг пока не требуется (единичный эпизод деградации провайдера,
|
||
восстанавливается сам). Если эпизоды повторятся — вариант, требующий решения владельца:
|
||
убрать LLM из петли (`hermes cron edit 29851c413903 --no-agent --script <path>`,
|
||
путь должен быть персистентным — `/root/.hermes` в контейнере не переживает рекреацию)
|
||
или пин модели/провайдера для этой задачи.
|