|
| From: | edgar . soldin |
| Subject: | Re: [Duplicity-talk] Strange exception during a restore with 1.2.1 from AWS |
| Date: | Wed, 16 Aug 2023 12:13:27 +0200 |
| User-agent: | Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:102.0) Gecko/20100101 Thunderbird/102.10.1 |
hey Jakob, the relevant bit indeed is
Giving up after 5 attempts. EndpointConnectionError: Could not connect to the endpoint URL: "https://wisemo-bk-hq.s3.eu-north-1.amazonaws.com/more/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg?uploads"; Processed volume 273 Writing wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol273.difftar.gpg Making directory /bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.6 Create Par2 recovery files
duplicity should not continue the backup if a retried upload finally fails. just checked the sources. the relevant code in the current https://gitlab.com/duplicity/duplicity/-/blob/main/duplicity/backend.py#L401 but also in the 1.2.1 sources https://gitlab.com/duplicity/duplicity/-/blob/rel.1.2.1/duplicity/backend.py?ref_type=tags#L419 calls log.FatalError(...) https://gitlab.com/duplicity/duplicity/-/blob/main/duplicity/log.py?ref_type=heads#L344 which in turn exits the program with an error code. i am stumped why that didn't happen in your case. maybe because of the par backend wrapper? looks like you found a bug. please add a bug ticket https://gitlab.com/duplicity/duplicity/-/issues with these informations. generally, as backups are crucial, i would advise to verify regularily anyway, because even if an upload was supposedly successful, it does not warrant any restorability. only verification makes sure of that. thanks.. ede/duply.net On 16.08.2023 10:52, Jakob Bohm via Duplicity-talk wrote:
Ahh, now I can confirm that the file doesn't exist. Digging into old logs for May 25, I see there were connection errors for volumes 272 to 290, but somehow duplicity just kept going past each one. I suspect some kind of transitional network error during backup creation. But duplicity essentially ignored the errors and kept creating and "uploading" volumes until the connection was restored and later volumes got successfully uploaded. A few lines from that morning for volume 272 (this repeated for 29 volumes): 58.3GB 06:04:56 [1.6MB/s] [> ] 2% ETA 10d 6h 31min 58.3GB 06:04:59 [1.1MB/s] [> ] 2% ETA 10d 6h 33min 58.3GB 06:05:02 [816.7KB/s] [> ] 2% ETA 10d 6h 35min 58.3GB 06:05:05 [571.7KB/s] [> ] 2% ETA 10d 6h 37min 58.3GB 06:05:08 [400.2KB/s] [> ] 2% ETA 10d 6h 39min 58.3GB 06:05:11 [280.1KB/s] [> ] 2% ETA 10d 6h 41min AsyncScheduler: scheduling task for asynchronous execution Processed volume 272 Writing wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg Making directory /bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.1 Create Par2 recovery files Reading results of 'par2 c -r10 -n1 -q -q "/bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.1/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg"' 58.3GB 06:05:14 [196.1KB/s] [> ] 2% ETA 10d 6h 43min 58.3GB 06:05:17 [137.3KB/s] [> ] 2% ETA 10d 6h 45min 58.3GB 06:05:20 [96.1KB/s] [> ] 2% ETA 10d 6h 47min 58.3GB 06:05:23 [67.3KB/s] [> ] 2% ETA 10d 6h 49min 58.3GB 06:05:26 [47.1KB/s] [> ] 2% ETA 10d 6h 51min A bkup3/MSSQL/Backup2015-12-03_SW6.bin 58.3GB 06:05:29 [33.0KB/s] [> ] 2% ETA 10d 6h 53min 58.3GB 06:05:32 [23.1KB/s] [> ] 2% ETA 10d 6h 55min 58.3GB 06:05:35 [16.1KB/s] [> ] 2% ETA 10d 6h 57min A bkup3/MSSQL/Backup2015-12-03_SW7.bin 58.3GB 06:05:38 [11.3KB/s] [> ] 2% ETA 10d 6h 59min 58.3GB 06:05:41 [7.9KB/s] [> ] 2% ETA 10d 7h 1min Deleting /bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.1/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg Uploading boto3+s3://wisemo-bk-hq/more/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg to GLACIER_IR Storage 58.4GB 06:05:44 [1.3MB/s] [> ] 2% ETA 10d 7h A bkup3/MSSQL/Backup2015-12-03_SW8.bin A bkup3/MSSQL/Backup2015-12-04_STAGING.bin A bkup3/MSSQL/Backup2015-12-04_SW1.bin 58.4GB 06:05:47 [4.4MB/s] [> ] 2% ETA 10d 6h 53min A bkup3/MSSQL/Backup2015-12-04_SW2.bin 58.4GB 06:05:50 [3.3MB/s] [> ] 2% ETA 10d 6h 55min 58.4GB 06:05:53 [2.3MB/s] [> ] 2% ETA 10d 6h 57min 58.4GB 06:05:56 [1.6MB/s] [> ] 2% ETA 10d 6h 59min 58.4GB 06:05:59 [1.1MB/s] [> ] 2% ETA 10d 7h 1min 58.4GB 06:06:02 [815.7KB/s] [> ] 2% ETA 10d 7h 3min 58.4GB 06:06:05 [570.9KB/s] [> ] 2% ETA 10d 7h 5min 58.4GB 06:06:08 [399.6KB/s] [> ] 2% ETA 10d 7h 7min 58.4GB 06:06:11 [279.6KB/s] [> ] 2% ETA 10d 7h 9min 58.4GB 06:06:14 [195.8KB/s] [> ] 2% ETA 10d 7h 11min 58.4GB 06:06:17 [137.0KB/s] [> ] 2% ETA 10d 7h 13min 58.4GB 06:06:20 [95.9KB/s] [> ] 2% ETA 10d 7h 15min 58.4GB 06:06:23 [67.1KB/s] [> ] 2% ETA 10d 7h 17min A bkup3/MSSQL/Backup2015-12-04_SW6.bin 58.4GB 06:06:26 [47.0KB/s] [> ] 2% ETA 10d 7h 19min A bkup3/MSSQL/Backup2015-12-04_SW7.bin 58.4GB 06:06:29 [32.9KB/s] [> ] 2% ETA 10d 7h 21min AsyncScheduler: scheduling task for asynchronous execution 58.4GB 06:06:32 [23.0KB/s] [> ] 2% ETA 10d 7h 23min 58.4GB 06:06:35 [16.1KB/s] [> ] 2% ETA 10d 7h 25min 58.4GB 06:06:38 [11.3KB/s] [> ] 2% ETA 10d 7h 27min 58.4GB 06:06:41 [7.9KB/s] [> ] 2% ETA 10d 7h 29min 58.4GB 06:06:44 [5.5KB/s] [> ] 2% ETA 10d 7h 31min 58.4GB 06:06:47 [3.9KB/s] [> ] 2% ETA 10d 7h 33min 58.4GB 06:06:50 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:06:53 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:06:56 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:06:59 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:02 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:05 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:08 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:11 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:14 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:17 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:20 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:23 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:26 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:29 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:32 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:35 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:38 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:41 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:44 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:47 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:50 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:53 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:56 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:07:59 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:02 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:05 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:08 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:11 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:14 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:17 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:20 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:23 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:26 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:29 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:32 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:35 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:38 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:41 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:44 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:47 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:50 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:53 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:56 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:08:59 [0.0B/s] [> ] 2% ETA Stalled! Attempt of put Nr. 1 failed. EndpointConnectionError: Could not connect to the endpoint URL: "https://wisemo-bk-hq.s3.eu-north-1.amazonaws.com/more/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg?uploadId=V0ycpw5Yj3a0Owy7H7BsoQv9OTAZ0I63uwIMZbPAfaY_yRTPV6Wi0zEHksAetOAs8w7b1BI336bTQHP5TBpWuJzajmMsIRVXJZxd0Riu_lxMAg9dDaTQSE.cYrZazXWh&partNumber=1"; 58.4GB 06:09:02 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:05 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:08 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:11 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:14 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:17 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:20 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:23 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:26 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:29 [0.0B/s] [> ] 2% ETA Stalled! Writing wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg Making directory /bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.2 Create Par2 recovery files Reading results of 'par2 c -r10 -n1 -q -q "/bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.2/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg"' 58.4GB 06:09:32 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:35 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:38 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:41 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:44 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:47 [0.0B/s] [> ] 2% ETA Stalled! Deleting /bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.2/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg Uploading boto3+s3://wisemo-bk-hq/more/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg to GLACIER_IR Storage 58.4GB 06:09:50 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:53 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:56 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:09:59 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:02 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:05 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:08 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:11 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:14 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:17 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:20 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:23 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:26 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:29 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:32 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:35 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:38 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:41 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:44 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:47 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:50 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:53 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:56 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:10:59 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:02 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:05 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:08 [0.0B/s] [> ] 2% ETA Stalled! Attempt of put Nr. 2 failed. EndpointConnectionError: Could not connect to the endpoint URL: "https://wisemo-bk-hq.s3.eu-north-1.amazonaws.com/more/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg?uploads"; 58.4GB 06:11:11 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:14 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:17 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:20 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:23 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:26 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:29 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:32 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:35 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:38 [0.0B/s] [> ] 2% ETA Stalled! Writing wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg Making directory /bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.3 Create Par2 recovery files Reading results of 'par2 c -r10 -n1 -q -q "/bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.3/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg"' 58.4GB 06:11:41 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:44 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:47 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:50 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:53 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:56 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:11:59 [0.0B/s] [> ] 2% ETA Stalled! Deleting /bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.3/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg Uploading boto3+s3://wisemo-bk-hq/more/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg to GLACIER_IR Storage 58.4GB 06:12:02 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:05 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:08 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:11 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:15 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:18 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:21 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:24 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:27 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:30 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:33 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:36 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:39 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:42 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:45 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:48 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:51 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:54 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:12:57 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:00 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:03 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:06 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:09 [0.0B/s] [> ] 2% ETA Stalled! Attempt of put Nr. 3 failed. EndpointConnectionError: Could not connect to the endpoint URL: "https://wisemo-bk-hq.s3.eu-north-1.amazonaws.com/more/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg?uploads"; 58.4GB 06:13:12 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:15 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:18 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:21 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:24 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:27 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:30 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:33 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:36 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:39 [0.0B/s] [> ] 2% ETA Stalled! Writing wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg Making directory /bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.4 Create Par2 recovery files Reading results of 'par2 c -r10 -n1 -q -q "/bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.4/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg"' 58.4GB 06:13:42 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:45 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:48 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:51 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:54 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:13:57 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:00 [0.0B/s] [> ] 2% ETA Stalled! Deleting /bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.4/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg Uploading boto3+s3://wisemo-bk-hq/more/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg to GLACIER_IR Storage 58.4GB 06:14:03 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:06 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:09 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:12 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:15 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:18 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:21 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:24 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:27 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:30 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:33 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:36 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:39 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:42 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:45 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:48 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:51 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:54 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:14:57 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:00 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:03 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:06 [0.0B/s] [> ] 2% ETA Stalled! Attempt of put Nr. 4 failed. EndpointConnectionError: Could not connect to the endpoint URL: "https://wisemo-bk-hq.s3.eu-north-1.amazonaws.com/more/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg?uploads"; 58.4GB 06:15:09 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:12 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:15 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:18 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:21 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:24 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:27 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:30 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:33 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:36 [0.0B/s] [> ] 2% ETA Stalled! Writing wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg Making directory /bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.5 Create Par2 recovery files Reading results of 'par2 c -r10 -n1 -q -q "/bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.5/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg"' 58.4GB 06:15:39 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:42 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:45 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:48 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:51 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:54 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:15:57 [0.0B/s] [> ] 2% ETA Stalled! Deleting /bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.5/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg Uploading boto3+s3://wisemo-bk-hq/more/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg to GLACIER_IR Storage 58.4GB 06:16:00 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:03 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:06 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:09 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:12 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:15 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:18 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:21 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:24 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:27 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:30 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:33 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:36 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:39 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:42 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:45 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:48 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:51 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:54 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:16:57 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:17:00 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:17:03 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:17:06 [0.0B/s] [> ] 2% ETA Stalled! Giving up after 5 attempts. EndpointConnectionError: Could not connect to the endpoint URL: "https://wisemo-bk-hq.s3.eu-north-1.amazonaws.com/more/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg?uploads"; Processed volume 273 Writing wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol273.difftar.gpg Making directory /bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.6 Create Par2 recovery files Reading results of 'par2 c -r10 -n1 -q -q "/bkup4/tmp/wisemo-bk-real-more/duplicity-720dor6j-tempdir/duplicity_temp.6/wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol273.difftar.gpg"' 58.4GB 06:17:09 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:17:12 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:17:15 [0.0B/s] [> ] 2% ETA Stalled! 58.4GB 06:17:18 [0.0B/s] [> ] 2% ETA Stalled! On 2023-08-15 23:57, Scott Hannahs wrote:Before you go ragging on duplicity too much, it appears that this issue is a file is missing from your storage. This is more a storage issue than a duplicity issue. It is not clear that duplicity is the source of your missing volume. Network transfer issues may also be at play. Using the duplicity “verify” functionality might warn you of a storage issue. The file is probably wisemo-bk-real-more_duplicity-full.20230525T021330Z.vol272.difftar.gpg as my best guess at your backup strategy. I admit the “KeyError” report is a little hard to fathom as to what is the issue. I am not sure how big your backup is but 11K volumes seems a bit large, you might want to increase the volume size to reduce the number of volumes. Duplicity is designed to work with insecure and unreliable storage, but to fully implement that you need to have multiple copies in multiple places. -sthOn Aug 15, 2023, at 5:15 PM, Jakob Bohm via Duplicity-talk <duplicity-talk@nongnu.org> wrote: Dear list, This path contains a chain of full and incremental backups going back months. Any competent backup program is expected to not corrupt its storage and then proceed without errors to add further incrementals in a way that it cannot restore . As to how to check the directory listing on AWS S3, I don't know what file name to look for, especially given the limitation that S3 can only search on a name prefix, not arbitrary wildcards. The partition in question contains terabytes of data, that should not be lost under any circumstance, and this is the fire drill test of the restore procedure. If duplicity cannot handle this basic task, I will need to look for other solutions for continuous system backup. On 2023-08-11 18:54, Kenneth Loafman via Duplicity-talk wrote:That specific error says that volume 272 difftar of the backupset is missing. Not a good error message by any means. You can check on S3 to see if somehow it did not get downloaded, but my guess is that it is indeed missing. Did you have any restarts during the backup? Did you verify the backup? ...Ken On Fri, Aug 11, 2023 at 1:17 AM Jakob Bohm via Duplicity-talk <duplicity-talk@nongnu.org <mailto:duplicity-talk@nongnu.org>> wrote: Dear all, I am testing the viability of my backups by restoring to a blank Linux computer loaded up with the decryption keys and the same patched duplicity 1.2.1 that I used for the backup (just a patch for the doubled --encrypt option and one for lowering the threshold for displaying actual progress numbers instead of "Stalled"). However when restoring a large partition, instead of restoring, it fails with the error messages below, the message doesn't say what the error is or what it was trying to do, just an error number and traceback of the stack with no specific context: Added incremental Backupset (start_time: Thu May 25 02:13:30 2023 / end_time: Thu Jun 22 11:50:21 2023) Added incremental Backupset (start_time: Thu Jun 22 11:50:21 2023 / end_time: Mon Jul 3 09:17:24 2023) Added incremental Backupset (start_time: Mon Jul 3 09:17:24 2023 / end_time: Mon Jul 17 18:50:05 2023) Added incremental Backupset (start_time: Mon Jul 17 18:50:05 2023 / end_time: Wed Jul 19 22:32:43 2023) Added incremental Backupset (start_time: Wed Jul 19 22:32:43 2023 / end_time: Mon Jul 24 03:50:01 2023) Added incremental Backupset (start_time: Mon Jul 24 03:50:01 2023 / end_time: Mon Aug 7 21:33:50 2023) Local and Remote metadata are synchronized, no sync needed. Last full backup date: Thu May 25 02:13:30 2023 Processing local manifest b'/bkup4/archive/wisemo-bk-real-more/wisemo-bk-real-more/wisemo-bk-real-more_duplicity-full.20230525T021330Z.manifest' (82148726) Found 11293 volumes in manifest Traceback (innermost last): File "/usr/local/bin/duplicity", line 86, in <module> with_tempdir(main) File "/usr/local/bin/duplicity", line 70, in with_tempdir fn() File "/usr/local/lib/python3.11/dist-packages/duplicity/dup_main.py", line 1575, in main do_backup(action) File "/usr/local/lib/python3.11/dist-packages/duplicity/dup_main.py", line 1658, in do_backup restore(col_stats) File "/usr/local/lib/python3.11/dist-packages/duplicity/dup_main.py", line 749, in restore restore_get_patched_rop_iter(col_stats)): ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/dist-packages/duplicity/dup_main.py", line 801, in restore_get_patched_rop_iter file_names.append(backup_set.volume_name_dict[vol_num]) ~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^ KeyError: 272Enjoy Jakob
| [Prev in Thread] | Current Thread | [Next in Thread] |