Files
obsidian-vault/family/documents/vault-sync/2026-09-16-silent-tick-clusters.md
T

4.4 KiB
Raw Blame History

tags, date
tags date
vault
git
sync
cron
incident
correction
2026-09-16

2026-09-16 — перепроверка молчащих тиков: «кластеры» оказались артефактом метода

Утренняя находка этого дня («молчащие тики идут кластерами 4–5 подряд», 16:55→17:15 и 23:45→00:00) опровергнута при перепроверке 13:25 UTC.

Что было не так

Первый скрипт сверки сравнивал минуту тика из executions.db (claimed_at[:16]) с минутой timestamped-строки [syncthing] Pushed ✓ в логе.

Скрипт стартует внутри тика не мгновенно: при claimed_at = 16:55:55 первая строка лога появляется в 16:56:01 — минута не совпадает, и «здоровый» тик ложно попадал в молчащие. Все тики из обоих «кластеров» скрипт вызывал, их строки в логе есть: 16:56:01, 17:01:00, 17:06:04, 17:11:02, 23:46:02, 23:51:01, 23:56:02, 00:01:03.

Фактический сдвиг claimed_at → запись лога в окне 12–60 с; иногда он переходит через границу минуты — именно это и порождало ложные «пропуски».

Корректный метод

Сопоставлять по окну, а не по минуте: строка [syncthing] должна попадать в [claimed_at 45 с; finished_at + 90 с]. Метод замера 2026-09-14 (окно 300 с) был корректен — цифра 6,6 % за те сутки под сомнение не ставится.

Фактические цифры (окно текущего лога)

Окно 2026-09-15 11:35:19 → 2026-09-16 13:25 UTC (начало лога — рекреация контейнера): 312 тиков, 3 молчащих (0,96 %):

тик (UTC) dur
2026-09-15 13:55 5,8 с
2026-09-15 22:50 7,4 с
2026-09-16 12:10 6,1 с

Режим отказа реален (LLM-раунд завершается без вызова bash, status=completed, ~6 с), но встречается ~1 раз на 100 тиков, а не 1 на 15. 10-минутный разрыв в логе = один молчащий тик; разрывов 20–25 мин за окно нет.

Скрипт сверки (окно, а не минута)

python3 - <<'EOF'
import sqlite3, re
from datetime import datetime, timedelta
c=sqlite3.connect('file:/opt/data/cron/executions.db?mode=ro',uri=True)
rows=c.execute("select claimed_at,finished_at,status from executions where job_id='29851c413903' order by claimed_at").fetchall()
log=open('/tmp/vault-sync.log',encoding='utf-8',errors='replace').read()
P=lambda s: datetime.fromisoformat(s).replace(tzinfo=None)
pat=r'\[(\d{4}-\d\d-\d\d \d\d:\d\d:\d\d)\] \[syncthing\] Pushed'
logts=[datetime.strptime(m,'%Y-%m-%d %H:%M:%S') for m in re.findall(pat,log)]
start=min(logts)
sel=[r for r in rows if P(r[0])>=start-timedelta(minutes=7)]
silent=[]
for cl,fin,st in sel:
    if st!='completed' or not fin: continue
    a,b=P(cl),P(fin)
    if not any(a-timedelta(seconds=45)<=t<=b+timedelta(seconds=90) for t in logts):
        silent.append((cl[:16],round((b-a).total_seconds(),1)))
print('ticks',len(sel),'silent',len(silent))
for s in silent: print('  ',s)
EOF

Ручной прогон 13:25 UTC

Exit 0, «Pushed ✓» по всем трём фазам. Фаза 1 (и фаза 2) подтянула из bare коммит 812173b (work/projects/cpm-web-extension-breakage-validation.md, автор — Eagle). Проверка: /vault, /obsidian-syncthing и bare — все на 812173b, git status --porcelain в /vault пуст.

Что не сделано

Корневая причина — prompt-задача: каждый тик требует LLM-раунда, а раунд иногда заканчивается без вызова инструмента (0,96 % случаев). Устранение (убрать LLM из петли) — hermes cron edit 29851c413903 --no-agent --script <path>, требует решения владельца (см. заметку 2026-09-14).