[Bug](profile) move watcher.stop() into locked code block#62683
Open
BiteTheDDDDt wants to merge 1 commit intoapache:branch-4.0from
Open
[Bug](profile) move watcher.stop() into locked code block#62683BiteTheDDDDt wants to merge 1 commit intoapache:branch-4.0from
BiteTheDDDDt wants to merge 1 commit intoapache:branch-4.0from
Conversation
cherry-picked from apache#56462 (master commit 83c7020). Without taking _task_lock, _watcher.stop() in Dependency::set_ready() races with start_watcher() called inside is_blocked_by(): the latter may observe _ready==false (it acquires _task_lock and reads _ready before set_ready() can flip it) and re-start the stopwatch right after set_ready() stopped it. After the race nothing stops the watcher again and watcher_elapse_time() reported in close() reflects the operator's entire lifetime instead of the actual blocked duration. This inflates WaitForDependency[*]Time and WaitForRuntimeFilter counters, which in production were observed to be ~12s while real per-RF wait times were only tens of milliseconds. Fix: stop the watcher inside the _task_lock critical section so it is strictly mutually exclusive with start_watcher(). Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Contributor
Author
|
run buildall |
Contributor
|
Thank you for your contribution to Apache Doris. Please clearly describe your PR:
|
Contributor
There was a problem hiding this comment.
Pull request overview
Note
Copilot was unable to run its full agentic suite in this review.
Backports the fix from #56462 to prevent a race where a dependency watcher can be re-started between stop() and publishing _ready = true, inflating profile wait-time counters.
Changes:
- Move
_watcher.stop()under_task_lockinDependency::set_ready(). - Ensure watcher stop happens before setting
_ready = truewhile holding the mutex.
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
Contributor
BE UT Coverage ReportIncrement line coverage Increment coverage report
|
Contributor
BE Regression && UT Coverage ReportIncrement line coverage Increment coverage report
|
github-actions
Bot
added
the
approved
Contributor
|
PR approved by at least one committer and no changes requested. |
Contributor
|
PR approved by anyone and no changes requested. |
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.
What problem does this PR solve?
Issue Number: close #xxx
Related PR: #56462
Problem Summary:
Backport of #56462 to this branch.
Dependency::set_ready()previously called_watcher.stop()outside_task_lock. A concurrentis_blocked_by()(which acquires_task_lock, checks_ready, and callsstart_watcher()) could re-start the watcher right afterstop()but before_ready = truewas published; nothing stops it again. As a resultwatcher_elapse_time()accumulates wall-clock time from the first block until the operator closes, makingWaitForDependency/WaitForRuntimeFilterprofile counters appear hugely inflated (e.g. ~12s on a 20s query while each individual RFWaitTimeis only tens of ms).Move
_watcher.stop()inside the_task_lockblock, before setting_ready = true, matching the master fix.Release note
None
Check List (For Author)