# Окно сверки лога: кап по следующему тику (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 следующего тика)`.

```python
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`)

## Добавлено 19:33 UTC — третья точка: прогон из тика 19:30:43

Плановый прогон `cd /opt/data && bash /opt/data/sync-vault.sh >> /tmp/vault-sync.log 2>&1` из тика `19:30:43`:

- exit 0, `[syncthing] Pushed ✓` / `[taiga-vault] Pushed ✓` / `[syncthing-out] Pushed ✓` — все три фазы, строки лога `19:33:10`
- bare `/vault.git` = `/vault` = `/obsidian-syncthing` = `31655d29a7212c6530992c21edff502f7281a68e`
- `git status --porcelain` пуст в обоих клонах
- `grep -c "No such file or directory"` = 0, всего `Pushed ✓` в логе = 2790

Предыдущий тик (19:25:43) отработал штатно за 11,1 с, но перед ним 4 слота (19:05/19:10/19:15/19:20) пропущены — claim держал затянувшийся тик 19:00:40 → 19:20:55 (1215 с), разрыв в логе 19:05:27 → 19:25:47 (20,3 мин).

Статистика за 2026-09-18 (219 тиков из ~235 возможных): медиана 11 с, p95 231 с, максимум 1255 с; 214 `completed`, 1 `failed` (`RuntimeError: Request timed out.`, тик 17:55:33), 1 `unknown` (тик 15:55:45, перезапуск планировщика), 1 `running` (этот прогон). Затянутых тиков >120 с — 15 из 29 запусков после 15:50.

Данные не пострадали (git-синк идемпотентен, все три клона на одном коммите). Вмешательство в конфиг по-прежнему требует решения владельца — рекомендация из раздела 19:20 в силе (либо пин модели/провайдера).

## Добавлено 21:23 UTC — четвёртая точка: эпизод продолжается весь вечер, но разрывы сузились

Плановый прогон `cd /opt/data && bash /opt/data/sync-vault.sh >> /tmp/vault-sync.log 2>&1` из тика `21:20:56`:

- exit 0, строки лога `21:23:20` — `[syncthing] Pushed ✓`, `[taiga-vault] Pushed ✓`, `[syncthing-out] Pushed ✓`
- bare `/vault.git` = `/vault` = `/obsidian-syncthing` = `7b95ba62b9d9d5a0ecb28b3238e5b3c5c4c52490`
- `git status --porcelain` пуст в обоих клонах, ошибок в логе (`No such file or directory`) — 0

Каденция 19:20 → 21:23 (данные `executions.db`):

| тик (UTC) | длительность, с |
|---|---|
| 19:00:40 | 1215,2 (закрылся 19:20:55) |
| 19:30:43 | 697,5 |
| 19:50:45 | 423,6 |
| 20:00:46 | 148,1 |
| 20:25:50 | 150,7 |
| 20:50:53 | 148,8 |
| 20:55:53 | 163,9 |
| 21:00:54 | 148,0 |
| 21:05:55 | 285,3 |

Порога 600 с больше не достигается, но запуски 4–5 мин всё ещё случаются примерно дважды в час, поэтому отдельные 5-минутные слоты продолжают пропускаться: разрывы в логе теперь одинаковые, 7,3–7,4 мин (`21:03:17→21:10:36`, `21:16:04→21:23:20`) — то есть один пропущенный слот, а не дыры 12–20 мин периода 18:00–19:40.

**Итог дня 2026-09-18 (237 запусков):** медиана 11,1 с, p95 285,3 с, максимум 1254,8 с; 234 `completed`, 1 `failed` (`RuntimeError: Request timed out.`, тик 17:55:33), 1 `unknown` (тик 15:55:45, перезапуск планировщика), 1 `running` (текущий). Тиков >120 с — 28, из них >300 с — 11. Молчащих тиков (оконная методика, окно лога с 2026-09-15 11:35:19): 20 из 960.

Эпизод деградации провайдера длится с 14:35 UTC более 7 ч, с двумя пиками (15:55–17:15 и 17:55–19:40) и затуханием к вечеру. Данные не пострадали: git-синк идемпотентен, все три клона на одном коммите. По правилу 2026-09-14 (правка конфига при повторяющихся эпизодах) повод есть, но решение за Алексеем — варианты в разделе 19:20.