[fix](profile) guard execution profile access#65353
Conversation
|
run buildall |
|
/review |
|
Thank you for your contribution to Apache Doris. Please clearly describe your PR:
|
There was a problem hiding this comment.
I found one issue that should be fixed before merging.
Critical checkpoint conclusions:
- Goal: the PR adds diagnostics for query profile report handling, but the accepted issue makes one diagnostic WARN fire on an expected auto-profile-threshold cleanup path, so the signal is not reliable yet.
- Scope: the code change is small and localized to
ExecutionProfileandQeProcessorImpl. - Concurrency/lifecycle: the profile update remains asynchronous; no new locks or persistence paths were added. The concern is profile lifecycle cleanup versus late final BE profile reports.
- Config/session compatibility: no new config was added. Existing
auto_profile_threshold_msbehavior is directly involved in the accepted issue. - Parallel paths: realtime/final BE profile reporting and profile-manager cleanup paths were checked.
- Tests/validation: no tests were run because this checkout lacks
thirdparty/installedandthirdparty/installed/bin/protoc;git diff --check ab044d691635ea5d1e27daf72ee42d795ef6ab52 cd6884503b2c3eb0e08fffcaac119aa8f6001679passed.
User focus: no additional user-provided review focus was supplied.
Subagent conclusions: OR-1 was accepted as the inline comment. TSC-1 was dismissed with evidence because the unsafe unset-map receive-log path is pre-existing and current BE creators always set fragment_id_to_profile when sending query_profile; older mixed-version BEs omit query_profile entirely. Convergence round 1 ended with both optimizer-rewrite and tests-session-config reporting NO_NEW_VALUABLE_FINDINGS for the same final ledger/comment set.
| if (LOG.isDebugEnabled()) { | ||
| LOG.debug("Could not find execution profile, query {} be {}", | ||
| DebugUtil.printId(profile.query_id), address.toString()); | ||
| if (isDone) { |
There was a problem hiding this comment.
This turns an expected profile-filtering path into a WARN. The comment above still says missing execution profiles are common when auto_profile_threshold_ms != -1; for short queries Profile.updateSummary(..., true) removes the profile via ProfileManager.removeProfile(), and a final BE profile report that arrives after that cleanup reaches this branch with isDone=true. Those successful threshold-filtered queries will now emit WARN even though nothing is wrong, which makes the diagnostic noisy and can hide the real lost-profile case. Please keep the known filtered/cleaned-up miss at DEBUG, or only warn when the miss is distinguishable from intentional auto-profile cleanup, for example while the coordinator still exists.
FE UT Coverage ReportIncrement line coverage |
TPC-H: Total hot run time: 29550 ms |
TPC-DS: Total hot run time: 179642 ms |
ClickBench: Total hot run time: 24.92 s |
|
run buildall |
TPC-H: Total hot run time: 28986 ms |
|
/review |
TPC-DS: Total hot run time: 180109 ms |
There was a problem hiding this comment.
I found one additional issue that should be fixed before merging.
Critical checkpoint conclusions:
- Goal: the PR adds diagnostics for query profile report handling. Most changes are targeted logging/guarding, but the accepted issue makes a WARN fire during normal auto-profile cleanup, so one diagnostic signal is unreliable.
- Scope: the change is localized to FE profile/reporting code in
ExecutionProfile,ProfileManager, andQeProcessorImpl. - Concurrency/lifecycle: profile updates remain asynchronous, and the added read lock around
getExecutionProfilematches the existing profile-manager lock model. The accepted issue is a lifecycle/log-level mismatch betweenProfile.updateSummary(..., true),removeProfile, andunregisterQuery. - Config/session compatibility: no new config was added. Existing
auto_profile_threshold_msbehavior is directly involved in the accepted issue. - Parallel paths: the final BE profile report miss in
QeProcessorImplis already covered by existing thread discussion_r3541179558; the new inline comment covers the distinct FE-unregister warning path inProfileManager. - Tests/validation:
git diff --checkpassed after fetching the exact base SHA. FE build/checkstyle was not run because this checkout is missingthirdparty/installedandthirdparty/installed/bin/protoc.
User focus: no additional user-provided review focus was supplied.
Subagent conclusions: optimizer-rewrite-001 and tests-session-config-001 were merged into MAIN-001 and submitted as the inline comment. tests-session-config-001 was treated as a duplicate of MAIN-001; the existing QeProcessorImpl warning concern was duplicate-suppressed against discussion_r3541179558. Convergence round 1 ended with both optimizer-rewrite and tests-session-config reporting NO_NEW_VALUABLE_FINDINGS for the same final ledger/comment set.
| if (execProfile == null) { | ||
| LOG.debug("Profile {} does not exist, already finished or does not enable profile", | ||
| DebugUtil.printId(queryId)); | ||
| LOG.warn("Execution profile {} does not exist when marking query finished, {}", |
There was a problem hiding this comment.
This is another expected auto-profile cleanup path that now logs at WARN. For a query that finishes under auto_profile_threshold_ms, StmtExecutor.finalizeQuery() calls updateProfile(true), Profile.updateSummary(..., true) removes the profile through ProfileManager.removeProfile(), and then finalizeQuery() immediately calls QeProcessorImpl.unregisterQuery(), which still reaches markExecutionProfileFinished(). At that point execProfile == null is intentional, so this warning will fire during normal FE unregister even before any final BE profile report is involved. Please keep the known removed/disabled-profile case at DEBUG, or only warn when the state proves the profile was not intentionally filtered.
ClickBench: Total hot run time: 24.95 s |
|
run buildall |
TPC-H: Total hot run time: 29828 ms |
TPC-DS: Total hot run time: 179913 ms |
ClickBench: Total hot run time: 24.96 s |
FE Regression Coverage ReportIncrement line coverage |
|
run buildall |
TPC-H: Total hot run time: 29640 ms |
TPC-DS: Total hot run time: 180398 ms |
ClickBench: Total hot run time: 25 s |
0ba4a08 to
9b6c1d0
Compare
|
run buildall |
|
/review |
There was a problem hiding this comment.
I did not find any new blocking issue in the current head.
Critical checkpoint conclusions:
- Goal: the PR guards
ProfileManager.getExecutionProfile()with the existing profile-manager read lock and isolatesdml_profile_safefrom concurrent profile suites. The current diff accomplishes both stated goals. - Scope: the patch is small and focused: one FE lock correction and one regression-suite scheduling tag.
- Concurrency/lifecycle: all direct
queryIdToExecutionProfilesmutations inProfileManagerare under the write lock, and the new accessor now uses the read lock. The returnedExecutionProfilereference is still used outside the manager lock, which matches the existing async profile-update design; the mutable per-fragment profile maps have their ownExecutionProfilelock. - Locking cost/order: the new lock protects only a map lookup, with no RPC, external IO, journal wait, or nested catalog/table lock while held.
- Config/session compatibility: no new config was added. Existing profile session variables are unchanged. The
nonConcurrenttag is recognized by the regression framework as the single-run group, which is appropriate for a suite that executesclean all profile. - Incompatible formats/persistence: no Thrift, storage, or EditLog format changes are involved.
- Parallel paths: BE final profile reports reach the map through
QeProcessorImpl.processQueryProfile() -> ProfileManager.getExecutionProfile(), while finish marking and cleanup paths already use the same manager lock model. The previous WARN-level logging concerns in discussion_r3541179558 and discussion_r3543041140 were read as existing review context and are not duplicated; the current head no longer contains those WARN changes. - Tests/validation: PR-scoped
git show --check -- fe/fe-core/src/main/java/org/apache/doris/common/profile/ProfileManager.java regression-test/suites/query_profile/dml_profile_safe.groovywas clean. Local FE build/regression was not run because this checkout is missingthirdparty/installedandthirdparty/installed/bin/protoc.
User focus: no additional user-provided review focus was supplied.
Subagent conclusions: the optimizer-rewrite subagent reviewed optimizer/rewrite and parallel plan concerns and appended no candidates. The tests-session-config subagent reviewed regression/session/config and basic CI/style concerns and appended no candidates. Convergence round 1 used the final ledger and proposed no-inline-comment set; both live subagents replied NO_NEW_VALUABLE_FINDINGS, and no unresolved candidate remains in the ledger.
|
PR approved by at least one committer and no changes requested. |
|
skip buildall |
What
Fix two profile stability issues found while investigating
query_profile/adaptive_pipeline_task_serial_read_on_limit.groovy:ProfileManager.getExecutionProfile()with the existing read lock,matching the write-locked updates/removals of
queryIdToExecutionProfiles.query_profile/dml_profile_safe.groovyasnonConcurrentbecause it runsclean all profile, which clears global FE profile state and can interferewith other profile suites that are waiting for a query profile to become
complete.
Why
CI evidence showed
dml_profile_safe.groovyrunningclean all profilewhileadaptive_pipeline_task_serial_read_on_limit.groovywas waiting on anotherquery's profile. The final BE profile report then reached FE after the target
ExecutionProfilehad already been cleared, so the profile never becamecomplete for the waiting case.
The read-lock change is a small product hardening fix:
queryIdToExecutionProfilesis a regular map guarded by the profile manager read/write lock, so reads should
also use the read lock.
Validation
git diff --check989990:SUCCESS989992:SUCCESSci-selectdbfor builds989990and989992:ExecutionProfileExecutionProfileclean all profileinterference after isolatingdml_profile_safeLocal FE build/regression was not run in this cleanup pass; validation is
expected from the refreshed PR pipeline.