Are you comfortable with dynamic tracing ("trace-cmd record -e ..."
... the list of trace points can be seen in
/sys/kernel/debug/tracing/events/cifs)?
On Fri, May 1, 2020 at 10:40 AM Scott M. Lewandowski
<vgerkernel@xxxxxxxxxx> wrote:
>
> I’m also seeing entries like the following mixed in with the other messages:
>
> [27078.665192] CIFS VFS: \\file1 Cancelling wait for mid 13443257 cmd: 5
>
> And
>
> [31833.351785] CIFS VFS: cifs_invalidate_mapping: could not invalidate inode 00000000b4733e96
>
>
>
>
> > -----Original Message-----
> > From: Scott M. Lewandowski <vgerkernel@xxxxxxxxxx>
> > Sent: Friday, May 1, 2020 12:20 AM
> > To: 'Steve French' <smfrench@xxxxxxxxx>
> > Cc: CIFS <linux-cifs@xxxxxxxxxxxxxxx>
> > Subject: RE: issues with CIFS on Ubuntu 20 mounting Windows 2019
> >
> > > EINTR on read ... Hundreds of times?! I have seen scp do that by
> > > sending signals but in writes not reads
> >
> > Not using scp at the moment.
> >
> > > Could an app be sending signals trying to kill the process doing the reads?
> >
> > Not that I'm aware of. I'm not sure exactly how I'd check that, but I will look
> > into it.
> >
> > One other thing that came to mind that may be helpful is that one of the
> > processes doing the most IO is running under mono 6.8.0.105
> >
> > -scott
> >
> >
> >
> >
> > From: Steve French <smfrench@xxxxxxxxx>
> > Sent: Friday, May 1, 2020 12:07 AM
> > To: Scott M. Lewandowski <vgerkernel@xxxxxxxxxx>
> > Cc: CIFS <linux-cifs@xxxxxxxxxxxxxxx>
> > Subject: Re: issues with CIFS on Ubuntu 20 mounting Windows 2019
> >
> > EINTR on read ... Hundreds of times?! I have seen scp do that by sending
> > signals but in writes not reads
> >
> > On Thu, Apr 30, 2020, 23:48 Scott M. Lewandowski
> > <mailto:vgerkernel@xxxxxxxxxx> wrote:
> > I have an Ubuntu 20.04 box mounting shares from a Windows 2019 server.
> > Both boxes are fully patched. They are resident on the same hypervisor and
> > communicating directly via a vSwitch. I have 4 shares mounted; here is an
> > example from my fstab (yes, I know I should move the credential file):
> >
> > //file1/usenet /mnt/usenet cifs
> > vers=3.0,uid=scott,credentials=/home/scott/.smbcredentials,noserverino,n
> > ounix,iocharset=utf8 0 0
> >
> > My kernel is 5.4.0-28-generic and mount.cifs version is 6.9. The contents of
> > DebugData are included below.
> >
> > Right after the mount, I see a duplicate cookie reported. It is unclear if this is
> > a problem or not. Following that, I periodically see messages similar to the
> > following repeated in dmesg:
> >
> > [ 179.625296] SMB2_read: 9 callbacks suppressed [ 179.625298] CIFS VFS:
> > Send error in read = -4 [ 179.704191] CIFS VFS: Send error in read = -4
> > [ 179.847514] CIFS VFS: Send error in read = -4 [ 180.031516] CIFS VFS: Send
> > error in read = -4 [ 180.214848] CIFS VFS: Send error in read = -4
> > [ 180.282909] CIFS VFS: Send error in read = -4 [ 180.474829] CIFS VFS: Send
> > error in read = -4 [ 180.621349] CIFS VFS: Send error in read = -4
> > [ 180.780465] CIFS VFS: Send error in read = -4 [ 180.823249] CIFS VFS: Send
> > error in read = -4 [ 182.339351] CIFS VFS: Close unmatched open
> > [ 182.726829] CIFS VFS: Close unmatched open [ 184.292663] CIFS VFS: Close
> > unmatched open [ 184.501185] CIFS VFS: Close unmatched open
> > [ 191.784922] SMB2_read: 4 callbacks suppressed [ 191.784925] CIFS VFS:
> > Send error in read = -4 [ 191.884186] CIFS VFS: Send error in read = -4
> > [ 192.270851] CIFS VFS: Send error in read = -4 [ 192.323467] CIFS VFS: Send
> > error in read = -4 [ 192.381336] CIFS VFS: Send error in read = -4
> > [ 192.446711] CIFS VFS: Send error in read = -4 [ 192.507605] CIFS VFS: Send
> > error in read = -4 [ 193.244397] CIFS VFS: Send error in read = -4
> > [ 193.307588] CIFS VFS: Send error in read = -4 [ 193.403410] CIFS VFS: Send
> > error in read = -4 [ 193.797038] CIFS VFS: Close unmatched open
> > [ 196.784082] CIFS VFS: Close unmatched open [ 198.247594] CIFS VFS: Close
> > unmatched open
> >
> > Here is the duplicate cookie info:
> >
> > [ 21.713307] FS-Cache: Duplicate cookie detected [ 21.713840] FS-Cache: O-
> > cookie c=00000000e8276279 [p=0000000079ef0365 fl=222 nc=0 na=1]
> > [ 21.714330] FS-Cache: O-cookie d=00000000173ea0ee n=00000000243f210c
> > [ 21.714779] FS-Cache: O-key=[8] '020001bdc0a801af'
> > [ 21.715219] FS-Cache: N-cookie c=00000000afb49d9c [p=0000000079ef0365
> > fl=2 nc=0 na=1] [ 21.715672] FS-Cache: N-cookie d=00000000173ea0ee
> > n=00000000dd1465c5 [ 21.716141] FS-Cache: N-key=[8] '020001bdc0a801af'
> > [ 21.716591] FS-Cache: Duplicate cookie detected [ 21.717217] FS-Cache: O-
> > cookie c=00000000e8276279 [p=0000000079ef0365 fl=222 nc=0 na=1]
> > [ 21.717679] FS-Cache: O-cookie d=00000000173ea0ee n=00000000243f210c
> > [ 21.718220] FS-Cache: O-key=[8] '020001bdc0a801af'
> > [ 21.718681] FS-Cache: N-cookie c=0000000063665cf7 [p=0000000079ef0365
> > fl=2 nc=0 na=1] [ 21.719166] FS-Cache: N-cookie d=00000000173ea0ee
> > n=00000000e757f917 [ 21.719621] FS-Cache: N-key=[8] '020001bdc0a801af'
> > [ 21.720097] FS-Cache: Duplicate cookie detected [ 21.720565] FS-Cache: O-
> > cookie c=00000000e8276279 [p=0000000079ef0365 fl=222 nc=0 na=1]
> > [ 21.721053] FS-Cache: O-cookie d=00000000173ea0ee n=00000000243f210c
> > [ 21.721518] FS-Cache: O-key=[8] '020001bdc0a801af'
> > [ 21.721994] FS-Cache: N-cookie c=00000000d479c294 [p=0000000079ef0365
> > fl=2 nc=0 na=1] [ 21.722476] FS-Cache: N-cookie d=00000000173ea0ee
> > n=00000000ca1891fa [ 21.722941] FS-Cache: N-key=[8] '020001bdc0a801af'
> >
> > Any ideas what could be going on?
> >
> > Thanks for any help!
> >
> >
> >
> >
> >
> >
> > DebugData:
> > CIFS Version 2.23
> > Features:
> > DFS,FSCACHE,STATS,DEBUG,ALLOW_INSECURE_LEGACY,WEAK_PW_HASH,C
> > IFS_POSIX,UPCALL(SPNEGO),XATTR,ACL
> > CIFSMaxBufSize: 16384
> > Active VFS Requests: 0
> > Servers:
> > Number of credits: 8190 Dialect 0x300
> > 1) Name: 192.168.1.175 Uses: 1 Capability: 0x300067 Session Status: 1 TCP
> > status: 1 Instance: 1
> > Local Users To Server: 1 SecMode: 0x1 Req On Wire: 0 SessionId:
> > 0x100080000021
> > Shares:
> > 0) IPC: \\file1\IPC$ Mounts: 1 DevInfo: 0x0 Attributes: 0x0
> > PathComponentMax: 0 Status: 1 type: 0 Serial Number: 0x0
> > Share Capabilities: None Share Flags: 0x30
> > tid: 0x1 Maximal Access: 0x11f01ff
> >
> > 1) \\file1\XXX Mounts: 1 DevInfo: 0x20020 Attributes: 0x8500df
> > PathComponentMax: 255 Status: 1 type: DISK Serial Number: 0xa3c339a0
> > Share Capabilities: None Aligned, Partition Aligned, Share Flags: 0x0
> > tid: 0x5 Optimal sector size: 0x200 Maximal Access: 0x1f01ff
> >
> > MIDs:
> >
> > Server interfaces: 2
> > 0) Speed: 10000000000 bps
> > Capabilities:
> > IPv6: fe80:0000:0000:0000:71cb:1839:1069:9806
> > 1) Speed: 10000000000 bps
> > Capabilities:
> > IPv4: 192.168.1.175
> > Number of credits: 8190 Dialect 0x300
> >
> > 2) Name: 192.168.1.175 Uses: 1 Capability: 0x300067 Session Status: 1 TCP
> > status: 1 Instance: 1
> > Local Users To Server: 1 SecMode: 0x1 Req On Wire: 0 SessionId:
> > 0x10006c000019
> > Shares:
> > 0) IPC: \\file1\IPC$ Mounts: 1 DevInfo: 0x0 Attributes: 0x0
> > PathComponentMax: 0 Status: 1 type: 0 Serial Number: 0x0
> > Share Capabilities: None Share Flags: 0x30
> > tid: 0x1 Maximal Access: 0x11f01ff
> >
> > 1) \\file1\usenet Mounts: 1 DevInfo: 0x20020 Attributes: 0x8500df
> > PathComponentMax: 255 Status: 1 type: DISK Serial Number: 0xa3c339a0
> > Share Capabilities: None Aligned, Partition Aligned, Share Flags: 0x0
> > tid: 0x5 Optimal sector size: 0x200 Maximal Access: 0x1f01ff
> >
> > MIDs:
> >
> > Server interfaces: 2
> > 0) Speed: 10000000000 bps
> > Capabilities:
> > IPv6: fe80:0000:0000:0000:71cb:1839:1069:9806
> > 1) Speed: 10000000000 bps
> > Capabilities:
> > IPv4: 192.168.1.175
> >
> >
> > 3) Name: 192.168.1.175 Uses: 1 Capability: 0x300067 Session Status: 1 TCP
> > status: 1 Instance: 1
> > Local Users To Server: 1 SecMode: 0x1 Req On Wire: 2 SessionId:
> > 0x10007c000061
> > Shares:
> > 0) IPC: \\file1\IPC$ Mounts: 1 DevInfo: 0x0 Attributes: 0x0
> > PathComponentMax: 0 Status: 1 type: 0 Serial Number: 0x0
> > Share Capabilities: None Share Flags: 0x30
> > tid: 0x1 Maximal Access: 0x11f01ff
> >
> > 1) \\file1\YYY Mounts: 1 DevInfo: 0x20020 Attributes: 0x8500df
> > PathComponentMax: 255 Status: 1 type: DISK Serial Number: 0xa3c339a0
> > Share Capabilities: None Aligned, Partition Aligned, Share Flags: 0x0
> > tid: 0x5 Optimal sector size: 0x200 Maximal Access: 0x1f01ff
> >
> > MIDs:
> > State: 2 com: 8 pid: 1218 cbdata: 00000000e45c59d2 mid 1211489
> > State: 2 com: 8 pid: 1218 cbdata: 0000000018476195 mid 1211553
> >
> > Server interfaces: 2
> > 0) Speed: 10000000000 bps
> > Capabilities:
> > IPv6: fe80:0000:0000:0000:71cb:1839:1069:9806
> > 1) Speed: 10000000000 bps
> > Capabilities:
> > IPv4: 192.168.1.175
> >
> > Number of credits: 8190 Dialect 0x300
> > 4) Name: 192.168.1.175 Uses: 1 Capability: 0x300067 Session Status: 1 TCP
> > status: 1 Instance: 1
> > Local Users To Server: 1 SecMode: 0x1 Req On Wire: 0 SessionId:
> > 0x10006c000055
> > Shares:
> > 0) IPC: \\file1\IPC$ Mounts: 1 DevInfo: 0x0 Attributes: 0x0
> > PathComponentMax: 0 Status: 1 type: 0 Serial Number: 0x0
> > Share Capabilities: None Share Flags: 0x30
> > tid: 0x1 Maximal Access: 0x11f01ff
> >
> > 1) \\file1\ZZZ Mounts: 1 DevInfo: 0x20020 Attributes: 0x8500df
> > PathComponentMax: 255 Status: 1 type: DISK Serial Number: 0xa3c339a0
> > Share Capabilities: None Aligned, Partition Aligned, Share Flags: 0x0
> > tid: 0x5 Optimal sector size: 0x200 Maximal Access: 0x1f01ff
> >
> > MIDs:
> >
> > Server interfaces: 2
> > 0) Speed: 10000000000 bps
> > Capabilities:
> > IPv6: fe80:0000:0000:0000:71cb:1839:1069:9806
> > 1) Speed: 10000000000 bps
> > Capabilities:
> > IPv4: 192.168.1.175
--
Thanks,
Steve
