Unstable CIFS mount on CentOS 8

Question

We recently created several centOS 8 serveur for running some springboot applications, which mount several directories from a windows server. Mount is working, but we are getting lots of errors at random time of the day

sample dmesg output:

[Wed Oct 21 15:31:21 2020] CIFS VFS: Send error in SessSetup = -11
[Wed Oct 21 18:59:56 2020] CIFS VFS: Send error in SessSetup = -11
[Thu Oct 22 07:37:51 2020] CIFS VFS: Send error in SessSetup = -11
[Thu Oct 22 08:28:37 2020] CIFS VFS: Send error in SessSetup = -11
[Thu Oct 22 08:49:07 2020] CIFS VFS: Server XXXXXXX has not responded in 120 seconds. Reconnecting...
[Thu Oct 22 11:07:38 2020] CIFS VFS: Send error in SessSetup = -11
[Thu Oct 22 11:07:52 2020] CIFS VFS: Send error in SessSetup = -11
[Thu Oct 22 14:20:52 2020] CIFS VFS: Send error in SessSetup = -11
[Thu Oct 22 17:22:24 2020] CIFS VFS: Send error in SessSetup = -11
[Fri Oct 23 06:33:03 2020] CIFS VFS: Send error in SessSetup = -11
[Fri Oct 23 06:35:03 2020] CIFS VFS: Server XXXXXXX has not responded in 120 seconds. Reconnecting...
[Fri Oct 23 08:27:45 2020] CIFS VFS: Send error in SessSetup = -11
[Fri Oct 23 08:28:06 2020] CIFS VFS: Send error in SessSetup = -11

The issue does not arise when we mount the same dir from centOS 7

Mount

centOS 7

//SERVER/DATA on /mnt/data type cifs (rw,nosuid,noexec,relatime,vers=3.0,cache=strict,username=data_user,domain=xxx.xxx.xxx,uid=1000,forceuid,gid=1000,forcegid,addr=xxx.xx.x.xx,file_mode=0755,dir_mode=0755,soft,nounix,serverino,mapposix,rsize=1048576,wsize=1048576,echo_interval=60,actimeo=1)

centOS 8

//SERVER/DATA on /mnt/data type cifs (rw,nosuid,noexec,relatime,vers=3.0,cache=strict,username=data_user,domain=xxx.xxx.xxx,uid=1000,forceuid,gid=1000,forcegid,addr=xxx.xx.x.xx,file_mode=0755,dir_mode=0755,soft,nounix,serverino,mapposix,rsize=1048576,wsize=1048576,bsize=65536,echo_interval=60,actimeo=1)

Kernel and package version

+-----------+-----------------------------+-----------------------------+
|   prop    |          CentOS 7           |          centOS 8           |
+-----------+-----------------------------+-----------------------------+
| kernel    | 3.10.0-1127.18.2.el7.x86_64 | 4.18.0-147.8.1.el8_1.x86_64 |
| cifs-util | 6.2-10.el7                  | 6.8-3.el8                   |
+-----------+-----------------------------+-----------------------------+

Here is the exact sequence leading to the error on CentOS 8, with cifs debug enabled:

[Thu Oct 22 10:04:58 2020] fs/cifs/dir.c: name: \data
[Thu Oct 22 10:04:58 2020] fs/cifs/dir.c: name: \data
[Thu Oct 22 10:04:58 2020] fs/cifs/inode.c: Update attributes: \data inode 0x00000000bc98fea9 count 1 dentry: 0x00000000bd47d1e0 d_time 15148690417 jiffies 15179170239
[Thu Oct 22 10:04:58 2020] fs/cifs/inode.c: Getting info on \data
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2ops.c: set credits to 1 due to smb2 reconnect
[Thu Oct 22 10:04:58 2020] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2pdu.c: In echo request
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2pdu.c: Need negotiate, reconnecting tcons
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2pdu.c: Negotiate protocol
[Thu Oct 22 10:04:58 2020] fs/cifs/transport.c: Sending smb: smb_len=106
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2pdu.c: Negotiate protocol
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: RFC1002 header 0xf8
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2misc.c: SMB2 data length 120 offset 128
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2misc.c: SMB2 len 248
[Thu Oct 22 10:04:58 2020] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0 mid=0 state=4
[Thu Oct 22 10:04:58 2020] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2pdu.c: mode 0x1
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[Thu Oct 22 10:04:58 2020] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[Thu Oct 22 10:04:58 2020] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
[Thu Oct 22 10:04:58 2020] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
[Thu Oct 22 10:04:58 2020] fs/cifs/asn1.c: OID len = 8 oid = 0x1 0x2 0x348 0x1bb92
[Thu Oct 22 10:04:58 2020] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: Security Mode: 0x1 Capabilities: 0x300067 TimeAdjust: 0
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: Free previous auth_key.response = 00000000a46e9e42
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2pdu.c: Session Setup
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2pdu.c: sess setup type 4
[Thu Oct 22 10:04:58 2020] fs/cifs/transport.c: Sending smb: smb_len=124
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: Received no data or error: -104
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: cifs_reconnect: will retry 0 target(s)
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: Mark tcp session as need reconnect
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: cifs_reconnect: marking sessions and tcons for reconnect
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: cifs_reconnect: tearing down socket
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: State: 0x3 Flags: 0x0
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: Post shutdown state: 0x3 Flags: 0x0
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: cifs_reconnect: moving mids to private list
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: cifs_reconnect: issuing mid callbacks
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: Socket created
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
[Thu Oct 22 10:04:58 2020] fs/cifs/transport.c: cifs_sync_mid_result: cmd=1 mid=0 state=8
[Thu Oct 22 10:04:58 2020] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[Thu Oct 22 10:04:58 2020] CIFS VFS: Send error in SessSetup = -11
[Thu Oct 22 10:04:58 2020] fs/cifs/connect.c: cifs_put_tcon: tc_count=2
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2ops.c: set credits to 1 due to smb2 reconnect
[Thu Oct 22 10:04:58 2020] fs/cifs/smb2pdu.c: In echo request
[Thu Oct 22 10:05:09 2020] fs/cifs/smb2pdu.c: Negotiate protocol
[Thu Oct 22 10:05:09 2020] fs/cifs/transport.c: Sending smb: smb_len=106
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: RFC1002 header 0xf8
[Thu Oct 22 10:05:09 2020] fs/cifs/smb2misc.c: SMB2 data length 120 offset 128
[Thu Oct 22 10:05:09 2020] fs/cifs/smb2misc.c: SMB2 len 248
[Thu Oct 22 10:05:09 2020] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0 mid=0 state=4
[Thu Oct 22 10:05:09 2020] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[Thu Oct 22 10:05:09 2020] fs/cifs/smb2pdu.c: mode 0x1
[Thu Oct 22 10:05:09 2020] fs/cifs/transport.c: Sending smb: smb_len=106
[Thu Oct 22 10:05:09 2020] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[Thu Oct 22 10:05:09 2020] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[Thu Oct 22 10:05:09 2020] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
[Thu Oct 22 10:05:09 2020] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
[Thu Oct 22 10:05:09 2020] fs/cifs/asn1.c: OID len = 8 oid = 0x1 0x2 0x348 0x1bb92
[Thu Oct 22 10:05:09 2020] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: Security Mode: 0x1 Capabilities: 0x300067 TimeAdjust: 0
[Thu Oct 22 10:05:09 2020] fs/cifs/smb2pdu.c: Session Setup
[Thu Oct 22 10:05:09 2020] fs/cifs/smb2pdu.c: sess setup type 4
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: Received no data or error: -104
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: cifs_reconnect: will retry 0 target(s)
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: Mark tcp session as need reconnect
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: cifs_reconnect: marking sessions and tcons for reconnect
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: cifs_reconnect: tearing down socket
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: State: 0x3 Flags: 0x0
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: Post shutdown state: 0x3 Flags: 0x0
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: cifs_reconnect: moving mids to private list
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: cifs_reconnect: issuing mid callbacks
[Thu Oct 22 10:05:09 2020] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0 mid=1 state=8
[Thu Oct 22 10:05:09 2020] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: Socket created
[Thu Oct 22 10:05:09 2020] fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
[Thu Oct 22 10:05:09 2020] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[Thu Oct 22 10:05:09 2020] fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate_dentry_attr (xid = 35385880) rc = -112
[Thu Oct 22 10:05:09 2020] fs/cifs/inode.c: CIFS VFS: in cifs_revalidate_dentry_attr as Xid: 35385881 with uid: 1004

Windows server is a windows 2016 server. The only logs that appears on this server at the same time are these:

<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
   <System>
      <Provider Name="Service Control Manager" Guid="{555908d1-a6d7-4695-8e1e-26931d2012f4}" EventSourceName="Service Control Manager" />
      <EventID Qualifiers="16384">7036</EventID>
      <Version>0</Version>
      <Level>4</Level>
      <Task>0</Task>
      <Opcode>0</Opcode>
      <Keywords>0x8080000000000000</Keywords>
      <TimeCreated SystemTime="2020-10-16T10:42:59.636088900Z" />
      <Channel>System</Channel>
      <Computer>XXX.xxx.xxx</Computer>
   </System>
   <EventData>
      <Data Name="param1">Connection Assistant with a Microsoft account</Data>
      <Data Name="param2">stopped</Data>
      <Binary>77006C00690064007300760063002F0031000000</Binary>
   </EventData>
</Event>

<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
   <System>
      <Provider Name="Service Control Manager" Guid="{555908d1-a6d7-4695-8e1e-26931d2012f4}" EventSourceName="Service Control Manager" />
      <EventID Qualifiers="16384">7036</EventID>
      <Version>0</Version>
      <Level>4</Level>
      <Task>0</Task>
      <Opcode>0</Opcode>
      <Keywords>0x8080000000000000</Keywords>
      <TimeCreated SystemTime="2020-10-16T10:42:20.692575900Z" />
      <Channel>System</Channel>
      <Computer>XXX.xxx.xxx</Computer>
   </System>
   <EventData>
      <Data Name="param1">Client licenses service (ClipSVC)</Data>
      <Data Name="param2">stopped</Data>
      <Binary>43006C00690070005300560043002F0031000000</Binary>
   </EventData>
</Event>

After looking at open sessions in windows server, we noticed that user sessions from centOS 8 are automatically disconnected every 30 minutes, whereas user session from centOS 7 are note disconnected

It looks like the server is dropping the connection. Can you find anything in its logs? — Michael Hampton, Oct 26 '20 at 00:14
Hi @MichaelHampton, I added the only events that pops in windows server logs at the same time, they appear as 'information' — felix, Oct 27 '20 at 02:58
@felix, we have similar observations with CentOS8. CIFS mounts were stable on CentOS7. We had to migrate to CentOS8 and the CIFS mounts are unstable now. It is possible to connect, but shares are being dropped randomly after some time. And logs are full with `Send error in SessSetup = -13` messages. Let me know if you have any idea how to fix this. Thanks! — djhurio, Dec 01 '20 at 11:09

Unstable CIFS mount on CentOS 8

0 Answers0