fix(openclaw): resolve restart deadlock, foreign keys, cold-start latency, and wiki audit cron
This commit is contained in:
Moritz Graf
@@ -21,6 +21,10 @@ This document captures fixed issues, operational quirks, and incident root-cause
|
||||
| **2026-09-29** | **Compaction Pitfall & Split-Turn Drift** | Shopping agent ignored user message (Küchenwaage) and replied with old supermarket wiki edit in broken German | `RESOLVED` | Identified `--max-lines 250` bypassing LLM compaction on sessions with <250 lines but 40k-95k tokens. Switched to true LLM summarization, compacted live sessions, added event-loop pacing, and documented split-turn context recovery. |
|
||||
| **2026-09-29** | **Audio & Speech-to-Text** | Telegram voice notes failed transcription with `reason=ProviderHttpError`, passing empty text (`0 chars`) and inducing bot hallucinations | `RESOLVED` | Identified OpenRouter audio balance floor ($0.50) causing HTTP 402 when key quota was within $0.50 of monthly limit. Topped up buffer, verified transcription, and switched Recherche agent to DeepSeek V4.1 Flash. |
|
||||
| **2026-10-02** | **Memory Cgroup OOMKill & Probe Flapping** | Container killed by Linux kernel OOM (137) at 4Gi; liveness probe failed 52 times on event loop lag; nightly compaction cron reported `failed` delivery | `RESOLVED` | Injected `NODE_OPTIONS="--max-old-space-size=3072"`, raised liveness threshold to 12 (120s), lowered safeguard compaction to 400kb, added `--no-deliver` + automated WAL checkpointing to nightly cron, and purged 14 obsolete sessions (reclaiming >364k tokens). |
|
||||
| **2026-10-05** | **Disk I/O & Startup Latency** | Event loop starvation (48s freeze) and container restarts from MCP process storms & cold-start database integrity scans | `RESOLVED` | Implemented init-container page-cache pre-warming (`cat ... > /dev/null`) cutting DB open from 22 minutes to 11 seconds. |
|
||||
| **2026-10-05** | **CronJob & Alerting** | `openclaw-wiki-audit` CronJob failing daily with exit code 1; Prometheus alert `WikiAuditJobFailed` firing | `RESOLVED` | Appended `\|\| true` to `okf_lint.py` in `cronjob-wiki-audit.secret.yaml`, preventing `set -e` abort when lint findings exist. |
|
||||
| **2026-10-05** | **Cron Trigger State** | `rennerhof-website-watch` (Regensburg Topic 116) stuck in `status: error` with `ReferenceError: state is not defined` | `RESOLVED` | Cleared stale error state from `state_json` in `openclaw.sqlite` and triggered successful verification run. |
|
||||
| **2026-10-05** | **State Deadlock & Session Corruption** | Telegram Topic 117 (`#Recherche`) wedged with `restart recovery claim changed` and `entry_valid = 0` after crash | `RESOLVED` | Repaired `session_nodes` and `session_windows` (restored `entry_valid = 1`, synced `updated_at`, cleared dead claim), purged 20 obsolete cron sessions (>498k tokens), and added `--max-lines 200` compaction fallback. |
|
||||
|
||||
---
|
||||
|
||||
@@ -316,6 +320,118 @@ This document captures fixed issues, operational quirks, and incident root-cause
|
||||
- Never set liveness probe tolerance below 120 seconds on spinning disk storage with multi-agent SQLite databases.
|
||||
- Always register isolated automated cron jobs with `--no-deliver`.
|
||||
|
||||
---
|
||||
|
||||
### Issue 11: Event Loop Starvation and Probe Timeouts from MCP Process Storms & Cold-Start SQLite Verification on HDD Storage
|
||||
|
||||
- **Date**: 2026-10-05
|
||||
- **Severity**: Critical (Pod flapping with startup/liveness probe timeouts, event loop frozen for 48s–70s)
|
||||
- **Symptom**:
|
||||
1. OpenClaw container restarted frequently; logs recorded massive timing gaps:
|
||||
```text
|
||||
[health] host timing gap detected: process was frozen ~48830ms (clock jump: 48830ms, interval: 10000ms)
|
||||
system-prompt:64391ms
|
||||
[state/agent-db] slow OpenClaw agent database open
|
||||
```
|
||||
2. Kubelet liveness/startup probes timed out with `context deadline exceeded`.
|
||||
3. Cold starts took up to 22 minutes verifying database B-tree integrity across 12 agent SQLite stores.
|
||||
- **Root Cause**:
|
||||
1. **MCP Subprocess Storm**: 16 MCP servers were registered globally in `openclaw-instance.secret.yaml`. On turns or background runs, OpenClaw spawned all 16 processes simultaneously (Python, Node.js, and Go). Concurrent agent turns resulted in 32+ processes competing for CPU and random I/O on the rotational SATA drive (`/dev/sda2`), spiking RAM to 2.43 GB and starving the Node.js event loop.
|
||||
2. **Cold-Start Disk Seek Bottleneck**: On startup, OpenClaw runs SQLite integrity and schema assertions across 12 databases (~1.8 GB). On rotational disk, thousands of random 4KB read operations take up to 22 minutes if the OS page cache is cold.
|
||||
3. **ext4 Directory Inode Bloat**: `/home/node/.openclaw` directory inode had grown to 17.8 MB from historical file deletions. ext4 does not shrink directory leaf blocks upon unlink, forcing the kernel to scan ~4,300 directory blocks on every stat/lookup.
|
||||
- **Resolution**:
|
||||
1. Implemented sequential page-cache pre-warming in the pod `initContainer` and nightly cron script:
|
||||
```sh
|
||||
cat /home/node/.openclaw/state/openclaw.sqlite /home/node/.openclaw/agents/*/agent/openclaw-agent.sqlite > /dev/null 2>&1 || true
|
||||
```
|
||||
Because sequential read throughput on the HDD is ~150 MB/s, the kernel streams all 1.8 GB into RAM in ~11 seconds. When the main container boots, index verification runs in 11 seconds instead of 22 minutes.
|
||||
2. Applied manifest to ensure all restarts benefit from page cache warming.
|
||||
- **How to Avoid Recurrence**:
|
||||
- Always maintain database streaming in the pod `initContainer` before OpenClaw starts.
|
||||
- Avoid spawning unnecessary MCP servers; ensure heavy processes are lazy or decoupled.
|
||||
|
||||
---
|
||||
|
||||
### Issue 12: Knowledge Wiki Audit CronJob Failure Loop (`set -e` vs Lint Findings) and Prometheus Alert (`WikiAuditJobFailed`)
|
||||
|
||||
- **Date**: 2026-10-05
|
||||
- **Severity**: High (Daily audit CronJob failed repeatedly; Prometheus alert firing; git repo left uncommitted)
|
||||
- **Symptom**:
|
||||
1. Kubernetes CronJob `openclaw-wiki-audit` failed every night at 00:05 UTC with exit code 1.
|
||||
2. Prometheus fired persistent alert `WikiAuditJobFailed`.
|
||||
3. Changes detected by the linter were never staged or committed, leaving the repository dirty on the PVC.
|
||||
- **Root Cause**:
|
||||
In [`k8s/openclaw/cronjob-wiki-audit.secret.yaml`](file:///Users/moritz/src/infrapuzzle/k8s/openclaw/cronjob-wiki-audit.secret.yaml), the script had `set -euo pipefail` at line 25. Line 47 executed:
|
||||
```bash
|
||||
python3 scripts/okf_lint.py --vault "$TARGET_DIR" --add-tasks
|
||||
```
|
||||
`okf_lint.py` deliberately exits with code 1 whenever any lint findings or actionable tasks are added to Obsidian notes. Because of `set -e`, the shell script aborted immediately at line 47, skipping `git commit`, `git push`, and exiting 1.
|
||||
- **Resolution**:
|
||||
Patched line 47 to append `|| true`:
|
||||
```bash
|
||||
python3 scripts/okf_lint.py --vault "$TARGET_DIR" --add-tasks || true
|
||||
```
|
||||
Applied manifest, deleted the stale failed job, and triggered a test job. The test successfully audited 117 files, committed `chore(audit): automated OKF health check [skip ci]`, pushed to Gitea, and exited with code 0, clearing the Prometheus alert.
|
||||
- **How to Avoid Recurrence**:
|
||||
- Be mindful of command exit semantics in scripts using `set -e`. Linters and audit tools frequently return non-zero exit codes to indicate "findings were present", which is expected behavior, not a script crash.
|
||||
|
||||
---
|
||||
|
||||
### Issue 13: Stale Cron Job Error State on `rennerhof-website-watch` (Regensburg Topic 116)
|
||||
|
||||
- **Date**: 2026-10-05
|
||||
- **Severity**: Medium (Website watch cron job showed red error status in OpenClaw dashboard)
|
||||
- **Symptom**:
|
||||
The cron automation `rennerhof-website-watch` for Regensburg Topic 116 showed `status: error` with:
|
||||
```text
|
||||
cron trigger evaluation failed (internal_error): ReferenceError: state is not defined
|
||||
```
|
||||
- **Root Cause**:
|
||||
Although the trigger code was previously patched, the historical error was preserved in `state_json` in `/home/node/.openclaw/state/openclaw.sqlite`, causing OpenClaw to report the job as failed.
|
||||
- **Resolution**:
|
||||
Cleared the error state from `state_json` in SQLite and executed a manual trigger evaluation:
|
||||
```json
|
||||
"fire": false, "evals": 12, "last_result": null, "status": "running"
|
||||
```
|
||||
Job state returned to healthy `running` with zero errors.
|
||||
- **How to Avoid Recurrence**:
|
||||
- After fixing JavaScript trigger logic in cron jobs, always clear stale error payloads from `openclaw.sqlite` or trigger an explicit run to update state.
|
||||
|
||||
---
|
||||
|
||||
### Issue 14: Ungraceful Restart Deadlock on Telegram Topic 117 (`#Recherche`): `entry_valid = 0` and Recovery Claim Deadlock
|
||||
|
||||
- **Date**: 2026-10-05
|
||||
- **Severity**: Critical (Topic 117 completely unresponsive in Telegram; every message failed with error and retried endlessly)
|
||||
- **Symptom**:
|
||||
1. Inbound messages to Telegram Topic 117 failed with:
|
||||
```text
|
||||
[telegram] dispatch failed: Error: restart recovery claim changed before agent adoption
|
||||
[telegram] spooled update 985533189 failed; keeping for retry: restart recovery claim changed before agent adoption
|
||||
```
|
||||
2. Running any CLI command against the recherche agent failed with:
|
||||
```text
|
||||
SessionCanonicalKeyMigrationRequiredError: invalid persisted session row requires repair for agent:recherche:telegram:group:-1004326921510:topic:117; stop the Gateway and run openclaw doctor --fix
|
||||
```
|
||||
- **Root Cause**:
|
||||
1. **Active Writer Abort**: When the pod was killed or restarted during an active message turn, `session_nodes` and `entry_json` were left with `status: "running"`, `activeWriterRunId`, and `restartRecoveryDeliveryRunId`.
|
||||
2. **Admission Deadlock**: In `reply-admission-ticket.js:469`, when new messages arrive while `activeClaimRunId` is set and `entry.status === "running"`, the runtime throws `Error: restart recovery claim changed before agent adoption`. Because it throws before resetting state, Telegram kept spooling and retrying the message every 30 seconds forever.
|
||||
3. **Database Invalidation (`entry_valid = 0`)**: During the crash, OpenClaw marked `entry_valid = 0` in `session_nodes`. The runtime validator `scanCanonicalSqliteSessionEntries()` requires `row.entry_valid === 1`, throwing `SessionCanonicalKeyMigrationRequiredError` on any read.
|
||||
4. **Column Synchronization Requirement**: `parseSqliteSessionEntryRecord(row)` requires that `row.updated_at === record.updatedAt`. Any update modifying one without the other causes the parser to return `null` and reject the session.
|
||||
5. **Dead Cron Session Accumulation**: 20 isolated cron sessions from September were never pruned, holding >498,000 dead tokens across `main` and `itguy`.
|
||||
- **Resolution**:
|
||||
1. Synchronized SQLite state in `/home/node/.openclaw/agents/recherche/agent/openclaw-agent.sqlite`:
|
||||
- Set `entry_valid = 1`.
|
||||
- Reset `status = "done"`, cleared `restartRecoveryDeliveryRunId`, `restartRecoveryDeliverySourceRunId`, `restartRecoveryDeliveryContext`.
|
||||
- Synchronized `updated_at` on row and `updatedAt` in `entry_json`.
|
||||
- Updated `session_windows` to `status = "done"`.
|
||||
2. Upon repair, OpenClaw immediately admitted the spooled Telegram update and dispatched a clean response via DeepSeek V4.1 Flash.
|
||||
3. Purged all 20 abandoned cron sessions older than 48 hours across `main` and `itguy`, reclaiming 498,171 tokens and checkpointing WAL journals to disk.
|
||||
4. Upgraded `setup-compaction-cron.sh`:
|
||||
- Added automatic pre-warming of SQLite page cache.
|
||||
- Added automated pruning of isolated cron sessions older than 48 hours.
|
||||
- Raised compaction RPC timeout from 10s to 120s (`--timeout 120000`).
|
||||
- Added automatic fallback to `--max-lines 200` if LLM summarization safeguards fail quality checks.
|
||||
- **How to Avoid Recurrence**:
|
||||
- The nightly maintenance cron now automatically purges stale cron sessions and pre-warms cache.
|
||||
- If a session ever reports `invalid persisted session row requires repair`, check `entry_valid == 1` and ensure `row.updated_at == record.updatedAt`.
|
||||
|
||||
Binary file not shown.
Binary file not shown.
@@ -22,32 +22,111 @@ echo "Ensuring /home/node/.openclaw/scripts/compact_sessions.py exists..."
|
||||
kubectl exec -i -n "$NAMESPACE" "$POD_NAME" -c "$CONTAINER_NAME" -- /bin/sh -c 'cat << "EOF" > /home/node/.openclaw/scripts/compact_sessions.py
|
||||
#!/usr/bin/env python3
|
||||
"""
|
||||
Nightly multi-agent session compaction script for OpenClaw.
|
||||
Compacts all active forum topics and main sessions exceeding the token threshold.
|
||||
Nightly multi-agent session compaction and maintenance script for OpenClaw.
|
||||
1. Pre-warms OS page cache for SQLite databases on spinning disks.
|
||||
2. Prunes abandoned isolated cron sessions (>48h old) to prevent token/state bloat.
|
||||
3. Compacts all active forum topics and main sessions exceeding the token threshold.
|
||||
4. Checkpoints SQLite WAL journals across all agent databases to disk.
|
||||
"""
|
||||
import subprocess
|
||||
import glob
|
||||
import json
|
||||
import os
|
||||
import sqlite3
|
||||
import subprocess
|
||||
import sys
|
||||
import time
|
||||
|
||||
THRESHOLD_TOKENS = 25000
|
||||
CRON_MAX_AGE_HOURS = 48
|
||||
RPC_TIMEOUT_MS = 120000
|
||||
|
||||
def main():
|
||||
print(f"=== Running OpenClaw Nightly Multi-Agent Compaction (threshold: {THRESHOLD_TOKENS} tokens, LLM summarization) ===")
|
||||
def prewarm_page_cache():
|
||||
print("=== Pre-warming SQLite databases into OS page cache ===")
|
||||
t0 = time.time()
|
||||
try:
|
||||
subprocess.run(
|
||||
"cat /home/node/.openclaw/state/openclaw.sqlite /home/node/.openclaw/agents/*/agent/openclaw-agent.sqlite > /dev/null 2>&1 || true",
|
||||
shell=True,
|
||||
timeout=90.0
|
||||
)
|
||||
print(f"Page cache pre-warmed in {time.time() - t0:.2f}s")
|
||||
except Exception as e:
|
||||
print(f"Page cache pre-warming warning: {e}")
|
||||
|
||||
def prune_stale_cron_sessions():
|
||||
print(f"=== Pruning isolated cron sessions older than {CRON_MAX_AGE_HOURS}h ===")
|
||||
cutoff_ms = int(time.time() * 1000) - (CRON_MAX_AGE_HOURS * 3600 * 1000)
|
||||
total_pruned = 0
|
||||
total_tokens_reclaimed = 0
|
||||
|
||||
for db in sorted(glob.glob("/home/node/.openclaw/agents/*/agent/openclaw-agent.sqlite")):
|
||||
agent = db.split("/")[5]
|
||||
try:
|
||||
conn = sqlite3.connect(db, timeout=30.0)
|
||||
cursor = conn.cursor()
|
||||
cursor.execute("SELECT name FROM sqlite_master WHERE type=\"table\"")
|
||||
all_tables = set(r[0] for r in cursor.fetchall())
|
||||
|
||||
cursor.execute("SELECT session_key, current_session_id, updated_at, entry_json FROM session_nodes WHERE session_key LIKE \"%:cron:%\"")
|
||||
stale = []
|
||||
for k, sid, up, ej in cursor.fetchall():
|
||||
if up and up < cutoff_ms:
|
||||
tok = 0
|
||||
if ej:
|
||||
try:
|
||||
tok = json.loads(ej).get("totalTokens", 0) or 0
|
||||
except Exception:
|
||||
pass
|
||||
stale.append((k, sid, tok))
|
||||
|
||||
if stale:
|
||||
tokens_reclaimed = sum(t[2] for t in stale)
|
||||
for k, sid, _ in stale:
|
||||
for t in ["transcript_events", "transcript_event_identities", "session_transcript_active_events", "transcript_rewrite_watermarks", "session_transcript_index_state", "session_transcript_fts", "session_conversations"]:
|
||||
if t in all_tables and sid:
|
||||
cursor.execute(f"DELETE FROM {t} WHERE session_id = ?", (sid,))
|
||||
for t in ["session_participants", "heartbeat_outcomes", "session_progress_cards", "board_widgets", "board_tabs"]:
|
||||
if t in all_tables:
|
||||
cursor.execute(f"DELETE FROM {t} WHERE session_key = ?", (k,))
|
||||
if "memory_entry_origins" in all_tables:
|
||||
cursor.execute("DELETE FROM memory_entry_origins WHERE session_key = ? OR session_id = ?", (k, sid or ""))
|
||||
cursor.execute("DELETE FROM session_nodes WHERE session_key = ?", (k,))
|
||||
|
||||
# Resolve any dangling foreign key references
|
||||
while True:
|
||||
cursor.execute("PRAGMA foreign_key_check;")
|
||||
violations = cursor.fetchall()
|
||||
if not violations:
|
||||
break
|
||||
for table, rowid, parent, fkid in violations:
|
||||
cursor.execute(f"DELETE FROM {table} WHERE rowid = ?", (rowid,))
|
||||
|
||||
conn.commit()
|
||||
total_pruned += len(stale)
|
||||
total_tokens_reclaimed += tokens_reclaimed
|
||||
print(f" [{agent}] Pruned {len(stale)} dead cron sessions ({tokens_reclaimed} tokens reclaimed)")
|
||||
conn.close()
|
||||
except Exception as e:
|
||||
print(f" [{agent}] Pruning error: {e}")
|
||||
|
||||
print(f"Cron pruning complete: {total_pruned} sessions pruned, {total_tokens_reclaimed} tokens reclaimed.")
|
||||
|
||||
def compact_active_sessions():
|
||||
print(f"=== Running OpenClaw Multi-Agent Compaction (threshold: {THRESHOLD_TOKENS} tokens, LLM summarization) ===")
|
||||
res = subprocess.run(["openclaw", "sessions", "--all-agents", "--json"], capture_output=True, text=True)
|
||||
if res.returncode != 0:
|
||||
print(f"Failed to list sessions: {res.stderr}")
|
||||
sys.exit(1)
|
||||
|
||||
return
|
||||
|
||||
sessions = json.loads(res.stdout).get("sessions", [])
|
||||
compacted = 0
|
||||
skipped = 0
|
||||
|
||||
|
||||
for s in sessions:
|
||||
key = s.get("key", "")
|
||||
agent = s.get("agentId") or "main"
|
||||
tokens = s.get("totalTokens") or 0
|
||||
|
||||
|
||||
# Target main sessions and all telegram sessions (topics and direct)
|
||||
is_target = (
|
||||
key == "agent:main:main" or
|
||||
@@ -58,23 +137,31 @@ def main():
|
||||
if tokens >= THRESHOLD_TOKENS:
|
||||
print(f"Compacting {agent} ({tokens} tokens) -> {key}...")
|
||||
c_res = subprocess.run(
|
||||
["openclaw", "sessions", "compact", key, "--agent", agent],
|
||||
["openclaw", "sessions", "compact", key, "--agent", agent, "--timeout", str(RPC_TIMEOUT_MS)],
|
||||
capture_output=True, text=True
|
||||
)
|
||||
if c_res.returncode == 0:
|
||||
print(f" ✓ {c_res.stdout.strip()}")
|
||||
compacted += 1
|
||||
else:
|
||||
print(f" ✗ {c_res.stderr.strip()}")
|
||||
print(f" ✗ {c_res.stderr.strip()}; retrying with --max-lines 200 fallback...")
|
||||
fb_res = subprocess.run(
|
||||
["openclaw", "sessions", "compact", key, "--agent", agent, "--max-lines", "200", "--timeout", str(RPC_TIMEOUT_MS)],
|
||||
capture_output=True, text=True
|
||||
)
|
||||
if fb_res.returncode == 0:
|
||||
print(f" ✓ (fallback) {fb_res.stdout.strip()}")
|
||||
compacted += 1
|
||||
else:
|
||||
print(f" ✗ Fallback failed: {fb_res.stderr.strip()}")
|
||||
time.sleep(2)
|
||||
else:
|
||||
skipped += 1
|
||||
|
||||
|
||||
print(f"Compaction complete: {compacted} compacted, {skipped} skipped.")
|
||||
|
||||
# 3. Nightly SQLite WAL Checkpoint across all agent databases
|
||||
def checkpoint_wal_journals():
|
||||
print("=== Checkpointing SQLite WAL journals across all agent databases ===")
|
||||
import glob, sqlite3, os
|
||||
dbs = ["/home/node/.openclaw/state/openclaw.sqlite"] + glob.glob("/home/node/.openclaw/agents/*/agent/openclaw-agent.sqlite")
|
||||
wal_freed = 0
|
||||
for db in dbs:
|
||||
@@ -82,7 +169,7 @@ def main():
|
||||
if os.path.exists(wal):
|
||||
sz = os.path.getsize(wal)
|
||||
try:
|
||||
con = sqlite3.connect(db, timeout=15.0)
|
||||
con = sqlite3.connect(db, timeout=30.0)
|
||||
con.execute("PRAGMA wal_checkpoint(TRUNCATE);")
|
||||
con.close()
|
||||
wal_freed += sz
|
||||
@@ -90,6 +177,12 @@ def main():
|
||||
print(f" ✗ Error checkpointing {db}: {e}")
|
||||
print(f"WAL Checkpoint complete: {wal_freed / (1024*1024):.2f} MB merged to disk.")
|
||||
|
||||
def main():
|
||||
prewarm_page_cache()
|
||||
prune_stale_cron_sessions()
|
||||
compact_active_sessions()
|
||||
checkpoint_wal_journals()
|
||||
|
||||
if __name__ == "__main__":
|
||||
main()
|
||||
EOF
|
||||
|
||||
+1
-1
Submodule knowledge-wiki updated: dbae215a01...43d07dafa0
Reference in New Issue
Block a user