Onedrive : errors when syncing/copying

[fbastok]

Using onedrive on MacOS Sierra with rclone 1.33.
Especially with folders containing a lot of files (and especially with large ones like movies or software), I can't complete the copy because I get some errors.
Some logs :

2016/11/01 11:07:41 Movies/Toy Story Toons_ Hawaiian Vacation/Toy Story Toons_ Hawaiian Vacation (HD).m4v: Uploading segment 94371840/234431669 size 10485760
2016/11/01 11:07:48 Couldn't decode error response: invalid character '<' looking for beginning of value
2016/11/01 11:07:48 pacer: Rate limited, increasing sleep to 20ms
2016/11/01 11:07:48 pacer: low level retry 1/10 (error 503 Service Unavailable: )
2016/11/01 11:07:48 pacer: Reducing sleep to 15ms
2016/11/01 11:07:48 Mobile Applications/AIR RACE 1.74 1.ipa: Cancelling multipart upload
2016/11/01 11:07:48 pacer: Reducing sleep to 11.25ms
2016/11/01 11:07:48 Mobile Applications/AIR RACE 1.74 1.ipa: Failed to copy: Put https://api.onedrive.com/up/eyJSZXNvdXJjZUlEIjoiNzlGNDY1NEQxQkE0MDc1MyE0MzM2OSIsIlJlbGF0aW9uc2hpcE5hbWUiOiJBSVIgUkFDRSAxLjc0IDEuaXBhIn0/3mH_bu4oxlLxXb9HHmyTv_gpPPfgNWBMQnWRN83pBuVJrqGrZPMv9hdLyyIp8N0Wbl/eyJOYW1lIjoiQUlSIFJBQ0UgMS43NCAxLmlwYSJ9/3wYBV0iMr46yENesCJ0xvNTVpK2CQAtivBMe_RuO6iU24CkO4DJRfbBiH3T1YFKC1XJ1pKDKKpjKWLDv15JlJpnBJAnvaxH-DhJQhQIO_belAAzkDg_k50zPnDYPW0uUu5RM24Z1qthsIRZYbp_AxGF5KW_cZdClPA8Jdsetfc4n9ex7krcxpFoseIbCMyTXnW5FFTd9/0M7UuLA_4xLSy6s5h8_d3dvtuISUlDTd667JBIFMlES0C5gpm0JKT2fWGRRqyKd1hBVHx5B2XVGuimAYQukJaFQ1Fy3hMGF3wlXJ4BCWnBYgrZTrRvStQkewadl1ksSPSWyCuNBJY-Dj9sSsn327JA-m5_IesAzE7v7dthwrrrUUC-jnp983rE0L0D2BBxiZiR-HWgmQ/ti3UGU2vktTY_89tA2cautyH-jcwFCMpO3y1E5OqFCcMsHRFbPfWeUsTwBrY34YRPq3EKn0A: http: ContentLength=10485760 with Body length 0
2016/11/01 11:07:48 Mobile Applications/AIR RACE 1.74 1.ipa: Removing failed copy
2016/11/01 11:07:49 pacer: Reducing sleep to 10ms
2016/11/01 11:07:49 Mobile Applications/AIR RACE 1.74 1.ipa: Failed to remove failed copy: invalidRequest: API not found

[fbastok]

Another type of issue linked to this seems to be related to the length of the file name. Example:

2016/11/04 09:18:59 Music/Les Enfoirés/La Boîte À Musique Des Enfoirés/2-01 La Mode_ Le Sens De La Vie _ Call Me Maybe _ C'est Beau La Bourgeoisie _ Ai Se Eu Te Pego _ Et Alors _ Gangnam Style _ À La Pêche Aux Moules (Chanson Enfantine).mp3: Failed to copy: invalidRequest: Bad Argument
2016/11/04 09:18:59 Music/Les Enfoirés/La Boîte À Musique Des Enfoirés/2-05 Un Collège Au Théâtre_ Les Yeux d'Elsa _ T'es OK _ Heureux Qui Comme Ulysse _ C'est Ma Terre _ Tirade Du Nez _ Mignon, Mignon _ On Ne Badine Pas Avec L'amour _ À Ma Place _ La Langue De Chez Nous.mp3: Failed to copy: invalidRequest: Bad Argument

I tought this limitation of path length was gone in one drive.

[ncw]

Can you try v1.34 please?

And if you could capture some logs of the things going wrong with --dump-headers that would be very useful - that should hopefully tell us what is going on.

As for lengths - those look rather short to be causing a problem. It might be that this is a file name encoding problem fixed in 1.34.

[fbastok]

Nick, first tests show improvement. the error Failed to copy: invalid request seems gone. But the errors pacer: low level retry seems still to be there. I will post more info tomorrow.

[ncw]

A few low level retries is normal. Can you post some logs?

[fbastok]

command line:

/Users/fbastok/Downloads/rclone-v1.34-osx-amd64/rclone -v --dump-headers sync "/Users/Shared/iTunes Media" onedrive-backup:Backup/iTunesMedia 2>Desktop/rclone_errors.txt >Desktop/rclone_verbose.txt
See attached file for the logs
rclone_errors.txt
rclone_verbose.txt

[guilhermebf]

I'm getting the same errors. The "size differs" problem was resolved using the --ignore-size flag (#399)

[ncw]

@fbastok I looked rclone_errors.txt and I see this eror

2016/11/10 07:55:30 Music/Les Enfoirés/La Boîte À Musique Des Enfoirés/2-01 La Mode_ Le Sens De La Vie _ Call Me Maybe _ C'est Beau La Bourgeoisie _ Ai Se Eu Te Pego _ Et Alors _ Gangnam Style _ À La Pêche Aux Moules (Chanson Enfantine).mp3: Failed to copy: invalidRequest: Bad Argument
2016/11/10 07:55:30 Music/Les Enfoirés/La Boîte À Musique Des Enfoirés/
Music/Les Enfoirés/La Boîte À Musique Des Enfoirés/2-05 Un Collège Au Théâtre_ Les Yeux d'Elsa _ T'es OK _ Heureux Qui Comme Ulysse _ C'est Ma Terre _ Tirade Du Nez _ Mignon, Mignon _ On Ne Badine Pas Avec L'amour _ À Ma Place _ La Langue De Chez Nous.mp3: Failed to copy: invalidRequest: Bad Argument

Do these files always fail to transfer? I tried transferring a file with that name and directory structure and it worked fine. What is the original name on your hard disk?

in rclone_verbose.txt I couldn't see any problems. I saw a few retries from 502 gateway errors but these are normal.

[fbastok]

Yes, they always fail to transfert. It's the original name on the hard drive
the full directory:
/Users/Shared/iTunes Media/Music/Les Enfoirés/La Boite À Musique Des Enfoirés/2-01 La Mode_ Le Sens De La Vie _ Call Me Maybe _ C'est Beau La Bourgeoisie _ Ai Se Eu Te Pego _ Et Alors _ Gangnam Style _ À La Pêche Aux Moules (Chanson Enfantine).mp3

[fbastok]

@guilhermebf let me try that and I will post the results

[fbastok]

Command line:
/Users/fbastok/Downloads/rclone-v1.34-osx-amd64/rclone -v --ignore-size --dump-headers sync "/Users/Shared/iTunes Media" onedrive-backup:Backup/iTunesMedia 2>Desktop/rclone_errors.txt >Desktop/rclone_verbose.txt

Some errors:

Errors: 0
Checks: 9829
Transferred: 84
Elapsed time: 15m1.3s
Transferring:

• ...19 Tableau L'Eurovision Des Enfoirés.mp3: 23% done. avg: 38.8, cur: 2364.3 kByte/s. ETA: 14s
• ...Enfoirés/18 Tableau Le Train Fantôme.mp3: 57% done. avg: 73.7, cur: 1164.3 kByte/s. ETA: 12s
• ...és/20 Tableau Une Etrange Expo Photo.mp3: 35% done. avg: 40.3, cur: 4023.4 kByte/s. ETA: 4s
• ...és/21 Les Conseils Musicaux De Michaël.mp3: 31% done. avg: 42.1, cur: 8941.9 kByte/s. ETA: 2s

2016/11/20 09:38:42 Music/Les Enfoirés/Au rendez-vous des Enfoirés/20 Tableau Une Etrange Expo Photo.mp3: Failed to copy: Put https://api.onedrive.com/up/eyJSZXNvdXJjZUlEIjoiNzlGNDY1NEQxQkE0MDc1MyE1MDA1NCIsIlJlbGF0aW9uc2hpcE5hbWUiOiIyMCBUYWJsZWF1IF9VbmUgRXRyYW5nZSBFeHBvIFBob3RvXy5tcDMifQ/3mukilpSox_6cuvtrjFWBz4IxU9-y6380LSzsb4UVQ_yNnwzWyVzY6czxC6B_4_Mhu/eyJOYW1lIjoiMjAgVGFibGVhdSBfVW5lIEV0cmFuZ2UgRXhwbyBQaG90b18ubXAzIn0/3wW7rIzJinu-cQDBOfWZctNCQhPEjqfzeXcapVlwv8735Bp5dkKHin6DDM7ZDFygBoFUTVnbt5oJ92uFreLFV4jEDTroeykhW7EwVIWrvllNiutSv-BkGNYJsdfHhCvXcZj6MfucpXn8i4fdLAA-DE6JNv9HiZtcN1sqPhYKKErRiRDHvI4CuQleMFAc_ElTvf4gmb-5/SqIAhqqwmBfOyFtSKb5_uniHYNjualaAmBaImPDWGZhVdvHLeXoXc96Z8WxC_is0FTwJ0wH7OUpgZa0Jt9YlgrHrwQ_A71hAgvfK4n7n-PexUwnZs3ulnHmIwSMW4dfeV21rFeDvP_rX8ueg8t0F946jID4VffuiqEVogK6aBda9J3CUZKcEbve5EqvWO72lCT2Q2nzH/f2ekYbriiBhlXpisyB39Gg8szyQr9zn7vO1eja28w3fyRkjSq-QXMcf1soL6kCSMaT2zLNBg: read tcp 192.168.1.243:50241->204.79.197.213:443: read: network is down
2016/11/20 09:38:42 Music/Les Enfoirés/Au rendez-vous des Enfoirés/18 Tableau Le Train Fantôme.mp3: Failed to copy: Put https://api.onedrive.com/up/eyJSZXNvdXJjZUlEIjoiNzlGNDY1NEQxQkE0MDc1MyE1MDA1NCIsIlJlbGF0aW9uc2hpcE5hbWUiOiIxOCBUYWJsZWF1IF9MZSBUcmFpbiBGYW50w7RtZV8ubXAzIn0/3mEdPnbYI0ulDBhf6TZzC0VQ9VsPIljeMwUFw7IcqJvjkZ2Kg9C6kN7cJk43snf3C_/eyJOYW1lIjoiMTggVGFibGVhdSBfTGUgVHJhaW4gRmFudMO0bWVfLm1wMyJ9/3wqSDXpV8UJhdV-rh01rP59fMfc5rVmdl7PEArivi2WlbNxCo6a37DQy7vgpLMowIVuMrFdntOFObnS7VdU8DecEGBDw5tTbBqwUQ7Fb34YQQ93dtw4dntAz1yUE8SdxD5O5eH-SUDPFa0IbF-DFxJ_aXSqRHi6q2nM6R7vyI685AEh7I7sVsOYdt0AeGhiGCrYWUTpn/JsHHlyqR4RJjsIm0zYPP0ADIYi9uSTIZ6pv-oqCnWayDxOOT4fhpo5-K-mF1X25ODaomZd4qjUSPhdl3a3JP2-LKB-dBwZQBT9ojg4jIRJG3aVY8gqcrUDhCcc_DZxAs5LGtUqrWCCo2k1Sxia4--wOlXSOOM3t5iLpMNKWS4ov-PdgIcIApmTLxehWsv5o5cQKBm4kd/FSBfgBzc3MrZnBrhh3AnnZBV24AwCtshRZavFBiNTHlsqHfuOev5xT5fmgAVmP-3fUj2nVeg: read tcp 192.168.1.243:50244->204.79.197.213:443: read: network is down
2016/11/20 09:39:25 Music/Les Enfoirés/La Boite À Musique Des Enfoirés/2-01 La Mode_ Le Sens De La Vie _ Call Me Maybe _ C'est Beau La Bourgeoisie _ Ai Se Eu Te Pego _ Et Alors _ Gangnam Style _ À La Pêche Aux Moules (Chanson Enfantine).mp3: Failed to copy: invalidRequest: Bad Argument
2016/11/20 09:39:25 Music/Les Enfoirés/La Boite À Musique Des Enfoirés/2-04 La Soirée Diapos_ Le Coup De Soleil _ Regarde-Moi Bien En Face _ À Présent, Tu Peux T'en Aller _ Rien Que De L'eau _ C'est Dit.mp3: Failed to copy: invalidRequest: Bad Argument
2016/11/20 09:39:27 Music/Les Enfoirés/La Boite À Musique Des Enfoirés/2-05 Un Collège Au Théâtre_ Les Yeux d'Elsa _ T'es OK _ Heureux Qui Comme Ulysse _ C'est Ma Terre _ Tirade Du Nez _ Mignon, Mignon _ On Ne Badine Pas Avec L'amour _ À Ma Place _ La Langue De Chez Nous.mp3: Failed to copy: invalidRequest: Bad Argument
2016/11/20 09:39:27
Transferred: 744.799 MBytes (793.324 kBytes/s)
Errors: 5
Checks: 9860
Transferred: 85
Elapsed time: 16m1.3s

[ncw]

I'm not having much luck reproducing this. Can you make a log with -v --dump-headers too please and post the relevant section here, or email the whole lot to me at nick@craig-wood.com if you prefer with the subject "rclone log for issue 846" - thanks

[fbastok]

Attached rclone_versbose and rclone_errors, using --dump-headers.
Command line is the one above.
rclone_errors.txt
rclone_verbose.txt

[fbastok]

Back to the first issue I had. I tried to upload one file at a time.
The error "Couldn't decode error response: invalid character '<' looking for beginning of value" cancel the upload and so it never completes.
I get this always at some point during the upload:

Transferring:

• ...g.2006.FRENCH.720p.BluRay.x264-AiRLiNE.mkv: 14% done. avg: 919.1, cur: 1082.1 kByte/s. ETA: 1h0m26s

2016/11/22 10:37:26 Camping 2006 FRENCH/Camping.2006.FRENCH.720p.BluRay.x264-AiRLiNE.mkv: Uploading segment 671088640/4689143360 size 10485760
2016/11/22 10:37:36 Camping 2006 FRENCH/Camping.2006.FRENCH.720p.BluRay.x264-AiRLiNE.mkv: Uploading segment 681574400/4689143360 size 10485760
2016/11/22 10:38:19
Transferred: 660 MBytes (865.315 kBytes/s)
Errors: 0
Checks: 26
Transferred: 0
Elapsed time: 13m1s
Transferring:

• ...g.2006.FRENCH.720p.BluRay.x264-AiRLiNE.mkv: 14% done. avg: 874.3, cur: 80.5 kByte/s. ETA: 13h28m1s

2016/11/22 10:38:46 Couldn't decode error response: invalid character '<' looking for beginning of value
2016/11/22 10:38:46 pacer: Rate limited, increasing sleep to 20ms
2016/11/22 10:38:46 pacer: low level retry 1/10 (error 503 Service Unavailable: )
2016/11/22 10:38:46 pacer: Reducing sleep to 15ms
2016/11/22 10:38:46 Camping 2006 FRENCH/Camping.2006.FRENCH.720p.BluRay.x264-AiRLiNE.mkv: Cancelling multipart upload
2016/11/22 10:38:46 pacer: Reducing sleep to 11.25ms
2016/11/22 10:38:46 Camping 2006 FRENCH/Camping.2006.FRENCH.720p.BluRay.x264-AiRLiNE.mkv: Failed to copy: Put https://api.onedrive.com/up/eyJSZXNvdXJjZUlEIjoiNzlGNDY1NEQxQkE0MDc1MyE0NzQzNTkiLCJSZWxhdGlvbnNoaXBOYW1lIjoiQ2FtcGluZy4yMDA2LkZSRU5DSC43MjBwLkJsdVJheS54MjY0LUFpUkxpTkUubWt2In0/3mszD8tbSGYdg5xb5uA-WDmIzA2zSH3RsYqykhV1Dcl99Yf8bHNpB6DUz2wnuVaW1Y/eyJOYW1lIjoiQ2FtcGluZy4yMDA2LkZSRU5DSC43MjBwLkJsdVJheS54MjY0LUFpUkxpTkUubWt2In0/3wd3g4W3t9JBfq5_mY8cgnSc5_nu-5HaP0y6t7TZi_rbUZYajHJWE0jz7ddXOmK7KqlS2C41QSpWfkjbQ_5MOH-eogv3OoPawEri2nzsfdxhEEjFrpRiPZOPntPYcDYhMX-MvsOT7i_BGHvIH-iwq9Soi1enbCrHRGT_jyUcbvJBEAmSffu9cIM7BWRJXjFDe9NJN2Qx/rNJFItwhYWVx34GOR3eZjwAcihZN4VEDQKHsMvX699ANR9xdZP33Twfidj6n4G6geDpehsCdWRhY0oEyW9pkwgJggg30VEd7FdrFWJH5HTjrcttHBKSWhBGdvjFdVPvkD7ytF5Ori3BRc7Tv4gexCDiW1YO8UPAWXBvUyLfGnLhomTihih-TNTCCZLSjymKAA7tNuYoX/dAKtZbYmm4fc1whImk0reeWvrWZapO9V08RuArQpicxiYO-wL4-6Sc903-SYm2oe7v5zISQg: http: ContentLength=10485760 with Body length 0

[fbastok]

I was able to upload the file Campingxxx.mkv above after a few tries. So it seems not to always happen. Won't be easy to fix.
the next 5 movies I tried to upload didn't work. The same error as above

[fbastok]

I replicated the same behavior in Linux (linux mint 18). Same errors.

[Timber232]

I'm having this exact problem. Any updates?

[ncw]

@yonjah you've been looking at onedrive stuff recently - what do you think of this?

[yonjah]

@Timber232 Have you tested it with the latest version ?
The body length 0 issue should have been fixed at 1.36.
I saw a few issues where body length was mismatched but I haven't noticed it much and haven't had a chance to reproduce it (it wasn't recurring).

[Cnly]

Closing because this is too obsolete.