Closed haiertashu closed 3 years ago
could you share your config.yml?
and the result of the following command?
LOG_LEVEL=debug ./clickhouse-backup create mybackup_debug --config config.yml
I join the problem.
[root@localhost shadow]# clickhouse-server version
Processing configuration file 'config.xml'.
There is no file 'config.xml', will use embedded config.
Logging trace to console
2021.09.08 16:26:39.037053 [ 31947 ] {} <Information> SentryWriter: Sending crash reports is disabled
2021.09.08 16:26:39.066262 [ 31947 ] {} <Trace> Pipe: Pipe capacity is 1.00 MiB
2021.09.08 16:26:39.238912 [ 31947 ] {} <Information> : Starting ClickHouse 21.8.5.7 with revision 54453, build id: 002660CFDF969F9EBCB93D09D84DC76B0B469329, PID 31947
2021.09.08 16:26:39.239118 [ 31947 ] {} <Information> Application: starting up
2021.09.08 16:26:39.239188 [ 31947 ] {} <Information> Application: OS name: Linux, version: 3.10.0-1160.41.1.el7.x86_64, architecture: x86_64
2021.09.08 16:26:39.556847 [ 31947 ] {} <Information> Application: Calculated checksum of the binary: C815004D2EAD6F8A74A53F5B6A027A55, integrity check passed.
[root@localhost shadow]# clickhouse-backup
VERSION:
1.0.0
[root@localhost shadow]# cat /etc/clickhouse-backup/config.yml
general:
remote_storage: s3 # REMOTE_STORAGE
max_file_size: 107374182400 # MAX_FILE_SIZE
disable_progress_bar: false # DISABLE_PROGRESS_BAR
backups_to_keep_local: 0 # BACKUPS_TO_KEEP_LOCAL
backups_to_keep_remote: 0 # BACKUPS_TO_KEEP_REMOTE
log_level: DEBUG # LOG_LEVEL
allow_empty_backups: false # ALLOW_EMPTY_BACKUPS
clickhouse:
username: default # CLICKHOUSE_USERNAME
password: "" # CLICKHOUSE_PASSWORD
host: localhost # CLICKHOUSE_HOST
port: 9000 # CLICKHOUSE_PORT
disk_mapping: {} # CLICKHOUSE_DISK_MAPPING
skip_tables: # CLICKHOUSE_SKIP_TABLES
- system.*
timeout: 5m # CLICKHOUSE_TIMEOUT
freeze_by_part: false # CLICKHOUSE_FREEZE_BY_PART
secure: false # CLICKHOUSE_SECURE
skip_verify: false # CLICKHOUSE_SKIP_VERIFY
sync_replicated_tables: true # CLICKHOUSE_SYNC_REPLICATED_TABLES
log_sql_queries: true # CLICKHOUSE_LOG_SQL_QUERIES
config_dir: "/etc/clickhouse-server" # CLICKHOUSE_CONFIG_DIR
restart_command: "systemctl restart clickhouse-server" # CLICKHOUSE_RESTART_COMMAND
api:
listen: "localhost:7171" # API_LISTEN
enable_metrics: true # API_ENABLE_METRICS
enable_pprof: false # API_ENABLE_PPROF
username: "" # API_USERNAME
password: "" # API_PASSWORD
secure: false # API_SECURE
certificate_file: "" # API_CERTIFICATE_FILE
private_key_file: "" # API_PRIVATE_KEY_FILE
create_integration_tables: false # API_CREATE_INTEGRATION_TABLES
s3:
access_key: "MYKEY" # S3_ACCESS_KEY
secret_key: "MYKEY" # S3_SECRET_KEY
bucket: "/clickhouse" # S3_BUCKET
endpoint: "MYENDPOINT" # S3_ENDPOINT
# region: us-east-1 # S3_REGION
# acl: private # S3_ACL
force_path_style: false # S3_FORCE_PATH_STYLE
# path: "" # S3_PATH
disable_ssl: true # S3_DISABLE_SSL
# part_size: 104857600 # S3_PART_SIZE
# compression_level: 1 # S3_COMPRESSION_LEVEL
# supports 'tar', 'lz4', 'bzip2', 'gzip', 'sz', 'xz'
compression_format: gzip # S3_COMPRESSION_FORMAT
# empty (default), AES256, or aws:kms
# sse: AES256 # S3_SSE
disable_cert_verification: true # S3_DISABLE_CERT_VERIFICATION
# debug: true # S3_DEBUG
# storage_class: STANDARD # S3_STORAGE_CLASS
2021/09/08 16:22:42 debug create data backup=2021-09-08T13-21-57 operation=create table=petshop.crm_discount_wholesale
2021/09/08 16:22:42 info SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/09/08 16:22:42 info SELECT * FROM system.disks;
2021/09/08 16:22:42 info SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/09/08 16:22:42 info ALTER TABLE `petshop`.`crm_discount_wholesale` FREEZE WITH NAME '167ce852d1dc4034bf9a0f81a7713eb2';
2021/09/08 16:22:42 debug freezed backup=2021-09-08T13-21-57 operation=create table=petshop.crm_discount_wholesale
2021/09/08 16:22:42 debug shadow moved backup=2021-09-08T13-21-57 disk=default operation=create table=petshop.crm_discount_wholesale
2021/09/08 16:22:42 info SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/09/08 16:22:42 info SELECT * FROM system.disks;
2021/09/08 16:22:42 debug done backup=2021-09-08T13-21-57 operation=create table=petshop.crm_discount_wholesale
2021/09/08 16:22:42 debug create metadata backup=2021-09-08T13-21-57 operation=create table=petshop.crm_discount_wholesale
2021/09/08 16:22:42 info done backup=2021-09-08T13-21-57 operation=create table=petshop.crm_discount_wholesale
2021/09/08 16:22:42 debug create data backup=2021-09-08T13-21-57 operation=create table=petshop.crm_discount_wholesale_personal
2021/09/08 16:22:42 info SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/09/08 16:22:42 info SELECT * FROM system.disks;
2021/09/08 16:22:42 info SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/09/08 16:22:42 info ALTER TABLE `petshop`.`crm_discount_wholesale_personal` FREEZE WITH NAME '109952fe373b408a88f5810e1bfdd5d3';
2021/09/08 16:23:56 error can't freeze table: code: 84, message: Directory /var/lib/clickhouse/shadow/109952fe373b408a88f5810e1bfdd5d3/data/petshop/crm_discount_wholesale_personal/0_1_1_11 already exists and is not empty. backup=2021-09-08T13-21-57 operation=create table=petshop.crm_discount_wholesale_personal
2021/09/08 16:23:56 info SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/09/08 16:23:56 info SELECT * FROM system.disks;
2021/09/08 16:23:56 info SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/09/08 16:23:56 info SELECT * FROM system.disks;
2021/09/08 16:23:56 debug remove '2021-09-08T13-21-57' path=/var/lib/clickhouse/
2021/09/08 16:24:03 info done backup=2021-09-08T13-21-57 location=local operation=delete
2021/09/08 16:24:03 error can't freeze table: code: 84, message: Directory /var/lib/clickhouse/shadow/109952fe373b408a88f5810e1bfdd5d3/data/petshop/crm_discount_wholesale_personal/0_1_1_11 already exists and is not empty.
@AndeyS is the issue still actual for you? let's try to https://github.com/Altinity/clickhouse-backup/releases/tag/1.0.16 ?
@Slach Yes, relevant. I'll try it today. Thanks.
@Slach Unfortunately. did not help.
2021/09/14 12:58:48 info ALTER TABLE petshop
.crm_discount_wholesale_personal
FREEZE WITH NAME '9b049a701cc54abe92582be9860f5a82';
2021/09/14 13:00:19 error can't freeze table: code: 84, message: Directory /var/lib/clickhouse/shadow/9b049a701cc54abe92582be9860f5a82/data/petshop/crm_discount_wholesale_personal/0_1_1_11 already exists and is not empty. backup=2021-09-14T09-58-01 operation=create table=petshop.crm_discount_wholesale_personal
2021/09/14 13:00:19 info SELECT value FROM system
.build_options
where name='VERSION_INTEGER'
2021/09/14 13:00:19 info SELECT FROM system.disks;
2021/09/14 13:00:19 info SELECT value FROM system
.build_options
where name='VERSION_INTEGER'
2021/09/14 13:00:19 info SELECT FROM system.disks;
2021/09/14 13:00:19 debug remove '2021-09-14T09-58-01' path=/var/lib/clickhouse/
2021/09/14 13:00:26 info done backup=2021-09-14T09-58-01 duration=6.465s location=local operation=delete
2021/09/14 13:00:26 error can't freeze table: code: 84, message: Directory /var/lib/clickhouse/shadow/9b049a701cc54abe92582be9860f5a82/data/petshop/crm_discount_wholesale_personal/0_1_1_11 already exists and is not empty.
Maybe I need to clean something extra?
I deleted everything in the shadow folder.
could you share
SELECT * FROM system.disks
?
you can try to remove
rm -rfv /var/lib/clickhouse/shadow/*
and try to run LOG_LEVEL=debug clickhouse-backup create
again
@Slach [root@localhost clickhouse-backup]# clickhouse-client ClickHouse client version 21.8.5.7 (official build). Connecting to localhost:9000 as user default. Connected to ClickHouse server version 21.8.5 revision 54449.
localhost :) SELECT * FROM system.disks
SELECT * FROM system.disks
Query id: 1dac9c7c-a78b-43f9-946d-76f231b77acc
┌─name────┬─path─────────────────┬───free_space─┬──total_space─┬─keep_free_space─┬─type──┐ │ default │ /var/lib/clickhouse/ │ 173266612224 │ 258771193856 │ 0 │ local │ └─────────┴──────────────────────┴──────────────┴──────────────┴─────────────────┴───────┘
1 rows in set. Elapsed: 0.006 sec.
############################################################################## [root@localhost clickhouse-backup]# rm -rfv /var/lib/clickhouse/shadow/*
.... удалён «/var/lib/clickhouse/shadow/21c9075fe42a4aa88834b8966919ef38/data/petshop/crm_discount_wholesale_personal/1630595943_28335_28335_1/vendor_id.mrk2» удалён «/var/lib/clickhouse/shadow/21c9075fe42a4aa88834b8966919ef38/data/petshop/crm_discount_wholesale_personal/1630595943_28335_28335_1/vendor_id.null.bin» удалён «/var/lib/clickhouse/shadow/21c9075fe42a4aa88834b8966919ef38/data/petshop/crm_discount_wholesale_personal/1630595943_28335_28335_1/vendor_id.null.mrk2» удален каталог: «/var/lib/clickhouse/shadow/21c9075fe42a4aa88834b8966919ef38/data/petshop/crm_discount_wholesale_personal/1630595943_28335_28335_1» удален каталог: «/var/lib/clickhouse/shadow/21c9075fe42a4aa88834b8966919ef38/data/petshop/crm_discount_wholesale_personal» удален каталог: «/var/lib/clickhouse/shadow/21c9075fe42a4aa88834b8966919ef38/data/petshop» удален каталог: «/var/lib/clickhouse/shadow/21c9075fe42a4aa88834b8966919ef38/data» удален каталог: «/var/lib/clickhouse/shadow/21c9075fe42a4aa88834b8966919ef38» удалён «/var/lib/clickhouse/shadow/increment.txt» ############################################################################## [root@localhost clickhouse-backup]# clickhouse-client ClickHouse client version 21.8.5.7 (official build). Connecting to localhost:9000 as user default. Connected to ClickHouse server version 21.8.5 revision 54449.
localhost :) SELECT * FROM system.disks
SELECT * FROM system.disks
Query id: 1e51579a-1492-4604-b3cf-66b82e30fcfd
┌─name────┬─path─────────────────┬───free_space─┬──total_space─┬─keep_free_space─┬─type──┐ │ default │ /var/lib/clickhouse/ │ 173398331392 │ 258771193856 │ 0 │ local │ └─────────┴──────────────────────┴──────────────┴──────────────┴─────────────────┴───────┘
1 rows in set. Elapsed: 0.006 sec.
############################################################################## LOG_LEVEL=debug clickhouse-backup create .....
2021/09/15 00:47:49 debug ALTER TABLE petshop
.crm_client_retail_sms_mailing_rejection
FREEZE WITH NAME 'a005904d3b2745918c07e7ac9d569d24';
2021/09/15 00:47:49 debug freezed backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_retail_sms_mailing_rejection
2021/09/15 00:47:49 debug shadow moved backup=2021-09-14T21-47-28 disk=default operation=create table=petshop.crm_client_retail_sms_mailing_rejection
2021/09/15 00:47:49 debug SELECT FROM system.disks;
2021/09/15 00:47:49 debug done backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_retail_sms_mailing_rejection
2021/09/15 00:47:49 debug create metadata backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_retail_sms_mailing_rejection
2021/09/15 00:47:49 info done backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_retail_sms_mailing_rejection
2021/09/15 00:47:49 debug create data backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale
2021/09/15 00:47:49 debug ALTER TABLE petshop
.crm_client_wholesale
FREEZE WITH NAME '901edaeed37a467b9b0038be216dea54';
2021/09/15 00:47:51 debug freezed backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale
2021/09/15 00:48:11 debug shadow moved backup=2021-09-14T21-47-28 disk=default operation=create table=petshop.crm_client_wholesale
2021/09/15 00:48:11 debug SELECT FROM system.disks;
2021/09/15 00:48:11 debug done backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale
2021/09/15 00:48:11 debug create metadata backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale
2021/09/15 00:48:11 info done backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale
2021/09/15 00:48:11 debug create data backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale_address
2021/09/15 00:48:11 debug ALTER TABLE petshop
.crm_client_wholesale_address
FREEZE WITH NAME '26fcef605c9b41658150636b8d29f507';
2021/09/15 00:48:12 debug freezed backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale_address
2021/09/15 00:48:14 debug shadow moved backup=2021-09-14T21-47-28 disk=default operation=create table=petshop.crm_client_wholesale_address
2021/09/15 00:48:14 debug SELECT FROM system.disks;
2021/09/15 00:48:14 debug done backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale_address
2021/09/15 00:48:14 debug create metadata backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale_address
2021/09/15 00:48:14 info done backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale_address
2021/09/15 00:48:14 debug create data backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale_promo
2021/09/15 00:48:14 debug ALTER TABLE petshop
.crm_client_wholesale_promo
FREEZE WITH NAME 'c946efe3fc064793894570fe5653bc0b';
2021/09/15 00:48:14 debug freezed backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale_promo
2021/09/15 00:48:14 debug shadow moved backup=2021-09-14T21-47-28 disk=default operation=create table=petshop.crm_client_wholesale_promo
2021/09/15 00:48:14 debug SELECT FROM system.disks;
2021/09/15 00:48:14 debug done backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale_promo
2021/09/15 00:48:14 debug create metadata backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale_promo
2021/09/15 00:48:14 info done backup=2021-09-14T21-47-28 operation=create table=petshop.crm_client_wholesale_promo
2021/09/15 00:48:14 debug create data backup=2021-09-14T21-47-28 operation=create table=petshop.crm_discount_retail
2021/09/15 00:48:14 debug ALTER TABLE petshop
.crm_discount_retail
FREEZE WITH NAME '152219541d164becaf18227b68387b44';
2021/09/15 00:48:14 debug freezed backup=2021-09-14T21-47-28 operation=create table=petshop.crm_discount_retail
2021/09/15 00:48:16 debug shadow moved backup=2021-09-14T21-47-28 disk=default operation=create table=petshop.crm_discount_retail
2021/09/15 00:48:16 debug SELECT FROM system.disks;
2021/09/15 00:48:16 debug done backup=2021-09-14T21-47-28 operation=create table=petshop.crm_discount_retail
2021/09/15 00:48:16 debug create metadata backup=2021-09-14T21-47-28 operation=create table=petshop.crm_discount_retail
2021/09/15 00:48:16 info done backup=2021-09-14T21-47-28 operation=create table=petshop.crm_discount_retail
2021/09/15 00:48:16 debug create data backup=2021-09-14T21-47-28 operation=create table=petshop.crm_discount_wholesale
2021/09/15 00:48:16 debug ALTER TABLE petshop
.crm_discount_wholesale
FREEZE WITH NAME '73b2372cbd32479f89cdb985aa7b2e43';
2021/09/15 00:48:16 debug freezed backup=2021-09-14T21-47-28 operation=create table=petshop.crm_discount_wholesale
2021/09/15 00:48:16 debug shadow moved backup=2021-09-14T21-47-28 disk=default operation=create table=petshop.crm_discount_wholesale
2021/09/15 00:48:16 debug SELECT FROM system.disks;
2021/09/15 00:48:16 debug done backup=2021-09-14T21-47-28 operation=create table=petshop.crm_discount_wholesale
2021/09/15 00:48:16 debug create metadata backup=2021-09-14T21-47-28 operation=create table=petshop.crm_discount_wholesale
2021/09/15 00:48:16 info done backup=2021-09-14T21-47-28 operation=create table=petshop.crm_discount_wholesale
2021/09/15 00:48:16 debug create data backup=2021-09-14T21-47-28 operation=create table=petshop.crm_discount_wholesale_personal
2021/09/15 00:48:16 debug ALTER TABLE petshop
.crm_discount_wholesale_personal
FREEZE WITH NAME 'ada8bcdc292a4e778802c342d3b2c507';
2021/09/15 00:49:34 error can't freeze table: code: 84, message: Directory /var/lib/clickhouse/shadow/ada8bcdc292a4e778802c342d3b2c507/data/petshop/crm_discount_wholesale_personal/0_1_1_11 already exists and is not empty. backup=2021-09-14T21-47-28 operation=create table=petshop.crm_discount_wholesale_personal
2021/09/15 00:49:34 debug SELECT value FROM system
.build_options
where name='VERSION_INTEGER'
2021/09/15 00:49:34 debug SELECT FROM system.disks;
2021/09/15 00:49:34 debug SELECT value FROM system
.build_options
where name='VERSION_INTEGER'
2021/09/15 00:49:34 debug SELECT FROM system.disks;
2021/09/15 00:49:34 debug remove '2021-09-14T21-47-28' path=/var/lib/clickhouse/
2021/09/15 00:49:40 info done backup=2021-09-14T21-47-28 duration=5.954s location=local operation=delete
2021/09/15 00:49:40 error can't freeze table: code: 84, message: Directory /var/lib/clickhouse/shadow/ada8bcdc292a4e778802c342d3b2c507/data/petshop/crm_discount_wholesale_personal/0_1_1_11 already exists and is not empty.
[root@localhost clickhouse-backup]#
##############################################################################
[root@localhost clickhouse-backup]# clickhouse-client
ClickHouse client version 21.8.5.7 (official build).
Connecting to localhost:9000 as user default.
Connected to ClickHouse server version 21.8.5 revision 54449.
localhost :) SELECT * FROM system.disks
SELECT * FROM system.disks
Query id: b7bba6f5-ba7c-4ca5-bf37-c3f192c4e1ed
┌─name────┬─path─────────────────┬───free_space─┬──total_space─┬─keep_free_space─┬─type──┐ │ default │ /var/lib/clickhouse/ │ 173257052160 │ 258771193856 │ 0 │ local │ └─────────┴──────────────────────┴──────────────┴──────────────┴─────────────────┴───────┘
1 rows in set. Elapsed: 0.006 sec.
@Slach Это тестовая среда. Задача была взять клон прода (там кх версии 20.1.4.14 и версия clickhouse-backup 0.5.2 и все отлично работает) и обновить кх до последней стабильной версии. 1 - я обновил кх сервер, клиента и коммон, все прошло хорошо 2 - начали проверять бэкап и вот тут получили ошибку. Может это как-то сможет помочь понять проблему.
@Slach Обновил кликхаус до версии 21.9.2, клиент 21.9.2.17. Ошибка не ушла. Вот что в логе кликхаус сервера
2021.09.15 01:40:49.000238 [ 1844 ] {} petshop
.crm_discount_wholesale_personal
FREEZE WITH NAME 'b5e6b6305a5d4cfc9d54676aab9d10ef';), Stack trace (when copying this message, always include the lines below)
Ошибка
2021/09/15 01:39:19 debug create data backup=2021-09-14T22-38-30 operation=create table=petshop.crm_discount_wholesale_personal
2021/09/15 01:39:19 debug ALTER TABLE petshop
.crm_discount_wholesale_personal
FREEZE WITH NAME 'b5e6b6305a5d4cfc9d54676aab9d10ef';
2021/09/15 01:40:50 error can't freeze table: code: 84, message: Directory /var/lib/clickhouse/shadow/b5e6b6305a5d4cfc9d54676aab9d10ef/data/petshop/crm_discount_wholesale_personal/0_1_1_11 already exists and is not empty. backup=2021-09-14T22-38-30 operation=create table=petshop.crm_discount_wholesale_personal
2021/09/15 01:40:50 debug SELECT value FROM system
.build_options
where name='VERSION_INTEGER'
2021/09/15 01:40:50 debug SELECT FROM system.disks;
2021/09/15 01:40:50 debug SELECT value FROM system
.build_options
where name='VERSION_INTEGER'
2021/09/15 01:40:50 debug SELECT FROM system.disks;
2021/09/15 01:40:50 debug remove '2021-09-14T22-38-30' path=/var/lib/clickhouse/
2021/09/15 01:40:56 info done backup=2021-09-14T22-38-30 duration=6.3s location=local operation=delete
2021/09/15 01:40:56 error can't freeze table: code: 84, message: Directory /var/lib/clickhouse/shadow/b5e6b6305a5d4cfc9d54676aab9d10ef/data/petshop/crm_discount_wholesale_personal/0_1_1_11 already exists and is not empty.
Перед началом обновления и бэкапа, все из директории shadow было удалено.
Конфиг
[root@localhost ~]# cat /etc/clickhouse-backup/config.yml general: remote_storage: none max_file_size: 107374182400 disable_progress_bar: true backups_to_keep_local: 0 backups_to_keep_remote: 0 log_level: DEBUG allow_empty_backups: false download_concurrency: 1 upload_concurrency: 1 clickhouse: username: default password: "" host: localhost port: 9000 disk_mapping: {} skip_tables:
issue is didn't depends on clickhouse version could you share
grep b5e6b6305a5d4cfc9d54676aab9d10ef /var/log/clickouse-server/clickhouse-server.log
@Slach
319_1 snapshot will be placed at shadow/b5e6b6305a5d4cfc9d54676aab9d10ef/
2021.09.15 01:40:47.913282 [ 1616 ] {c24d5f98-642e-4160-954a-1243dbbcf032} petshop
.crm_discount_wholesale_personal
FREEZE WITH NAME 'b5e6b6305a5d4cfc9d54676aab9d10ef';), Stack trace (when copying this message, always include the lines below):
2021.09.15 01:40:50.402570 [ 1618 ] {c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542}
Если нужно, могу его файлом прикрепить, он большой.
Could you share results of the following query?
SELECT * FROM system.query_log WHERE queri_id IN ('c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542', 'c24d5f98-642e-4160-954a-1243dbbcf032') AND event_date = '2021-09-15' FORMAT Vertical
@Slach [root@localhost ~]# clickhouse-client ClickHouse client version 21.9.2.17 (official build). Connecting to localhost:9000 as user default. Connected to ClickHouse server version 21.9.2 revision 54449.
localhost :) SELECT * FROM system.query_log WHERE queri_id IN ('c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542', 'c24d5f98-642e-4160-954a-1243dbbcf032') AND event_date = '2021-09-15' FORMAT Vertical
SELECT * FROM system.query_log WHERE (queri_id IN ('c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542', 'c24d5f98-642e-4160-954a-1243dbbcf032')) AND (event_date = '2021-09-15') FORMAT Vertical
Query id: 7cf7515e-5e4f-4e94-98f2-3405deacb2a4
0 rows in set. Elapsed: 0.068 sec.
Received exception from server (version 21.9.2): Code: 47. DB::Exception: Received from localhost:9000. DB::Exception: Missing columns: 'queri_id' while processing query: 'SELECT type, event_date, event_time, event_time_microseconds, query_start_time, query_start_time_microseconds, query_duration_ms, read_rows, read_bytes, written_rows, written_bytes, result_rows, result_bytes, memory_usage, current_database, query, formatted_query, normalized_query_hash, query_kind, databases, tables, columns, projections, views, exception_code, exception, stack_trace, is_initial_query, user, query_id, address, port, initial_user, initial_query_id, initial_address, initial_port, initial_query_start_time, initial_query_start_time_microseconds, interface, os_user, client_hostname, client_name, client_revision, client_version_major, client_version_minor, client_version_patch, http_method, http_user_agent, http_referer, forwarded_for, quota_key, revision, log_comment, thread_ids, ProfileEvents, Settings, used_aggregate_functions, used_aggregate_function_combinators, used_database_engines, used_data_type_families, used_dictionaries, used_formats, used_functions, used_storages, used_table_functions FROM system.query_log WHERE (queri_id IN ('c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542', 'c24d5f98-642e-4160-954a-1243dbbcf032')) AND (event_date = '2021-09-15')', required columns: 'initial_query_start_time_microseconds' 'event_time_microseconds' 'tables' 'event_date' 'client_hostname' 'http_user_agent' 'http_referer' 'query_duration_ms' 'columns' 'query_start_time_microseconds' 'interface' 'read_rows' 'query_kind' 'read_bytes' 'current_database' 'query' 'written_rows' 'exception_code' 'databases' 'queri_id' 'http_method' 'result_rows' 'written_bytes' 'type' 'formatted_query' 'normalized_query_hash' 'views' 'os_user' 'used_functions' 'exception' 'memory_usage' 'used_storages' 'stack_trace' 'result_bytes' 'initial_query_id' 'event_time' 'is_initial_query' 'client_version_major' 'query_id' 'thread_ids' 'client_version_patch' 'address' 'used_aggregate_functions' 'client_name' 'initial_address' 'client_version_minor' 'port' 'forwarded_for' 'ProfileEvents' 'user' 'initial_user' 'Settings' 'query_start_time' 'initial_query_start_time' 'initial_port' 'client_revision' 'used_database_engines' 'used_aggregate_function_combinators' 'projections' 'quota_key' 'used_dictionaries' 'log_comment' 'revision' 'used_table_functions' 'used_formats' 'used_data_type_families', maybe you meant: ['initial_query_start_time_microseconds','event_time_microseconds','tables','event_date','client_hostname','http_user_agent','http_referer','query_duration_ms','columns','query_start_time_microseconds','interface','read_rows','query_kind','read_bytes','current_database','query','written_rows','exception_code','databases','query_id','http_method','result_rows','written_bytes','type','formatted_query','normalized_query_hash','views','os_user','used_functions','exception','memory_usage','used_storages','stack_trace','result_bytes','initial_query_id','event_time','is_initial_query','client_version_major','query_id','thread_ids','client_version_patch','address','used_aggregate_functions','client_name','initial_address','client_version_minor','port','forwarded_for','ProfileEvents','user','initial_user','Settings','query_start_time','initial_query_start_time','initial_port','client_revision','used_database_engines','used_aggregate_function_combinators','projections','quota_key','used_dictionaries','log_comment','revision','used_table_functions','used_formats','used_data_type_families']. (UNKNOWN_IDENTIFIER)
query_id instead of queri_id, sorry
SELECT * FROM system.query_log WHERE query_id IN ('c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542', 'c24d5f98-642e-4160-954a-1243dbbcf032') AND event_date = '2021-09-15' FORMAT Vertical
@Slach localhost :) SELECT * FROM system.query_log WHERE queri_id IN ('c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542', 'c24d5f98-642e-4160-954a-1243dbbcf032') AND event_date = '2021-09-15' FORMAT Vertical
SELECT * FROM system.query_log WHERE (queri_id IN ('c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542', 'c24d5f98-642e-4160-954a-1243dbbcf032')) AND (event_date = '2021-09-15') FORMAT Vertical
Query id: 8cd5acc9-730a-45aa-9279-99498bcb3eb9
0 rows in set. Elapsed: 0.021 sec.
Received exception from server (version 21.9.2): Code: 47. DB::Exception: Received from localhost:9000. DB::Exception: Missing columns: 'queri_id' while processing query: 'SELECT type, event_date, event_time, event_time_microseconds, query_start_time, query_start_time_microseconds, query_duration_ms, read_rows, read_bytes, written_rows, written_bytes, result_rows, result_bytes, memory_usage, current_database, query, formatted_query, normalized_query_hash, query_kind, databases, tables, columns, projections, views, exception_code, exception, stack_trace, is_initial_query, user, query_id, address, port, initial_user, initial_query_id, initial_address, initial_port, initial_query_start_time, initial_query_start_time_microseconds, interface, os_user, client_hostname, client_name, client_revision, client_version_major, client_version_minor, client_version_patch, http_method, http_user_agent, http_referer, forwarded_for, quota_key, revision, log_comment, thread_ids, ProfileEvents, Settings, used_aggregate_functions, used_aggregate_function_combinators, used_database_engines, used_data_type_families, used_dictionaries, used_formats, used_functions, used_storages, used_table_functions FROM system.query_log WHERE (queri_id IN ('c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542', 'c24d5f98-642e-4160-954a-1243dbbcf032')) AND (event_date = '2021-09-15')', required columns: 'initial_query_start_time_microseconds' 'event_time_microseconds' 'tables' 'event_date' 'client_hostname' 'http_user_agent' 'http_referer' 'query_duration_ms' 'columns' 'query_start_time_microseconds' 'interface' 'read_rows' 'query_kind' 'read_bytes' 'current_database' 'query' 'written_rows' 'exception_code' 'databases' 'queri_id' 'http_method' 'result_rows' 'written_bytes' 'type' 'formatted_query' 'normalized_query_hash' 'views' 'os_user' 'used_functions' 'exception' 'memory_usage' 'used_storages' 'stack_trace' 'result_bytes' 'initial_query_id' 'event_time' 'is_initial_query' 'client_version_major' 'query_id' 'thread_ids' 'client_version_patch' 'address' 'used_aggregate_functions' 'client_name' 'initial_address' 'client_version_minor' 'port' 'forwarded_for' 'ProfileEvents' 'user' 'initial_user' 'Settings' 'query_start_time' 'initial_query_start_time' 'initial_port' 'client_revision' 'used_database_engines' 'used_aggregate_function_combinators' 'projections' 'quota_key' 'used_dictionaries' 'log_comment' 'revision' 'used_table_functions' 'used_formats' 'used_data_type_families', maybe you meant: ['initial_query_start_time_microseconds','event_time_microseconds','tables','event_date','client_hostname','http_user_agent','http_referer','query_duration_ms','columns','query_start_time_microseconds','interface','read_rows','query_kind','read_bytes','current_database','query','written_rows','exception_code','databases','query_id','http_method','result_rows','written_bytes','type','formatted_query','normalized_query_hash','views','os_user','used_functions','exception','memory_usage','used_storages','stack_trace','result_bytes','initial_query_id','event_time','is_initial_query','client_version_major','query_id','thread_ids','client_version_patch','address','used_aggregate_functions','client_name','initial_address','client_version_minor','port','forwarded_for','ProfileEvents','user','initial_user','Settings','query_start_time','initial_query_start_time','initial_port','client_revision','used_database_engines','used_aggregate_function_combinators','projections','quota_key','used_dictionaries','log_comment','revision','used_table_functions','used_formats','used_data_type_families']. (UNKNOWN_IDENTIFIER)
localhost :)
@AndeyS
I say twice
query_id
instead of queri_id
SELECT * FROM system.query_log WHERE query_id IN ('c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542', 'c24d5f98-642e-4160-954a-1243dbbcf032') AND event_date = '2021-09-15' FORMAT Vertical
@Slach please forgive me :)
[root@localhost ~]# clickhouse-client ClickHouse client version 21.9.2.17 (official build). Connecting to localhost:9000 as user default. Connected to ClickHouse server version 21.9.2 revision 54449.
localhost :) SELECT * FROM system.query_log WHERE query_id IN ('c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542', 'c24d5f98-642e-4160-954a-1243dbbcf032') AND event_date = '2021-09-15' FORMAT Vertical
SELECT * FROM system.query_log WHERE (query_id IN ('c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542', 'c24d5f98-642e-4160-954a-1243dbbcf032')) AND (event_date = '2021-09-15') FORMAT Vertical
Query id: 4627a5bf-2733-4943-9dfd-a6782c58b814
Ok.
0 rows in set. Elapsed: 0.106 sec.
Could you share
SHOW CREATE TABLE system.query_log
and
SELECT * FROM system.settings WHERE name = 'query_log' ?
also, could you share results of
grep -i "c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542" -r /var/log/clickhouse-server/clickhouse-server.log*
and
grep -i "c24d5f98-642e-4160-954a-1243dbbcf032" -r /var/log/clickhouse-server/clickhouse-server.log*
@Slach localhost :) SHOW CREATE TABLE system.query_log
SHOW CREATE TABLE system.query_log
Query id: d5c6b4ef-d9d9-4d32-aa4b-b7f56587e786
┌─statement──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┐
│ CREATE TABLE system.query_log
(
type
Enum8('QueryStart' = 1, 'QueryFinish' = 2, 'ExceptionBeforeStart' = 3, 'ExceptionWhileProcessing' = 4),
event_date
Date,
event_time
DateTime,
event_time_microseconds
DateTime64(6),
query_start_time
DateTime,
query_start_time_microseconds
DateTime64(6),
query_duration_ms
UInt64,
read_rows
UInt64,
read_bytes
UInt64,
written_rows
UInt64,
written_bytes
UInt64,
result_rows
UInt64,
result_bytes
UInt64,
memory_usage
UInt64,
current_database
String,
query
String,
formatted_query
String,
normalized_query_hash
UInt64,
query_kind
LowCardinality(String),
databases
Array(LowCardinality(String)),
tables
Array(LowCardinality(String)),
columns
Array(LowCardinality(String)),
projections
Array(LowCardinality(String)),
views
Array(LowCardinality(String)),
exception_code
Int32,
exception
String,
stack_trace
String,
is_initial_query
UInt8,
user
String,
query_id
String,
address
IPv6,
port
UInt16,
initial_user
String,
initial_query_id
String,
initial_address
IPv6,
initial_port
UInt16,
initial_query_start_time
DateTime,
initial_query_start_time_microseconds
DateTime64(6),
interface
UInt8,
os_user
String,
client_hostname
String,
client_name
String,
client_revision
UInt32,
client_version_major
UInt32,
client_version_minor
UInt32,
client_version_patch
UInt32,
http_method
UInt8,
http_user_agent
String,
http_referer
String,
forwarded_for
String,
quota_key
String,
revision
UInt32,
log_comment
String,
thread_ids
Array(UInt64),
ProfileEvents
Map(String, UInt64),
Settings
Map(String, String),
used_aggregate_functions
Array(String),
used_aggregate_function_combinators
Array(String),
used_database_engines
Array(String),
used_data_type_families
Array(String),
used_dictionaries
Array(String),
used_formats
Array(String),
used_functions
Array(String),
used_storages
Array(String),
used_table_functions
Array(String),
ProfileEvents.Names
Array(String) ALIAS mapKeys(ProfileEvents),
ProfileEvents.Values
Array(UInt64) ALIAS mapValues(ProfileEvents),
Settings.Names
Array(String) ALIAS mapKeys(Settings),
Settings.Values
Array(String) ALIAS mapValues(Settings)
)
ENGINE = MergeTree
PARTITION BY toYYYYMM(event_date)
ORDER BY (event_date, event_time)
SETTINGS index_granularity = 8192 │
└────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┘
1 rows in set. Elapsed: 0.006 sec.
################################################################################################### localhost :) SELECT * FROM system.settings WHERE name = 'query_log'
SELECT * FROM system.settings WHERE name = 'query_log'
Query id: e4ce44e1-ac66-49ee-b0be-682af413cf69
Ok.
0 rows in set. Elapsed: 0.009 sec.
###################################################################################################
grep -i "c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542" -r /var/log/clickhouse-server/clickhouse-server.log*
https://github.com/AndeyS/python_tree/blob/main/c5f9f7c8.log
################################################################################################### grep -i "c24d5f98-642e-4160-954a-1243dbbcf032" -r /var/log/clickhouse-server/clickhouse-server.log*
https://raw.githubusercontent.com/AndeyS/python_tree/main/c24d5f98.log
Ok. Let's try to figure out.
The first query run start in thread 1616:
2021.09.15 01:39:19.950003 [ 1616 ] {c24d5f98-642e-4160-954a-1243dbbcf032} <Debug> executeQuery: (from 127.0.0.1:36814) ALTER TABLE `petshop`.`crm_discount_wholesale_personal` FREEZE WITH NAME 'b5e6b6305a5d4cfc9d54676aab9d10ef';
And successfully finish after 90 seconds
2021.09.15 01:40:47.962953 [ 1616 ] {c24d5f98-642e-4160-954a-1243dbbcf032} <Debug> petshop.crm_discount_wholesale_personal: Freezed 28338 parts
And the second query start in different thread 1618
:2021.09.15 01:40:19.954445 [ 1618 ] {c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542} <Debug> executeQuery: (from 127.0.0.1:36816) ALTER TABLE `petshop`.`crm_discount_wholesale_personal` FREEZE WITH NAME 'b5e6b6305a5d4cfc9d54676aab9d10ef';
and only after 30 seconds it fail
2021.09.15 01:40:50.382628 [ 1618 ] {c5f9f7c8-5eaf-4a7a-8f47-c5693cae3542} <Error> executeQuery: Code: 84. DB::Exception: Directory /var/lib/clickhouse/shadow/b5e6b6305a5d4cfc9d54676aab9d10ef/data/petshop/crm_discount_wholesale_personal/0_1_1_11 already exists and is not empty. (DIRECTORY_ALREADY_EXISTS)
And look like this queries run in parallel but HOW?
clickhouse-backup create
should run ALTER TABLE ... FREEZE
for tables one by one in single goroutine
could you run again the following commands and share full logs via upload it to github or pastebin?
rm -rfv /var/lib/clickhouse/shadow/*
rm -rfv /var/lib/clickhouse/backup/*
and try to run LOG_LEVEL=debug clickhouse-backup create again
@Slach rm -rfv /var/lib/clickhouse/shadow/ - COMPLETE rm -rfv /var/lib/clickhouse/backup/ - COMPLETE clickhouse-backup create mybk > /root/mubk_debug.log Logs https://github.com/AndeyS/python_tree/blob/main/clickhouse-server.err.log https://github.com/AndeyS/python_tree/blob/main/clickhouse-server.log https://github.com/AndeyS/python_tree/blob/main/mubk_debug.log
@AndeyS @haiertashu could you check https://github.com/AlexAkulov/clickhouse-backup/releases/tag/v1.0.0 and report if issue still reproduce?
@Slach Successfully worked on a combination clickhouse-backup version 1.1.0 clickhouse-server version 21.9.4 clickhouse-client version 21.9.4.35
Additional changes to my config file /etc/clickhouse-backup/config.yml freeze_by_part: true
@AndeyS could run freeze_by_part: false
?
@Slach now I will try, I will write on the result
@Slach With parameter freeze_by_part: false everything went well too. Thank you very much for your help!
@AndeyS thank you for your detailed reports
root@myhost:/clickhouse-backup# ./clickhouse-backup create mybackup --config config.yml
error can't freeze table: code: 84, message: Directory /tmp/lib/clickhouse/clickhouse/shadow/5076776fdd744d29a1e9554eb9120b06/store/e24/e24c18be-4cb4-4b31-be67-fc23cf435db8/20201201_1101768_1355747_493 already exists and is not empty.
clickhouse-backup version
clickhouse-server version