I'm trying to become comfortable now 😊
I have it setup to capture all CIFS events, but I haven't seen the messages in dmesg since. I'm not sure if I've just gotten unlucky, or if the instrumentation is changing the behavior.
> -----Original Message-----
> From: Steve French <smfrench@xxxxxxxxx>
> Sent: Friday, May 1, 2020 10:57 AM
> To: Scott M. Lewandowski <vgerkernel@xxxxxxxxxx>
> Cc: Scott M. Lewandowski <scott@xxxxxxxxxxxxxxxxx>; CIFS <linux-
> cifs@xxxxxxxxxxxxxxx>
> Subject: Re: issues with CIFS on Ubuntu 20 mounting Windows 2019
>
> 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,noserveri
> > > no,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
