Require 1,000ms statement elapsed before rule 35 fires - #563
Merged
Merged
Conversation
Expensive Operator compared one operator's own time against the whole statement's elapsed time and fired at a 20% share. In a statement that finishes in under a second, one or two operators always take most of the (tiny) time just because there is almost nothing else to divide it among, so the share pointed at nothing. Add a 1,000ms floor on statement elapsed time before the rule runs, matching the floor rule 19 uses for compile CPU and rule 4 uses to call UDF time Critical. Closes #562
erikdarlingdata
marked this pull request as ready for review
September 24, 2026 10:08
|
Reviewed. Small, correctly-scoped fix — the |
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.
Problem
Rule 35 (Expensive Operator) warns when one operator takes at least 20% of a statement's elapsed time. In a statement that finishes in under a second, one or two operators always take most of the (tiny) elapsed time. There is almost nothing else to divide the time among, so the 20% share points at nothing (#562).
Change
Rule35_ExpensiveOperatorinsrc/PlanViewer.Core/Services/PlanAnalyzer.Node.csnow requires the statement's elapsed time to be at least 1,000ms before it runs at all. The floor is a named constant,Rule35MinStatementElapsedMs, placed just above the rule. Rule 19 uses the same floor to fire on compile CPU (stmt.CompileCPUMs >= 1000). Rule 4 uses it to call UDF time Critical (stmt.QueryUdfElapsedTimeMs >= 1000). A different value changes no fixture: every fixture with this warning ran for 3ms or less, or for 1,000ms or more.Tests
Added to
tests/PlanViewer.Core.Tests/PlanAnalyzerTests.cs:Rule35_ExpensiveOperator_NotFiredWhenStatementUnderOneSecond:multi_index_update_plan.sqlplan(statement elapsed 1ms) gets no "Expensive Operator" warning.Rule35_ExpensiveOperator_FiredWhenStatementAtOneSecond:parallel_row_over_batch_plan.sqlplan(statement elapsed exactly 1,000ms) still gets its Critical "Hash Match" warning. This pins the floor as>=, not>.Rule35_ExpensiveOperator_NotFiredJustUnderOneSecondFloorandRule35_ExpensiveOperator_FiredAtOneSecondFloorExactly: the same plan, with the statement's elapsed time forced to 999ms, then 1,000ms. This checks both sides of the line on one plan.The last two tests needed a way to override a loaded plan's elapsed time before analysis. I added
PlanTestHelper.LoadAndAnalyzeWithElapsedTimeMs(planFileName, elapsedTimeMs)next to the existingLoadAndAnalyzeWithConfighelper.All 89 tests in
PlanAnalyzerTestspass.Mutation results
Two mutations, each restored before the next:
stmt.QueryTimeStats.ElapsedTimeMs > 0): failedRule35_ExpensiveOperator_NotFiredWhenStatementUnderOneSecondandRule35_ExpensiveOperator_NotFiredJustUnderOneSecondFloor, as expected.>in place of>=: failedRule35_ExpensiveOperator_FiredWhenStatementAtOneSecondandRule35_ExpensiveOperator_FiredAtOneSecondFloorExactly, as expected.Each mutation was built with
--no-incrementalafter restoring the file, to rule out a stale DLL.Baseline diff
Regenerated
WarningBaseline.txtfrom empty. The diff removes exactly 5 lines, all "Expensive Operator", across the 3 fixtures the brief predicted:multi_index_update_plan.sqlplan: 1 line (Critical, Clustered Index Update, 1ms, 100%).join_or_expression_plan.sqlplan: 2 lines (Nested Loops and Sort, 1ms, 33.3% each).join_or_mixed_parameter_plan.sqlplan: 2 lines (Nested Loops and Sort, 1ms, 33.3% each).No other fixture changed.
ComparisonBaseline.txtwas also regenerated: deleted, then the characterization test run twice, because it fails on purpose on the recording run. It came back byte-identical in content to the committed version, so it is not part of this diff.Full suite
I merged this branch and
fix/561-table-variable-bare-columnsinto a throwaway branch offorigin/dev, and ran the fullPlanViewer.Core.Testsproject once there, including the headless UI tests. Totals: 758 total, 757 passed, 0 failed, 1 skipped, in 1m 11s. The 1 skip is a pre-existing, unrelated Windows/WAM contract pin (EntraInteractiveAuthTests).Closes #562
🤖 Generated with Claude Code
https://claude.ai/code/session_017ZVrq8tpA2DBPEFEqahFK6