Copy Job from Google Drive to Local works , from Google Drive to NAS doesn't

Support
#1

Hi,

i have the following scenario: I create multiple backups to Google Drive, then prune and then check the backup. Now I want to copy the backup from Google Drive to my NAS (TrueNAS).

While the copy job from Google Drive to Local Disk works flawlessly, the copy from Google Drive to my NAS fails with this error:

Running copy command from C:\Users\Chef/.duplicacy-web/repositories/localhost/all
Options: [-log copy -from Google_Drive -to TrueNAS]
2023-05-22 21:21:57.233 INFO STORAGE_SET Source storage set to gcd://Duplicacy
2023-05-22 21:22:00.907 INFO STORAGE_SET Destination storage set to sftp://backup-user@truenas:22/mnt/main/backup/duplicacy
2023-05-22 21:22:15.636 INFO SNAPSHOT_COPY Chunks to copy: 9213, to skip: 0, total: 9213
2023-05-22 21:22:18.153 ERROR UPLOAD_CHUNK Failed to upload the chunk 55628f715c0d8e29c75c37fd61b944b3fecf69e69dc78d15edf38d899230cba9: file does not exist
Failed to upload the chunk 55628f715c0d8e29c75c37fd61b944b3fecf69e69dc78d15edf38d899230cba9: file does not exist

When I search on my Google Drive or Local Storage neither the chunk 628f715c0d8e29c75c37fd61b944b3fecf69e69dc78d15edf38d899230cba9 nor the folder 55 exists.

I tried to delete all cache folders from my repositories but this did not help.
I also tried to create a copy job from Local Drive to NAS but the same error occurs.

How can I further troubleshoot this problem and get my copy job from Google Drive to NAS running? Any help would be greatly appreciated.

#2

Maybe you had prune in progress that delete those files while you were copying? Or are you saying that every time you try to copy it stumbles on this specific magic chunk?

Does check command succeeds on the source storage?

1 Like
#3

Hi,

thank you for your reply :slight_smile:

Maybe you had prune in progress that delete those files while you were copying?

This shouldn’t have happened as I only have one prune in the schedule and it is not running in Parallel

Or are you saying that every time you try to copy it stumbles on this specific magic chunk?

Actually every time I run the copy job it stumbles on another chunk that is not existing

Does check command succeeds on the source storage?

Yes

#4

To confirm, when you run check, if you have more than one target, are you passing -all, or the id of the storage you want to check explicitly (e.g. -id Google_Drive)?

So, if check succeeds, that means all chunks referenced by all revisions in the specified snapshot exit; and it makes no sense for chunks to suddenly disappear from the storage between your check and copy jobs. I’m not aware of any other failure modes here…

You can add -d argument to any command to get obscenely more verbose logging.

Of course there is always a possibility of some google drive outage, but let’s exhaust all other possibilities first.

1 Like
#5

I used -files for the check of the Google Drive storage, will try with -all and -d now.

#6

If you don’t specificy the storage, then it will use the “default” storage, which may not be what you want to check. (I think it takes the storage called “default” or the first one in the preferences file).

No need to check -files, simple check is enough.

1 Like
#7

I think the check was successful then:

Check log 
Running check command from C:\Users\Chef/.duplicacy-web/repositories/localhost/all
Options: [-log check -storage Google_Drive -a -tabular]
2023-05-24 19:25:31.485 INFO STORAGE_SET Storage set to gcd://Duplicacy
2023-05-24 19:25:36.906 INFO SNAPSHOT_CHECK Listing all chunks
2023-05-24 19:29:17.084 INFO SNAPSHOT_CHECK 4 snapshots and 24 revisions
2023-05-24 19:29:17.085 INFO SNAPSHOT_CHECK Total chunk size is 33,146M in 9683 chunks
2023-05-24 19:29:17.085 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Config_BF4 at revision 1 exist
2023-05-24 19:29:17.085 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Config_BF4 at revision 5 exist
2023-05-24 19:29:17.086 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Config_BF4 at revision 6 exist
2023-05-24 19:29:17.086 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Config_BF4 at revision 7 exist
2023-05-24 19:29:17.086 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Config_BF4 at revision 8 exist
2023-05-24 19:29:17.086 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Config_BF4 at revision 9 exist
2023-05-24 19:29:17.086 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Config_LOL at revision 1 exist
2023-05-24 19:29:17.086 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Config_LOL at revision 5 exist
2023-05-24 19:29:17.086 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Config_LOL at revision 6 exist
2023-05-24 19:29:17.086 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Config_LOL at revision 7 exist
2023-05-24 19:29:17.086 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Config_LOL at revision 8 exist
2023-05-24 19:29:17.086 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Config_LOL at revision 9 exist
2023-05-24 19:29:17.094 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Chef at revision 1 exist
2023-05-24 19:29:17.100 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Chef at revision 5 exist
2023-05-24 19:29:17.106 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Chef at revision 6 exist
2023-05-24 19:29:17.112 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Chef at revision 7 exist
2023-05-24 19:29:17.119 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Chef at revision 8 exist
2023-05-24 19:29:17.126 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Chef at revision 9 exist
2023-05-24 19:29:17.132 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Portable at revision 1 exist
2023-05-24 19:29:17.137 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Portable at revision 5 exist
2023-05-24 19:29:17.142 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Portable at revision 6 exist
2023-05-24 19:29:17.146 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Portable at revision 7 exist
2023-05-24 19:29:17.150 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Portable at revision 8 exist
2023-05-24 19:29:17.154 INFO SNAPSHOT_CHECK All chunks referenced by snapshot Portable at revision 9 exist
2023-05-24 19:29:17.280 INFO SNAPSHOT_CHECK 
       snap | rev |                          | files | bytes | chunks | bytes | uniq | bytes | new | bytes |
 Config_BF4 |   1 | @ 2023-05-17 12:02 -hash |     1 |   397 |      4 |    1K |    0 |     0 |   4 |    1K |
 Config_BF4 |   5 | @ 2023-05-18 11:21 -hash |     1 |   397 |      4 |    1K |    0 |     0 |   0 |     0 |
 Config_BF4 |   6 | @ 2023-05-19 19:00 -hash |     1 |   397 |      4 |    1K |    0 |     0 |   0 |     0 |
 Config_BF4 |   7 | @ 2023-05-20 19:00 -hash |     1 |   397 |      4 |    1K |    0 |     0 |   0 |     0 |
 Config_BF4 |   8 | @ 2023-05-21 17:26 -hash |     1 |   397 |      4 |    1K |    0 |     0 |   0 |     0 |
 Config_BF4 |   9 | @ 2023-05-24 19:00 -hash |     1 |   397 |      4 |    1K |    0 |     0 |   0 |     0 |
 Config_BF4 | all |                          |       |       |      4 |    1K |    4 |    1K |     |       |

       snap | rev |                          | files | bytes | chunks | bytes | uniq | bytes | new | bytes |
 Config_LOL |   1 | @ 2023-05-17 12:02 -hash |    12 |  103K |      4 |   20K |    0 |     0 |   4 |   20K |
 Config_LOL |   5 | @ 2023-05-18 11:21 -hash |    12 |  103K |      4 |   20K |    0 |     0 |   0 |     0 |
 Config_LOL |   6 | @ 2023-05-19 19:00 -hash |    12 |  103K |      4 |   20K |    0 |     0 |   0 |     0 |
 Config_LOL |   7 | @ 2023-05-20 19:00 -hash |    12 |  103K |      4 |   20K |    0 |     0 |   0 |     0 |
 Config_LOL |   8 | @ 2023-05-21 17:26 -hash |    12 |  103K |      4 |   20K |    0 |     0 |   0 |     0 |
 Config_LOL |   9 | @ 2023-05-24 19:00 -hash |    12 |  103K |      4 |   20K |    0 |     0 |   0 |     0 |
 Config_LOL | all |                          |       |       |      4 |   20K |    4 |   20K |     |       |

  snap | rev |                          | files |   bytes | chunks |   bytes | uniq |    bytes |  new |    bytes |
  Chef |   1 | @ 2023-05-17 12:02 -hash | 68687 | 21,836M |   3851 | 14,039M |  554 |   2,267M | 3851 |  14,039M |
  Chef |   5 | @ 2023-05-18 11:22 -hash | 70421 | 22,075M |   3903 | 14,307M |  167 | 682,826K |  623 |   2,565M |
  Chef |   6 | @ 2023-05-19 19:00 -hash | 70400 | 21,914M |   3871 | 14,133M |  136 | 471,376K |  161 | 598,271K |
  Chef |   7 | @ 2023-05-20 19:00 -hash | 70012 | 22,791M |   3949 | 14,137M |  314 | 854,670K |  460 |   1,417M |
  Chef |   8 | @ 2023-05-21 17:26 -hash | 70063 | 19,783M |   3618 | 13,828M |  239 | 964,094K |  515 |   1,404M |
  Chef |   9 | @ 2023-05-24 19:00 -hash | 70486 | 20,398M |   3650 | 13,920M |  555 |   2,073M |  555 |   2,073M |
  Chef | all |                          |       |         |   6165 | 22,084M | 6148 |  22,043M |      |          |

     snap | rev |                          |  files |   bytes | chunks |   bytes | uniq |    bytes |  new |    bytes |
 Portable |   1 | @ 2023-05-17 12:02 -hash | 123258 | 11,258M |   2279 |  6,700M |  237 | 681,538K | 2279 |   6,700M |
 Portable |   5 | @ 2023-05-18 11:22 -hash | 123694 | 13,082M |   2642 |  8,529M |   61 | 177,468K |  600 |   2,494M |
 Portable |   6 | @ 2023-05-19 19:00 -hash | 123692 | 13,078M |   2641 |  8,528M |   60 | 176,076K |   60 | 176,076K |
 Portable |   7 | @ 2023-05-20 19:00 -hash | 123754 | 13,087M |   2638 |  8,533M |  103 | 343,735K |  116 | 382,776K |
 Portable |   8 | @ 2023-05-21 17:26 -hash | 123627 | 13,077M |   2646 |  8,522M |  109 | 334,562K |  116 | 353,788K |
 Portable |   9 | @ 2023-05-24 19:00 -hash | 124033 | 13,514M |   2692 |  8,640M |  226 | 655,618K |  226 | 655,618K |
 Portable | all |                          |        |         |   3397 | 10,726M | 3380 |  10,686M |      |          |
#8

Indeed, check thinks all chunks exist.

Can you run the copy job now with the -d flag (verbose logging), and post few lines that are preceding the failure?

It would be interesting to understand where does the nonexistent chunk name come from.

1 Like
#9

Here are the Logs:

Copy Local -> TrueNAS 
Running copy command from C:\Users\Chef/.duplicacy-web/repositories/localhost/all
Options: [-log -d copy -from Local_Storage -to TrueNAS]
2023-05-24 20:08:34.368 INFO STORAGE_SET Source storage set to C:/BACKUP/Duplicacy
2023-05-24 20:08:34.391 DEBUG PASSWORD_ENV_VAR Reading the environment variable DUPLICACY_LOCAL_STORAGE_PASSWORD
2023-05-24 20:08:34.391 TRACE CONFIG_ITERATIONS Using 16384 iterations for key derivation
2023-05-24 20:08:34.397 DEBUG STORAGE_NESTING Chunk read levels: [1], write level: 1
2023-05-24 20:08:34.398 INFO CONFIG_INFO Compression level: 100
2023-05-24 20:08:34.398 INFO CONFIG_INFO Average chunk size: 4194304
2023-05-24 20:08:34.398 INFO CONFIG_INFO Maximum chunk size: 16777216
2023-05-24 20:08:34.398 INFO CONFIG_INFO Minimum chunk size: 1048576
2023-05-24 20:08:34.398 INFO CONFIG_INFO Chunk seed: 285c63f4914547b41adca211a87d016e1509a18540ff9aa8b77957575582fb65
2023-05-24 20:08:34.398 TRACE CONFIG_INFO Hash key: 03ffe805d63efe3e3fc0fcc09b2f4710f542012b4a1813ab2139568afeef5ec8
2023-05-24 20:08:34.398 TRACE CONFIG_INFO ID key: 6ba1153c0f663833547c3aa4142280622dd187ff67153c640f29fef64cd4de27
2023-05-24 20:08:34.398 TRACE CONFIG_INFO File chunks are encrypted
2023-05-24 20:08:34.398 TRACE CONFIG_INFO Metadata chunks are encrypted
2023-05-24 20:08:34.398 INFO STORAGE_SET Destination storage set to sftp://backup-user@truenas:22/mnt/main/backup/duplicacy
2023-05-24 20:08:34.398 DEBUG PASSWORD_ENV_VAR Reading the environment variable DUPLICACY_TRUENAS_SSH_KEY_FILE
2023-05-24 20:08:34.445 DEBUG SSH_PASSWORD Attempting password login
2023-05-24 20:08:34.445 DEBUG PASSWORD_ENV_VAR Reading the environment variable DUPLICACY_TRUENAS_SSH_PASSWORD
2023-05-24 20:08:34.548 DEBUG PASSWORD_ENV_VAR Reading the environment variable DUPLICACY_TRUENAS_PASSWORD
2023-05-24 20:08:34.583 TRACE CONFIG_ITERATIONS Using 16384 iterations for key derivation
2023-05-24 20:08:34.591 DEBUG STORAGE_NESTING Chunk read levels: [1], write level: 1
2023-05-24 20:08:34.592 INFO CONFIG_INFO Compression level: 100
2023-05-24 20:08:34.592 INFO CONFIG_INFO Average chunk size: 4194304
2023-05-24 20:08:34.592 INFO CONFIG_INFO Maximum chunk size: 16777216
2023-05-24 20:08:34.592 INFO CONFIG_INFO Minimum chunk size: 1048576
2023-05-24 20:08:34.592 INFO CONFIG_INFO Chunk seed: 285c63f4914547b41adca211a87d016e1509a18540ff9aa8b77957575582fb65
2023-05-24 20:08:34.592 TRACE CONFIG_INFO Hash key: 03ffe805d63efe3e3fc0fcc09b2f4710f542012b4a1813ab2139568afeef5ec8
2023-05-24 20:08:34.592 TRACE CONFIG_INFO ID key: 8b7592f379421b79a9bd59fd6978fa9e83ae60a40fffc107bb1d78131f3c922e
2023-05-24 20:08:34.592 TRACE CONFIG_INFO File chunks are encrypted
2023-05-24 20:08:34.592 TRACE CONFIG_INFO Metadata chunks are encrypted
2023-05-24 20:08:34.592 TRACE SNAPSHOT_LIST_IDS Listing all snapshot ids
2023-05-24 20:08:34.593 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot Chef
2023-05-24 20:08:35.115 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Chef/1
2023-05-24 20:08:35.120 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Chef/2
2023-05-24 20:08:35.126 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Chef/3
2023-05-24 20:08:35.131 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Chef/4
2023-05-24 20:08:35.136 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Chef/5
2023-05-24 20:08:35.141 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Chef/6
2023-05-24 20:08:35.147 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Chef/7
2023-05-24 20:08:35.152 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Chef/8
2023-05-24 20:08:35.154 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Chef/9
2023-05-24 20:08:35.154 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot Config_BF4
2023-05-24 20:08:35.161 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_BF4/1
2023-05-24 20:08:35.167 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_BF4/2
2023-05-24 20:08:35.172 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_BF4/3
2023-05-24 20:08:35.178 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_BF4/4
2023-05-24 20:08:35.184 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_BF4/5
2023-05-24 20:08:35.191 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_BF4/6
2023-05-24 20:08:35.199 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_BF4/7
2023-05-24 20:08:35.205 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_BF4/8
2023-05-24 20:08:35.208 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_BF4/9
2023-05-24 20:08:35.208 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot Config_LOL
2023-05-24 20:08:35.214 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_LOL/1
2023-05-24 20:08:35.219 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_LOL/2
2023-05-24 20:08:35.225 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_LOL/3
2023-05-24 20:08:35.231 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_LOL/4
2023-05-24 20:08:35.237 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_LOL/5
2023-05-24 20:08:35.244 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_LOL/6
2023-05-24 20:08:35.250 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_LOL/7
2023-05-24 20:08:35.256 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_LOL/8
2023-05-24 20:08:35.259 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Config_LOL/9
2023-05-24 20:08:35.259 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot Portable
2023-05-24 20:08:35.265 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Portable/1
2023-05-24 20:08:35.270 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Portable/2
2023-05-24 20:08:35.276 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Portable/3
2023-05-24 20:08:35.281 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Portable/4
2023-05-24 20:08:35.286 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Portable/5
2023-05-24 20:08:35.292 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Portable/6
2023-05-24 20:08:35.297 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Portable/7
2023-05-24 20:08:35.302 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Portable/8
2023-05-24 20:08:35.304 DEBUG DOWNLOAD_FILE Downloaded file snapshots/Portable/9
2023-05-24 20:08:35.304 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 1
2023-05-24 20:08:35.311 DEBUG CHUNK_CACHE Chunk ec992098e12c3c89ae397dd5da621dde8c038655bc72998d1b475e5fd3f6d7ac has been loaded from the snapshot cache
2023-05-24 20:08:35.314 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 2
2023-05-24 20:08:35.318 DEBUG CHUNK_CACHE Chunk e9e4d530ec207a62048304c2b62b3a27881a66244719a08c07b00c8ed022ca93 has been loaded from the snapshot cache
2023-05-24 20:08:35.322 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 3
2023-05-24 20:08:35.327 DEBUG CHUNK_CACHE Chunk 9b88f14ba80a69c948543eff9920d9fa54034edb936af49807a8700f1844f4aa has been loaded from the snapshot cache
2023-05-24 20:08:35.330 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 4
2023-05-24 20:08:35.334 DEBUG CHUNK_CACHE Chunk 75bc760fe227a88771b0a5dc4c033ddafc3042ba763431a2527a76a89842f804 has been loaded from the snapshot cache
2023-05-24 20:08:35.337 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 5
2023-05-24 20:08:35.341 DEBUG CHUNK_CACHE Chunk 70a899d5ccc9ef783e6c12622cfebfdc4076dcc7f2f1b07aa27ff9691fc63273 has been loaded from the snapshot cache
2023-05-24 20:08:35.344 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 6
2023-05-24 20:08:35.349 DEBUG CHUNK_CACHE Chunk 4d28f43afe7212b408bed382e153a1501193818980fa05e3fc931212ff3f0852 has been loaded from the snapshot cache
2023-05-24 20:08:35.352 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 7
2023-05-24 20:08:35.357 DEBUG CHUNK_CACHE Chunk 217dc15cd8fb49e000edc232b9eee2849963225a0f0a21e32f3969c09ee2d4c6 has been loaded from the snapshot cache
2023-05-24 20:08:35.360 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 8
2023-05-24 20:08:35.364 DEBUG CHUNK_CACHE Chunk d3808bf9f34b9f6eae85a03a9e36f2c379397b3d08bbd07fdc6a4dbc74b8d447 has been loaded from the snapshot cache
2023-05-24 20:08:35.367 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 9
2023-05-24 20:08:35.371 DEBUG CHUNK_DOWNLOAD Chunk 4cc29c0d4e79117a2744c3535e4494bd28bd541be1d78f91feabcb4924fb502e has been downloaded
2023-05-24 20:08:35.374 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 1
2023-05-24 20:08:35.375 DEBUG CHUNK_CACHE Chunk e5a922efd594c7d417f6db034af14e24d93fc365703afda46c58b495d9659a87 has been loaded from the snapshot cache
2023-05-24 20:08:35.375 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 2
2023-05-24 20:08:35.375 DEBUG CHUNK_CACHE Chunk e5a922efd594c7d417f6db034af14e24d93fc365703afda46c58b495d9659a87 has been loaded from the snapshot cache
2023-05-24 20:08:35.375 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 3
2023-05-24 20:08:35.375 DEBUG CHUNK_CACHE Chunk e5a922efd594c7d417f6db034af14e24d93fc365703afda46c58b495d9659a87 has been loaded from the snapshot cache
2023-05-24 20:08:35.375 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 4
2023-05-24 20:08:35.375 DEBUG CHUNK_CACHE Chunk e5a922efd594c7d417f6db034af14e24d93fc365703afda46c58b495d9659a87 has been loaded from the snapshot cache
2023-05-24 20:08:35.375 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 5
2023-05-24 20:08:35.375 DEBUG CHUNK_CACHE Chunk e5a922efd594c7d417f6db034af14e24d93fc365703afda46c58b495d9659a87 has been loaded from the snapshot cache
2023-05-24 20:08:35.375 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 6
2023-05-24 20:08:35.375 DEBUG CHUNK_CACHE Chunk e5a922efd594c7d417f6db034af14e24d93fc365703afda46c58b495d9659a87 has been loaded from the snapshot cache
2023-05-24 20:08:35.375 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 7
2023-05-24 20:08:35.375 DEBUG CHUNK_CACHE Chunk e5a922efd594c7d417f6db034af14e24d93fc365703afda46c58b495d9659a87 has been loaded from the snapshot cache
2023-05-24 20:08:35.375 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 8
2023-05-24 20:08:35.375 DEBUG CHUNK_CACHE Chunk e5a922efd594c7d417f6db034af14e24d93fc365703afda46c58b495d9659a87 has been loaded from the snapshot cache
2023-05-24 20:08:35.375 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 9
2023-05-24 20:08:35.375 DEBUG CHUNK_CACHE Chunk e5a922efd594c7d417f6db034af14e24d93fc365703afda46c58b495d9659a87 has been loaded from the snapshot cache
2023-05-24 20:08:35.375 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 1
2023-05-24 20:08:35.378 DEBUG CHUNK_CACHE Chunk c799a9958da4d908918f91deadec657e536da61cc6bdf11e0ab2ea7f5c3df3a8 has been loaded from the snapshot cache
2023-05-24 20:08:35.378 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 2
2023-05-24 20:08:35.378 DEBUG CHUNK_CACHE Chunk c799a9958da4d908918f91deadec657e536da61cc6bdf11e0ab2ea7f5c3df3a8 has been loaded from the snapshot cache
2023-05-24 20:08:35.378 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 3
2023-05-24 20:08:35.378 DEBUG CHUNK_CACHE Chunk c799a9958da4d908918f91deadec657e536da61cc6bdf11e0ab2ea7f5c3df3a8 has been loaded from the snapshot cache
2023-05-24 20:08:35.378 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 4
2023-05-24 20:08:35.378 DEBUG CHUNK_CACHE Chunk c799a9958da4d908918f91deadec657e536da61cc6bdf11e0ab2ea7f5c3df3a8 has been loaded from the snapshot cache
2023-05-24 20:08:35.378 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 5
2023-05-24 20:08:35.378 DEBUG CHUNK_CACHE Chunk c799a9958da4d908918f91deadec657e536da61cc6bdf11e0ab2ea7f5c3df3a8 has been loaded from the snapshot cache
2023-05-24 20:08:35.378 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 6
2023-05-24 20:08:35.378 DEBUG CHUNK_CACHE Chunk c799a9958da4d908918f91deadec657e536da61cc6bdf11e0ab2ea7f5c3df3a8 has been loaded from the snapshot cache
2023-05-24 20:08:35.378 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 7
2023-05-24 20:08:35.378 DEBUG CHUNK_CACHE Chunk c799a9958da4d908918f91deadec657e536da61cc6bdf11e0ab2ea7f5c3df3a8 has been loaded from the snapshot cache
2023-05-24 20:08:35.378 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 8
2023-05-24 20:08:35.379 DEBUG CHUNK_CACHE Chunk c799a9958da4d908918f91deadec657e536da61cc6bdf11e0ab2ea7f5c3df3a8 has been loaded from the snapshot cache
2023-05-24 20:08:35.379 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 9
2023-05-24 20:08:35.379 DEBUG CHUNK_CACHE Chunk c799a9958da4d908918f91deadec657e536da61cc6bdf11e0ab2ea7f5c3df3a8 has been loaded from the snapshot cache
2023-05-24 20:08:35.379 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 1
2023-05-24 20:08:35.383 DEBUG CHUNK_CACHE Chunk d8be3e8482e4639e48259101404a4f34129149062df7b3e5c61d01c660405d67 has been loaded from the snapshot cache
2023-05-24 20:08:35.385 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 2
2023-05-24 20:08:35.389 DEBUG CHUNK_CACHE Chunk 180895fbb8145ff4cf08e4cdcb57d2d82664370102d8633e635a6001d1b4e034 has been loaded from the snapshot cache
2023-05-24 20:08:35.390 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 3
2023-05-24 20:08:35.395 DEBUG CHUNK_CACHE Chunk d8c50fa72341b6607b68a00bdf0cad4560c4594654318859ff6f2d8820cef1d0 has been loaded from the snapshot cache
2023-05-24 20:08:35.396 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 4
2023-05-24 20:08:35.400 DEBUG CHUNK_CACHE Chunk b479f9fd4c85e4600686c3b5d6e0b29c16f5ea9f8897abf1b9e3bc922a2bb086 has been loaded from the snapshot cache
2023-05-24 20:08:35.402 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 5
2023-05-24 20:08:35.406 DEBUG CHUNK_CACHE Chunk fbeb5e9fec356f88d31ef4a161bd2269071855255dffd3781110fafbdf6d1d23 has been loaded from the snapshot cache
2023-05-24 20:08:35.407 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 6
2023-05-24 20:08:35.411 DEBUG CHUNK_CACHE Chunk f8ce970e1022e719f3360f4e7a1a7477870a9fc3d009a217261740f29921b95f has been loaded from the snapshot cache
2023-05-24 20:08:35.413 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 7
2023-05-24 20:08:35.418 DEBUG CHUNK_CACHE Chunk 524b41da3a997c46214a0cb8f5e6d8b4974ff16bb719b31db4589533a6ce2387 has been loaded from the snapshot cache
2023-05-24 20:08:35.419 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 8
2023-05-24 20:08:35.424 DEBUG CHUNK_CACHE Chunk 70da5f42c0ce170d3d37f72a10426744f52f8c3dc5d19064aa7d211d0f876a49 has been loaded from the snapshot cache
2023-05-24 20:08:35.425 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 9
2023-05-24 20:08:35.428 DEBUG CHUNK_DOWNLOAD Chunk 04d353c3c7dfece3cfe031e4d976309e276f2414f9e83271df0a05e33047d15c has been downloaded
2023-05-24 20:08:35.430 TRACE LIST_FILES Listing chunks/
2023-05-24 20:08:35.460 DEBUG SNAPSHOT_COPY Found 0 chunks on destination storage
2023-05-24 20:08:35.467 INFO SNAPSHOT_COPY Chunks to copy: 9991, to skip: 0, total: 9991
2023-05-24 20:08:35.467 DEBUG SNAPSHOT_COPY Copying chunk babb1953d4050cb1d64411bdce3a2d5c249857607892519f3e904d539cf04742 to 14ba4886c498fef394f490698b33500c016a615300232683f7a3bf0bb81bfd0a
2023-05-24 20:08:35.467 DEBUG SNAPSHOT_COPY Copying chunk 4aeb1d91778b3879f9cd697bc981113d0121b5e2b8c1c15b9b3e5c54aaca599b to 830b09c6c31fb32221791eefc94dbf31d604d359bb51921b150cefdc458d610d
2023-05-24 20:08:35.476 DEBUG CHUNK_DOWNLOAD Chunk babb1953d4050cb1d64411bdce3a2d5c249857607892519f3e904d539cf04742 has been downloaded
2023-05-24 20:08:35.478 DEBUG SNAPSHOT_COPY Copying chunk cac2430072761f3ed9cee8da51e2d5a3f80eaddcc66fc614f9bdef2a7897bbdb to 3e8228a3ca954ca6152bb72982610d0c06d878566df13f858f73dfa80967417d
2023-05-24 20:08:35.483 DEBUG CHUNK_DOWNLOAD Chunk 4aeb1d91778b3879f9cd697bc981113d0121b5e2b8c1c15b9b3e5c54aaca599b has been downloaded
2023-05-24 20:08:35.485 DEBUG SNAPSHOT_COPY Copying chunk b88f3b7d95cfaf1096aaee01c82bb327b11b3cba09ac4291d482ce182ee25762 to 3cc4b1bc007ea2da31f5e105dbf33021c43772e9273d923e267c02cef031a20c
2023-05-24 20:08:35.486 ERROR UPLOAD_CHUNK Failed to upload the chunk 14ba4886c498fef394f490698b33500c016a615300232683f7a3bf0bb81bfd0a: file does not exist
Failed to upload the chunk 14ba4886c498fef394f490698b33500c016a615300232683f7a3bf0bb81bfd0a: file does not exist
Copy Google Drive -> TrueNAS 
Running copy command from C:\Users\Chef/.duplicacy-web/repositories/localhost/all
Options: [-log -d copy -from Google_Drive -to TrueNAS]
2023-05-24 20:08:35.537 INFO STORAGE_SET Source storage set to gcd://Duplicacy
2023-05-24 20:08:35.562 DEBUG PASSWORD_ENV_VAR Reading the environment variable DUPLICACY_GOOGLE_DRIVE_GCD_TOKEN
2023-05-24 20:08:37.371 DEBUG PASSWORD_ENV_VAR Reading the environment variable DUPLICACY_GOOGLE_DRIVE_PASSWORD
2023-05-24 20:08:38.656 TRACE CONFIG_ITERATIONS Using 16384 iterations for key derivation
2023-05-24 20:08:38.983 DEBUG STORAGE_NESTING Chunk read levels: [1], write level: 1
2023-05-24 20:08:38.984 INFO CONFIG_INFO Compression level: 100
2023-05-24 20:08:38.984 INFO CONFIG_INFO Average chunk size: 4194304
2023-05-24 20:08:38.984 INFO CONFIG_INFO Maximum chunk size: 16777216
2023-05-24 20:08:38.984 INFO CONFIG_INFO Minimum chunk size: 1048576
2023-05-24 20:08:38.984 INFO CONFIG_INFO Chunk seed: 285c63f4914547b41adca211a87d016e1509a18540ff9aa8b77957575582fb65
2023-05-24 20:08:38.984 TRACE CONFIG_INFO Hash key: 03ffe805d63efe3e3fc0fcc09b2f4710f542012b4a1813ab2139568afeef5ec8
2023-05-24 20:08:38.984 TRACE CONFIG_INFO ID key: 906b32d83dcb3ff0ceac5bc3f38d7106207d7757dd719b17ad24f6e7d4f4c5e9
2023-05-24 20:08:38.984 TRACE CONFIG_INFO File chunks are encrypted
2023-05-24 20:08:38.984 TRACE CONFIG_INFO Metadata chunks are encrypted
2023-05-24 20:08:38.984 INFO STORAGE_SET Destination storage set to sftp://backup-user@truenas:22/mnt/main/backup/duplicacy
2023-05-24 20:08:38.984 DEBUG PASSWORD_ENV_VAR Reading the environment variable DUPLICACY_TRUENAS_SSH_KEY_FILE
2023-05-24 20:08:39.012 DEBUG SSH_PASSWORD Attempting password login
2023-05-24 20:08:39.012 DEBUG PASSWORD_ENV_VAR Reading the environment variable DUPLICACY_TRUENAS_SSH_PASSWORD
2023-05-24 20:08:39.080 DEBUG PASSWORD_ENV_VAR Reading the environment variable DUPLICACY_TRUENAS_PASSWORD
2023-05-24 20:08:39.083 TRACE CONFIG_ITERATIONS Using 16384 iterations for key derivation
2023-05-24 20:08:39.090 DEBUG STORAGE_NESTING Chunk read levels: [1], write level: 1
2023-05-24 20:08:39.090 INFO CONFIG_INFO Compression level: 100
2023-05-24 20:08:39.090 INFO CONFIG_INFO Average chunk size: 4194304
2023-05-24 20:08:39.090 INFO CONFIG_INFO Maximum chunk size: 16777216
2023-05-24 20:08:39.090 INFO CONFIG_INFO Minimum chunk size: 1048576
2023-05-24 20:08:39.090 INFO CONFIG_INFO Chunk seed: 285c63f4914547b41adca211a87d016e1509a18540ff9aa8b77957575582fb65
2023-05-24 20:08:39.090 TRACE CONFIG_INFO Hash key: 03ffe805d63efe3e3fc0fcc09b2f4710f542012b4a1813ab2139568afeef5ec8
2023-05-24 20:08:39.090 TRACE CONFIG_INFO ID key: 8b7592f379421b79a9bd59fd6978fa9e83ae60a40fffc107bb1d78131f3c922e
2023-05-24 20:08:39.090 TRACE CONFIG_INFO File chunks are encrypted
2023-05-24 20:08:39.090 TRACE CONFIG_INFO Metadata chunks are encrypted
2023-05-24 20:08:39.090 TRACE SNAPSHOT_LIST_IDS Listing all snapshot ids
2023-05-24 20:08:39.477 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot Config_BF4
2023-05-24 20:08:40.267 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Config_BF4/1 from the snapshot cache
2023-05-24 20:08:40.614 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Config_BF4/5 from the snapshot cache
2023-05-24 20:08:40.993 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Config_BF4/6 from the snapshot cache
2023-05-24 20:08:41.359 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Config_BF4/7 from the snapshot cache
2023-05-24 20:08:41.719 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Config_BF4/8 from the snapshot cache
2023-05-24 20:08:42.062 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Config_BF4/9 from the snapshot cache
2023-05-24 20:08:42.062 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot Config_LOL
2023-05-24 20:08:42.860 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Config_LOL/1 from the snapshot cache
2023-05-24 20:08:43.251 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Config_LOL/5 from the snapshot cache
2023-05-24 20:08:43.603 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Config_LOL/6 from the snapshot cache
2023-05-24 20:08:44.007 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Config_LOL/7 from the snapshot cache
2023-05-24 20:08:44.351 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Config_LOL/8 from the snapshot cache
2023-05-24 20:08:44.741 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Config_LOL/9 from the snapshot cache
2023-05-24 20:08:44.741 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot Chef
2023-05-24 20:08:45.502 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Chef/1 from the snapshot cache
2023-05-24 20:08:45.849 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Chef/5 from the snapshot cache
2023-05-24 20:08:46.220 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Chef/6 from the snapshot cache
2023-05-24 20:08:46.795 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Chef/7 from the snapshot cache
2023-05-24 20:08:47.185 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Chef/8 from the snapshot cache
2023-05-24 20:08:47.527 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Chef/9 from the snapshot cache
2023-05-24 20:08:47.527 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot Portable
2023-05-24 20:08:48.318 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Portable/1 from the snapshot cache
2023-05-24 20:08:48.666 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Portable/5 from the snapshot cache
2023-05-24 20:08:49.015 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Portable/6 from the snapshot cache
2023-05-24 20:08:49.384 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Portable/7 from the snapshot cache
2023-05-24 20:08:49.749 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Portable/8 from the snapshot cache
2023-05-24 20:08:50.111 DEBUG DOWNLOAD_FILE_CACHE Loaded file snapshots/Portable/9 from the snapshot cache
2023-05-24 20:08:50.111 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 1
2023-05-24 20:08:50.112 DEBUG CHUNK_CACHE Chunk 7c7a3f8a52f85e37e3542b97b2bfbb784f4e42cb139045b64d38b3cba5ef40b1 has been loaded from the snapshot cache
2023-05-24 20:08:50.112 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 5
2023-05-24 20:08:50.112 DEBUG CHUNK_CACHE Chunk 7c7a3f8a52f85e37e3542b97b2bfbb784f4e42cb139045b64d38b3cba5ef40b1 has been loaded from the snapshot cache
2023-05-24 20:08:50.112 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 6
2023-05-24 20:08:50.112 DEBUG CHUNK_CACHE Chunk 7c7a3f8a52f85e37e3542b97b2bfbb784f4e42cb139045b64d38b3cba5ef40b1 has been loaded from the snapshot cache
2023-05-24 20:08:50.112 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 7
2023-05-24 20:08:50.112 DEBUG CHUNK_CACHE Chunk 7c7a3f8a52f85e37e3542b97b2bfbb784f4e42cb139045b64d38b3cba5ef40b1 has been loaded from the snapshot cache
2023-05-24 20:08:50.112 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 8
2023-05-24 20:08:50.112 DEBUG CHUNK_CACHE Chunk 7c7a3f8a52f85e37e3542b97b2bfbb784f4e42cb139045b64d38b3cba5ef40b1 has been loaded from the snapshot cache
2023-05-24 20:08:50.112 TRACE SNAPSHOT_COPY Copying snapshot Config_BF4 at revision 9
2023-05-24 20:08:50.112 DEBUG CHUNK_CACHE Chunk 7c7a3f8a52f85e37e3542b97b2bfbb784f4e42cb139045b64d38b3cba5ef40b1 has been loaded from the snapshot cache
2023-05-24 20:08:50.112 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 1
2023-05-24 20:08:50.112 DEBUG CHUNK_CACHE Chunk cacf6aa5016f5c877ffa6c2431cabb9c8ca100aa9431de6adc6adacdcf033ab9 has been loaded from the snapshot cache
2023-05-24 20:08:50.112 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 5
2023-05-24 20:08:50.112 DEBUG CHUNK_CACHE Chunk cacf6aa5016f5c877ffa6c2431cabb9c8ca100aa9431de6adc6adacdcf033ab9 has been loaded from the snapshot cache
2023-05-24 20:08:50.112 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 6
2023-05-24 20:08:50.112 DEBUG CHUNK_CACHE Chunk cacf6aa5016f5c877ffa6c2431cabb9c8ca100aa9431de6adc6adacdcf033ab9 has been loaded from the snapshot cache
2023-05-24 20:08:50.112 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 7
2023-05-24 20:08:50.113 DEBUG CHUNK_CACHE Chunk cacf6aa5016f5c877ffa6c2431cabb9c8ca100aa9431de6adc6adacdcf033ab9 has been loaded from the snapshot cache
2023-05-24 20:08:50.113 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 8
2023-05-24 20:08:50.113 DEBUG CHUNK_CACHE Chunk cacf6aa5016f5c877ffa6c2431cabb9c8ca100aa9431de6adc6adacdcf033ab9 has been loaded from the snapshot cache
2023-05-24 20:08:50.113 TRACE SNAPSHOT_COPY Copying snapshot Config_LOL at revision 9
2023-05-24 20:08:50.113 DEBUG CHUNK_CACHE Chunk cacf6aa5016f5c877ffa6c2431cabb9c8ca100aa9431de6adc6adacdcf033ab9 has been loaded from the snapshot cache
2023-05-24 20:08:50.113 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 1
2023-05-24 20:08:50.113 DEBUG CHUNK_CACHE Chunk 155a00ab47cc98eb149b428d695c2c8ae3599a45dfd2067504d6182602d1bef0 has been loaded from the snapshot cache
2023-05-24 20:08:50.116 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 5
2023-05-24 20:08:50.117 DEBUG CHUNK_CACHE Chunk d36e9091fb8e406a7374535bb273ad91ffc4123cc7c3c99ead4ea9c683e17f99 has been loaded from the snapshot cache
2023-05-24 20:08:50.120 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 6
2023-05-24 20:08:50.120 DEBUG CHUNK_CACHE Chunk 5f2320ce5f83ddb7170888771f433e25390d594c2136e2b2e31920e97a2946dc has been loaded from the snapshot cache
2023-05-24 20:08:50.123 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 7
2023-05-24 20:08:50.123 DEBUG CHUNK_CACHE Chunk 09a4a2c1f1a1773203b3d1b1bc528396338c67bf0fbf97f7e67bddf84abfd45f has been loaded from the snapshot cache
2023-05-24 20:08:50.126 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 8
2023-05-24 20:08:50.127 DEBUG CHUNK_CACHE Chunk cc38c4a4b02887e79fe98ee1a41c706463a349652a73fef39e798b9db4e630c1 has been loaded from the snapshot cache
2023-05-24 20:08:50.130 TRACE SNAPSHOT_COPY Copying snapshot Chef at revision 9
2023-05-24 20:08:50.130 DEBUG CHUNK_CACHE Chunk aaba33a2943e9d98fc468a77be5e42779d5df0a032b2101bd8bdbdb770548b23 has been loaded from the snapshot cache
2023-05-24 20:08:50.133 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 1
2023-05-24 20:08:50.133 DEBUG CHUNK_CACHE Chunk 87ec59d7fcd6bc2fdadaa52777a7fa67a1adac9509a5f9d80c3a494a6a299799 has been loaded from the snapshot cache
2023-05-24 20:08:50.135 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 5
2023-05-24 20:08:50.135 DEBUG CHUNK_CACHE Chunk e377b00f386b707a51d041daa441358a5732fee46927c338c2f33cbd19d33337 has been loaded from the snapshot cache
2023-05-24 20:08:50.137 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 6
2023-05-24 20:08:50.137 DEBUG CHUNK_CACHE Chunk 4a2516bb9cafd24dca0cbc271195b0298e859327c7c5a7ff867e606cc3e82d51 has been loaded from the snapshot cache
2023-05-24 20:08:50.139 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 7
2023-05-24 20:08:50.139 DEBUG CHUNK_CACHE Chunk d06ff5d08ee4f8e66fd7b8533bc9e5361431e20e55aaea1039cae2c7ecb9ccf3 has been loaded from the snapshot cache
2023-05-24 20:08:50.141 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 8
2023-05-24 20:08:50.141 DEBUG CHUNK_CACHE Chunk e7efcd55ded1a7dfcb18a97094de33bb5ed89c2f83947e81f0e2edcb5ee42590 has been loaded from the snapshot cache
2023-05-24 20:08:50.143 TRACE SNAPSHOT_COPY Copying snapshot Portable at revision 9
2023-05-24 20:08:50.144 DEBUG CHUNK_CACHE Chunk 023a16ed3762f4d2b1c25c96100e848ccb976c02270bafe78acaaee8bb74f36d has been loaded from the snapshot cache
2023-05-24 20:08:50.146 TRACE LIST_FILES Listing chunks/
2023-05-24 20:08:50.148 DEBUG SNAPSHOT_COPY Found 0 chunks on destination storage
2023-05-24 20:08:50.153 INFO SNAPSHOT_COPY Chunks to copy: 9553, to skip: 0, total: 9553
2023-05-24 20:08:50.153 DEBUG SNAPSHOT_COPY Copying chunk ccc53fb6bc9f786cf55abcae03b1be504b3ed6797137cdd6704fa27537dbe78f to 325d27cc9448842e536bef140708fcb664ad7c597b2e9e7496f9eb3b48b4d509
2023-05-24 20:08:50.153 DEBUG SNAPSHOT_COPY Copying chunk d33beff7868854c86d52a2e88f846055eddf42656bc537a92c42a58b57892f08 to 4ecda4a480f632e178c181be65bb9e22574b2ba1671739e61bf30397c176542f
2023-05-24 20:08:53.874 DEBUG CHUNK_DOWNLOAD Chunk ccc53fb6bc9f786cf55abcae03b1be504b3ed6797137cdd6704fa27537dbe78f has been downloaded
2023-05-24 20:08:53.889 DEBUG SNAPSHOT_COPY Copying chunk b17efb58ec047ae3523bc7cdaec1cc69f04539d1ddf99e1e58ce0fcdbd0f4491 to eb3e2e9b684148401aa0e44bc7b0fff8256a6336e57b8a9079c71aed04b64e6d
2023-05-24 20:08:53.939 ERROR UPLOAD_CHUNK Failed to upload the chunk 325d27cc9448842e536bef140708fcb664ad7c597b2e9e7496f9eb3b48b4d509: file does not exist
Failed to upload the chunk 325d27cc9448842e536bef140708fcb664ad7c597b2e9e7496f9eb3b48b4d509: file does not exist

I don’t really know what is relevant and what isn’t so sorry for dumping the whole log :roll_eyes:

#10

Plot thickens :slight_smile:

From first log, entries containing problematic chunk:

2023-05-24 20:08:35.467 DEBUG SNAPSHOT_COPY Copying chunk babb1953d4050cb1d64411bdce3a2d5c249857607892519f3e904d539cf04742 to 14ba4886c498fef394f490698b33500c016a615300232683f7a3bf0bb81bfd0a
2023-05-24 20:08:35.486 ERROR UPLOAD_CHUNK Failed to upload the chunk 14ba4886c498fef394f490698b33500c016a615300232683f7a3bf0bb81bfd0a: file does not exist
Failed to upload the chunk 14ba4886c498fef394f490698b33500c016a615300232683f7a3bf0bb81bfd0a: file does not exist

So the complaint is not about the source chunk, it’s about destination. Duplicacy copy operation does not copy chunk files as it - it unpacks them and re-packs them, and because chunk file name is derived from its content - the name is also different.

It appears it for some reason fails to upload the new chunk to the truenas, and perhaps provides a misleading error message.

To confirm, that this is a truenas related issue: Create a local storage in a local folder and do copy there. I expect it to succeed.

Then copy to some temporary truenas storage, but using some other than SFTP protocol. SMB, or NFS for example. If that also succeeds – then the problem with SFTP, we can debug this further on the truenas side by enabling verbose SSDH logging.

If that also fails - the issue may be with the storage system on your truenas – space, quoatas, etc?

BTW does the folder 14 on the truenas exist now? Wondering if this is related to failure to create folders before uploading chunk?

1 Like
#11

Create a local storage in a local folder and do copy there. I expect it to succeed.

Copy from Google Drive to Local Storage on same PC works :wink:

Then copy to some temporary truenas storage, but using some other than SFTP protocol. SMB, or NFS for example.

I’ve mounted the TrueNAS share “backup\duplicacy_temp” with the same User “backup-user” that is used by SFTP into Windows explorer Drive Z: because I don’t see SMB or NFS when I create a new storage in GUI.

Apparently this seems to work as I didn’t get an error instantly and the copy job is progressing now.

Copy Google_Drive -> TrueNAS via SMB 
...
2023-05-24 20:35:08.070 TRACE LIST_FILES Listing chunks/
2023-05-24 20:35:08.073 DEBUG SNAPSHOT_COPY Found 0 chunks on destination storage
2023-05-24 20:35:08.079 INFO SNAPSHOT_COPY Chunks to copy: 9553, to skip: 0, total: 9553
2023-05-24 20:35:08.079 DEBUG SNAPSHOT_COPY Copying chunk 1b0327ea50bd50c63660184315551c34e4eff40608f6284c89af63d994ea55c0 to 99cecf2acf340ffe27266fee43b4bb3c1d5a0913c3cad60286b354ec42b314e5
2023-05-24 20:35:08.079 DEBUG SNAPSHOT_COPY Copying chunk 621537958b920133b07c8f002cba87d1820bcd5dfb068b742a06c4aff372f92a to be31b426c483f7845f6d4e81d1ca4ba31d864ed61cbf4f2effc9f828538bf655
2023-05-24 20:35:10.816 DEBUG CHUNK_DOWNLOAD Chunk 1b0327ea50bd50c63660184315551c34e4eff40608f6284c89af63d994ea55c0 has been downloaded
2023-05-24 20:35:10.819 DEBUG SNAPSHOT_COPY Copying chunk 94e5493412db32044a4063a3dcdd0852f0291be91ef3bd736bb095b58ac12301 to 4848fc61003522a29e9a74f9ce714fbb9e1811a6d824fb20c4f73917bcc6c1a5
2023-05-24 20:35:10.971 DEBUG CHUNK_UPLOAD Chunk 99cecf2acf340ffe27266fee43b4bb3c1d5a0913c3cad60286b354ec42b314e5 has been uploaded
2023-05-24 20:35:10.971 INFO COPY_PROGRESS Copied chunk 99cecf2acf340ffe27266fee43b4bb3c1d5a0913c3cad60286b354ec42b314e5 (1/9553) 835KB/s 07:40:26 0.0%
2023-05-24 20:35:14.996 DEBUG CHUNK_DOWNLOAD Chunk 621537958b920133b07c8f002cba87d1820bcd5dfb068b742a06c4aff372f92a has been downloaded
2023-05-24 20:35:15.009 DEBUG SNAPSHOT_COPY Copying chunk 7b4d24b8e3795752b2546a14153e107b711c4153dc591ba68b78bcfc88f199fc to a3057d980aab9f2cf1ce355d0a02a4ea938202c10928cbd276040062064dee9d
2023-05-24 20:35:15.480 DEBUG CHUNK_UPLOAD Chunk be31b426c483f7845f6d4e81d1ca4ba31d864ed61cbf4f2effc9f828538bf655 has been uploaded
2023-05-24 20:35:15.480 INFO COPY_PROGRESS Copied chunk be31b426c483f7845f6d4e81d1ca4ba31d864ed61cbf4f2effc9f828538bf655 (2/9553) 1.61MB/s 09:49:06 0.0%
2023-05-24 20:35:17.936 DEBUG CHUNK_DOWNLOAD Chunk 94e5493412db32044a4063a3dcdd0852f0291be91ef3bd736bb095b58ac12301 has been downloaded
2023-05-24 20:35:17.942 DEBUG SNAPSHOT_COPY Copying chunk 9e53ebf781ff74a3f986022085042ee371a4227836d333a571eef98322cdbce5 to aa534f8dc5ab47dee3d1aaf8575c06a73b0d49994d5f548d6188ecf389e2a996
2023-05-24 20:35:18.629 DEBUG CHUNK_UPLOAD Chunk 4848fc61003522a29e9a74f9ce714fbb9e1811a6d824fb20c4f73917bcc6c1a5 has been uploaded
2023-05-24 20:35:18.629 INFO COPY_PROGRESS Copied chunk 4848fc61003522a29e9a74f9ce714fbb9e1811a6d824fb20c4f73917bcc6c1a5 (3/9553) 1.66MB/s 09:19:44 0.0%
2023-05-24 20:35:19.948 DEBUG CHUNK_DOWNLOAD Chunk 7b4d24b8e3795752b2546a14153e107b711c4153dc591ba68b78bcfc88f199fc has been downloaded

I’ll post an update after the job has been finished (takes over 8 hours)

BTW does the folder 14 on the truenas exist now? Wondering if this is related to failure to create folders before uploading chunk?

The chunk folder on TrueNAS is empty…

1 Like
#12

Ah, yes, I missed its windows, you are right, that’s what I meant – mount the network folder and backup to it.

So, it seems it will succeed then, and the issue is indeed with SFTP.

Aha! So it failed to upload a chunk because the folder it uploads to does not exit, in which case “file does not exist” is correct!

Which TrueNAS is it? FreeBSD (Core) or Linux(Scale)?

Paging @gchen: Perhaps something changed in the way sftp endpoint works? Does duplicacy explicitly create folders before upload or does it expect the sftp server to create all intermediate folders?

Since this happens with the very first chunk file, it’s not a fluke, something is broken.

1 Like
#13

Aha! So it failed to upload a chunk because the folder it uploads to does not exit, in which case “file does not exist” is correct!

The folder “chunks” exists on TrueNAS but is empty.

Which TrueNAS is it? FreeBSD (Core) or Linux(Scale)?

TrueNAS-13.0-U4 (Core)

1 Like
#14

Right, the chunk 14ba4886c498fef394f490698b33500c016a615300232683f7a3bf0bb81bfd0a would go as file ba4886c498fef394f490698b33500c016a615300232683f7a3bf0bb81bfd0a into folder chunks\14. Since chunks folder is empty, it failed to (or did not try) create the folder 14. Hence the question to the developer.

I have the same at home, if we don’t get response by the evening, I can try to reproduce the failure, to rule out there being anything unique about your boxes configuration.

So far the ugly workaround would be to just manually (with a script) create all 256 folders under chunks ( 00, 01, 02, …ff).

1 Like
#15

I think I found the solution…

I stripped all ACLs and reapplied the permissions rwx for the “backup-user” recursively in TrueNAS for the backup dataset and now it works. I don’t know how or why the permissions got messed up but now the copy job appears to be working.

Thank you very much @saspus for your help and hopefully this thread will also help some other users. Maybe the error or debug message could be optimized if the SSH user doesn’t have the correct permissions.

1 Like
#16

Interesting. If that was permissions problem, why would mounting it over SMB with the same user did not fail the same way?

Did you have unix permissions and ACLs at the same time? it could be an issue, I’m wondering if there is some bug in TrueNAS with sftp handling unix vs ACL permissions (or the mix thereof – I don’t think mixing the two is supported)?

#17

If that was permissions problem, why would mounting it over SMB with the same user did not fail the same way?

I have no Idea :roll_eyes:

Did you have unix permissions and ACLs at the same time?

It appears so. I have 2 users on my TrueNAS : “backup-user” and “personal”. User “personal” had ownership of the dataset “backup” and there was an ACL that allowed user “backup-user” to rwx into dataset “backup”.

This is what I changed:

  1. Delete all ACLs
  2. (Re)apply ownership to user personal for dataset backup recursively
  3. Add ACL for user backup-user with rwx permissions
1 Like