Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Added possibility to save logs on crash and options to configure logs buffer #52174

Merged
merged 2 commits into from
Jul 28, 2023

Conversation

Demilivor
Copy link
Contributor

  • Used by-value + move idiom for system logs.
  • Removed unused parameter in Session methods.
  • Added max_size for the system logs instead of a hardcoded parameter.
  • Added reserved_size for the system logs instead of the constexpr non-configurable parameter.
  • Added buffer_size_flush_threshold for the system logs instead of the constexpr non-configurable parameter.
  • Added possibility to notify flush (non-blocking flush) logs to the disk on crash.

Changelog category (leave one):

  • Improvement

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

  • Added possibility to flush logs to the disk on crash
  • Added logs buffer configuration

@Demilivor
Copy link
Contributor Author

Good day to all,

Please label 'can be tested' and assign a reviewer.

@alexey-milovidov alexey-milovidov added the can be tested Allows running workflows for external contributors label Jul 17, 2023
@robot-ch-test-poll3 robot-ch-test-poll3 added the pr-improvement Pull request with some product improvements label Jul 17, 2023
@robot-ch-test-poll3
Copy link
Contributor

robot-ch-test-poll3 commented Jul 17, 2023

This is an automated comment for commit 112058d with description of existing statuses. It's updated for the latest CI running
The full report is available here
The overall status of the commit is 🟢 success

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
CI runningA meta-check that indicates the running CI. Normally, it's in success or pending state. The failed status indicates some problems with the PR🟢 success
ClickHouse build checkBuilds ClickHouse in various configurations for use in further steps. You have to fix the builds that fail. Build logs often has enough information to fix the error, but you might have to reproduce the failure locally. The cmake options can be found in the build log, grepping for cmake. Use these options and follow the general build process🟢 success
Compatibility checkChecks that clickhouse binary runs on distributions with old libc versions. If it fails, ask a maintainer for help🟢 success
Docker image for serversThe 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. Integrational 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
Mergeable CheckChecks if all other necessary checks are successful🟢 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
Push to DockerhubThe check for building and pushing the CI related docker images to docker hub🟢 success
SQLancerFuzzing tests that detect logical bugs with SQLancer tool🟢 success
SqllogicRun clickhouse on the sqllogic test set against sqlite and checks that all statements are passed🟢 success
Stateful testsRuns stateful functional tests for ClickHouse binaries built in various configurations -- release, debug, with sanitizers, etc🟢 success
Stateless testsRuns stateless functional tests for ClickHouse binaries built in various configurations -- release, debug, with sanitizers, etc🟢 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

@tavplubix tavplubix self-assigned this Jul 18, 2023
@tavplubix
Copy link
Member

Integration tests failures are probably related to the changes

@Demilivor
Copy link
Contributor Author

You are right, Alexander. 
Those fails are valid and relate to my changes. Tests contain a trivial error, database name is not set, I will fix this on Monday.

Copy link
Member

@tavplubix tavplubix left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In general LGTM

- `partition_by` — устанавливает [произвольный ключ партиционирования](../../operations/server-configuration-parameters/settings.md). Нельзя использовать если используется `engine`
- `engine` - устанавливает [настройки MergeTree Engine](../../engines/table-engines/mergetree-family/mergetree.md#table_engine-mergetree-creating-a-table) для системной таблицы. Нельзя использовать если используется `partition_by`.
- `flush_interval_milliseconds` — период сброса данных из буфера в памяти в таблицу.
- `max_size` – максимальный размер в линиях для буфера с логами. Когда буфер будет заполнен полностью, сбрасывает логи на диск.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

в строках?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done!

tests/integration/test_system_flush_logs/test.py Outdated Show resolved Hide resolved
Comment on lines +90 to +93
node.restart_clickhouse()
for i in range(10):
node.query(f"select {i}")
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do we need TRUNCATE here as well? (afaik tests may be reordered)
Also we probably need to add these tests to parallel_skip.json, so they will not be executed in parallel

Copy link
Contributor Author

@Demilivor Demilivor Jul 28, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

TRUNCATE is not strictly necessary. It just removes entries from previous log queries from other test cases.

Thanks for letting me know about parallel_skip.json. I did not know that integrational tests could be run in parallel. Does parallel test execution use the same test fixture

I saw that the test order is not equal to the declaration order.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Added tests to parallel_skip.json

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does parallel test execution use the same test fixture?

I'm not sure

@@ -182,7 +182,7 @@ class NamedSessionsStorage
std::chrono::steady_clock::time_point close_cycle_time = std::chrono::steady_clock::now();
UInt64 close_cycle = 0;

void scheduleCloseSession(NamedSessionData & session, std::unique_lock<std::mutex> &)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Consider using TSA

This comment was marked as outdated.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Unfortunally, It may be some kind of Sanitizer error, at least i don't get why the error happens in this context:

unique_lock

Error text:

/home/admin/ClickHouse5/ClickHouse/src/Interpreters/Session.cpp:212:29: error: calling function 'closeSessions' requires holding mutex 'mutex' exclusively [-Werror,-Wthread-safety-analysis]
            auto interval = closeSessions();
                            ^
/home/admin/ClickHouse5/ClickHouse/src/Interpreters/Session.cpp:207:5: note: thread warning in function 'cleanThread'
    {
    ^
1 error generated.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I just reverted my changes, and keep unused unique_lock in parameters.
But later I found this:
https://clang.llvm.org/docs/ThreadSafetyAnalysis.html

To use unique_lock with TSA, we need to use PT_GUARDED_BY macro in Clang

src/Common/SystemLogBase.cpp Outdated Show resolved Hide resolved
src/Common/SystemLogBase.cpp Outdated Show resolved Hide resolved
@tavplubix
Copy link
Member

Please note that it will not guarantee that all logs are flushed on crash. However, we could implement a simple "WAL" for system logs, like:

  • Append into a TSV file (without fsync) when pushing an element into the queue
  • Remove that file when flushing the queue (and create a new one on next push)
  • Pick up that file (if any) on server start, parse TSV, insert into the corresponding table

Of course it will be too much for introspection logs (text_log, trace_log, etc), but it may be okay for session_log

But it's out of the scope of this PR

@Demilivor
Copy link
Contributor Author

Please note that it will not guarantee that all logs are flushed on crash. However, we could implement a simple "WAL" for system logs, like:

Yes, I confirm that this solution does not guarantee log flushing. It just notifies the flushing thread. 
At the moment, we have at least 3 seconds (hardcoded in signalHandler in BaseDaemon.cpp) to save the logs.
I did mention that fact in the documentation because that looks like a temporary solution, but it's better than nothing.

I like the idea of the Write Ahead Log. It could be a good addition to these changes.
I'm not going to implement it in this pull request.

@tavplubix tavplubix merged commit 3920060 into ClickHouse:master Jul 28, 2023
276 of 279 checks passed
@Demilivor
Copy link
Contributor Author

#52841 WAL implementation task.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
can be tested Allows running workflows for external contributors pr-improvement Pull request with some product improvements
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants