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

Missing partitions on uploaded backup to S3 #203

Closed
mastertheknife opened this issue Jun 3, 2021 · 10 comments
Closed

Missing partitions on uploaded backup to S3 #203

mastertheknife opened this issue Jun 3, 2021 · 10 comments

Comments

@mastertheknife
Copy link

Hi,

I use v1.0.0-alpha2 because v0.6.5 doesn't work with ClickHouse 21.3 for me, gives some error about no tables to backup.

If i create a backup with "clickhouse-backup create", the local backup is good, all the partitions are there.
But once i do "clickhouse-backup upload " to upload this backup to S3, the uploaded backup is missing many partitions, of a like a full year. I verified that by downloading default_1.tar.zstd and extracting it.
The local backup is fine however.

Also, when uploading, the output is a little strange, it finishes too soon:

 8.44 GiB / 34.16 GiB [=====================================>------------------------------------------------------------------------------------------------------------------]  24.69% 4m16s
2021/06/03 22:55:36  info done                      backup=2021-06-03T22-13-02 operation=upload table=mydb.mytable
@Slach
Copy link
Collaborator

Slach commented Jun 4, 2021

could you share results of

LOG_LEVEL=debug DISABLE_PROGRESS_BAR=true clickhouse-backup create debug_backup
LOG_LEVEL=debug DISABLE_PROGRESS_BAR=true clickhouse-backup upload debug_backup

?

@mastertheknife
Copy link
Author 

2021/06/04 06:45:53 debug SELECT name, engine FROM system.databases WHERE name != 'system'
2021/06/04 06:45:53 debug SHOW CREATE DATABASE `default`
2021/06/04 06:45:53 debug SHOW CREATE DATABASE `mydbm`
2021/06/04 06:45:53 debug SHOW CREATE DATABASE `mydba27`
2021/06/04 06:45:53 debug SHOW CREATE DATABASE `mydba2o`
2021/06/04 06:45:53 debug SHOW CREATE DATABASE `mydbvb7`
2021/06/04 06:45:53 debug SHOW CREATE DATABASE `mydbvbo`
2021/06/04 06:45:53 debug SHOW CREATE DATABASE `mydbzm`
2021/06/04 06:45:53 debug SHOW CREATE DATABASE `mydbzo`
2021/06/04 06:45:53 debug SELECT count() FROM system.settings WHERE name = 'show_table_uuid_in_table_create_query_if_not_nil'
2021/06/04 06:45:53 debug SELECT * FROM system.tables WHERE is_temporary = 0 SETTINGS show_table_uuid_in_table_create_query_if_not_nil=1
2021/06/04 06:47:28 debug SELECT database, table, sum(bytes_on_disk) as size FROM system.parts GROUP BY (database, table);
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug create data               backup=debug_backup operation=create table=mydba2o.cc
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug ALTER TABLE `mydba2o`.`cc` FREEZE WITH NAME '227261b2851f4ad7b269c70275333315';
2021/06/04 06:47:28 debug freezed                   backup=debug_backup operation=create table=mydba2o.cc
2021/06/04 06:47:28 debug shadow moved              backup=debug_backup disk=default operation=create table=mydba2o.cc
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug done                      backup=debug_backup operation=create table=mydba2o.cc
2021/06/04 06:47:28 debug create metadata           backup=debug_backup operation=create table=mydba2o.cc
2021/06/04 06:47:28  info done                      backup=debug_backup operation=create table=mydba2o.cc
2021/06/04 06:47:28 debug create data               backup=debug_backup operation=create table=mydba2o.cc_2017
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug ALTER TABLE `mydba2o`.`cc_2017` FREEZE WITH NAME 'ea36affe9ee44e46990e9abf5712e010';
2021/06/04 06:47:28 debug freezed                   backup=debug_backup operation=create table=mydba2o.cc_2017
2021/06/04 06:47:28 debug shadow moved              backup=debug_backup disk=default operation=create table=mydba2o.cc_2017
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug done                      backup=debug_backup operation=create table=mydba2o.cc_2017
2021/06/04 06:47:28 debug create metadata           backup=debug_backup operation=create table=mydba2o.cc_2017
2021/06/04 06:47:28  info done                      backup=debug_backup operation=create table=mydba2o.cc_2017
2021/06/04 06:47:28 debug create data               backup=debug_backup operation=create table=mydba2o.cc_2018
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug ALTER TABLE `mydba2o`.`cc_2018` FREEZE WITH NAME 'd7877978b4544c829626a88a94f2c2be';
2021/06/04 06:47:28 debug freezed                   backup=debug_backup operation=create table=mydba2o.cc_2018
2021/06/04 06:47:28 debug shadow moved              backup=debug_backup disk=default operation=create table=mydba2o.cc_2018
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug done                      backup=debug_backup operation=create table=mydba2o.cc_2018
2021/06/04 06:47:28 debug create metadata           backup=debug_backup operation=create table=mydba2o.cc_2018
2021/06/04 06:47:28  info done                      backup=debug_backup operation=create table=mydba2o.cc_2018
2021/06/04 06:47:28 debug create data               backup=debug_backup operation=create table=mydba2o.cc_2019
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug ALTER TABLE `mydba2o`.`cc_2019` FREEZE WITH NAME '594f148e1bb54b69856f726aa897dba0';
2021/06/04 06:47:28 debug freezed                   backup=debug_backup operation=create table=mydba2o.cc_2019
2021/06/04 06:47:28 debug shadow moved              backup=debug_backup disk=default operation=create table=mydba2o.cc_2019
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug done                      backup=debug_backup operation=create table=mydba2o.cc_2019
2021/06/04 06:47:28 debug create metadata           backup=debug_backup operation=create table=mydba2o.cc_2019
2021/06/04 06:47:28  info done                      backup=debug_backup operation=create table=mydba2o.cc_2019
2021/06/04 06:47:28 debug create data               backup=debug_backup operation=create table=mydba2o.ccd
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug skipped                   backup=debug_backup engine=Dictionary operation=create table=mydba2o.ccd
2021/06/04 06:47:28 debug create metadata           backup=debug_backup operation=create table=mydba2o.ccd
2021/06/04 06:47:28  info done                      backup=debug_backup operation=create table=mydba2o.ccd
2021/06/04 06:47:28 debug create data               backup=debug_backup operation=create table=mydba2o.country_code_with_iso
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug skipped                   backup=debug_backup engine=Dictionary operation=create table=mydba2o.country_code_with_iso
2021/06/04 06:47:28 debug create metadata           backup=debug_backup operation=create table=mydba2o.country_code_with_iso
2021/06/04 06:47:28  info done                      backup=debug_backup operation=create table=mydba2o.country_code_with_iso
2021/06/04 06:47:28 debug create data               backup=debug_backup operation=create table=mydbvbo.drtl
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug skipped                   backup=debug_backup engine=Dictionary operation=create table=mydbvbo.drtl
2021/06/04 06:47:28 debug create metadata           backup=debug_backup operation=create table=mydbvbo.drtl
2021/06/04 06:47:28  info done                      backup=debug_backup operation=create table=mydbvbo.drtl
2021/06/04 06:47:28 debug create data               backup=debug_backup operation=create table=mydbvbo.join_cc_delta
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug skipped                   backup=debug_backup engine=Join operation=create table=mydbvbo.join_cc_delta
2021/06/04 06:47:28 debug create metadata           backup=debug_backup operation=create table=mydbvbo.join_cc_delta
2021/06/04 06:47:28  info done                      backup=debug_backup operation=create table=mydbvbo.join_cc_delta
2021/06/04 06:47:28 debug create data               backup=debug_backup operation=create table=mydbzo.dict_hostnames
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug skipped                   backup=debug_backup engine=Dictionary operation=create table=mydbzo.dict_hostnames
2021/06/04 06:47:28 debug create metadata           backup=debug_backup operation=create table=mydbzo.dict_hostnames
2021/06/04 06:47:28  info done                      backup=debug_backup operation=create table=mydbzo.dict_hostnames
2021/06/04 06:47:28 debug create data               backup=debug_backup operation=create table=mydbzo.fh
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug SELECT * FROM system.disks;
2021/06/04 06:47:28 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:28 debug ALTER TABLE `mydbzo`.`fh` FREEZE WITH NAME 'ee60591bb13346a5a9fbd3679b6aabd1';
2021/06/04 06:47:28 debug freezed                   backup=debug_backup operation=create table=mydbzo.fh
2021/06/04 06:47:28 debug shadow moved              backup=debug_backup disk=default operation=create table=mydbzo.fh
2021/06/04 06:47:29 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:29 debug SELECT * FROM system.disks;
2021/06/04 06:47:29 debug done                      backup=debug_backup operation=create table=mydbzo.fh
2021/06/04 06:47:29 debug create metadata           backup=debug_backup operation=create table=mydbzo.fh
2021/06/04 06:47:29  info done                      backup=debug_backup operation=create table=mydbzo.fh
2021/06/04 06:47:29 debug create data               backup=debug_backup operation=create table=mydbzo.fh_uint
2021/06/04 06:47:29 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:29 debug SELECT * FROM system.disks;
2021/06/04 06:47:29 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:29 debug ALTER TABLE `mydbzo`.`fh_uint` FREEZE WITH NAME '66b45dd387d14fadbbea13618eae199c';
2021/06/04 06:47:29 debug freezed                   backup=debug_backup operation=create table=mydbzo.fh_uint
2021/06/04 06:47:29 debug shadow moved              backup=debug_backup disk=default operation=create table=mydbzo.fh_uint
2021/06/04 06:47:29 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:29 debug SELECT * FROM system.disks;
2021/06/04 06:47:29 debug done                      backup=debug_backup operation=create table=mydbzo.fh_uint
2021/06/04 06:47:29 debug create metadata           backup=debug_backup operation=create table=mydbzo.fh_uint
2021/06/04 06:47:29  info done                      backup=debug_backup operation=create table=mydbzo.fh_uint
2021/06/04 06:47:29 debug SELECT value FROM `system`.`build_options` where name='VERSION_DESCRIBE'
2021/06/04 06:47:29 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:29 debug SELECT * FROM system.disks;
2021/06/04 06:47:29 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:29 debug SELECT * FROM system.disks;
2021/06/04 06:47:29 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:47:29 debug SELECT * FROM system.disks;
2021/06/04 06:47:29  info delete '2021-06-03T22-13-02'
2021/06/04 06:47:29 debug remove '2021-06-03T22-13-02' path=/var/lib/clickhouse/
2021/06/04 06:47:29  info done                      backup=debug_backup operation=create

[root@server ~]# LOG_LEVEL=debug DISABLE_PROGRESS_BAR=true clickhouse-backup upload debug_backup
2021/06/04 06:54:52 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:54:52 debug SELECT * FROM system.disks;
2021/06/04 06:54:52 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:54:52 debug SELECT * FROM system.disks;
2021/06/04 06:54:52 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 06:54:52 debug SELECT * FROM system.disks;
2021/06/04 06:58:06  info done                      backup=debug_backup operation=upload table=mydba2o.cc
2021/06/04 06:59:52  info done                      backup=debug_backup operation=upload table=mydba2o.cc_2017
2021/06/04 07:04:04  info done                      backup=debug_backup operation=upload table=mydba2o.cc_2018
2021/06/04 07:09:01  info done                      backup=debug_backup operation=upload table=mydba2o.cc_2019
2021/06/04 07:11:23  info done                      backup=debug_backup operation=upload table=mydbo.fh_uint
2021/06/04 07:11:24  info done                      backup=debug_backup operation=upload table=mydbvbo.join_cc_delta
2021/06/04 07:11:57  info done                      backup=debug_backup operation=upload table=mydbo.fh
2021/06/04 07:11:57  info done                      backup=debug_backup operation=upload table=mydba2o.country_code_with_iso
2021/06/04 07:11:57  info done                      backup=debug_backup operation=upload table=mydbvbo.drtl
2021/06/04 07:11:57  info done                      backup=debug_backup operation=upload table=mydbo.dict_hostnames
2021/06/04 07:11:57  info done                      backup=debug_backup operation=upload table=mydba2o.ccd
2021/06/04 07:11:57 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 07:11:57 debug SELECT * FROM system.disks;
2021/06/04 07:11:57  info done                      backup=debug_backup operation=upload

[root@server ~]# LOG_LEVEL=debug DISABLE_PROGRESS_BAR=true clickhouse-backup list
2021/06/04 07:12:25 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/04 07:12:25 debug SELECT * FROM system.disks;
debug_backup   75.73GiB   04/06/2021 06:47:29   local       
debug_backup   ???        01/01/0001 00:00:00   remote      broken (not found metadata.json)

@mastertheknife
Copy link
Author

I am not sure why it thinks the backup is broken. debug_backup/metadata.json exists in the S3 bucket.
Also, the local backup is fine, the metadata for affected table is correct, and all partitions are listed.

Again i downloaded default_1.tar and extracted it. It only has parts from 199802 until 202007, but the local backup has much more:

[root@server ~]# ls -lh /var/lib/clickhouse/backup/debug_backup/shadow/mydba2o/cc/default/
total 216K
drwxr-x---. 2 root root  260 Jun  4 06:47 199802_309_309_3_8920
drwxr-x---. 2 root root  260 Jun  4 06:47 201911_310_310_3_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202001_4_28_4_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202002_29_62_5_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202003_63_95_4_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202004_96_108_4_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202005_109_125_4_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202006_126_145_4_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202007_146_168_4_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202008_169_189_4_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202009_190_211_4_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202010_212_234_4_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202011_235_272_5_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202012_273_312_5_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202101_313_339_4_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202102_340_381_5_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202103_382_429_5_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202104_8921_8985_3
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202105_8795_8850_4_8920
drwxr-x---. 2 root root 8.0K Jun  4 06:47 202106_8851_8986_12_8920
drwxr-x---. 2 root root  260 Jun  4 06:47 202106_8987_8987_0

@mastertheknife
Copy link
Author

Sorry, closed by accident.

@mastertheknife mastertheknife reopened this Jun 4, 2021
@mastertheknife mastertheknife mentioned this issue Jun 4, 2021
Closed
@AlexAkulov
Copy link
Collaborator

Thank you for detailed description. It is very useful.
I think there is an error on uploading that is not being handled correctly.

@AlexAkulov
Copy link
Collaborator

I have improved error handling on upload in aadce0b. Please try again with version from master.

@mastertheknife
Copy link
Author

mastertheknife commented Jun 9, 2021 •
edited
Loading

@AlexAkulov Good work! It turned out to be helpful:

[root@server ~]# LOG_LEVEL=debug clickhouse-backup upload 2021-06-09T19-51-41
2021/06/09 19:53:36 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/09 19:53:36 debug SELECT * FROM system.disks;
2021/06/09 19:53:36 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/09 19:53:36 debug SELECT * FROM system.disks;
2021/06/09 19:53:36 debug SELECT value FROM `system`.`build_options` where name='VERSION_INTEGER'
2021/06/09 19:53:36 debug SELECT * FROM system.disks;
 8.44 GiB / 34.86 GiB [====================================>-------------------------------------------------------------------------------------------------------------------]  24.20% 4m20s
2021/06/09 19:57:57 error can't upload: open /var/lib/clickhouse/backup/2021-06-09T19-51-41/shadow/mydba2o/cc/default/202007_146_168_4_10024/extension_name.bin: too many open files

Edit: Here are the current shell limits. This is CentOS 8:

[root@server ~]# ulimit -a
core file size          (blocks, -c) unlimited
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 60606
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 1024
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 60606
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

I guess i can increase with ulimit -n prior running clickhouse-backup

@AlexAkulov
Copy link
Collaborator

This is bug in clickhouse-backup. I tried to fix it in 65af2e0
Please, try again.

@mastertheknife
Copy link
Author

Hi, thank you.
Indeed, before the fix, i saw open files steadily increase, even to about ~4000 open files, until the next table and so on.
After the fix, i haven't seen it exceed 9-10 open files.

As of commit 756ceac, everything is working perfectly for me.
Thank you for this little tool, its awesome and very easy to use.

@AlexAkulov
Copy link
Collaborator

Thank you very much for debug!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@Slach @mastertheknife @AlexAkulov