GitNexus/gitnexus/test/integration
azizur100389 ac148612ab
feat(search): per-phase timing instrumentation for the query pipeline (#953)
* feat(search): per-phase timing instrumentation for the query pipeline

The eval harness already measures search-pipeline latency per phase,
but the *product* query() tool has no timing visibility. That leaves
production latency opaque:

 - Is BM25 the tail, or vector search?
 - How much Promise.all overlap do concurrent searches actually save?
 - Does symbol_lookup dominate when per-symbol Cypher round-trips pile up?

None of this is answerable from the outside, which blocks the
latency-quality Pareto work tracked in #546 / #553.

Changes:

* New PhaseTimer class at src/core/search/phase-timer.ts.
  Supports three APIs:
    - start(phase) / stop() for sequential phases (per issue spec)
    - mark(phase, durationMs) for pre-measured durations
    - time(phase, promise) to wrap a promise inside Promise.all

  The issue's original spec was sequential-only, which doesn't work
  for BM25 + vector inside Promise.all — the second start() would
  auto-stop the first and only one phase would get timed. The mark()
  and time() variants resolve that without changing the sequential
  API for the other phases.

* local-backend.ts query() instrumented across seven phase markers:
    bm25, vector   (concurrent via timer.time inside Promise.all)
    merge          (RRF reciprocal-rank-fusion)
    symbol_lookup  (per-symbol process + cohesion + content Cypher)
    ranking        (in-memory priority sort)
    formatting     (response object construction + dedup)
    wall           (end-to-end; separate mark so callers can compare
                   sum(phases) vs wall and see Promise.all savings)

* logQueryTiming() helper next to logQueryError(), same console-based
  pattern (repo has no structured logger). Emits
    GitNexus [query:timing] query="..." totalMs=N phases={...}
  to stdout — greppable prefix, JSON-parseable payload, no new deps.

* timing: Record<string, number> added as a top-level field on the
  query() response. Strict superset of the previous shape — existing
  tests only assert field presence, so no regression. Other MCP tools
  use the same top-level-metadata convention (status, row_count,
  warning) rather than a nested _meta wrapper.

Tests:

 - 6 new unit tests for PhaseTimer covering start/stop, implicit
   stop-on-start, additive mark(), Promise.all-safe time(),
   negative/NaN rejection, and totalMs auto-stop.
 - 3 new assertions on the existing query integration test verifying
   timing.wall is a non-negative number and at least one of
   bm25/vector fired.

Verification:
  npx vitest run test/unit/phase-timer.test.ts       -> 6 pass
  npx vitest run test/unit/calltool-dispatch.test.ts -> 65 pass
  npx vitest run test/integration/local-backend-calltool.test.ts -> 18 pass
  npm run test:unit                                   -> 3777 pass
    (4 pre-existing env failures unchanged: skip-git-cli needs
     built dist/, git-utils tmpdir on Windows worktree)
  npx tsc --noEmit                                    -> clean

Scope declined for v1:

 - In-process histogram aggregation — the log line is enough for
   external tooling
 - Pareto curve generation — issue asks to enable it, not generate it
 - Sub-phases of symbol_lookup (process vs cohesion vs content) —
   issue lists them under one bucket; can split later if demand surfaces

Closes #553

* fix(search): route query:timing log to stderr to preserve stdio MCP contract

CI (#953) failed the `query: JSON appears on stdout, not stderr`
e2e test in test/integration/cli-e2e.test.ts with:

  SyntaxError: Unexpected token 'G', "GitNexus [..." is not valid JSON

Root cause: my initial logQueryTiming() in 63fbdc4 used console.log,
which writes to stdout. The MCP stdio transport uses stdout
exclusively for JSON-RPC responses (#324), and the CLI e2e test
guards that contract by asserting stdout parses as JSON on every
tool invocation. The "GitNexus [query:timing] ..." line was
interleaving with the response JSON and breaking the parse.

Fix: route logQueryTiming through console.error instead. stderr is
the correct channel for human-readable diagnostics and it is what
the sibling logQueryError already uses for the same reason. The log
line format is otherwise unchanged -- still greppable, still
JSON-parseable payload.

Verification (local, with dist built):
  npx vitest run test/integration/cli-e2e.test.ts -t "query: JSON"
    -> now passes (was failing across ubuntu/windows/macos in CI)
  npx tsc --noEmit                                  -> clean
  Two unrelated pre-existing failures on non-git
  directory handling remain (same on upstream/main).

Closes the CI regression introduced in 63fbdc4.
2026-04-18 16:30:07 +01:00
..
group fix(group): address 4 HIGH-priority issues from PR #626 review 2026-04-02 12:55:33 +03:00
resolvers feat(ingestion): language-agnostic heritage extractor with config+factory pattern (#890) 2026-04-17 17:51:17 +01:00
api-impact-e2e.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
augmentation.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
class-impact-all-languages.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
cli-e2e.test.ts fix(test): isolate cli-e2e from shared mini-repo fixture (#954) 2026-04-18 12:54:59 +01:00
cross-file-binding.test.ts fix: resolve C/C++ cross-file calls through transitive #include chains (#816) 2026-04-14 09:39:17 +01:00
csv-pipeline.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
enrichment.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
expo-routes.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
filesystem-walker.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
has-method.test.ts feat(cpp): C/C++ MethodExtractor config with pure virtual detection (#617) 2026-04-01 18:07:11 +01:00
heritage-extractor-wiring.test.ts feat(ingestion): language-agnostic heritage extractor with config+factory pattern (#890) 2026-04-17 17:51:17 +01:00
hooks-e2e.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
ignore-and-skip-e2e.test.ts Extract registries into model/ module with SemanticModel interface (#786) 2026-04-12 01:06:55 +01:00
java-class-impact.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
lbug-core-adapter.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
lbug-lock-retry.test.ts fix(lbug): retry on DB lock with session-safe cleanup (#325) 2026-03-22 18:21:21 +09:00
lbug-pool-stability.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
lbug-pool.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
lbug-vector-extension.test.ts fix: load VECTOR extension during DB init for semantic search (#782) 2026-04-11 12:17:40 +01:00
local-backend-calltool.test.ts feat(search): per-phase timing instrumentation for the query pipeline (#953) 2026-04-18 16:30:07 +01:00
local-backend.test.ts feat: METHOD_IMPLEMENTS edges, overload disambiguation, MethodExtractor unification (#574) (#642) 2026-04-04 18:41:47 +01:00
orm-dataflow.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
parsing.test.ts feat: configure eslint with unused import removal (#564) 2026-03-28 15:28:09 +00:00
pipeline-graph-golden.test.ts fix(test): isolate cli-e2e from shared mini-repo fixture (#954) 2026-04-18 12:54:59 +01:00
pipeline.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
qualified-class-lookups.test.ts Extract registries into model/ module with SemanticModel interface (#786) 2026-04-12 01:06:55 +01:00
query-compilation.test.ts [dart] Add call patterns for await, cascade, lambda, and widget-tree contexts (#801) 2026-04-13 11:21:11 +01:00
search-core.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
search-pool.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
server-analyze.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
setup-skills.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
shape-check-regression.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
skills-e2e.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
staleness-and-stability.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
tree-sitter-languages.test.ts feat: configure prettier with pre-commit hook (#563) 2026-03-28 14:58:04 +00:00
worker-pool.test.ts fix: keep worker warnings non-terminal (#261) 2026-04-17 06:46:31 +01:00