bug: restoring from gdrive on gui: rate limit exceeded with 64 threads

[TheBestPessimist]

I was testing the gui version (2.0.8) in a vm, trying to restore with 64 threads some 20+ GB of stuff, 30k folders, 77k files (linux kernel, photos, videos + duplicates of those -- all the general file sizes), and a few minutes after starting restore i got an error about rate limit exceeded, and the restore stopped.

"error failed to find the chuck : googleapi: error 403: user rate limit exceeded, userRateLimitExceeded."

From what i remembered this error was fixed in 2.0.6, right?

[gilbertchen]

Error 403 should be retried. Sorry, just found out the FindChunk function doesn't retry on any error at all -- will fix that.

[TheBestPessimist]

waiting for the fix. will close after it's fixed and i can restore properly (and yes, need more than 30 threads to fill up my 1Gbit connection).

[gilbertchen]

I was wrong. Although FindChunk doesn't retry, it calls listByName which does retry. So I think the issue could be that the maximum number of retries (8) had been reached and the 403 error was returned as it was.

Can you try to run the CLI version from the command line to see if this is the case? I'll run my own tests too.

[TheBestPessimist]

I ran in cmd, and i can say that the rate limiting happens only sometimes there. It's rather inconsistent.
Beside duplicacy -v, is there any other logging option which i can give you?

[TheBestPessimist]

With 64 threads i also got 403 during backup, not only restore

kipped chunk 846 size 4268989, 5.74MB/s 00:17:35 38.5%
Skipped chunk 773 size 2842950, 5.74MB/s 00:17:34 38.5%
Skipped chunk 864 size 1600060, 5.74MB/s 00:17:35 38.6%
Skipped chunk 865 size 3154388, 5.74MB/s 00:17:34 38.6%
Skipped chunk 774 size 1212879, 5.74MB/s 00:17:33 38.6%
Skipped chunk 863 size 9556815, 5.76MB/s 00:17:29 38.7%
Skipped chunk 772 size 9815284, 5.77MB/s 00:17:25 38.8%
Skipped chunk 847 size 16777216, 5.80MB/s 00:17:18 38.9%
Packed old/pics/2017-05-19 -- Team building SSI/2017-05-19/DSC04509.JPG (9994240)
Packing old/pics/2017-05-19 -- Team building SSI/2017-05-19/DSC04510.JPG
Failed to find the path for the chunk 65889e594cd49e356a41492d6dcf5ff6dbfa8500aba24e4067f77d64be9f5d99: googleapi: Error 403: User Rate Limit Exceeded, userRateLimitExceeded

[TheBestPessimist]

It failed (during backup) even with 24 threads:

Failed to find the path for the chunk 7824eb3d4785283a7773294e4c2a3b2e122ed0bf046f5ef3b56de70fd24e4fbf: googleapi: Error 403: User Rate Limit Exceeded, userRateLimitExceeded

Z:\backup_software_test\the_data>Duplicacy_win_x64_2.0.8  -v backup -threads 24 -stats

[gilbertchen]

'-d' instead of '-v' will show retry messages.

[TheBestPessimist]

Restore with 24 threads of linux kernel source. Look at the speed there :(.

Downloaded chunk 174 size 1064889, 129KB/s 16:38:01 9.7%
Downloaded chunk 173 size 3448618, 129KB/s 16:33:36 9.8%
Downloaded chunk 194 size 2804473, 130KB/s 16:30:01 9.8%
Downloaded chunk 181 size 3582272, 130KB/s 16:25:29 9.9%
Downloaded chunk 190 size 7786646, 132KB/s 16:15:55 9.9%
Downloaded chunk 180 size 4161084, 132KB/s 16:10:48 10.0%
Failed to download the chunk 1e9d1c516aca9265af2a8396fe26a27348d126db809d7e665c7799748b1c912b: googleapi: got HTTP response code 403 with body: {
 "error": {
  "errors": [
   {
    "domain": "usageLimits",
    "reason": "userRateLimitExceeded",
    "message": "User Rate Limit Exceeded"
   }
  ],
  "code": 403,
  "message": "User Rate Limit Exceeded"
 }
}


Z:\backup_software_test\duplicacy\3 -- 64 threads>Duplicacy_win_x64_2.0.8  restore -overwrite -stats -r 6 -threads 24

[stevenhorner]

It's a Google issue really isn't it, read how you can possibly solve it on their api page: Here.

Although I guess it would be good if Duplicacy could deal with this problem somehow.

[TheBestPessimist]

Unsure if it's a google issue. In the API docs it just sais that google doesn't want to be DOSed which i can totally agree.
Thing is: i don't actually understand why so many requests are being made: i used 24 threads, which means 24 requests per second, possibly some threads finish faster, hence another 24. But this only sums to about 50-100 requests per second, i don't think there are more. From my point of view 100 requests per second is not a very big deal for any downlink server which serves chunked data.

Either way i feel duplicacy should handle this gracefully, no matter whose (english: is it just whos?) fault is.

[TheBestPessimist]

Storage set to gcd://duplicacy-test
Reading the environment variable DUPLICACY_GCD_TOKEN
Reading the environment variable DUPLICACY_PASSWORD
Compression level: 100
Average chunk size: 4194304
Maximum chunk size: 16777216
Minimum chunk size: 1048576
Chunk seed: 745e66227fdb08064bb2e3a01f8a5d1c7c445169d053a3c9a73a4abaa263dbfd
top: Z:\backup_software_test\duplicacy\3 -- 64 threads, revision: 6, in-place: true, quick: true, delete: false
Loaded file snapshots/DESKTOP-5CVRVBE-tbp-the_data/6 from the snapshot cache
Chunk 3a181f2b53fc59be984bd72ebb3a670f133c6650bc7ba54d4e6e89a603a2f792 has been loaded from the snapshot cache
Fetching chunk b8522411cf06e47b82ebf718395a80750d9ef16c635f9ac623c11ab8d70d3d4b
Chunk b8522411cf06e47b82ebf718395a80750d9ef16c635f9ac623c11ab8d70d3d4b has been loaded from the snapshot cache
Fetching chunk a7f20d12877dfe9e9a5c433661bf0e57b43e532e79a75c3aa95b6bcd58b7dd94
Chunk a7f20d12877dfe9e9a5c433661bf0e57b43e532e79a75c3aa95b6bcd58b7dd94 has been loaded from the snapshot cache
Fetching chunk 61e2ff5d63a41071ddd9238fa7b3db2bf74f18736f716f2047d5b41d89ddeb72
Chunk 61e2ff5d63a41071ddd9238fa7b3db2bf74f18736f716f2047d5b41d89ddeb72 has been loaded from the snapshot cache
Fetching chunk fdec185470346871e53bf870fb3e675eb4ce001c44a0d5b9a9bde1ef2b668af7
Chunk fdec185470346871e53bf870fb3e675eb4ce001c44a0d5b9a9bde1ef2b668af7 has been loaded from the snapshot cache
Fetching chunk 22142b327297872649624a82a9328cd32d1f639c2785d9aa917e58182be3c11e
Chunk 22142b327297872649624a82a9328cd32d1f639c2785d9aa917e58182be3c11e has been loaded from the snapshot cache
Fetching chunk cb6f0333298d982b577992f7ed5f4e13e033b745f40531e5caa88cc5a28c2c5f
Chunk cb6f0333298d982b577992f7ed5f4e13e033b745f40531e5caa88cc5a28c2c5f has been loaded from the snapshot cache
Fetching chunk 4e96ae0d4a4ee41158476623b7bac4f47e712885b2e790d7e6d5887dd0588d09
Chunk 4e96ae0d4a4ee41158476623b7bac4f47e712885b2e790d7e6d5887dd0588d09 has been loaded from the snapshot cache
Fetching chunk b950989ecb2e1ea2a62093233beeb04075f84ae90bf9cbe450526a0d29689334
Chunk b950989ecb2e1ea2a62093233beeb04075f84ae90bf9cbe450526a0d29689334 has been loaded from the snapshot cache
Fetching chunk 0e6d361e2a07c300ec0cc9ce293765f3cae4f9204917eac37a5363927877adb1
Chunk 0e6d361e2a07c300ec0cc9ce293765f3cae4f9204917eac37a5363927877adb1 has been loaded from the snapshot cache
Loaded 0 include/exclude pattern(s)
Listing
Listing linux-4.12/


[more listing]


Restoring Z:\backup_software_test\duplicacy\3 -- 64 threads to revision 6
Downloading old/linux-4.12/Documentation/devicetree/bindings/display/panel/netron-dy,e231732.txt
Prefetching old/linux-4.12/Documentation/devicetree/bindings/display/panel/netron-dy,e231732.txt chunk 8506c4d0009428d5ac80b987829bf65f891149f01636881339d972bc8a743f10
Updating Z:\backup_software_test\duplicacy\3 -- 64 threads/old/linux-4.12/Documentation/devicetree/bindings/display/panel/netron-dy,e231732.txt in place
Prefetching chunk 6323ebc6cd6426298a6c8dceb5449b8a59f92f4979e97dccc23c94dd8319e09f
Prefetching chunk f12ba33d6cf03c948470491f24dbd4efccfa0c4554401d0f8f521bb36b59f36b
Prefetching chunk e817ca779f44fcd5af36e5460fcaf7b376b7c9e2a558f62279266e56449bd481
Prefetching chunk e6525c080927ec69d613dc46ef5294d0e0bb9c82faa20e6e4704118fc134da31
Prefetching chunk 64c2094dbc55ebb1f449e4e6b66a773193af719440d57875d60d2bd574e56f6d
Prefetching chunk fdc78cc2f6566f14e4cf7babf3a92abc759cfe0e54c8d7a97252318e841e55bf
Prefetching chunk 3a02ac3e36d5ef6507b1fca8fa89a477a40c0251e9fafa079f9fdb634630664f
Prefetching chunk ac2970867589d5bfc47e3be41a68e4b177d151250e427cd16625359ac537dea6
Prefetching chunk 462d9548bfb19f5abd9d9be64ed5a0d2473d8ca0fc59d077d1744b4b56ee4f4d
Prefetching chunk 681d35e847c54eff57c5684cb7d9f27ddb86f15c1c1a19387d012f63767da7fb
Prefetching chunk ca50419ab3e2198a0616f2fcabcf40a2b4cf1485965087293610fb48369b243a
Prefetching chunk 3f77cc225bb15355d590bb14629d2254537fad388f448af65a79db50d499d970
Prefetching chunk 59fdc7a98359d9f7b2ba05dbbba973aedbbbfa0206403d2e7d00e8e2ab33d53d
Prefetching chunk e45ac15f0c30c294c8891c7b824319b7ad0ebbd4ab4b473fa85d3005ab2f5e0e
Prefetching chunk f9b41797c2d04bd633cb64f4317ac9eea841baf3d9124b3fc128e9193550ea38
Prefetching chunk 35b423b5ca66898afcc495a467f67a7b35b0a6babee816e52438b3ec781e2b3d
Prefetching chunk 41969e7f37b1ec89bc748259500f911a8d4916bab744bf6be43ded9143ed8a76
Prefetching chunk e53634fde126c2477a1892011551b3e2fc8c1e39e3d026577bcb7342ae4aaef6
Prefetching chunk 366f2b09991274905cb76cf9716180ae370e8bbde66300c1d1210aa280dc98fa
Prefetching chunk de5a76a9bf2089f6f3247fe18f8b7b6a4216941ffbc2c19456140ee770f2a6dc
Prefetching chunk 067b40b18c8bc05654d140325017d8626dab8838291ad1be065f5265c6b081ca
Prefetching chunk 333618d219fa9b8873b935e3b52cc2cfb5f09b1932991d99b4e0e3769bbb7796
Prefetching chunk 02497021e3f4efc7d1f5063f6a416db5824d104d67c77ca9b21079730a409615
Prefetching chunk bf6753463da1981768c2dc540823ad6b6f3dcfbadc4fd17545c9f21091fb0015
Prefetching chunk 00d3f15d6e12b87d35c700f2f7f096ce680f89e9534f7225ce87f83f0932873c
Prefetching chunk 3f36bc279b6f78f69bda25a89413c7a4790f949dcb02f87e3445f131b68d1ccf
Prefetching chunk 04f0121584c6e6631b908c7be3c2527aff572954eb368feed8a8f8f8a6e558ad
Prefetching chunk b4d478fc5a918b478cd21e00c728b252fd76461341bfda792fb5a9bc77a2f4fd
Prefetching chunk 27afc659a0d94846c6b66785fe0d95cd0df04690fbafbdf760c489d3db7bf6ea
Prefetching chunk 92634a7be0df66db4c92f9f4f04fd7cdf58fe24e4ca8a768fa994f698d3f9cfd
Prefetching chunk eede9cf60366e4d9d42f5feee6e4bef4fd1f25df634ba1f9c2ba90ffaefcd780
Prefetching chunk ca8ee20fcbae81a8295bf65d1686a0e4ddd6224d8a72abffa2525c7a1a2f04db
Prefetching chunk 9515ffcedd92f9d42d52ffef421a6991afefecf905bd26db7279e2399ee5578e
Prefetching chunk 2ccb5eeea80debce8c6a1bbcf861cadbdec28f89dea7743e569a7f90bb59d9ab
Prefetching chunk c7b63de982d5827892a1a679f6ea20e9c83375abb517b50d79b79dba6e3bbb48
Prefetching chunk dd7c2df88275392cbde152092d6b21737fe07531f1ce2759a02771369490f644
Prefetching chunk 50c91f46ff9c1247254ee98c99ad92baffd2ebc54780bfeba8ae4d26f4ded3ad
Prefetching chunk 59e95d818b94e13c31718d78493ef129174b38ada212f6d96a893796bfc64d05
Prefetching chunk 0d5d7fe77a0bc372ad3839399712798aca9b531c3b8fdf2eee15c3cad2e2def5
Prefetching chunk ba4a18d4dc476582de421637ffe5c130b3edd6d27f769e9ce53f960ad990f9ad
User Rate Limit Exceeded; retrying after 0.13 seconds
User Rate Limit Exceeded; retrying after 0.83 seconds
User Rate Limit Exceeded; retrying after 0.22 seconds
User Rate Limit Exceeded; retrying after 0.16 seconds
User Rate Limit Exceeded; retrying after 0.59 seconds
User Rate Limit Exceeded; retrying after 0.97 seconds
User Rate Limit Exceeded; retrying after 0.25 seconds
User Rate Limit Exceeded; retrying after 0.79 seconds
User Rate Limit Exceeded; retrying after 0.77 seconds
User Rate Limit Exceeded; retrying after 0.05 seconds
User Rate Limit Exceeded; retrying after 0.65 seconds
User Rate Limit Exceeded; retrying after 0.78 seconds
User Rate Limit Exceeded; retrying after 0.39 seconds
User Rate Limit Exceeded; retrying after 0.10 seconds
User Rate Limit Exceeded; retrying after 0.63 seconds
User Rate Limit Exceeded; retrying after 0.88 seconds
User Rate Limit Exceeded; retrying after 0.79 seconds
User Rate Limit Exceeded; retrying after 0.31 seconds
User Rate Limit Exceeded; retrying after 0.70 seconds
User Rate Limit Exceeded; retrying after 0.28 seconds
User Rate Limit Exceeded; retrying after 0.03 seconds
User Rate Limit Exceeded; retrying after 0.53 seconds
User Rate Limit Exceeded; retrying after 0.50 seconds
User Rate Limit Exceeded; retrying after 0.30 seconds
User Rate Limit Exceeded; retrying after 0.12 seconds
User Rate Limit Exceeded; retrying after 0.10 seconds
User Rate Limit Exceeded; retrying after 1.00 seconds
User Rate Limit Exceeded; retrying after 0.75 seconds
User Rate Limit Exceeded; retrying after 0.54 seconds
User Rate Limit Exceeded; retrying after 0.44 seconds
User Rate Limit Exceeded; retrying after 0.48 seconds
User Rate Limit Exceeded; retrying after 0.60 seconds
User Rate Limit Exceeded; retrying after 0.87 seconds
Downloaded chunk 5 size 4217453, 1.34MB/s 01:27:42 0.0%
Failed to find the chunk 462d9548bfb19f5abd9d9be64ed5a0d2473d8ca0fc59d077d1744b4b56ee4f4d: googleapi: Error 403: User Rate Limit Exceeded, userRateLimitExceeded

[stevenhorner]

I agree if Duplicacy could deal with the error and retry. There are 3 quotas I think for Google Drive, the likely one you are hitting is the per user one which for me is: 1000 Queries per 100 seconds per user.

I would presume Duplicacy would need to ensure it didn't use more than that, not sure if this limit can be changed in the Google Drive API.

[TheBestPessimist]

From what i know, a user can request for a specific project/licence to have said limits increased, and google will check (afaik this raises some questions on usage -- maybe some other code enhancements will come out) whether they want to increase the limit.

@gilbertchen wanna check this?

[gilbertchen]

There is a bug in the GCD backend -- the variable backoff is shared by all threads so it will reach the maximum too quickly (that is why the backoffs were all less than 1 second in your log).

I also found out the web page to request more quotas. This is definitely needed, as 100 queries per 100 seconds means only 500 chunks per 100 seconds which is about 20MB/s.

[gilbertchen]

This is fixed by 6f70b37. Let me know if you need a Windows binary.

[TheBestPessimist]

Please giver me one, so i can test this.

[TheBestPessimist]

Note: is this fixed both for backups and restores?

[gilbertchen]

this is the Windows binary: https://acrosync.com/duplicacy/duplicacy_win_x64_2.0.8a.exe

Yes, both backup and restore are fixed.

[TheBestPessimist]

I think google really doesn't like me:

Uploaded chunk 1149 size 5138664, 2.73MB/s 00:19:21 62.5%
Failed to upload the chunk abd5580ed77efa115a37dfe9718db58e93756674afc3c9bd35552a5cf9b651c8: googleapi: Error 403: User rate limit exceeded., userRateLimitExceeded
Incomplete snapshot saved to Z:\backup_software_test\the_data/.duplicacy/incomplete

This is backup with 128 threads however, so i may be of fault here.

---

With 64 threads however i did not get any 403s either on up or down.

Do you want to check 128? or that is not a normal value?

[TheBestPessimist]

And of course i talked too soon: with 64, (and 40, 32) threads i still got 403:

Uploaded chunk 5562 size 1861281, 46.67MB/s 00:12:28 28.4%
Uploaded chunk 5529 size 8786938, 46.54MB/s 00:12:30 28.4%
Uploaded chunk 5563 size 1859780, 46.54MB/s 00:12:30 28.4%
Failed to find the path for the chunk 065b2ef76122427697d4ee1c72c7c09f40188f60c9ab0bf2c1505c8566078e48: googleapi: Error 403: User Rate Limit Exceeded, userRateLimitExceeded

Z:\backup_software_test\the_data>duplicacy_win_x64_2.0.8  backup -stats -threads 64

[TheBestPessimist]

Also: i got 403 while restoring revision 1, and doing backup 2, both with 32 threads, on the same VM, in 2 different folders (and cmd-s).

This means that if i am backing up from multiple PCs in my house at night, i could get 403 for each, and my backups won't finish?

[TheBestPessimist]

Are you sure you gave me the right version? , there seems to be no difference.

[gilbertchen]

I'm pretty sure I did. If you turn on the -d option you should be able to see more retry messages and it may take a few minutes for it to finally give up and return the error.

[TheBestPessimist]

There are more messages now, i did see that.
I attached the full -d restore log to look upon (since at the end it finished in error, whilst trying to resize a VM file -- maybe this needs a new bug UPDATE: linked to another bug).

Here's an example of retries:

Prefetching chunk 6affbe30bfcdc425331839e3acfcdaf239d0ebf042fbc1ec000e8380f79e55d6
User Rate Limit Exceeded; retrying after 0.15 seconds
User Rate Limit Exceeded; retrying after 0.10 seconds
User Rate Limit Exceeded; retrying after 0.71 seconds
User Rate Limit Exceeded; retrying after 0.68 seconds
User Rate Limit Exceeded; retrying after 0.54 seconds
User Rate Limit Exceeded; retrying after 0.53 seconds
User Rate Limit Exceeded; retrying after 0.72 seconds
User Rate Limit Exceeded; retrying after 0.01 seconds
User Rate Limit Exceeded; retrying after 0.49 seconds
User Rate Limit Exceeded; retrying after 0.71 seconds
User Rate Limit Exceeded; retrying after 0.06 seconds
User Rate Limit Exceeded; retrying after 0.83 seconds
User Rate Limit Exceeded; retrying after 0.27 seconds
User Rate Limit Exceeded; retrying after 0.05 seconds
User Rate Limit Exceeded; retrying after 0.20 seconds
User Rate Limit Exceeded; retrying after 0.74 seconds
User Rate Limit Exceeded; retrying after 0.63 seconds
User Rate Limit Exceeded; retrying after 0.36 seconds
User Rate Limit Exceeded; retrying after 0.07 seconds
User Rate Limit Exceeded; retrying after 0.32 seconds
Downloaded chunk 1672 size 1511977, 3.23MB/s 04:13:50 14.0%
Downloaded chunk 1677 size 1148847, 3.23MB/s 04:13:48 14.0%
User Rate Limit Exceeded; retrying after 1.48 seconds
User Rate Limit Exceeded; retrying after 0.04 seconds
User Rate Limit Exceeded; retrying after 1.84 seconds
User Rate Limit Exceeded; retrying after 1.77 seconds
User Rate Limit Exceeded; retrying after 0.66 seconds
Downloaded chunk 1676 size 5081373, 3.23MB/s 04:13:37 14.0%
User Rate Limit Exceeded; retrying after 0.77 seconds
Downloaded chunk 1674 size 5907657, 3.23MB/s 04:13:31 14.0%
User Rate Limit Exceeded; retrying after 0.12 seconds
Downloaded chunk 1688 size 4957491, 3.23MB/s 04:13:21 14.0%
Downloaded chunk 1671 size 3943074, 3.24MB/s 04:13:12 14.0%
Downloaded chunk 1664 size 3632994, 3.24MB/s 04:13:05 14.0%
Downloaded chunk 1662 size 4796261, 3.24MB/s 04:12:55 14.0%
Downloaded chunk 1659 size 7126719, 3.24MB/s 04:12:40 14.1%
Downloaded chunk 1686 size 1077253, 3.24MB/s 04:12:38 14.1%
Downloaded chunk 1670 size 1297408, 3.24MB/s 04:12:35 14.1%
Downloaded chunk 1673 size 2993242, 3.24MB/s 04:12:35 14.1%
Downloaded chunk 1679 size 1620903, 3.24MB/s 04:12:31 14.1%
Downloaded chunk 1658 size 4872269, 3.24MB/s 04:12:21 14.1%
Downloaded chunk 1661 size 13204979, 3.25MB/s 04:11:54 14.1%
Downloaded chunk 1685 size 5908179, 3.25MB/s 04:11:41 14.1%
Downloaded chunk 1665 size 3317587, 3.25MB/s 04:11:35 14.1%
Downloaded chunk 1675 size 7039127, 3.26MB/s 04:11:20 14.1%
Downloaded chunk 1687 size 5754350, 3.26MB/s 04:11:08 14.1%
Downloaded chunk 1678 size 6120773, 3.26MB/s 04:11:02 14.1%
Downloaded chunk 1680 size 6634529, 3.26MB/s 04:10:48 14.2%
Downloaded chunk 1663 size 7534405, 3.26MB/s 04:10:32 14.2%
Downloaded chunk 1669 size 1893671, 3.27MB/s 04:10:29 14.2%
Downloaded chunk 1681 size 4981922, 3.27MB/s 04:10:18 14.2%
Downloaded chunk 1668 size 16777216, 3.27MB/s 04:09:44 14.2%
Downloaded chunk 1667 size 1592521, 3.27MB/s 04:09:41 14.2%
Downloaded chunk 1684 size 1926029, 3.27MB/s 04:09:43 14.2%
Downloaded chunk 1657 size 8964520, 3.28MB/s 04:09:24 14.2%
Prefetching chunk 9eb830aea0bc2958799787a2a06b6ebc8bc6c0497886a18b624c8824823ac800
Prefetching chunk 9d4828afdc37da6559f32289ad454fc1dd659d42d64381e0a2dd72d207ccb64b
Prefetching chunk 1588d212e41f4812c5175271a7934914f9208adeb858ac509cb0cb4d3c4c57b5
Downloaded chunk 1666 size 3327551, 3.28MB/s 04:09:18 14.2%
Downloaded chunk 1682 size 4490549, 3.28MB/s 04:09:09 14.2%
Downloaded chunk 1660 size 2166651, 3.28MB/s 04:09:04 14.2%
Prefetching chunk 72242e0fb0972f26d5d08e0d0fa16c1fb5ea4ff18caf08c5e7af8e9b0a22a7a0
Prefetching chunk bc17a630f6a53c8a570209bac08cb0efce87a8de3fdfeca5bf377c7fbcbade40
Prefetching chunk a707cb743a0e50487dead40ad64f8b95346ccd3e6de49d75a95a8e8325076fca
Prefetching chunk dc6859bbc67d9da9bfa8ffeea6d67650389e3aa10547a4cf3483cb033a7ba81e
Prefetching chunk e3e0c340bc3502ba1580555aa0e8d9a1b6777636e30a7c1b6f76f95d465149f4
Prefetching chunk fd42d19cbcbca856af479bf7d1f5e827412aad3d59120f53d73aa99d8dee0798
Prefetching chunk 372f60491112ebc0228b3966bd7e52f1f767a88b8d2470d1a2300ffcf92d627c
Prefetching chunk f719801db17bda834f9f36b89ccaf685cc07e5c25d7d74be4387ec112f4bafc0
Prefetching chunk da47bbd69c0e312bdeea1e842d9eaa2999bce5218c8793083a330b35d0b418fc
Prefetching chunk d47303b7ba5a94b2748b802ce3365b4e9d7918f84a38e6ee46dfed5b2d6c8e4d
Prefetching chunk 257952eef7670aa7b1fabd17c6d24b4ae784a685c3b8bca274581c108ea1c0f4
Prefetching chunk bc23b9f207e86a94e50d46757df3b56436ee8945aaaae8d74f49f15237eafecc
Prefetching chunk fc7177598f5ff53f91628aa1d74a2dff9c084b9ec102fa9e032d8b782a555dcf
Prefetching chunk e3460a02f50b97336c4aeb1e4d774dbeb3c800a5b4ae9533df5366cec9fe1671
Prefetching chunk bc251a3b41ded073fcf706a994db25b8f6977e6e4a34295c681a6d8abf2bad40
Prefetching chunk f18a41cca132b0755caeffbcba70f35817d58815cf58830de81d27ba42790a8a
Prefetching chunk a8d70c7c24e8faf178686d8adc4bb4e8570b3212658c47298fbe9d2a7eb8fcd8
Prefetching chunk d7ab445e9afa99906030f2958754239ed04f7048a338ca83457fad8efd1f5f4d
Prefetching chunk d3e24e33959316873a46a450851364405f3c4ade60f661a21114cd10a631279e
Prefetching chunk e22342984f502831528f1aa992faef55667960df3057fa347bd18aa5bc02f948
Prefetching chunk 5694134b800dea1022c05569f96dad8cb2967bdcc68104d6c4c990c5d771d975
Prefetching chunk 8189f8034803e032a2b439e0644bbfa4d5326c443ac42eee11792ce87096d8db
Prefetching chunk b0b697095f169d09314646f44b86fb6ccb1dca0e378b917c2a3cef382f2e6e74
User Rate Limit Exceeded; retrying after 0.24 seconds
User Rate Limit Exceeded; retrying after 0.41 seconds
User Rate Limit Exceeded; retrying after 0.72 seconds
User Rate Limit Exceeded; retrying after 0.94 seconds
User Rate Limit Exceeded; retrying after 0.26 seconds
User Rate Limit Exceeded; retrying after 0.03 seconds
User Rate Limit Exceeded; retrying after 0.92 seconds
User Rate Limit Exceeded; retrying after 0.85 seconds
User Rate Limit Exceeded; retrying after 0.91 seconds
User Rate Limit Exceeded; retrying after 0.72 seconds
User Rate Limit Exceeded; retrying after 0.18 seconds
User Rate Limit Exceeded; retrying after 0.22 seconds
User Rate Limit Exceeded; retrying after 0.18 seconds
User Rate Limit Exceeded; retrying after 0.35 seconds
User Rate Limit Exceeded; retrying after 0.78 seconds
User Rate Limit Exceeded; retrying after 0.35 seconds
Downloaded chunk 1691 size 2282736, 3.28MB/s 04:09:05 14.2%
Downloaded chunk 1692 size 1755754, 3.28MB/s 04:09:02 14.2%
Downloaded chunk 1689 size 4195696, 3.28MB/s 04:08:53 14.3%
User Rate Limit Exceeded; retrying after 0.52 seconds
User Rate Limit Exceeded; retrying after 1.89 seconds
User Rate Limit Exceeded; retrying after 1.28 seconds
Downloaded chunk 1700 size 3034639, 3.28MB/s 04:08:53 14.3%
User Rate Limit Exceeded; retrying after 0.78 seconds
User Rate Limit Exceeded; retrying after 0.27 seconds
User Rate Limit Exceeded; retrying after 0.99 seconds
User Rate Limit Exceeded; retrying after 0.63 seconds
User Rate Limit Exceeded; retrying after 0.84 seconds
User Rate Limit Exceeded; retrying after 1.23 seconds
User Rate Limit Exceeded; retrying after 0.22 seconds
Downloaded chunk 1708 size 4620104, 3.28MB/s 04:08:44 14.3%
User Rate Limit Exceeded; retrying after 0.27 seconds
User Rate Limit Exceeded; retrying after 0.10 seconds
Downloaded chunk 1683 size 15538056, 3.29MB/s 04:08:12 14.3%
Prefetching chunk c8f8d9600523ed14c0f10872001e0e04264cd57e9a7396d8dd455b666f54c91a
Prefetching chunk b56e2f36f9f04a2da1634a93887385fcb1e0b901db9c7b9c9b13337930feb548
Prefetching chunk fa821ebeeba580a538825e2de387ae8c387d1bb468f768299ce8adf39070fb3f
Prefetching chunk 6a5a9e2381daec82695831c0eb5ab1f9e216f13daf0368b59b3dc89e023de0be
Prefetching chunk dd1fc4c676ad098aab998d5788deb6fdd0893bb47bb6f1298eb4da51ec82dea6
Prefetching chunk 716a8787bad7598e04f807133c0641ef7629cd042c545bb9177c9e62c3e94a5a
Prefetching chunk b7c92fa1ea6e6dfaa6bffce04033a5df698aa33d456d4b96e81ba798085649e2
Downloaded chunk 1703 size 6719772, 3.29MB/s 04:07:59 14.3%
Downloaded chunk 1698 size 4345823, 3.29MB/s 04:07:50 14.3%
Downloaded chunk 1693 size 3623794, 3.29MB/s 04:07:49 14.3%
User Rate Limit Exceeded; retrying after 0.88 seconds
Downloaded chunk 1696 size 4260802, 3.30MB/s 04:07:40 14.3%
User Rate Limit Exceeded; retrying after 0.21 seconds
User Rate Limit Exceeded; retrying after 0.82 seconds
User Rate Limit Exceeded; retrying after 0.34 seconds
Downloaded chunk 1690 size 9507638, 3.30MB/s 04:07:21 14.3%
User Rate Limit Exceeded; retrying after 0.54 seconds
Prefetching chunk e3640bc474da5c3856027e7b686f2abac823f1399bad05f4246a0b49bc79862b
Prefetching chunk 8d7ee7929a2593c7355a52baa5aa00be9ebf8cd8b6c2250d91f2dfc69111e0e1
Prefetching chunk dba4c8d1df0fa4f93e77b753b4a382a955841e6fc79d4e96b873bd2b0c730201
Prefetching chunk 7d5f72b90ec8de84639bbc879080c259568d5c2c0b25ad30a585d9a19738555e
User Rate Limit Exceeded; retrying after 0.05 seconds
User Rate Limit Exceeded; retrying after 0.70 seconds
User Rate Limit Exceeded; retrying after 0.84 seconds
User Rate Limit Exceeded; retrying after 0.33 seconds
User Rate Limit Exceeded; retrying after 0.64 seconds
User Rate Limit Exceeded; retrying after 0.62 seconds
User Rate Limit Exceeded; retrying after 0.79 seconds
User Rate Limit Exceeded; retrying after 1.48 seconds
User Rate Limit Exceeded; retrying after 1.58 seconds
User Rate Limit Exceeded; retrying after 0.68 seconds
User Rate Limit Exceeded; retrying after 0.18 seconds
Downloaded chunk 1712 size 4093325, 3.30MB/s 04:07:13 14.3%
User Rate Limit Exceeded; retrying after 0.78 seconds
User Rate Limit Exceeded; retrying after 0.65 seconds
Downloaded chunk 1694 size 8856391, 3.30MB/s 04:06:55 14.4%
Downloaded chunk 1713 size 4793262, 3.31MB/s 04:06:45 14.4%
Prefetching chunk 1fb77da2d250a80b30ef7696e6d620331049381bb2b82f3774730a5c3666adf2
User Rate Limit Exceeded; retrying after 0.51 seconds
User Rate Limit Exceeded; retrying after 3.56 seconds
User Rate Limit Exceeded; retrying after 1.17 seconds
User Rate Limit Exceeded; retrying after 0.40 seconds
User Rate Limit Exceeded; retrying after 1.45 seconds
User Rate Limit Exceeded; retrying after 0.83 seconds
User Rate Limit Exceeded; retrying after 0.52 seconds
User Rate Limit Exceeded; retrying after 1.79 seconds
User Rate Limit Exceeded; retrying after 1.40 seconds
User Rate Limit Exceeded; retrying after 1.76 seconds
User Rate Limit Exceeded; retrying after 1.79 seconds
User Rate Limit Exceeded; retrying after 0.55 seconds
User Rate Limit Exceeded; retrying after 1.38 seconds
User Rate Limit Exceeded; retrying after 0.27 seconds
Downloaded chunk 1711 size 7896159, 3.31MB/s 04:06:36 14.4%
User Rate Limit Exceeded; retrying after 1.76 seconds
User Rate Limit Exceeded; retrying after 2.58 seconds
User Rate Limit Exceeded; retrying after 0.80 seconds
Downloaded chunk 1709 size 1115227, 3.31MB/s 04:06:45 14.4%
Downloaded chunk 1701 size 3038890, 3.31MB/s 04:06:39 14.4%
Downloaded chunk 1715 size 1240004, 3.31MB/s 04:06:37 14.4%

a.zip

[TheBestPessimist]

64 threads, upload in clean folder (everything deleted in gdrive)

Uploaded chunk 8154 size 11677898, 3.39MB/s 02:30:03 46.5%
User Rate Limit Exceeded; retrying after 0.15 seconds
User Rate Limit Exceeded; retrying after 1.30 seconds
User Rate Limit Exceeded; retrying after 0.17 seconds
User Rate Limit Exceeded; retrying after 0.91 seconds
User Rate Limit Exceeded; retrying after 0.02 seconds
User Rate Limit Exceeded; retrying after 2.45 seconds
User Rate Limit Exceeded; retrying after 0.98 seconds
User Rate Limit Exceeded; retrying after 0.28 seconds
User Rate Limit Exceeded; retrying after 0.66 seconds
User Rate Limit Exceeded; retrying after 2.44 seconds
User Rate Limit Exceeded; retrying after 0.23 seconds
User Rate Limit Exceeded; retrying after 0.57 seconds
User Rate Limit Exceeded; retrying after 2.00 seconds
User Rate Limit Exceeded; retrying after 0.71 seconds
User Rate Limit Exceeded; retrying after 0.94 seconds
User Rate Limit Exceeded; retrying after 0.35 seconds
User Rate Limit Exceeded; retrying after 1.96 seconds
User Rate Limit Exceeded; retrying after 1.49 seconds
User Rate Limit Exceeded; retrying after 2.51 seconds
User Rate Limit Exceeded; retrying after 0.65 seconds
User Rate Limit Exceeded; retrying after 1.59 seconds
User Rate Limit Exceeded; retrying after 0.56 seconds
User Rate Limit Exceeded; retrying after 1.51 seconds
User Rate Limit Exceeded; retrying after 3.41 seconds
User Rate Limit Exceeded; retrying after 0.75 seconds
User Rate Limit Exceeded; retrying after 1.29 seconds
User Rate Limit Exceeded; retrying after 1.31 seconds
User Rate Limit Exceeded; retrying after 0.26 seconds
User Rate Limit Exceeded; retrying after 1.60 seconds
User Rate Limit Exceeded; retrying after 1.34 seconds
User Rate Limit Exceeded; retrying after 11.00 seconds
User Rate Limit Exceeded; retrying after 0.36 seconds
User Rate Limit Exceeded; retrying after 0.13 seconds
User Rate Limit Exceeded; retrying after 0.36 seconds
User Rate Limit Exceeded; retrying after 2.23 seconds
User Rate Limit Exceeded; retrying after 0.79 seconds
User Rate Limit Exceeded; retrying after 0.31 seconds
Failed to upload the chunk 0ae906bd30ff9f5dafb5d89edeac9cd965b6a9876fa7bb56d2aba630abc54e7c: googleapi: Error 403: User rate limit exceeded., userRateLimitExceeded
User Rate Limit Exceeded; retrying after 0.93 seconds
Incomplete snapshot saved to Z:\backup_software_test\the_data/.duplicacy/incomplete

I see there an 11 second wait time. Is that why the transfer failed?
I see that the rest of the threads have rather low wait time (3.41s second closest).

What i am thinking (i could be wrong) is that maybe google tracks all the threads somehow? And that when a thread gets a 403, some others will also get, and maybe in that case we should delay all the threads/requests with 0.1-0.5s (more?) instead of retrying so hard? Somehow serialize the threads, so that each one starts a new upload/download request 0.5 seconds after the previous one started?

In other lines: can't you just increase the timeout even more? (lets say 100 seconds of wait before failing?

Another request: in the debug (-d) log could you also print the number of the thread which does whichever task it does? (for example this way we could see because of which thread the transfer has died, and which was its last wait time/which was the total wait time, etc). Could that help us debugging?

[angadsingh]

Facing the same issue:

Skipped chunk 23 size 2415122, 69.99MB/s 02:25:22 0.0%
Skipped chunk 21 size 3932168, 73.74MB/s 02:17:58 0.0%
Skipped chunk 22 size 3692749, 77.26MB/s 02:11:41 0.0%
Skipped chunk 24 size 3962531, 81.04MB/s 02:05:32 0.0%
Skipped chunk 18 size 4928300, 85.74MB/s 01:58:39 0.0%
Skipped chunk 26 size 1260356, 86.94MB/s 01:57:01 0.0%
Skipped chunk 44 size 2912941, 44.86MB/s 03:46:47 0.0%
Skipped chunk 15 size 10014099, 49.63MB/s 03:24:57 0.0%
Failed to find the path for the chunk ab18f7ba9d0a44d119691c1170e201a6ee176983e741b8872695425047a7b13e: googleapi: Error 403: User Rate Limit Exceeded, userRateLimitExceeded

[gilbertchen]

I'll have some time next week to work on GCD improvements.

[TheBestPessimist]

May I close this as it seems that google rate limiting is just too much of a beast with all its hidden rate limiting?

[gilbertchen]

You can close this issue for now. I'll try to contact Google to see if they can increase the rate limits for Duplicacy.

[TheBestPessimist]

Nice to hear. Hope they will accept it!

[archon810]

I'm assuming this hasn't happened because it's still really easy to run into this rate limit https://forum.duplicacy.com/t/googleapi-error-403-user-rate-limit-exceeded-userratelimitexceeded-maximum-number-of-retries-reached-backoff-64-attempts-15/2500.

What I'm curious about is if @gilbertchen would be open to implementing the Google Cloud Platform Drive v3 API, as it seems to have much more relaxed limits.