#StackBounty: #linux #centos #mount #cifs #centos8 Unstable CIFS mount on CentOS 8

Bounty: 100

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


Get this bounty!!!

Leave a Reply

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.