Skip to content

v0.9.0 Windows: search_code times out after 180s; related parallel call shows ~180s dispatch wait; diagnostics lack per-call timing #965

Closed

Description

@ertankucukoglu

Version

0.9.0

Platform

Windows (x64)

Install channel

GitHub release archive / install.sh / install.ps1

Binary variant

standard

What happened, and what did you expect?

After upgrading to codebase-memory-mcp 0.9.0 on 2026-07-08, search_code still times out on some calls.

The main failing call was:

Tool: codebase-memory-mcp/search_code

Arguments:
{
"project": "D-1-Freelancer-Sarel",
"pattern": "TEtaWriteInvoices",
"file_pattern": "*.pas",
"limit": 20,
"context": 2,
"mode": "compact"
}

Actual result:

tool call error: tool call failed for codebase-memory-mcp/search_code
Caused by:
timed out awaiting tools/call after 179.9999998s

Expected result:

  • search_code in compact mode should complete before the configured 180s client timeout for this query, or return a structured internal timeout/partial result before the outer MCP timeout fires.
  • If the client cancels the request at timeout, the server should stop expensive work promptly.
  • Diagnostics should show enough per-call timing to distinguish queue/dispatch wait, grep/text search time, graph lookup/enrichment time, serialization time, and cancellation/timeout handling.

Closest existing issues checked:

Reproduction

Reproduction is not so easy. It has to use same project in different codex consoles and make a search about the same time or long searches close to each other. However, also happens on searching totally different projects.

Observed through Codex using the MCP tool call below:

{
"tool": "codebase-memory-mcp/search_code",
"arguments": {
"project": "D-1-Freelancer-Sarel",
"pattern": "TEtaWriteInvoices",
"file_pattern": "*.pas",
"limit": 20,
"context": 2,
"mode": "compact"
}
}

Observed timeline from Codex logs:

  • 2026-07-08 16:57:07: search_code call started.
  • 2026-07-08 17:00:07: timeout reported.
  • Codex call id: call_89dzQ5typQFKYOtrSMLAyLVf.
  • Logged total duration: approximately 180308 ms.

There was also a nearby/parallel search_code call:

{
"tool": "codebase-memory-mcp/search_code",
"arguments": {
"project": "D-1-Freelancer-Sarel-ZEntegre-ServerService",
"pattern": "TEtaWriteInvoices",
"file_pattern": "*.pas",
"limit": 20,
"context": 2,
"mode": "compact"
}
}

That second call completed after approximately 225585 ms, with Codex logging:

  • dispatch_duration_ms = 180248
  • handler_duration_ms = 45337
  • total_duration_ms = 225585

This suggests the timeout may involve request queueing/serialization or dispatch wait consuming most of the client timeout budget before the actual handler work starts.

Logs

Codex log source:

C:\Users\Ertan\.codex\logs_2.sqlite

Relevant extracted log facts:

- 2026-07-08 16:57:07:
  ToolCall: mcp__codebase_memory_mcpsearch_code
  {"project":"D-1-Freelancer-Sarel","pattern":"TEtaWriteInvoices","file_pattern":"*.pas","limit":20,"context":2,"mode":"compact"}

- 2026-07-08 17:00:07:
  MCP tool call error:
  "tool call error: tool call failed for `codebase-memory-mcp/search_code`
  Caused by:
      timed out awaiting tools/call after 179.9999998s"

- 2026-07-08 17:00:07:
  tool_name=mcp__codebase_memory_mcpsearch_code
  call_id=call_89dzQ5typQFKYOtrSMLAyLVf
  dispatch_duration_ms=281
  handler_duration_ms=180027
  total_duration_ms=180308

- 2026-07-08 17:00:52:
  tool_name=mcp__codebase_memory_mcpsearch_code
  call_id=call_NRhigzvTQIXSxTPpux4JfzIq
  dispatch_duration_ms=180248
  handler_duration_ms=45337
  total_duration_ms=225585

Diagnostics trajectory (memory / performance / leak issues)

Server diagnostics are active and files are being written under:

C:\tem\codebase-memory-mcp-diagnostics\live

Examples:

- cbm-diagnostics-63624.ndjson
- cbm-diagnostics-85084.ndjson
- cbm-diagnostics-9276.ndjson

However, the live diagnostics currently contain process metrics only:

- uptime_s
- rss
- peak_rss
- committed
- peak_committed
- page_faults
- fd
- queries

They do not include per-tool request details such as tool name, request id,
project, pattern, file_pattern, mode, limit, phase timings, queue wait,
grep/search time, graph enrichment time, result counts, cancellation, or timeout
state.

Current observed process state on 2026-07-08 around 17:22 local time:

- PID 9276
  - start: 2026-07-08 17:08:16
  - current RSS: 19156992 bytes
  - peak RSS from diagnostics: 688541696 bytes
  - peak committed: 694956032 bytes
  - queries: 8

- PID 63624
  - start: 2026-07-08 16:03:48
  - current RSS: 15962112 bytes
  - peak RSS from diagnostics: 81911808 bytes
  - peak committed: 36478976 bytes
  - queries: 86

- PID 85084
  - start: 2026-07-08 15:46:16
  - current RSS: 19673088 bytes
  - peak RSS from diagnostics: 40558592 bytes
  - peak committed: 53735424 bytes
  - queries: 10

No monotonic leak is proven from these samples, but multiple long-lived
codebase-memory-mcp.exe processes were present at the same time, and one process
showed a transient peak RSS of about 657 MiB.

Project scale (if relevant)

Primary failing indexed project: Project: D-1-Freelancer-Sarel Counts from get_graph_schema: - Total node count by summed labels: 3355679 - Total edge count by summed edge types: 3410676 - File nodes: 184268 - Folder nodes: 1017 - Module nodes: 183799 - Function nodes: 18395 - Method nodes: 1438 - Class nodes: 2962315 Top File.extension counts from graph: - .xml: 181761 - .xsd: 903 - .pas: 445 - .csv: 174 - .py: 120 - .md: 102 - .ini: 98 - .java: 95 - .json: 91 - .sql: 87 - .res: 86 - .html: 83 - .css: 58 - .inc: 29 - .xsl: 24 Filesystem cross-check for D:\1-Freelancer\Sarel, excluding .git/.svn, __history, and __recovery: - Total files: 232614 - .pas files: 446 - .pas line count: approximately 239451 Secondary nearby project involved in the parallel/nearby call: Project: D-1-Freelancer-Sarel-ZEntegre-ServerService Counts from get_graph_schema: - Total node count by summed labels: 238 - Total edge count by summed edge types: 499 - File nodes: 11 - Module nodes: 11 - Function nodes: 159 - Class nodes: 35 - Variable nodes: 21 File.extension counts from graph: - .pas: 6 - .sql: 2 - .res: 2 - .inc: 1

Confirmations

  • I searched existing issues and this is not a duplicate.
  • My reproduction uses shareable code (a dummy snippet or a public OSS repository), not proprietary code.

Activity

  1. ertankucukoglu commented on Jul 8, 2026

    @ertankucukoglu
    ContributorAuthor

    D-1-Freelancer-Sarel: 3,355,679 nodes / 3,410,676 edges / 184,268 files;
    related small project D-1-Freelancer-Sarel-ZEntegre-ServerService: 238 nodes / 499 edges / 11 files

  2. added
    stability/performanceServer crashes, OOM, hangs, high CPU/memory
    windowsWindows-specific issues
    priority/highNeeds near-term maintainer attention; high-impact bug, regression, safety issue, or release blocker.
    on Jul 8, 2026
  3. added this to the 0.9.1-rc milestone on Jul 8, 2026
  4. DeusData commented on Jul 8, 2026

    @DeusData
    Owner

    Thanks for the very concrete 0.9.0 timing report. Triage: high-priority Windows/search_code performance and diagnostics bug. This is distinct from handshake-only timeout reports: the dispatch-vs-handler timing, huge graph size, compact search arguments, and multiple process observation make it actionable. Added to 0.9.1-rc. A fix should cover bounded per-tool timeouts or partial results, cancellation when the client times out, and per-call timing diagnostics for queue wait, text search, graph enrichment, serialization, and result counts.

  5. DeusData commented on Sep 26, 2026

    @DeusData
    Owner

    Thank you, @ertankucukoglu, for such a precise timing report! The dispatch-versus-handler split and the exact arguments made it actionable.

    Since v0.11.0 (31bdd4d), a search_code scan has its own execution deadline. It returns a structured request_timeout error well inside a 180 s client timeout instead of running until the client gives up, and a client cancellation stops the in-flight request. Could you try v0.11.0 on the same large project? If a call still exceeds the client timeout, or you see the dispatch wait again, please paste the matching mcp.request log lines.

  6. added
    awaiting-reporterWaiting on the reporter for info/repro; stale bot will warn then close
    on Sep 26, 2026
  7. ertankucukoglu commented on Sep 26, 2026

    @ertankucukoglu
    ContributorAuthor

    I tested with codebase-memory-mcp 0.11.0 on Windows x64. Both the binary and the running daemon report 0.11.0. The original search_code query against D-1-Freelancer-Sarel completed in 4.7 seconds, returning 15 results and 47 grep matches. I also ran it concurrently with the query against D-1-Freelancer-Sarel-ZEntegre-ServerService; the large-project call completed in 2.3 seconds and the smaller one in 0.3 seconds. Both mcp.request entries have status=ok (duration_ms=2032 and 250). I did not reproduce a client timeout or the approximately 180-second dispatch wait. This was a short test from one session; I will provide matching log lines if the intermittent issue recurs.

  8. github-actions commented on Sep 26, 2026

    @github-actions

    Thanks for the report! To move this forward we need a bit more so we can reproduce it ourselves:

    • the codebase-memory-mcp --version you're on
    • the exact steps or command you ran
    • a public repo (or a small dummy snippet) that shows the problem — please don't paste proprietary code

    Once that's here we'll pick it straight back up. Heads-up: issues left awaiting-reporter are automatically closed after a few weeks of silence, but a comment reopens the door anytime.

  9. github-actions commented on Oct 18, 2026

    @github-actions

    This issue has been waiting on more information for 21 days (a version, exact steps, or a public repro), so it's now marked stale. It will not be closed automatically — a maintainer reviews stale issues by hand. Adding a comment with the details clears the label and puts it straight back in the queue. We're happy to pick it back up the moment we can reproduce it.

  10. added
    staleNo activity after an info request; will be closed soon
    on Oct 18, 2026
  11. ertankucukoglu commented on Oct 18, 2026

    @ertankucukoglu
    ContributorAuthor

    Thanks for following up. I tested the requested v0.11.0 on the original large project and posted the results on 26 September:
    #965 (comment)

    Both the binary and running daemon reported 0.11.0. The original search_code query completed in 4.7 seconds, returning 15 results and 47 grep matches. Concurrent searches against the large and small projects completed in 2.3 and 0.3 seconds, respectively, with both mcp.request entries reporting status=ok. Neither the 180-second client timeout nor the approximately 180-second dispatch wait recurred in that test.

    I also ran an additional synthetic Windows test on v0.11.0: all 50 search calls completed successfully across ten rounds of each of three scenarios (single search, two independent sessions on the same project, and two independent sessions on different projects).

    I do not have a reproducible failing case for v0.11.0. Please feel free to close this issue if these results cover the intended fix. Thanks for investigating it.

  12. removed
    staleNo activity after an info request; will be closed soon
    on Oct 19, 2026
  13. removed
    awaiting-reporterWaiting on the reporter for info/repro; stale bot will warn then close
    on Oct 19, 2026
  14. DeusData commented on Oct 19, 2026

    @DeusData
    Owner

    Thank you for both retests, including the additional concurrent-session cases. You already supplied the requested version and results; the repeated information request was unnecessary. I have removed awaiting-reporter. There is no further rerun requested from you now—the remaining resolution decision is on the maintainer side, and your successful tests are recorded without claiming they prove every intermittent case impossible.

  15. DeusData commented on Oct 27, 2026

    @DeusData
    Owner

    Thanks again, @ertankucukoglu, for the precise report and both retests. The per-call timing split from #2372 is now on main in 69b26df. Every mcp.request log line now carries handler_duration_ms, response_serialization_ms, cancelled and timed_out, and a scan that reaches its deadline logs status=timeout. Together with the search_code execution deadline from v0.11.0 (31bdd4d), that covers what this issue asked for. If a slow call ever shows up again, those fields on the matching mcp.request line will show right away whether the time went to the handler or to the reply.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingpriority/highNeeds near-term maintainer attention; high-impact bug, regression, safety issue, or release blocker.stability/performanceServer crashes, OOM, hangs, high CPU/memorywindowsWindows-specific issues

    Projects

    No projects

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions