Bug 198349 - Copy multiple files from cifs-mout hangs
Summary: Copy multiple files from cifs-mout hangs
Status: NEW
Alias: None
Product: File System
Classification: Unclassified
Component: CIFS (show other bugs)
Hardware: All Linux
: P1 high
Assignee: fs_cifs
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2018-01-04 10:31 UTC by Steve
Modified: 2023-01-16 16:22 UTC (History)
22 users (show)

See Also:
Kernel Version: 4.14.11
Subsystem:
Regression: No
Bisected commit-id:


Attachments
$ strace -o output.txt gio copy * /home/sysop/foo/ (364.07 KB, text/plain)
2018-01-04 10:31 UTC, Steve
Details
Test Program for cifs hang on file IO (2.04 KB, text/x-csrc)
2018-08-31 01:07 UTC, Monthero Ronald
Details

Description Steve 2018-01-04 10:31:35 UTC
Created attachment 273397 [details]
$ strace -o output.txt gio copy * /home/sysop/foo/

Copying multiple files within one CIFS mount is "hanging" most of time. It can be reproduced when copying folders with files inside (with nautilus) or "copying dir" with many files using "gio copy". There seems to be no problem with single or large files. Those "hangs" are some kind of random but always on the same files. Also there is no problem by copying those folders on command line (terminal). This bug does not affect copying to the share.
Comment 1 Steve 2018-01-04 15:42:06 UTC
Please see also here: https://bugzilla.gnome.org/show_bug.cgi?id=792169
Comment 2 Steve 2018-02-16 13:16:22 UTC
The bug was in kernel 4.14 and still persists in version 4.15.
Comment 3 Chris Severance 2018-02-21 10:01:42 UTC
https://bugzilla.samba.org/show_bug.cgi?id=13252
Comment 4 Till Schäfer 2018-02-21 12:50:44 UTC
this is most likely a duplicate of https://bugzilla.kernel.org/show_bug.cgi?id=91621
Comment 5 Steve French 2018-02-21 18:38:58 UTC
Couple quick questions - what does /proc/fs/cifs/DebugData show when it hangs? Have you tried this on current mainline?  Does it fail quickly enough that a useful wireshark trace output could be obtained?   Fail to Samba and Windows (or Mac or NetApp or whatever) server (or only Samba)?
Comment 6 Steve French 2018-02-21 20:23:02 UTC
Also note that this commit which when in after 4.15 could help file copy via Nautilus and gio copy (which can use splice_write)

cd1aca29fa020b6e6edcd3d5b3e49ab877d1bed7 cifs: add .splice_write
Comment 7 Steve French 2018-02-21 20:25:46 UTC
Could you try mounting with rsize and wsize (read and write size) closer to what was used for CIFS (SMB1) - as an experiment try adding "rsize=20000,wsize=20000" to the mount options you specify when mounting the share.  That would reduce the i/o sizes from the typical 1MB default (for SMB3) to something closer to the 16K typical I/O sizes you might see with older dialects.
Comment 8 Steve 2018-02-22 05:46:31 UTC
For question one: proc/fs/cifs/DebugData shows nothing, even when debug is enabled (in /proc/fs/cifs/cifsFYI?).

2. I'm not very smart with wireshark.

And adding "rsize=20000,wsize=20000" to the mount options makes no difference.
Comment 9 Steve 2018-03-21 06:44:12 UTC
No changes until now. The bug persists in kernel-4.15.10-300.fc27.x86_64.
Comment 10 Steve 2018-05-02 08:48:28 UTC
The bug persists in Fedora 28, kernel-4.16.5-300.fc28.x86_64.
Comment 11 Steve 2018-05-07 05:25:36 UTC
Please note: I no longer use samba. Because we have a productive system, samba is useless. I think that's a pity and I'm sorry. Please keep in mind that I can no longer help here.
Comment 12 _razer_ 2018-06-09 06:15:54 UTC
Regression comes from 4.9 commits.
There are a lot related to CIFS indeed.
I'm in charge of several desktops running archlinux on a school, using microsoft server 2008 as samba share.
This issue is ruining my life since 2 months without a clue of what's going on.
Right now I downgraded all terminals kernels to 4.8.
Not sure that's a long term solution...
Comment 13 Shirish Pargaonkar 2018-06-11 12:04:43 UTC
Trying to install gio command in ubuntu (trusty), just can not find a package
that brings in gio....
Will try to recreate using other means...
Comment 14 Monthero Ronald 2018-08-31 01:07:38 UTC
Created attachment 278211 [details]
Test Program for cifs hang on file IO

Test program to trigger a hang on a cifs file IO
Comment 15 Monthero Ronald 2018-08-31 01:14:12 UTC
Issue reproducible with test program  I have attached in Comment 14
I tried on kernel: 4.17.3-1.el7.elrepo.x86_64 

Test program scenario - multiple processes try to smb_open the same cifs file 

[root@dhcp-1-0 ]# uname -mrs 
Linux 4.17.3-1.el7.elrepo.x86_64 x86_64

Test program used: attached in this BZ, 
Compile and run around 4 to 5 instances of this program 
as background processes.

Objective: Attempt to reproduce the CIFS errors and  hang scenario, during multiple open/close/read on same file cifs from different processes.  

Executing this program in attachment, as a background task, with multiple instances of background tasks  causes the following cifs errors and we observe hung tasks waiting for cifs_close and cifs_open in multiple processes. 

kernel buffer:
---
[2843067.793666] cifs_vfs_err: 6 callbacks suppressed
[2843067.793671] CIFS VFS: Send error in Close = -512
[2846487.977934] CIFS VFS: Send error in Close = -512
..
---
[rhm@dhcp-1-0]# mount | grep cifs 
//10.64.24.221/cifs on /cifs-test type cifs (rw,relatime,vers=default,cache=strict,username=administrator,domain=,uid=0,noforceuid,gid=0,noforcegid,addr=10.64.24.221,file_mode=0755,dir_mode=0755,soft,
nounix,serverino,mapposix,rsize=1048576,wsize=1048576,echo_interval=60,actimeo=1)

==> Execute a few instances of the compiled test program  as background processes
Test program is attached in BZ  

--Hung tasks seen waiting at SMB_open

[rhm@dhcp-1-0 testagain]# ps -elf | egrep -e t11
0 D root      4475 18633  2  80   0 -  1078 wait_f 01:29 pts/0    00:00:11 ./t11
0 D root      4621 18633  2  80   0 -  1078 wait_f 01:31 pts/0    00:00:07 ./t11
0 D root      4723 18633  2  80   0 -  1078 wait_f 01:32 pts/0    00:00:04 ./t11
0 D root      4792 18633  2  80   0 -  1078 wait_f 01:33 pts/0    00:00:03 ./t11


[rhm@dhcp-1-0]# cat /proc/4475/stack 
[<0>] wait_for_response.isra.12+0xac/0x110 [cifs]
[<0>] cifs_send_recv+0x100/0x3e0 [cifs]
[<0>] smb2_send_recv+0x11a/0x200 [cifs]
[<0>] SMB2_open+0x55b/0xb10 [cifs]
[<0>] smb2_open_file+0xac/0x250 [cifs]
[<0>] cifs_open+0x303/0x800 [cifs]
[<0>] do_dentry_open+0x215/0x330
[<0>] vfs_open+0x50/0x70
[<0>] path_openat+0x54b/0x13b0
[<0>] do_filp_open+0x91/0x100
[<0>] do_sys_open+0x124/0x210
[<0>] __x64_sys_open+0x21/0x30
[<0>] do_syscall_64+0x60/0x190
[<0>] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[<0>] 0xffffffffffffffff

[rhm@dhcp-1-0]# cat /proc/4621/stack 
[<0>] wait_for_response.isra.12+0xac/0x110 [cifs]
[<0>] cifs_send_recv+0x100/0x3e0 [cifs]
[<0>] smb2_send_recv+0x11a/0x200 [cifs]
[<0>] SMB2_open+0x55b/0xb10 [cifs]
[<0>] smb2_open_file+0xac/0x250 [cifs]
[<0>] cifs_open+0x303/0x800 [cifs]
[<0>] do_dentry_open+0x215/0x330
[<0>] vfs_open+0x50/0x70
[<0>] path_openat+0x54b/0x13b0
[<0>] do_filp_open+0x91/0x100
[<0>] do_sys_open+0x124/0x210
[<0>] __x64_sys_open+0x21/0x30
[<0>] do_syscall_64+0x60/0x190
[<0>] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[<0>] 0xffffffffffffffff

== To verify, access to cifs share is possible

[rhm@dhcp-1-0 ]# dmesg >> /cifs-test/file-2july18
[root@dhcp-1-0 ]# 
[root@dhcp-1-0 ]# ll /cifs-test/file-2july18
-rwxr-xr-x 1 root root 205608 Jul  2 14:33 /cifs-test/file-2july18
[root@dhcp-1-0 ]# 
[root@dhcp-1-0 ]# ll /cifs-test
total 428
-rwxr-xr-x 1 root root 205608 Jul  2 14:33 file-2july18
-rwxr-xr-x 1 root root   4670 Jun  4 01:52 foo-dmesg
drwxr-xr-x 2 root root      0 Aug  3  2014 ron
-rwxr-xr-x 1 root root   4260 May 18 04:30 libgss.a
drwxr-xr-x 2 root root      0 Aug  3  2014 mariog
drwxr-xr-x 2 root root      0 Aug 22  2014 test
--------------
Comment 16 Steve French 2018-08-31 03:35:40 UTC
ok - will try to repro this with current code.  Do you have your mount options ("cat /proc/mounts | grep cifs")
Comment 17 Monthero Ronald 2018-08-31 04:30:40 UTC
I don't have the same mount point of cifs anymore but a similar one right now
looks like this. ( Note: Apart from vers 1.1 test, I remember I did test with sec=krb5 and vers=2.1 as well in my earlier tests, and it provided same results )

[rhm@t520test ~]# cat /proc/mounts | grep cifs 
//10.xx.xx.xx/cifs /ctest3 cifs rw,relatime,vers=1.0,cache=strict,username=administrator,domain=,uid=0,noforceuid,gid=0,noforcegid,addr=10.64.24.221,file_mode=0755,dir_mode=0755,soft,nounix,serverino,mapposix,rsize=61440,wsize=16580,echo_interval=60,actimeo=1 0 0
Comment 18 Michael 2018-09-14 07:22:22 UTC
Maybe this is related to this one?

https://bugzilla.redhat.com/show_bug.cgi?id=1624029
Comment 19 cs_gon 2018-11-14 17:50:49 UTC
I experience the same problem with the 4.15 kernel from Ubuntu 18.04, when trying to copy files from a CIFS share to the local filesystem using Nautilus. Nautilus/Glib is using splice() and when the hang occurs the splice() call never returns. This happens when using the mount option vers=3.0. But it does not happen when using mount option vers=2.0.

Maybe this bug report contains some valueable information: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=886049 , e.g. the comment 

"I tested a simple example program for copying files which is using the 
splice() function (from here: https://gist.github.com/karthick18/1234187). 
This program works normal and finishes correctly also with the small file. 
I modified the program structure like inside the libglib2.0-0 so that the 
splice function is called 3 times and added a progress callback. The program 
works. The difference is that it uses normal file descriptors instead of an 
Input-/Output-Stream inside the libglib2.0-0. Using these objects 
together with the splice() seems to cause the deadlock."

The bugreport also contains a small test program, which uses g_file_copy() to reproduce the problem.


I can reproduce the problem any time and can provide more information if needed.


My Nautilus stack trace looks like this:

(gdb) info threads
  Id   Target Id         Frame 
* 1    Thread 0x7efdfc378a80 (LWP 29928) "nautilus" 0x00007efdf791374d in poll () at ../sysdeps/unix/syscall-template.S:84
  2    Thread 0x7efdecc67700 (LWP 29929) "gmain" 0x00007efdf791374d in poll () at ../sysdeps/unix/syscall-template.S:84
  3    Thread 0x7efdec466700 (LWP 29930) "gdbus" 0x00007efdf791374d in poll () at ../sysdeps/unix/syscall-template.S:84
  4    Thread 0x7efde9b53700 (LWP 29932) "dconf worker" 0x00007efdf791374d in poll () at ../sysdeps/unix/syscall-template.S:84
  5    Thread 0x7efda77fe700 (LWP 20437) "pool" 0x00007efdf791fd13 in splice () at ../sysdeps/unix/syscall-template.S:84
  6    Thread 0x7efdcd390700 (LWP 20539) "pool" syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
(gdb) thread 5
[Switching to thread 5 (Thread 0x7efda77fe700 (LWP 20437))]
#0  0x00007efdf791fd13 in splice () at ../sysdeps/unix/syscall-template.S:84
84	../sysdeps/unix/syscall-template.S: No such file or directory.
(gdb) bt f
#0  0x00007efdf791fd13 in splice () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007efdf8af09be in do_splice (fd_in=fd_in@entry=25, off_in=off_in@entry=0x7efda77fd570, fd_out=28, off_out=off_out@entry=0x0, len=len@entry=65536, bytes_transferd=bytes_transferd@entry=0x7efda77fd580, error=0x7efda77fd568) at /build/glib2.0-2.48.2/./gio/gfile.c:2874
        result = <optimized out>
#2  0x00007efdf8af745d in g_file_copy (error=0x7efda77fd568, progress_callback_data=0x7efda77fd730, progress_callback=0x4b1530, cancellable=0x7efdb80291a0 [GCancellable], out=0x28ad5e0 [GLocalFileOutputStream], in=0x27738f0 [GLocalFileInputStream]) at /build/glib2.0-2.48.2/./gio/gfile.c:2942
        n_read = 0
        n_written = 147
        buffer = {27, 28}
        total_size = 147
        offset_in = 147
        offset_out = 147
        res = 0
        fd_in = 25
        fd_out = <optimized out>
        splice_err = 0x0
        ret = 0
        info = 0x7efde001f2f0 [GFileInfo]
        attrs_to_read = 0x7efda003d110 " \264\002\240\375~"
        file_in = <optimized out>
        in = <optimized out>
        out = 0x28ad5e0 [GLocalFileOutputStream]
        target = <optimized out>
        do_set_attributes = 1
        iface = <optimized out>
        my_error = 0x0
        res = <optimized out>
        __func__ = "g_file_copy"
#3  0x00007efdf8af745d in g_file_copy (error=0x7efda77fd718, progress_callback_data=0x7efda77fd730, progress_callback=0x4b1530, cancellable=0x7efdb80291a0 [GCancellable], flags=<optimized out>, destination=0x24d8020, source=0x27be040) at /build/glib2.0-2.48.2/./gio/gfile.c:3213
        splice_err = 0x0
        ret = 0
        info = 0x7efde001f2f0 [GFileInfo]
        attrs_to_read = 0x7efda003d110 " \264\002\240\375~"
        file_in = <optimized out>
        in = <optimized out>
        out = 0x28ad5e0 [GLocalFileOutputStream]
        target = <optimized out>
        do_set_attributes = 1
        iface = <optimized out>
---Type <return> to continue, or q <return> to quit---
        my_error = 0x0
        res = <optimized out>
        __func__ = "g_file_copy"
#4  0x00007efdf8af745d in g_file_copy (source=0x27be040, destination=0x24d8020, flags=<optimized out>, cancellable=0x7efdb80291a0 [GCancellable], progress_callback=0x4b1530, progress_callback_data=0x7efda77fd730, error=0x7efda77fd718) at /build/glib2.0-2.48.2/./gio/gfile.c:3394
        iface = <optimized out>
        my_error = 0x0
        res = <optimized out>
        __func__ = "g_file_copy"
#5  0x00000000004b5796 in  ()
#6  0x00000000004b593f in  ()
#7  0x00000000004b593f in  ()
#8  0x00000000004b6aa2 in  ()
#9  0x00007efdf8b0c2c6 in io_job_thread (task=<optimized out>, source_object=<optimized out>, task_data=0x2da4880, cancellable=<optimized out>)
    at /build/glib2.0-2.48.2/./gio/gioscheduler.c:85
        job = 0x2da4880
        result = <optimized out>
#10 0x00007efdf8b3230d in g_task_thread_pool_thread (thread_data=0x7efda002bd50, pool_data=<optimized out>)
    at /build/glib2.0-2.48.2/./gio/gtask.c:1288
        task = 0x7efda002bd50 [GTask]
#11 0x00007efdf85b75ee in g_thread_pool_thread_proxy (data=<optimized out>) at /build/glib2.0-2.48.2/./glib/gthreadpool.c:307
        task = 0x7efda002bd50
        pool = 0x2371420
#12 0x00007efdf85b6c55 in g_thread_proxy (data=0x29e15e0) at /build/glib2.0-2.48.2/./glib/gthread.c:780
        thread = 0x29e15e0
#13 0x00007efdf7be96ba in start_thread (arg=0x7efda77fe700) at pthread_create.c:333
        __res = <optimized out>
        pd = 0x7efda77fe700
        now = <optimized out>
        unwind_buf = 
              {cancel_jmp_buf = {{jmp_buf = {139627902002944, 3838776821374542507, 0, 140731910676767, 8388608, 42821184, -3981923340648947029, -3981749061996617045}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <optimized out>
        pagesize_m1 = <optimized out>
        sp = <optimized out>
        freesize = <optimized out>
        __PRETTY_FUNCTION__ = "start_thread"
#14 0x00007efdf791f41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
(gdb)
Comment 20 cs_gon 2019-02-06 14:27:33 UTC
I did a git-bisect and the commit that causes the problem is:

82c156f853840645604acd7c2cebcb75ed1b6652 is the first bad commit
commit 82c156f853840645604acd7c2cebcb75ed1b6652
Author: Al Viro <viro@zeniv.linux.org.uk>
Date:   Thu Sep 22 23:35:42 2016 -0400

    switch generic_file_splice_read() to use of ->read_iter()
    
    ... and kill the ->splice_read() instances that can be switched to it
    
    Signed-off-by: Al Viro <viro@zeniv.linux.org.uk>


I can still replicate the problem with kernel 5.0-rc5. 

And i'm still trying to fix this primarily in the 4.15 Ubuntu kernel. I've tried switching to SMB 2.0 as a workaround, but SMB 2.0 in this kernel has some problems with oplock breaks (the client does not respond to oplock breaks from the server, which causes hangs), and when disabling oplocks on the client, it seems to run into the same problem with splice().
Comment 21 Claudio Laurita 2019-03-16 17:35:45 UTC
This bug affect me too, on a Debian Sid kernel 4.19.0-3-686-pae
Command line copy works, as well as copying from GUI with vers=2.0
Regards
Comment 22 Ronald Huetter 2019-03-17 21:37:45 UTC
I'm using Linux Mint since years and this problem only appeared with some update (can't say when exactly). It appears in Mint Nemo as described above. Meanwhile I also see it in Nautilus. Want to point out that in my case the server is a Windows desktop system (not a Samba server). It makes using the file manager GUI very cumbersome, to say the least.
Comment 23 Steve French 2019-03-18 02:08:00 UTC
Current kernel looks promising - I launched 5 copies of the hang reproducer above and don't see any issues on current tree (5.1-rc1) and nothing logged to dmesg and no recoonnects or errors listed in /proc/fs/cifs/Stats.   There have been enormous number of sets of changes (well over 400 since 4.15) to cifs.ko alone, and I do remember some fixes that affected splice write.

In general due to the crediting fixes (thanks to Pavel and also Ronnie at RedHat) and some fixes to better deal with interrupted i/o and large write error paths, I have not been seeing large write hangs (mostly due to reconnect bugs) that I saw last year.  We spent a lot of time working through various large file copy scenarios - note that the two most recent fixes from Long Li (in cifs-2.6.git for-next but not merged to Linus yet - targetted for 5.1-rc2) do fix a possibly related problem (Fix an issue with re-sending rdata when transport returning -EAGAIN and a similar fix for resending wdata).

For your reproduction scenario with the provided test case how large did you set the test file ("foo-dmesg")?
Comment 24 Steve French 2019-03-18 02:11:32 UTC
And was your target server Samba (Linux)? Macs? Azure (Cloud)? NetApp or EMC? Windows?
Comment 25 t.wede 2019-03-18 12:30:51 UTC
I have the same issue on openSUSE (KDE) using Kernel 4.20.13 os 5.0.1. It seems to be the same as https://bugzilla.kernel.org/show_bug.cgi?id=202903 .

There is no significant network traffic. Copying, moving and reading a few pdf's on a CIFS mount, suddenly CIFS hungs:

[ 7790.949982] CIFS VFS: Cancelling wait for mid 5621 cmd: 4
[ 7790.950006] CIFS VFS: Send error in Close = -512
[ 7868.253059] CIFS VFS: Send error in Close = -512
[ 7973.280475] CIFS VFS: Server 192.168.5.6 has not responded in 120 seconds. Reconnecting...

There seems to be no correlation to the file size or number of files. Copying many files, eg. the kernel Sources, from and to the CIFS Mount, everything works fine.
Reading a single file (file size is about 63 kiB), suddenly all CIFS mounts to this Server hungs at the same time.

Target server is Samba 4.2.4 on openSuse 13.1. I use smb vers 1.0
Comment 26 Steve French 2019-03-18 15:16:04 UTC
So this only fails with the older vers=1.0?  Not the default (SMB2.1 or later)?  99% of our regression tests are for the later dialects, probably should add a few more for older cifs dialects.

Can you confirm that this works with SMB2.1 or SMB3 but fails for CIFS (the older vers=1.0 dialect)
Comment 27 t.wede 2019-03-18 16:43:48 UTC
With vers=2.1 for now in the short time I could reproduce this problem.

Bit with vers=2.1 I have other Issues:

1.) I have to use the mount option cache=loose. Without this, the transfer rate drops to <30% (1GB net, cache=lose: 112 MiB/s. without cache=loose: 36 MiB/s).

2.) Suddenly, some of the files I just copied can not be deleted. After umount cifs and then mount it again, it works.

[  760.434929] CIFS VFS: Cancelling wait for mid 137109 cmd: 5
[  819.914091] CIFS VFS: Cancelling wait for mid 144880 cmd: 5
[  819.914713] CIFS VFS: Close unmatched open
[  848.284127] CIFS VFS: Cancelling wait for mid 147408 cmd: 16
[  848.284188] CIFS VFS: Cancelling wait for mid 147409 cmd: 6
[  864.404117] CIFS VFS: Cancelling wait for mid 148647 cmd: 5
[  872.541917] CIFS VFS: Cancelling wait for mid 149396 cmd: 5
[  876.062164] CIFS VFS: Cancelling wait for mid 149691 cmd: 5
[  884.137114] CIFS VFS: Cancelling wait for mid 150425 cmd: 5
[  884.535185] CIFS VFS: Cancelling wait for mid 150463 cmd: 5
[  884.535506] CIFS VFS: Close unmatched open
[  987.036354] CIFS VFS: Cancelling wait for mid 162247 cmd: 5
[  987.036797] CIFS VFS: Close unmatched open

3.) Unix-extensions dosn't work.

4.) Symlinks are not present.

It is not usable for my purposes.
Comment 28 t.wede 2019-03-18 16:46:05 UTC
Sorry, I meant: With vers=2.1 for now in the short time I could not reproduce this problem.
Comment 29 cs_gon 2019-03-18 16:50:25 UTC
Steve,

at least for me it happened with vers=3.0, but not with vers=2.0 (cannot say anything about vers=1.0 or vers=2.1, but could test that, if it would help you). The file servers are Windows. I don't know the version right now, but could find out, if this matters.

So we tried switching to vers=2.0 to work around the problem. But then we ran into oplock break issues with vers=2.0, diabled oplocks using the module option "enable_oplocks". But after that, it seems we ran into the same problem again.

That's why I did the git bisect (comment 20) and reverted the commit in the Ubuntu 4.15 kernel that we use. Since then the problem has notreoccurred. I'm not sure, if this is a problem in the splice() implementation or in the CIFS code.

I could reproduce the problem with 5.0-rc5, but it seems I can not reproduce it with 5.1.0-rc1.

Do you know if there were specific commits between 5.0-rc5 and 5.1.0-rc1 that should have fixed this?
Comment 30 Steve French 2019-03-18 17:08:33 UTC
Interesting - at first glance looks like there are multiple possibilities for what fixed it. There were 66 commits to cifs.ko in that period, and some of these marked for stable (for autobackporting) but it would be helpful to know which commit so we make sure it will be marked for stable.  I will also do a 'full backport' (of all cifs.ko) commits for 4.18 and 5.0 pretty soon (probably later this week) since it is safer with this volume of cifs/smb3 fixes and features (very high activity level over last year or so) to do full backports as that is closer to what the majority of the test activity is centered on.  We also want to make sure that whatever we find on this that we are sure that the 'buildbot' (the automated test framework Ronnie and Aurelien and Paulo set up for cifs.ko) includes at least one test that covers this scenario so we don't have a problem with it.   You mentioned a second problem (with oplocks and vers=2.0) that we should also add an automated test for.

Below is the list of the 66 commits in 5.1-rc1 (or between 5.0-rc5 and 5.1-rc1)

bc31d0cdcfbadb6258b45db97e93b1c83822ba33 CIFS: fix POSIX lock leak and invalid ptr deref
f5778c398713692a16150ae96e5c8270bab8399f SMB3: Allow SMB3 FSCTL queries to be sent to server from tools
f16994797ea89e572b27f41c554aeac6b1c16048 cifs: fix incorrect handling of smb2_set_sparse() return in smb3_simple_falloc
dd0ac2d24bf0b39c0f4f17934a0e1dde2b3a2840 smb2: fix typo in definition of a few error flags
c847dccfbdc198671e80cd81891ff7a255606aea CIFS: make mknod() an smb_version_op
6552580286e5fdcde50206dd0263b63ab87b64fe cifs: minor documentation updates
d44d13723b0994bc61e0f2d3efeb17856128673b cifs: remove unused value pointed out by Coverity
31ba4331d571f501fb32ae072478787e77baf52a SMB3: passthru query info doesn't check for SMB3 FSCTL passthru
779ede040dd491acdb076ed9660d7160228949fd smb3: add dynamic tracepoints for simple fallocate and zero range
72c419d9b073628d3b5b0b2fc787b724f1a8c726 cifs: fix smb3_zero_range so it can expand the file-size when required
ccdc77a3054afb851473e43f4d60890263cd22e9 cifs: add SMB2_ioctl_init/free helpers to be used with compounding
8191576a1249763b246164b323003bec084cc8a2 smb3: Add dynamic trace points for various compounded smb3 ops
b0f6df737a1c5d9d5ff90cc946205d8af46cc067 cifs: cache FILE_ALL_INFO for the shared root handle
ab7b10cf4fd14496292c62099f3a0a1c1ef90c0e smb3: display volume serial number for shares in /proc/fs/cifs/DebugData
257b78099be015762b1b19b3e4c58f90a9913fb7 cifs: simplify how we handle credits in compound_send_recv()
7937ca961c847bda8a75da5d9c34efee9602f6b5 smb3: add dynamic tracepoint for timeout waiting for credits
ffd1ef1e50727e96e360e871b89aa8cf329935f7 smb3: display security information in /proc/fs/cifs/DebugData more accurately
2b53b929faedacc6531bbb4315585cb7c14a252d cifs: add a timeout argument to wait_for_free_credits
16b34aa44b257155d9392a19e08e4ce139bc2789 cifs: prevent starvation in wait_for_free_credits for multi-credit requests
b227d215deef4f3528b8f754accef4db03539a59 cifs: wait_for_free_credits() make it possible to wait for >=1 credits
4230cff8c0b7aaee7203e434b05a9acc1635fc04 cifs: pass flags down into wait_for_free_credits()
480b1cb9dad894f40523a29964746cfc6ebd714f cifs: change wait_for_free_request() to take flags as argument
50cfad780bcf9e03d11aaf0a7296a4c0ed336b54 fs: cifs: Kconfig: pedantic formatting
69dc4b181710d0a7c1a2780a56c715703cd1fb06 smb3: request more credits on normal (non-large read/write) ops
b30c74c73c787d853ecb9fcf5c59511a09a4ec59 CIFS: Mask off signals when sending SMB packets
afc18a6f7b849a4935f3b4d782c902749b1580fd CIFS: Return -EAGAIN instead of -ENOTSOCK
2084ed57167c3e39f99ac2bb19f19e85321d2169 CIFS: Only send SMB2_NEGOTIATE command on new TCP connections
6dfbd84684700cb58b34e8602c01c12f3d2595c8 CIFS: Fix read after write for files with read caching
96281b9e46ebb90cefa8b57b11ca40e5ac05f649 smb3: for kerberos mounts display the credential uid used
259594bea574e515a148171b5cd84ce5cbdc028a cifs: use correct format characters
d42043a600abfd4d6208c1f1454ee8afa3b5e905 smb3: add dynamic trace point for query_info_enter/done
53a3e0d96c708bca1607507ab2470a3c911c8c81 smb3: add dynamic trace point for smb3_cmd_enter
efe2e9f369c72bb72410741ac101b90573256ec0 smb3: improve dynamic tracing of open and posix mkdir
b0a42f2ac96e93f27704440ec55651d0570622f1 smb3: add missing read completion trace point
d323c24617527f28cdb03f3bb7d8f9b62eecee80 smb3: Add tracepoints for read, write and query_dir enter
adb3b4e90e103f8300cf2b7187016dad13e848c6 smb3: add tracepoints for query dir
0d481325a9e5e3a31bf83bfcd3690a7a7152ece1 smb3: Update POSIX negotiate context with POSIX ctxt GUID
cfe7e41f791dde0b8280df9aa264fe5cb31d281c cifs: update internal module version number
7091bcaba9f34c83e1e6f418b6de5c6d987571da CIFS: Try to acquire credits at once for compound requests
fe768d51c832ebde70a83221b0633dc7bc9640a6 CIFS: Return error code when getting file handle for writeback
c4b8f657d55b4ed60cb0a2187e940706de23f2b2 CIFS: Move open file handling to writepages
258f0603beb869ba5f6a05713a1508d991baae43 CIFS: Move unlocking pages from wdata_send_pages()
c7d38dbe7d3851e52f6117d9bbbf6865066b81d9 CIFS: Find and reopen a file before get MTU credits in writepages
3e9529944d4177bd3a0952f4e7fe4f76c0f9bf6f CIFS: Reopen file before get SMB2 MTU credits for async IO
f0b93cb9d10789381c2c8c3bcab2315c3dcb3311 CIFS: Remove custom credit adjustments for SMB2 async IO
9a1c67e8d5dad143d5166dac1ee6776f433dac00 CIFS: Adjust MTU credits before reopening a file
97ea499883cc0566b1fafdc12ca49d0926aab332 CIFS: Check for reconnects before sending compound requests
3349c3a79fb5d7632bfe426c014cbb589d1ca8e0 CIFS: Check for reconnects before sending async requests
34f4deb7c56c6fdc77a7e414203f0045bb6db32b CIFS: Respect reconnect in non-MTU credits calculations
335b7b62ffb69d18055f2bb6f3a029263a07c735 CIFS: Respect reconnect in MTU credits calculations
5b964852609b2826126a526851f316fc06f5e37e CIFS: Set reconnect instance to one initially
bb1bccb60c2ebd9a6f895507d1d48d5ed773814e CIFS: Respect SMB2 hdr preamble size in read responses
66265f134acfb202465fecfbeb61fefb66595c40 CIFS: Count SMB3 credits for malformed pending responses
82e0457af5f92126a0a6389d827b1e4daad8e0fd CIFS: Do not log credits when unmounting a share
6b15eb18c6a9ddfbb387456c0f1ed86d987cb741 CIFS: Always reset read error to -EIO if no response
969ae8e8d4ee54c99134d3895f2adf96047f5bee cifs: Accept validate negotiate if server return NT_STATUS_NOT_SUPPORTED
c781af7e0c1fed9f1d0e0ec31b86f5b21a8dca17 CIFS: Do not skip SMB2 message IDs on send failures
4fe75c4e4bc2caeb4159573e26cf3075e2c0fd9b smb3: request more credits on tree connect
e8506d25f740fd058791cc12a6dfa9386ada6b96 smb3: make default i/o size for smb3 mounts larger
7b9b9edb49ad377b1e06abf14354c227e9ac4b06 CIFS: Do not reset lease state to NONE on lease break
d26e2903fc10cfa2d3b8587b9eb8cf7c2a3ff2f5 smb3: fix bytes_read statistics
2109464184919f81efd593b4008291448c522815 cifs: return -ENODATA when deleting an xattr that does not exist
eca004523811f816bcfca3046ab54e1278e0973b cifs: add credits from unmatched responses/messages
74ea5f983f9e86ebb4b7ed611937776dab18c67e cifs: replace snprintf with scnprintf
68e2672f8fbd1e04982b8d2798dd318bf2515dd2 cifs: Fix NULL pointer dereference of devname
165df9a080b6863ae286fa01780c13d87cd81076 CIFS: Fix leaking locked VFS cache pages in writeback retry
Comment 31 t.wede 2019-03-19 11:15:07 UTC
Additional informations (kernel 4.20.2), because of other issues, I have not tested Kernel 5.0.1 again:

I have tested the following on a single CIFS mount (Samba 4.2.4 on openSuse 13.1):

1.) manual copying of 94 of files from one to another direktory on this mount
2.) manual moving the files from one to another direktory on this mount
3.) manual opening and closing the pdf's with KDE'S Okular one afte another
4.) manual deleting the files

Results:

vers=1.0
mount options: vers=1.0,echo_interval=2,serverino,mapchars

1.) without errors
2.) without errors
3.) CIFS mount hangs after 20 to 30 files
--> VFS: Server 192.168.5.6 has not responded in 4 seconds. Reconnecting...

after automatic reconnect:
4.) without errors

vers=2.1
mount options: vers=2.1,cache=loose,serverino,mapchars

1.) without errors
2.) without errors
3.) works but with following error messages:
[ 7009.587682] CIFS VFS: Cancelling wait for mid 13391 cmd: 5
[ 7036.232816] CIFS VFS: Cancelling wait for mid 15703 cmd: 5
[ 7036.233285] CIFS VFS: Close unmatched open
[ 7046.875742] CIFS VFS: Cancelling wait for mid 16634 cmd: 5
[ 7052.186630] CIFS VFS: Cancelling wait for mid 17061 cmd: 5
[ 7058.996801] CIFS VFS: Cancelling wait for mid 17668 cmd: 5
[ 7060.866389] CIFS VFS: Cancelling wait for mid 17816 cmd: 5
[ 7086.802382] CIFS VFS: Cancelling wait for mid 20200 cmd: 5
[ 7086.802644] CIFS VFS: Close unmatched open
[ 7097.139383] CIFS VFS: Cancelling wait for mid 21125 cmd: 5
[ 7098.950860] CIFS VFS: Cancelling wait for mid 21318 cmd: 5
[ 7102.600039] CIFS VFS: Cancelling wait for mid 21640 cmd: 5
[ 7117.172553] CIFS VFS: Cancelling wait for mid 23006 cmd: 5
[ 7132.280502] CIFS VFS: Cancelling wait for mid 24231 cmd: 5
[ 7136.927822] CIFS VFS: Cancelling wait for mid 24676 cmd: 5
[ 7140.104525] CIFS VFS: Cancelling wait for mid 24947 cmd: 5

4.) some files could not be deleted.
    Dolphins message: file does not exist

However, the files are present and accessible on the servers file system.
After umounting the CIFS mount, the files are automaticaly deletet on the server.

vers=3.0
mount options: vers=3.0,cache=loose,serverino,mapchars

1.) without errors
2.) without errors
3.) CIFS mount hangs after 3 to 5 files
No error message.

after automatic reconnect:
4.) without errors

Therefor I will check if I can go back to kernel 4.4. There were no such issues.
Comment 32 t.wede 2019-03-19 16:33:39 UTC
I have tested the same with kernel 4.14.106 and vers=1.0.
There are the errors in large file write.

And I have tested the same with kernel 4.9.2 and vers=1.0.
CIFS works quick and without any error.

The bug seems to be between kernels 4.9 and 4.14.

Maybe that will help.

Downgrade to a kernel before 4.14 is unfortunately not an option for me because I use btrfs and the current file systems are incompatible with older kernels.
Comment 33 Chris Severance 2019-03-19 18:44:19 UTC
Tests by Marc Neiger show that 4.13 is the last working kernel.

https://github.com/linuxmint/nemo/issues/1683#issuecomment-441256000
Comment 34 t.wede 2019-03-20 11:27:34 UTC
I tested the CIFS of 5.1-rc1 on 4.20.17 with the following changes to compile with 4.20.17:

-------------------------------------------------------------------------------

diff -uNrp cifs_5.1-rc1/file.c cifs_5.1-rc1_4.20.17/file.c
--- cifs_5.1-rc1/file.c	2019-03-17 22:22:26.000000000 +0100
+++ cifs_5.1-rc1_4.20.17/file.c	2019-03-20 11:28:52.000000000 +0100
@@ -1105,10 +1105,10 @@ try_again:
 	rc = posix_lock_file(file, flock, NULL);
 	up_write(&cinode->lock_sem);
 	if (rc == FILE_LOCK_DEFERRED) {
-		rc = wait_event_interruptible(flock->fl_wait, !flock->fl_blocker);
+		rc = wait_event_interruptible(flock->fl_wait, !flock->fl_next);
 		if (!rc)
 			goto try_again;
-		locks_delete_block(flock);
+		posix_unblock_lock(flock);
 	}
 	return rc;
 }
@@ -4093,7 +4093,7 @@ readpages_get_pages(struct address_space
 
 	INIT_LIST_HEAD(tmplist);
 
-	page = lru_to_page(page_list);
+	page = list_entry(page_list->prev, struct page, lru);
 
 	/*
 	 * Lock the page and put it in the cache. Since no one else

-------------------------------------------------------------------------------

I tested only vers=1.0. The same issues, but now the reconnection also fails. CIFS hangs completely.

-------------------------------------------------------------------------------

[ 2258.163486] CIFS VFS: Send error in Close = -512
[ 2432.877188]  ? CIFSSMBEcho+0x6f/0x1c0 [cifs]
[ 2442.095559] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2456.432179] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2470.768804] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2476.771555]  ? CIFSSMBNegotiate+0x3f/0x790 [cifs]
[ 2476.771595]  ? CIFSSMBUnixQPathInfo+0x6d/0x330 [cifs]
[ 2485.105435] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2499.442063] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2513.778704] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2528.115331] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2542.451967] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2556.788658] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2571.125209] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2585.461847] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2599.798454] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2614.135105] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2628.471721] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2642.808341] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2657.144960] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2671.481559] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2685.818176] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2700.154821] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
[ 2714.492416] CIFS VFS: Server 192.168.5.6 has not responded in 10 seconds. Reconnecting...
^C
 
-------------------------------------------------------------------------------

May be, the above changes dos not work or CIFS seems to be massively broken.

Is there a way to go back to CIFS of kernel 4.9 on the new kernels (eg. 4.20) until the new CIFS works? New features do not help for the moment, if CIFS does not work on the whole.

May be it is not synonymous a CIFS problem, but one of the underlying kernel. To test that, I think, a regression would be helpful.
Comment 35 cs_gon 2019-03-21 19:25:57 UTC
Steve, 

I did another git bisect between 5.0-rc5 and 5.1.0-rc1 to find the commit, which fixes the problem or makes it not reproducible any more (not sure if it really fixes the root cause). 

The commit is:

commit 7b9b9edb49ad377b1e06abf14354c227e9ac4b06
Author: Pavel Shilovsky <piastryyy@gmail.com>
Date:   Wed Feb 13 15:43:08 2019 -0800

    CIFS: Do not reset lease state to NONE on lease break
    
    Currently on lease break the client sets a caching level twice:
    when oplock is detected and when oplock is processed. While the
    1st attempt sets the level to the value provided by the server,
    the 2nd one resets the level to None unconditionally.
    This happens because the oplock/lease processing code was changed
    to avoid races between page cache flushes and oplock breaks.
    The commit c11f1df5003d534 ("cifs: Wait for writebacks to complete
    before attempting write.") fixed the races for oplocks but didn't
    apply the same changes for leases resulting in overwriting the
    server granted value to None. Fix this by properly processing
    lease breaks.
    
    Signed-off-by: Pavel Shilovsky <pshilov@microsoft.com>
    Signed-off-by: Steve French <stfrench@microsoft.com>
    CC: Stable <stable@vger.kernel.org>


Does this make sense to you? 

Anyway, I'm currently building a new 4.15 Ubuntu kernel with this commit applied, to test if this helps with that kernel. I hope to be able to point the Canonical kernel team to this commit, to get it included in the Ubuntu kernel. I can probably report back tomorrow, to tell if this was successful.
Comment 36 cs_gon 2019-03-22 17:20:38 UTC
Steve,

I have done some additional testing with 5.1.0-rc1 and with 4.15 with the above commit applied. With both kernels I cannot reproduce the problem as long as I have oplocks enabled. When I disable oplocks (echo N > /sys/module/cifs/parameters/enable_oplocks) I can still reproduce the problem. 

So I think the commit above only masks the problem, and a proper fix would still be needed. 

All tests were done with the following mount options:
rw,noexec,relatime,vers=3.0,sec=krb5,cache=strict,username=m525025,uid=85289,forceuid,gid=27425,forcegid,addr=10.226.64.157,file_mode=0755,dir_mode=0755,soft,nounix,serverino,mapposix,nobrl,rsize=4194304,wsize=4194304,echo_interval=60,actimeo=15

And I'm not sure, it this was clear, but at least for me the problem only happens with small files (like a couple hundred bytes). I have a test folder with a bunch of 5 byte files. When I try to copy the whole folder in Nautilus, it immediately hangs forever while trying to copy the first file. I don't see any "Server xxx has not responded in y seconds", like t.wede, but as I said earlier, I'm not mounting the shares from a Samba server, but from a Windows server. When I enable CIFS debugging, the connection seems to idle and only echo packets get sent.

Is there any additional information I could provide to make it easier to find the root cause?
Comment 37 lotek 2019-03-31 00:06:27 UTC
hi Steve,
maybe I have the same issue since 2 years. I use cif-shares mounted on Ubuntu to a samba-server (synology). I have the problem only from cif and not when I use gvfs-shares managed by Gnome-nautilus. Windows10-clients to samba or windows10-shares as server bring no problem! seems a cif-client bug or feature ;)
Now I'm happy to found this bug-thread.

please can you confirm that small text-files (extension not important) with 4092sign (count with notepadqq) don't finish copy jobs but files with 4093 and more sign copy complete. (Copy with Nautilus)

Copying files on terminal with "cp" from Ubntu-cleint to samba-servr working fine with every file size.

Tested with smb 1,2,3 - protocoll-version verified on client and smb-server.
Comment 38 lotek 2019-03-31 00:07:46 UTC
(In reply to krabelle from comment #37)
> hi Steve,
> maybe I have the same issue since 2 years. I use cif-shares mounted on
> Ubuntu to a samba-server (synology). I have the problem only from cif and
> not when I use gvfs-shares managed by Gnome-nautilus. Windows10-clients to
> samba or windows10-shares as server bring no problem! seems a cif-client bug
> or feature ;)
> Now I'm happy to found this bug-thread.
> 
> please can you confirm that small text-files (extension not important) with
> 4092sign (count with notepadqq) don't finish copy jobs but files with 4093
> and more sign copy complete. (Copy with Nautilus)
> 
> Copying files on terminal with "cp" from Ubntu-cleint to samba-servr working
> fine with every file size.
> 
> Tested with smb 1,2,3 - protocoll-version verified on client and smb-server.

other bugs with 4092 bytes:
https://lists.samba.org/archive/rsync/2013-May/028364.html
https://bugzilla.samba.org/show_bug.cgi?id=5478
Comment 39 t.wede 2019-04-01 13:05:37 UTC
On Kernel 4.20.17 CIFS vers=1.0 with oplocks disabled works without errors
(echo 0 > /sys/module/cifs/parameters/enable_oplocks).

With oplocks enabled I get the errors after opening and closing of round about 30 files (open and close pdf-files with KDE's Okular). On 5 Tests I got the error on file: 33, 28, 34, 36 and 29). It seems to me that there run buffers full on updating timestamp of the files.

Due to time constraints, I only tested vers=1.0.
Comment 40 Steve French 2019-04-17 04:28:08 UTC
Presumably the oplock break issue mentioned above is easy to workaround - "modprobe ifs enable_oplocks=N" but the problem seems to be that we are leaking 'credits' (or perhaps more accurately for SMB1 dialect would be to say we are leaking the active request count) one for every oplock break. Should be a fairly easy fix - the reason it probably wasn't noticed as much is due to discouraging the use of SMB1 due to security being worse in this very old dialect.
Comment 41 John 2019-04-18 00:57:17 UTC
I just discovered this after having upgraded my servers.  OMG!!!

Anyway, here is some information that I hope will be useful in helping you troubleshoot.  Since I work in a hybrid environment, there are some differences in my testing results that may provide useful hints.

Original setup:
desktop: lubuntu 4.15.0-47-lowlatency #50~16.04.1-Ubuntu SMP PREEMPT Fri Mar 15 17:23:09 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux; Samba version 4.3.11-Ubuntu

server_1: (don’t laugh!) illumian1.0 (on a 32 bit only Atom processor)

server_2: OmniOS (probably rt-151020; J1900 processor)

Neither server used Samba.  SMB version 1.0 to both servers.

Everything worked like a champ, but server_1 was starting to show its age and, rarely, got confused with a lot of activity and needed a reboot.

New setup:
desktop: same as above

server_1: ZFS on Ubuntu server 18.04 LTS; Samba version 4.7.6-Ubuntu (J1900 processor)

server_2: OmniOS-CE rt-151028b (J1900 processor)

All directories on servers are mounted on the desktop via fstab.  With server_1, the SMB connection is with SMB version 3.02.  I’m not sure what version the connection to server_2 is, but it is > 2.0.

The tests are run from the desktop computer and, are generally:

1) copy the directory lots_a_files (about 6500 files, 260 subdirectories, 25GB) from A to B.

2) delete the directory lots_a_files from B.

In my original setup, all the tests have run quickly and without problems.

Here are the results in my new setup.

Test 1: using PCManFM, copy from ~/server_1/directory_1 to ~/server_1/directory_2.
Result: hangs pretty quickly.  Smbstatus on server_1 shows the input file directory and file as locked (readonly) and the output file as locked (writeonly).  When I try to delete directory_2, PCManFM complains about a file that it can’t delete that it can’t see (the one that is write locked according to smbstatus).  Restarting smbd clears the locks.  In this case, I delete the remaining file from the server using rm in a terminal on the server.  I can then delete the directory with PCManFM.

Test 2: using cp from a terminal, repeat Test1.  
Result: the copy works ok.  I can delete directory_2 with PCManFM, or from the terminal.

Test 3: using PCManFM, copy from ~/server_1/directory 1 to ~/desktop/directory_2.
Result: fails identically to Test 1.  Identical results from smbstatus on server_1.  Same deletion scenario.

Test 4: using cp from a terminal, repeat Test3.
Result: the copy works ok.  I can delete directory_2 with PCManFM, or from the terminal.

Test 5: using PCManFM, copy from ~/server_1/directory_1 to ~/server_2/directory_2.
Result: hangs pretty quickly.  Smbstatus on server_1 shows the input directory and an input file as locked (readonly).  When I try to delete directory_2, PCManFM complains about a file that it can’t delete that it can’t see (the one that is read locked according to smbstatus).  However, I can delete the file from a terminal at server_2 without difficulty, and the directories that contain it.  Restarting smbd clears the locks.

Test 6: using cp from a terminal, repeat Test5.
Result: the copy works ok.  I can delete directory_2 with PCManFM, or from the terminal.

Test 7: using PCManFM, copy from ~/server_2/directory_2 to ~/server_1/directory_1.
Result: the copy works ok.  I can delete directory_1 with PCManFM.

Test 8: using cp from a terminal, repeat Test7.  
Result: the copy works ok.  I can delete directory_1 with PCManFM, or from the terminal.

Test 9: using PCManFM, copy from ~/server_2/directory_2 to ~/desktop/directory_1.
Result: the copy works ok.  I can delete directory_1 with PCManFM.

Test 10: using cp from a terminal, repeat Test9.  
Result: the copy works ok.  I can delete directory_1 with PCManFM, or from the terminal.

Test 11: using PCManFM, copy from ~/desktop/directory_2 to ~/server_2/directory_2.
Result: the copy works ok.  I can delete directory_2 with PCManFM.

Test 12: using cp from a terminal, repeat Test9.  
Result: the copy works ok.  I can delete directory_2 with PCManFM, or from the terminal.

Test 13: using PCManFM, copy from ~/desktop/directory_2 to ~/server_1/directory_1.
Result: the copy works ok.  I can delete directory_1 with PCManFM.

Test 14: using cp from a terminal, repeat Test9.  
Result: the copy works ok.  I can delete directory_1 with PCManFM, or from the terminal.

To me, this suggests a read-lock problem, probably on the samba server, TBD.  Yet, when I run software that I wrote (in Lazarus) to find duplicate files, all of the files in both directories are enumerated (i.e., including those in server_1) and I can read all of the potentially duplicated files (in this case, all of them) so that they can be compared.  For the tests that are the basis of this message, all of the duplicated files (i.e., all of them) in the target directory were deleted.  

However, I’ve had other experiences, especially when deleting files (including with my duplicate file finder application) that suggest there may be more to the problem.  However, I’m not confident enough in those results to report them here right now.  If I find them to be repeatable, then I will do so.

Meanwhile, Samba does appear to a large extent unusable.  If this persists, I need to find another solution for my new server.  At least the Illumos distributions, in spite of their limited hardware compatibility issues, work.
Comment 42 Steve French 2019-04-18 04:11:50 UTC
Note that if you are mounting with vers=1.0 (SMB1/CIFS) you will need to either disable oplocks (see above) or use a recently proposed patch from Ronnie to fix  credit handling for SMB1 oplocks.  The fix for SMB1 oplock regression (which can cause hangs) will be in Linux kernel 5.2

I realize that with some very old servers they only support SMB1, but if at all possible, for security reasons not just functional reasons, SMB2.1 or later should be used (SMB2.1 was introduced 10 years ago!)
Comment 43 Willi32 2019-07-10 19:35:43 UTC
I wonder why some people just saying that they have found a solution!!! 
In NONE of the kernel versions since 4.13.16-041316 is it possible to transfer "text" files between a smb 2.0 version maschine (e.g windows 7 64bit with actual patches) and linux mint cinnamon for example.   
The copy process is only working as usual if i am using a terminal session ! 
It EVER FAILS if i use any file-manager as described earlier in this post.  

So the problem is still in the kernel and never has been fixed again. 
Why? What has been changed between version 4.13 and the newer 4.14 Kernel that this problem suddenly exists ?
And why has the  5.2.rc6 kernel the same old problem ?
As mentioned earlier non kernels after 4.13.x are able to transfer text files via Nemo or similar file manager without problems. only console with cp is still working.  
switching to earlier smb version isn't an option.
enabling or disabling oplock doesnt helped here much.
Comment 44 SDato 2019-08-06 17:06:12 UTC
I am having the same problem on Fedora 30 and copying files from an Apple Time Capsule.

Kernel version: 5.2.5-200.fc30.x86_64

fstab configuration for the share:

//x.x.x.x/TimeCapsule 	/media/timecapsule 	cifs 	uid=1000,credentials=/home/xxxxx,iocharset=utf8,vers=1.0,sec=ntlm,serverino 0 0

I had tried enabling and disabling oplocks make no difference, file copy stalls every time after copying about 2.2 GB. The files are mostly RAW pictures in DNG format. As stated previously copying from terminal using cp works fine.
Comment 45 Steve French 2019-08-06 17:11:48 UTC
Does changing wsize and rsize on the mount help (wsize=65536,rsize=65536)?
Comment 46 SDato 2019-08-06 17:29:31 UTC
Same result, I changed the wsize and rsize and having the result. Tried again with oplocks disabled and enabled. The file copy stalls at the same point.
Comment 47 Steve French 2019-08-06 17:44:56 UTC
And can you confirm if you only see the problem with the much older smb1 (cifs, "vers=1.0") dialect, not with the typical SMB3 or SMB3.11 dialect (defaults, or you can specify it directly "vers=3.0").
Comment 48 SDato 2019-08-06 18:04:58 UTC
I do not have any other SMB share at home, that one is the only one and the Apple Time Capsule only supports SMB1, this is the only reason I am using SMB1.
Comment 49 Cédric Bellegarde 2019-09-02 14:15:10 UTC
Hello, here I can confirm the issue with/without oplocks:
- Only happens on small files
- wsize=65536,rsize=65536 does not help
- happens with vers=3.0

Here full gio log while trying to move a small file:

$ LANG=C strace gio move bug ~
execve("/usr/bin/gio", ["gio", "move", "bug", "/home/bellegarde-c"], 0x7ffee6536cb8 /* 53 vars */) = 0
brk(NULL)                               = 0x557cee235000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=125283, ...}) = 0
mmap(NULL, 125283, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f31fbd22000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libgio-2.0.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200\250\3\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=1858736, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f31fbd20000
mmap(NULL, 1868520, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fbb57000
mmap(0x7f31fbb8e000, 1052672, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x37000) = 0x7f31fbb8e000
mmap(0x7f31fbc8f000, 548864, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x138000) = 0x7f31fbc8f000
mmap(0x7f31fbd15000, 36864, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1bd000) = 0x7f31fbd15000
mmap(0x7f31fbd1e000, 4840, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f31fbd1e000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libgmodule-2.0.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\22\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=18328, ...}) = 0
mmap(NULL, 20600, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fbb51000
mmap(0x7f31fbb52000, 8192, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1000) = 0x7f31fbb52000
mmap(0x7f31fbb54000, 4096, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) = 0x7f31fbb54000
mmap(0x7f31fbb55000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) = 0x7f31fbb55000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libglib-2.0.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\275\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=1174832, ...}) = 0
mmap(NULL, 1180072, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fba30000
mprotect(0x7f31fba4b000, 1060864, PROT_NONE) = 0
mmap(0x7f31fba4b000, 524288, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b000) = 0x7f31fba4b000
mmap(0x7f31fbacb000, 532480, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x9b000) = 0x7f31fbacb000
mmap(0x7f31fbb4e000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x11d000) = 0x7f31fbb4e000
mmap(0x7f31fbb50000, 424, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f31fbb50000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libgobject-2.0.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\347\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=370744, ...}) = 0
mmap(NULL, 375688, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb9d4000
mmap(0x7f31fb9e2000, 204800, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xe000) = 0x7f31fb9e2000
mmap(0x7f31fba14000, 98304, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x40000) = 0x7f31fba14000
mmap(0x7f31fba2c000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x57000) = 0x7f31fba2c000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200|\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=149840, ...}) = 0
mmap(NULL, 132288, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb9b3000
mmap(0x7f31fb9ba000, 61440, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x7f31fb9ba000
mmap(0x7f31fb9c9000, 20480, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16000) = 0x7f31fb9c9000
mmap(0x7f31fb9ce000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a000) = 0x7f31fb9ce000
mmap(0x7f31fb9d0000, 13504, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f31fb9d0000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200l\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=2000480, ...}) = 0
mmap(NULL, 2008696, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb7c8000
mmap(0x7f31fb7ed000, 1519616, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x25000) = 0x7f31fb7ed000
mmap(0x7f31fb960000, 299008, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x198000) = 0x7f31fb960000
mmap(0x7f31fb9a9000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1e0000) = 0x7f31fb9a9000
mmap(0x7f31fb9af000, 13944, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f31fb9af000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libz.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P!\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=108768, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f31fb7c6000
mmap(NULL, 110768, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb7aa000
mprotect(0x7f31fb7ac000, 98304, PROT_NONE) = 0
mmap(0x7f31fb7ac000, 69632, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f31fb7ac000
mmap(0x7f31fb7bd000, 24576, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13000) = 0x7f31fb7bd000
mmap(0x7f31fb7c4000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x19000) = 0x7f31fb7c4000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000\21\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=18656, ...}) = 0
mmap(NULL, 20752, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb7a4000
mmap(0x7f31fb7a5000, 8192, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1000) = 0x7f31fb7a5000
mmap(0x7f31fb7a7000, 4096, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) = 0x7f31fb7a7000
mmap(0x7f31fb7a8000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) = 0x7f31fb7a8000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libmount.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\360\275\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=371168, ...}) = 0
mmap(NULL, 374056, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb748000
mmap(0x7f31fb753000, 241664, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xb000) = 0x7f31fb753000
mmap(0x7f31fb78e000, 73728, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x46000) = 0x7f31fb78e000
mmap(0x7f31fb7a0000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x57000) = 0x7f31fb7a0000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 h\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=158928, ...}) = 0
mmap(NULL, 170192, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb71e000
mprotect(0x7f31fb724000, 131072, PROT_NONE) = 0
mmap(0x7f31fb724000, 98304, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x7f31fb724000
mmap(0x7f31fb73c000, 28672, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1e000) = 0x7f31fb73c000
mmap(0x7f31fb744000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x25000) = 0x7f31fb744000
mmap(0x7f31fb746000, 6352, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f31fb746000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libresolv.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240C\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=97072, ...}) = 0
mmap(NULL, 109184, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb703000
mprotect(0x7f31fb707000, 77824, PROT_NONE) = 0
mmap(0x7f31fb707000, 61440, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4000) = 0x7f31fb707000
mmap(0x7f31fb716000, 12288, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13000) = 0x7f31fb716000
mmap(0x7f31fb71a000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16000) = 0x7f31fb71a000
mmap(0x7f31fb71c000, 6784, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f31fb71c000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libpcre.so.3", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p!\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=468944, ...}) = 0
mmap(NULL, 471304, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb68f000
mmap(0x7f31fb691000, 335872, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f31fb691000
mmap(0x7f31fb6e3000, 122880, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x54000) = 0x7f31fb6e3000
mmap(0x7f31fb701000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x71000) = 0x7f31fb701000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libffi.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\"\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=35128, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f31fb68d000
mmap(NULL, 38408, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb683000
mmap(0x7f31fb685000, 20480, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f31fb685000
mmap(0x7f31fb68a000, 4096, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x7f31fb68a000
mmap(0x7f31fb68b000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x7f31fb68b000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libblkid.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\253\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=343008, ...}) = 0
mmap(NULL, 345896, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb62e000
mprotect(0x7f31fb638000, 282624, PROT_NONE) = 0
mmap(0x7f31fb638000, 212992, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xa000) = 0x7f31fb638000
mmap(0x7f31fb66c000, 65536, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3e000) = 0x7f31fb66c000
mmap(0x7f31fb67d000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4e000) = 0x7f31fb67d000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/librt.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\2603\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=39880, ...}) = 0
mmap(NULL, 44000, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb623000
mmap(0x7f31fb626000, 16384, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) = 0x7f31fb626000
mmap(0x7f31fb62a000, 8192, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x7f31fb62a000
mmap(0x7f31fb62c000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x8000) = 0x7f31fb62c000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libuuid.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\340\"\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=30776, ...}) = 0
mmap(NULL, 32792, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb61a000
mmap(0x7f31fb61c000, 16384, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f31fb61c000
mmap(0x7f31fb620000, 4096, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x7f31fb620000
mmap(0x7f31fb621000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x7f31fb621000
close(3)                                = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f31fb618000
mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f31fb615000
arch_prctl(ARCH_SET_FS, 0x7f31fb615880) = 0
mprotect(0x7f31fb9a9000, 12288, PROT_READ) = 0
mprotect(0x7f31fb621000, 4096, PROT_READ) = 0
mprotect(0x7f31fb9ce000, 4096, PROT_READ) = 0
mprotect(0x7f31fb62c000, 4096, PROT_READ) = 0
mprotect(0x7f31fb67d000, 20480, PROT_READ) = 0
mprotect(0x7f31fb68b000, 4096, PROT_READ) = 0
mprotect(0x7f31fb701000, 4096, PROT_READ) = 0
mprotect(0x7f31fb71a000, 4096, PROT_READ) = 0
mprotect(0x7f31fb7a8000, 4096, PROT_READ) = 0
mprotect(0x7f31fb744000, 4096, PROT_READ) = 0
mprotect(0x7f31fb7a0000, 12288, PROT_READ) = 0
mprotect(0x7f31fb7c4000, 4096, PROT_READ) = 0
mprotect(0x7f31fbb4e000, 4096, PROT_READ) = 0
mprotect(0x7f31fba2c000, 12288, PROT_READ) = 0
mprotect(0x7f31fbb55000, 4096, PROT_READ) = 0
mprotect(0x7f31fbd15000, 32768, PROT_READ) = 0
mprotect(0x557cecb23000, 8192, PROT_READ) = 0
mprotect(0x7f31fbd6b000, 4096, PROT_READ) = 0
munmap(0x7f31fbd22000, 125283)          = 0
set_tid_address(0x7f31fb615b50)         = 10210
set_robust_list(0x7f31fb615b60, 24)     = 0
rt_sigaction(SIGRTMIN, {sa_handler=0x7f31fb9ba6c0, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x7f31fb9c6f40}, NULL, 8) = 0
rt_sigaction(SIGRT_1, {sa_handler=0x7f31fb9ba760, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f31fb9c6f40}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
statfs("/sys/fs/selinux", 0x7ffde930fb90) = -1 ENOENT (No such file or directory)
statfs("/selinux", 0x7ffde930fb90)      = -1 ENOENT (No such file or directory)
brk(NULL)                               = 0x557cee235000
brk(0x557cee256000)                     = 0x557cee256000
openat(AT_FDCWD, "/proc/filesystems", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
read(3, "nodev\tsysfs\nnodev\trootfs\nnodev\tr"..., 1024) = 502
read(3, "", 1024)                       = 0
close(3)                                = 0
access("/etc/selinux/config", F_OK)     = -1 ENOENT (No such file or directory)
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gio/modules", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3
fstat(3, {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat("/usr/lib/x86_64-linux-gnu/gio/modules/giomodule.cache", {st_mode=S_IFREG|0644, st_size=270, ...}) = 0
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gio/modules/giomodule.cache", O_RDONLY) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=270, ...}) = 0
read(4, "libdconfsettings.so: gsettings-b"..., 270) = 270
close(4)                                = 0
getdents64(3, /* 9 entries */, 32768)   = 344
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
stat("/usr/lib/x86_64-linux-gnu/gio/modules/libgiognutls.so", {st_mode=S_IFREG|0644, st_size=108680, ...}) = 0
stat("/usr/lib/x86_64-linux-gnu/gio/modules/libgioremote-volume-monitor.so", {st_mode=S_IFREG|0644, st_size=124848, ...}) = 0
stat("/usr/lib/x86_64-linux-gnu/gio/modules/libgiognomeproxy.so", {st_mode=S_IFREG|0644, st_size=22528, ...}) = 0
stat("/usr/lib/x86_64-linux-gnu/gio/modules/libgvfsdbus.so", {st_mode=S_IFREG|0644, st_size=211144, ...}) = 0
stat("/usr/lib/x86_64-linux-gnu/gio/modules/libdconfsettings.so", {st_mode=S_IFREG|0644, st_size=63400, ...}) = 0
stat("/usr/lib/x86_64-linux-gnu/gio/modules/libgiolibproxy.so", {st_mode=S_IFREG|0644, st_size=18432, ...}) = 0
getdents64(3, /* 0 entries */, 32768)   = 0
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/gio/modules", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "lib/x86_64-linux-gnu/charset.alias", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gconv/gconv-modules.cache", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=26402, ...}) = 0
mmap(NULL, 26402, PROT_READ, MAP_SHARED, 3, 0) = 0x7f31fbd3a000
close(3)                                = 0
futex(0x7f31fb9ae6f4, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
stat("/usr/lib/x86_64-linux-gnu/gio/modules/libgvfsdbus.so", {st_mode=S_IFREG|0644, st_size=211144, ...}) = 0
futex(0x7f31fb7a90c8, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gio/modules/libgvfsdbus.so", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\300\276\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=211144, ...}) = 0
mmap(NULL, 213792, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb5e0000
mmap(0x7f31fb5ea000, 118784, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xa000) = 0x7f31fb5ea000
mmap(0x7f31fb607000, 45056, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x27000) = 0x7f31fb607000
mmap(0x7f31fb612000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x31000) = 0x7f31fb612000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gvfs/tls/haswell/x86_64/libgvfscommon.so", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/usr/lib/x86_64-linux-gnu/gvfs/tls/haswell/x86_64", 0x7ffde930ea30) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gvfs/tls/haswell/libgvfscommon.so", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/usr/lib/x86_64-linux-gnu/gvfs/tls/haswell", 0x7ffde930ea30) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gvfs/tls/x86_64/libgvfscommon.so", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/usr/lib/x86_64-linux-gnu/gvfs/tls/x86_64", 0x7ffde930ea30) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gvfs/tls/libgvfscommon.so", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/usr/lib/x86_64-linux-gnu/gvfs/tls", 0x7ffde930ea30) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gvfs/haswell/x86_64/libgvfscommon.so", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/usr/lib/x86_64-linux-gnu/gvfs/haswell/x86_64", 0x7ffde930ea30) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gvfs/haswell/libgvfscommon.so", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/usr/lib/x86_64-linux-gnu/gvfs/haswell", 0x7ffde930ea30) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gvfs/x86_64/libgvfscommon.so", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/usr/lib/x86_64-linux-gnu/gvfs/x86_64", 0x7ffde930ea30) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gvfs/libgvfscommon.so", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\00001\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=251816, ...}) = 0
mmap(NULL, 254648, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f31fb5a1000
mmap(0x7f31fb5b3000, 102400, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x12000) = 0x7f31fb5b3000
mmap(0x7f31fb5cc000, 53248, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2b000) = 0x7f31fb5cc000
mmap(0x7f31fb5d9000, 28672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x37000) = 0x7f31fb5d9000
close(3)                                = 0
mprotect(0x7f31fb5d9000, 24576, PROT_READ) = 0
mprotect(0x7f31fb612000, 8192, PROT_READ) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
eventfd2(0, EFD_CLOEXEC|EFD_NONBLOCK)   = 3
write(3, "\1\0\0\0\0\0\0\0", 8)         = 8
mmap(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f31fada0000
mprotect(0x7f31fada1000, 8388608, PROT_READ|PROT_WRITE) = 0
clone(child_stack=0x7f31fb59fe70, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x7f31fb5a09d0, tls=0x7f31fb5a0700, child_tidptr=0x7f31fb5a09d0) = 10211
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
write(3, "\1\0\0\0\0\0\0\0", 8)         = 8
futex(0x557cee250c40, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
brk(0x557cee277000)                     = 0x557cee277000
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f31fb80bf60}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
eventfd2(0, EFD_CLOEXEC|EFD_NONBLOCK)   = 4
write(4, "\1\0\0\0\0\0\0\0", 8)         = 8
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC, 0) = 5
fcntl(5, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(5, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
connect(5, {sa_family=AF_UNIX, sun_path="/run/user/3121/bus"}, 110) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
getpid()                                = 10210
geteuid()                               = 3121
getegid()                               = 2513
getpid()                                = 10210
geteuid()                               = 3121
getegid()                               = 2513
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
sendmsg(5, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0", iov_len=1}], msg_iovlen=1, msg_control=[{cmsg_len=28, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=10210, uid=3121, gid=2513}}], msg_controllen=32, msg_flags=0}, MSG_NOSIGNAL) = 1
sendto(5, "AUTH\r\n", 6, MSG_NOSIGNAL, NULL, 0) = 6
recvfrom(5, "REJECTED EXTERNAL\r\n", 4096, 0, NULL, NULL) = 19
sendto(5, "AUTH EXTERNAL 33313231\r\n", 24, MSG_NOSIGNAL, NULL, 0) = 24
recvfrom(5, "OK 468259f12965fe35fd294ece5d6d2"..., 4096, 0, NULL, NULL) = 37
sendto(5, "NEGOTIATE_UNIX_FD\r\n", 19, MSG_NOSIGNAL, NULL, 0) = 19
recvfrom(5, "AGREE_UNIX_FD\r\n", 4096, 0, NULL, NULL) = 15
sendto(5, "BEGIN\r\n", 7, MSG_NOSIGNAL, NULL, 0) = 7
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
eventfd2(0, EFD_CLOEXEC|EFD_NONBLOCK)   = 6
write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
mmap(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f31fa59f000
mprotect(0x7f31fa5a0000, 8388608, PROT_READ|PROT_WRITE) = 0
clone(child_stack=0x7f31fad9ee70, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x7f31fad9f9d0, tls=0x7f31fad9f700, child_tidptr=0x7f31fad9f9d0) = 10212
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4fda0, FUTEX_WAKE_PRIVATE, 1) = 0
eventfd2(0, EFD_CLOEXEC|EFD_NONBLOCK)   = 7
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
poll([{fd=7, events=POLLIN}], 1, 25000) = 1 ([{fd=7, revents=POLLIN}])
read(7, "\1\0\0\0\0\0\0\0", 16)         = 8
futex(0x557cee263c90, FUTEX_WAKE_PRIVATE, 1) = 1
poll([{fd=7, events=POLLIN}], 1, 25000) = 1 ([{fd=7, revents=POLLIN}])
read(7, "\1\0\0\0\0\0\0\0", 16)         = 8
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
futex(0x557cee263ca0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
close(7)                                = 0
rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f31fb80bf60}, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f31fb80bf60}, 8) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
eventfd2(0, EFD_CLOEXEC|EFD_NONBLOCK)   = 7
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
poll([{fd=7, events=POLLIN}], 1, 25000) = 1 ([{fd=7, revents=POLLIN}])
read(7, "\2\0\0\0\0\0\0\0", 16)         = 8
write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
poll([{fd=7, events=POLLIN}], 1, 25000) = 1 ([{fd=7, revents=POLLIN}])
read(7, "\1\0\0\0\0\0\0\0", 16)         = 8
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
futex(0x557cee26c5c0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
close(7)                                = 0
eventfd2(0, EFD_CLOEXEC|EFD_NONBLOCK)   = 7
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
poll([{fd=7, events=POLLIN}], 1, 25000) = 1 ([{fd=7, revents=POLLIN}])
read(7, "\1\0\0\0\0\0\0\0", 16)         = 8
poll([{fd=7, events=POLLIN}], 1, 25000) = 1 ([{fd=7, revents=POLLIN}])
read(7, "\1\0\0\0\0\0\0\0", 16)         = 8
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
futex(0x557cee26cc90, FUTEX_WAKE_PRIVATE, 2147483647) = 0
close(7)                                = 0
write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4fcd0, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/gvfs/modules", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = -1 ENOENT (No such file or directory)
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
lstat("/home/bellegarde-c", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
stat(".", {st_mode=S_IFDIR|0700, st_size=0, ...}) = 0
stat("/home/bellegarde-c/R\303\251seau/Perso", {st_mode=S_IFDIR|0700, st_size=0, ...}) = 0
lstat("/home/bellegarde-c/R\303\251seau/Perso/bug", {st_mode=S_IFREG|0755, st_size=4, ...}) = 0
lstat("/home/bellegarde-c/bug", 0x7ffde930fa20) = -1 ENOENT (No such file or directory)
rename("/home/bellegarde-c/R\303\251seau/Perso/bug", "/home/bellegarde-c/bug") = -1 EXDEV (Invalid cross-device link)
lstat("/home/bellegarde-c/R\303\251seau/Perso/bug", {st_mode=S_IFREG|0755, st_size=4, ...}) = 0
openat(AT_FDCWD, "/home/bellegarde-c/R\303\251seau/Perso/bug", O_RDONLY) = 7
fstat(7, {st_mode=S_IFREG|0755, st_size=4, ...}) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
fstat(7, {st_mode=S_IFREG|0755, st_size=4, ...}) = 0
flistxattr(7, NULL, 0)                  = 0
flistxattr(7, NULL, 0)                  = 0
openat(AT_FDCWD, "/home/bellegarde-c/bug", O_WRONLY|O_CREAT|O_EXCL, 0600) = 8
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f31fbb4ff68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
ioctl(8, BTRFS_IOC_CLONE or FICLONE, 7) = -1 EXDEV (Invalid cross-device link)
pipe2([9, 10], O_CLOEXEC)               = 0
fcntl(10, F_SETPIPE_SZ, 1048576)        = 1048576
splice(7, [0], 10, NULL, 1048576, SPLICE_F_MORE) = 4
splice(9, NULL, 8, [0], 4, SPLICE_F_MORE) = 4
splice(7, [4], 10, NULL, 1048576, SPLICE_F_MORE^Cstrace: Process 10210 detached
 <detached ...>
Comment 50 Cédric Bellegarde 2019-09-02 15:47:57 UTC
Fixed the issue on Ubuntu 19.04 by:
- Installing 5.2.0-15-generic from 19.10
- Enabling oplocks on server
- Removing cache=none from mount.cifs

Will be deployed soon, will wait for users feedback.
Comment 51 Cédric Bellegarde 2019-09-02 15:57:31 UTC
Ok, bad news, moving small files now works but copying/moving large directories just hangs... With gio/nautilus, works in command line...
Comment 52 Jorge Correa 2023-01-16 16:22:42 UTC
Hi all! 

I was having similar problems here and note that client and server had different interface MTU size. As I have jumbo frames support in switches, changing both to 9000 the problem disappeared (I'd tested both with 1500 and works too). I don't know if this could be related to the original problem.

Note You need to log in before you can comment on or make changes to this bug.