diff --git a/CHANGELOG.md b/CHANGELOG.md index d7a3f70..3ecc29e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,7 @@ Versionamento independente do OpenClaw — kit segue semver próprio. ## [Unreleased] ### Adicionado +- **Lesson** [`lessons/2026-05-30-openclaw-5.27-upgrade-and-vec0-cli-recovery.md`](lessons/2026-05-30-openclaw-5.27-upgrade-and-vec0-cli-recovery.md) — Upgrade 5.22→5.27 saiu limpo (zero downtime, 32s de gateway-ready). Mas o trabalho real foi de recovery: descobrimos que nox-mem-watch estava silenciosamente abortando ingests há 5 dias por uma cadeia - **Lesson** [`lessons/2026-05-24-upgrade-5.22-harness-restart-latency-and-plugin-config-env.md`](lessons/2026-05-24-upgrade-5.22-harness-restart-latency-and-plugin-config-env.md) — (sem TL;DR — ver lesson para detalhes) - **Lesson** [`lessons/2026-05-08-09-invariant-upgrade-and-health-probe-race.md`](lessons/2026-05-08-09-invariant-upgrade-and-health-probe-race.md) — (sem TL;DR — ver lesson para detalhes) - **Lesson** [`lessons/2026-05-09-upgrade-5.7-and-f18-f17-mitigation.md`](lessons/2026-05-09-upgrade-5.7-and-f18-f17-mitigation.md) — | Item | Estado | diff --git a/README.md b/README.md index 086eb96..7fc38bb 100644 --- a/README.md +++ b/README.md @@ -160,7 +160,7 @@ openclaw-update-toolkit/ │ ├── upgrade-from-v24-to-v29.md │ ├── recovery-from-fratricide-loop.md │ └── recovery-from-cost-explosion.md -└── lessons/ # 23 lições por incident — fonte de truth +└── lessons/ # 24 lições por incident — fonte de truth ``` --- diff --git a/lessons/2026-05-30-openclaw-5.27-upgrade-and-vec0-cli-recovery.md b/lessons/2026-05-30-openclaw-5.27-upgrade-and-vec0-cli-recovery.md new file mode 100644 index 0000000..d9dcb45 --- /dev/null +++ b/lessons/2026-05-30-openclaw-5.27-upgrade-and-vec0-cli-recovery.md @@ -0,0 +1,333 @@ +--- +chunk_type: lesson +source: internal +date: 2026-05-30 +severity: medium +downtime_minutes: 0 +tags: [openclaw, upgrade, v5.27, nox-mem, sqlite-vec, audit-20, ingest-guard, doctor, cron-jobs, model-allowlist, haiku-4-5, dist-patch] +related_lessons: [2026-05-24-upgrade-5.22-harness-restart-latency-and-plugin-config-env, 2026-05-21-openclaw-5.20-upgrade-regressions, 2026-05-09-upgrade-5.7-and-f18-f17-mitigation] +--- + +# 2026-05-30 — Upgrade OpenClaw 5.27 + recovery de 5 dias paralisados (vec0 + Large-DB guard chain) + +## TL;DR + +Upgrade 5.22→5.27 saiu limpo (zero downtime, 32s de gateway-ready). Mas o trabalho real foi de **recovery**: descobrimos que `nox-mem-watch` estava silenciosamente abortando ingests há **5 dias** por uma **cadeia de 2 bugs em camadas**: + +1. **Camada 1 — Large-DB ingest guard** (adicionado pós-incident 2026-05-19) bloqueia qualquer ingest em DB com >10k chunks sem `NOX_ALLOW_PROD_INGEST=1`. Production tem 69k → todos os ingests do watcher legítimo abortavam. +2. **Camada 2 — sqlite-vec não loaded no CLI** `nox-mem ingest`. Quando trigger `trg_chunks_delete_cascade` (criado/ativado no recovery da Recorrência #4 atlas-reindex) tenta tocar em `vec_chunks` virtual table, falha com `SqliteError: no such module: vec0`. + +Fixes aplicados: `NOX_ALLOW_PROD_INGEST=1` prefix no watcher script + patch tático em `dist/db.js#getDb()` carregando vec0 via `db.loadExtension(VEC0_PATH)`. Recovery de 60 chunks dos 8 files paralisados. + +Bonus: cleanup de 16 cron jobs em `claude-haiku-4-5` retired (doctor mapeava pra sonnet caro; resolvido adicionando `claude-haiku-4-5-20251001` à `agents.defaults.models` allowlist). + +VPS saiu de **3 doctor warnings pra 0**. + +--- + +## Severidade & impacto + +- **Downtime gateway:** 0 (restart de ~32s coberto por warmup hook) +- **Downtime nox-mem ingest:** **5 dias** (silencioso — sem alarme, watcher seguia "active") +- **Impacto operacional:** 8 files de memória do agent (`obra-bvv-log.md`, `lessons.md`, `decisions.md`, etc) ficaram fora do index semantic durante o período. Busca por entries criadas nesse intervalo retornaria zero matches até o recovery. +- **Custo:** ~$0.30/dia desperdiçado em fallback chain (fallbacks de cron jobs em haiku retired). Sem corruption. + +--- + +## Sintomas observados + +1. **Falso positivo do `check-reindex-30mai-oneshot.sh` (06:03 BRT):** + - Discord notif `🔴 RED — atlas: 1204MB ⚠️ stale (20260526) ❌ SIZE BUG 1204MB (main DB hit!)` + - Sugeria recorrência do atlas-reindex-hits-main, mas era snapshot histórico (26/mai) mal interpretado + +2. **5 dias sem novos chunks no nox-mem main DB:** + - Query `SELECT COUNT(*) FROM chunks WHERE created_at > datetime('now', '-2 days')` retornava 0 em todos os agent DBs e main + - Watcher service `active (running)` desde 4 dias, mas zero ingests bem-sucedidos + - Files modificados em `workspace/memory/` (state-snapshot, pending, obra-bvv-log, lessons, projects, decisions, people, digests/W21) não apareciam em chunks + +3. **Logs do watcher mostrando 16 ABORTs em 7 dias:** + ``` + May 30 12:47:39 nox-mem-watcher: [db] ABORT: Large-DB ingest guard triggered on operation 'ingest'. + DB path: /root/.openclaw/workspace/tools/nox-mem/nox-mem.db + Chunk count: 69135 (threshold: 10000) + If you intend to ingest into production, set: NOX_ALLOW_PROD_INGEST=1 nox-mem ingest ... + ``` + +4. **Após primeiro fix (guard bypass via env var), ingests ainda falhavam:** + ``` + SqliteError: no such module: vec0 + at Database.prepare (.../better-sqlite3/lib/methods/wrappers.js:5:21) + at ingestFile (.../nox-mem/dist/ingest.js:152:12) + ``` + +5. **Doctor warnings (pré-upgrade):** + - `OPENCLAW_GATEWAY_TOKEN conflicts with gateway.auth.token` (false positive — mesmo valor) + - `channels.telegram: default account has no available bot token` (residual de remoção 2026-05-01) + - `Legacy config keys detected: 43 jobs use a different model than agents.defaults.model` + +--- + +## Root cause analysis + +### Bug 1: Large-DB ingest guard bloqueando watcher legítimo + +**Code** (em `dist/db.js#checkLargeDbIngestGuard`): +```javascript +const PROD_CHUNK_THRESHOLD = 10_000; +function checkLargeDbIngestGuard(db, operation) { + if (process.env.NOX_ALLOW_PROD_INGEST === "1") return; + const row = db.prepare("SELECT COUNT(*) AS n FROM chunks").get(); + if (row.n > PROD_CHUNK_THRESHOLD) { + console.error(`[db] ABORT: Large-DB ingest guard...`); + process.exit(1); + } +} +``` + +**Origem:** "audit #20 fix" pós-incident 2026-05-19 (eval/test scripts poluindo production DB). Comment cravado no source: *"This DB appears to be the production nox-mem.db. If you intend to ingest into production, set NOX_ALLOW_PROD_INGEST=1"*. + +**Falha de design:** o guard foi pensado pra bloquear scripts ad-hoc (`run_locomo_ablations.sh`, evals com NOX_DB_PATH errado, etc), **mas o watcher legítimo também é vítima** — ele é o único caller real de ingest em prod, deveria ter sido excluído por design. + +**Caller bugado** em `nox-mem-watch.sh#L43`: +```bash +# Ingest with validated path +if [[ -f "$file" ]]; then + /usr/local/bin/nox-mem ingest "$file" 2>&1 | logger -t nox-mem-watcher + # ❌ falta: NOX_ALLOW_PROD_INGEST=1 prefix +fi +``` + +### Bug 2: sqlite-vec não loaded no CLI `nox-mem` + +**Code analysis:** +- `dist/embed.ts` linha 22 — `db.loadExtension(VEC0_PATH)` ✓ +- `dist/reindex.js` linha 92 — `sqliteVec.load(db)` via dynImport ✓ (fix de 21/mai) +- `dist/api-server.ts` — carrega no boot do server ✓ +- `dist/db.js#getDb()` — **NÃO carrega**, e é a função usada pelo CLI direto ❌ + +**Comment cravado em** `reindex.js.bak-pre-fix-deploy-20260524`: +> "Load sqlite-vec extension BEFORE any DELETE/INSERT on chunks (2026-05-21 fix). Root cause: `trg_chunks_delete_cascade` trigger references `vec_chunks` (sqlite-vec virtual table). api-server.js loads sqlite-vec at startup; CLI (index.js) does not, so this must load it explicitly." + +Reindex.js recebeu esse fix em 21/mai. **Ingest.js nunca recebeu.** + +**Trigger timeline:** +- ≤ 25/mai 02:00 UTC — ingest funcionava (trigger inativo ou em outro estado) +- 25/mai 23:00 BRT — Recorrência #4 atlas-reindex-hits-main +- 25/mai 23:11 — primeiro `vec0 error` no journal (durante o recovery, trigger foi (re)criado ou re-ativado, expondo o code path quebrado) +- 30/mai 13:35 — patch tático aplicado + +### Bug 3: doctor --fix mapeia haiku retired → sonnet (caro) + +**Sequência:** +1. `openclaw doctor --fix` encontra `claude-haiku-4-5` retired em `agents.defaults.models` +2. Modelo default atual = `claude-sonnet-4-6` → mapeamento naive haiku → sonnet +3. 16 cron jobs com `payload.model = claude-haiku-4-5` ficam órfãos (allowlist do agent rejeita haiku tanto sem versão quanto com `-20251001`) +4. Sem ação, jobs caem na fallback chain `[gpt-5.5, gemini-2.5-pro]` silenciosamente + +**Allowlist padrão pós-5.27:** +``` +gemini/gemini-2.5-flash-lite, gemini/gemini-2.5-pro, +anthropic/claude-opus-4-6, claude-opus-4-7, claude-sonnet-4-6, +openai/gpt-5.4, gpt-5.5 +``` +**Sem haiku.** Sub-agents (nox, atlas, boris, cipher, forge, lex) herdam. + +--- + +## Fixes aplicados + +### Fix 1 — Watcher: adicionar env var + +```bash +sed -i 's|/usr/local/bin/nox-mem ingest "$file"|NOX_ALLOW_PROD_INGEST=1 /usr/local/bin/nox-mem ingest "$file"|' \ + /root/.openclaw/workspace/tools/nox-mem/nox-mem-watch.sh +systemctl restart nox-mem-watch.service +``` +Backup: `.bak-pre-allow-prod-20260530-134459`. + +### Fix 2 — Patch tático em dist/db.js (vec0 load) + +```javascript +// Adicionado em getDb() antes do ensureSchema(_db): +try { + const VEC0_PATH = resolve(__dirname, "..", "node_modules", "sqlite-vec-linux-x64", "vec0"); + _db.loadExtension(VEC0_PATH); +} catch (err) { + console.error("[db] sqlite-vec load failed:", err.message); +} +``` +Backup: `dist/db.js.bak-pre-vec0-load-retry-20260530-135253`. Pattern copiado do `embed.ts`. + +**⚠️ ATENÇÃO:** patch em `dist/` NÃO sobrevive ao próximo `npm run build` do nox-mem. Source fix permanente é tarefa pra repo `~/Claude/Projetos/memoria-nox/` (`src/db.ts` + rebuild + deploy). + +### Fix 3 — Recovery dos 8 files + +```bash +for f in /root/.openclaw/workspace/memory/{state-snapshot,pending,obra-bvv-log,lessons,projects,decisions,people}.md \ + /root/.openclaw/workspace/memory/digests/2026-W21.md; do + NOX_ALLOW_PROD_INGEST=1 /usr/local/bin/nox-mem ingest "$f" +done +``` +**60 chunks ingestidos.** Net delta: 69.135 → 69.130 (-5; files mais concisos na versão atualizada). + +### Fix 4 — Cron jobs em haiku retired + +**Iteração 1 (revertida):** batch update pra `claude-sonnet-4-6` (Toto vetou — overkill caro). + +**Iteração 2 (final):** adicionar haiku à allowlist + restore. +```bash +# 1. Add haiku-4-5-20251001 (ID com versão) à allowlist do agents.defaults.models +jq '.agents.defaults.models["anthropic/claude-haiku-4-5-20251001"] = {"agentRuntime": {"id": "claude-cli"}}' \ + /root/.openclaw/openclaw.json > /tmp/o.new.json && \ + mv /tmp/o.new.json /root/.openclaw/openclaw.json && chmod 600 /root/.openclaw/openclaw.json + +# 2. Restart gateway pra recarregar allowlist +systemctl restart openclaw-gateway.service && sleep 12 + +# 3. Batch update 16 jobs +for id in <16 IDs>; do + openclaw cron edit "$id" --model anthropic/claude-haiku-4-5-20251001 +done + +# 4. Manual smoke test +openclaw cron run 8b8b8500-...-daily-briefing # → durationMs=15930 ✓ +``` + +### Fix 5 — Token cleanup + +```bash +# OPENCLAW_GATEWAY_TOKEN era orphan (zero refs); canonical é OPENCLAW_AUTH_TOKEN +sed -i 's|^OPENCLAW_GATEWAY_TOKEN=|# OPENCLAW_GATEWAY_TOKEN (removed 2026-05-30, orphan)\n# OPENCLAW_GATEWAY_TOKEN=|' /root/.openclaw/.env +``` + +### Fix 6 — Telegram residual + +```bash +jq 'del(.channels.telegram) | .plugins.allow |= map(select(. != "telegram"))' \ + /root/.openclaw/openclaw.json > /tmp/o.new.json && mv /tmp/o.new.json /root/.openclaw/openclaw.json +``` + +### Fix 7 — Novo check-reindex script + +Substituiu `check-reindex-30mai-oneshot.sh` (bugado, comparava snapshots historicos) por `check-reindex-postnight.sh` que parseia `/var/log/nox-maintenance.log` direto — Phase outcome real. Trata `Phase 2: Skipped` (legítimo) como GREEN. + +--- + +## Operação do upgrade — playbook validado + +1. **Pre-flight snapshots** (sem risco): + - `tar czf /root/openclaw-pre-5.27-.tar.gz <.env, openclaw.json, credentials/, auth-profiles.json[main+6 sub-agents], nightly-maintenance.sh, systemd units>` (274K) + - `/root/bin/ckpt save "pre-upgrade-5.27-"` (760K) + - `cp
/var/backups/nox-mem/pre-upgrade-5.27-.db` (1.2G) + - State confirmation: version, chunks count, gateway active, Tailscale auth + +2. **`npm install -g openclaw@2026.5.27`** (20s; removed 10 pkgs, changed 345) + - **Pré-check:** se `chattr +i` setado em `/usr/lib/node_modules/openclaw/dist/status-message-*.js` (emoji patch), liberar com `chattr -i` ANTES (regra #2 do CLAUDE.md). Hoje não estava setado. + +3. **`systemctl restart openclaw-gateway.service`** — **MANUAL obrigatório** (memória `openclaw-update-skips-system-service-restart`) + +4. **Wait + smoke test:** + - `openclaw --version` (5.27 ✓) + - `systemctl is-active openclaw-gateway.service` (active) + - `systemctl show ... --property=NRestarts` (0) + - Sqlite chunks count (69.135) + - `journalctl --since "60s ago" | grep -c MissingAgentHarnessError` (0) + - Warmup hook logs (`/var/log/openclaw-warmup.log` — ready+done em 15s) + +5. **`openclaw doctor --fix`** — atualiza `agents.defaults.models`: + - `claude-opus-4-5` → `claude-opus-4-7` + - `claude-sonnet-4-5` → `claude-sonnet-4-6` + - `claude-haiku-4-5` → `claude-sonnet-4-6` (!! NOT `haiku-4-5-20251001` — ver Bug 3) + +6. **Monkey-patch #62028 check:** validar `restart-stale-pids-*.js` ainda interceptando. Hoje passou clean (chattr não-setado significou que o npm install fez clean replace e patch foi auto-mantido). + +**Resultado:** gateway ready em 32s, warmup OK em 15s, 0 MissingAgentHarnessError, 0 errors. Plugins: 13 loaded, 84 disabled, 0 errors. Skills: 62 eligible, 0 blocked. + +--- + +## Prevenção / patterns reusáveis + +### Pre-upgrade (sempre): +1. Snapshot tarball + ckpt + DB +2. Check `chattr +i` em `/usr/lib/node_modules/openclaw/dist/` — liberar se setado +3. Verificar plugins `@openclaw/*` em `/root/.openclaw/npm/node_modules/` (não em `/usr/lib/`) +4. Snapshot do nightly-maintenance.sh + +### Pós-upgrade (sempre): +1. `systemctl restart openclaw-gateway.service` manual +2. Validar 7 invariants (regra #1 do CLAUDE.md): model.primary, baseUrl, relayplane inactive, fallback chain sem dup, sessions sem fallback grudado, web search provider, canais loaded +3. `openclaw doctor --fix` (apenas se tiver warnings — review os mapeamentos antes de aplicar pra evitar haiku→sonnet) +4. Pre-update da allowlist se houver cron jobs em modelos retired: + ```bash + # ANTES de doctor --fix: + jq '.agents.defaults.models["anthropic/claude-haiku-4-5-20251001"] = {"agentRuntime":{"id":"claude-cli"}}' \ + /root/.openclaw/openclaw.json > /tmp/o.new.json && mv /tmp/o.new.json /root/.openclaw/openclaw.json + systemctl restart openclaw-gateway.service + ``` +5. Smoke test de 1 cron job representativo via `openclaw cron run ` + +### Recovery patterns (se algo paralisar): +1. **Watcher silenciosamente quebrado:** comparar `MAX(created_at)` em chunks vs `find -mtime` em workspace/. Drift = problema. +2. **Large-DB guard abortando legítimos:** `journalctl -u nox-mem-watch.service | grep "Large-DB ingest guard"`. Fix = prefix `NOX_ALLOW_PROD_INGEST=1`. +3. **vec0 not loaded:** `journalctl | grep "no such module: vec0"`. Fix = patch tático em `dist/db.js` OU usar `nox-mem reindex` (que carrega vec0) OU api-server endpoint (que carrega no boot). +4. **Falso positivo em alarme:** sempre validar via log source-of-truth (`/var/log/nox-maintenance.log`), não inferir por filesystem state. + +--- + +## Backups dessa sessão + +``` +/root/openclaw-pre-5.27-20260530-133400.tar.gz # full pre-flight (274K) +/var/backups/nox-mem/pre-upgrade-5.27-20260530-133400.db # main DB pre-upgrade (1.2G) +/root/.openclaw/checkpoints/20260530-133402-pre-upgrade-527-... # ckpt full +/root/openclaw-cron-backup-20260530-140217.json # cron jobs pre-batch +/root/.openclaw/openclaw.json.bak-pre-haiku-allowlist-20260530-141* # config pre-haiku-allowlist +/root/.openclaw/openclaw.json.bak-pre-telegram-cleanup-20260530-140907 # config pre-telegram-cleanup +/root/.openclaw/.env.bak-pre-gateway-token-cleanup-20260530-140503 # env pre-gateway-token-cleanup +/root/.openclaw/workspace/tools/nox-mem/dist/db.js.bak-pre-vec0-load-retry-* # db.js pre-vec0 patch +/root/.openclaw/workspace/tools/nox-mem/nox-mem-watch.sh.bak-pre-allow-prod-* # watcher pre-allow-prod +``` + +--- + +## Pendências (não-bloqueantes) + +| # | Item | Onde | Quando | +|---|---|---|---| +| ~~#12~~ | ~~Source fix vec0 permanente~~ | ✅ **RESOLVIDO 30/mai (sessão paralela)** — source fix LIVE em produção; nox-workspace push functional (1.9GB clean); aggressive .gitignore protege futuro | DONE | +| **#16** | Avaliar desligar keepalive cron + warmup service | `infra/` | ~2026-06-06 (7d sem MissingAgentHarnessError) | +| Auto | `check-reindex-postnight.sh` dispara 1/jun 06:03 BRT | Discord | aguardar notif (esperada 🟢 GREEN) | + +--- + +## Estado final (14:30 BRT) + +| Métrica | Valor | +|---|---| +| OpenClaw | **5.27 (27ae826)** | +| Gateway | active, NRestarts=0 | +| **Doctor warnings** | **0** (era 3 pré-sessão) | +| Main DB chunks | 69.130 (recuperado) | +| Canary orphans | 0 (24h estável) | +| 16 cron jobs | `anthropic/claude-haiku-4-5-20251001` ✅ | +| MissingAgentHarnessError 24h | 0 | +| vec0 errors pós-fix (13:35) | 0 | +| Custo cron jobs/dia | ~$0.30 (haiku preservado, não sonnet) | + +--- + +## Cross-references + +- **Lessons relacionadas:** + - `2026-05-24-upgrade-5.22-harness-restart-latency-and-plugin-config-env.md` — upgrade anterior 5.20→5.22 + ENV var substitution broken + harness restart latency + - `2026-05-21-openclaw-5.20-upgrade-regressions.md` — plugins.allow gate novo + - `2026-05-09-upgrade-5.7-and-f18-f17-mitigation.md` — pattern de upgrade similar + +- **Memórias persistentes criadas/atualizadas:** + - `vec0-cli-load-required.md` (nova) + - `nox-mem-watch-needs-allow-prod-ingest.md` (nova) + - `openclaw-haiku-not-in-default-allowlist.md` (nova) + - `openclaw-522-beta-breaks-harness.md` (update — VPS agora 5.27) + +- **Incident log:** `infra/docs/INCIDENTS.md` (entry 2026-05-30) +- **Handoff:** `infra/docs/HANDOFF.md` (seção "Onde paramos" 2026-05-30)