[Samba] System freeze if mount cifs share with option "hard", and samba server is not available

Sun Dec 25 11:37:15 UTC 2016

I know "hard" means command will hang if network is broken. But it seems that's not actuate. It's CPU that will hang.

Affected scope:

I tested it against CentOS 5/6/7, it can be reproduced on all the systems. the debug logs below are captured from CentOS 7 (cifs.ko v2.05)

How to reproduce this problem?

1. mount a cifs share with option "hard"

2. stop samba server

3. access the mount point (e.g. ls /mnt)

Actual result:

case #1: if system has only one CPU (one core):

(1) system will get freeze after about 20 seconds. No command can be run, but I can ping the system from another machine;

(2) CPU goes to 100% (using VM, I can monitor CPU usage from hypervisor management console. )

(3) System will not be back even after samba server is started again;

case #2: if system has more than one CPU:

(1) the command will hang, but system is still responsive (can run other commands)

(2) CPU goes high, but not 100%

(3) the command can exit after samba server is started again

(4) observe the following log in "dmesg":

Dec 25 05:35:56 machine-hostname kernel: BUG: soft lockup - CPU#1 stuck for 22s! [du:2602]

Dec 25 05:35:56 machine-hostname kernel: [<ffffffff810a6806>] prepare_to_wait+0x56/0x90
Dec 25 05:35:56 machine-hostname kernel: [<ffffffffa04052cb>] cifs_reconnect_tcon+0xbb/0x2f0 [cifs]
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff810a6ae0>] ? wake_up_atomic_t+0x30/0x30
Dec 25 05:35:56 machine-hostname kernel: [<ffffffffa04055ba>] smb_init+0x2a/0x50 [cifs]
Dec 25 05:35:56 machine-hostname kernel: [<ffffffffa040bd8a>] CIFSSMBUnixQPathInfo+0x7a/0x2e0 [cifs]
Dec 25 05:35:56 machine-hostname kernel: [<ffffffffa042224b>] cifs_get_inode_info_unix+0x8b/0x1e0 [cifs]
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff811e8ba0>] ? complete_walk+0x60/0xe0
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff811ed823>] ? path_lookupat+0x83/0x7a0
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff8116b8f5>] ? filemap_fault+0x225/0x430
Dec 25 05:35:56 machine-hostname kernel: [<ffffffffa023ed4c>] ? xfs_iunlock+0x11c/0x130 [xfs]
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff811c1d95>] ? __kmalloc+0x55/0x230
Dec 25 05:35:56 machine-hostname kernel: [<ffffffffa041723e>] ? build_path_from_dentry+0xae/0x290 [cifs]
Dec 25 05:35:56 machine-hostname kernel: [<ffffffffa041723e>] ? build_path_from_dentry+0xae/0x290 [cifs]
Dec 25 05:35:56 machine-hostname kernel: [<ffffffffa04247c0>] cifs_revalidate_dentry_attr+0xd0/0x1e0 [cifs]
Dec 25 05:35:56 machine-hostname kernel: [<ffffffffa0424987>] cifs_getattr+0x57/0x130 [cifs]
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff811e34c6>] vfs_getattr+0x46/0x80
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff811e35f5>] vfs_fstatat+0x75/0xc0
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff811e3c04>] SYSC_newfstatat+0x24/0x60
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff816411b3>] ? trace_do_page_fault+0x43/0x110
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff816408d9>] ? do_async_page_fault+0x29/0xe0
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff8163d438>] ? async_page_fault+0x28/0x30
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff811e3e4e>] SyS_newfstatat+0xe/0x10
Dec 25 05:35:56 machine-hostname kernel: [<ffffffff81645909>] system_call_fastpath+0x16/0x1b
(5) enable "cifsFYI", observed cifs.ko keeps printing the logs below:

[ 3058.820504] fs/cifs/file.c: 7: iov_base=ffff8800129e6000 iov_len=4096
[ 3058.820506] fs/cifs/file.c: 8: iov_base=ffff88003d4e3000 iov_len=4096
[ 3058.820508] fs/cifs/file.c: 9: iov_base=ffff8800109cb000 iov_len=4096
[ 3058.820510] fs/cifs/file.c: 10: iov_base=ffff88003b56b000 iov_len=4096
[ 3058.820512] fs/cifs/file.c: 11: iov_base=ffff880013bd6000 iov_len=4096
[ 3058.820515] fs/cifs/cifssmb.c: total_read=49216 buflen=49216 remaining=49152
[ 3058.820529] fs/cifs/cifssmb.c: cifs_readv_callback: mid=61459 state=4 result=0 bytes=49152
[ 3058.820531] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 3058.820546] fs/cifs/cifssmb.c: cifs_async_readv: offset=116178944 bytes=16384
[ 3058.820547] fs/cifs/transport.c: For smb_command 46
[ 3058.820548] fs/cifs/transport.c: Sending smb: smb_len=59
[ 3058.820961] fs/cifs/connect.c: RFC1002 header 0x403c
[ 3058.820963] fs/cifs/cifssmb.c: cifs_readv_receive: mid=61460 offset=116178944 bytes=16384
[ 3058.820964] fs/cifs/cifssmb.c: cifs_readv_receive: total_read=63 data_offset=64
[ 3058.820965] fs/cifs/cifssmb.c: 0: iov_base=ffff880036267d40 iov_len=64
[ 3058.820966] fs/cifs/file.c: 0: iov_base=ffff880013bd6000 iov_len=4096
[ 3058.820968] fs/cifs/file.c: 1: iov_base=ffff88003b56b000 iov_len=4096
[ 3058.820970] fs/cifs/file.c: 2: iov_base=ffff8800109cb000 iov_len=4096
[ 3058.820972] fs/cifs/file.c: 3: iov_base=ffff88003d4e3000 iov_len=4096
[ 3058.820975] fs/cifs/cifssmb.c: total_read=16448 buflen=16448 remaining=16384
[ 3058.820976] fs/cifs/cifssmb.c: cifs_readv_callback: mid=61460 state=4 result=0 bytes=16384
[ 3058.820978] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 3058.821600] fs/cifs/cifssmb.c: cifs_async_readv: offset=116195328 bytes=49152
[ 3058.821602] fs/cifs/transport.c: For smb_command 46
[ 3058.821603] fs/cifs/transport.c: Sending smb: smb_len=59
[ 3058.821982] fs/cifs/connect.c: RFC1002 header 0xc03c
[ 3058.821985] fs/cifs/cifssmb.c: cifs_readv_receive: mid=61461 offset=116195328 bytes=49152
[ 3058.821986] fs/cifs/cifssmb.c: cifs_readv_receive: total_read=63 data_offset=64
[ 3058.821987] fs/cifs/cifssmb.c: 0: iov_base=ffff880036267d40 iov_len=64
[ 3058.821988] fs/cifs/file.c: 0: iov_base=ffff880036797000 iov_len=4096
[ 3058.821990] fs/cifs/file.c: 1: iov_base=ffff8800367cc000 iov_len=4096
[ 3058.821992] fs/cifs/file.c: 2: iov_base=ffff88003d069000 iov_len=4096
[ 3058.821993] fs/cifs/file.c: 3: iov_base=ffff8800156b8000 iov_len=4096
[ 3058.821995] fs/cifs/file.c: 4: iov_base=ffff88003d07b000 iov_len=4096
[ 3058.821997] fs/cifs/file.c: 5: iov_base=ffff880014f7b000 iov_len=4096
[ 3058.821999] fs/cifs/file.c: 6: iov_base=ffff88003b44d000 iov_len=4096
[ 3058.822001] fs/cifs/file.c: 7: iov_base=ffff880013aba000 iov_len=4096
[ 3058.822015] fs/cifs/file.c: 8: iov_base=ffff880013abb000 iov_len=4096
[ 3058.822016] fs/cifs/file.c: 9: iov_base=ffff880036856000 iov_len=4096
[ 3058.822018] fs/cifs/file.c: 10: iov_base=ffff880036857000 iov_len=4096
[ 3058.822020] fs/cifs/file.c: 11: iov_base=ffff880010a8e000 iov_len=4096
[ 3058.822023] fs/cifs/cifssmb.c: total_read=49216 buflen=49216 remaining=49152
[ 3058.822024] fs/cifs/cifssmb.c: cifs_readv_callback: mid=61461 state=4 result=0 bytes=49152
[ 3058.822026] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 3058.822040] fs/cifs/cifssmb.c: cifs_async_readv: offset=116244480 bytes=16384
[ 3058.822041] fs/cifs/transport.c: For smb_command 46
[ 3058.822042] fs/cifs/transport.c: Sending smb: smb_len=59
[ 3058.822418] fs/cifs/connect.c: RFC1002 header 0x403c
[ 3058.822420] fs/cifs/cifssmb.c: cifs_readv_receive: mid=61462 offset=116244480 bytes=16384
[ 3058.822422] fs/cifs/cifssmb.c: cifs_readv_receive: total_read=63 data_offset=64
[ 3058.822423] fs/cifs/cifssmb.c: 0: iov_base=ffff880036267d40 iov_len=64
[ 3058.822424] fs/cifs/file.c: 0: iov_base=ffff880010a8e000 iov_len=4096
[ 3058.822426] fs/cifs/file.c: 1: iov_base=ffff880036857000 iov_len=4096
[ 3058.822428] fs/cifs/file.c: 2: iov_base=ffff880036856000 iov_len=4096
[ 3058.822430] fs/cifs/file.c: 3: iov_base=ffff880013abb000 iov_len=4096
[ 3058.822434] fs/cifs/cifssmb.c: total_read=16448 buflen=16448 remaining=16384
[ 3058.822435] fs/cifs/cifssmb.c: cifs_readv_callback: mid=61462 state=4 result=0 bytes=16384
[ 3058.822437] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 3058.822967] fs/cifs/cifssmb.c: cifs_async_readv: offset=116260864 bytes=49152
[ 3058.822969] fs/cifs/transport.c: For smb_command 46
[ 3058.822970] fs/cifs/transport.c: Sending smb: smb_len=59
[ 3058.833419] fs/cifs/connect.c: RFC1002 header 0xc03c
[ 3058.833423] fs/cifs/cifssmb.c: cifs_readv_receive: mid=61463 offset=116260864 bytes=49152
[ 3058.833425] fs/cifs/cifssmb.c: cifs_readv_receive: total_read=63 data_offset=64
[ 3058.833438] fs/cifs/cifssmb.c: 0: iov_base=ffff880036267d40 iov_len=64
[ 3058.833440] fs/cifs/file.c: 0: iov_base=ffff8800206d5000 iov_len=4096
[ 3058.833441] fs/cifs/file.c: 1: iov_base=ffff88003d1d6000 iov_len=4096
[ 3058.833444] fs/cifs/file.c: 2: iov_base=ffff8800367cd000 iov_len=4096
[ 3058.833445] fs/cifs/file.c: 3: iov_base=ffff88003acd2000 iov_len=4096
[ 3058.833447] fs/cifs/file.c: 4: iov_base=ffff88003acd3000 iov_len=4096
[ 3058.833449] fs/cifs/file.c: 5: iov_base=ffff88003d128000 iov_len=4096

Thanks

Mike