Too many "corrupted on transfer : sizes differ"

Help and Support
1

Hi,
rclone is great.
I’m using rclone on many differnt computers (Mac OSX 10.13.1, Lubuntu 17.10 64bits, Lubuntu 17.10 32 bits, and Windows 10 64 bits), and I’m using it with Hubic.

My rclone version on OSX is v1.39, and it’s probably similar on other systems as I installed them at the same time. I’ll check that if you need to know.

I’m using a command of this kind
rclone copy src dir --checksum --eclude ‘.*’

9 times out of 10 I get those “corrupted on transfer: sizes differ” errors. I’m surprised files get corrupted so often. Some times the sizes differ A LOT for example this traces :

2018/03/06 22:42:51 ERROR : notes/LubuntuRevoRL80.txt: corrupted on transfer: sizes differ 3273 vs 1998
2018/03/06 22:42:52 ERROR : Attempt 1/3 failed with 1 errors and: corrupted on transfer: sizes differ **3273 vs 1998**
2018/03/06 22:43:02 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/06 22:43:02 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/06 22:43:02 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/06 22:43:24 ERROR : Attempt 2/3 succeeded

What is even more a problem, is that when all 3 attempts fail, the destination file is deleted. I saw it while copying remote files to my Mac OSX, the 3 attempts failed, and my local fil disappeared.
The “corrupted on transfer” errors happen on ALL my systems, with the same frequency.
Any thoughts about this ? Is it a specific problem with Hubic ?

2

That might indicate that the transfer was interrupted somehow, or it might indicate that the file is corrupt on the cloud provider.

Does it happen to the same files? Do you always get the same numbers x vs y?

Are those files in use, or being copied from elsewhere?

Can you try with the latest beta please?

3

As far as I can remember, it happens randomly on any of my files (I manage about 10 files) and no the numbers x vs y can be very different, sometimes it can be huge difference (9000 vs 30000 for example).

But one of the files I copy, is in used (it’s a script upload.sh or download.sh). Next time I use rclone, I’ll check if it happens only to those files in use, but as far as I can remember it’s not the case.

I’ll use the latest beta and let you know.

Is the fact that the destination file is removed after the 3rd attempt failed is an intended behaviour or is it something to fix ?

4

So I did the test, I installed the latest beta.
My rclone -V gives
rclone v1.39-213-gb3f55d6bβ
- os/arch: darwin/amd64
- go version: go1.10

I modified a file locally. I added just one more character at the end of the file.Then I tried to copy it to remote (still with copycommand). And again a corrupted transfer occured on first attempt. What’s interesting to note is that it’s a 2926 vs 2925 2926 being the size of the newly modificated file, and 2925 the size of the old file.

2018/03/08 15:24:32 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/08 15:24:32 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/08 15:24:32 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/08 15:24:32 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/08 15:24:32 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/08 15:24:33 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/08 15:24:56 ERROR : notes/LubuntuMacbook.txt: corrupted on transfer: sizes differ 2926 vs 2925
2018/03/08 15:24:57 ERROR : Attempt 1/3 failed with 1 errors and: corrupted on transfer: sizes differ 2926 vs 2925
2018/03/08 15:25:08 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/08 15:25:13 ERROR : Attempt 2/3 succeeded

I added again 1 character at the end of the file (new size=2927), and I uploaded again, and got about the same kind of error :

2018/03/08 15:31:48 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/08 15:31:48 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/08 15:32:16 ERROR : notes/LubuntuMacbook.txt: corrupted on transfer: sizes differ 2927 vs 2926
2018/03/08 15:32:16 ERROR : Attempt 1/3 failed with 1 errors and: corrupted on transfer: sizes differ 2927 vs 2926
2018/03/08 15:32:27 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 408 Request Time-out\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n<html><body><h1>408 Request Time-out</h1>\nYour browser didn't send a complete request in time.\n</body></html>\n"; err=<nil>
2018/03/08 15:33:05 ERROR : Attempt 2/3 succeeded

I did it again (size 2928), but this time, it went without ANY errors, not even the “Unsolicited response received” errors.

I did it again (size 2929), no errors at all.

I did it again (size 2930), I received 2 “Unsolicited response received” but not “corrupted transfer” errors.

I did it again (size 2931), I received 3 “Unsolicited response received” but not “corrupted transfer” errors.

I did i’t again (size 2932à, no errors at all.

So it happens very often, but not all the time. And it seems not to be related to the “Unsolicited response received”.

5

rclone would rather you had no file than a corrupted one, so yes that is the intended behaviour.

So it happens very often, but not all the time.

Interesting…

And it seems not to be related to the “Unsolicited response received”.

Those are hubic sending a message when closing idle HTTP connections which it shouldn’t do, but it is harmless.

What’s interesting to note is that it’s a 2926 vs 2925 2926 being the size of the newly modificated file, and 2925 the size of the old file.

That is making me thing it is to do with the eventual consistency of swift. What rclone does is it uploads an object, then it reads it checksum and size to check it was uploaded OK. What it looks like is that sometimes you are getting the old size back from the old, now overwritten object. Does that make sense?

In Swift terms rclone does a PUT to upload the object then does a HEAD to read info about it. I thought this was always supposed to be consistent - it certainly has been in all my testing.

Anyway, it looks like from your logs that this is always cleared up within 3 retries so you can just ignore it if you want to and rclone will get there in the end.