KB-5CB1
GPT vs Claude MCP Search Latency RCA + Cache Mitigation
15 min read Revision 1
reportscodexhistorical-sync
GPT vs Claude MCP Search Latency RCA + Cache Mitigation
Date: 2026-05-19 Agent: Codex Scope: Investigate GPT MCP search latency after Mac restart / cache refresh Mode: Read-only investigation; no data/vector/ingest mutation; no secret rotation; no Claude/default route changes
Progress
- Step 0: Read
.claude/skills/incomex-rules.md - Step 0: Read OR via
search_knowledge("operating rules SSOT") - Step 0: Read constitution via
search_knowledge("hiến pháp v4.0 constitution") - Step 0: Read mission-related knowledge via
search_knowledge(...) - Phase T0: Verify current state
- Phase T1: GPT vs Claude/default benchmark
- Phase T2: Live GPT request correlation
- Phase T3: Cache/state accumulation analysis
- Phase T4: Search pipeline timing analysis
- Phase T5: Embedding/retry check
- Phase T6: Route difference analysis
- Phase T7: Refresh/cache mitigation design
- Final report
Rules Evidence
- Skill:
.claude/skills/incomex-rules.md, 36 items, 8-step workflow. - OR:
knowledge/dev/ssot/operating-rules.md, search result version v7.58, 2026-05-01. - Constitution:
knowledge/dev/laws/constitution.md, search result version v4.6.3. - Relevant knowledge search: GPT Agent Data Connector Stability Fix, GPT MCP Connector Root Cause Timeline Investigation, AgentData MCP Timeout Investigation.
3 câu Tuyên ngôn
- Vĩnh viễn: RCA identifies layer split and durable controls: canary, log-only timing breakdown, optional embedding cache. It does not conclude "restart fixed it" as a root fix.
- Nhầm được không: Classification uses benchmark + nginx request/upstream + app
mcp_call+ live GPT tool correlation. - 100% tự động: Recommended path is synthetic canary plus server timing logs; manual fresh conversation/reconnect is only a workaround.
1. Executive verdict
GPT is currently slow primarily outside the Agent Data search backend when called through the ChatGPT/GPT MCP connector surface.
Strongest evidence:
Live GPT MCP tool call:
wall time from tool surface = 35.124s
payload usage.latency_ms = 676ms
nginx request_time = 0.802s
nginx upstream_response = 0.694s
app mcp_call total_ms = 688ms
app retrieval_ms = 676ms
serialize_ms = 0ms
status = 200
This is Case B: ingress reached VPS, upstream/app were low, but GPT/client-facing wall time was very high. That points to OpenAI connector/gateway/client/session overhead, not Qdrant/Postgres/backend search for that live case.
There is also one historical server-side retrieval spike still visible after restart:
2026-05-19 09:44:10 app mcp_call:
total_ms=11124 retrieval_ms=11107 serialize_ms=0
tool=search_knowledge profile=gpt-full limit=1
So the classification is mixed:
- Primary current issue: OpenAI GPT MCP connector/session/client overhead.
- Secondary rare issue: backend retrieval spike, likely embedding/OpenAI/Qdrant retry path, not serialization or compact response.
2. Benchmark GPT vs Claude/default
Benchmark scope: 5 queries, limits 1 and 5, 30 runs each, 3 routes. Full 4-limit matrix was reduced to the prompt-approved safer subset to avoid 1,800 embedding calls.
Routes:
gpt_public: public/gpt-mcp/<SECRET>/mcp->/mcp-gpt-fulldefault_public: public/api/mcpwith valid API header -> default/mcpgpt_internal: container-localhttp://127.0.0.1:8000/mcp-gpt-full
| route | query | limit | runs | p50 | p90 | p95 | max | spike>2s | spike>5s | errors | bytes |
|---|---|---|---|---|---|---|---|---|---|---|---|
| gpt_public | GPT MCP connector root cause | 1 | 30 | 364.8 | 4250.4 | 4497.8 | 7660.2 | 4 | 1 | 0 | 1349 |
| gpt_public | GPT MCP connector root cause | 5 | 30 | 261.3 | 357.1 | 373.9 | 393.5 | 0 | 0 | 0 | 4624 |
| gpt_public | backup postgres | 1 | 30 | 249.9 | 369.2 | 400.2 | 2975.0 | 1 | 0 | 0 | 1434 |
| gpt_public | backup postgres | 5 | 30 | 288.3 | 359.4 | 382.1 | 409.3 | 0 | 0 | 0 | 5614 |
| gpt_public | hiến pháp tự động | 1 | 30 | 288.4 | 571.4 | 665.0 | 819.3 | 0 | 0 | 0 | 2237 |
| gpt_public | hiến pháp tự động | 5 | 30 | 350.6 | 549.2 | 649.1 | 867.5 | 0 | 0 | 0 | 6845 |
| gpt_public | điều lệ vận hành Incomex | 1 | 30 | 297.1 | 386.7 | 399.8 | 430.0 | 0 | 0 | 0 | 1572 |
| gpt_public | điều lệ vận hành Incomex | 5 | 30 | 269.9 | 408.6 | 453.7 | 1760.2 | 0 | 0 | 0 | 7225 |
| gpt_public | zzzz-nonexistent-search-probe | 1 | 30 | 251.9 | 352.8 | 408.6 | 1597.9 | 0 | 0 | 0 | 1449 |
| gpt_public | zzzz-nonexistent-search-probe | 5 | 30 | 260.7 | 359.8 | 391.5 | 413.4 | 0 | 0 | 0 | 5644 |
| default_public | GPT MCP connector root cause | 1 | 30 | 246.1 | 348.5 | 366.3 | 391.7 | 0 | 0 | 0 | 5299 |
| default_public | GPT MCP connector root cause | 5 | 30 | 270.2 | 631.5 | 715.6 | 1392.7 | 0 | 0 | 0 | 5299 |
| default_public | backup postgres | 1 | 30 | 277.2 | 501.9 | 616.9 | 900.9 | 0 | 0 | 0 | 6272 |
| default_public | backup postgres | 5 | 30 | 281.2 | 403.5 | 455.0 | 565.3 | 0 | 0 | 0 | 6273 |
| default_public | hiến pháp tự động | 1 | 30 | 255.7 | 361.7 | 1009.1 | 1733.3 | 0 | 0 | 0 | 7995 |
| default_public | hiến pháp tự động | 5 | 30 | 254.1 | 374.5 | 395.6 | 905.1 | 0 | 0 | 0 | 7995 |
| default_public | điều lệ vận hành Incomex | 1 | 30 | 258.8 | 380.2 | 396.9 | 442.2 | 0 | 0 | 0 | 8270 |
| default_public | điều lệ vận hành Incomex | 5 | 30 | 237.5 | 286.3 | 318.1 | 576.6 | 0 | 0 | 0 | 8271 |
| default_public | zzzz-nonexistent-search-probe | 1 | 30 | 316.2 | 632.9 | 657.7 | 759.8 | 0 | 0 | 0 | 6280 |
| default_public | zzzz-nonexistent-search-probe | 5 | 30 | 262.6 | 385.7 | 401.7 | 439.6 | 0 | 0 | 0 | 6284 |
| gpt_internal | GPT MCP connector root cause | 1 | 30 | 170.3 | 256.8 | 271.5 | 278.2 | 0 | 0 | 0 | 1349 |
| gpt_internal | GPT MCP connector root cause | 5 | 30 | 163.3 | 272.1 | 978.3 | 1648.7 | 0 | 0 | 0 | 4624 |
| gpt_internal | backup postgres | 1 | 30 | 156.3 | 251.6 | 273.2 | 292.5 | 0 | 0 | 0 | 1434 |
| gpt_internal | backup postgres | 5 | 30 | 172.1 | 295.9 | 355.1 | 461.9 | 0 | 0 | 0 | 5614 |
| gpt_internal | hiến pháp tự động | 1 | 30 | 156.5 | 276.7 | 281.6 | 315.8 | 0 | 0 | 0 | 2237 |
| gpt_internal | hiến pháp tự động | 5 | 30 | 169.7 | 194.8 | 247.1 | 269.7 | 0 | 0 | 0 | 6845 |
| gpt_internal | điều lệ vận hành Incomex | 1 | 30 | 160.0 | 264.1 | 270.7 | 274.3 | 0 | 0 | 0 | 1572 |
| gpt_internal | điều lệ vận hành Incomex | 5 | 30 | 178.3 | 274.6 | 292.6 | 338.6 | 0 | 0 | 0 | 7225 |
| gpt_internal | zzzz-nonexistent-search-probe | 1 | 30 | 188.0 | 285.3 | 326.4 | 524.6 | 0 | 0 | 0 | 1449 |
| gpt_internal | zzzz-nonexistent-search-probe | 5 | 30 | 173.9 | 269.2 | 289.9 | 364.5 | 0 | 0 | 0 | 5643 |
Interpretation:
- GPT internal is fastest: p50 mostly 156-188ms.
- Default public is stable: no >2s spikes in 300 calls.
- GPT public had spikes in 2 groups: 5 total >2s, 1 >5s, all 200.
- Current ChatGPT/GPT tool-surface live call was far worse than curl/public benchmark: 35.124s wall for a 0.802s nginx request.
3. Live GPT correlation
Live tool call from this GPT session:
search_knowledge("zzzz-correlation-probe-20260519-1212", limit=1)
tool wall time: 35.124s
usage.latency_ms: 676
Nginx immediately after:
request_id=2e48233644c82527230b8a456092ee13
status=200 upstream_status=200
request_time=0.802 upstream_response_time=0.694
bytes_sent=1968
Agent Data log:
2026-05-19 10:12:37
mcp_call request_id=2e48233644c82527230b8a456092ee13
tool=search_knowledge profile=gpt-full status=200
total_ms=688 retrieval_ms=676 serialize_ms=0
response_bytes=1239 result_count=1 limit=1
Conclusion: request reached VPS; nginx and app were under 1s. The 35s user-visible wall is upstream of the VPS response path, i.e. OpenAI connector/gateway/client/session layer.
4. Timeline and regression hypothesis
Known timeline:
- Initial setup: GPT and Claude near parity, about 8/10.
- Before Mac restart: one GPT query showed
usage.latency_ms≈11107ms;backup postgreswas around 618ms. - After Mac restart / cache refresh: GPT same query improved to about 666ms;
backup postgresabout 216ms. - Current benchmark: public curl mostly 250-350ms p50; GPT live tool surface can still take 35s while VPS finishes <1s.
Evidence supports client/connector/session state as a strong suspect for the user-visible GPT slowdown. Evidence does not prove that Mac/browser cache is the sole cause, because:
- Public GPT curl route can spike too, but much less often.
- Backend had one historical 11s retrieval spike.
- The 35s live GPT case happened after restart and did not correspond to server slowness.
5. Backend timing breakdown
Current code path:
server.pystarts_t0before_retrieve_query_context().- In raw mode,
usage.latency_msincludes retrieval + raw reply build. - Retrieval calls
QdrantVectorStore.search(). search()does_embed(query), Qdrant search, dedupe, path/title rerank.- Compact GPT post-process happens after dispatch and is logged separately as
serialize_ms.
Current measured components:
Embedding-only, 30 same:
p50=146.2ms p95=247.2ms max=307.3ms spikes>2s=0
Embedding-only, 30 random:
p50=144.0ms p95=354.1ms max=553.6ms spikes>2s=0
Qdrant-only, 30 runs:
limit=5 p50=11.9ms p95=33.6ms max=69.5ms
limit=25 p50=25.2ms p95=72.6ms max=292.5ms
limit=50 p50=21.0ms p95=69.6ms max=88.8ms
Log summary over last 3h:
mcp_call_count=867
slow_total_gt2s=2
retrieval_gt2s=1
max_total_ms=11124
max_retrieval_ms=11107
max_serialize_ms=6
Current logs do not break retrieval_ms into embedding/qdrant/rerank/build, so the 11s server-side retrieval spike cannot be attributed precisely without a log-only timing patch.
6. Cache/state analysis
Client / ChatGPT app cache:
- Supported as strong suspect by restart improvement and the live 35s vs VPS 0.8s correlation.
- Needs user-side matrix to prove which client state: desktop vs browser, fresh vs old conversation, reconnect vs recreate connector.
OpenAI MCP connector/gateway cache:
- Strong suspect for live GPT 35s case.
- Tool surface is correct: app name
Incomex AgentData MCP — GPT Full b1gdc, 11 tools,get_document_chunk,delete_document,ingest_document. - Schema version/hash is correctly bumped:
gpt-agent-data-2026-05-14.2+b1gdc, hash52cfa07c350b. - Because schema is already fresh and public curl is fast, repeated schema bump is not the right fix.
VPS/app cache:
- Agent Data process uptime: started
2026-05-19T08:26:16Z, restart_count=0, about 2h at investigation start. server.pydirty/uncommitted on VPS: repomain...origin/main [ahead 17, behind 112], modifiedagent_data/server.py, backups present.- No evidence that process uptime currently degrades latency; 50 repeated GPT public searches did not trend upward.
Query embedding cache:
- No query embedding cache exists in search path.
- Cached objects: Qdrant client and OpenAI client only.
- Adding query embedding LRU would reduce dependency on OpenAI embeddings for repeated/common queries, but would not fix OpenAI connector/client overhead when VPS already finishes quickly.
Repeated 50 GPT public same-query test:
| test | condition | p50/avg | max | trend | conclusion |
|---|---|---|---|---|---|
| repeated 50 | same query, same public GPT route, limit=1 | first10 avg 317.4ms, last10 avg 426.1ms | 1572.2ms | no monotonic rise | no server-side accumulation reproduced |
| live GPT tool | same connector surface from GPT session | wall 35.124s, VPS 0.802s | 35.124s | isolated connector/client wait | connector/client overhead reproduced |
7. Root cause classification
Chosen classification: mixed causes.
- OpenAI connector/session/client overhead: primary current cause. Proven by live GPT wall 35.124s while nginx/app finished <1s.
- Backend retrieval spike: secondary rare cause. Proven by app log total/retrieval 11.1s at 2026-05-19 09:44:10.
- GPT route post-processing: not root cause.
serialize_msmax was 6ms and compact response is small. - Qdrant/Postgres: not supported for current case. Qdrant-only p95 <80ms in local benchmark; no PG hydrate in search path observed.
- Wrong/stale app instance: not current root cause. Endpoint advertises correct b1gdc schema/tool surface.
8. Fix plan
Immediate operational workaround:
- Use a fresh conversation at the start of a heavy work day or after long MCP-heavy sessions.
- If GPT tool call wall time >5s while
usage.latency_msis low, reconnect/recreate connector or restart/refresh ChatGPT desktop/web client. - Do not bump schema just to refresh; only bump schema when tool contract changes.
Safe technical fix:
- Add log-only breakdown behind no behavior change:
embedding_msqdrant_msrerank_msbuild_msserialize_mstotal_msopenai_embedding_retriesopenai_embedding_error/statusquery_hash, not raw query
- Add canary cron every 5-15 minutes:
- initialize
- tools/list
search_knowledgelimit=1 via GPT public route- default public
/api/mcpwith API key - internal
/mcp-gpt-full - log p50/p95/max and classify: public slow vs internal slow vs GPT UI-only slow.
Durable fix:
- Query embedding LRU cache:
- normalized query hash key
- TTL 1-24h
- max entries with eviction
- log hit/miss and avoided embedding_ms
- helps both GPT and default route; does not fix OpenAI connector overhead.
- Consider timeout/retry tuning only after timing logs prove embedding retries.
Rollback:
- Log-only patch rollback: remove timing fields; no data impact.
- Canary rollback: disable cron entry; no data impact.
- Embedding cache rollback: disable env flag or set max entries 0; no vector/data mutation.
9. Recommendation
- Daily fresh conversation: yes as operational workaround for GPT MCP-heavy days.
- Recreate connector when spike: yes only when
usage.latency_msis low but GPT wall time is high or no nginx ingress appears. - Add query embedding cache: yes, but as backend resilience/performance improvement, not as the primary connector-overhead fix.
- Add canary: yes, highest value immediate technical control.
- Add log-only breakdown: yes before any larger fix.
- Continue main work: only if GPT latency is tolerable after fresh session; otherwise add canary + log-only breakdown first.
Step 0-6 Report Evidence
- Step 0 foundation: read skill, OR, constitution, mission-related knowledge. Versions listed above.
- Step 1-2 design: mission is investigation/read-only; no feature/collection design, no DOT/schema change.
- Step 3 code: no production code change; report file only.
- Step 4 deployment: N/A, no patch deployed.
- Step 5 verify: production endpoint verified with real JSON-RPC output summarized above.
- Step 6 report: this file is the report at
knowledge/current-state/reports/. - OR/TD update: not needed; no operating rule changed. Recommended future TD: canary + log-only timing patch if approved.