Add planning-effort counters and prepare-stage timer to profile notes - #16
Merged
Merged
Conversation
Extends the profile-gated instrumentation (bhensley5#15) with per-query planning-effort counters and a `prepare` stage timer. - `prepare` timer fills the gap between lowering and the published snapshot (order-by resolution, row-count evaluation, target config), the only previously uninstrumented stage around the graph-row call. - Counters: node_legal_universe_sources, edge_source_consults, edge_source_misses, secondary_index_followups. Counters use a crate-local thread-local the planner increments (always) and the GQL layer snapshots when profiling; values ride the existing GqlExecutionExplain.notes line, so no public struct or connector changes and the shared read substrate is untouched. profile=false is unchanged: timer mark() returns None and counter values are neither snapshotted nor surfaced. Measured fire count is 3-8 per query (~22-57 ns, ~0.001-0.005% of read latency).
Owner
|
Thanks for the follow-up. I reviewed this on top of #15 and the scope still looks right. It keeps the profiling data on the existing explain notes surface, avoids public/connector API changes, and adds useful planner-effort visibility. Merging via squash. |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Builds on #15. When
profile: true(withinclude_plan: true), theexisting stage-timing note in
GqlExecutionExplain.notesalso carries:preparestage timer, covering the GQL work between lowering and thepublished snapshot (order-by resolution, row-count evaluation, target
configuration) — previously the only uninstrumented gap around the
graph-row call;
node_legal_universe_sources(legal-universecandidate sources enumerated across node plans),
edge_source_consults/edge_source_misses(edge-source cost memo use), andsecondary_index_followups(secondary-index read followups enqueued).Why
The stage timers from #15 isolate the graph-row call as the dominant bucket
but say nothing about planning effort. These counters are a cheap
regression canary for planner work — they surface how many candidate
sources the planner evaluated, so a change that balloons enumeration (new
index types, planner refactors) is visible before it ships. Filling the
preparegap also means the graph-row bucket is the only unexplainedstage, so its isolation is exact.
Design (same contract as #15)
notes: Vec<String>line.read.rs,query_exec.rs,ReadView/SourceList); the native hot path is unaffected.increments and the GQL layer snapshots only when profiling.
graph_row_plan_and_executeremains a single combined bucket; splittingit (plan vs probe vs execution) is intentionally out of scope here.
Overhead
profile: falseis unchanged: the timermark()returnsNoneandcounter values are neither snapshotted nor surfaced. The planner always
increments the thread-local; measured fire count is 3–8 per query
(~22–57 ns on the default path, ~0.001–0.005% of read latency), confirmed
by reading the values back through the note.
Tests
New
gql_query_profile_planning_counters_in_explain_noteasserts the notecarries every counter/timer field, that a single-node query enumerates