Add wait stats - #405
Draft
Alena0704 wants to merge 2 commits into
Draft
Conversation
A cross-slice ShareInputScan consumer blocks waiting for the producer slice to publish its tuplestore. That wait is invisible: in EXPLAIN ANALYZE the node just looks slow, and a query killed by statement_timeout leaves no trace at all. Measure the wait and surface it per segment in EXPLAIN ANALYZE (max, the segment that waited longest, and the average). The max-vs-avg gap exposes slice-to-slice wait skew, so the metric is useful for spotting anomalies, not only for diagnosing a mis-wired cross-slice share. Only waits above 1 ms are shown, so plans of queries that do not wait are unchanged. An errcontext callback attaches the elapsed wait to any error raised while blocked -- most importantly the statement_timeout cancellation, the only channel that survives a killed query. The wait is also rolled up per query in EState.es_cross_slice_wait for the stats collector to report.
Add cross_slice_wait_ms to the collector's MetricInstrumentation and fill it from EState.es_cross_slice_wait (the per-query cross-slice ShareInputScan wait rolled up in the executor), reported in milliseconds. A cross-slice ShareInputScan consumer blocks until its producer slice publishes the shared tuplestore. Beyond catching a share wired between slices that cannot reach each other, the wait is a general slice-to-slice signal: yagpcc takes the max across segments, and a wide gap against the average means the producer finished unevenly rather than the consumer being slow. It also rises when the producer slice is starved of CPU or interconnect, and it is the only trace left by a query killed on statement_timeout while blocked there. Filled outside the instrumentation block, since the executor measures the wait whether or not instrumentation is on, and the statement_timeout case often runs without it. A zero wait is not reported, so queries that never waited get no empty instrumentation submessage.
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.
Report cross-slice ShareInputScan wait
A ShareInputScan consumer placed in a slice other than its producer blocks
until the producer publishes the shared tuplestore. The wait is charged to
the node's own time, so an idle node looks slow, and a query killed by
statement_timeout while blocked leaves no trace at all.
Measure the wait on the consumer side and report it in three ways:
workers" under the node, for waits of 1 ms and above. Max against average
shows whether one segment waited or all of them did.
blocked, which covers the statement_timeout cancellation.
gp_stats_collector reports it as cross_slice_wait_ms.
Tests are added to src/test/regress/sql/shared_scan.sql for the planner and
the optimizer. The producer sleeps to force a wait above the threshold, and
a plpgsql wrapper checks only that the line is present, so no timing value
reaches the expected output. The metric is documented in
gpcontrib/gp_stats_collector/metric.md.
To reproduce:
Only the segment holding the row sleeps, so its consumer blocks for half a
second while the others do not:
Without the patch the node reports only its actual time, with the half
second charged to the scan itself.