I/O error on mount

I have an Amazon cloud drive that seems to be working fine.

I have an encrypted drive (“type=crypt, filename_encryption=off”) which also seems to work.

I know Amazon has size limits, so I make sure my file uploads are less than 5Gb in size.

I rclone sync my backup tree on a daily basis.

I thought I should compare the two trees…

rclone mount backups: /mnt/Amazon
diff -r /BACKUPS /mnt/Amazon

That threw up various I/O errors. Probably 95% of the files worked OK, but some files gave errors.

So I tried a single file that previously gave an error. To ensure no local caching, I umounted, remounted.

umount /mnt/Amazon
rclone mount backups: /mnt/Amazon
diff /mnt/Amazon/godzilla/20170924.root.0.gz_aa godzilla/20170924.root.0.gz_aa
diff: /mnt/Amazon/godzilla/20170924.root.0.gz_aa: Input/output error

This is one of the 5Gb files.

This appears to be pretty consistent.

Is there any way to debug why I’m getting this error?

Mount with -vv options and --log-file=/path/logfile.log

Hmm, stripping out things like Statfs and Attr entries

2017/10/23 08:45:22 DEBUG : godzilla/: Lookup: name="20170924.root.0.gz_aa"
2017/10/23 08:45:22 DEBUG : godzilla/: >Lookup: node=godzilla/20170924.root.0.gz_aa, err=<nil>
2017/10/23 08:45:22 DEBUG : godzilla/: Lookup: name="20170924.root.0.gz_aa"
2017/10/23 08:45:22 DEBUG : godzilla/: >Lookup: node=godzilla/20170924.root.0.gz_aa, err=<nil>
2017/10/23 08:45:22 DEBUG : godzilla/: Lookup: name="20170924.root.0.gz_aa"
2017/10/23 08:45:22 DEBUG : godzilla/: >Lookup: node=godzilla/20170924.root.0.gz_aa, err=<nil>
2017/10/23 08:45:22 DEBUG : godzilla/20170924.root.0.gz_aa: Open: flags=OpenReadOnly
2017/10/23 08:45:22 DEBUG : godzilla/20170924.root.0.gz_aa: >Open: fh=godzilla/20170924.root.0.gz_aa (r), err=<nil>
2017/10/23 08:45:22 DEBUG : godzilla/20170924.root.0.gz_aa (r): Read: len=16384, offset=0
2017/10/23 08:45:22 DEBUG : pacer: Rate limited, sleeping for 670.727727ms (1 consecutive low level retries)
2017/10/23 08:45:22 DEBUG : pacer: Rate limited, sleeping for 1.933251094s (2 consecutive low level retries)
2017/10/23 08:45:23 DEBUG : pacer: Rate limited, sleeping for 2.483687015s (3 consecutive low level retries)
2017/10/23 08:45:25 DEBUG : pacer: Rate limited, sleeping for 5.516701955s (4 consecutive low level retries)
2017/10/23 08:45:27 DEBUG : pacer: Rate limited, sleeping for 5.801288457s (5 consecutive low level retries)
2017/10/23 08:45:33 DEBUG : pacer: Rate limited, sleeping for 6.880535992s (6 consecutive low level retries)
2017/10/23 08:45:39 DEBUG : pacer: Rate limited, sleeping for 28.806288252s (7 consecutive low level retries)
2017/10/23 08:45:45 DEBUG : pacer: Rate limited, sleeping for 14.39624865s (8 consecutive low level retries)
2017/10/23 08:46:14 DEBUG : pacer: Rate limited, sleeping for 2m29.363380772s (9 consecutive low level retries)
2017/10/23 08:46:29 DEBUG : pacer: Rate limited, sleeping for 2m21.585429075s (10 consecutive low level retries)
2017/10/23 08:46:29 DEBUG : godzilla/20170924.root.0.gz_aa (r): Read: len=4096, offset=0
2017/10/23 08:48:58 DEBUG : pacer: Rate limited, sleeping for 1m4.788938057s (11 consecutive low level retries)
2017/10/23 08:51:20 DEBUG : pacer: Rate limited, sleeping for 2m55.106461073s (12 consecutive low level retries)
2017/10/23 08:52:24 DEBUG : pacer: Rate limited, sleeping for 1m35.140055565s (13 consecutive low level retries)
2017/10/23 08:55:20 DEBUG : pacer: Rate limited, sleeping for 2m54.004112026s (14 consecutive low level retries)
2017/10/23 08:56:55 DEBUG : pacer: Rate limited, sleeping for 1m42.271409579s (15 consecutive low level retries)
2017/10/23 08:59:49 DEBUG : pacer: Rate limited, sleeping for 2m50.127827215s (16 consecutive low level retries)
2017/10/23 09:01:31 DEBUG : pacer: Rate limited, sleeping for 1.032768916s (17 consecutive low level retries)
2017/10/23 09:04:21 DEBUG : pacer: Rate limited, sleeping for 3m11.91779461s (18 consecutive low level retries)
2017/10/23 09:04:22 DEBUG : pacer: Rate limited, sleeping for 1m18.214398905s (19 consecutive low level retries)
2017/10/23 09:07:34 DEBUG : pacer: Rate limited, sleeping for 3m5.05063977s (20 consecutive low level retries)
2017/10/23 09:07:34 DEBUG : godzilla/20170924.root.0.gz_aa (r): Flush: 
2017/10/23 09:07:34 DEBUG : godzilla/20170924.root.0.gz_aa (r): >Flush: err=<nil>
2017/10/23 09:07:34 DEBUG : godzilla/20170924.root.0.gz_aa (r): Release: 
2017/10/23 09:07:34 DEBUG : godzilla/20170924.root.0.gz_aa (r): >Release: err=<nil>

Not sure why I’m seeing so many rate limiting calls, and it’s definitely not sleeping for the period of time it claims

It would be worth trying rclone cryptcheck too - that should be much quicker.

Those logs look like it never read any data from that file.

Try cp it from the mount and see if it is OK.

Also try rclone copy the file and see if you can retreive it.

rclone copy doesn’t seem to be working, and if I do -vv then I see a lot of lines like

2017/10/23 13:22:07 DEBUG : pacer: low level retry 8/10 (error HTTP code 400: "400 Bad Request": response body: "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<Error><Code>InvalidArgument</Code><Message>Only one auth mechanism allowed; only the X-Amz-Algorithm query parameter, Signature query string parameter or the Authorization header should be specified</Message><ArgumentName>Authorization</ArgumentName><ArgumentValue>Bearer ....</ArgumentValue><RequestId>....</RequestId><HostId>....</HostId></Error>")

(where magic numbers replaced by …)

I don’t see that error with rclone -vv lsd backups:

I did see that error with the mount

I’m also seeing the problem if I try to get the encrypted data (Amazon:Backups/godzilla/....)

I am able to download it from the web site (it’s encrypted of course) and creating a local crypt filesystem with the same keys I was able to extract the file and compare it. So it’s stored correctly on ACD… just somehow rclone can’t get to it!

1 Like

Ah, you need to use --acd-templink-threshold 0 to fix the one auth mechanism problem

This is issue 1501 which I haven’t got around to fixing yet.

This stopped working for large files for some reason.

That fixed the problem :slight_smile:
rclone mount --acd-templink-threshold=0 backups: /mnt/Amazon &
allows me to verify the whole filesystem matches… and it did :slight_smile:

1 Like

Excellent. I really must fix #1501!