Failed to copy: read <file>: input/output error

What is the problem you are having with rclone?

A problem to copy (copyto, sync) local files to One Google.
Some part of my files is not copied with the message
Failed to copy: read : input/output error
Note:

  1. The same files are copied from one local directory to another local one
  2. The other files in the same directory are copied successfully, with the same RW properties, similar names (latin or cyrillic, with or without spaces)
  3. The files successfully copied are tens of thousands, not copied - hundreds, different sizes, types, names and so on.

What is your rclone version (output from rclone version)

rclone v1.55.0

  • os/type: linux
  • os/arch: amd64
  • go/version: go1.16.2
  • go/linking: static
  • go/tags: cmount

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

Linux Mint 64 bit

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

Google Drive

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

sudo rclone copyto /mnt/vol1/wxona/1/test/ drvlas:vol1/wcomm/wxona/1/test
sudo rclone sync -i /mnt/vol1/wxona/1/test/ drvlas:vol1/wcomm/wxona/1/test

The rclone config contents with secrets removed.

[drvlas]
type = drive
scope = drive
token = {"access_token":"...","token_type":"Bearer","refresh_token":"...","expiry":"2021-04-25T13:49:03.011640185+03:00"}

A log from the command with the -vv flag

2021/04/25 12:57:03 DEBUG : Using config file from "/home/<username>/.config/rclone/rclone.conf"
2021/04/25 12:57:03 DEBUG : rclone: Version "v1.55.0" starting with parameters ["rclone" "-vv" "copyto" "/mnt/vol1/wxona/1/test/" "drvlas:vol1/wcomm/wxona/1/test"]
2021/04/25 12:57:03 DEBUG : Creating backend with remote "/mnt/vol1/wxona/1/test/"
2021/04/25 12:57:03 DEBUG : Creating backend with remote "drvlas:vol1/wcomm/wxona/1/test"
2021/04/25 12:57:03 DEBUG : Google drive root 'vol1/wcomm/wxona/1/test': root_folder_id = "..." - save this in the config to speed up startup
2021/04/25 12:57:05 DEBUG : Google drive root 'vol1/wcomm/wxona/1/test': Waiting for checks to finish
2021/04/25 12:57:05 DEBUG : Google drive root 'vol1/wcomm/wxona/1/test': Waiting for transfers to finish
2021/04/25 12:57:06 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 1/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:06 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 2/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:06 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 3/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:06 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 4/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:06 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 5/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:06 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 6/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:06 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 7/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:06 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 8/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:06 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 9/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:06 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 10/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:06 DEBUG : bad.png: Reopen failed after 0 bytes read: failed to reopen: too many retries
2021/04/25 12:57:06 ERROR : bad.png: Failed to copy: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:07 DEBUG : good.jpg: MD5 = d37aaaa182d0a26b51a8eec0add81bb2 OK
2021/04/25 12:57:07 INFO  : good.jpg: Copied (new)
2021/04/25 12:57:07 ERROR : Attempt 1/3 failed with 1 errors and: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:07 DEBUG : Google drive root 'vol1/wcomm/wxona/1/test': Waiting for checks to finish
2021/04/25 12:57:07 DEBUG : good.jpg: Size and modification time the same (differ by -900.8µs, within tolerance 1ms)
2021/04/25 12:57:07 DEBUG : good.jpg: Unchanged skipping
2021/04/25 12:57:07 DEBUG : Google drive root 'vol1/wcomm/wxona/1/test': Waiting for transfers to finish
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 1/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 2/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 3/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 4/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 5/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 6/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 7/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 8/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 9/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 10/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopen failed after 0 bytes read: failed to reopen: too many retries
2021/04/25 12:57:08 ERROR : bad.png: Failed to copy: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 ERROR : Attempt 2/3 failed with 1 errors and: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : Google drive root 'vol1/wcomm/wxona/1/test': Waiting for checks to finish
2021/04/25 12:57:08 DEBUG : good.jpg: Size and modification time the same (differ by -900.8µs, within tolerance 1ms)
2021/04/25 12:57:08 DEBUG : good.jpg: Unchanged skipping
2021/04/25 12:57:08 DEBUG : Google drive root 'vol1/wcomm/wxona/1/test': Waiting for transfers to finish
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 1/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 2/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 3/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 4/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 5/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 6/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 7/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 8/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 9/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopening on read failure after 0 bytes: retry 10/10: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:08 DEBUG : bad.png: Reopen failed after 0 bytes read: failed to reopen: too many retries
2021/04/25 12:57:09 ERROR : bad.png: Failed to copy: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:09 ERROR : Attempt 3/3 failed with 1 errors and: read /mnt/vol1/wxona/1/test/bad.png: input/output error
2021/04/25 12:57:09 INFO  : 
Transferred:   	   34.627k / 34.627 kBytes, 100%, 12.638 kBytes/s, ETA 0s
Errors:                 1 (retrying may help)
Checks:                 2 / 2, 100%
Transferred:            1 / 1, 100%
Elapsed time:         5.8s

2021/04/25 12:57:09 DEBUG : 6 go routines active
2021/04/25 12:57:09 Failed to copyto: read /mnt/vol1/wxona/1/test/bad.png: input/output error

That looks like rclone is having trouble with the /mnt/vol1/. What kind of mount is this? is it an rclone mount or a local disk or something else?

If it is a local disk then check dmesg to see if there are errors in there.

Hi ncv,
Thanks for your answer!
The /mnt/vol1 is a local NAS disk mounted with mount -t cifs -o ... command
This setup work for years already.
No errors in my dmesg, no messages at all after the first 23 seconds at the startup.
Please note, the other (thousands) of files are copied OK. And when I do test rclone copyto between 2 NAS directories - it's OK.
So, we have some "good" files from the /mnt/vol1/ and some "bad ones - but the "bad ones are "good" if I copy them locally.

Hmm CIFS - we've had several reports of oddities with rclone and CIFS. This might be related. It is something to do with a bug in the CIFS driver in the linux kernel.

There is a workaround though - try

export GODEBUG=asyncpreemptoff=1

See

For background.

This might be a different problem of course!

Hi Nick,
I'm not sure that issue with GO is clear for me and whether it may be applied in my case.
But sure I've tried: set the env

$ echo $GODEBUG
asyncpreemptoff=1

and repeated the rclone copyto command. The same result.
Is it of any importance: the same directory copied to the other volume on my NAS:

$ sudo rclone -vv copyto /mnt/vol1/wxona/1/test/ /mnt/vol2/ksona/1/test
2021/04/25 20:11:19 DEBUG : Using config file from "/home/vpe/.config/rclone/rclone.conf"
2021/04/25 20:11:19 DEBUG : rclone: Version "v1.55.0" starting with parameters ["rclone" "-vv" "copyto" "/mnt/vol1/wxona/1/test/" "/mnt/vol2/ksona/1/test"]
2021/04/25 20:11:19 DEBUG : Creating backend with remote "/mnt/vol1/wxona/1/test/"
2021/04/25 20:11:19 DEBUG : Creating backend with remote "/mnt/vol2/ksona/1/test"
2021/04/25 20:11:19 DEBUG : Local file system at /mnt/vol2/ksona/1/test: Waiting for checks to finish
2021/04/25 20:11:19 DEBUG : Local file system at /mnt/vol2/ksona/1/test: Waiting for transfers to finish
2021/04/25 20:11:19 DEBUG : preAllocate: got error on fallocate, trying combination 1/2: operation not supported
2021/04/25 20:11:19 DEBUG : preAllocate: got error on fallocate, trying combination 2/2: operation not supported
2021/04/25 20:11:19 DEBUG : cat.jpg: MD5 = 4118856346fd5a072595fe9c0d195dab OK
2021/04/25 20:11:19 INFO  : cat.jpg: Copied (new)
2021/04/25 20:11:19 DEBUG : good.jpg: MD5 = d37aaaa182d0a26b51a8eec0add81bb2 OK
2021/04/25 20:11:19 INFO  : good.jpg: Copied (new)
2021/04/25 20:11:19 DEBUG : bad (copy).png: MD5 = 4288ae696a478f95892655480db6841f OK
2021/04/25 20:11:19 INFO  : bad (copy).png: Copied (new)
2021/04/25 20:11:19 DEBUG : bad.png: MD5 = 4288ae696a478f95892655480db6841f OK
2021/04/25 20:11:19 INFO  : bad.png: Copied (new)
2021/04/25 20:11:19 INFO  : 
Transferred:   	    1.884M / 1.884 MBytes, 100%, 23.965 MBytes/s, ETA 0s
Transferred:            4 / 4, 100%
Elapsed time:         0.1s

2021/04/25 20:11:19 DEBUG : 2 go routines active

All files are OK!

No it wasn't 100% clear to me either!

:frowning:

That is suprising as it will be the same code in each case.

Can you try running the command with strace so something like

strace rclone -vv copyto /mnt/vol1/wxona/1/test/ drvlas:vol1/wcomm/wxona/1/test 2>&1 | tee rclone-strace.log

And attach the log? I want to see exactly what the OS is telling rclone.

Hi Nick,
I'm, awfully sorry for not noticing your answer!
Attaching the log
strace-rclone.log

I don't think there is quite enough stuff in that strace log - it appeared to go wrong half way through?

Hi Nick,
Sorry for a bad file.
Today I've checked rclone on the other directory, it works. Then I issued the command you've gave, with sudo:

sudo strace rclone -vv copyto /mnt/vol1/wxona/1/test/ drvlas:vol1/wcomm/wxona/1/test 2>&1 | tee rclone-strace-2021-0608.log

The log is ready, but I cannot up;load it here - it says new users cannot upload files

https://drive.google.com/file/d/1EE_ZABPq1h_PTLGa4RA80xatImKn1-gd/view?usp=sharing

I sent you a request to view the log file - it didn't seem to be public?

I believe I've shared it with you.
It's just because I cannot attach the file here.

I've got it - thanks.

I was looking through that for any EIO errors but I don't see any. :frowning:

Can you try adding -f to your strace command line please?

Hi Nick,
Here is the log with -f option.
(my own attempts to make heads or tails of it - fruitless. So happy that you keep trying!)

Hope the file has the right properties:

Sorry, that needed to be

strace -f rclone -vv copyto /mnt/vol1/wxona/1/test/ drvlas:vol1/wcomm/wxona/1/test 2>&1 | tee rclone-strace-2021-0608.log

As in the -f parameter goes on the strace, not on rclone - I should have been clearer - apologies.

Hi Nick,

Here you are:

Thanks for that.

The errors are definitely being caused by the read side of the equation

[pid 21501] <... read resumed> 0xc000d80000, 16777216) = -1 EIO (Input/output error)

They don't seem to be synchonised with SIGURG which the export GODEBUG=asyncpreemptoff=1 would fix.

Not all the errors are after a resume, there is one straight error

[pid 21500] read(11, 0xc000d76000, 16777216) = -1 EIO (Input/output error)

This is looking like either a Go bug or a kernel bug or a bad interaction between the two.

Can you try a different machine to see if it has the same problem? Or a different kernel?

Ouph! Another PC after rclone installed and GODEBUG=asyncpreemptoff=1 set: