Make query_log faster under MSAN by Algunenano · Pull Request #92716 · ClickHouse/ClickHouse · GitHub
Skip to content

Make query_log faster under MSAN#92716

Merged
Algunenano merged 2 commits into
ClickHouse:masterfrom
Algunenano:querylog_faster
Jan 7, 2026
Merged

Make query_log faster under MSAN#92716
Algunenano merged 2 commits into
ClickHouse:masterfrom
Algunenano:querylog_faster

Conversation

@Algunenano

@Algunenano Algunenano commented Dec 19, 2025

Copy link
Copy Markdown
Member

Changelog category (leave one):

  • Not for changelog (changelog entry is not required)

Changelog entry (a user-readable short description of the changes that goes into CHANGELOG.md):

Make query_log faster under MSAN by disabling it when building Settings.cpp

Closes #91410

Documentation entry for user-facing changes

  • Documentation is written (mandatory for new features)

@clickhouse-gh

clickhouse-gh Bot commented Dec 19, 2025

Copy link
Copy Markdown
Contributor

@clickhouse-gh clickhouse-gh Bot added the pr-not-for-changelog This PR should not be mentioned in the changelog label Dec 19, 2025
Comment thread src/Core/Settings.cpp Outdated
Comment thread src/Core/Settings.cpp Outdated
@azat

azat commented Dec 24, 2025

Copy link
Copy Markdown
Member

@Algunenano Algunenano enabled auto-merge January 7, 2026 16:21
@Algunenano Algunenano added this pull request to the merge queue Jan 7, 2026
Merged via the queue into ClickHouse:master with commit 7c9ecc9 Jan 7, 2026
124 of 131 checks passed
@Algunenano Algunenano deleted the querylog_faster branch January 7, 2026 16:35
@robot-ch-test-poll3 robot-ch-test-poll3 added the pr-synced-to-cloud The PR is synced to the cloud repo label Jan 7, 2026
Algunenano added a commit to Algunenano/ClickHouse that referenced this pull request May 14, 2026
Even at track-origins=1, the per-call origin maintenance dominates two
hot helpers used by every QueryLog flush:
  - ProfileEvents::dumpToMapColumn (Interpreters/ProfileEventsExt.cpp)
  - SettingsImpl::dumpToMapColumn  (Core/Settings.cpp, already covered)

Each walks hundreds of keys and does tight LowCardinality::insertData
calls in a loop, so the per-call __msan_set_alloca_origin overhead
adds up to seconds per `SYSTEM FLUSH LOGS query_log` and the failing
tests on the MSan WasmEdge 2/2 shard hit the 180 s flush-wait
timeout. The CI logs show Block phase up to 14.7 s for a 5759-entry
batch, dominated by these two functions.

Extend the existing per-file override added in ClickHouse#92716 to also cover
ProfileEventsExt.cpp and SystemLog.cpp. These files are leaf helpers
where MSan checks don't carry uninit values into user code, so
turning origin tracking off here is safe; the rest of the build keeps
origin tracking.
Algunenano added a commit that referenced this pull request May 15, 2026
Even at track-origins=1, the per-call origin maintenance dominates two
hot helpers used by every QueryLog flush:
  - ProfileEvents::dumpToMapColumn (Interpreters/ProfileEventsExt.cpp)
  - SettingsImpl::dumpToMapColumn  (Core/Settings.cpp, already covered)

Each walks hundreds of keys and does tight LowCardinality::insertData
calls in a loop, so the per-call __msan_set_alloca_origin overhead
adds up to seconds per `SYSTEM FLUSH LOGS query_log` and the failing
tests on the MSan WasmEdge 2/2 shard hit the 180 s flush-wait
timeout. The CI logs show Block phase up to 14.7 s for a 5759-entry
batch, dominated by these two functions.

Extend the existing per-file override added in #92716 to also cover
ProfileEventsExt.cpp and SystemLog.cpp. These files are leaf helpers
where MSan checks don't carry uninit values into user code, so
turning origin tracking off here is safe; the rest of the build keeps
origin tracking.
Algunenano added a commit that referenced this pull request May 15, 2026
The earlier override on Settings.cpp / ProfileEventsExt.cpp /
SystemLog.cpp removed __msan_chain_origin / __msan_set_alloca_origin
from the helpers (dumpToMapColumn, flushImpl). But the per-row
LogElement::appendToBlock functions, which are called once per row
inside flushImpl and dominate the Block phase, were still being
compiled with origin tracking at level 1. With ~5000 rows per
query_log flush, the per-call origin-tracking overhead in those
functions added seconds to every SYSTEM FLUSH LOGS query_log.

Cover QueryLog.cpp, QueryThreadLog.cpp, MetricLog.cpp,
QueryMetricLog.cpp. Result on the rebuilt MSan binary:
  QueryLogElement::appendToBlock     57 KB -> 39 KB (-32%), 0 origin calls
  QueryThreadLogElement              9.5 KB -> 6 KB (-37%), 0 origin calls
  MetricLogElement / QueryMetricLog        also 0 origin calls
Compare with PartLogElement::appendToBlock (still origin-tracked):
55 __msan_set_alloca_origin calls in 22 KB.

Also drop the `-fomit-frame-pointer -momit-leaf-frame-pointer` flags
from the override: they were an artifact of exploratory commits in
PR #92716 that didn't move the needle (azat/Algunenano review thread
on Core/Settings.cpp). The single-line override on Common/ThreadFuzzer.cpp
keeps them with a comment pointing at commit d5825ec, where they
were measured to almost double ThreadFuzzer test throughput.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

pr-not-for-changelog This PR should not be mentioned in the changelog pr-synced-to-cloud The PR is synced to the cloud repo

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Timeouts on SYSTEM FLUSH LOGS (caused by MSan overhead)

3 participants