Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Dropbox v2 api error too_many_write_operations #1539

Closed
austinginder opened this issue Jul 17, 2017 · 8 comments
Closed

Dropbox v2 api error too_many_write_operations #1539

austinginder opened this issue Jul 17, 2017 · 8 comments

Comments

@austinginder
Copy link

austinginder commented Jul 17, 2017

Just upgraded to the latest beta to try out the new Dropbox v2 API. Thanks for all of your hard work! Much appreciated. I'm noticing a lot of files being updated while syncing which haven't changed. I assume that's due to client_modified attribute now being applied correctly.

While reviewing my log output it appears there is a high number of too_many_write_operations errors. They seem to self correct during a low level retry. It's happening frequently around every 5th or 6th file. Maybe this is normal behavior? I haven't noticed it before the update. Sorta reminds me of the "lock held by connection" errors I would see in Dropbox v1 API. Not really affecting anything but there in the background.

What is your rclone version (eg output from rclone -V)

rclone v1.36-254-g6f71260aβ

Which OS you are using and how many bits (eg Windows 7, 64 bit)

Ubuntu 16.04 64bit

Which cloud storage system are you using? (eg Google Drive)

Dropbox

The command you were trying to run (eg rclone copy /tmp remote:tmp)

rclone sync Backup/foldername Anchor-Dropbox:Backup/foldername -vv --exclude .DS_Store --stats=5m

A log from the command with the -vv flag (eg output from rclone -vv copy /tmp remote:tmp)

Transferred:   10.516 MBytes (17.912 kBytes/s)
Errors:                 0
Checks:              2101
Transferred:          540
Elapsed time:     10m1.1s

2017/07/17 10:35:17 INFO  : wp-content/plugins/display-widgets/languages/display-widgets-fi.mo: Copied (replaced existing)
2017/07/17 10:35:17 DEBUG : wp-content/themes/Trim/epanel/js/custom_uploader.js: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:17 DEBUG : wp-content/themes/Trim/epanel/js/custom_uploader.js: Unchanged skipping
2017/07/17 10:35:17 DEBUG : wp-content/themes/Webly/images/project-overlay.png: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:17 DEBUG : wp-content/themes/Webly/images/project-overlay.png: Unchanged skipping
2017/07/17 10:35:17 DEBUG : wp-admin/css/colors/light/colors-rtl.css: Modification times differ by 4h7m9s: 2017-06-08 18:05:50 -0400 EDT, 2017-06-09 02:12:59 +0000 UTC
2017/07/17 10:35:17 DEBUG : wp-admin/css/colors/light/colors-rtl.css: src and dst identical but can't set mod time without deleting and re-uploading
2017/07/17 10:35:17 DEBUG : pacer: Reducing sleep to 41.277856ms
2017/07/17 10:35:17 INFO  : wp-content/plugins/display-widgets/languages/display-widgets-fr_FR.mo: Copied (replaced existing)
2017/07/17 10:35:17 DEBUG : wp-admin/css/colors/light/colors-rtl.min.css: Modification times differ by 216h46m7s: 2016-11-28 23:11:52 -0500 EST, 2016-12-08 04:57:59 +0000 UTC
2017/07/17 10:35:17 DEBUG : wp-admin/css/colors/light/colors-rtl.min.css: src and dst identical but can't set mod time without deleting and re-uploading
2017/07/17 10:35:17 DEBUG : pacer: Reducing sleep to 30.958392ms
2017/07/17 10:35:20 DEBUG : pacer: Reducing sleep to 23.218794ms
2017/07/17 10:35:20 DEBUG : pacer: Reducing sleep to 17.414095ms
2017/07/17 10:35:20 DEBUG : pacer: Reducing sleep to 13.060571ms
2017/07/17 10:35:20 DEBUG : pacer: Rate limited, increasing sleep to 26.121142ms
2017/07/17 10:35:20 DEBUG : pacer: low level retry 1/1 (error too_many_write_operations/.)
2017/07/17 10:35:20 DEBUG : pacer: Rate limited, increasing sleep to 52.242284ms
2017/07/17 10:35:20 DEBUG : pacer: low level retry 1/1 (error too_many_write_operations/..)
2017/07/17 10:35:20 DEBUG : wp-content/plugins/et-shortcodes/et-shortcodes.php: Received error: upload failed: too_many_write_operations/.. - low level retry 1/10
2017/07/17 10:35:20 DEBUG : pacer: Rate limited, increasing sleep to 104.484568ms
2017/07/17 10:35:20 DEBUG : pacer: low level retry 1/1 (error too_many_write_operations/..)
2017/07/17 10:35:20 ERROR : wp-admin/css/colors/light/colors-rtl.min.css: failed to delete before re-upload: too_many_write_operations/..
2017/07/17 10:35:20 DEBUG : pacer: Reducing sleep to 78.363426ms
2017/07/17 10:35:20 INFO  : wp-content/mu-plugins/wpengine-common/views/admin/notice-sticky.php: Copied (replaced existing)
2017/07/17 10:35:20 DEBUG : pacer: Reducing sleep to 58.772569ms
2017/07/17 10:35:20 INFO  : wp-content/mu-plugins/wpengine-common/views/admin/notice.php: Copied (replaced existing)
2017/07/17 10:35:20 DEBUG : wp-admin/css/colors/light/colors.css: Modification times differ by 4h10m16s: 2017-06-08 18:05:50 -0400 EDT, 2017-06-09 02:16:06 +0000 UTC
2017/07/17 10:35:20 DEBUG : pacer: Reducing sleep to 44.079426ms
2017/07/17 10:35:20 INFO  : wp-content/plugins/et-shortcodes/shortcodes.php: Copied (replaced existing)
2017/07/17 10:35:20 ERROR : wp-admin/css/colors/light/colors-rtl.css: failed to delete before re-upload: too_many_write_operations/.
2017/07/17 10:35:20 DEBUG : wp-content/themes/Trim/epanel/images/mainmenu-li-bottom.png: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:20 DEBUG : wp-content/themes/Trim/epanel/images/mainmenu-li-bottom.png: Unchanged skipping
2017/07/17 10:35:20 DEBUG : wp-content/themes/twentythirteen/functions.php: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:20 DEBUG : wp-content/themes/twentythirteen/functions.php: Unchanged skipping
2017/07/17 10:35:20 DEBUG : wp-content/themes/Webly/includes/breadcrumbs.php: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:20 DEBUG : wp-content/themes/Webly/includes/breadcrumbs.php: Unchanged skipping
2017/07/17 10:35:20 DEBUG : wp-content/plugins/display-widgets/languages/display-widgets-ja.po: Modification times differ by -21923h40m55s: 2017-07-06 21:44:47 -0400 EDT, 2015-01-05 14:03:52 +0000 UTC
2017/07/17 10:35:20 DEBUG : wp-admin/css/colors/light/colors.css: src and dst identical but can't set mod time without deleting and re-uploading
2017/07/17 10:35:20 DEBUG : wp-content/themes/Trim/epanel/js/eye.js: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:20 DEBUG : wp-content/themes/Trim/epanel/js/eye.js: Unchanged skipping
2017/07/17 10:35:20 DEBUG : wp-content/themes/Webly/images/readmore.png: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:20 DEBUG : wp-content/themes/Webly/images/readmore.png: Unchanged skipping
2017/07/17 10:35:20 DEBUG : wp-content/themes/twentythirteen/header.php: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:20 DEBUG : wp-content/themes/twentythirteen/header.php: Unchanged skipping
2017/07/17 10:35:20 DEBUG : wp-admin/css/colors/light/colors.min.css: Modification times differ by 216h46m8s: 2016-11-28 23:11:52 -0500 EST, 2016-12-08 04:58:00 +0000 UTC
2017/07/17 10:35:20 DEBUG : wp-content/plugins/display-widgets/languages/display-widgets-ja.po: src and dst identical but can't set mod time without deleting and re-uploading
2017/07/17 10:35:20 DEBUG : wp-admin/css/colors/light/colors.min.css: src and dst identical but can't set mod time without deleting and re-uploading
2017/07/17 10:35:20 DEBUG : pacer: Reducing sleep to 33.059569ms
2017/07/17 10:35:21 DEBUG : pacer: Reducing sleep to 24.794676ms
2017/07/17 10:35:24 DEBUG : pacer: Reducing sleep to 18.596007ms
2017/07/17 10:35:24 DEBUG : pacer: Rate limited, increasing sleep to 37.192014ms
2017/07/17 10:35:24 DEBUG : pacer: low level retry 1/1 (error too_many_write_operations/..)
2017/07/17 10:35:24 DEBUG : pacer: Reducing sleep to 27.89401ms
2017/07/17 10:35:24 DEBUG : pacer: Rate limited, increasing sleep to 55.78802ms
2017/07/17 10:35:24 DEBUG : pacer: low level retry 1/1 (error too_many_write_operations/..)
2017/07/17 10:35:24 DEBUG : wp-content/plugins/adrotate-pro/library/license-functions.php: Received error: upload failed: too_many_write_operations/.. - low level retry 1/10
2017/07/17 10:35:24 DEBUG : pacer: Rate limited, increasing sleep to 111.57604ms
2017/07/17 10:35:24 DEBUG : pacer: low level retry 1/1 (error too_many_write_operations/)
2017/07/17 10:35:24 ERROR : wp-content/plugins/display-widgets/languages/display-widgets-ja.po: failed to delete before re-upload: too_many_write_operations/
2017/07/17 10:35:24 DEBUG : wp-content/plugins/display-widgets/languages/display-widgets-it_IT.mo: Received error: upload failed: too_many_write_operations/.. - low level retry 1/10
2017/07/17 10:35:24 DEBUG : pacer: Reducing sleep to 83.68203ms
2017/07/17 10:35:24 INFO  : wp-content/plugins/et-shortcodes/et-shortcodes.php: Copied (replaced existing)
2017/07/17 10:35:24 DEBUG : wp-content/themes/Trim/epanel/images/navigation-icon.png: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:24 DEBUG : wp-content/themes/Trim/epanel/images/navigation-icon.png: Unchanged skipping
2017/07/17 10:35:24 DEBUG : wp-content/themes/Webly/includes/entry.php: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:24 DEBUG : wp-content/themes/Webly/includes/entry.php: Unchanged skipping
2017/07/17 10:35:24 DEBUG : wp-content/plugins/display-widgets/languages/display-widgets-nl_NL.mo: Modification times differ by -16412h20m9s: 2017-07-06 21:44:47 -0400 EDT, 2015-08-23 05:24:38 +0000 UTC
2017/07/17 10:35:24 INFO  : wp-content/plugins/display-widgets/languages/display-widgets-fr_FR.po: Copied (replaced existing)
2017/07/17 10:35:24 DEBUG : wp-content/plugins/display-widgets/languages/display-widgets-nl_NL.mo: src and dst identical but can't set mod time without deleting and re-uploading
2017/07/17 10:35:24 DEBUG : wp-content/themes/Trim/epanel/js/functions-init.js: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:24 DEBUG : wp-content/themes/Trim/epanel/js/functions-init.js: Unchanged skipping
2017/07/17 10:35:24 DEBUG : wp-admin/css/colors/light/colors.scss: Modification times differ by -4587h19m44s: 2015-07-15 16:14:25 -0400 EDT, 2015-01-05 16:54:41 +0000 UTC
2017/07/17 10:35:24 DEBUG : wp-admin/css/colors/light/colors.scss: DropboxHash = de74b2d882c6bb9ae6ba971231338c15c1e9e75f123c1fd6056dac86ab03a2a7 (Local file system at /home/wordpress/Backup/pastorsnetwork.wpengine.com)
2017/07/17 10:35:24 DEBUG : wp-admin/css/colors/light/colors.scss: DropboxHash = b0378d908a7c5046ee35b39dc7b91d8fc2ee093427e00f7bd83382d8494584e0 (Dropbox root 'Backup/Sites/pastorsnetwork.wpengine.com')
2017/07/17 10:35:24 DEBUG : wp-admin/css/colors/light/colors.scss: DropboxHash differ
2017/07/17 10:35:24 DEBUG : pacer: Reducing sleep to 62.761522ms
2017/07/17 10:35:24 DEBUG : pacer: Reducing sleep to 47.071141ms
2017/07/17 10:35:25 DEBUG : pacer: Reducing sleep to 35.303355ms
2017/07/17 10:35:25 DEBUG : pacer: Reducing sleep to 26.477516ms
2017/07/17 10:35:25 INFO  : wp-content/plugins/display-widgets/languages/display-widgets-it_IT.mo: Copied (replaced existing)
2017/07/17 10:35:25 DEBUG : wp-content/themes/Trim/epanel/js/layout.js: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:25 DEBUG : wp-content/themes/Trim/epanel/js/layout.js: Unchanged skipping
2017/07/17 10:35:25 DEBUG : wp-content/themes/Webly/images/right-menu-bg.png: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:25 DEBUG : wp-content/themes/Webly/images/right-menu-bg.png: Unchanged skipping
2017/07/17 10:35:25 DEBUG : wp-content/themes/twentythirteen/image.php: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:25 DEBUG : wp-content/themes/twentythirteen/image.php: Unchanged skipping
2017/07/17 10:35:25 DEBUG : wp-content/themes/Trim/epanel/images/no.gif: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:25 DEBUG : wp-content/themes/Trim/epanel/images/no.gif: Unchanged skipping
2017/07/17 10:35:25 DEBUG : wp-content/themes/Webly/includes/featured.php: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:25 DEBUG : wp-content/themes/Webly/includes/featured.php: Unchanged skipping
2017/07/17 10:35:25 DEBUG : wp-content/plugins/display-widgets/languages/display-widgets-nl_NL.po: Modification times differ by -16412h20m9s: 2017-07-06 21:44:47 -0400 EDT, 2015-08-23 05:24:38 +0000 UTC
2017/07/17 10:35:26 DEBUG : wp-content/plugins/display-widgets/languages/display-widgets-nl_NL.po: src and dst identical but can't set mod time without deleting and re-uploading
2017/07/17 10:35:26 DEBUG : pacer: Rate limited, increasing sleep to 52.955032ms
2017/07/17 10:35:26 DEBUG : pacer: low level retry 1/1 (error too_many_write_operations/)
2017/07/17 10:35:26 DEBUG : wp-content/plugins/adrotate-pro/library/license-api.php: Received error: upload failed: too_many_write_operations/ - low level retry 1/10
2017/07/17 10:35:26 DEBUG : pacer: Reducing sleep to 39.716274ms
2017/07/17 10:35:26 INFO  : wp-content/plugins/adrotate-pro/library/raphael-min.js: Copied (replaced existing)
2017/07/17 10:35:26 DEBUG : wp-content/plugins/coming-soon/framework/css/font-awesome.css: Modification times differ by -2081h48m46s: 2017-05-19 18:40:03 -0400 EDT, 2017-02-22 04:51:17 +0000 UTC
2017/07/17 10:35:26 DEBUG : wp-content/plugins/coming-soon/framework/css/font-awesome.css: src and dst identical but can't set mod time without deleting and re-uploading
2017/07/17 10:35:26 DEBUG : pacer: Reducing sleep to 29.787205ms
2017/07/17 10:35:26 DEBUG : pacer: Reducing sleep to 22.340403ms
2017/07/17 10:35:26 INFO  : wp-content/plugins/adrotate-pro/library/license-functions.php: Copied (replaced existing)
2017/07/17 10:35:26 DEBUG : wp-content/themes/Webly/images/right-projects-bg.png: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:26 DEBUG : wp-content/themes/Webly/images/right-projects-bg.png: Unchanged skipping
2017/07/17 10:35:26 DEBUG : wp-content/themes/Trim/epanel/images/panel-top-bg.png: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:26 DEBUG : wp-content/themes/Trim/epanel/images/panel-top-bg.png: Unchanged skipping
2017/07/17 10:35:26 DEBUG : wp-content/themes/twentythirteen/index.php: Size and modification time the same (differ by 0s, within tolerance 1s)
2017/07/17 10:35:26 DEBUG : wp-content/themes/twentythirteen/index.php: Unchanged skipping
2017/07/17 10:35:26 DEBUG : wp-content/themes/twentyseventeen/inc/back-compat.php: Modification times differ by -3189h39m58s: 2017-06-08 23:33:38 -0400 EDT, 2017-01-27 05:53:40 +0000 UTC
2017/07/17 10:35:27 DEBUG : wp-content/themes/twentyseventeen/inc/back-compat.php: src and dst identical but can't set mod time without deleting and re-uploading
2017/07/17 10:35:27 DEBUG : pacer: Rate limited, increasing sleep to 44.680806ms
2017/07/17 10:35:27 DEBUG : pacer: low level retry 1/1 (error too_many_write_operations/.)
2017/07/17 10:35:27 DEBUG : wp-content/plugins/adrotate-pro/library/uploader-hook.js: Received error: upload failed: too_many_write_operations/. - low level retry 1/10
2017/07/17 10:35:27 DEBUG : pacer: Rate limited, increasing sleep to 89.361612ms
2017/07/17 10:35:27 DEBUG : pacer: low level retry 1/1 (error too_many_write_operations/..)
2017/07/17 10:35:27 DEBUG : wp-content/plugins/adrotate-pro/library/license-api.php: Received error: upload failed: too_many_write_operations/.. - low level retry 2/10
2017/07/17 10:35:27 DEBUG : pacer: Rate limited, increasing sleep to 178.723224ms
2017/07/17 10:35:27 DEBUG : pacer: low level retry 1/1 (error too_many_write_operations/)
2017/07/17 10:35:27 DEBUG : wp-content/plugins/adrotate-pro/library/textatcursor.js: Received error: upload failed: too_many_write_operations/ - low level retry 1/10
2017/07/17 10:35:27 DEBUG : pacer: Rate limited, increasing sleep to 357.446448ms
2017/07/17 10:35:27 DEBUG : pacer: low level retry 1/1 (error too_many_write_operations/...)
2017/07/17 10:35:27 ERROR : wp-content/plugins/coming-soon/framework/css/font-awesome.css: failed to delete before re-upload: too_many_write_operations/...
2017/07/17 10:35:27 DEBUG : pacer: Reducing sleep to 268.084836ms
2017/07/17 10:35:28 DEBUG : pacer: Reducing sleep to 201.063627ms
2017/07/17 10:35:28 DEBUG : pacer: Reducing sleep to 150.79772ms
2017/07/17 10:35:28 INFO  : wp-content/themes/twentythirteen/content.php: Copied (replaced existing)
@ncw
Copy link
Member

ncw commented Jul 17, 2017

Just upgraded to the latest beta to try out the new Dropbox v2 API. Thanks for all of your hard work! Much appreciated.

:-)

I'm noticing a lot of files being updated while syncing which haven't changed. I assume that's due to client_modified attribute now being applied correctly.

That is correct, yes.

While reviewing my log output it appears there is a high number of too_many_write_operations errors. They seem to self correct during a low level retry. It's happening frequently around every 5th or 6th file. Maybe this is normal behavior?

I saw a similar thing in my testing.

I think this is normal for multi-threaded uploads to dropbox. You can set --transfers to 1 and I expect they will disappear. However I think they are harmless and you should probably ignore them. Dropbox Docs here.

I haven't noticed it before the update. Sorta reminds me of the "lock held by connection" errors I would see in Dropbox v1 API. Not really affecting anything but there in the background.

I don't think the v1 API has the same concept.

@austinginder
Copy link
Author

Confirmed. Setting --transfers=1 significantly reduces the too_many_write_operations errors. It doesn't completely remove them but in my last batch I had 4 low level errors out of 2116 success. Again these were all successful as they were automatically retried. Thanks for the followup.

I think my main concern was that these errors were causing performance issues however it looks like that's being discussed in #1483. Will follow that issue.

@bulletmark
Copy link

I use rclone on Arch linux to sync a directory to Dropbox periodically. Today I started seeing heaps of these too_many_write errors. I checked my update log and see that rclone updated yesterday in the standard Arch packages:

2017-07-24 10:01 rclone 1.36-1 -> 1.37-1

Searching the web brings me to this bug. I added the --transfers=1 option and I get no errors but the sync is slower. @ncw given you say the messages are harmless, can you possibly change rclone to silently ignore them?

@tskeeley
Copy link

@ncw It looks like it's actually non-trivial. When I tested, I got the errors. So I ran again just to verify, and the same files had to upload still. The uploads were not truly in sync until after several more runs I finally got through without any errors. Only seems to be happening to files change, not new ones, if that helps at all.

@ncw
Copy link
Member

ncw commented Aug 11, 2017

@tskeeley this isn't under my control, alas, it is dropbox doing rate limiting. It might be that I could change the default pacer for dropbox to make it more reliable. Can you experiment with different values for --tpslimit to see if that makes a difference? For dropbox the limit is 100 normally, so try numbers smaller than that. You'll need a recent beta for that.

@tskeeley
Copy link

tskeeley commented Aug 11, 2017 via email

@FiloSottile
Copy link

FWIW, I had to set --tpslimit 1 for the errors to stop when deleting a big folder of pictures.

@nh2
Copy link
Contributor

nh2 commented May 1, 2021

While reviewing my log output it appears there is a high number of too_many_write_operations errors

For others who found this issue, this improvement looks very relevant: #5156 (comment)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants