Skip to content

Logging in dump/restore #10681

New issue

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

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

Already on GitHub? Sign in to your account

Merged
merged 9 commits into from
Oct 23, 2024
Merged

Logging in dump/restore #10681

merged 9 commits into from
Oct 23, 2024

Conversation

CyberROFL
Copy link
Member

@CyberROFL CyberROFL commented Oct 21, 2024

Changelog entry

Log events during backup/restore.

Changelog category

  • New feature

Additional information

Example
$ ydb -vv tools dump -p . -o ~/test_dump
2024-10-22T19:45:34.000003Z :INFO: Backup "/root/db" to "/home/ilnaz/test_dump"
2024-10-22T19:45:34.000050Z :INFO: Create temporary directory "/root/db/~backup_20241022T224533"
2024-10-22T19:45:34.108713Z :INFO: Copy tables: { src: "/root/db/my_table", dst: "/root/db/~backup_20241022T224533/my_table" }, { src: "/root/db/dir/my_table", dst: "/root/db/~backup_20241022T224533/dir/my_table" }
2024-10-22T19:45:34.270524Z :INFO: Backup table "/root/db/~backup_20241022T224533/my_table" to "/home/ilnaz/test_dump/my_table"
2024-10-22T19:45:34.413531Z :INFO: Backup table "/root/db/~backup_20241022T224533/dir/my_table" to "/home/ilnaz/test_dump/dir/my_table"
2024-10-22T19:45:34.583208Z :INFO: Remove temporary directory "/root/db/~backup_20241022T224533"
2024-10-22T19:45:34.624912Z :INFO: Backup completed successfully

$ ydb -vvv tools dump -p . -o ~/test_dump
2024-10-22T19:46:05.470603Z :INFO: Backup "/root/db" to "/home/ilnaz/test_dump"
2024-10-22T19:46:05.470619Z :INFO: Create temporary directory "/root/db/~backup_20241022T224605"
2024-10-22T19:46:05.525637Z :DEBUG: Process "/home/ilnaz/test_dump/my_table"
2024-10-22T19:46:05.525716Z :DEBUG: Process "/home/ilnaz/test_dump/dir"
2024-10-22T19:46:05.525812Z :DEBUG: Create directory "/root/db/~backup_20241022T224605/dir"
2024-10-22T19:46:05.574958Z :DEBUG: Process "/home/ilnaz/test_dump/dir/my_table"
2024-10-22T19:46:05.575083Z :INFO: Copy tables: { src: "/root/db/my_table", dst: "/root/db/~backup_20241022T224605/my_table" }, { src: "/root/db/dir/my_table", dst: "/root/db/~backup_20241022T224605/dir/my_table" }
2024-10-22T19:46:05.741663Z :INFO: Backup table "/root/db/~backup_20241022T224605/my_table" to "/home/ilnaz/test_dump/my_table"
2024-10-22T19:46:05.741685Z :DEBUG: Describe table "/root/db/~backup_20241022T224605/my_table"
2024-10-22T19:46:05.766875Z :DEBUG: Write scheme into "/home/ilnaz/test_dump/my_table/scheme.pb"
2024-10-22T19:46:05.775038Z :DEBUG: Write ACL into "/home/ilnaz/test_dump/my_table/permissions.pb"
2024-10-22T19:46:05.775092Z :DEBUG: Read table "/root/db/~backup_20241022T224605/my_table"
2024-10-22T19:46:05.801860Z :DEBUG: Write data into "/home/ilnaz/test_dump/my_table/data_00.csv"
2024-10-22T19:46:05.806023Z :DEBUG: Drop table "/root/db/~backup_20241022T224605/my_table"
2024-10-22T19:46:05.884647Z :INFO: Backup table "/root/db/~backup_20241022T224605/dir/my_table" to "/home/ilnaz/test_dump/dir/my_table"
2024-10-22T19:46:05.884665Z :DEBUG: Describe table "/root/db/~backup_20241022T224605/dir/my_table"
2024-10-22T19:46:05.908247Z :DEBUG: Write scheme into "/home/ilnaz/test_dump/dir/my_table/scheme.pb"
2024-10-22T19:46:05.916270Z :DEBUG: Write ACL into "/home/ilnaz/test_dump/dir/my_table/permissions.pb"
2024-10-22T19:46:05.916314Z :DEBUG: Read table "/root/db/~backup_20241022T224605/dir/my_table"
2024-10-22T19:46:05.942835Z :DEBUG: Write data into "/home/ilnaz/test_dump/dir/my_table/data_00.csv"
2024-10-22T19:46:05.947056Z :DEBUG: Drop table "/root/db/~backup_20241022T224605/dir/my_table"
2024-10-22T19:46:06.020630Z :DEBUG: Write ACL into "/home/ilnaz/test_dump/dir/permissions.pb"
2024-10-22T19:46:06.020698Z :DEBUG: Remove directory "/root/db/~backup_20241022T224605/dir"
2024-10-22T19:46:06.051269Z :INFO: Remove temporary directory "/root/db/~backup_20241022T224605"
2024-10-22T19:46:06.090732Z :INFO: Backup completed successfully

$ ydb -vv tools restore -i ~/test_dump/ -p test_restore --import-data
2024-10-21T16:26:08.473196Z :INFO: Restore from '/home/ilnaz/test_dump/' to '/root/db/test_restore'
2024-10-21T16:26:08.515399Z :INFO: Restore table '/home/ilnaz/test_dump/dir/my_table' to '/root/db/test_restore/dir/my_table'
2024-10-21T16:26:08.703785Z :INFO: Restore table '/home/ilnaz/test_dump/my_table' to '/root/db/test_restore/my_table'
2024-10-21T16:26:08.883766Z :INFO: Restore completed successfully

$ ydb -vvv tools restore -i ~/test_dump/ -p test_restore --import-data
2024-10-21T16:25:41.885434Z :INFO: Restore from '/home/ilnaz/test_dump/' to '/root/db/test_restore'
2024-10-21T16:25:41.911236Z :DEBUG: Resolved db base path: '/root/db'
2024-10-21T16:25:41.927269Z :DEBUG: Restore folder '/home/ilnaz/test_dump/' to '/root/db/test_restore'
2024-10-21T16:25:41.927357Z :DEBUG: Restore folder '/home/ilnaz/test_dump/dir' to '/root/db/test_restore/dir'
2024-10-21T16:25:41.927393Z :DEBUG: Process '/home/ilnaz/test_dump/dir/my_table'
2024-10-21T16:25:41.927401Z :DEBUG: Read scheme from '/home/ilnaz/test_dump/dir/my_table/scheme.pb'
2024-10-21T16:25:41.929386Z :INFO: Restore table '/home/ilnaz/test_dump/dir/my_table' to '/root/db/test_restore/dir/my_table'
2024-10-21T16:25:42.069385Z :DEBUG: Created '/root/db/test_restore/dir/my_table'
2024-10-21T16:25:42.082176Z :DEBUG: Read data from '/home/ilnaz/test_dump/dir/my_table/data_00.csv'
2024-10-21T16:25:42.094056Z :DEBUG: Restore permissions to '/root/db/test_restore/dir/my_table'
2024-10-21T16:25:42.107516Z :DEBUG: Restore permissions to '/root/db/test_restore/dir'
2024-10-21T16:25:42.119346Z :DEBUG: Process '/home/ilnaz/test_dump/my_table'
2024-10-21T16:25:42.119364Z :DEBUG: Read scheme from '/home/ilnaz/test_dump/my_table/scheme.pb'
2024-10-21T16:25:42.119492Z :INFO: Restore table '/home/ilnaz/test_dump/my_table' to '/root/db/test_restore/my_table'
2024-10-21T16:25:42.250412Z :DEBUG: Created '/root/db/test_restore/my_table'
2024-10-21T16:25:42.262672Z :DEBUG: Read data from '/home/ilnaz/test_dump/my_table/data_00.csv'
2024-10-21T16:25:42.284185Z :DEBUG: Restore permissions to '/root/db/test_restore/my_table'
2024-10-21T16:25:42.296698Z :INFO: Restore completed successfully

$ ydb -vv tools restore -i ~/test_dump/ -p test_restore --import-data
2024-10-21T16:32:32.828818Z :INFO: Restore from '/home/ilnaz/test_dump/' to '/root/db/test_restore'
2024-10-21T16:32:32.871101Z :INFO: Restore table '/home/ilnaz/test_dump/dir/my_table' to '/root/db/test_restore/dir/my_table'
2024-10-21T16:32:32.893956Z :ERROR: Failed to create '/root/db/test_restore/dir/my_table'
2024-10-21T16:32:32.894047Z :ERROR: Restore failed: [ { <main>: Info: Path: /root/db/test_restore/dir/my_table } { <main>: Error: UserAttributes: attribute '__async_replica' cannot be set } ]
2024-10-21T16:32:32.894056Z :INFO: Cleanup
Status: BAD_REQUEST
Issues: 
<main>: Info: Path: /root/db/test_restore/dir/my_table
<main>: Error: UserAttributes: attribute '__async_replica' cannot be set

@CyberROFL CyberROFL linked an issue Oct 21, 2024 that may be closed by this pull request
@CyberROFL CyberROFL self-assigned this Oct 21, 2024
@CyberROFL CyberROFL requested a review from pixcc October 21, 2024 16:37
@CyberROFL CyberROFL marked this pull request as ready for review October 21, 2024 16:38
Copy link

github-actions bot commented Oct 21, 2024

2024-10-21 16:40:22 UTC Pre-commit check linux-x86_64-release-asan for 8794e1f has started.
2024-10-21 16:40:38 UTC Artifacts will be uploaded here
2024-10-21 16:43:10 UTC ya make is running...
🔴 2024-10-21 16:50:51 UTC Build failed, see the logs. Also see fail summary
🟢 2024-10-21 16:51:09 UTC ydbd size 5.7 GiB changed* by -10.4 MiB, which is <= 0 Bytes vs main: OK

ydbd size dash main: 989a4fa merge: 8794e1f diff diff %
ydbd size 6 109 603 216 Bytes 6 098 693 568 Bytes -10.4 MiB -0.179%
ydbd stripped size 1 522 866 288 Bytes 1 522 306 704 Bytes -546.5 KiB -0.037%

*please be aware that the difference is based on comparing your commit and the last completed build from the post-commit, check comparation

Copy link

github-actions bot commented Oct 21, 2024

2024-10-21 16:40:45 UTC Pre-commit check linux-x86_64-relwithdebinfo for 8794e1f has started.
2024-10-21 16:40:57 UTC Artifacts will be uploaded here
2024-10-21 16:43:39 UTC ya make is running...
🔴 2024-10-21 16:50:34 UTC Build failed, see the logs. Also see fail summary
🟢 2024-10-21 16:50:45 UTC ydbd size 2.8 GiB changed* by 0 Bytes, which is <= 0 Bytes vs main: OK

ydbd size dash main: ff01ea7 merge: 8794e1f diff diff %
ydbd size 3 011 632 376 Bytes 3 011 632 376 Bytes 0 Bytes 0.000%
ydbd stripped size 478 038 488 Bytes 478 038 488 Bytes 0 Bytes 0.000%

*please be aware that the difference is based on comparing your commit and the last completed build from the post-commit, check comparation

Copy link

github-actions bot commented Oct 22, 2024

2024-10-22 08:47:49 UTC Pre-commit check linux-x86_64-release-asan for 829688f has started.
2024-10-22 08:48:00 UTC Artifacts will be uploaded here
2024-10-22 08:50:32 UTC ya make is running...
🟢 2024-10-22 08:58:40 UTC Tests successful.

Test history | Ya make output | Test bloat

TESTS PASSED ERRORS FAILED SKIPPED MUTED?
739 737 0 0 2 0

🟢 2024-10-22 08:58:49 UTC Build successful.
🟢 2024-10-22 08:59:04 UTC ydbd size 5.7 GiB changed* by +384 Bytes, which is < 100.0 KiB vs main: OK

ydbd size dash main: b91414f merge: 829688f diff diff %
ydbd size 6 099 010 536 Bytes 6 099 010 920 Bytes +384 Bytes +0.000%
ydbd stripped size 1 522 360 752 Bytes 1 522 360 816 Bytes +64 Bytes +0.000%

*please be aware that the difference is based on comparing your commit and the last completed build from the post-commit, check comparation

Copy link

github-actions bot commented Oct 22, 2024

2024-10-22 08:47:55 UTC Pre-commit check linux-x86_64-relwithdebinfo for 829688f has started.
2024-10-22 08:48:06 UTC Artifacts will be uploaded here
2024-10-22 08:50:36 UTC ya make is running...
🟢 2024-10-22 08:57:02 UTC Tests successful.

Test history | Ya make output | Test bloat

TESTS PASSED ERRORS FAILED SKIPPED MUTED?
762 760 0 0 2 0

🟢 2024-10-22 08:57:12 UTC Build successful.
🟢 2024-10-22 08:57:21 UTC ydbd size 2.8 GiB changed* by +320 Bytes, which is < 100.0 KiB vs main: OK

ydbd size dash main: b91414f merge: 829688f diff diff %
ydbd size 3 011 981 496 Bytes 3 011 981 816 Bytes +320 Bytes +0.000%
ydbd stripped size 478 072 920 Bytes 478 072 984 Bytes +64 Bytes +0.000%

*please be aware that the difference is based on comparing your commit and the last completed build from the post-commit, check comparation

@CyberROFL CyberROFL enabled auto-merge (squash) October 22, 2024 09:07
@pixcc
Copy link
Member

pixcc commented Oct 22, 2024

Не хочешь добавить Restore data, Restore indexes, Restore ACL в инфо?

Это параметры, которыми пользователь может управлять, и в логе он бы видел изменения.

@CyberROFL
Copy link
Member Author

Не хочешь добавить Restore data, Restore indexes, Restore ACL в инфо?

Это параметры, которыми пользователь может управлять, и в логе он бы видел изменения.

Попробовал, получается слишком много записей по каждой таблице. В норме там должна быть 1 запись на таблицу.

Copy link

github-actions bot commented Oct 22, 2024

2024-10-22 13:48:00 UTC Pre-commit check linux-x86_64-relwithdebinfo for 3003608 has started.
2024-10-22 13:48:11 UTC Artifacts will be uploaded here
2024-10-22 13:50:40 UTC ya make is running...
🟢 2024-10-22 13:57:53 UTC Tests successful.

Test history | Ya make output | Test bloat

TESTS PASSED ERRORS FAILED SKIPPED MUTED?
762 760 0 0 2 0

🟢 2024-10-22 13:58:02 UTC Build successful.
🟢 2024-10-22 13:58:12 UTC ydbd size 2.8 GiB changed* by +3.0 KiB, which is < 100.0 KiB vs main: OK

ydbd size dash main: fca1f18 merge: 3003608 diff diff %
ydbd size 3 012 107 216 Bytes 3 012 110 296 Bytes +3.0 KiB +0.000%
ydbd stripped size 478 085 880 Bytes 478 086 392 Bytes +512 Bytes +0.000%

*please be aware that the difference is based on comparing your commit and the last completed build from the post-commit, check comparation

Copy link

github-actions bot commented Oct 22, 2024

2024-10-22 13:48:09 UTC Pre-commit check linux-x86_64-release-asan for 3003608 has started.
2024-10-22 13:48:20 UTC Artifacts will be uploaded here
2024-10-22 13:52:26 UTC ya make is running...
🔴 2024-10-22 14:00:08 UTC Build failed, see the logs. Also see fail summary
🟢 2024-10-22 14:00:25 UTC ydbd size 5.7 GiB changed* by +7.0 KiB, which is < 100.0 KiB vs main: OK

ydbd size dash main: fca1f18 merge: 3003608 diff diff %
ydbd size 6 099 292 416 Bytes 6 099 299 608 Bytes +7.0 KiB +0.000%
ydbd stripped size 1 522 410 640 Bytes 1 522 411 920 Bytes +1.2 KiB +0.000%

*please be aware that the difference is based on comparing your commit and the last completed build from the post-commit, check comparation

pixcc
pixcc previously approved these changes Oct 22, 2024
Copy link

github-actions bot commented Oct 22, 2024

2024-10-22 19:45:16 UTC Pre-commit check linux-x86_64-release-asan for 87b60a2 has started.
2024-10-22 19:45:54 UTC Artifacts will be uploaded here
2024-10-22 19:49:42 UTC ya make is running...
🔴 2024-10-22 19:55:01 UTC Build failed, see the logs. Also see fail summary

Copy link

github-actions bot commented Oct 22, 2024

2024-10-22 19:46:18 UTC Pre-commit check linux-x86_64-relwithdebinfo for 87b60a2 has started.
2024-10-22 19:47:15 UTC Artifacts will be uploaded here
2024-10-22 19:50:56 UTC ya make is running...
🔴 2024-10-22 19:58:28 UTC Build failed, see the logs. Also see fail summary

@CyberROFL CyberROFL changed the title Introduce logging in 'tools restore' Introduce logging in dump/restore Oct 22, 2024
@CyberROFL CyberROFL changed the title Introduce logging in dump/restore Logging in dump/restore Oct 22, 2024
Copy link

github-actions bot commented Oct 22, 2024

2024-10-22 20:19:17 UTC Pre-commit check linux-x86_64-relwithdebinfo for dbe68f1 has started.
2024-10-22 20:19:28 UTC Artifacts will be uploaded here
2024-10-22 20:22:40 UTC ya make is running...
🟡 2024-10-22 21:31:13 UTC Some tests failed, follow the links below. Going to retry failed tests...

Test history | Ya make output | Test bloat

TESTS PASSED ERRORS FAILED SKIPPED MUTED?
75147 61142 0 1 13907 97

2024-10-22 21:38:05 UTC ya make is running... (failed tests rerun, try 2)
🟡 2024-10-22 21:49:23 UTC Some tests failed, follow the links below. Going to retry failed tests...

Test history | Ya make output | Test bloat | Test bloat

TESTS PASSED ERRORS FAILED SKIPPED MUTED?
97 (only retried tests) 3 0 1 0 93

2024-10-22 21:49:31 UTC ya make is running... (failed tests rerun, try 3)
🔴 2024-10-22 22:00:57 UTC Some tests failed, follow the links below.

Test history | Ya make output | Test bloat | Test bloat | Test bloat

TESTS PASSED ERRORS FAILED SKIPPED MUTED?
94 (only retried tests) 1 0 1 0 92

🟢 2024-10-22 22:01:03 UTC Build successful.
🟢 2024-10-22 22:01:26 UTC ydbd size 2.8 GiB changed* by +736 Bytes, which is < 100.0 KiB vs main: OK

ydbd size dash main: c8a32ef merge: dbe68f1 diff diff %
ydbd size 3 012 369 992 Bytes 3 012 370 728 Bytes +736 Bytes +0.000%
ydbd stripped size 478 204 152 Bytes 478 204 152 Bytes 0 Bytes 0.000%

*please be aware that the difference is based on comparing your commit and the last completed build from the post-commit, check comparation

Copy link

github-actions bot commented Oct 22, 2024

2024-10-22 20:19:30 UTC Pre-commit check linux-x86_64-release-asan for dbe68f1 has started.
2024-10-22 20:19:41 UTC Artifacts will be uploaded here
2024-10-22 20:22:58 UTC ya make is running...
🟡 2024-10-22 21:56:16 UTC Some tests failed, follow the links below. This fail is not in blocking policy yet

Test history | Ya make output | Test bloat

TESTS PASSED ERRORS FAILED SKIPPED MUTED?
12100 11719 0 53 289 39

🟢 2024-10-22 21:57:23 UTC Build successful.
🟢 2024-10-22 21:57:55 UTC ydbd size 5.7 GiB changed* by +6.3 KiB, which is < 100.0 KiB vs main: OK

ydbd size dash main: c8a32ef merge: dbe68f1 diff diff %
ydbd size 6 099 783 304 Bytes 6 099 789 712 Bytes +6.3 KiB +0.000%
ydbd stripped size 1 522 530 608 Bytes 1 522 535 216 Bytes +4.5 KiB +0.000%

*please be aware that the difference is based on comparing your commit and the last completed build from the post-commit, check comparation

Copy link

github-actions bot commented Oct 22, 2024

2024-10-22 22:15:57 UTC Pre-commit check linux-x86_64-relwithdebinfo for 06a4abf has started.
2024-10-22 22:16:36 UTC Artifacts will be uploaded here
2024-10-22 22:20:09 UTC ya make is running...
🟡 2024-10-22 23:24:57 UTC Some tests failed, follow the links below. Going to retry failed tests...

Test history | Ya make output | Test bloat

TESTS PASSED ERRORS FAILED SKIPPED MUTED?
75146 61143 0 2 13907 94

2024-10-22 23:31:52 UTC ya make is running... (failed tests rerun, try 2)
🟢 2024-10-22 23:43:10 UTC Tests successful.

Test history | Ya make output | Test bloat | Test bloat

TESTS PASSED ERRORS FAILED SKIPPED MUTED?
96 (only retried tests) 4 0 0 0 92

🟢 2024-10-22 23:43:16 UTC Build successful.
🟢 2024-10-22 23:43:34 UTC ydbd size 2.8 GiB changed* by +720 Bytes, which is < 100.0 KiB vs main: OK

ydbd size dash main: e45fe26 merge: 06a4abf diff diff %
ydbd size 3 012 402 936 Bytes 3 012 403 656 Bytes +720 Bytes +0.000%
ydbd stripped size 478 209 400 Bytes 478 209 400 Bytes 0 Bytes 0.000%

*please be aware that the difference is based on comparing your commit and the last completed build from the post-commit, check comparation

Copy link

github-actions bot commented Oct 22, 2024

2024-10-22 22:16:22 UTC Pre-commit check linux-x86_64-release-asan for 06a4abf has started.
2024-10-22 22:16:55 UTC Artifacts will be uploaded here
2024-10-22 22:20:47 UTC ya make is running...
🟡 2024-10-22 23:41:13 UTC Some tests failed, follow the links below. This fail is not in blocking policy yet

Test history | Ya make output | Test bloat

TESTS PASSED ERRORS FAILED SKIPPED MUTED?
12092 11907 0 41 45 99

🟢 2024-10-22 23:42:14 UTC Build successful.
🟢 2024-10-22 23:42:48 UTC ydbd size 5.7 GiB changed* by +6.3 KiB, which is < 100.0 KiB vs main: OK

ydbd size dash main: e45fe26 merge: 06a4abf diff diff %
ydbd size 6 099 842 784 Bytes 6 099 849 192 Bytes +6.3 KiB +0.000%
ydbd stripped size 1 522 550 000 Bytes 1 522 554 608 Bytes +4.5 KiB +0.000%

*please be aware that the difference is based on comparing your commit and the last completed build from the post-commit, check comparation

@CyberROFL CyberROFL merged commit 03ea37e into ydb-platform:main Oct 23, 2024
11 checks passed
@CyberROFL CyberROFL deleted the restore-log branch October 23, 2024 11:14
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Progress logs for tools dump/restore
2 participants