[2026-09-14 23:46:07] taiga-vault: family/documents/vault-sync/2026-09-14-cron-api-timeout-sync-outage.md

family/documents/vault-sync/2026-09-14-cron-api-timeout-sync-outage.md

@@ -2,7 +2,7 @@
 tags: [vault-sync, incident, cron, deepseek, api-timeout, taiga]
 created: 2026-09-14
 updated: 2026-09-14
-status: resolved 2026-09-14 21:40 UTC — sync прогнан вручную, все три фазы Pushed ✓, данные целы; причина (LLM timeout в cron-задаче) не устранена на уровне конфига
+status: resolved 2026-09-14 21:40 UTC — sync прогнан вручную, все три фазы Pushed ✓, данные целы; причина (LLM timeout в cron-задаче) не устранена на уровне конфига. 23:45 UTC — найден второй режим отказа: ~6,6 % тиков `completed` без запуска скрипта (см. раздел ниже)
 ---
 
 # Incident 2026-09-14: 3-часовой разрыв в vault-sync — cron-задача блокировалась API-таймаутами deepseek
@@ -18,7 +18,7 @@ status: resolved 2026-09-14 21:40 UTC — sync прогнан вручную, в
 [2026-09-14 21:30:52] [syncthing]     Pushed ✓
 ```
 
-GAP 18:30:16 → 21:30:52 = **180.6 мин**. Остальные разрывы за сутки — штатные 9–10 мин (пропущенные тики диспетчера).
+GAP 18:30:16 → 21:30:52 = **180.6 мин**. Остальные разрывы за сутки — 9–10 мин. **Важно:** это не «пропуск тика диспетчером» — см. второй режим отказа ниже, тик запускается и даже помечается `completed`, но скрипт в нём не исполняется.
 
 ## Корень: не диспетчер, а LLM-вызовы внутри задачи
 
@@ -67,6 +67,40 @@ for r in c.execute(\"select claimed_at,finished_at,status,error from executions
 
 После ручного прогона 21:40 каденция вернулась сама, без вмешательства в конфиг: тики 21:35→22:30 — **12 запусков/час, failed = 0**, разрывов >10 мин нет. Все три репозитория по-прежнему на одном коммите (`ec21efe`), рабочие деревья чистые. Итог: инцидент закрыт по данным, причина (LLM timeout в prompt-задаче) остаётся открытой — см. «Что можно сделать».
 
+## Второй режим отказа: тик `completed` за ~9 с, но скрипт не запущен (найдено 2026-09-14 23:45 UTC)
+
+**Симптом:** в `/tmp/vault-sync.log` разрыв 10 мин (например, `23:35:07 → 23:45:10`), при этом в `executions.db` тик `2026-09-14T23:40:01` имеет статус **`completed`**, `finished_at = 23:40:10` (9 с), `error = ''`. В логе за `2026-09-14 23:40` — **ноль строк**, хотя `sync-vault.sh` всегда печатает три timestamped `Pushed ✓`.
+
+**Механика:** prompt-задача исполняется LLM-раундом; если агент отвечает текстом и **не делает вызова инструмента** (короткий ответ, «нечего делать»), запуск считается успешным, но bash-команда не выполняется. Скрипт не вызывался вообще — это не graceful skip `fetch`, не конфликт и не пропуск диспетчера.
+
+**Масштаб (замер за 24 ч, 2026-09-14):** из 258 запусков job_id `29851c413903` — **17 запусков (6,6 %) завершились без единой строки в логе**, из них 12 «здоровых» (~7–12 с, статус `completed`) и 5 в окне таймаутов 18:35–21:20. То есть ~1 из 15 тиков молча ничего не синхронизирует, а лог sync при этом выглядит безобидно (просто 10-минутный разрыв).
+
+**Аудит — сверка executions.db с логом (выполнять при любом подозрении на «пропущенный тик»):**
+
+```bash
+python3 - <<'EOF'
+import sqlite3, re
+from datetime import datetime, timedelta
+c=sqlite3.connect('file:/opt/data/cron/executions.db?mode=ro',uri=True)
+rows=list(c.execute("select claimed_at,finished_at,status from executions where job_id='29851c413903' order by claimed_at"))
+p=lambda s: datetime.fromisoformat(s)
+cut=p(rows[-1][0])-timedelta(hours=24)
+ex=[(p(a),b) for a,b,st in rows if p(a)>=cut]
+txt=open('/tmp/vault-sync.log',errors='replace').read()
+tz=ex[0][0].tzinfo
+ticks=[datetime.strptime(t,'%Y-%m-%d %H:%M:%S').replace(tzinfo=tz) for t in
+       set(re.findall(r'\[(\d{4}-\d\d-\d\d \d\d:\d\d:\d\d)\] \[syncthing\]', txt))]
+ticks=[t for t in ticks if t>=cut]
+miss=[(a.isoformat(),b) for a,b in ex if not any(0<=(t-a).total_seconds()<=300 for t in ticks)]
+print(f'executions 24ч: {len(ex)} | тиков в логе: {len(ticks)} | без записи в лог: {len(miss)}')
+for m in miss: print('  ', m)
+EOF
+```
+
+**Данные не теряются** (git-синк идемпотентен, следующий удачный тик догоняет всё), но фактическая каденция гарантированно ниже номинальных 5 мин — замер 2026-09-14: 245 реальных синков вместо ~288.
+
+**Вывод:** это аргумент за `--no-agent --script` (пункт 1 ниже) — LLM в петле не только блокирует очередь таймаутами, но и в ~6 % случаев просто не вызывает команду.
+
 ## Связанные заметки
 - [[2026-09-02-dubious-ownership-and-merge-cleanup]] — предыдущий инцидент sync (dubious ownership /vault.git)
 - [[2026-08-31-syncthing-truenas-incident]]