Initial backup to OneDrive: Failed to find the path for the chunk - Maximum number of retries reached

RF1 · 14 December 2017 03:53

I’m evaluating v2.0.9 of the CLI version and I’ve been having a lot of trouble doing the initial backup to OneDrive. It keeps on failing due to the following error.

Failed to find the path for the chunk xxxxxxxxxxxxxxx: Maximum number of retries reached

I’ve tried using different number of threads (10, 5, 2 and 1) in case its an API limit but it keeps on failing.

I’m only trying to backup about 100GB worth of data.

Here are some logs from the last few tries:

(previous attempts above)

duplicacy_win_i386_2.0.9.exe backup -stats -threads 5
Storage set to one://foobar
No previous backup found
Indexing <path-to-backup>
Incomplete snapshot loaded from <path-to-backup>/.duplicacy/incomplete
Listing all chunks
Skipped 112 files from previous incomplete backup
...
Skipped chunk 2950 size 4924345, 10.59MB/s 02:52:01 6.7%
Skipped chunk 2951 size 1804920, 10.59MB/s 02:51:58 6.7%
Skipped chunk 2952 size 1108911, 10.59MB/s 02:51:57 6.7%
Failed to find the path for the chunk 9c2eeff7ff14eacec684fedc80047ac4f679a53277c135771226256d2e248add: Maximum number of retries reached
Incomplete snapshot saved to <path-to-backup>/.duplicacy/incomplete


duplicacy_win_i386_2.0.9.exe backup -stats -threads 5
...
Skipped chunk 9961 size 6582507, 10.32MB/s 02:10:44 30.9%
Failed to find the path for the chunk 44ba286b0eb1500ca59056c687437bdd3ef8ed642bfa166534c9aa1eb45f8e53: Maximum number of retries reached
Incomplete snapshot saved to <path-to-backup>/.duplicacy/incomplete


duplicacy_win_i386_2.0.9.exe backup -stats -threads 2
...
Skipped chunk 10124 size 1630727, 10.56MB/s 02:06:27 31.6%
Failed to find the path for the chunk 124bc126fe5e0af404fc5436203a119023c8f84bd71558fc5eb345b92db252d0: Maximum number o
f retries reached
Incomplete snapshot saved to <path-to-backup>/.duplicacy/incomplete

duplicacy_win_i386_2.0.9.exe backup -stats -threads 1
Storage set to one://foobar
No previous backup found
Indexing <path-to-backup>
Incomplete snapshot loaded from <path-to-backup>/.duplicacy/incomplete
Listing all chunks
Skipped 0 files from previous incomplete backup
Skipped chunk 1 size 9616800, 9.17MB/s 03:33:03 0.0%
Skipped chunk 2 size 1988760, 11.07MB/s 02:56:32 0.0%
Skipped chunk 3 size 2753776, 6.85MB/s 04:45:21 0.0%
Skipped chunk 4 size 13703758, 8.92MB/s 03:38:59 0.0%
Skipped chunk 5 size 6563636, 8.26MB/s 03:56:37 0.0%
Skipped chunk 6 size 4387581, 9.30MB/s 03:30:00 0.0%
Skipped chunk 7 size 16777216, 8.87MB/s 03:40:15 0.0%
Skipped chunk 8 size 4774157, 9.63MB/s 03:22:53 0.0%
...
Skipped chunk 9790 size 10634832, 10.13MB/s 02:14:29 30.3%
Skipped chunk 9791 size 6841295, 10.13MB/s 02:14:29 30.3%
Skipped chunk 9792 size 4037281, 10.13MB/s 02:14:27 30.3%
Skipped chunk 9795 size 8169823, 10.12MB/s 02:14:30 30.3%
Failed to find the path for the chunk e0817b53f86d96dab9bd89ca974415514f3b4c8018321ca7424e16bbddaab064: Maximum number of retries reached
Incomplete snapshot saved to <path-to-backup>/.duplicacy/incomplete

duplicacy_win_i386_2.0.9.exe backup -stats -threads 1
Storage set to one://foobar
No previous backup found
Indexing <path-to-backup>
Incomplete snapshot loaded from <path-to-backup>/.duplicacy/incomplete
Listing all chunks
Skipped 0 files from previous incomplete backup
...........
Skipped chunk 10107 size 2483644, 10.54MB/s 02:06:52 31.5%
Skipped chunk 10109 size 3869664, 10.53MB/s 02:06:55 31.5%
Skipped chunk 10110 size 2478120, 10.53MB/s 02:06:55 31.6%
Skipped chunk 10111 size 6858109, 10.53MB/s 02:06:55 31.6%
Failed to find the path for the chunk 3dc308b0d009d891e0215d84d098343eb94d57d4619640020e9e9b6f5be8c9af: Maximum number of retries reached
Incomplete snapshot saved to <path-to-backup>/.duplicacy/incomplete

You can see in one instance it was able to keep track of what files were left to upload (Skipped 112 files from previous incomplete backup) but most of the time it doesn’t and tries to determine if everything needs to be uploaded. Note that I only have around 170 files to upload, with an approx average of 1.5 GB/file.

This leads to thousands of skipped chunk uploads. It’s now erroring out before it can even upload a new chunk.

Any ideas?

gchen · 14 December 2017 12:58

Can you turn on debug level logging by running:

duplicacy_win_i386_2.0.9.exe -d backup -stats -threads 1

This should tell why it needs to retry.

RF1 · 15 December 2017 01:11

Ok well I already started that as I discovered the option after my first post.

Strangely, it seems to have to have progressed a lot further now that its under observation.

Here’s the log of it failing:

Chunk 15e843a30a7e6845b662b1b1a09d990b4b6725f1f08f44dfcee687cf619152a7 has been uploaded
Uploaded chunk 27397 size 12173782, 2.02MB/s 00:35:45 96.2%
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/6f42085422c71d9749fd28bd70f871a310ca83a06cdda6a8145acefbcaeed4be?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/6f42085422c71d9749fd28bd70f871a310ca83a06cdda6a8145acefbcaeed4be?select=id,name,size,folder
Chunk 4b5692f808e4f8e6d5f24b065780b67cfb0a3e62bc1d08dc484fd244bb3eb68a has been uploaded
Uploaded chunk 27402 size 7130322, 2.03MB/s 00:35:41 96.3%
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/25660dd72a76d8c270b23d6e22ff8633349137ec9474a706ffd3a9c9309cb9c2?select=id,name,size,folder
PUT https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/6e6a9873c8619cc7a219b2db168930ece18131f8ad30cb75535254a8cfd4f53b:/content
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/6f42085422c71d9749fd28bd70f871a310ca83a06cdda6a8145acefbcaeed4be?select=id,name,size,folder
PUT https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/3ae311b03a54c6dbf35345c33ad7f6d39d5c6c07e1ec597e9c84ed05458efd8d:/content
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/25660dd72a76d8c270b23d6e22ff8633349137ec9474a706ffd3a9c9309cb9c2?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/6f42085422c71d9749fd28bd70f871a310ca83a06cdda6a8145acefbcaeed4be?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/25660dd72a76d8c270b23d6e22ff8633349137ec9474a706ffd3a9c9309cb9c2?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/6f42085422c71d9749fd28bd70f871a310ca83a06cdda6a8145acefbcaeed4be?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/25660dd72a76d8c270b23d6e22ff8633349137ec9474a706ffd3a9c9309cb9c2?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/6f42085422c71d9749fd28bd70f871a310ca83a06cdda6a8145acefbcaeed4be?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/25660dd72a76d8c270b23d6e22ff8633349137ec9474a706ffd3a9c9309cb9c2?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/6f42085422c71d9749fd28bd70f871a310ca83a06cdda6a8145acefbcaeed4be?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/6f42085422c71d9749fd28bd70f871a310ca83a06cdda6a8145acefbcaeed4be?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/25660dd72a76d8c270b23d6e22ff8633349137ec9474a706ffd3a9c9309cb9c2?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/25660dd72a76d8c270b23d6e22ff8633349137ec9474a706ffd3a9c9309cb9c2?select=id,name,size,folder
Failed to find the path for the chunk 6f42085422c71d9749fd28bd70f871a310ca83a06cdda6a8145acefbcaeed4be: Maximum number of retries reached
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks/25660dd72a76d8c270b23d6e22ff8633349137ec9474a706ffd3a9c9309cb9c2?select=id,name,size,folder
Incomplete snapshot saved to <path-to-backup>/.duplicacy/incomplete

RF1 · 15 December 2017 01:38

Another one from the start, showing it not resuming:

duplicacy_win_i386_2.0.9.exe -d backup -stats -threads 4
Storage set to one://foobar
Reading the environment variable DUPLICACY_ONE_TOKEN
GET https://api.onedrive.com/v1.0/drive/root:/foobar?select=id,name,size,folder
POST https://duplicacy.com/one_refresh
GET https://api.onedrive.com/v1.0/drive/root:/foobar?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/fossils?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/root:/foobar/snapshots?select=id,name,size,folder
Reading the environment variable DUPLICACY_ONE_TOKEN
GET https://api.onedrive.com/v1.0/drive/root:/foobar/config?select=id,name,size,folder
GET https://api.onedrive.com/v1.0/drive/items/root:/foobar/config:/content
Compression level: 100
Average chunk size: 4194304
Maximum chunk size: 16777216
Minimum chunk size: 1048576
Chunk seed: 6475706c6963616379
top: <path-to-backup>, quick: true, tag:
Downloading latest revision for snapshot foobar
Listing revisions for snapshot foobar
GET https://api.onedrive.com/v1.0/drive/root:/foobar/snapshots?select=id,name,size,folder
POST https://api.onedrive.com/v1.0/drive/items/A6FA7445227F34F5!12329/children
GET https://api.onedrive.com/v1.0/drive/root:/foobar/snapshots/foobar:/children?top=1000&select=name,
e,folder
No previous backup found
Indexing <path-to-backup>
Listing
Listing $RECYCLE.BIN/
Listing Shares/
Incomplete snapshot loaded from <path-to-backup>/.duplicacy/incomplete
Listing all chunks
Listing chunks/
GET https://api.onedrive.com/v1.0/drive/root:/foobar/chunks:/children?top=1000&select=name,size,folder
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MTAwMQ
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MjAwMQ
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MzAwMQ
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=NDAwMQ
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=NTAwMQ
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=NjAwMQ
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=NzAwMQ
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=ODAwMQ
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=OTAwMQ
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MTAwMDE
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MTEwMDE
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MTIwMDE
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MTMwMDE
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MTQwMDE
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MTUwMDE
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MTYwMDE
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MTcwMDE
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MTgwMDE
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MTkwMDE
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MjAwMDE
GET https://api.onedrive.com/v1.0/drives('me')/items('root%252Ffoobar%252Fchunks')/children?$top=1000&$select=name,size,folder&$skiptoken=MjEwMDE
GET https://api.onedrive.com/v1.0/drive/root:/foobar/fossils:/children?top=1000&select=name,size,folder
Skipped 0 files from previous incomplete backup

gchen · 15 December 2017 13:39

Can you try this latest build: https://acrosync.com/duplicacy/duplicacy_win_i386_2.0.10d.exe

I think what happened is that there was an authorization error returned by OneDrive, but Duplicacy didn’t refresh the token because according to the timestamp of the token it is still valid. This is the only possibility that can cause the maximum number of retries to be reached without showing any error response code. So the fix is to force a token refresh in case of an authorization error.

Fast resuming could fail if there are new files, and if it is not the case then I don’t know why, but I added a few debugging logs in this latest build that could be helpful.

RF1 · 16 December 2017 06:54

Fast resuming could fail if there are new files, and if it is not the case then I don’t know why,

No files had been added. This was just an initial backup for testing purposes.

Using that build, the backup finally completed. However, i then ran “duplicacy check -stats” and got thousands of chunk missing errors:

Chunk xyz referenced by snapshot foobar at revision 1 does not exist

gchen · 16 December 2017 14:47

If you have more than 20k chunks under the chunks directory, you are likely affected by this bug: https://github.com/OneDrive/onedrive-api-docs/issues/740

The workaround is to start a new backup by initializing the storage with the 2.0.10 version. With 2.0.10 the chunks directory will have a nesting level of 1, thus significantly reducing the number of chunks in each subdirectory.

maccra · 20 December 2017 09:40

@gchen

I read this thread and it makes me concerned that my backup to OneDrive is not integral. I have +43k chunks so based on what you say I may be effected by the 20k bug.

As a solution, are you saying I will need to start a new backup and re-upload all chunks or will the existing chunks be recognised and moved to a new location to reduce the quantity of chunks in each subdirectory. I have a at least 3 repositories with +20k chunks in OneDrive and sounds like it could be a serious issue for me that the backups are not integral.

I am not planing to do anything until you release the new version but it is not clear to me what you mean when you say “start a new backup by initializing with the 2.0.10 versions”. That sounds like I have to delete my current backup settings, storage config file and .duplicacy folder and start again. I hope that is not the case.lease advise.

Cheers and thanks

gchen · 21 December 2017 02:08

Can you run duplicacy check to confirm that you’re affected by this bug?

Yes, you’ll need to upload all chunks again in order to switch to the new chunk directory structure. However, I’m thinking about making a change: if a chunk is not found in the list returned by the list call, it should issue a lookup to see if the chunk is actually there. With this change, if the list call doesn’t return all chunks, for each missing chunk we will check one by one unless they are actually missing. This is not the ideal solution, but at least this would make it work without requiring you to start over again.

maccra · 21 December 2017 13:29

here is my result from running the check command. I ran it several times and always the same.

PS D:> duplicacy check
Storage set to one://BDup
Listing all chunks
Failed to download the chunk a83fd4a13ddf01bd73583199d1ea59ee51104bbcf1755ee43acbb982df814a26: 404 Item does not exist

gchen · 22 December 2017 03:03

Does the chunk file a83fd4… exist in OneDrive? If it does, then this is likely another OneDrive bug.

If it doesn’t, then check the prune logs under .duplicacy/logs to find out when it was removed.

maccra · 22 December 2017 09:30

Hi… The file a83fd4… does exist. I could download it directly from the OneDrive website.

gchen · 22 December 2017 15:13

Can you run again with debug-level logging enabled?

duplicacy -d -log check

maccra · 23 December 2017 14:46

Attached are some log printouts from duplicacy -d -log check command

2017-12-23 14:41:00.601 DEBUG ONEDRIVE_CALL GET https://api.onedrive.com/v1.0/drives('me')/items('root%252FBDup%252Ffossils')/children?$top=1000&$select=name,size,folder&$skiptoken=MzAwMQ
2017-12-23 14:41:02.128 DEBUG ONEDRIVE_CALL GET https://api.onedrive.com/v1.0/drives('me')/items('root%252FBDup%252Ffossils')/children?$top=1000&$select=name,size,folder&$skiptoken=NDAwMQ
2017-12-23 14:41:03.648 DEBUG ONEDRIVE_CALL GET https://api.onedrive.com/v1.0/drives('me')/items('root%252FBDup%252Ffossils')/children?$top=1000&$select=name,size,folder&$skiptoken=NTAwMQ
2017-12-23 14:41:04.595 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot RF409-DDrive
2017-12-23 14:41:04.595 DEBUG ONEDRIVE_CALL GET https://api.onedrive.com/v1.0/drive/root:/BDup/snapshots?select=id,name,size,folder
2017-12-23 14:41:04.933 DEBUG ONEDRIVE_CALL POST https://api.onedrive.com/v1.0/drive/items/EA89B52BCAFF6B30!131/children
2017-12-23 14:41:05.267 DEBUG ONEDRIVE_CALL GET https://api.onedrive.com/v1.0/drive/root:/BDup/snapshots/RF409-DDrive:/children?top=1000&select=name,size,folder
2017-12-23 14:41:06.061 DEBUG ONEDRIVE_CALL GET https://api.onedrive.com/v1.0/drive/root:/BDup/snapshots?select=id,name,size,folder
2017-12-23 14:41:06.395 DEBUG ONEDRIVE_CALL POST https://api.onedrive.com/v1.0/drive/items/EA89B52BCAFF6B30!131/children
2017-12-23 14:41:06.724 DEBUG ONEDRIVE_CALL GET https://api.onedrive.com/v1.0/drive/root:/BDup/snapshots/RF409-DDrive/1?select=id,name,size,folder
2017-12-23 14:41:07.053 DEBUG ONEDRIVE_CALL GET https://api.onedrive.com/v1.0/drive/items/root:/BDup/snapshots/RF409-DDrive/1:/content
2017-12-23 14:41:08.334 DEBUG DOWNLOAD_FILE Downloaded file snapshots/RF409-DDrive/1
2017-12-23 14:41:08.336 DEBUG FS_FIND File D:\/.duplicacy/cache/default/chunks/a8/3f/d4a13ddf01bd73583199d1ea59ee51104bbcf1755ee43acbb982df814a26 can't be found: GetFileAttributesEx D:\/.duplicacy/cache/default/chunks/a8/3f/d4a13ddf01bd73583199d1ea59ee51104bbcf1755ee43acbb982df814a26: The system cannot find the file specified.
2017-12-23 14:41:08.337 DEBUG ONEDRIVE_CALL GET https://api.onedrive.com/v1.0/drive/root:/BDup/chunks/a83fd4a13ddf01bd73583199d1ea59ee51104bbcf1755ee43acbb982df814a26?select=id,name,size,folder
2017-12-23 14:41:08.653 DEBUG ONEDRIVE_CALL GET https://api.onedrive.com/v1.0/drive/root:/BDup/fossils/a83fd4a13ddf01bd73583199d1ea59ee51104bbcf1755ee43acbb982df814a26?select=id,name,size,folder
2017-12-23 14:41:08.981 DEBUG CHUNK_FOSSIL Chunk a83fd4a13ddf01bd73583199d1ea59ee51104bbcf1755ee43acbb982df814a26 has been marked as a fossil
2017-12-23 14:41:08.982 DEBUG ONEDRIVE_CALL GET https://api.onedrive.com/v1.0/drive/items/root:/BDup/chunks/a83fd4a13ddf01bd73583199d1ea59ee51104bbcf1755ee43acbb982df814a26.fsl:/content
2017-12-23 14:41:09.331 ERROR UPLOAD_FATAL Failed to download the chunk a83fd4a13ddf01bd73583199d1ea59ee51104bbcf1755ee43acbb982df814a26: 404 Item does not exist
PS D:\>

Christoph · 19 July 2018 11:33

This issue has been resolved, I suppose?

RF1 · 21 July 2018 08:25

Yes, it appears so. 20chars.