search

rustic-rs / rustic

rustic - fast, encrypted, and deduplicated backups powered by Rust
https://rustic.cli.rs
Apache License 2.0
1.95k stars 70 forks source link

Larger Storage Footprint after Prune and Corruption #1219

Closed webdjoe closed 2 months ago

webdjoe commented 2 months ago

I ran prune for the first time in a while after upgrading to v0.8.0 and had some strange behavior start to appear. I received errors from the prune command and then tried to repair index, then repair snapshots, followed by some manually pruning of ungrouped snapshots. I received different errors in most of the commands and my bucket size increased from 4.1GB to 5.2GB after prune, increasing in size after each prune command.

I have a database that is backed up with stdin and it seems that those packs need to have their size corrected when running repair snapshot but this is a small database so it shouldn't have a major impact on size. I'm not as worried about this database backup but more so the possibility of corruption of other backups and the unchecked increase in bucket size.

Any idea why the bucket would increase in size after running prune?

This is the slimmed down progression of commands and the output.

```bash root@probox:~# rustic -P home_bb prune # PRIMARY ERROR [WARN] Error in cache backend removing Pack,12ff9867: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` ``` ``` [INFO] using config /root/.config/rustic/home_bb.toml [INFO] repository opendal:probox: password is correct. [INFO] using cache at /root/.cache/rustic/1d84a41971981e132290d7e405f819f0cec6ca90f3762ba96c587ac3acc6ecd7 [00:00:00] reading index... ████████████████████████████████████████ 160/160 [00:00:00] reading snapshots... ████████████████████████████████████████ 214/214 [00:00:04] finding used blobs... ████████████████████████████████████████ 214/214 [00:00:00] getting packs from repository... to repack: 241 packs, 17026 blobs, 932.7 MiB this removes: 5682 blobs, 577.2 MiB to delete: 24 packs, 4017 blobs, 474.6 MiB unindexed: 0 packs, ?? blobs, 0 B total prune: 9699 blobs, 1.0 GiB remaining: 38602 blobs, 2.4 GiB unused size after prune: 659.9 MiB (26.36% of remaining size) packs marked for deletion: 125, 653.5 MiB - complete deletion: 125, 653.5 MiB - keep marked: 0, 0 B - recover: 0, 0 B [00:01:11] repacking // rebuilding index... ████████████████████████████████████████ 355.51 MiB/355.51 MiB 4.98 MiB/s (ETA -) [00:00:00] removing old index files... ████████████████████████████████████████ 160/160 [00:00:00] removing old data packs... ████████████████████████████████████████ 71/71 [00:00:00] removing old tree packs... ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░ 0/54 [WARN] Error in cache backend removing Pack,12ca2e45: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,12ff9867: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,45faf838: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,eaea5c63: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,a3d9db04: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,751d7b21: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,54a52658: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,5d9e6dfc: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,fa90e2d6: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,2c929247: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,ba78187b: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,74291dba: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,c0d0d67d: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,08a0de74: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,18bc0482: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,5e1c5f67: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,e341baed: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,5509be38: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,2f5e142d: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [WARN] Error in cache backend removing Pack,b1e946e7: `Os { code: 2, kind: NotFound, message: "No such file or directory" }` [00:00:00] removing old tree packs... ████████████████████████████████████████ 54/54 root@probox:~# rustic -P home_bb check [INFO] using config /root/.config/rustic/home_bb.toml [INFO] repository opendal:probox: password is correct. [INFO] using cache at /root/.cache/rustic/1d84a41971981e132290d7e405f819f0cec6ca90f3762ba96c587ac3acc6ecd7 [00:00:00] checking Snapshot in cache... ████████████████████████████████████████ 114.70 KiB/114.70 KiB 26.19 MiB/s (ETA -) [00:00:00] checking Index in cache... ████████████████████████████████████████ 2.22 MiB/2.22 MiB 456.84 MiB/s (ETA -) [00:00:00] reading index... ████████████████████████████████████████ 1/1 [00:00:00] listing packs... [00:00:00] cleaning up packs from cache... [00:00:00] checking packs in cache... ████████████████████████████████████████ 4.55 MiB/4.55 MiB 18.62 MiB/s (ETA -) [00:00:00] reading snapshots... ████████████████████████████████████████ 214/214 [00:00:00] checking trees... ████████████████████████████████████████ 214/214 ```
```bash # NO ERRORS THAT I CAN SEE rustic -P home_bb repair index --log-level debug ``` Full Output ``` root@probox:~# rustic -P home_bb repair index --log-level debug [INFO] using config /root/.config/rustic/home_bb.toml [DEBUG] (1) opendal::services::s3::backend: backend build started: S3Builder { config: S3Config { root: Some("/"), bucket: "probox", endpoint: Some("https://s3.us-east-005.backblazeb2.com"), region: Some("auto"), .. }, .. } [DEBUG] (1) opendal::services::s3::backend: backend use root / [DEBUG] (1) opendal::services::s3::backend: backend use bucket probox [DEBUG] (1) reqsign::aws::config: load_via_profile_config_file failed: No such file or directory (os error 2) [DEBUG] (1) reqsign::aws::config: load_via_profile_shared_credentials_file failed: No such file or directory (os error 2) [DEBUG] (1) opendal::services::s3::backend: backend use region: auto [DEBUG] (1) opendal::services::s3::backend: backend use endpoint: https://s3.us-east-005.backblazeb2.com/probox [DEBUG] (1) opendal::services: service=s3 name=probox : metadata started [DEBUG] (1) opendal::services: service=s3 name=probox : metadata finished [DEBUG] (1) opendal::services: service=s3 name=probox : metadata started [DEBUG] (1) opendal::services: service=s3 name=probox : metadata finished [DEBUG] (1) opendal::services: service=s3 name=probox : metadata started [DEBUG] (1) opendal::services: service=s3 name=probox : metadata finished [DEBUG] (1) opendal::services: service=s3 name=probox : metadata started [DEBUG] (1) opendal::services: service=s3 name=probox : metadata finished [DEBUG] (1) opendal::services: service=s3 name=probox path=config: stat started [DEBUG] (1) reqsign::aws::v4: calculated scope: 20240902/auto/s3/aws4_request [DEBUG] (1) reqsign::aws::v4: calculated string to sign: AWS4-HMAC-SHA256 20240902T032341Z 20240902/auto/s3/aws4_request 131b8cf426781b08b45f4189d12d1557c60697025acf9f6d61cff8be794087dc [DEBUG] (1) reqwest::connect: starting new connection: https://s3.us-east-005.backblazeb2.com/ [DEBUG] (14) hyper_util::client::legacy::connect::dns: resolving host="s3.us-east-005.backblazeb2.com" [DEBUG] (1) hyper_util::client::legacy::connect::http: connecting to 149.137.140.9:443 [DEBUG] (1) hyper_util::client::legacy::connect::http: connected to 149.137.140.9:443 [DEBUG] (1) hyper_util::client::legacy::pool: pooling idle connection for ("https", s3.us-east-005.backblazeb2.com) [DEBUG] (1) opendal::services: service=s3 name=probox path=config: stat finished [DEBUG] (1) opendal::services: service=s3 name=probox path=keys/: list started [DEBUG] (1) opendal::services: service=s3 name=probox path=keys/: list created lister [DEBUG] (1) reqsign::aws::v4: calculated scope: 20240902/auto/s3/aws4_request [DEBUG] (1) reqsign::aws::v4: calculated string to sign: AWS4-HMAC-SHA256 20240902T032341Z 20240902/auto/s3/aws4_request 5f75040c63c82f798f450b59a1bce296f4fffb80abcc0ce09cdf18ebdac21074 [DEBUG] (1) hyper_util::client::legacy::pool: reuse idle connection for ("https", s3.us-east-005.backblazeb2.com) [DEBUG] (1) hyper_util::client::legacy::pool: pooling idle connection for ("https", s3.us-east-005.backblazeb2.com) [DEBUG] (1) opendal::services: service=s3 name=probox path=keys/bbdef02b5ac7c49a6ca1094b28f50acfa7d5b65ef335d3532eb64816c9f5bbce: stat started [DEBUG] (1) reqsign::aws::v4: calculated scope: 20240902/auto/s3/aws4_request [DEBUG] (1) reqsign::aws::v4: calculated string to sign: AWS4-HMAC-SHA256 20240902T032341Z 20240902/auto/s3/aws4_request 20bcc01ed3278e7b0e2a4295cd9c52822e55bedb899c6b8aab80ccd540989eb3 [DEBUG] (1) hyper_util::client::legacy::pool: reuse idle connection for ("https", s3.us-east-005.backblazeb2.com) [DEBUG] (1) hyper_util::client::legacy::pool: pooling idle connection for ("https", s3.us-east-005.backblazeb2.com) [DEBUG] (1) opendal::services: service=s3 name=probox path=keys/bbdef02b5ac7c49a6ca1094b28f50acfa7d5b65ef335d3532eb64816c9f5bbce: stat finished [DEBUG] (1) opendal::services: service=s3 name=probox path=keys/bbdef02b5ac7c49a6ca1094b28f50acfa7d5b65ef335d3532eb64816c9f5bbce: read started [DEBUG] (1) reqsign::aws::v4: calculated scope: 20240902/auto/s3/aws4_request [DEBUG] (1) reqsign::aws::v4: calculated string to sign: AWS4-HMAC-SHA256 20240902T032341Z 20240902/auto/s3/aws4_request 61073c6465f744902dda96c1537e1edf11305faf2a77f506e0e19389b84d089e [DEBUG] (1) hyper_util::client::legacy::pool: reuse idle connection for ("https", s3.us-east-005.backblazeb2.com) [DEBUG] (1) hyper_util::client::legacy::pool: pooling idle connection for ("https", s3.us-east-005.backblazeb2.com) [DEBUG] (1) opendal::services: service=s3 name=probox path=keys/bbdef02b5ac7c49a6ca1094b28f50acfa7d5b65ef335d3532eb64816c9f5bbce: read created reader [INFO] repository opendal:probox: password is correct. [DEBUG] (1) opendal::services: service=s3 name=probox path=config: stat started [DEBUG] (1) reqsign::aws::v4: calculated scope: 20240902/auto/s3/aws4_request [DEBUG] (1) reqsign::aws::v4: calculated string to sign: AWS4-HMAC-SHA256 20240902T032341Z 20240902/auto/s3/aws4_request 131b8cf426781b08b45f4189d12d1557c60697025acf9f6d61cff8be794087dc [DEBUG] (1) hyper_util::client::legacy::pool: reuse idle connection for ("https", s3.us-east-005.backblazeb2.com) [DEBUG] (1) hyper_util::client::legacy::pool: pooling idle connection for ("https", s3.us-east-005.backblazeb2.com) [DEBUG] (1) opendal::services: service=s3 name=probox path=config: stat finished [DEBUG] (1) opendal::services: service=s3 name=probox path=config: read started [DEBUG] (1) reqsign::aws::v4: calculated scope: 20240902/auto/s3/aws4_request [DEBUG] (1) reqsign::aws::v4: calculated string to sign: AWS4-HMAC-SHA256 20240902T032341Z 20240902/auto/s3/aws4_request 0edaf8304ae342a18f04f1874d9ce11b4f5728ed905b5805473df7e4e35deb53 [DEBUG] (1) hyper_util::client::legacy::pool: reuse idle connection for ("https", s3.us-east-005.backblazeb2.com) [DEBUG] (1) hyper_util::client::legacy::pool: pooling idle connection for ("https", s3.us-east-005.backblazeb2.com) [DEBUG] (1) opendal::services: service=s3 name=probox path=config: read created reader [INFO] using cache at /root/.cache/rustic/1d84a41971981e132290d7e405f819f0cec6ca90f3762ba96c587ac3acc6ecd7 [00:00:00] listing packs... ⠁ [DEBUG] (1) opendal::services: service=s3 name=probox path=data/: list started [DEBUG] (1) opendal::services: service=s3 name=probox path=data/: list created lister [DEBUG] (1) reqsign::aws::v4: calculated scope: 20240902/auto/s3/aws4_request [DEBUG] (1) reqsign::aws::v4: calculated string to sign: AWS4-HMAC-SHA256 20240902T032341Z 20240902/auto/s3/aws4_request 4239968efda13734d0a27d33ca13ed713eabd7ffcde24b0dbc910e4969240f1a [DEBUG] (1) hyper_util::client::legacy::pool: reuse idle connection for ("https", s3.us-east-005.backblazeb2.com) [00:00:00] listing packs... ⠁ [DEBUG] (3) hyper_util::client::legacy::pool: pooling idle connection for ("https", s3.us-east-005.backblazeb2.com) [00:00:00] listing packs... [00:00:00] reading index... ████████████████████████████████████████ 0 [DEBUG] (1) opendal::services: service=s3 name=probox path=index/: list started [DEBUG] (1) opendal::services: service=s3 name=probox path=index/: list created lister [DEBUG] (1) reqsign::aws::v4: calculated scope: 20240902/auto/s3/aws4_request [DEBUG] (1) reqsign::aws::v4: calculated string to sign: AWS4-HMAC-SHA256 20240902T032341Z 20240902/auto/s3/aws4_request 8ef816e0dbf792668a571acaa4a8271823b2fdf8acddc1e3241ef613caaf763d [DEBUG] (1) hyper_util::client::legacy::pool: reuse idle connection for ("https", s3.us-east-005.backblazeb2.com) [00:00:00] reading index... ████████████████████████████████████████ 0 [DEBUG] (1) hyper_util::client::legacy::pool: pooling idle connection for ("https", s3.us-east-005.backblazeb2.com) [00:00:00] reading index... ████████████████████████████████████████ 1/1 [00:00:00] reading pack headers ████████████████████████████████████████ 0/0 ```
```bash rustic -P home_bb repair snapshots # Many of these errors for different snapshots [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as d9190e5b. [INFO] file 00023870: corrected file size [INFO] saved modified snapshot as 1313ba9d. ``` Full Output ```bash root@probox:~# rustic -P home_bb repair snapshots [INFO] using config /root/.config/rustic/home_bb.toml [INFO] repository opendal:probox: password is correct. [INFO] using cache at /root/.cache/rustic/1d84a41971981e132290d7e405f819f0cec6ca90f3762ba96c587ac3acc6ecd7 [00:00:00] reading index... ████████████████████████████████████████ 1/1 [00:00:00] getting snapshots... ████████████████████████████████████████ 214/214 [INFO] processing snapshot 43dfa7e7 [INFO] snapshot 43dfa7e7 is ok. [INFO] processing snapshot 856225d6 [INFO] snapshot 856225d6 is ok. [INFO] processing snapshot 013696b6 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as d9190e5b. [INFO] processing snapshot 8589c9b0 [INFO] snapshot 8589c9b0 is ok. [INFO] processing snapshot 4413cfb9 [INFO] snapshot 4413cfb9 is ok. [INFO] processing snapshot 85964456 [INFO] snapshot 85964456 is ok. [INFO] processing snapshot bb8cd647 [INFO] snapshot bb8cd647 is ok. [INFO] processing snapshot 444d5273 [INFO] snapshot 444d5273 is ok. [INFO] processing snapshot 05d1c426 [INFO] snapshot 05d1c426 is ok. [INFO] processing snapshot 1a94fe80 [INFO] snapshot 1a94fe80 is ok. [INFO] processing snapshot 88136a23 [INFO] snapshot 88136a23 is ok. [INFO] processing snapshot 44b9af25 [INFO] snapshot 44b9af25 is ok. [INFO] processing snapshot 0186a6a0 [INFO] snapshot 0186a6a0 is ok. [INFO] processing snapshot 881ea901 [INFO] snapshot 881ea901 is ok. [INFO] processing snapshot 4592fb7c [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 7abe6cb2. [INFO] processing snapshot 884897e8 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as a07c9846. [INFO] processing snapshot bc7045dc [INFO] snapshot bc7045dc is ok. [INFO] processing snapshot 0f212bff [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as a6483809. [INFO] processing snapshot 2990f8bd [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 24b73649. [INFO] processing snapshot 45a38278 [INFO] snapshot 45a38278 is ok. [INFO] processing snapshot 07af8732 [INFO] snapshot 07af8732 is ok. [INFO] processing snapshot 1b6016bb [INFO] snapshot 1b6016bb is ok. [INFO] processing snapshot 248a59fb [INFO] snapshot 248a59fb is ok. [INFO] processing snapshot 888e9f44 [INFO] snapshot 888e9f44 is ok. [INFO] processing snapshot 45d80355 [INFO] snapshot 45d80355 is ok. [INFO] processing snapshot 0a5a561a [INFO] snapshot 0a5a561a is ok. [INFO] processing snapshot 01ac308a [INFO] snapshot 01ac308a is ok. [INFO] processing snapshot 8eb313e4 [INFO] snapshot 8eb313e4 is ok. [INFO] processing snapshot 8950165f [INFO] snapshot 8950165f is ok. [INFO] processing snapshot bdc172dd [INFO] snapshot bdc172dd is ok. [INFO] processing snapshot 46154289 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 076fa451. [INFO] processing snapshot 08c2b7e8 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as b6861731. [INFO] processing snapshot 8a455692 [INFO] snapshot 8a455692 is ok. [INFO] processing snapshot 01f1cc70 [INFO] snapshot 01f1cc70 is ok. [INFO] processing snapshot 481663e6 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as bcc741c6. [INFO] processing snapshot a14f9907 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 6ca88c93. [INFO] processing snapshot 26166164 [INFO] snapshot 26166164 is ok. [INFO] processing snapshot 8f2fc9ae [INFO] snapshot 8f2fc9ae is ok. [INFO] processing snapshot 8a8927fb [INFO] snapshot 8a8927fb is ok. [INFO] processing snapshot 48ba110f [INFO] snapshot 48ba110f is ok. [INFO] processing snapshot bef106e8 [INFO] snapshot bef106e8 is ok. [INFO] processing snapshot 10a9dee5 [INFO] snapshot 10a9dee5 is ok. [INFO] processing snapshot 2a7a8e45 [INFO] snapshot 2a7a8e45 is ok. [INFO] processing snapshot 0403057e [INFO] snapshot 0403057e is ok. [INFO] processing snapshot 8c65c727 [INFO] snapshot 8c65c727 is ok. [INFO] processing snapshot 4acd1904 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 26d5e90c. [INFO] processing snapshot 22682c19 [INFO] snapshot 22682c19 is ok. [INFO] processing snapshot 13447975 [INFO] snapshot 13447975 is ok. [INFO] processing snapshot 0a862a0f [INFO] snapshot 0a862a0f is ok. [INFO] processing snapshot 4c9a46a9 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 0ef4f125. [INFO] processing snapshot 8f4987ab [INFO] snapshot 8f4987ab is ok. [INFO] processing snapshot 8e31d007 [INFO] snapshot 8e31d007 is ok. [INFO] processing snapshot c01f5e34 [INFO] snapshot c01f5e34 is ok. [INFO] processing snapshot 0462bdbd [INFO] snapshot 0462bdbd is ok. [INFO] processing snapshot 2664f970 [INFO] snapshot 2664f970 is ok. [INFO] processing snapshot 4ca020ae [INFO] snapshot 4ca020ae is ok. [INFO] processing snapshot 8ea1866c [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as fc2a1807. [INFO] processing snapshot 2a952b92 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 92e411cc. [INFO] processing snapshot 1125e48e [INFO] snapshot 1125e48e is ok. [INFO] processing snapshot a19aa7c1 [INFO] snapshot a19aa7c1 is ok. [INFO] processing snapshot 142a6aa9 [INFO] snapshot 142a6aa9 is ok. [INFO] processing snapshot 0ae7e1a7 [INFO] snapshot 0ae7e1a7 is ok. [INFO] processing snapshot 36b8276e [INFO] snapshot 36b8276e is ok. [INFO] processing snapshot 3c296d13 [INFO] snapshot 3c296d13 is ok. [INFO] processing snapshot 4dbdffda [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as eda9d617. [INFO] processing snapshot 294b6d87 [INFO] snapshot 294b6d87 is ok. [INFO] processing snapshot c68af810 [INFO] snapshot c68af810 is ok. [INFO] processing snapshot 93647a57 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as afa51756. [INFO] processing snapshot a28560ad [INFO] snapshot a28560ad is ok. [INFO] processing snapshot 2d949498 [INFO] snapshot 2d949498 is ok. [INFO] processing snapshot 2a9bb5e9 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 520b847b. [INFO] processing snapshot 17bca632 [INFO] snapshot 17bca632 is ok. [INFO] processing snapshot 4eb0e723 [INFO] snapshot 4eb0e723 is ok. [INFO] processing snapshot 374dd0d3 [INFO] snapshot 374dd0d3 is ok. [INFO] processing snapshot 3ca21275 [INFO] snapshot 3ca21275 is ok. [INFO] processing snapshot 0e1bc1b7 [INFO] snapshot 0e1bc1b7 is ok. [INFO] processing snapshot 2b02e7ec [INFO] snapshot 2b02e7ec is ok. [INFO] processing snapshot a34b8c5a [INFO] snapshot a34b8c5a is ok. [INFO] processing snapshot e582e47c [INFO] snapshot e582e47c is ok. [INFO] processing snapshot 4fb7b994 [INFO] snapshot 4fb7b994 is ok. [INFO] processing snapshot 3ccbf8bd [INFO] snapshot 3ccbf8bd is ok. [INFO] processing snapshot 30a0755d [INFO] snapshot 30a0755d is ok. [INFO] processing snapshot c7572890 [INFO] snapshot c7572890 is ok. [INFO] processing snapshot 941479bc [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 49b9b0ba. [INFO] processing snapshot eec0e8d3 [INFO] snapshot eec0e8d3 is ok. [INFO] processing snapshot 2ce9799a [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 12b7f41b. [INFO] processing snapshot 3aa5bf31 [INFO] snapshot 3aa5bf31 is ok. [INFO] processing snapshot a4197af3 [INFO] snapshot a4197af3 is ok. [INFO] processing snapshot 50ca2d44 [INFO] snapshot 50ca2d44 is ok. [INFO] processing snapshot 3e3c160f [INFO] snapshot 3e3c160f is ok. [INFO] processing snapshot 38c47b48 [INFO] snapshot 38c47b48 is ok. [INFO] processing snapshot ef09bcf9 [INFO] snapshot ef09bcf9 is ok. [INFO] processing snapshot 3a729eed [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 0ae91258. [INFO] processing snapshot 381a97ec [INFO] snapshot 381a97ec is ok. [INFO] processing snapshot 3bd74068 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 550ce3fa. [INFO] processing snapshot a4f58a65 [INFO] snapshot a4f58a65 is ok. [INFO] processing snapshot 31c8b153 [INFO] snapshot 31c8b153 is ok. [INFO] processing snapshot 50e6a4ff [INFO] snapshot 50e6a4ff is ok. [INFO] processing snapshot 404401f8 [INFO] snapshot 404401f8 is ok. [INFO] processing snapshot e6d70ff9 [INFO] snapshot e6d70ff9 is ok. [INFO] processing snapshot 9433eca4 [INFO] snapshot 9433eca4 is ok. [INFO] processing snapshot f1c3c8b7 [INFO] snapshot f1c3c8b7 is ok. [INFO] processing snapshot 5e011542 [INFO] snapshot 5e011542 is ok. [INFO] processing snapshot 94e9b80b [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 920c2965. [INFO] processing snapshot 989bc630 [INFO] snapshot 989bc630 is ok. [INFO] processing snapshot 51862af3 [INFO] snapshot 51862af3 is ok. [INFO] processing snapshot 407d711d [INFO] snapshot 407d711d is ok. [INFO] processing snapshot c7b5eeef [INFO] snapshot c7b5eeef is ok. [INFO] processing snapshot f4c17c57 [INFO] snapshot f4c17c57 is ok. [INFO] processing snapshot 9b8f8e0c [INFO] snapshot 9b8f8e0c is ok. [INFO] processing snapshot 6158fb4a [INFO] snapshot 6158fb4a is ok. [INFO] processing snapshot a54bc137 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 844df89f. [INFO] processing snapshot aa3d7796 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as dea3499e. [INFO] processing snapshot 31fb7515 [INFO] snapshot 31fb7515 is ok. [INFO] processing snapshot 963d08f4 [INFO] snapshot 963d08f4 is ok. [INFO] processing snapshot 51f8517e [INFO] snapshot 51f8517e is ok. [INFO] processing snapshot 412eef05 [INFO] snapshot 412eef05 is ok. [INFO] processing snapshot e7571a02 [INFO] snapshot e7571a02 is ok. [INFO] processing snapshot 9e9da27b [INFO] snapshot 9e9da27b is ok. [INFO] processing snapshot 553280c5 [INFO] snapshot 553280c5 is ok. [INFO] processing snapshot f5cef815 [INFO] snapshot f5cef815 is ok. [INFO] processing snapshot 6183bc69 [INFO] snapshot 6183bc69 is ok. [INFO] processing snapshot 97d14f3c [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 22c394ba. [INFO] processing snapshot a0db02fe [INFO] snapshot a0db02fe is ok. [INFO] processing snapshot d193d4f4 [INFO] snapshot d193d4f4 is ok. [INFO] processing snapshot a7c86141 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 576e3076. [INFO] processing snapshot a60864c1 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as e2407189. [INFO] processing snapshot f5e9cf2e [INFO] snapshot f5e9cf2e is ok. [INFO] processing snapshot 61f46fdc [INFO] snapshot 61f46fdc is ok. [INFO] processing snapshot 324dc9dd [INFO] snapshot 324dc9dd is ok. [INFO] processing snapshot cb23cd7f [INFO] snapshot cb23cd7f is ok. [INFO] processing snapshot aa73e1d4 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as acafd6ff. [INFO] processing snapshot e77f5875 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as dc710a37. [INFO] processing snapshot 3493e40e [INFO] snapshot 3493e40e is ok. [INFO] processing snapshot 636140e3 [INFO] snapshot 636140e3 is ok. [INFO] processing snapshot 57410e25 [INFO] snapshot 57410e25 is ok. [INFO] processing snapshot a7df1965 [INFO] snapshot a7df1965 is ok. [INFO] processing snapshot d1de505a [INFO] snapshot d1de505a is ok. [INFO] processing snapshot f7798178 [INFO] snapshot f7798178 is ok. [INFO] processing snapshot 562e47ec [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as cd89b0b6. [INFO] processing snapshot 34acea1c [INFO] snapshot 34acea1c is ok. [INFO] processing snapshot ccd131c0 [INFO] snapshot ccd131c0 is ok. [INFO] processing snapshot 63baaa48 [INFO] snapshot 63baaa48 is ok. [INFO] processing snapshot a8e056dd [INFO] snapshot a8e056dd is ok. [INFO] processing snapshot 5b543c54 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as b61e8eec. [INFO] processing snapshot a66b4f99 [INFO] snapshot a66b4f99 is ok. [INFO] processing snapshot d3278561 [INFO] snapshot d3278561 is ok. [INFO] processing snapshot e8a1c972 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as e0616a18. [INFO] processing snapshot e81068a4 [INFO] snapshot e81068a4 is ok. [INFO] processing snapshot f79c0e30 [INFO] snapshot f79c0e30 is ok. [INFO] processing snapshot aa9c4b75 [INFO] snapshot aa9c4b75 is ok. [INFO] processing snapshot d8d00098 [INFO] snapshot d8d00098 is ok. [INFO] processing snapshot 63f83b70 [INFO] snapshot 63f83b70 is ok. [INFO] processing snapshot a91f063e [INFO] snapshot a91f063e is ok. [INFO] processing snapshot 572e6e68 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 4365ea9b. [INFO] processing snapshot d36120dc [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as f9dbde9b. [INFO] processing snapshot e91a2939 [INFO] snapshot e91a2939 is ok. [INFO] processing snapshot 5c02ab65 [INFO] snapshot 5c02ab65 is ok. [INFO] processing snapshot d8e9dab6 [INFO] snapshot d8e9dab6 is ok. [INFO] processing snapshot cff272cf [INFO] snapshot cff272cf is ok. [INFO] processing snapshot 647c8923 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 90e7b659. [INFO] processing snapshot d680821d [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 7ca910ed. [INFO] processing snapshot b406058c [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 5ff0ab52. [INFO] processing snapshot d3a09d0f [INFO] snapshot d3a09d0f is ok. [INFO] processing snapshot e8189090 [INFO] snapshot e8189090 is ok. [INFO] processing snapshot eb871d8e [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 33a6aaef. [INFO] processing snapshot 5d1c3436 [INFO] snapshot 5d1c3436 is ok. [INFO] processing snapshot fc19c762 [INFO] snapshot fc19c762 is ok. [INFO] processing snapshot e20c52b7 [INFO] snapshot e20c52b7 is ok. [INFO] processing snapshot ae88ed50 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as fb504c68. [INFO] processing snapshot 649020dc [INFO] snapshot 649020dc is ok. [INFO] processing snapshot d7403267 [INFO] saved modified snapshot as 34935af7. [INFO] processing snapshot fd4f4793 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as cf0f7f1a. [INFO] processing snapshot fd71e861 [INFO] snapshot fd71e861 is ok. [INFO] processing snapshot ec1d3a2b [INFO] snapshot ec1d3a2b is ok. [INFO] processing snapshot 6b258af6 [INFO] snapshot 6b258af6 is ok. [INFO] processing snapshot d0b27e89 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as dd81dba7. [INFO] processing snapshot e278c480 [INFO] snapshot e278c480 is ok. [INFO] processing snapshot b41f3c4d [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 8152d656. [INFO] processing snapshot 6898dc28 [INFO] snapshot 6898dc28 is ok. [INFO] processing snapshot b264da3d [INFO] snapshot b264da3d is ok. [INFO] processing snapshot fc2db96c [INFO] snapshot fc2db96c is ok. [INFO] processing snapshot ecaef005 [INFO] snapshot ecaef005 is ok. [INFO] processing snapshot b3f12a14 [INFO] snapshot b3f12a14 is ok. [INFO] processing snapshot 6b61c1d5 [INFO] snapshot 6b61c1d5 is ok. [INFO] processing snapshot fdd28ec5 [INFO] snapshot fdd28ec5 is ok. [INFO] processing snapshot fd52c68d [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 6b1b1cff. [INFO] processing snapshot e31ea3de [INFO] snapshot e31ea3de is ok. [INFO] processing snapshot e338ddda [INFO] snapshot e338ddda is ok. [INFO] processing snapshot 693410bb [INFO] snapshot 693410bb is ok. [INFO] processing snapshot b0808a3c [INFO] snapshot b0808a3c is ok. [INFO] processing snapshot ed707abb [INFO] snapshot ed707abb is ok. [INFO] processing snapshot d185fad1 [INFO] snapshot d185fad1 is ok. [INFO] processing snapshot e43c1b50 [INFO] snapshot e43c1b50 is ok. [INFO] processing snapshot 6d6e310e [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as fbbe725d. [INFO] processing snapshot b5731342 [INFO] snapshot b5731342 is ok. [INFO] processing snapshot b7c472c6 [INFO] snapshot b7c472c6 is ok. [INFO] processing snapshot 7cbedab0 [INFO] file 00023870: corrected file size [INFO] saved modified snapshot as 1313ba9d. [INFO] processing snapshot ba3c5dab [INFO] snapshot ba3c5dab is ok. [INFO] processing snapshot 69899a8f [INFO] snapshot 69899a8f is ok. [INFO] processing snapshot 7da0a498 [INFO] snapshot 7da0a498 is ok. [INFO] processing snapshot 80bf3b5e [INFO] snapshot 80bf3b5e is ok. [INFO] processing snapshot 70bf1ab9 [INFO] snapshot 70bf1ab9 is ok. [INFO] processing snapshot ee772bde [INFO] snapshot ee772bde is ok. [INFO] processing snapshot 6adfabdd [INFO] snapshot 6adfabdd is ok. [INFO] processing snapshot 835f3b1e [INFO] snapshot 835f3b1e is ok. [INFO] processing snapshot b9cb6dd4 [INFO] snapshot b9cb6dd4 is ok. [INFO] processing snapshot bb89d80c [INFO] snapshot bb89d80c is ok. [INFO] processing snapshot 81f42536 [INFO] snapshot 81f42536 is ok. [INFO] processing snapshot 7e47f4a3 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 44a0b74a. [INFO] processing snapshot 7c7bae6e [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 435341b7. [INFO] processing snapshot 7a08c5d0 [INFO] snapshot 7a08c5d0 is ok. [INFO] processing snapshot 79742e17 [INFO] file grafana_db.sql: corrected file size [INFO] saved modified snapshot as 0dbde65f. [INFO] processing snapshot 7fc23cba [INFO] snapshot 7fc23cba is ok. ```
Strange Error When Running Prune Again ```bash rustic -P home_bb prune [WARN] Error in cache backend reading Pack,097567f6: `Error { kind: UnexpectedEof, message: "failed to fill whole buffer" }` ``` ``` [INFO] using config /root/.config/rustic/home_bb.toml [INFO] repository opendal:probox: password is correct. [INFO] using cache at /root/.cache/rustic/1d84a41971981e132290d7e405f819f0cec6ca90f3762ba96c587ac3acc6ecd7 [00:00:00] reading index... ████████████████████████████████████████ 2/2 [00:00:00] reading snapshots... ████████████████████████████████████████ 262/262 [00:00:11] finding used blobs... ███████████████████████░░░░░░░░░░░░░░░░░ 156/262 [WARN] Error in cache backend reading Pack,097567f6: `Error { kind: UnexpectedEof, message: "failed to fill whole buffer" }` [00:00:14] finding used blobs... ████████████████████████████████████████ 262/262 [00:00:00] getting packs from repository.. to repack: 63 packs, 4189 blobs, 331.5 MiB this removes: 166 blobs, 6.9 MiB to delete: 0 packs, 0 blobs, 0 B unindexed: 0 packs, ?? blobs, 0 B total prune: 166 blobs, 6.9 MiB remaining: 47483 blobs, 3.2 GiB unused size after prune: 1.4 GiB (43.43% of remaining size) packs marked for deletion: 265, 1.4 GiB - complete deletion: 0, 0 B - keep marked: 265, 1.4 GiB - recover: 0, 0 B [00:01:37] repacking // rebuilding index... ████████████████████████████████████████ 324.60 MiB/324.60 MiB 3.33 MiB/s (ETA -) [00:00:00] removing old index files... ████████████████████████████████████████ 2/2 ```

Ran check with no errors, thought everything was ok. Ran interactive snapshots and deleted some old testing snapshots and that were backed up incorrectly, along with the repaired db snapshots because they weren't needed. The snapshots I removed were the largest in the repo 2-3GB each.

I ran prune again and it showed an even larger repository size, even though I didn't perform a backup

[INFO] repository opendal:probox: password is correct.
[INFO] using cache at /root/.cache/rustic/1d84a41971981e132290d7e405f819f0cec6ca90f3762ba96c587ac3acc6ecd7
[00:00:00] reading index...               ████████████████████████████████████████          2/2                                                                                                                                            
[00:00:00] reading snapshots...           ████████████████████████████████████████        137/137                                                                                                                                          
[00:00:00] finding used blobs...          ████████████████████████████████████████        137/137                                                                                                                                          
[00:00:00] getting packs from repository...                                                                                                                                                                                                to repack:          3 packs,       5001 blobs,   69.8 MiB
this removes:                        34 blobs,  514.9 kiB
to delete:          0 packs,          0 blobs,        0 B
unindexed:          0 packs,         ?? blobs,        0 B
total prune:                         34 blobs,  514.9 kiB
remaining:                        68045 blobs,    4.1 GiB
unused size after prune:    3.5 GiB (84.37% of remaining size)

packs marked for deletion:        462,    3.5 GiB
 - complete deletion:               0,        0 B
 - keep marked:                   462,    3.5 GiB
 - recover:                         0,        0 B
[00:00:18] repacking // rebuilding index... ████████████████████████████████████████  69.29 MiB/69.29 MiB  3.87 MiB/s   (ETA -)                                                                                                            
[WARN] will retry after 1.109370828s because: Unexpected (temporary) at Writer::close, context: { uri: https://s3.us-east-005.backblazeb2.com/probox/data/bc/bc8e0ee69428397e832fa5079789c3d7570894f54465477020f817f7accebea3, response: Parts { status: 503, version: HTTP/1.1, headers: {"server": "nginx", "date": "Mon, 02 Sep 2024 03:35:06 GMT", "content-type": "application/xml", "content-length": "151", "connection": "keep-alive", "x-amz-request-id": "f07b06280aea1d3d", "x-amz-id-2": "aNxBmEWFwM4kyWDiWZrA5/GEwYcNihzXG", "cache-control": "max-age=0, no-cache, no-store", "strict-transport-security": "max-age=63072000"} }, service: s3, path: data/bc/bc8e0ee69428397e832fa5079789c3d7570894f54465477020f817f7accebea3, written: 2718259 } => S3Error { code: "ServiceUnavailable", message: "no tomes available", resource: "", request_id: "" }

Also running repair snapshots again led to the same db file backup snapshots being repaired again (different snapshots than the first time but same backup). Any ideas as to why this corruption is happening and why the repo would increase in size after prune?

FYI, the command used to backup the DB is:

cmd_string='mysqldump -u root --password=${MYSQL_ROOT_PASSWORD} --host=HOST_ADDRESS --port 3306 --add-drop-table --allow-keywords --complete-insert --quote-names --skip-comments --all-databases --system=all 2>/dev/null'
"$(docker exec mysqldb sh -c "${cmd_string}" | rustic -P "$profile" backup --stdin-filename "$backup_name".sql - --json 2>/dev/null)"
aawsome commented 2 months ago

Any idea why the bucket would increase in size after running prune?

This is because of the 2-phase-pruning. Either re-run prune after 24h or (in case you can ensure that no parallel access is made to the repository) use --instant-delete.

Are you sure you are having corruption? If check reports no error I would first assume everything is OK.

The cache error is strange, but that shouldn't harm anything. Backup up from stdin seems to set a wrong size for the file - this is a minor bug. The other error I saw was just a temporary backend error which rustic obviously just retried.

aawsome commented 2 months ago

In general, if you have questions about the repository size, rustic repoinfo shows details about that...

webdjoe commented 2 months ago

Ahh, ok I wasn't aware of the 2-phase pruning, thank you for clarifying. I was worried that there was another issue I wasn't seeing, just didn't want to lose these backups. I should mention that the file size was correct on the original packs there were repaired and I confirmed there was no corruption. Thank you for the quick response.