Problem with copy from samba share

Suspected Bug
1

I have a NAS (Dlink-327L).
I want to make backup from the nas to b2 with a raspberry pi.
I have mounted the nas with cifs specified in the /etc/fstab file.
When I try to copy the files from the nas to b2 then I got the following error for some files, not all off them:
2017/07/20 09:57:53 ERROR : IMG_0669.jpg: Failed to copy: Post https://pod-000-1042-10.backblaze.com/b2api/v1/b2_upload_file/379c8abbb80458c05cde0118/c001_v0001042_t0039: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
2017/07/20 09:57:53 ERROR : Attempt 1/3 failed with 1 errors and: Post https://pod-000-1042-10.backblaze.com/b2api/v1/b2_upload_file/379c8abbb80458c05cde0118/c001_v0001042_t0039: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error

I have tested this with rclone 1.6 and also with v1.36-259-g0cf19ef6β
If I try to copy the same file from the /home/pi directory then rclone sucessfully copy the file to b2.

If I make a file on the cifs share with echo “hello” > file1. Then it can also sucessfully copy it to b2.
Could it be an issue or what do you think?

The command I’ve run:
./rclone -v -v -v copy /mnt/photos/photos/2008/teszt/ b2:nasclone

Thanks in advance.

2

That looks like a problem with the CIFS mount. Can you check its logs to see what the problem is?

3

I can’t find anything in the log and I can also copy this file with cp command and then I can view the image.

4

That error comes from the OS via the CIFS mount - there should be a log about it somewhere! (check dmesg also)

5

I’ve checked /var/log/syslog, dmesg, /var/log/messages.
The only thing I have found was a line:
Status code returned 0xc0000016 NT_STATUS_MORE_PROCESSING_REQUIRED

But this isnt’t lead to anything in google.

The other thing which bothers me, the fact that th “cp” command is working. I can cp all of the files from cifs share to my home directory. These are the same files that can’t be synced to b2 with rclone.
So how can it be a cifs error this input/output error if the cp command is working.
Thanks in advance.

6

I think that error is in the CIFS handshake so isn’t related.

cp doesn’t necessarily use the same system calls that rclone does to copy files.

One thing worth trying would be a local rclone copy

so try

rclone -vv copy /mnt/photos/photos/2008/teszt/ /tmp/teszt

anc see if that works and if not post the log.

If it doesn’t work, you could post the log of

strace rclone -vv copy /mnt/photos/photos/2008/teszt/ /tmp/teszt

Which would at least show us which system call is going wrong.

7

Result of the 1st command:
pi@raspberrypi:~ $ rclone -vv copy /mnt/photos/photos/2008/teszt/ /tmp/teszt
2017/07/21 12:56:14 DEBUG : rclone: Version “v1.36” starting with parameters [“rclone” “-vv” “copy” “/mnt/photos/photos/2008/teszt/” “/tmp/teszt”]
2017/07/21 12:56:14 INFO : Local file system at /tmp/teszt: Modify window is 1ns
2017/07/21 12:56:14 INFO : img.jpg: Copied (new)
2017/07/21 12:56:14 INFO : tesztfikle: Copied (new)
2017/07/21 12:56:14 INFO : Local file system at /tmp/teszt: Waiting for checks to finish
2017/07/21 12:56:14 INFO : Local file system at /tmp/teszt: Waiting for transfers to finish
2017/07/21 12:56:14 NOTICE: IMG_0669.jpg: Removing partially written file on error: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
2017/07/21 12:56:14 ERROR : IMG_0669.jpg: Failed to copy: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
2017/07/21 12:56:14 ERROR : Attempt 1/3 failed with 1 errors and: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
2017/07/21 12:56:14 DEBUG : img.jpg: Size and modification time the same (differ by 0s, within tolerance 1ns)
2017/07/21 12:56:14 DEBUG : img.jpg: Unchanged skipping
2017/07/21 12:56:14 INFO : Local file system at /tmp/teszt: Waiting for checks to finish
2017/07/21 12:56:14 DEBUG : tesztfikle: Size and modification time the same (differ by 0s, within tolerance 1ns)
2017/07/21 12:56:14 DEBUG : tesztfikle: Unchanged skipping
2017/07/21 12:56:14 INFO : Local file system at /tmp/teszt: Waiting for transfers to finish
2017/07/21 12:56:15 NOTICE: IMG_0669.jpg: Removing partially written file on error: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
2017/07/21 12:56:15 ERROR : IMG_0669.jpg: Failed to copy: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
2017/07/21 12:56:15 ERROR : Attempt 2/3 failed with 1 errors and: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
2017/07/21 12:56:15 DEBUG : img.jpg: Size and modification time the same (differ by 0s, within tolerance 1ns)
2017/07/21 12:56:15 DEBUG : img.jpg: Unchanged skipping
2017/07/21 12:56:15 DEBUG : tesztfikle: Size and modification time the same (differ by 0s, within tolerance 1ns)
2017/07/21 12:56:15 DEBUG : tesztfikle: Unchanged skipping
2017/07/21 12:56:15 INFO : Local file system at /tmp/teszt: Waiting for checks to finish
2017/07/21 12:56:15 INFO : Local file system at /tmp/teszt: Waiting for transfers to finish
2017/07/21 12:56:15 NOTICE: IMG_0669.jpg: Removing partially written file on error: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
2017/07/21 12:56:15 ERROR : IMG_0669.jpg: Failed to copy: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
2017/07/21 12:56:15 ERROR : Attempt 3/3 failed with 1 errors and: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
2017/07/21 12:56:15 Failed to copy: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error

8 
2nd)
execve("/usr/bin/rclone", ["rclone", "-vv", "copy", "/mnt/photos/photos/2008/teszt/", "/tmp/teszt"], [/* 39 vars */]) = 0

getpid() = 6004
sched_getaffinity(0, 8192, {1}) = 4
mmap2(0xc00000, 807411712, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xc00000
mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6fa4000
clock_gettime(CLOCK_MONOTONIC, {28631, 304057844}) = 0
mmap2(0x10e00000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x10e00000
mmap2(0xfd10000, 17760256, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfd10000
mmap2(0xc00000, 139264, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xc00000
mmap2(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6f94000
clock_gettime(CLOCK_MONOTONIC, {28631, 306693067}) = 0
mmap2(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6f84000
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
clock_gettime(CLOCK_MONOTONIC, {28631, 316516899}) = 0
clock_gettime(CLOCK_MONOTONIC, {28631, 316940935}) = 0
sigaltstack(NULL, {ss_sp=0, ss_flags=SS_DISABLE, ss_size=0}) = 0
sigaltstack({ss_sp=0x10e02000, ss_flags=0, ss_size=32720}, NULL) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
gettid() = 6004
rt_sigaction(SIGHUP, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGHUP, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGINT, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGINT, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGQUIT, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGQUIT, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGILL, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGILL, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGTRAP, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGTRAP, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGABRT, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGABRT, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGBUS, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGBUS, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGFPE, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGFPE, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGUSR1, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGUSR1, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGSEGV, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGSEGV, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGUSR2, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGUSR2, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGPIPE, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGPIPE, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGALRM, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGALRM, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGTERM, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGTERM, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGSTKFLT, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGSTKFLT, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGCHLD, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGURG, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGURG, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGXCPU, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGXCPU, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGXFSZ, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGXFSZ, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGVTALRM, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGVTALRM, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGPROF, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGPROF, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGWINCH, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGWINCH, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGIO, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGIO, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGPWR, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGPWR, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGSYS, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGSYS, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRTMIN, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_1, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_2, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_2, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_3, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_3, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_4, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_4, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_5, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_5, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_6, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_6, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_7, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_7, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_8, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_8, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_9, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_9, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_10, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_10, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_11, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_11, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_12, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_12, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_13, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_13, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_14, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_14, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_15, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_15, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_16, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_16, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_17, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_17, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_18, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_18, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_19, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_19, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_20, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_20, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_21, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_21, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_22, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_22, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_23, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_23, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_24, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_24, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_25, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_25, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_26, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_26, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_27, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_27, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_28, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_28, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_29, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_29, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_30, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_30, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_31, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_31, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
rt_sigaction(SIGRT_32, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGRT_32, {0x6b010, ~[], SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 0
clock_gettime(CLOCK_MONOTONIC, {28631, 363921910}) = 0
clock_gettime(CLOCK_MONOTONIC, {28631, 364500959}) = 0
rt_sigprocmask(SIG_SETMASK, ~[], [], 8) = 0
clone(child_stack=0x10e33ff0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD) = 6005
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clock_gettime(CLOCK_MONOTONIC, {28631, 366927164}) = 0
rt_sigprocmask(SIG_SETMASK, ~[], [], 8) = 0
clone(child_stack=0x10e2fff0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD) = 6006
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
futex(0xb99984, FUTEX_WAIT, 0, NULL) = 0
readlinkat(AT_FDCWD, “/proc/self/exe”, “/usr/bin/rclone”, 128) = 15
futex(0xb99984, FUTEX_WAIT, 0, NULL) = 0
mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6f44000
futex(0x10e245ac, FUTEX_WAKE, 1) = 1
openat(AT_FDCWD, “/proc/sys/net/core/somaxconn”, O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
read(3, “128\n”, 4096) = 4
read(3, “”, 4092) = 0
close(3) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
close(3) = 0
socket(PF_INET6, SOCK_STREAM, IPPROTO_TCP) = 3
setsockopt(3, SOL_IPV6, IPV6_V6ONLY, [1], 4) = 0
bind(3, {sa_family=AF_INET6, sin6_port=htons(0), inet_pton(AF_INET6, “::1”, &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = 0
socket(PF_INET6, SOCK_STREAM, IPPROTO_TCP) = 4
setsockopt(4, SOL_IPV6, IPV6_V6ONLY, [0], 4) = 0
bind(4, {sa_family=AF_INET6, sin6_port=htons(0), inet_pton(AF_INET6, “::ffff:127.0.0.1”, &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = 0
close(4) = 0
close(3) = 0
futex(0x10e2432c, FUTEX_WAKE, 1) = 1
futex(0x10e2432c, FUTEX_WAKE, 1) = 1
futex(0x10e2432c, FUTEX_WAKE, 1) = 1
clock_gettime(CLOCK_REALTIME, {1500634721, 98388448}) = 0
getuid32() = 1000
getgid32() = 1000
stat64("/home/pi/.config/rclone/rclone.conf", {st_mode=S_IFREG|0600, st_size=227, …}) = 0
futex(0x10e2432c, FUTEX_WAKE, 1) = 1
futex(0x10e2432c, FUTEX_WAKE, 1) = 1
futex(0x10e2432c, FUTEX_WAKE, 1) = 1
clock_gettime(CLOCK_REALTIME, {1500634721, 170856579}) = 0
geteuid32() = 1000
getegid32() = 1000
umask(0) = 022
futex(0x10e2432c, FUTEX_WAKE, 1) = 1
umask(022) = 0
futex(0x10e2432c, FUTEX_WAKE, 1) = 1
mmap2(0x10f00000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x10f00000
mmap2(0xfd00000, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfd00000
clock_gettime(CLOCK_MONOTONIC, {28631, 558266353}) = 0
clock_gettime(CLOCK_MONOTONIC, {28631, 561012586}) = 0
futex(0x10e2432c, FUTEX_WAKE, 1) = 1
clock_gettime(CLOCK_REALTIME, {1500634721, 216178414}) = 0
futex(0x10e2432c, FUTEX_WAKE, 1) = 1
clock_gettime(CLOCK_REALTIME, {1500634721, 239679402}) = 0
clock_gettime(CLOCK_REALTIME, {1500634721, 253692588}) = 0
futex(0x10e2432c, FUTEX_WAKE, 1) = 1
openat(AT_FDCWD, “/home/pi/.config/rclone/rclone.conf”, O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
fstat64(3, {st_mode=S_IFREG|0600, st_size=227, …}) = 0
read(3, “[b2]\ntype = b2\naccount = 7cab848”…, 739) = 227
read(3, “”, 512) = 0
close(3) = 0
clock_gettime(CLOCK_REALTIME, {1500634721, 272423173}) = 0
clock_gettime(CLOCK_REALTIME, {1500634721, 273191238}) = 0
openat(AT_FDCWD, “/etc/localtime”, O_RDONLY|O_LARGEFILE) = 3
read(3, “TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\6\0\0\0\6\0\0\0\0”…, 4096) = 2379
read(3, “”, 4096) = 0
close(3) = 0
clock_gettime(CLOCK_REALTIME, {1500634721, 276174490}) = 0
write(2, “2017/07/21 12:58:41 DEBUG : rclo”…, 1472017/07/21 12:58:41 DEBUG : rclone: Version “v1.36” starting with parameters [“rclone” “-vv” “copy” “/mnt/photos/photos/2008/teszt/” “/tmp/teszt”]
) = 147
lstat64("/mnt/photos/photos/2008/teszt", {st_mode=S_IFDIR|0777, st_size=0, …}) = 0
lstat64("/tmp/teszt", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
clock_gettime(CLOCK_REALTIME, {1500634721, 283352098}) = 0
getpid() = 6004
openat(AT_FDCWD, “/tmp/rclone960826877”, O_RDWR|O_CREAT|O_EXCL|O_LARGEFILE|O_CLOEXEC, 0600) = 3
close(3) = 0
clock_gettime(CLOCK_REALTIME, {1500634721, 285826307}) = 0
utimensat(AT_FDCWD, “/tmp/rclone960826877”, {{1500634721, 1}, {1500634721, 1}}, 0) = 0
stat64("/tmp/rclone960826877", {st_mode=S_IFREG|0600, st_size=0, …}) = 0
unlinkat(AT_FDCWD, “/tmp/rclone960826877”, 0) = 0
openat(AT_FDCWD, “/tmp/rclone938864440”, O_RDWR|O_CREAT|O_EXCL|O_LARGEFILE|O_CLOEXEC, 0600) = 3
close(3) = 0
clock_gettime(CLOCK_REALTIME, {1500634721, 289361606}) = 0
utimensat(AT_FDCWD, “/tmp/rclone938864440”, {{1500634721, 1}, {1500634721, 1}}, 0) = 0
stat64("/tmp/rclone938864440", {st_mode=S_IFREG|0600, st_size=0, …}) = 0
unlinkat(AT_FDCWD, “/tmp/rclone938864440”, 0) = 0
clock_gettime(CLOCK_REALTIME, {1500634721, 291918822}) = 0
write(2, “2017/07/21 12:58:41 INFO : Loca”…, 822017/07/21 12:58:41 INFO : Local file system at /tmp/teszt: Modify window is 1ns
) = 82
stat64("/tmp/teszt", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
lstat64("/tmp/teszt", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
stat64("/tmp/teszt", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
openat(AT_FDCWD, “/tmp/teszt”, O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
getdents64(3, /* 4 entries /, 4096) = 112
getdents64(3, / 0 entries /, 4096) = 0
lstat64("/tmp/teszt/tesztfikle", {st_mode=S_IFREG|0644, st_size=29, …}) = 0
lstat64("/tmp/teszt/img.jpg", {st_mode=S_IFREG|0644, st_size=7, …}) = 0
getdents64(3, / 0 entries /, 4096) = 0
close(3) = 0
clock_gettime(CLOCK_MONOTONIC, {28631, 657426744}) = 0
clock_gettime(CLOCK_MONOTONIC, {28631, 657937787}) = 0
futex(0x10e2432c, FUTEX_WAKE, 1) = 1
clock_gettime(CLOCK_MONOTONIC, {28631, 660641015}) = 0
futex(0xb98eec, FUTEX_WAIT, 0, {59, 999488957}2017/07/21 12:58:41 DEBUG : img.jpg: Size and modification time the same (differ by 0s, within tolerance 1ns)
2017/07/21 12:58:41 DEBUG : img.jpg: Unchanged skipping
2017/07/21 12:58:41 DEBUG : tesztfikle: Size and modification time the same (differ by 0s, within tolerance 1ns)
2017/07/21 12:58:41 DEBUG : tesztfikle: Unchanged skipping
2017/07/21 12:58:41 INFO : Local file system at /tmp/teszt: Waiting for checks to finish
) = 0
futex(0xb99984, FUTEX_WAIT, 0, NULL2017/07/21 12:58:41 INFO : Local file system at /tmp/teszt: Waiting for transfers to finish
) = 0
write(4, “\354\232t\352&\332n\355_g\345\345\353\330\267\32i&\2374\252Y;i\267e\326\335\264\350<\252”…, 32768) = 32768
write(4, “n\234\177\n\342\271\242\350\323\203\204\244\341$\356\357wh\311\351\345\273\326\3372\342\2415i>Y\255”…, 32768) = 32768
write(4, “\3\214\n\345.\212\317!\336\240\211\1X\301q\275\234\20J\345q a\220\10\316r@\316M^\1”…, 32768) = 32768
write(4, “q\37t\360\2740\7q\300\34s\320\36Rn\223\224gN\324S\367\257\273z]%\273Ku\367\27”…, 32768) = 32768
write(4, “C\205\nb\300\21\215\243w\3141\324\266\340Fs\331\275yk\246\360X\355\4\5\7\v\200\30\220”…, 32768) = 32768
write(4, “J\315h\355\333\257\251\363\277\215\3453\231\25\213\0\315(t\345\3201\0,\207n\346P\207p\311\34”…, 32768) = 32768
write(4, “\352\333\263\327k\257\307\360\361\246\243C\331\265$\234\227F\357\333^\247;s{x\210gRf\210\254”…, 32768) = 32768
write(4, “\34\250\n@\312\2222X\203\222\177\17J\260\221\354\301\0\264lX\5\3118\\2HR\3400\0c”…, 32768) = 32768
read(3, “88\7\00789\254g\211\246\250F\265:i\327\246\375\355\32m\265\242w\335y”%\nU\334\251"…, 524288) = 524288
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
write(4, “88\7\00789\254g\211\246\250F\265:i\327\246\375\355\32m\265\242w\335y”%\nU\334\251"…, 32768) = 32768
write(4, "\227\30)e\3’pR0H\1s\235\245\233 \36\244\214\22% \345\201\344\200\254\n\234"…, 32768) = 32768
write(4, “\302\220\17={\214 pJ\243(`X\6,\33\357\22w(<\20\347vz\220r}kWS\23”…, 32768) = 32768
write(4, “p\241$\0207\262\202G\251\252\327P\230\0310Y^T\371\224\220\321\344\222He\351\221\264\261\0g”…, 32768) = 32768
write(4, “\224pp{\200\r\230\304\221;#\242\221\33.\326g\7x \22\10^\6NF\7\240\364\305x8”…, 32768) = 32768
write(4, “\205x\267M\246\265Vv\277n\276\277u\312\257\271\270,\333\244\f\312\244\f6\0\3c\22\t\1\262”…, 32768) = 32768
write(4, “h)\327\251iB0\262\335F\326oM\367\327\252\320\272\264\343\32\252MZ\17\357\327OB\243\202"…, 32768) = 32768
write(4, “<\230bK\252\262\227S\302\221\2269\4\34\16\244m\310\353\300\317\0V%\376\257c\247B\363]]”…, 32768) = 32768
write(4, "\275\306\311\267nik\332\311m\247\3741\237\225V\31R\316\252\345\t\31Vx\321\\250\0\357\f”…, 32768) = 32768
write(4, “\376\266>\307.x\274\2524!\230\323\236\33\25\26\322O\254w\276\237\325\266\261u.P\250\1Y\212”…, 32768) = 32768
write(4, “c\246\t\347 \324,B0,\310\345\10\4\235\271\5HP\16\343\203\301\301’<\234\234\344U(\272”…, 32768) = 32768
write(4, “eud~i\305X\231\342\352a\260T]\235y\244\333wj\355+\2376\265\315\316\263\250jZ\245”…, 32768) = 32768
write(4, “\362KU\352b\334\324\S\263m\253\275\232\177-z\21\310\273\0039 \251p\314\244\202v\260U\310”…, 32768) = 32768
write(4, “\22\3\346R\270\31\344\365$\325\207\322\236\17\222\335\244\362\3631\0\30\366\261\341r\273\225\200\4\344\4”…, 32768) = 32768
write(4, “\270\21\311\301\361?\212>\274\277Ht+\24qszc\17.\337\2265(\24\200T\260n\354N"…, 32768) = 32768
write(4, “],X\323\30\264\242\7,\261\300\314\367\7\31W\371\224F\244rL\201\201\3\214\341\207\255n\306\316”…, 32768) = 32768
read(3, 0x10fb6000, 1048576) = -1 EIO (Input/output error)
close(4) = 0
clock_gettime(CLOCK_REALTIME, {1500634721, 636968017}) = 0
write(2, “2017/07/21 12:58:41 NOTICE: IMG_”…, 1522017/07/21 12:58:41 NOTICE: IMG_0669.jpg: Removing partially written file on error: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
) = 152
unlinkat(AT_FDCWD, “/tmp/teszt/IMG_0669.jpg”, 0) = 0
close(3) = 0
clock_gettime(CLOCK_REALTIME, {1500634721, 643016529}) = 0
write(2, “2017/07/21 12:58:41 ERROR : IMG_”…, 1262017/07/21 12:58:41 ERROR : IMG_0669.jpg: Failed to copy: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
) = 126
clock_gettime(CLOCK_REALTIME, {1500634721, 644606664}) = 0
write(2, “2017/07/21 12:58:41 ERROR : Atte”…, 1342017/07/21 12:58:41 ERROR : Attempt 1/3 failed with 1 errors and: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
) = 134
stat64("/tmp/teszt", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
lstat64("/tmp/teszt", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
stat64("/tmp/teszt", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
openat(AT_FDCWD, “/tmp/teszt”, O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
getdents64(3, / 4 entries /, 4096) = 112
getdents64(3, / 0 entries /, 4096) = 0
lstat64("/tmp/teszt/tesztfikle", {st_mode=S_IFREG|0644, st_size=29, …}) = 0
lstat64("/tmp/teszt/img.jpg", {st_mode=S_IFREG|0644, st_size=7, …}) = 0
getdents64(3, / 0 entries /, 4096) = 0
close(3) = 0
stat64("/mnt/photos/photos/2008/teszt", {st_mode=S_IFDIR|0777, st_size=0, …}) = 0
openat(AT_FDCWD, “/mnt/photos/photos/2008/teszt”, O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
getdents64(3, / 5 entries /, 4096) = 144
getdents64(3, / 0 entries /, 4096) = 0
lstat64("/mnt/photos/photos/2008/teszt/IMG_0669.jpg", {st_mode=S_IFREG|0777, st_size=1386678, …}) = 0
lstat64("/mnt/photos/photos/2008/teszt/img.jpg", {st_mode=S_IFREG|0777, st_size=7, …}) = 0
lstat64("/mnt/photos/photos/2008/teszt/tesztfikle", {st_mode=S_IFREG|0777, st_size=29, …}) = 0
getdents64(3, / 0 entries /, 4096) = 0
close(3) = 0
openat(AT_FDCWD, “/mnt/photos/photos/2008/teszt/IMG_0669.jpg”, O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
clock_gettime(CLOCK_REALTIME, {1500634721, 664528349}) = 0
stat64("/tmp/teszt", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
openat(AT_FDCWD, “/tmp/teszt/IMG_0669.jpg”, O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE|O_CLOEXEC, 0666) = 4
clock_gettime(CLOCK_REALTIME, {1500634721, 666893550}) = 0
read(3, "\377\330\377\341\262\272Exif\0\0II\0\10\0\0\0\v\0\17\1\2\0\21\0\0\0\222\0”…, 4096) = 4096
write(4, “\377\330\377\341\262\272Exif\0\0II*\0\10\0\0\0\v\0\17\1\2\0\21\0\0\0\222\0”…, 4096) = 4096
read(3, “\243F:\271\21\313\360\247\366\226\277\5\245\320\242\207=\314\221/\365\252\262\376\316\277\2646\244\31\245\324”…, 8192) = 8192
write(4, “\243F:\271\21\313\360\247\366\226\277\5\245\320\242\207=\314\221/\365\252\262\376\316\277\2646\244\31\245\324”…, 8192) = 8192
read(3, “\37y\341g\205\322\343\365\210\255^n\235j\311\256\263{-wKyu\325\36\257\360s\376\n/"…, 16384) = 16384
write(4, "\37y\341g\205\322\343\365\210\255^n\235j\311\256\263{-wKyu\325\36\257\360s\376\n/”…, 16384) = 16384
read(3, “\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0”…, 32768) = 32768
write(4, “\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0”…, 32768) = 32768
read(3, “\304\304\262\225\223\311\270\234\356]\250N\0\4H\24\22\301\202u-\360\377\0\3423[\303p\236\36\262”…, 65536) = 65536
write(4, “\304\304\262\225\223\311\270\234\356]\250N\0\4H\24\22\301\202u-\360\377\0\3423[\303p\236\36\262”…, 32768) = 32768
write(4, “\251Y\273\351t\365Mk\273\354r\303\21A>HIM\265uk\352\332\263\177&\255\350j\306\223)”…, 32768) = 32768

9

read(3, “R\212\2514\334^\226z5ek\331ukq^Q"0b\352\244\226B\2\251\345H\f\314\24m”…, 131072) = 131072
clock_gettime(CLOCK_REALTIME, {1500634721, 737496523}) = 0
write(2, “2017/07/21 12:58:41 DEBUG : img.”…, 1102017/07/21 12:58:41 DEBUG : img.jpg: Size and modification time the same (differ by 0s, within tolerance 1ns)
) = 110
clock_gettime(CLOCK_REALTIME, {1500634721, 738617618}) = 0
write(2, “2017/07/21 12:58:41 DEBUG : img.”…, 562017/07/21 12:58:41 DEBUG : img.jpg: Unchanged skipping
) = 56
clock_gettime(CLOCK_REALTIME, {1500634721, 740143747}) = 0
write(2, “2017/07/21 12:58:41 DEBUG : tesz”…, 1132017/07/21 12:58:41 DEBUG : tesztfikle: Size and modification time the same (differ by 0s, within tolerance 1ns)
) = 113
clock_gettime(CLOCK_REALTIME, {1500634721, 741317847}) = 0
write(2, “2017/07/21 12:58:41 DEBUG : tesz”…, 592017/07/21 12:58:41 DEBUG : tesztfikle: Unchanged skipping
) = 59
clock_gettime(CLOCK_REALTIME, {1500634721, 742691963}) = 0
write(2, “2017/07/21 12:58:41 INFO : Loca”…, 902017/07/21 12:58:41 INFO : Local file system at /tmp/teszt: Waiting for checks to finish
) = 90
clock_gettime(CLOCK_MONOTONIC, {28632, 100419226}) = 0
futex(0xb98eec, FUTEX_WAKE, 1) = 1
clock_gettime(CLOCK_REALTIME, {1500634721, 745328186}) = 0
write(2, “2017/07/21 12:58:41 INFO : Loca”…, 932017/07/21 12:58:41 INFO : Local file system at /tmp/teszt: Waiting for transfers to finish
) = 93
write(4, “R\212\2514\334^\226z5ek\331ukq^Q"0b\352\244\226B\2\251\345H\f\314\24m”…, 32768) = 32768
write(4, “M=\35\377\0\257\300\271e\3733\370f)\310\232\302\320\10\224\30\323/+\347\16\25\230\263\22\304"…, 32768) = 32768
write(4, “\334b\332vz\365OV\2723(U\224\25Jn|\312\351\256\326\357]'J\211\207\227i\0*"..., 32768) = 32768 write(4, "Y\333\362\334\0E\231\355\312\221:\254\214 !\226c\32\27\363\34.\v\220\205$\7\3\202\214\17L"..., 32768) = 32768 read(3, "\354\232t\352&\332n\355_g\345\345\353\330\267\32i&\2374\252Y;i\267e\326\335\264\350<\252"..., 262144) = 262144 futex(0xb993c4, FUTEX_WAKE, 1) = 1 futex(0xb99350, FUTEX_WAKE, 1) = 1 write(4, "\354\232t\352&\332n\355_g\345\345\353\330\267\32i&\2374\252Y;i\267e\326\335\264\350<\252"..., 32768) = 32768 write(4, "n\234\177\n\342\271\242\350\323\203\204\244\341$\356\357wh\311\351\345\273\326\3372\342\2415i>Y\255"..., 32768) = 32768 write(4, "\3\214\n\345.\212\317!\336\240\211\1X\301q\275\234\20J\345q a\220\10\316r@\316M^\1"..., 32768) = 32768 write(4, "q\37t\360\2740\7q\300\34s\320\36Rn\223\224gN\324S\367\257\273z]%\273Ku\367\27"..., 32768) = 32768 write(4, "C\205\\nb\300\21\215\243w\3141\324\266\340Fs\331\275yk\246\360X\355\4\5\7\v\200\30\220"..., 32768) = 32768 write(4, "J\315h\355\333\257\251\363\277\215\3453\231\25\213\0\315(t\345\3201\0,\207n\346P\207p\311\34"..., 32768) = 32768 write(4, "\352\333\263\327k\257\307\360\361\246\243C\331\265$\234\227F\357\333^\247;s{x\210gRf\210\254"..., 32768) = 32768 write(4, "\34\250\n@\312\2222X\203\222\177\17J\260\221\354\301\0\264lX\5\3118\\\2HR\3400\0c"..., 32768) = 32768 read(3, "88\7\00789\254g\211\246\250F\265:i\327\246\375\355\32m\265\242w\335y\"%\nU\334\251"..., 524288) = 524288 futex(0xb993c4, FUTEX_WAKE, 1) = 1 futex(0xb99350, FUTEX_WAKE, 1) = 1 write(4, "88\7\00789\254g\211\246\250F\265:i\327\246\375\355\32m\265\242w\335y\"%\nU\334\251"..., 32768) = 32768 write(4, "\227\30)e\3'pR0H\1s\235\245\233 \36\244\214\22*% \345\201\344\200\254\n\234"..., 32768) = 32768 write(4, "\302\220\17={\214 pJ\243(X\6,\33\357\22w(<\20\347vz\220r}kWS\23”…, 32768) = 32768
write(4, “p\241$\0207\262\202G\251\252\327P\230\0310Y^T\371\224\220\321\344\222He\351\221\264\261\0g”…, 32768) = 32768
write(4, “\224pp{\200\r\230\304\221;#\242\221\33.\326g\7x \22\10^\6NF\7\240\364\305x8”…, 32768) = 32768
write(4, “\205x\267M\246\265Vv\277n\276\277u\312\257\271\270,\333\244\f\312\244\f6\0\3c\22\t\1\262”…, 32768) = 32768
write(4, "h)\327\251iB0\262\335F\326oM\367\327\252\320\272\264\343\32\252MZ\17\357\327OB\243\202”…, 32768) = 32768
write(4, “<\230bK\252\262\227S\302\221\2269\4\34\16\244m\310\353\300\317\0V%\376\257c\247B\363]]”…, 32768) = 32768
write(4, “\275\306\311\267nik\332\311m\247\3741\237*\225V\31R\316\252\345\t\31Vx\321\\250\0\357\f”…, 32768) = 32768
write(4, “\376\266>\307.x\274\2524!\230\323\236\33\25\26\322O\254w\276\237\325\266\261u.P\250\1Y\212”…, 32768) = 32768
write(4, “c\246\t\347 \324,B0,\310\345\10\4\235\271\5HP\16\343\203\301\301’<\234\234\344U(\272”…, 32768) = 32768
write(4, “eud~i\305X\231\342\352a\260T]\235y\244\333wj\355+\2376\265\315\316\263\250jZ\245”…, 32768) = 32768
write(4, “\362KU\352b\334\324\S\263m\253\275\232\177-z\21\310\273\0039 \251p\314\244\202v\260U\310”…, 32768) = 32768
write(4, “\22\3\346R\270\31\344\365$\325\207\322\236\17\222\335\244\362\3631\0\30\366\261\341r\273\225\200\4\344\4”…, 32768) = 32768
write(4, “\270\21\311\301\361?\212>\274\277Ht+\24qszc\17.\337\2265(\24\200T\260n\354N"…, 32768) = 32768
write(4, “],X\323\30\264\242\7,\261\300\314\367\7\31W\371\224F\244rL\201\201\3\214\341\207\255n\306\316”…, 32768) = 32768
read(3, 0x10fb6000, 1048576) = -1 EIO (Input/output error)
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
close(4) = 0
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
clock_gettime(CLOCK_REALTIME, {1500634722, 15063009}) = 0
write(2, “2017/07/21 12:58:42 NOTICE: IMG_”…, 1522017/07/21 12:58:42 NOTICE: IMG_0669.jpg: Removing partially written file on error: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
) = 152
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
unlinkat(AT_FDCWD, “/tmp/teszt/IMG_0669.jpg”, 0) = 0
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
close(3) = 0
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
clock_gettime(CLOCK_REALTIME, {1500634722, 27337047}) = 0
write(2, “2017/07/21 12:58:42 ERROR : IMG_”…, 1262017/07/21 12:58:42 ERROR : IMG_0669.jpg: Failed to copy: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
) = 126
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
clock_gettime(CLOCK_REALTIME, {1500634722, 31524401}) = 0
write(2, “2017/07/21 12:58:42 ERROR : Atte”…, 1342017/07/21 12:58:42 ERROR : Attempt 2/3 failed with 1 errors and: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
) = 134
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
stat64("/tmp/teszt", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
lstat64("/tmp/teszt", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
stat64("/tmp/teszt", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
openat(AT_FDCWD, “/tmp/teszt”, O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
getdents64(3, / 4 entries /, 4096) = 112
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
getdents64(3, / 0 entries /, 4096) = 0
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
lstat64("/tmp/teszt/tesztfikle", {st_mode=S_IFREG|0644, st_size=29, …}) = 0
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
lstat64("/tmp/teszt/img.jpg", {st_mode=S_IFREG|0644, st_size=7, …}) = 0
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
getdents64(3, / 0 entries /, 4096) = 0
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
close(3) = 0
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
2017/07/21 12:58:42 DEBUG : img.jpg: Size and modification time the same (differ by 0s, within tolerance 1ns)
2017/07/21 12:58:42 DEBUG : img.jpg: Unchanged skipping
2017/07/21 12:58:42 DEBUG : tesztfikle: Size and modification time the same (differ by 0s, within tolerance 1ns)
2017/07/21 12:58:42 DEBUG : tesztfikle: Unchanged skipping
2017/07/21 12:58:42 INFO : Local file system at /tmp/teszt: Waiting for checks to finish
2017/07/21 12:58:42 INFO : Local file system at /tmp/teszt: Waiting for transfers to finish
openat(AT_FDCWD, “/mnt/photos/photos/2008/teszt/IMG_0669.jpg”, O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
clock_gettime(CLOCK_REALTIME, {1500634722, 71128752}) = 0
stat64("/tmp/teszt", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
openat(AT_FDCWD, “/tmp/teszt/IMG_0669.jpg”, O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE|O_CLOEXEC, 0666) = 4
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
clock_gettime(CLOCK_REALTIME, {1500634722, 80303529}) = 0
write(4, "\377\330\377\341\262\272Exif\0\0II\0\10\0\0\0\v\0\17\1\2\0\21\0\0\0\222\0”…, 4096) = 4096
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
read(3, “\243F:\271\21\313\360\247\366\226\277\5\245\320\242\207=\314\221/\365\252\262\376\316\277\2646\244\31\245\324”…, 8192) = 8192
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
write(4, “\243F:\271\21\313\360\247\366\226\277\5\245\320\242\207=\314\221/\365\252\262\376\316\277\2646\244\31\245\324”…, 8192) = 8192
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
read(3, “\37y\341g\205\322\343\365\210\255^n\235j\311\256\263{-wKyu\325\36\257\360s\376\n/"…, 16384) = 16384
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
write(4, "\37y\341g\205\322\343\365\210\255^n\235j\311\256\263{-wKyu\325\36\257\360s\376\n/”…, 16384) = 16384
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
read(3, “\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0”…, 32768) = 32768
futex(0xb993c4, FUTEX_WAKE, 1) = 1
futex(0xb99350, FUTEX_WAKE, 1) = 1
write(4, “\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0”…, 32768) = 32768
read(3, “\304\304\262\225\223\311\270\234\356]\250N\0\4H\24\22\301\202u-\360\377\0\3423[\303p\236\36\262”…, 65536) = 65536
write(4, “\304\304\262\225\223\311\270\234\356]\250N\0\4H\24\22\301\202u-\360\377\0\3423[\303p\236\36\262”…, 32768) = 32768
write(4, “\251Y\273\351t\365Mk\273\354r\303\21A>HIM\265uk\352\332\263\177&\255\350j\306\223)”…, 32768) = 32768
read(3, “R\212\2514\334^\226z5ek\331ukq^Q"0b\352\244\226B\2\251\345H\f\314\24m”…, 131072) = 131072
write(4, “R\212\2514\334^\226z5ek\331ukq^Q"0b\352\244\226B\2\251\345H\f\314\24m”…, 32768) = 32768
write(4, “M=\35\377\0\257\300\271e\3733\370f)\310\232\302\320\10\224\30\323/+\347\16\25\230\263\22\304"…, 32768) = 32768
write(4, “\334b\332vz\365OV\2723(U\224\25Jn|\312\351\256\326\357]'J\211\207\227i\0*"..., 32768) = 32768 write(4, "Y\333\362\334\0E\231\355\312\221:\254\214 !\226c\32\27\363\34.\v\220\205$\7\3\202\214\17L"..., 32768) = 32768 read(3, "\354\232t\352&\332n\355_g\345\345\353\330\267\32i&\2374\252Y;i\267e\326\335\264\350<\252"..., 262144) = 262144 futex(0xb993c4, FUTEX_WAKE, 1) = 1 futex(0xb99350, FUTEX_WAKE, 1) = 1 write(4, "\354\232t\352&\332n\355_g\345\345\353\330\267\32i&\2374\252Y;i\267e\326\335\264\350<\252"..., 32768) = 32768 write(4, "n\234\177\n\342\271\242\350\323\203\204\244\341$\356\357wh\311\351\345\273\326\3372\342\2415i>Y\255"..., 32768) = 32768 write(4, "\3\214\n\345.\212\317!\336\240\211\1X\301q\275\234\20J\345q a\220\10\316r@\316M^\1"..., 32768) = 32768 write(4, "q\37t\360\2740\7q\300\34s\320\36Rn\223\224gN\324S\367\257\273z]%\273Ku\367\27"..., 32768) = 32768 write(4, "C\205\\nb\300\21\215\243w\3141\324\266\340Fs\331\275yk\246\360X\355\4\5\7\v\200\30\220"..., 32768) = 32768 write(4, "J\315h\355\333\257\251\363\277\215\3453\231\25\213\0\315(t\345\3201\0,\207n\346P\207p\311\34"..., 32768) = 32768 write(4, "\352\333\263\327k\257\307\360\361\246\243C\331\265$\234\227F\357\333^\247;s{x\210gRf\210\254"..., 32768) = 32768 write(4, "\34\250\n@\312\2222X\203\222\177\17J\260\221\354\301\0\264lX\5\3118\\\2HR\3400\0c"..., 32768) = 32768 read(3, "88\7\00789\254g\211\246\250F\265:i\327\246\375\355\32m\265\242w\335y\"%\nU\334\251"..., 524288) = 524288 futex(0xb993c4, FUTEX_WAKE, 1) = 1 futex(0xb99350, FUTEX_WAKE, 1) = 1 write(4, "88\7\00789\254g\211\246\250F\265:i\327\246\375\355\32m\265\242w\335y\"%\nU\334\251"..., 32768) = 32768 write(4, "\227\30)e\3'pR0H\1s\235\245\233 \36\244\214\22*% \345\201\344\200\254\n\234"..., 32768) = 32768 write(4, "\302\220\17={\214 pJ\243(X\6,\33\357\22w(<\20\347vz\220r}kWS\23”…, 32768) = 32768
write(4, “p\241$\0207\262\202G\251\252\327P\230\0310Y^T\371\224\220\321\344\222He\351\221\264\261\0g”…, 32768) = 32768
write(4, “\224pp{\200\r\230\304\221;#\242\221\33.\326g\7x \22\10^\6NF\7\240\364\305x8”…, 32768) = 32768
write(4, “\205x\267M\246\265Vv\277n\276\277u\312\257\271\270,\333\244\f\312\244\f6\0\3c\22\t\1\262”…, 32768) = 32768
write(4, "h)\327\251iB0\262\335F\326oM\367\327\252\320\272\264\343\32\252MZ\17\357\327OB\243\202”…, 32768) = 32768
write(4, “<\230bK\252\262\227S\302\221\2269\4\34\16\244m\310\353\300\317\0V%\376\257c\247B\363]]”…, 32768) = 32768
write(4, “\275\306\311\267nik\332\311m\247\3741\237*\225V\31R\316\252\345\t\31Vx\321\\250\0\357\f”…, 32768) = 32768
write(4, “\376\266>\307.x\274\2524!\230\323\236\33\25\26\322O\254w\276\237\325\266\261u.P\250\1Y\212”…, 32768) = 32768
write(4, “c\246\t\347 \324,B0,\310\345\10\4\235\271\5HP\16\343\203\301\301’<\234\234\344U(\272”…, 32768) = 32768
write(4, “eud~i\305X\231\342\352a\260T]\235y\244\333wj\355+\2376\265\315\316\263\250jZ\245”…, 32768) = 32768
write(4, “\362KU\352b\334\324\S\263m\253\275\232\177-z\21\310\273\0039 \251p\314\244\202v\260U\310”…, 32768) = 32768
write(4, “\22\3\346R\270\31\344\365$\325\207\322\236\17\222\335\244\362\3631\0\30\366\261\341r\273\225\200\4\344\4”…, 32768) = 32768
write(4, “\270\21\311\301\361?\212>*\274\277Ht+\24qszc\17.\337\2265(\24\200T\260n\354N”…, 32768) = 32768
write(4, “],X\323\30\264\242\7,\261\300\314\367\7\31W\371\224F\244rL\201\201\3\214\341\207\255n\306\316”…, 32768) = 32768
read(3, 0x10fb6000, 1048576) = -1 EIO (Input/output error)
close(4) = 0
clock_gettime(CLOCK_REALTIME, {1500634722, 427397897}) = 0
write(2, “2017/07/21 12:58:42 NOTICE: IMG_”…, 1522017/07/21 12:58:42 NOTICE: IMG_0669.jpg: Removing partially written file on error: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
) = 152
unlinkat(AT_FDCWD, “/tmp/teszt/IMG_0669.jpg”, 0) = 0
close(3) = 0
clock_gettime(CLOCK_REALTIME, {1500634722, 433709431}) = 0
write(2, “2017/07/21 12:58:42 ERROR : IMG_”…, 1262017/07/21 12:58:42 ERROR : IMG_0669.jpg: Failed to copy: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
) = 126
clock_gettime(CLOCK_REALTIME, {1500634722, 435055545}) = 0
write(2, “2017/07/21 12:58:42 ERROR : Atte”…, 1342017/07/21 12:58:42 ERROR : Attempt 3/3 failed with 1 errors and: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
) = 134
clock_gettime(CLOCK_REALTIME, {1500634722, 436174639}) = 0
write(2, “2017/07/21 12:58:42 Failed to co”…, 1042017/07/21 12:58:42 Failed to copy: read /mnt/photos/photos/2008/teszt/IMG_0669.jpg: input/output error
) = 104
exit_group(1) = ?
+++ exited with 1 +++

10

Ok, I’ve tried --buffer-size option with 1k value and it solved the problem.
I’ve tried 4M, 1M also, but these don’t work.
Values worked for me: 16, 8, 1k.
What do you think? Is it a bug?

11

The problem is here where it does this read

read(3, 0x10fb6000, 1048576) = -1 EIO (Input/output error)

Now quite a few reads have succeeded before that, so I think rclone must be reading off the end of the file.

However this is allowed - see the read(2) man page which says

RETURN VALUE
On success, the number of bytes read is returned (zero indicates end of file), and the file position is advanced by this number. It is not an error if this number is smaller
than the number of bytes requested; this may happen for example because fewer bytes are actually available right now (maybe because we were close to end-of-file, or because we
are reading from a pipe, or from a terminal), or because read() was interrupted by a signal.

That is interesting…

Yes it is a bug. But I don’t think it is a bug in rclone.

Let’s see if we can replicate with another language…

Save this as test.py

#!/usr/bin/python
import os
import sys
bufsize = 1048576
if len(sys.argv) < 2:
    print "Pass in file as arg"
    raise SystemExit(1)
fname = sys.argv[1]
print "Opening", fname
f = open(fname)
fd = f.fileno()
while True:
    data = os.read(fd, bufsize)
    print "Bytes read", len(data)
    if len(data) == 0:
        break

Then run it

python test.py /path/to/the/file

It should read the file the way rclone does. If you strace it you should see the same pattern of read calls.

What does it do?

I suspect if you do

dd if=/path/to/the/file of=/dev/null bs=1M

You’ll probably get the same error too. If not experiment with the parameters to bs.

12

Yes the python do the same error:
pi@raspberrypi:~ $ python test.py /mnt/photos/photos/2008/2008.05.15-MelleslegSzülinap/IMG_0669.jpg
Opening /mnt/photos/photos/2008/2008.05.15-MelleslegSzülinap/IMG_0669.jpg
Bytes read 1048576
Traceback (most recent call last):
File “test.py”, line 13, in
data = os.read(fd, bufsize)
OSError: [Errno 5] Input/output error

strace output can be find here: https://pastebin.com/CgpAYmNJ

the dd output:
pi@raspberrypi:~ $ dd if=/mnt/photos/photos/2008/2008.05.15-MelleslegSzülinap/IMG_0669.jpg of=/dev/null bs=1M
dd: error reading ‘/mnt/photos/photos/2008/2008.05.15-MelleslegSzülinap/IMG_0669.jpg’: Input/output error
1+0 records in
1+0 records out
1048576 bytes (1.0 MB) copied, 0.236308 s, 4.4 MB/s

13

I would say the output from dd is particularly convincing for an upstream bug report and that means it definitely isn’t an rclone problem.

Now to track down the bug.

Which OS are you running and what is the version of the CIFS client you are using? Can you try using a newer version? Have you tried the same thing on different computers?

14 
pi@raspberrypi:~ $ uname -a
Linux raspberrypi 4.9.35+ #1014 Fri Jun 30 14:34:49 BST 2017 armv6l GNU/Linux
pi@raspberrypi:~ $ lsb_release -a
No LSB modules are available.
Distributor ID:	Raspbian
Description:	Raspbian GNU/Linux 8.0 (jessie)
Release:	8.0
Codename:	jessie


pi@raspberrypi:~ $ apt list --installed | grep cifs
WARNING: apt does not have a stable CLI interface yet. Use with caution in scripts.
cifs-utils/oldstable,now 2:6.4-1 armhf [installed]

I haven’t tried with any other versions.

15

I found another thread where people are talking about a very similar issue.

Is it a Synology NAS?

There is a suggested workaround in that thread - set rsize=16384 as a mount option in /etc/fstab. Another person suggests the cache=none mount option instead.

16

No, this is a bare raspberry pi. Now i don’t want to umount my share cause the rclone process is still running (it’s rather big photo library, 500GB). So I can’t test the options you mentioned.
If the process will be terminated then I can test the options.
Thanks for your fast feedback by the way :slight_smile:

17

Ok, I was stupid, you mean the NAS :), the NAS is a D-Link DNS-327L.

18

It would be interesting to see what happens with the mount options when rclone finishes.

19

Ok, now rclone stopped.

With cache=none option the result of test.py:

pi@raspberrypi:~ $ python test.py /mnt/photos/photos/2008/2008.05.15-MelleslegSzülinap/IMG_0669.jpg
Opening /mnt/photos/photos/2008/2008.05.15-MelleslegSzülinap/IMG_0669.jpg
Bytes read 1048576
Traceback (most recent call last):
  File "test.py", line 13, in <module>
    data = os.read(fd, bufsize)
OSError: [Errno 5] Input/output error

With the option rsize=16384

pi@raspberrypi:~ $ python test.py /mnt/photos/photos/2008/2008.05.15-MelleslegSzülinap/IMG_0669.jpg
Opening /mnt/photos/photos/2008/2008.05.15-MelleslegSzülinap/IMG_0669.jpg
Bytes read 1048576
Bytes read 338102
Bytes read 0

So it is working with the rsize option.

20

OK that is good. At least we have a work-around! Thanks for testing and reporting back.