Окно сверки лога: кап по следующему тику (2026-09-18)

Связано: family/documents/vault-sync/2026-09-16-silent-tick-clusters.md

Суть

Метод сверки executions.db с /tmp/vault-sync.log по окну [claimed_at − 45 с; finished_at + 90 с] занижает число молчащих тиков, если тик был затянувшимся: его окно заходит в интервал следующего тика и захватывает его строку [syncthing] Pushed ✓.

Наблюдение: тик 2026-09-18T09:35:51 → finished_at 09:39:41 (230,8 с — LLM-раунд растянулся, вероятно деградация провайдера). Строк в логе за этот тик нет вообще. Окно без капа: [09:35:06; 09:41:11] — а строка следующего тика 09:40:55 попадает внутрь, поэтому тик считался «не молчащим».

Исправленный метод

Верхняя граница = min(finished_at + 90 с, claimed_at следующего тика).

for i,(cl,fin,st,err) in enumerate(sel):
    if st!='completed' or not fin: continue
    a,b=P(cl),P(fin)
    nxt=P(sel[i+1][0]) if i+1<len(sel) else None
    hi=b+timedelta(seconds=90)
    if nxt: hi=min(hi, nxt)
    if not any(a-timedelta(seconds=45)<=t<=hi for t in logts):
        silent.append((cl[:16],round((b-a).total_seconds(),1)))

Замер (окно лога 2026-09-15 11:35:19 → 2026-09-18 11:35:16, 853 строки)

тиков: 863, молчащих: 15 (1,7 %), failed: 1 (старый Fire claim lost, 2026-09-15 11:30)
без капа по следующему тику выходило 14 (1,6 %) — расхождение ровно на затянувшемся тике 09:35
длительности: медиана 10,1 с, p95 20,9 с, максимум 230,8 с (тот самый тик)

Состояние на момент проверки (2026-09-18 11:35 UTC)

Ручной прогон cd /opt/data && bash /opt/data/sync-vault.sh → exit 0, Pushed ✓ по всем трём фазам.

bare /vault.git = /vault = /obsidian-syncthing = 54d69ca885d42249b9d4a1af6bd697d30c9b51ad
git status --porcelain пуст в обоих клонах
ошибок в логе (No such file or directory, error, fatal) — 0

Вывод: молчащие тики — известный и безвредный режим (git-синк идемпотентен, следующий тик догоняет всё); методика сверки обновлена, вмешательство в конфиг не требуется.

Добавлено 17:15 UTC — деградация провайдера во второй половине дня (затянувшиеся LLM-раунды)

Плановый прогон 17:14:47 UTC → exit 0, Pushed ✓ по всем трём фазам, SHA выровнены: bare /vault.git = /vault = /obsidian-syncthing = 774f53135293ff5e81d9b44ce67f7fec49d7ab78, git status --porcelain пуст.

Но каденция сегодня просела. Статистика executions.db за 2026-09-18 (203 тика, медиана длительности 10,7 с):

тик (UTC)	длительность, с
00:00	85,4
09:35	230,8
11:35	63,9
14:35	161,8
14:40	144,9
15:00	161,0
15:20	146,0
15:55	512,9 → статус `unknown`
16:04	157,0
16:25	147,0
16:40	433,5
16:55	436,5
17:05	598,0 (подтверждено 17:20 — ровно на пороге таймаута 600 с)

Итого 12 тиков >60 с, из них 8 — после 14:35. Разрывы в /tmp/vault-sync.log: 15:55:48→16:06:52 (11,1 мин), 16:30:25→16:47:27 (17,0 мин), 16:55:29→17:14:47 (19,3 мин).

Механика: пока затянувшийся запуск держит claim, очередной 5-минутный тик не стартует вовсе — тик 17:00 в executions.db отсутствует (предыдущий, 16:55, завершился только в 17:02:42), поэтому это пропуск планировщика, а не молчащий LLM-тик из методики выше.

Отдельная аномалия: тик 15:55:45 → finished_at 16:04:18, status=unknown, error='Scheduler restarted after this execution's owner exited before a durable terminal state; whether side effects ran is unknown.' — перезапуск планировщика Hermes около 16:04; в логе за этот интервал строки есть (16:06:52, следующий тик), потери данных нет.

Состояние данных: потерь нет, git-синк идемпотентен, все три клона на одном коммите. Вмешательство в конфиг не требуется (см. правило 2026-09-14: править конфиг только при повторяющихся эпизодах). Если серия затянутых тиков (150–500 с) продолжится >суток — рассмотреть hermes cron edit 29851c413903 --no-agent --script или пин модели/провайдера.

Добавлено 17:38 UTC — эпизод затухает

Прогон 17:35:30 → 17:37:52 UTC (≈142 с): exit 0, Pushed ✓ по всем трём фазам, bare = /vault = /obsidian-syncthing = 5ac3228d2b42e3fdb5fb0644fd7b13ed23c6b653, оба клона clean.

Длительности после пика 598 с: 17:20 → 107 с, 17:25 → 148 с, 17:30 → 11 с, 17:35 → 142 с. Порога 600 с больше не достигается, пропущенных слотов после 17:15 нет. Итог дня: 207 тиков, 4 затянутых (>300 с), 4 пропущенных слота — все в окне 15:55–17:15.

Вмешательство не требуется; серия закрылась сама, как и предсказывает правило 2026-09-14.

Добавлено 19:20 UTC — вторая волна деградации (17:55–19:20): серия НЕ закрылась

Поправка к записи 17:38. Прогон 19:05:26 UTC из тика: exit 0, Pushed ✓ по всем трём фазам, bare /vault.git = /vault = /obsidian-syncthing = bfa54d62f5d130df19da0bcffc14514cbedf4d6f, оба клона clean, совпадений fatal|error|No such file в логе — 0.

Но каденция снова просела. executions.db за 17:30–19:20:

тик (claimed_at, UTC)	длительность, с	статус	строка в логе
17:30:29	11,1	completed	17:30:35 ✓
17:35:30	236,1	completed	17:37:52 ✓
17:40:31	431,7	completed	17:47:34 ✓
17:45	—	слота нет (claim держал тик 17:40)	—
17:50:32	11,5	completed	17:50:36 ✓
17:55:33	1254,8	failed — `RuntimeError: Request timed out.`	нет
18:00 / 18:05 / 18:10 / 18:15	—	4 слота пропущены (claim держал тик 17:55 до 18:16:28)	—
18:20:35	444,9	completed	18:20:44 ✓
18:25	—	слот пропущен	—
18:30:36	148,3	completed	18:33:00 ✓
18:35:36	174,4	completed	18:37:58 ✓
18:40:38	9,1	completed	18:40:41 ✓
18:45:39	428,0	completed	18:52:45 ✓
18:50	—	слот пропущен	—
18:55:40	5,8	completed	нет → молчащий тик (агент ответил текстом, скрипт не вызван)
19:00:40	>1190 (ещё `running` на 19:20)	running	нет

С 17:00 в базе всего 15 тиков вместо ~28: 13 пропущенных 5-минутных слотов, 1 failed по таймауту (1254,8 с), 1 молчащий тик (18:55), 1 зависший (19:00). Разрывы в /tmp/vault-sync.log: 18:02:38→18:20:44 (18,1 мин), 18:52:45→19:05:26 (12,7 мин), 18:20:44→18:33:00 (12,3 мин).

Итог дня на 19:20 UTC: 216 запусков — 214 completed, 1 failed, 1 unknown (тик 15:55, перезапуск планировщика), 1 running; максимум длительности 1254,8 с.

Механика та же, что в разделе 17:15: затянувшийся LLM-раунд держит claim, очередной 5-минутный тик не стартует вовсе (пропуск планировщика), а не «молчащий LLM-тик» из окной методики. Эпизод длится более 4,5 ч (с 14:35), с затуханием 17:25–17:50 и усилением с 17:55.

Данные не пострадали: git-синк идемпотентен, все три клона на одном коммите, git status --porcelain пуст.

Рекомендация владельцу (конфиг не меняла — решение за Алексеем): эпизод сегодня повторяющийся, а не единичный, то есть по правилу 2026-09-14 это уже повод править конфиг. Варианты: hermes cron edit 29851c413903 --no-agent --script <persist-path> (убирает LLM из петли; ловушка с ~/.hermes/scripts/ и рекреацией /root — в SKILL vault-sync-infrastructure) либо пин модели/провайдера.

9.6 KiB Raw Blame History Unescape Escape