agentscope-ai / agentscope-ai/QwenPaw
[Performance] v2.0 introduces ~2s fixed overhead per simple conversational reply vs v1.x
- Lingua principale
- Python
- Stelle
- 34.9k
- Fork
- 3.1k
- Merge medio
- 1g 15h
- PR unite (30g)
- 225
Descrizione
## Summary
Upgrading from v1.1.12.post2 to v2.0.0.post3 introduces approximately **2 seconds of fixed overhead** on every simple conversational reply (e.g. "what's the weather today"), independent of model latency. This overhead is absent in v1.x and is caused by architectural changes in the request processing pipeline.
We confirmed this by running v1.x and v2.0 on the **same machine** (Hong Kong, 2-core / 3.4 GB RAM) with the **same model** (DeepSeek V4 Flash) and the **same WeChat Enterprise channel session**. After downgrading from v2.0 back to v1.x on the same machine, lightweight response times returned to v1.x levels, isolating the software version as the primary cause.
## Measured Data
| Environment | Median response time (simple chat) | Sample size |
|---|---|---|
| v1.1.12.post2 on Shanghai (8-core, 30 GB) | ~3.5s | 15 messages |
| **v2.0.0.post3 on Hong Kong** (2-core, 3.4 GB) | **~5.8s** | 12 messages |
| **v1.1.12.post2 on Hong Kong** (same machine) | **~3.6s** | 8 messages |
Response time = wall clock from user message timestamp to first `model_turn` assistant message. The ~2.2s delta between v2.0 and v1.x on the same machine is consistent across samples. The model API latency (~1–3s for DeepSeek) is identical in both versions.
## Root Cause Analysis
We traced the critical path from message arrival to first model API call across both versions. The overhead comes from four sources:
### 1. Scroll Context Manager — largest contributor (~200–800ms per reasoning step)
v2.0 defaults to `strategy: "scroll"` (`LightContextConfig`), which runs `compress_context()` before **every** reasoning step:
- **`_persist_guarded()` → SQLite write-through** to `history.db` (~20–50ms)
- **`prepare_model_input()`** (~10ms)
- **`model.count_tokens()`** — precise token counting, potentially a **remote API tokenizer call** (~50–200ms). In v1.x, `EstimatedTokenCounter` used local byte-length heuristics (~1ms).
- **Eviction index maintenance** + optional LLM headline generation for un-headlined spans
Key bottleneck: `model.count_tokens()` in the scroll path. When the model provider doesn't ship a local tokenizer, this becomes a network round-trip on every reasoning step.
**Source:** `src/qwenpaw/agents/context/scroll/manager.py` — `compress()` method, lines 342–561.
### 2. Per-request Agent rebuild (~100–300ms)
v1.x's `Runner` builds the agent once at startup and reuses it. v2.0's `Runtime` executes a full `AgentBuilder.build()` for **every request**: `load_agent_config()` → `resolve_effective_skills()` → `_init_governor()` → `create_model_and_formatter()` → `_build_scroll_components()` (SQLite open) → `build_toolkit()` → `build_prompt()` (reads AGENTS.md etc.) → `_build_middlewares()`.
**Source:** `src/qwenpaw/runtime/runtime.py` line 105; `src/qwenpaw/runtime/builder.py` — `build()` method.
### 3. Middleware onion model (~20–70ms per step)
v2.0 wraps every reasoning step through multiple middleware layers: `ToolResultPruningMiddleware`, `ToolCoordinatorMiddleware`, `MemoryMiddleware`, `LangfuseToolSpanMiddleware`, plus plugin middlewares. While each layer is lightweight, the aggregate adds up — especially `MemoryMiddleware.on_model_call()` which checks `auto_memory_search` state on every model call.
### 4. Session state deserialization (~50–200ms)
v2.0 uses Pydantic `AgentState.model_validate()` + `_sanitize_tool_messages()` (full context traversal) + scroll `load_state()` to rebuild the eviction index. v1.x simply loaded a JSON dict.
### Comparison: critical path waterfall
```
v2.0 (simple chat, no tools): v1.x (simple chat, no tools):
Channel receives message Channel receives message
├ Runtime 8-phase hooks ~10ms ├ Runner.stream_query() ~5ms
├ AgentBuilder.build() ~100-300ms ├ Agent reuse (pre-built) 0ms
├ load_state_dict() ~50-200ms ├ Session JSON load ~20-50ms
├ compress_context() ├ LightContextManager
│ ├ sanitize_tool_messages ~5ms │ └ EstimatedTokenCounter ~10-30ms
│ ├ persist → SQLite ~20-50ms ├ memory pre_reply ~0-10ms
│ ├ prepare_model_input ~10ms └ Model API call ~1-3s
│ └ model.count_tokens() ~50-200ms
├ MemoryMiddleware ~5-10ms Total fixed overhead: ~50-100ms
└ Model API call ~1-3s
Total fixed overhead: ~400-1500ms
```
## Environment
- **QwenPaw versions:** v1.1.12.post2 and v2.0.0.post3
- **OS:** Linux (Docker on Ubuntu)
- **Machine:** 2-core CPU / 3.4 GB RAM (Hong Kong)
- **Channel:** WeChat Enterprise (WecomChannel)
- **Model:** DeepSeek V4 Flash (deepseek.com API)
- **Context strategy:** scroll (default)
## Suggested Improvements
In priority order:
1. **Local token count fallback for scroll.** When the model provider doesn't offer a local tokenizer, fall back to the byte-length estimate (`EstimatedTokenCounter`) used in v1.x, instead of making a remote API call on every `compress_context()`. The precise count can run lazily or on a background timer.
2. **Agent caching / reuse across requests.** The per-request `AgentBuilder.build()` is the second largest contributor. Consider caching the built agent per session (or per agent profile) and invalidating only when configuration changes, similar to v1.x's `Runner` pattern.
3. **Lazy scroll persistence.** Instead of write-through on every `on_save`, batch SQLite writes or defer them to post-reply, so the first reasoning step isn't blocked by disk I/O.
4. **Make `strategy: "scroll"` vs `"native"` a more visible configuration.** Users who don't need long-conversation recall (the primary benefit of scroll) should be able to opt into the faster `native` strategy easily. Currently this requires editing the agent profile YAML.
## Workarounds
- Set `light_context_config.strategy: "native"` in the agent profile to bypass scroll entirely (loses `recall_history` and `history.db` durability).
- Set `scroll_config.summarize_unheadlined_evictions: false` to avoid extra LLM calls during eviction.
- Downgrade to v1.x if response latency is critical.
## Related Issues
- #5218 — Context compaction freeze (same `compress_context` path, but about missing timeouts rather than baseline overhead)
- #6193 — MCP drivers sequential startup (similar "serial where parallel is possible" pattern)
- #6144, #6145 — ReMe startup memory/performance (closed, addressed ReMe init overhead)
Guida per i contributori
Apri la guida per i contributori
Valutazione
Questa issue non è ancora stata valutata.