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.

Sign up for GitHub

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

Jump to bottom

"Unknown error" when loading Query Analytics on PMM 2.43.2 due to dirty clickhouse DB migration #3288

Open
1 task done
jessebye opened this issue Nov 7, 2024 · 5 comments
Open
1 task done

"Unknown error" when loading Query Analytics on PMM 2.43.2 due to dirty clickhouse DB migration #3288

jessebye opened this issue Nov 7, 2024 · 5 comments
Assignees
@BupycHuk
Labels
bug Bug report

Comments

@jessebye
Copy link

jessebye commented Nov 7, 2024

Description

We recently updated PMM to v2.43.2 and encountered an error in QAN "Unknown error". The network logs show 502 bad gateway responses. Looking at the qan-api2.log, we see the following error:

stdlog: qan-api2 v2.43.2.
time="2024-11-07T18:08:43.720+00:00" level=info msg="Log level: info."
time="2024-11-07T18:08:43.720+00:00" level=info msg="DSN: clickhouse://127.0.0.1:9000?database=pmm&block_size=10000&pool_size=2" component=main
stdlog: dsn:  clickhouse://127.0.0.1:9000?database=pmm&block_size=10000&pool_size=2
stdlog: Migrations: Dirty database version 17. Fix and force version.

Going back in time a ways, it looks like the migration attempted to run after the upgrade but the DB was not healthy, so it got a connection refused. When the DB became healthy again, the migration began failing.

time="2024-11-04T17:32:00.538+00:00" level=info msg="Saved 2480 buckets in 533.156749ms." component=data_ingestion
stdlog: Drop 20241004 partitions of metrics. Result: {0xc000138000 0x1408a40}, Error: <nil>
stdlog: Got SIGTERM, shutting down...
time="2024-11-04T17:32:54.288+00:00" level=info msg="Server stopped." component=JSON
time="2024-11-04T17:32:54.288+00:00" level=info msg="Server stopped." component=debug
time="2024-11-04T17:32:54.288+00:00" level=warning msg="Closing requests channel." component=data_ingestion
time="2024-11-04T17:32:54.288+00:00" level=warning msg="Requests channel closed, nothing to store." component=data_ingestion
time="2024-11-04T17:32:54.288+00:00" level=warning msg="Requests channel closed, nothing to store." component=data_ingestion
time="2024-11-04T17:32:54.288+00:00" level=info msg=Done. component=main
stdlog: qan-api2 v2.43.2.
time="2024-11-04T17:33:53.109+00:00" level=info msg="Log level: info."
time="2024-11-04T17:33:53.109+00:00" level=info msg="DSN: clickhouse://127.0.0.1:9000?database=pmm&block_size=10000&pool_size=2" component=main
stdlog: Connection: dial tcp 127.0.0.1:9000: connect: connection refused
stdlog: qan-api2 v2.43.2.
time="2024-11-04T17:33:54.188+00:00" level=info msg="Log level: info."
time="2024-11-04T17:33:54.188+00:00" level=info msg="DSN: clickhouse://127.0.0.1:9000?database=pmm&block_size=10000&pool_size=2" component=main
stdlog: dsn:  clickhouse://127.0.0.1:9000?database=pmm&block_size=10000&pool_size=2
stdlog: Migrations: driver: bad connection in line 0: INSERT INTO schema_migrations (version, dirty, sequence) VALUES (?, ?, ?)
stdlog: qan-api2 v2.43.2.
time="2024-11-04T17:33:57.730+00:00" level=info msg="Log level: info."
time="2024-11-04T17:33:57.730+00:00" level=info msg="DSN: clickhouse://127.0.0.1:9000?database=pmm&block_size=10000&pool_size=2" component=main
stdlog: Connection: dial tcp 127.0.0.1:9000: connect: connection refused
stdlog: qan-api2 v2.43.2.
time="2024-11-04T17:33:58.738+00:00" level=info msg="Log level: info."
time="2024-11-04T17:33:58.738+00:00" level=info msg="DSN: clickhouse://127.0.0.1:9000?database=pmm&block_size=10000&pool_size=2" component=main
stdlog: Connection: dial tcp 127.0.0.1:9000: connect: connection refused
stdlog: qan-api2 v2.43.2.
time="2024-11-04T17:34:00.746+00:00" level=info msg="Log level: info."
time="2024-11-04T17:34:00.746+00:00" level=info msg="DSN: clickhouse://127.0.0.1:9000?database=pmm&block_size=10000&pool_size=2" component=main
stdlog: Connection: dial tcp 127.0.0.1:9000: connect: connection refused
stdlog: qan-api2 v2.43.2.
time="2024-11-04T17:34:03.911+00:00" level=info msg="Log level: info."
time="2024-11-04T17:34:03.911+00:00" level=info msg="DSN: clickhouse://127.0.0.1:9000?database=pmm&block_size=10000&pool_size=2" component=main
stdlog: dsn:  clickhouse://127.0.0.1:9000?database=pmm&block_size=10000&pool_size=2
stdlog: Migrations: Dirty database version 17. Fix and force version.
stdlog: qan-api2 v2.43.2.

Expected Results

After updating the Helm chart version, we expected a smooth update and QAN to continue to work correctly.

Actual Results

QAN stopped working after updating the Helm chart version to latest.

Version

v2.43.2

Steps to reproduce

  1. Install PMM helm chart v1.3.6 and collect some metrics for a while
  2. Update to chart v1.3.20
  3. Navigate to QAN and observe error

Relevant logs

see snippets above (can provide additional logs if requested)

Code of Conduct

  • I agree to follow Percona Community Code of Conduct
@jessebye jessebye added the bug Bug report label Nov 7, 2024
@BupycHuk
Copy link
Member

Hi, could you share clickhouse logs for that period?

@jessebye
Copy link
Author

Hi @BupycHuk, sorry for the wait. Here are the Clickhouse logs. Sorry there are a lot - wasn't sure which ones you might need so uploaded quite a chunk.

Show logs 
2024.11.01 17:32:43.690523 [ 101 ] {} <Information> Application: Ready for connections.
2024.11.02 17:32:45.447691 [ 123 ] {f8d25849-6add-4a6b-a154-bf079f66ff36} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Remove 3 parts by covering them with empty 3 parts. With txn (1, 1, 00000000-0000-0000-0000-000000000000).
2024.11.02 17:32:45.447691 [ 123 ] {f8d25849-6add-4a6b-a154-bf079f66ff36} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Remove 3 parts by covering them with empty 3 parts. With txn (1, 1, 00000000-0000-0000-0000-000000000000).
2024.11.02 17:32:45.448538 [ 123 ] {f8d25849-6add-4a6b-a154-bf079f66ff36} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Dropped partition with 3 parts by replacing them with new empty 3 parts. With txn (1, 1, 00000000-0000-0000-0000-000000000000)
2024.11.02 17:32:45.448538 [ 123 ] {f8d25849-6add-4a6b-a154-bf079f66ff36} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Dropped partition with 3 parts by replacing them with new empty 3 parts. With txn (1, 1, 00000000-0000-0000-0000-000000000000)
2024.11.02 17:32:45.518833 [ 123 ] {f8d25849-6add-4a6b-a154-bf079f66ff36} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241002_797328_798393_11
2024.11.02 17:32:45.518833 [ 123 ] {f8d25849-6add-4a6b-a154-bf079f66ff36} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241002_797328_798393_11
2024.11.02 17:32:45.518947 [ 123 ] {f8d25849-6add-4a6b-a154-bf079f66ff36} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241002_798394_798757_8
2024.11.02 17:32:45.518988 [ 123 ] {f8d25849-6add-4a6b-a154-bf079f66ff36} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241002_798758_798770_4
2024.11.02 17:32:45.518947 [ 123 ] {f8d25849-6add-4a6b-a154-bf079f66ff36} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241002_798394_798757_8
2024.11.02 17:32:45.518988 [ 123 ] {f8d25849-6add-4a6b-a154-bf079f66ff36} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241002_798758_798770_4
2024.11.03 17:32:45.471071 [ 123 ] {1de7e12e-1650-4725-9af7-7dac9ce87918} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Remove 4 parts by covering them with empty 4 parts. With txn (1, 1, 00000000-0000-0000-0000-000000000000).
2024.11.03 17:32:45.471071 [ 123 ] {1de7e12e-1650-4725-9af7-7dac9ce87918} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Remove 4 parts by covering them with empty 4 parts. With txn (1, 1, 00000000-0000-0000-0000-000000000000).
2024.11.03 17:32:45.471329 [ 123 ] {1de7e12e-1650-4725-9af7-7dac9ce87918} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Dropped partition with 4 parts by replacing them with new empty 4 parts. With txn (1, 1, 00000000-0000-0000-0000-000000000000)
2024.11.03 17:32:45.471329 [ 123 ] {1de7e12e-1650-4725-9af7-7dac9ce87918} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Dropped partition with 4 parts by replacing them with new empty 4 parts. With txn (1, 1, 00000000-0000-0000-0000-000000000000)
2024.11.03 17:32:45.565553 [ 123 ] {1de7e12e-1650-4725-9af7-7dac9ce87918} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241003_798771_799929_10
2024.11.03 17:32:45.565553 [ 123 ] {1de7e12e-1650-4725-9af7-7dac9ce87918} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241003_798771_799929_10
2024.11.03 17:32:45.565666 [ 123 ] {1de7e12e-1650-4725-9af7-7dac9ce87918} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241003_799930_800117_7
2024.11.03 17:32:45.565705 [ 123 ] {1de7e12e-1650-4725-9af7-7dac9ce87918} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241003_800118_800165_6
2024.11.03 17:32:45.565731 [ 123 ] {1de7e12e-1650-4725-9af7-7dac9ce87918} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241003_800166_800211_6
2024.11.03 17:32:45.565666 [ 123 ] {1de7e12e-1650-4725-9af7-7dac9ce87918} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241003_799930_800117_7
2024.11.03 17:32:45.565705 [ 123 ] {1de7e12e-1650-4725-9af7-7dac9ce87918} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241003_800118_800165_6
2024.11.03 17:32:45.565731 [ 123 ] {1de7e12e-1650-4725-9af7-7dac9ce87918} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241003_800166_800211_6
2024.11.04 17:32:45.483949 [ 123 ] {f97da86e-4120-424f-835e-e2719019c6eb} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Remove 1 parts by covering them with empty 1 parts. With txn (1, 1, 00000000-0000-0000-0000-000000000000).
2024.11.04 17:32:45.483949 [ 123 ] {f97da86e-4120-424f-835e-e2719019c6eb} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Remove 1 parts by covering them with empty 1 parts. With txn (1, 1, 00000000-0000-0000-0000-000000000000).
2024.11.04 17:32:45.484058 [ 123 ] {f97da86e-4120-424f-835e-e2719019c6eb} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Dropped partition with 1 parts by replacing them with new empty 1 parts. With txn (1, 1, 00000000-0000-0000-0000-000000000000)
2024.11.04 17:32:45.484058 [ 123 ] {f97da86e-4120-424f-835e-e2719019c6eb} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Dropped partition with 1 parts by replacing them with new empty 1 parts. With txn (1, 1, 00000000-0000-0000-0000-000000000000)
2024.11.04 17:32:45.509717 [ 123 ] {f97da86e-4120-424f-835e-e2719019c6eb} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241004_800212_801651_10
2024.11.04 17:32:45.509717 [ 123 ] {f97da86e-4120-424f-835e-e2719019c6eb} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241004_800212_801651_10
2024.11.04 17:32:55.718535 [ 103 ] {} <Information> Application: Received termination signal (Terminated)
2024.11.04 17:32:55.718535 [ 103 ] {} <Information> Application: Received termination signal (Terminated)
2024.11.04 17:32:56.936850 [ 101 ] {} <Information> Application: Closed all listening sockets.
2024.11.04 17:32:56.936897 [ 101 ] {} <Information> Application: Closed connections.
2024.11.04 17:32:56.936850 [ 101 ] {} <Information> Application: Closed all listening sockets.
2024.11.04 17:32:56.936897 [ 101 ] {} <Information> Application: Closed connections.
2024.11.04 17:32:56.937397 [ 101 ] {} <Information> Application: Shutting down storages.
2024.11.04 17:32:56.937408 [ 101 ] {} <Information> Context: Shutdown disk default
2024.11.04 17:32:56.937397 [ 101 ] {} <Information> Application: Shutting down storages.
2024.11.04 17:32:56.937408 [ 101 ] {} <Information> Context: Shutdown disk default
2024.11.04 17:32:57.925601 [ 101 ] {} <Information> Application: Closed all listening sockets.
2024.11.04 17:32:57.925650 [ 101 ] {} <Information> Application: Closed connections to servers for tables.
2024.11.04 17:32:57.925601 [ 101 ] {} <Information> Application: Closed all listening sockets.
2024.11.04 17:32:57.925650 [ 101 ] {} <Information> Application: Closed connections to servers for tables.
2024.11.04 17:32:57.927594 [ 101 ] {} <Information> Application: shutting down
2024.11.04 17:32:57.927594 [ 101 ] {} <Information> Application: shutting down
2024.11.04 17:32:57.927855 [ 103 ] {} <Information> BaseDaemon: Stop SignalListener thread
2024.11.04 17:32:57.927855 [ 103 ] {} <Information> BaseDaemon: Stop SignalListener thread
2024.11.04 17:32:58.033075 [ 19 ] {} <Information> Application: Child process exited normally with code 0.
2024.11.04 17:32:58.033075 [ 19 ] {} <Information> Application: Child process exited normally with code 0.
Processing configuration file '/etc/clickhouse-server/config.xml'.
Logging information to /srv/logs/clickhouse-server.log
2024.11.04 17:33:53.116723 [ 20 ] {} <Information> Application: Will watch for the process with pid 108
2024.11.04 17:33:53.116759 [ 108 ] {} <Information> Application: Forked a child process to watch
2024.11.04 17:33:53.116957 [ 108 ] {} <Information> SentryWriter: Sending crash reports is disabled
2024.11.04 17:33:53.160463 [ 108 ] {} <Information> Application: Starting ClickHouse 23.8.2.7 (revision: 54477, git hash: f73c8f378745d0520eec7e3519fc0ce6991639b9, build id: 8D11186275018B3F7DD7F6CCF24A69C19328DA7F), PID 108
2024.11.04 17:33:53.160572 [ 108 ] {} <Information> Application: starting up
2024.11.04 17:33:53.160586 [ 108 ] {} <Information> Application: OS name: Linux, version: 6.1.112, architecture: x86_64
2024.11.04 17:33:53.163560 [ 108 ] {} <Information> Application: Available RAM: 61.75 GiB; physical cores: 16; logical cores: 16.
2024.11.04 17:33:53.116723 [ 20 ] {} <Information> Application: Will watch for the process with pid 108
2024.11.04 17:33:53.116759 [ 108 ] {} <Information> Application: Forked a child process to watch
2024.11.04 17:33:53.116957 [ 108 ] {} <Information> SentryWriter: Sending crash reports is disabled
2024.11.04 17:33:53.160463 [ 108 ] {} <Information> Application: Starting ClickHouse 23.8.2.7 (revision: 54477, git hash: f73c8f378745d0520eec7e3519fc0ce6991639b9, build id: 8D11186275018B3F7DD7F6CCF24A69C19328DA7F), PID 108
2024.11.04 17:33:53.160572 [ 108 ] {} <Information> Application: starting up
2024.11.04 17:33:53.160586 [ 108 ] {} <Information> Application: OS name: Linux, version: 6.1.112, architecture: x86_64
2024.11.04 17:33:53.163560 [ 108 ] {} <Information> Application: Available RAM: 61.75 GiB; physical cores: 16; logical cores: 16.
2024.11.04 17:33:53.289558 [ 108 ] {} <Information> Application: Integrity check of the executable successfully passed (checksum: A9BA33088A6E58B8A1BE882810065B9D)
2024.11.04 17:33:53.289611 [ 108 ] {} <Information> Application: It looks like the process has no CAP_IPC_LOCK capability, binary mlock will be disabled. It could happen due to incorrect ClickHouse package installation. You could resolve the problem manually with 'sudo setcap cap_ipc_lock=+ep /usr/bin/clickhouse'. Note that it will not work on 'nosuid' mounted filesystems.
2024.11.04 17:33:53.289558 [ 108 ] {} <Information> Application: Integrity check of the executable successfully passed (checksum: A9BA33088A6E58B8A1BE882810065B9D)
2024.11.04 17:33:53.289611 [ 108 ] {} <Information> Application: It looks like the process has no CAP_IPC_LOCK capability, binary mlock will be disabled. It could happen due to incorrect ClickHouse package installation. You could resolve the problem manually with 'sudo setcap cap_ipc_lock=+ep /usr/bin/clickhouse'. Note that it will not work on 'nosuid' mounted filesystems.
2024.11.04 17:33:53.290940 [ 108 ] {} <Information> SensitiveDataMaskerConfigRead: 1 query masking rules loaded.
2024.11.04 17:33:53.290940 [ 108 ] {} <Information> SensitiveDataMaskerConfigRead: 1 query masking rules loaded.
2024.11.04 17:33:53.295558 [ 108 ] {} <Information> Application: Setting max_server_memory_usage was set to 55.58 GiB (61.75 GiB available * 0.90 max_server_memory_usage_to_ram_ratio)
2024.11.04 17:33:53.295575 [ 108 ] {} <Information> Application: Setting merges_mutations_memory_usage_soft_limit was set to 30.88 GiB (61.75 GiB available * 0.50 merges_mutations_memory_usage_to_ram_ratio)
2024.11.04 17:33:53.295579 [ 108 ] {} <Information> Application: Merges and mutations memory limit is set to 30.88 GiB
2024.11.04 17:33:53.295558 [ 108 ] {} <Information> Application: Setting max_server_memory_usage was set to 55.58 GiB (61.75 GiB available * 0.90 max_server_memory_usage_to_ram_ratio)
2024.11.04 17:33:53.295575 [ 108 ] {} <Information> Application: Setting merges_mutations_memory_usage_soft_limit was set to 30.88 GiB (61.75 GiB available * 0.50 merges_mutations_memory_usage_to_ram_ratio)
2024.11.04 17:33:53.295579 [ 108 ] {} <Information> Application: Merges and mutations memory limit is set to 30.88 GiB
2024.11.04 17:33:53.295792 [ 108 ] {} <Information> BackgroundSchedulePool/BgBufSchPool: Create BackgroundSchedulePool with 16 threads
2024.11.04 17:33:53.295792 [ 108 ] {} <Information> BackgroundSchedulePool/BgBufSchPool: Create BackgroundSchedulePool with 16 threads
2024.11.04 17:33:53.296310 [ 108 ] {} <Information> BackgroundSchedulePool/BgSchPool: Create BackgroundSchedulePool with 128 threads
2024.11.04 17:33:53.296310 [ 108 ] {} <Information> BackgroundSchedulePool/BgSchPool: Create BackgroundSchedulePool with 128 threads
2024.11.04 17:33:53.301788 [ 108 ] {} <Information> BackgroundSchedulePool/BgMBSchPool: Create BackgroundSchedulePool with 16 threads
2024.11.04 17:33:53.301788 [ 108 ] {} <Information> BackgroundSchedulePool/BgMBSchPool: Create BackgroundSchedulePool with 16 threads
2024.11.04 17:33:53.303945 [ 108 ] {} <Information> BackgroundSchedulePool/BgDistSchPool: Create BackgroundSchedulePool with 16 threads
2024.11.04 17:33:53.303945 [ 108 ] {} <Information> BackgroundSchedulePool/BgDistSchPool: Create BackgroundSchedulePool with 16 threads
2024.11.04 17:33:53.308253 [ 108 ] {} <Error> CertificateReloader: Cannot obtain modification time for certificate file /etc/clickhouse-server/server.crt, skipping update. errno: 2, strerror: No such file or directory2024.11.04 17:33:53.308253 [ 108 ] {} <Error> CertificateReloader: Cannot obtain modification time for certificate file /etc/clickhouse-server/server.crt, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:33:53.308354 [ 108 ] {} <Error> CertificateReloader: Cannot obtain modification time for key file /etc/clickhouse-server/server.key, skipping update. errno: 2, strerror: No such file or directory

2024.11.04 17:33:53.308354 [ 108 ] {} <Error> CertificateReloader: Cannot obtain modification time for key file /etc/clickhouse-server/server.key, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:33:53.313572 [ 108 ] {} <Error> CertificateReloader: Poco::Exception. Code: 1000, e.code() = 0, SSL context exception: Error loading private key from file /etc/clickhouse-server/server.key: error:02000002:system library:OPENSSL_internal:No such file or directory (version 23.8.2.7 (official build))
2024.11.04 17:33:53.313572 [ 108 ] {} <Error> CertificateReloader: Poco::Exception. Code: 1000, e.code() = 0, SSL context exception: Error loading private key from file /etc/clickhouse-server/server.key: error:02000002:system library:OPENSSL_internal:No such file or directory (version 23.8.2.7 (official build))
2024.11.04 17:33:53.313900 [ 108 ] {} <Information> Application: Listening for replica communication (interserver): http://[::1]:9009
2024.11.04 17:33:53.313951 [ 108 ] {} <Information> Application: Listening for replica communication (interserver): http://127.0.0.1:9009
2024.11.04 17:33:53.313900 [ 108 ] {} <Information> Application: Listening for replica communication (interserver): http://[::1]:9009
2024.11.04 17:33:53.313951 [ 108 ] {} <Information> Application: Listening for replica communication (interserver): http://127.0.0.1:9009
2024.11.04 17:33:53.319554 [ 108 ] {} <Information> Context: Initialized background executor for merges and mutations with num_threads=16, num_tasks=32, scheduling_policy=round_robin
2024.11.04 17:33:53.319554 [ 108 ] {} <Information> Context: Initialized background executor for merges and mutations with num_threads=16, num_tasks=32, scheduling_policy=round_robin
2024.11.04 17:33:53.319867 [ 108 ] {} <Information> Context: Initialized background executor for move operations with num_threads=8, num_tasks=8
2024.11.04 17:33:53.319867 [ 108 ] {} <Information> Context: Initialized background executor for move operations with num_threads=8, num_tasks=8
2024.11.04 17:33:53.320152 [ 108 ] {} <Information> Context: Initialized background executor for fetches with num_threads=8, num_tasks=8
2024.11.04 17:33:53.320152 [ 108 ] {} <Information> Context: Initialized background executor for fetches with num_threads=8, num_tasks=8
2024.11.04 17:33:53.320430 [ 108 ] {} <Information> Context: Initialized background executor for common operations (e.g. clearing old parts) with num_threads=8, num_tasks=8
2024.11.04 17:33:53.320430 [ 108 ] {} <Information> Context: Initialized background executor for common operations (e.g. clearing old parts) with num_threads=8, num_tasks=8
2024.11.04 17:33:53.320981 [ 108 ] {} <Information> DNSCacheUpdater: Update period 15 seconds
2024.11.04 17:33:53.320998 [ 108 ] {} <Information> Application: Loading metadata from /srv/clickhouse/
2024.11.04 17:33:53.320981 [ 108 ] {} <Information> DNSCacheUpdater: Update period 15 seconds
2024.11.04 17:33:53.320998 [ 108 ] {} <Information> Application: Loading metadata from /srv/clickhouse/
2024.11.04 17:33:53.327945 [ 108 ] {} <Information> DatabaseAtomic (system): Metadata processed, database system has 10 tables and 0 dictionaries in total.
2024.11.04 17:33:53.327965 [ 108 ] {} <Information> TablesLoader: Parsed metadata of 10 tables in 1 databases in 0.003817008 sec
2024.11.04 17:33:53.327945 [ 108 ] {} <Information> DatabaseAtomic (system): Metadata processed, database system has 10 tables and 0 dictionaries in total.
2024.11.04 17:33:53.327965 [ 108 ] {} <Information> TablesLoader: Parsed metadata of 10 tables in 1 databases in 0.003817008 sec
2024.11.04 17:33:53.328594 [ 108 ] {} <Information> TablesLoader: Loading 10 tables with dependency level 0
2024.11.04 17:33:53.328594 [ 108 ] {} <Information> TablesLoader: Loading 10 tables with dependency level 0
2024.11.04 17:33:53.519916 [ 108 ] {} <Information> DatabaseAtomic (system): Starting up tables.
2024.11.04 17:33:53.519916 [ 108 ] {} <Information> DatabaseAtomic (system): Starting up tables.
2024.11.04 17:33:53.537537 [ 108 ] {} <Information> DatabaseCatalog: Found 0 partially dropped tables. Will load them and retry removal.
2024.11.04 17:33:53.537537 [ 108 ] {} <Information> DatabaseCatalog: Found 0 partially dropped tables. Will load them and retry removal.
2024.11.04 17:33:53.540834 [ 108 ] {} <Information> DatabaseAtomic (default): Metadata processed, database default has 0 tables and 0 dictionaries in total.
2024.11.04 17:33:53.540834 [ 108 ] {} <Information> DatabaseAtomic (default): Metadata processed, database default has 0 tables and 0 dictionaries in total.
2024.11.04 17:33:53.542333 [ 108 ] {} <Information> DatabaseAtomic (pmm): Metadata processed, database pmm has 2 tables and 0 dictionaries in total.
2024.11.04 17:33:53.542356 [ 108 ] {} <Information> TablesLoader: Parsed metadata of 2 tables in 2 databases in 0.001566644 sec
2024.11.04 17:33:53.542333 [ 108 ] {} <Information> DatabaseAtomic (pmm): Metadata processed, database pmm has 2 tables and 0 dictionaries in total.
2024.11.04 17:33:53.542356 [ 108 ] {} <Information> TablesLoader: Parsed metadata of 2 tables in 2 databases in 0.001566644 sec
2024.11.04 17:33:53.542453 [ 108 ] {} <Information> TablesLoader: Loading 2 tables with dependency level 0
2024.11.04 17:33:53.542453 [ 108 ] {} <Information> TablesLoader: Loading 2 tables with dependency level 0
2024.11.04 17:33:54.143318 [ 108 ] {} <Information> DatabaseAtomic (default): Starting up tables.
2024.11.04 17:33:54.143350 [ 108 ] {} <Information> DatabaseAtomic (pmm): Starting up tables.
2024.11.04 17:33:54.143318 [ 108 ] {} <Information> DatabaseAtomic (default): Starting up tables.
2024.11.04 17:33:54.143350 [ 108 ] {} <Information> DatabaseAtomic (pmm): Starting up tables.
2024.11.04 17:33:54.143471 [ 439 ] {} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241004_800212_801651_10
2024.11.04 17:33:54.143471 [ 439 ] {} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241004_800212_801651_10
2024.11.04 17:33:54.143847 [ 108 ] {} <Information> UserDefinedSQLObjectsLoaderFromDisk: Loading user defined objects from /srv/clickhouse/user_defined/
2024.11.04 17:33:54.143847 [ 108 ] {} <Information> UserDefinedSQLObjectsLoaderFromDisk: Loading user defined objects from /srv/clickhouse/user_defined/
2024.11.04 17:33:54.143921 [ 108 ] {} <Information> Application: Tasks stats provider: procfs
2024.11.04 17:33:54.143921 [ 108 ] {} <Information> Application: Tasks stats provider: procfs
2024.11.04 17:33:54.143934 [ 108 ] {} <Information> Application: It looks like the process has no CAP_SYS_NICE capability, the setting 'os_thread_priority' will have no effect. It could happen due to incorrect ClickHouse package installation. You could resolve the problem manually with 'sudo setcap cap_sys_nice=+ep /usr/bin/clickhouse'. Note that it will not work on 'nosuid' mounted filesystems.
2024.11.04 17:33:54.143934 [ 108 ] {} <Information> Application: It looks like the process has no CAP_SYS_NICE capability, the setting 'os_thread_priority' will have no effect. It could happen due to incorrect ClickHouse package installation. You could resolve the problem manually with 'sudo setcap cap_sys_nice=+ep /usr/bin/clickhouse'. Note that it will not work on 'nosuid' mounted filesystems.
2024.11.04 17:33:54.260777 [ 108 ] {} <Error> CertificateReloader: Cannot obtain modification time for certificate file /etc/clickhouse-server/server.crt, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:33:54.260804 [ 108 ] {} <Error> CertificateReloader: Cannot obtain modification time for key file /etc/clickhouse-server/server.key, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:33:54.260777 [ 108 ] {} <Error> CertificateReloader: Cannot obtain modification time for certificate file /etc/clickhouse-server/server.crt, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:33:54.260804 [ 108 ] {} <Error> CertificateReloader: Cannot obtain modification time for key file /etc/clickhouse-server/server.key, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:33:54.264151 [ 108 ] {} <Error> CertificateReloader: Poco::Exception. Code: 1000, e.code() = 0, SSL context exception: Error loading private key from file /etc/clickhouse-server/server.key: error:02000002:system library:OPENSSL_internal:No such file or directory (version 23.8.2.7 (official build))
2024.11.04 17:33:54.264151 [ 108 ] {} <Error> CertificateReloader: Poco::Exception. Code: 1000, e.code() = 0, SSL context exception: Error loading private key from file /etc/clickhouse-server/server.key: error:02000002:system library:OPENSSL_internal:No such file or directory (version 23.8.2.7 (official build))
2024.11.04 17:33:54.265806 [ 108 ] {} <Information> Application: Listening for http://[::1]:8123
2024.11.04 17:33:54.265806 [ 108 ] {} <Information> Application: Listening for http://[::1]:8123
2024.11.04 17:33:54.265853 [ 108 ] {} <Information> Application: Listening for native protocol (tcp): [::1]:9000
2024.11.04 17:33:54.265853 [ 108 ] {} <Information> Application: Listening for native protocol (tcp): [::1]:9000
2024.11.04 17:33:54.265891 [ 108 ] {} <Information> Application: Listening for MySQL compatibility protocol: [::1]:9004
2024.11.04 17:33:54.265891 [ 108 ] {} <Information> Application: Listening for MySQL compatibility protocol: [::1]:9004
2024.11.04 17:33:54.265924 [ 108 ] {} <Information> Application: Listening for PostgreSQL compatibility protocol: [::1]:9005
2024.11.04 17:33:54.265957 [ 108 ] {} <Information> Application: Listening for Prometheus: http://[::1]:9363
2024.11.04 17:33:54.265924 [ 108 ] {} <Information> Application: Listening for PostgreSQL compatibility protocol: [::1]:9005
2024.11.04 17:33:54.265985 [ 108 ] {} <Information> Application: Listening for http://127.0.0.1:8123
2024.11.04 17:33:54.265957 [ 108 ] {} <Information> Application: Listening for Prometheus: http://[::1]:9363
2024.11.04 17:33:54.265985 [ 108 ] {} <Information> Application: Listening for http://127.0.0.1:8123
2024.11.04 17:33:54.266021 [ 108 ] {} <Information> Application: Listening for native protocol (tcp): 127.0.0.1:9000
2024.11.04 17:33:54.266021 [ 108 ] {} <Information> Application: Listening for native protocol (tcp): 127.0.0.1:9000
2024.11.04 17:33:54.266054 [ 108 ] {} <Information> Application: Listening for MySQL compatibility protocol: 127.0.0.1:9004
2024.11.04 17:33:54.266054 [ 108 ] {} <Information> Application: Listening for MySQL compatibility protocol: 127.0.0.1:9004
2024.11.04 17:33:54.266094 [ 108 ] {} <Information> Application: Listening for PostgreSQL compatibility protocol: 127.0.0.1:9005
2024.11.04 17:33:54.266094 [ 108 ] {} <Information> Application: Listening for PostgreSQL compatibility protocol: 127.0.0.1:9005
2024.11.04 17:33:54.266142 [ 108 ] {} <Information> Application: Listening for Prometheus: http://127.0.0.1:9363
2024.11.04 17:33:54.266150 [ 108 ] {} <Information> Application: Ready for connections.
2024.11.04 17:33:54.266142 [ 108 ] {} <Information> Application: Listening for Prometheus: http://127.0.0.1:9363
2024.11.04 17:33:54.266150 [ 108 ] {} <Information> Application: Ready for connections.
2024.11.04 17:33:54.474679 [ 125 ] {825f69e1-1015-455e-bc00-5ab4b62f0a03} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Added mutation: mutation_848053.txt
2024.11.04 17:33:54.474718 [ 125 ] {825f69e1-1015-455e-bc00-5ab4b62f0a03} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Waiting mutation: mutation_848053.txt
2024.11.04 17:33:54.474679 [ 125 ] {825f69e1-1015-455e-bc00-5ab4b62f0a03} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Added mutation: mutation_848053.txt
2024.11.04 17:33:54.474718 [ 125 ] {825f69e1-1015-455e-bc00-5ab4b62f0a03} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Waiting mutation: mutation_848053.txt
2024.11.04 17:33:56.500889 [ 109 ] {} <Information> Application: Received termination signal (Terminated)
2024.11.04 17:33:56.500889 [ 109 ] {} <Information> Application: Received termination signal (Terminated)
2024.11.04 17:33:57.720444 [ 125 ] {825f69e1-1015-455e-bc00-5ab4b62f0a03} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Mutation mutation_848053.txt done
2024.11.04 17:33:57.720444 [ 125 ] {825f69e1-1015-455e-bc00-5ab4b62f0a03} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Mutation mutation_848053.txt done
2024.11.04 17:33:58.019766 [ 108 ] {} <Warning> Application: Closed all listening sockets. Waiting for 3 outstanding connections.
2024.11.04 17:33:58.019766 [ 108 ] {} <Warning> Application: Closed all listening sockets. Waiting for 3 outstanding connections.
2024.11.04 17:34:02.923420 [ 108 ] {} <Warning> Application: Closed connections. But 1 remain. Tip: To increase wait time add to config: <shutdown_wait_unfinished>60</shutdown_wait_unfinished>
2024.11.04 17:34:02.923461 [ 108 ] {} <Warning> Application: Will shutdown forcefully.
2024.11.04 17:34:02.923420 [ 108 ] {} <Warning> Application: Closed connections. But 1 remain. Tip: To increase wait time add to config: <shutdown_wait_unfinished>60</shutdown_wait_unfinished>
2024.11.04 17:34:02.923461 [ 108 ] {} <Warning> Application: Will shutdown forcefully.
2024.11.04 17:34:02.945886 [ 20 ] {} <Information> Application: Child process exited normally with code 0.
2024.11.04 17:34:02.945886 [ 20 ] {} <Information> Application: Child process exited normally with code 0.
Processing configuration file '/etc/clickhouse-server/config.xml'.
Logging information to /srv/logs/clickhouse-server.log
2024.11.04 17:34:02.973245 [ 922 ] {} <Information> Application: Will watch for the process with pid 923
2024.11.04 17:34:02.973290 [ 923 ] {} <Information> Application: Forked a child process to watch
2024.11.04 17:34:02.973245 [ 922 ] {} <Information> Application: Will watch for the process with pid 923
2024.11.04 17:34:02.973290 [ 923 ] {} <Information> Application: Forked a child process to watch
2024.11.04 17:34:02.973620 [ 923 ] {} <Information> SentryWriter: Sending crash reports is disabled
2024.11.04 17:34:02.973620 [ 923 ] {} <Information> SentryWriter: Sending crash reports is disabled
2024.11.04 17:34:03.014142 [ 923 ] {} <Information> Application: Starting ClickHouse 23.8.2.7 (revision: 54477, git hash: f73c8f378745d0520eec7e3519fc0ce6991639b9, build id: 8D11186275018B3F7DD7F6CCF24A69C19328DA7F), PID 923
2024.11.04 17:34:03.014224 [ 923 ] {} <Information> Application: starting up
2024.11.04 17:34:03.014236 [ 923 ] {} <Information> Application: OS name: Linux, version: 6.1.112, architecture: x86_64
2024.11.04 17:34:03.014142 [ 923 ] {} <Information> Application: Starting ClickHouse 23.8.2.7 (revision: 54477, git hash: f73c8f378745d0520eec7e3519fc0ce6991639b9, build id: 8D11186275018B3F7DD7F6CCF24A69C19328DA7F), PID 923
2024.11.04 17:34:03.014224 [ 923 ] {} <Information> Application: starting up
2024.11.04 17:34:03.014236 [ 923 ] {} <Information> Application: OS name: Linux, version: 6.1.112, architecture: x86_64
2024.11.04 17:34:03.016815 [ 923 ] {} <Information> Application: Available RAM: 61.75 GiB; physical cores: 16; logical cores: 16.
2024.11.04 17:34:03.016815 [ 923 ] {} <Information> Application: Available RAM: 61.75 GiB; physical cores: 16; logical cores: 16.
2024.11.04 17:34:03.143728 [ 923 ] {} <Information> Application: Integrity check of the executable successfully passed (checksum: A9BA33088A6E58B8A1BE882810065B9D)
2024.11.04 17:34:03.143765 [ 923 ] {} <Information> Application: It looks like the process has no CAP_IPC_LOCK capability, binary mlock will be disabled. It could happen due to incorrect ClickHouse package installation. You could resolve the problem manually with 'sudo setcap cap_ipc_lock=+ep /usr/bin/clickhouse'. Note that it will not work on 'nosuid' mounted filesystems.
2024.11.04 17:34:03.143817 [ 923 ] {} <Information> StatusFile: Status file /srv/clickhouse/status already exists - unclean restart. Contents:
PID: 108
Started at: 2024-11-04 17:33:53
Revision: 54477

2024.11.04 17:34:03.143728 [ 923 ] {} <Information> Application: Integrity check of the executable successfully passed (checksum: A9BA33088A6E58B8A1BE882810065B9D)
2024.11.04 17:34:03.143765 [ 923 ] {} <Information> Application: It looks like the process has no CAP_IPC_LOCK capability, binary mlock will be disabled. It could happen due to incorrect ClickHouse package installation. You could resolve the problem manually with 'sudo setcap cap_ipc_lock=+ep /usr/bin/clickhouse'. Note that it will not work on 'nosuid' mounted filesystems.
2024.11.04 17:34:03.143817 [ 923 ] {} <Information> StatusFile: Status file /srv/clickhouse/status already exists - unclean restart. Contents:
PID: 108
Started at: 2024-11-04 17:33:53
Revision: 54477

2024.11.04 17:34:03.144218 [ 923 ] {} <Information> SensitiveDataMaskerConfigRead: 1 query masking rules loaded.
2024.11.04 17:34:03.144218 [ 923 ] {} <Information> SensitiveDataMaskerConfigRead: 1 query masking rules loaded.
2024.11.04 17:34:03.148525 [ 923 ] {} <Information> Application: Setting max_server_memory_usage was set to 55.58 GiB (61.75 GiB available * 0.90 max_server_memory_usage_to_ram_ratio)
2024.11.04 17:34:03.148538 [ 923 ] {} <Information> Application: Setting merges_mutations_memory_usage_soft_limit was set to 30.88 GiB (61.75 GiB available * 0.50 merges_mutations_memory_usage_to_ram_ratio)
2024.11.04 17:34:03.148542 [ 923 ] {} <Information> Application: Merges and mutations memory limit is set to 30.88 GiB
2024.11.04 17:34:03.148745 [ 923 ] {} <Information> BackgroundSchedulePool/BgBufSchPool: Create BackgroundSchedulePool with 16 threads
2024.11.04 17:34:03.148525 [ 923 ] {} <Information> Application: Setting max_server_memory_usage was set to 55.58 GiB (61.75 GiB available * 0.90 max_server_memory_usage_to_ram_ratio)
2024.11.04 17:34:03.148538 [ 923 ] {} <Information> Application: Setting merges_mutations_memory_usage_soft_limit was set to 30.88 GiB (61.75 GiB available * 0.50 merges_mutations_memory_usage_to_ram_ratio)
2024.11.04 17:34:03.148542 [ 923 ] {} <Information> Application: Merges and mutations memory limit is set to 30.88 GiB
2024.11.04 17:34:03.148745 [ 923 ] {} <Information> BackgroundSchedulePool/BgBufSchPool: Create BackgroundSchedulePool with 16 threads
2024.11.04 17:34:03.149285 [ 923 ] {} <Information> BackgroundSchedulePool/BgSchPool: Create BackgroundSchedulePool with 128 threads
2024.11.04 17:34:03.149285 [ 923 ] {} <Information> BackgroundSchedulePool/BgSchPool: Create BackgroundSchedulePool with 128 threads
2024.11.04 17:34:03.153290 [ 923 ] {} <Information> BackgroundSchedulePool/BgMBSchPool: Create BackgroundSchedulePool with 16 threads
2024.11.04 17:34:03.153290 [ 923 ] {} <Information> BackgroundSchedulePool/BgMBSchPool: Create BackgroundSchedulePool with 16 threads
2024.11.04 17:34:03.153968 [ 923 ] {} <Information> BackgroundSchedulePool/BgDistSchPool: Create BackgroundSchedulePool with 16 threads
2024.11.04 17:34:03.153968 [ 923 ] {} <Information> BackgroundSchedulePool/BgDistSchPool: Create BackgroundSchedulePool with 16 threads
2024.11.04 17:34:03.154612 [ 923 ] {} <Error> CertificateReloader: Cannot obtain modification time for certificate file /etc/clickhouse-server/server.crt, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:34:03.154622 [ 923 ] {} <Error> CertificateReloader: Cannot obtain modification time for key file /etc/clickhouse-server/server.key, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:34:03.154612 [ 923 ] {} <Error> CertificateReloader: Cannot obtain modification time for certificate file /etc/clickhouse-server/server.crt, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:34:03.154622 [ 923 ] {} <Error> CertificateReloader: Cannot obtain modification time for key file /etc/clickhouse-server/server.key, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:34:03.166278 [ 923 ] {} <Error> CertificateReloader: Poco::Exception. Code: 1000, e.code() = 0, SSL context exception: Error loading private key from file /etc/clickhouse-server/server.key: error:02000002:system library:OPENSSL_internal:No such file or directory (version 23.8.2.7 (official build))
2024.11.04 17:34:03.166278 [ 923 ] {} <Error> CertificateReloader: Poco::Exception. Code: 1000, e.code() = 0, SSL context exception: Error loading private key from file /etc/clickhouse-server/server.key: error:02000002:system library:OPENSSL_internal:No such file or directory (version 23.8.2.7 (official build))
2024.11.04 17:34:03.166598 [ 923 ] {} <Information> Application: Listening for replica communication (interserver): http://[::1]:9009
2024.11.04 17:34:03.166598 [ 923 ] {} <Information> Application: Listening for replica communication (interserver): http://[::1]:9009
2024.11.04 17:34:03.166637 [ 923 ] {} <Information> Application: Listening for replica communication (interserver): http://127.0.0.1:9009
2024.11.04 17:34:03.166637 [ 923 ] {} <Information> Application: Listening for replica communication (interserver): http://127.0.0.1:9009
2024.11.04 17:34:03.170085 [ 923 ] {} <Information> Context: Initialized background executor for merges and mutations with num_threads=16, num_tasks=32, scheduling_policy=round_robin
2024.11.04 17:34:03.170085 [ 923 ] {} <Information> Context: Initialized background executor for merges and mutations with num_threads=16, num_tasks=32, scheduling_policy=round_robin
2024.11.04 17:34:03.170417 [ 923 ] {} <Information> Context: Initialized background executor for move operations with num_threads=8, num_tasks=8
2024.11.04 17:34:03.170417 [ 923 ] {} <Information> Context: Initialized background executor for move operations with num_threads=8, num_tasks=8
2024.11.04 17:34:03.171489 [ 923 ] {} <Information> Context: Initialized background executor for fetches with num_threads=8, num_tasks=8
2024.11.04 17:34:03.171489 [ 923 ] {} <Information> Context: Initialized background executor for fetches with num_threads=8, num_tasks=8
2024.11.04 17:34:03.171920 [ 923 ] {} <Information> Context: Initialized background executor for common operations (e.g. clearing old parts) with num_threads=8, num_tasks=8
2024.11.04 17:34:03.171920 [ 923 ] {} <Information> Context: Initialized background executor for common operations (e.g. clearing old parts) with num_threads=8, num_tasks=8
2024.11.04 17:34:03.172457 [ 923 ] {} <Information> DNSCacheUpdater: Update period 15 seconds
2024.11.04 17:34:03.172475 [ 923 ] {} <Information> Application: Loading metadata from /srv/clickhouse/
2024.11.04 17:34:03.172457 [ 923 ] {} <Information> DNSCacheUpdater: Update period 15 seconds
2024.11.04 17:34:03.172475 [ 923 ] {} <Information> Application: Loading metadata from /srv/clickhouse/
2024.11.04 17:34:03.175666 [ 923 ] {} <Information> DatabaseAtomic (system): Metadata processed, database system has 10 tables and 0 dictionaries in total.
2024.11.04 17:34:03.175691 [ 923 ] {} <Information> TablesLoader: Parsed metadata of 10 tables in 1 databases in 0.002538393 sec
2024.11.04 17:34:03.175666 [ 923 ] {} <Information> DatabaseAtomic (system): Metadata processed, database system has 10 tables and 0 dictionaries in total.
2024.11.04 17:34:03.175691 [ 923 ] {} <Information> TablesLoader: Parsed metadata of 10 tables in 1 databases in 0.002538393 sec
2024.11.04 17:34:03.176243 [ 923 ] {} <Information> TablesLoader: Loading 10 tables with dependency level 0
2024.11.04 17:34:03.176243 [ 923 ] {} <Information> TablesLoader: Loading 10 tables with dependency level 0
2024.11.04 17:34:03.343219 [ 923 ] {} <Information> DatabaseAtomic (system): Starting up tables.
2024.11.04 17:34:03.343219 [ 923 ] {} <Information> DatabaseAtomic (system): Starting up tables.
2024.11.04 17:34:03.363842 [ 923 ] {} <Information> DatabaseCatalog: Found 0 partially dropped tables. Will load them and retry removal.
2024.11.04 17:34:03.363842 [ 923 ] {} <Information> DatabaseCatalog: Found 0 partially dropped tables. Will load them and retry removal.
2024.11.04 17:34:03.364048 [ 923 ] {} <Information> DatabaseAtomic (default): Metadata processed, database default has 0 tables and 0 dictionaries in total.
2024.11.04 17:34:03.364048 [ 923 ] {} <Information> DatabaseAtomic (default): Metadata processed, database default has 0 tables and 0 dictionaries in total.
2024.11.04 17:34:03.364730 [ 923 ] {} <Information> DatabaseAtomic (pmm): Metadata processed, database pmm has 2 tables and 0 dictionaries in total.
2024.11.04 17:34:03.364758 [ 923 ] {} <Information> TablesLoader: Parsed metadata of 2 tables in 2 databases in 0.000727615 sec
2024.11.04 17:34:03.364730 [ 923 ] {} <Information> DatabaseAtomic (pmm): Metadata processed, database pmm has 2 tables and 0 dictionaries in total.
2024.11.04 17:34:03.364758 [ 923 ] {} <Information> TablesLoader: Parsed metadata of 2 tables in 2 databases in 0.000727615 sec
2024.11.04 17:34:03.364886 [ 923 ] {} <Information> TablesLoader: Loading 2 tables with dependency level 0
2024.11.04 17:34:03.364886 [ 923 ] {} <Information> TablesLoader: Loading 2 tables with dependency level 0
2024.11.04 17:34:03.451715 [ 923 ] {} <Information> DatabaseAtomic (default): Starting up tables.
2024.11.04 17:34:03.451742 [ 923 ] {} <Information> DatabaseAtomic (pmm): Starting up tables.
2024.11.04 17:34:03.451715 [ 923 ] {} <Information> DatabaseAtomic (default): Starting up tables.
2024.11.04 17:34:03.451742 [ 923 ] {} <Information> DatabaseAtomic (pmm): Starting up tables.
2024.11.04 17:34:03.452044 [ 1174 ] {} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241004_800212_801651_10
2024.11.04 17:34:03.452044 [ 1174 ] {} <Information> pmm.metrics (cf59123d-0921-4a66-baed-ba053131a5e4): Will drop empty part 20241004_800212_801651_10
2024.11.04 17:34:03.452595 [ 923 ] {} <Information> loadMetadata: Found convert_ordinary_to_atomic file in flags directory, will try to convert all Ordinary databases to Atomic
2024.11.04 17:34:03.452616 [ 923 ] {} <Information> loadMetadata: Conversion finished, removing convert_ordinary_to_atomic flag
2024.11.04 17:34:03.452595 [ 923 ] {} <Information> loadMetadata: Found convert_ordinary_to_atomic file in flags directory, will try to convert all Ordinary databases to Atomic
2024.11.04 17:34:03.452616 [ 923 ] {} <Information> loadMetadata: Conversion finished, removing convert_ordinary_to_atomic flag
2024.11.04 17:34:03.462520 [ 923 ] {} <Information> UserDefinedSQLObjectsLoaderFromDisk: Loading user defined objects from /srv/clickhouse/user_defined/
2024.11.04 17:34:03.462520 [ 923 ] {} <Information> UserDefinedSQLObjectsLoaderFromDisk: Loading user defined objects from /srv/clickhouse/user_defined/
2024.11.04 17:34:03.463853 [ 923 ] {} <Information> Application: Tasks stats provider: procfs
2024.11.04 17:34:03.463880 [ 923 ] {} <Information> Application: It looks like the process has no CAP_SYS_NICE capability, the setting 'os_thread_priority' will have no effect. It could happen due to incorrect ClickHouse package installation. You could resolve the problem manually with 'sudo setcap cap_sys_nice=+ep /usr/bin/clickhouse'. Note that it will not work on 'nosuid' mounted filesystems.
2024.11.04 17:34:03.463853 [ 923 ] {} <Information> Application: Tasks stats provider: procfs
2024.11.04 17:34:03.463880 [ 923 ] {} <Information> Application: It looks like the process has no CAP_SYS_NICE capability, the setting 'os_thread_priority' will have no effect. It could happen due to incorrect ClickHouse package installation. You could resolve the problem manually with 'sudo setcap cap_sys_nice=+ep /usr/bin/clickhouse'. Note that it will not work on 'nosuid' mounted filesystems.
2024.11.04 17:34:03.572861 [ 923 ] {} <Error> CertificateReloader: Cannot obtain modification time for certificate file /etc/clickhouse-server/server.crt, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:34:03.572882 [ 923 ] {} <Error> CertificateReloader: Cannot obtain modification time for key file /etc/clickhouse-server/server.key, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:34:03.572861 [ 923 ] {} <Error> CertificateReloader: Cannot obtain modification time for certificate file /etc/clickhouse-server/server.crt, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:34:03.572882 [ 923 ] {} <Error> CertificateReloader: Cannot obtain modification time for key file /etc/clickhouse-server/server.key, skipping update. errno: 2, strerror: No such file or directory
2024.11.04 17:34:03.575872 [ 923 ] {} <Error> CertificateReloader: Poco::Exception. Code: 1000, e.code() = 0, SSL context exception: Error loading private key from file /etc/clickhouse-server/server.key: error:02000002:system library:OPENSSL_internal:No such file or directory (version 23.8.2.7 (official build))
2024.11.04 17:34:03.575872 [ 923 ] {} <Error> CertificateReloader: Poco::Exception. Code: 1000, e.code() = 0, SSL context exception: Error loading private key from file /etc/clickhouse-server/server.key: error:02000002:system library:OPENSSL_internal:No such file or directory (version 23.8.2.7 (official build))
2024.11.04 17:34:03.577586 [ 923 ] {} <Information> Application: Listening for http://[::1]:8123
2024.11.04 17:34:03.577586 [ 923 ] {} <Information> Application: Listening for http://[::1]:8123
2024.11.04 17:34:03.577636 [ 923 ] {} <Information> Application: Listening for native protocol (tcp): [::1]:9000
2024.11.04 17:34:03.577636 [ 923 ] {} <Information> Application: Listening for native protocol (tcp): [::1]:9000
2024.11.04 17:34:03.577667 [ 923 ] {} <Information> Application: Listening for MySQL compatibility protocol: [::1]:9004
2024.11.04 17:34:03.577667 [ 923 ] {} <Information> Application: Listening for MySQL compatibility protocol: [::1]:9004
2024.11.04 17:34:03.577700 [ 923 ] {} <Information> Application: Listening for PostgreSQL compatibility protocol: [::1]:9005
2024.11.04 17:34:03.577700 [ 923 ] {} <Information> Application: Listening for PostgreSQL compatibility protocol: [::1]:9005
2024.11.04 17:34:03.577739 [ 923 ] {} <Information> Application: Listening for Prometheus: http://[::1]:9363
2024.11.04 17:34:03.577772 [ 923 ] {} <Information> Application: Listening for http://127.0.0.1:8123
2024.11.04 17:34:03.577739 [ 923 ] {} <Information> Application: Listening for Prometheus: http://[::1]:9363
2024.11.04 17:34:03.577772 [ 923 ] {} <Information> Application: Listening for http://127.0.0.1:8123
2024.11.04 17:34:03.577802 [ 923 ] {} <Information> Application: Listening for native protocol (tcp): 127.0.0.1:9000
2024.11.04 17:34:03.577802 [ 923 ] {} <Information> Application: Listening for native protocol (tcp): 127.0.0.1:9000
2024.11.04 17:34:03.577844 [ 923 ] {} <Information> Application: Listening for MySQL compatibility protocol: 127.0.0.1:9004
2024.11.04 17:34:03.577844 [ 923 ] {} <Information> Application: Listening for MySQL compatibility protocol: 127.0.0.1:9004
2024.11.04 17:34:03.577885 [ 923 ] {} <Information> Application: Listening for PostgreSQL compatibility protocol: 127.0.0.1:9005
2024.11.04 17:34:03.577885 [ 923 ] {} <Information> Application: Listening for PostgreSQL compatibility protocol: 127.0.0.1:9005
2024.11.04 17:34:03.577914 [ 923 ] {} <Information> Application: Listening for Prometheus: http://127.0.0.1:9363
2024.11.04 17:34:03.577920 [ 923 ] {} <Information> Application: Ready for connections.
2024.11.04 17:34:03.577914 [ 923 ] {} <Information> Application: Listening for Prometheus: http://127.0.0.1:9363
2024.11.04 17:34:03.577920 [ 923 ] {} <Information> Application: Ready for connections.

@Grokon
Copy link

Grokon commented Nov 26, 2024 •
edited
Loading

Hello! I also encountered this issue when attempting to update from v2.42.0 to v2.43.2. I found this thread and carried out migration 17 manually. Then, I executed the following: insert into schema_migrations (version, dirty, sequence) values(17, 0, toUnixTimestamp(NOW())*1000000000); and successfully started the qan-api.

@jessebye
Copy link
Author

@Grokon Wow, thank you so much for that! It solved the problem for me as well!

@yauhen-vastraknutau-epam
Copy link

Thanks for the workaround! From my side as it wasn't so important I've deleted /srv/clickhouse folder at all and after it has been recreated QAN started to work again. Well, analytics has gone obviously.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@BupycHuk BupycHuk

Labels
bug Bug report
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@BupycHuk @Grokon @jessebye @yauhen-vastraknutau-epam