Skip to content

perf(mcp): report search phase timings - #1605

Open
ertankucukoglu wants to merge 1 commit into
DeusData:mainfrom
ertankucukoglu:perf/search-code-counters
Open

perf(mcp): report search phase timings#1605
ertankucukoglu wants to merge 1 commit into
DeusData:mainfrom
ertankucukoglu:perf/search-code-counters

Conversation

@ertankucukoglu

Copy link
Copy Markdown
Contributor

What does this PR do?

Adds phase-level timing counters to search_code results:

  • scope_ms
  • scan_ms
  • enrich_ms

The existing elapsed_ms field is preserved. All four timing fields are included in both the default tree output and JSON output.

Adds regression coverage for both output formats.

Test results: 7352 passed, 0 failed, 63 skipped.

Part of #1565

Checklist

  • Every commit is signed off (git commit -s) — required, CI rejects
    unsigned commits (DCO, see CONTRIBUTING.md)
  • Tests pass locally (make -f Makefile.cbm test)
  • Lint passes (make -f Makefile.cbm lint-ci)
  • New behavior is covered by a test (reproduce-first for bug fixes)

@github-actions

Copy link
Copy Markdown

Thanks for opening this — it has been seen, and it is queued.

This note is automated, but it is not a brush-off: it exists so you know where your PR stands instead of having to guess from silence.

Current review status: working through a backlog. 0.9.1-rc.1 is out, so the release freeze that held reviews is over — but it left a large queue of open pull requests behind it, and we are reading through them oldest-first. The background is in discussion #1144.

What that means for this PR, concretely:

  • It will not be closed for inactivity. No stale bot touches pull requests here.
  • It may still sit a while before a human reads it. That is on us, not on you.
  • Older PRs are read first, so a recent one is not being skipped — it is behind a queue.

Things that will genuinely speed it up whenever review does happen:

  • Keep it rebased on main — the tree is moving quickly right now, and a conflicting branch cannot be reviewed as the diff you intended.
  • Get CI green, or say which failures you believe are pre-existing.
  • Keep the change to one claim. Bundled features and refactors get split before they get merged, which costs you a round trip.
  • Every commit needs a sign-off (git commit -s) — CI enforces DCO.

If this fixes a bug, a reproduction we can run is worth more than a description of the symptom.

Thanks for contributing, and sorry in advance for the wait.

@DeusData

Copy link
Copy Markdown
Owner

Maintainer decision: yes, but behind a debug flag rather than always on.

The diagnostic value is real — scope_ms / scan_ms / enrich_ms is exactly what we would want while chasing #1565. The reservation is that search_code is the highest-traffic tool in the server, and three extra scalars on every response is a permanent cost paid by every caller for a signal almost none of them use. A response field is also a one-way door: once agents parse it, removing it is a breaking change.

So the ask is to gate it — a verbose / debug flag on the request, absent by default. That keeps the numbers available when someone is tracing a slow search, without taxing the common path or committing the surface permanently.

The measurement work itself is good and the split you chose (scope / scan / enrich) is the right one — it separates the three phases we would actually want to distinguish. Happy to take it once it is behind the flag.

Signed-off-by: Ertan <ertan.kucukoglu@gmail.com>
@ertankucukoglu

Copy link
Copy Markdown
Contributor Author

Updated as requested and rebased onto current main. The three phase timings are now omitted by default and exposed only when search_code receives debug:true; the existing elapsed_ms behavior is unchanged. Tests cover the default absence plus debug output in compact tree and JSON formats.

@ertankucukoglu
ertankucukoglu force-pushed the perf/search-code-counters branch from 526c573 to 2eb46cf Compare August 14, 2026 14:47
@DeusData

Copy link
Copy Markdown
Owner

Checked it rather than taking it on trust — debug is declared "default": false in the schema and the three fields only emit when include_phase_timings is set from it, so a caller who does not ask sees exactly what they saw before. elapsed_ms untouched. Tests cover both directions in tree and JSON.

That is exactly the shape we wanted, turned around fast. Merging once CI clears.

Worth saying why the flag mattered rather than it being bureaucracy: search_code is the highest-traffic tool in the server, so anything unconditional in its response is paid for by every call forever, and a response field is a one-way door once agents start parsing it. Behind a flag you get the numbers when you are actually chasing something — which is precisely the #1565 case — without that cost.

Your #1606 is already merged, and #1604 is next up in your cluster: it is results-preserving by construction, so it wants to land before #1607/#1608 rather than after.

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

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants