Skip to content

[RFC] Fix jemalloc assertion due to non-monotonic CLOCK_MONOTONIC_COARSE#66439

Merged
antonio2368 merged 2 commits intoClickHouse:masterfrom
azat:jemalloc-clock-assertion
Jul 15, 2024
Merged

[RFC] Fix jemalloc assertion due to non-monotonic CLOCK_MONOTONIC_COARSE#66439
antonio2368 merged 2 commits intoClickHouse:masterfrom
azat:jemalloc-clock-assertion

Conversation

@azat
Copy link
Copy Markdown
Member

@azat azat commented Jul 12, 2024

Changelog category (leave one):

  • Not for changelog (changelog entry is not required)

Fix jemalloc assertion due to non-monotonic CLOCK_MONOTONIC_COARSE

Recently one tricky assertion of jemalloc had been discovered 1:

Failed assertion: "nstime_compare(&decay->epoch, new_time) <= 0"

And as it turns out it is really possible for CLOCK_MONOTONIC_COARSE to go backwards, in a nutshell it can be done with ADJ_FREQUENCY, you can find example here 2. And I can't trigger this issue for non-coarse clocks.

But, jemalloc do not call clock_gettime() that frequently (I've verified it), so it can use non-coarse version - CLOCK_MONOTONIC

I've also measured the latency of CLOCK_MONOTONIC and CLOCK_MONOTONIC_COARSE, and it is 20ns vs 4ns per call 3, so make this change affect performance you need really frequently calls of clock_gettime.

Interesting, that this bug started to appears only after jemalloc heap profiler had been enabled by default 4, no clue why (I would believe more in a more frequent calls to clock_adjtime(ADJ_FREQUENCY), but I can't verify this)

To be continued...

Fixes: #66193 (cc @antonio2368 )

@azat azat changed the title Fix jemalloc assertion due to non-monotonic CLOCK_MONOTONIC_COARSE [RFC] Fix jemalloc assertion due to non-monotonic CLOCK_MONOTONIC_COARSE Jul 12, 2024
@robot-ch-test-poll4 robot-ch-test-poll4 added pr-bugfix Pull request with bugfix, not backported by default submodule changed At least one submodule changed in this PR. labels Jul 12, 2024
@robot-ch-test-poll3
Copy link
Copy Markdown
Contributor

robot-ch-test-poll3 commented Jul 12, 2024

This is an automated comment for commit 669ce7c with description of existing statuses. It's updated for the latest CI running

❌ Click here to open a full report in a separate page

Check nameDescriptionStatus
Bugfix validationChecks that either a new test (functional or integration) or there some changed tests that fail with the binary built on master branch❌ failure
BuildsThere's no description for the check yet, please add it to tests/ci/ci_config.py:CHECK_DESCRIPTIONS⏳ pending
Stateful testsRuns stateful functional tests for ClickHouse binaries built in various configurations -- release, debug, with sanitizers, etc❌ failure
Stateless testsRuns stateless functional tests for ClickHouse binaries built in various configurations -- release, debug, with sanitizers, etc❌ failure
Successful checks
Check nameDescriptionStatus
AST fuzzerRuns randomly generated queries to catch program errors. The build type is optionally given in parenthesis. If it fails, ask a maintainer for help✅ success
ClickBenchRuns [ClickBench](https://github.com/ClickHouse/ClickBench/) with instant-attach table✅ success
Compatibility checkChecks that clickhouse binary runs on distributions with old libc versions. If it fails, ask a maintainer for help✅ success
Docker keeper imageThe check to build and optionally push the mentioned image to docker hub✅ success
Docker server imageThe check to build and optionally push the mentioned image to docker hub✅ success
Docs checkBuilds and tests the documentation✅ success
Fast testNormally this is the first check that is ran for a PR. It builds ClickHouse and runs most of stateless functional tests, omitting some. If it fails, further checks are not started until it is fixed. Look at the report to see which tests fail, then reproduce the failure locally as described here✅ success
Flaky testsChecks if new added or modified tests are flaky by running them repeatedly, in parallel, with more randomization. Functional tests are run 100 times with address sanitizer, and additional randomization of thread scheduling. Integration tests are run up to 10 times. If at least once a new test has failed, or was too long, this check will be red. We don't allow flaky tests, read the doc✅ success
Install packagesChecks that the built packages are installable in a clear environment✅ success
Integration testsThe integration tests report. In parenthesis the package type is given, and in square brackets are the optional part/total tests✅ success
Performance ComparisonMeasure changes in query performance. The performance test report is described in detail here. In square brackets are the optional part/total tests✅ success
Stress testRuns stateless functional tests concurrently from several clients to detect concurrency-related errors✅ success
Style checkRuns a set of checks to keep the code style clean. If some of tests failed, see the related log from the report✅ success
Unit testsRuns the unit tests for different release types✅ success
Upgrade checkRuns stress tests on server version from last release and then tries to upgrade it to the version from the PR. It checks if the new server can successfully startup without any errors, crashes or sanitizer asserts✅ success

@azat azat force-pushed the jemalloc-clock-assertion branch 2 times, most recently from 1f6a0b4 to 0aa4dbd Compare July 12, 2024 12:56
@antonio2368
Copy link
Copy Markdown
Member

Let's enable profiler back for debug so we don't have different configurations
https://github.com/ClickHouse/ClickHouse/blob/master/contrib/jemalloc-cmake/CMakeLists.txt#L37
Remove if else here

@antonio2368 antonio2368 self-assigned this Jul 12, 2024
@azat azat force-pushed the jemalloc-clock-assertion branch from 0aa4dbd to 65a00c7 Compare July 12, 2024 12:59
@antonio2368
Copy link
Copy Markdown
Member

antonio2368 commented Jul 12, 2024

If performance tests are happy then okay
If performance tests are not happy we will patch MONOTONIC_COARSE to be non-monotonic.

@alexey-milovidov
Copy link
Copy Markdown
Member

@azat Let's submit a fix to the Linux man page. It says that

All CLOCK_MONOTONIC variants guarantee that the time returned by consecutive calls will not go backwards, but successive calls may—depending on the architecture—return
identical (not-increased) time values.

@azat
Copy link
Copy Markdown
Member Author

azat commented Jul 13, 2024

I haven't finished yet:

To be continued...

By this I meant:

  • jemalloc
  • linux

@alexey-milovidov
Copy link
Copy Markdown
Member

Depends on #66460

azat added 2 commits July 14, 2024 08:21
Recently one tricky assertion of jemalloc had been discovered [1]:

    Failed assertion: "nstime_compare(&decay->epoch, new_time) <= 0"

  [1]: ClickHouse#66193

And as it turns out it is really possible for CLOCK_MONOTONIC_COARSE to
go backwards, in a nutshell it can be done with ADJ_FREQUENCY, you can
find example here [2]. And I can't trigger this issue for non-coarse
clocks.

  [2]: https://gist.github.com/azat/7ea7f50ed75591b1af2d675a240ea94c?permalink_comment_id=5119222#gistcomment-5119222

But, jemalloc do not call clock_gettime() that frequently (I've verified
it), so it can use non-coarse version - CLOCK_MONOTONIC

I've also measured the latency of CLOCK_MONOTONIC and
CLOCK_MONOTONIC_COARSE, and it is 20ns vs 4ns per call [3], so make this
change affect performance you need really frequently calls of
clock_gettime.

  [3]: https://gist.github.com/azat/622fa1f9a5d8e7d546ee9d294501961d?permalink_comment_id=5119245#gistcomment-5119245

Interesting, that this bug started to appears only after jemalloc heap
profiler had been enabled by default [4], no clue why (I would believe
more in a more frequent calls to clock_adjtime(ADJ_FREQUENCY), but I
can't verify this)

  [4]: ClickHouse#65702

To be continued...

Fixes: ClickHouse#66193
Signed-off-by: Azat Khuzhin <a.khuzhin@semrush.com>
Since the issue with jemalloc assertion is clear, let's revert that
workaround

Signed-off-by: Azat Khuzhin <a.khuzhin@semrush.com>
@azat azat force-pushed the jemalloc-clock-assertion branch from 42ff7c4 to 669ce7c Compare July 14, 2024 06:21
@azat
Copy link
Copy Markdown
Member Author

azat commented Jul 14, 2024

Stateless tests (ubsan) — fail: 1, passed: 6692, skipped: 57

Stateless tests (debug, s3 storage) [1/2] — fail: 1, passed: 3296, skipped: 69

  • 01069_window_view_proc_tumble_watch

Stateful tests (tsan) — Timeout 3600 exceeded

@alexey-milovidov
Copy link
Copy Markdown
Member

@azat, your pull request is mistakenly classified as a bugfix, but it does not fix any wrong behavior in production ClickHouse builds. It does not even have tests to prove that. Our CI pointed to that. Please change the classification.

@antonio2368
Copy link
Copy Markdown
Member

I'm going to merge as test failures seem unrelated and performance tests are okay

@antonio2368 antonio2368 enabled auto-merge July 15, 2024 06:44
@antonio2368 antonio2368 added this pull request to the merge queue Jul 15, 2024
Merged via the queue into ClickHouse:master with commit 7d62a19 Jul 15, 2024
@robot-ch-test-poll robot-ch-test-poll added the pr-synced-to-cloud The PR is synced to the cloud repo label Jul 15, 2024
@azat azat deleted the jemalloc-clock-assertion branch July 16, 2024 20:44
@robot-ch-test-poll4 robot-ch-test-poll4 added the pr-backports-created-cloud deprecated label, NOOP label Jul 17, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

pr-backports-created-cloud deprecated label, NOOP pr-bugfix Pull request with bugfix, not backported by default pr-synced-to-cloud The PR is synced to the cloud repo submodule changed At least one submodule changed in this PR.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Failed assertion in jemalloc

6 participants