[BUG] auto-recall timeout 在首次啟動或多進程 session 時容易發生

[jlin53882]

問題描述

在以下兩種情境下，memory-lancedb-pro 的 auto-recall 功能容易出現 timeout 錯誤：

1. 首次啟動 OpenClaw Gateway：啟動時 retriever.test() 或 auto-recall 經常 timeout
2. 多進程 session 同時執行：當有多個 session 並發運行時，auto-recall 容易超時

錯誤訊息範例

[plugins] memory-lancedb-pro: startup checks failed: Error: retriever.test() timed out after 8000ms

[plugins] memory-lancedb-pro: auto-recall timed out after 60000ms

capture failed: ENOENT: no such file or directory, lstat '.memory-write.lock'

環境資訊

• memory-lancedb-pro 版本：1.1.0-beta.10
• OpenClaw 版本：v2026.4.x
• Node 環境：Windows

根因分析

經過調查，問題出在 schema 限制。

目前的 openclaw.plugin.json 中，autoRecallTimeoutMs 的 schema 限制為：

"autoRecallTimeoutMs": {
  "type": "integer",
  "minimum": 500,
  "maximum": 60000,  // ← 這裡限制最大為 60 秒
  "default": 5000,
  "description": "Timeout for the entire auto-recall pipeline..."
}

問題：

• 預設值只有 5 秒（default: 5000）
• 即使使用者想要增加 timeout，schema 的 maximum 限制為 60000ms（60 秒）
• 在首次啟動或多進程並發的場景下，60 秒不夠用

緩解措施（需要官方修改）

建議修改 openclaw.plugin.json

將 schema 的 maximum 從 60000 調整為更大的值：

"autoRecallTimeoutMs": {
  "type": "integer",
  "minimum": 500,
  "maximum": 300000,  // 從 60000 改為 300000（300 秒）
  "default": 120000,   // 預設值也建議從 5000 改為 120000（120 秒）
  "description": "Timeout for the entire auto-recall pipeline..."
}

調整理由

設定	原始值	建議值	理由
maximum	60000 (60秒)	300000 (300秒)	允許使用者在需要時設定更長 timeout
default	5000 (5秒)	120000 (120秒)	首次啟動和多進程場景需要更長的 timeout

為什麼這樣調整可以解決問題

1. 首次啟動：首次載入 LanceDB 資料和建立連線需要更長時間
2. 多進程並發：當有多個 session 同時執行時，lock 競爭和資源排程會拉長處理時間
3. 增加緩衝：120 秒的預設值提供足夠緩衝應對常見情境，而 300 秒的上限允許特殊情況進一步調整

期望行為

• schema 的 maximum 應該允許至少 180-300 秒的 timeout
• default 值應該足夠應對首次啟動和多進程場景（建議 120 秒）
• timeout 應該是可配置的，並提供足夠的彈性

[jlin53882]

問題更新分析（根因已更正）

⚠️ 注意：原始 issue 描述中的「schema 限制為根因」是錯誤判斷。實際根因如下。

---

觸發情境

情境	觸發頻率	說明

|
eset /
ew 指令執行 | 高 | 幾乎每次都觸發 |
| 首次啟動 OpenClaw Gateway | 中 | 首次建立連線較慢 |
| 多進程 session 並發 | 中 | 多個 agent 同時競爭 |

---

三層問題鏈

第一層｜記憶層（Lock Race）

\
reset/new 執行
→ 寫入 lock 被卡住（LLM enrichment + DB 寫入持有時間長）
→ 其他 agent 的 store.search() 無法取得 lock
→ auto-recall timed out
→ 記憶來不及 inject
\\

對應修復：PR #517 + PR #639

PR	修復內容
#517	proper-lockfile 重試參數優化（minTimeout=1000, maxTimeout=30000）+ onCompromised callback + 主動清除 >5 min stale lock
#639	Two-phase processing：LLM enrichment 移到 lock 外，寫 DB 才拿 lock（N locks/entry → 1 lock/batch）

---

第二層｜框架層（Carbon ctx.waitUntil）

\
InteractionEventListener 收到 command
→ 傳入 ctx = {}（空物件）
→ ctx.waitUntil 是 undefined
→ Carbon Client.handleInteraction() 永遠執行 await promise
→ 這個 await blocking 了整個 InteractionEventListener.handle()
→ EventQueue listener timeout = 120 秒
→ reset/new 因為需要 reflection（5-10s）+ 其他處理，一定跑超過 120 秒
→ timeout error
\\

對應修復：需要修改 Carbon framework 本身（@buape/carbon）

---

第三層｜推論層（硬體）

\
Ollama 模型未設定在 GPU 執行
→ 推論速度過慢
→ 拉長整體處理時間
→ 加劇 lock 競爭
\\

對應修復：Ollama 設定調整（硬體配置，非 PR）

---

完整問題鏈總圖

┌─────────────────────────────────────────────────────────────┐ │ reset / new 指令 │ └─────────────┬───────────────────────────────────────────────┘ │ ▼ ┌─────────────────────────────────────────────────────────────┐ │ Layer 1：Carbon Framework（ctx.waitUntil = undefined） │ │ → await promise blocking InteractionEventListener │ │ → 一定跑超過 120 秒 timeout │ └─────────────┬───────────────────────────────────────────────┘ │ ▼ ┌─────────────────────────────────────────────────────────────┐ │ Layer 2：Lock Race（store.ts） │ │ → 長時間持有 lock │ │ → 其他 agent 無法搜尋 → auto-recall timed out │ │ → PR #517（retries）+ PR #639（two-phase）修復 │ └─────────────┬───────────────────────────────────────────────┘ │ ▼ ┌─────────────────────────────────────────────────────────────┐ │ Layer 3：Ollama 硬體 │ │ → 模型未跑 GPU → 推論慢 │ │ → 加劇 lock 競爭 │ │ → 需手動設定 Ollama GPU │ └─────────────────────────────────────────────────────────────┘

---

結論

項目	狀態
PR #517	修復 Layer 2 的 lock 競爭
PR #639	修復 Layer 2 的 lock 持有時間過長
Carbon framework 修改	需另外提 PR 到 @buape/carbon
Ollama GPU 設定	需手動調整

[jlin53882]

完整測試分析報告

🔍 測試與程式碼調查結果

1. 各環節實際延遲測量

環節	實測延遲	結論
Ollama embedder (jina-v5-retrieval-test)	130-170ms	✅ 正常
Reranker (warm, cache hit)	2-6ms	✅ 極快
Reranker (cold)	200-300ms	✅ 正常
LanceDB 向量搜尋 (7052 rows)	300-700ms	✅ 正常
理論總和	< 2 秒	-

2. Lock 檔案狀態監控

\
.lock 年齡: 496-577 秒（持續更新中）
proactive cleanup 門檻: 300 秒
超出門檻: 196-277 秒
mtime 完全不變 (delta=0.000s)
\\

發現：雖然 lock 年齡遠超 cleanup 門檻，但 mtime 完全沒有變化，顯示 lock 可能被某個 holder process 持續持有。

3. 程式碼分析：runWithFileLock 使用範圍

\\ ypescript
// store.ts:212 - 以下操作使用 runWithFileLock:

• store() // 寫入
• importEntry() // 寫入
• delete() // 刪除
• update() // 更新
• patchMetadata() // 更新
• bulkDelete() // 刪除

// 以下操作不需要 lock:

• vectorSearch() // 讀取
• bm25Search() // 讀取
• hasId() // 讀取
• getById() // 讀取
• list() // 讀取
  \\

結論：讀取操作（auto-recall 使用的 vectorSearch/bm25Search）不需要 lock，lock 只保護寫入操作。

📊 Log 分析

02:00:55 [injecting 3 memories] - SUCCESS 02:02:13 [injecting 1 memories] - SUCCESS 02:06:06 [injecting 3 memories] - SUCCESS 02:06:40 [injecting 3 memories] - SUCCESS ✓

所有成功的 injection 都顯示 auto-recall 大多數時候是正常的。

Timeout 時的 pattern：

• 先有 governance filters log → 17 秒後 timeout
• 這代表 governance filter 執行完成（early return），但 overall timeout 仍然被觸發

💡 真正的根因（推測）

根據測試和程式碼分析，最可能的原因：

1. 並發 lock 競爭：多個 agent 同時進行需要 lock 的寫入操作（auto-capture、smart-extractor、patchMetadata）。

2. patchMetadata 在 recallWork 結束後執行（store.ts:2556-2583），每個 selected item 都要 write，可能造成並發阻塞。

3. 非預期的長時間操作：在某些條件下（例如系統負載高、大量記憶體），某個環節變慢。

🧪 已產出的測試腳本

1. reranker_pipeline_test.py - 測量各環節延遲（已驗證所有環節 < 2 秒）
2. auto_recall_bottleneck_test.py - 並發測試
3. file_lock_bottleneck_diagnostic.py - Lock 診斷

✅ 已驗證有效的緩解方案

設定 �utoRecallTimeoutMs 為較大的值（例如 120000ms = 120 秒）可以解決問題。

🔧 根本修復方向

1. 將 read 操作完全移出 runWithFileLock（已經是這樣，但需要確認）
2. 優化 patchMetadata 的並發行為（例如 batch update）
3. 添加 per-step timing instrumentation 以識別真正的瓶頸

📋 總結

• 60 秒 timeout 不是單一環節延遲造成
• embed/rerank 本身很快（< 2 秒）
• 真正瓶頸可能是：並發的寫入操作在 lock 內執行太久
• 建議增加 timeout 配置並添加 instrumentation 追蹤

[jlin53882]

更新：PR #639 機制觀察

已在 Issue #632 留言詳細分析，這裡摘要：

觀察到的問題

• lock 年齡: 496-577 秒（持續更新中）
• proactive cleanup 門檻: 300 秒
• 超出門檻: 196-277 秒
• mtime 完全不變 (delta=0.000s)

PR #639 程式碼（已正確實作，但沒效）

1. Proactive cleanup (store.ts:233): ageMs > 300000ms (5分鐘) → 沒刪除！
2. Stale detection (store.ts:245): stale: 10000ms → 沒觸發！
3. Retries (store.ts:242): 10次, max 30s → 有重試但沒解決

根本原因

1. Stale detection 假設「10秒沒更新 = holder crash」，但 holder 可能活著只是很慢
2. Proactive cleanup 只在新 process 嘗試取得 lock 時才會執行
3. 單元測試沒有並發，所以測試通過但生產會爆

建議方案

方案 2：改用更好的 lock 機制

不要用 file lock（lockfile npm 套件在 Windows 上有問題），改用：

• Redis 分散式 lock
• 或資料庫內建 lock（如 PostgreSQL advisory locks）
• 或使用 Redis SET NX + PX 作為 lock

測試建議

需要寫並發壓力測試：
it('should handle 10 concurrent writes', async () => {
const promises = Array(10).fill(null).map(() => store.store(memory));
const results = await Promise.allSettled(promises);
// 至少 80% 成功
});

[jlin53882]

🔥 根本原因確認！

觸發問題的設定

James 確認：當開啟以下兩個設定時才會觸發問題：

設定	預設值	說明
captureAssistant	true	每次 AI 回覆都寫入 DB
sessionMemory.enabled	true	每個 session 寫入 DB

為什麼會觸發

當這兩個設定打開時：

• 每次 auto-capture → 寫入 DB → 搶 lock
• 每個 session → 寫入 DB → 搶 lock

當多個寫入同時發生（reset/new 或多個 agents）→ 高並發寫入 → lock contention → 55-56% 失敗

當這兩個設定關閉時：

• 很少寫入
• 低並發
• 大部分時候正常運作

測試驗證

我們的單元測試證實：

• 低並發 (3-5 ops)：✅ 100% 成功
• 高並發 (20-50 ops)：❌ 55-56% 失敗

結論

不是 PR #639 的問題，而是：

1. 這兩個設定導致頻繁寫入
2. 寫入觸發 lock 競爭
3. 高並發時 lock 機制撐不住

緩解方案

1. 關閉這些設定（目前解法）
2. 改用 Redis lock（根本修復）
3. 增加 lock 的並發容忍度

[jlin53882]

📊 完整並發測試結果

測試數據

並發數	成功率	耗時
3	100%	638ms
5	100%	3s
10	100%	26s
12	92%	31s
15	73%	31s
20	55%	31s
50	56%	31s
200	6%	31s

🔥 根本原因

• File lock 機制無法應付高並發
• 超過 15 個並發寫入就開始失敗
• 200 個並發只有 6% 成功
• 30 秒 timeout 後，大部分 operation 被放棄

💡 需要的修復

1. Redis 分散式 lock（根本解決）
2. 增加重試次數 + 指數退避（短期緩解）
3. 分離讀寫 lock（讀不需要 lock）

測試環境

• 單元測試在本地 memory-lancedb-pro-pr639 repo
• 使用 node --test 框架
• 模擬真實的 store.store() 操作

[jlin53882]

Related

New solution proposed in Issue #659: Redis Distributed Lock

This continues the work from #643 with:

• Complete Redis Lock implementation
• 10 edge case unit tests
• 15x improvement (6% -> 97.5% success rate at 200 concurrent)

See Issue #659 for details.

[jlin53882]

Update

This issue has been addressed in PR #662: feat: Redis distributed lock for high concurrency

Solution

Implemented src/redis-lock.ts with:

• Token-based lock acquisition (prevents race conditions)
• Lua script for safe release (only releases if token matches)
• Graceful fallback: Returns no-op lock when Redis unavailable
• 60s TTL with exponential backoff

Test Results

Concurrency	File Lock	Redis Lock
10	100%	100%
20	55%	100%
50	22%	100%
200	6%	97.5%

15x improvement!

PR

#662