Add query profiling functions: util:time, memory, track, explain, profile, index-report

[joewiz]

Summary

Add a suite of query profiling and visibility functions to eXist-db's util: module, inspired by BaseX's prof: module and addressing long-standing requests for query plan visibility (core dev feedback: "Make optimizations visible").

This PR adds 7 new functions across 3 categories: pass-through measurement, query plan inspection, and execution profiling with per-query isolation.

New Functions

Pass-Through Measurement

Function	Returns	Purpose
util:time(\$expr)	item()*	Measures and logs execution time; returns result unchanged
util:time(\$expr, \$label)	item()*	Same, with custom log label
util:memory(\$expr)	item()*	Measures and logs memory delta; returns result unchanged
util:memory(\$expr, \$label)	item()*	Same, with custom log label
util:track(\$expr)	map(*)	Returns map { "time": xs:dayTimeDuration, "memory": xs:integer, "value": item()* }
util:track(\$expr, \$label)	map(*)	Same, with label in the result map

Query Plan Inspection

Function	Returns	Purpose
util:explain(\$query)	element(explain)	Compiles query string and returns the post-optimization expression tree as XML
util:explain(\$query, \$module-load-path)	element(explain)	Same, with module import resolution path

Execution Profiling

Function	Returns	Purpose
util:profile(\$query)	map(*)	Executes query with profiling; returns map { "result", "time", "memory", "plan", "stats" }
util:profile(\$query, \$module-load-path)	map(*)	Same, with module import resolution path
util:index-report(\$query)	element()	Executes query and returns XML report of index usage and optimizations

What Changed

File	Changes
FunTime.java	Pass-through timer with formatted logging (µs/ms/s)
FunMemory.java	Pass-through memory profiler with formatted logging (B/KB/MB/GB)
FunTrack.java	Combined time + memory measurement returning structured map
FunExplain.java	Compiles query, runs optimizer, serializes expression tree via QueryPlanSerializer
QueryPlanSerializer.java	ExpressionVisitor that emits XML for ~20 expression types (FLWOR, path, comparison, function call, conditional, etc.)
FunProfile.java	Combines execution, timing, memory, plan, and per-query profiler stats into a single map result
FunIndexReport.java	Executes with profiling and returns PerformanceStats as XML report
Profiler.java	Added getPerformanceStats() for per-query stats isolation
GeneralComparison.java	Added DEBUG-level optimizer decision logging
UtilModule.java	Registered all 11 new function signatures
profiling.xql	31 XQSuite tests covering all functions and signatures

Design Decisions

Per-query profiling isolation: Each util:profile() call creates its own XQueryContext with its own Profiler instance, which has its own PerformanceStatsImpl. This ensures profiling data is accurate under concurrent load — no crosstalk between queries.

Expression tree as XML: util:explain() uses a visitor pattern (QueryPlanSerializer extends DefaultExpressionVisitor) to walk the compiled expression tree and emit XML. This shows the post-optimization tree — what the engine actually executes.

Deferred: ValueComparison optimization (Phase 4.2). The profiling audit revealed that eq/ne/lt/gt (value comparisons) never trigger index optimizations — only =/!=/</> (general comparisons) do. Making ValueComparison implement Optimizable would be a significant performance improvement but changes query execution behavior and requires careful XQTS regression testing. Deferred to a dedicated optimizer overhaul tasking.

Examples

(: Quick timing :)
util:time(collection("/db/data")//title, "title lookup")
(: Logs: title lookup — 42.3ms :)

(: Structured measurement :)
let $r := util:track(collection("/db/data")//title)
return "Found " || count($r?value) || " titles in " || $r?time

(: Query plan :)
util:explain('for $x in 1 to 10 where $x > 5 return $x * 2')
(: Returns: <explain><for variable="$x"><in>...</in>...</for></explain> :)

(: Full profiling :)
let $p := util:profile('collection("/db/data")//book[@year > 2020]')
return ($p?time, count($p?result), $p?plan, $p?stats)

Test Plan

• XQSuite: 31 tests in profiling.xql (94/94 total util tests pass)
• Manual testing with indexed collections for util:index-report() and util:profile() stats
• Verify no regressions in existing util function tests

🤖 Generated with Claude Code

[joewiz]

[This comment was co-authored with Claude Code. -Joe]

Closing — superseded by #6208 (v2/query-profiling).

This work has been consolidated into a clean v2/ branch as part of the eXist-db 7.0 PR reorganization. The new PR includes all commits from this PR plus additional related work, with reviewer feedback incorporated where applicable. See the reviewer guide for the full context.