Files
obsidian-vault/family/documents/vault-sync/2026-09-18-evening-cadence-degradation.md
T

10 KiB
Raw Blame History

Деградация каденции 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 суммарно агент-секунд
2214 12/час 0 100400
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:45unknown, «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:33failed, RuntimeError: Request timed out. (1254,8 с = 20,9 мин).
  • 2026-09-18T21:55:59running (этот самый тик; скрипт вызван в 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 мин), чередование нормы и раундов 1501250 с, 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 в контейнере не переживает рекреацию) или пин модели/провайдера для этой задачи.