OK - updated the wording in the warning message (and the comments around it).
If we make it lower than KERN_WARNING it won't be logged by default, and I am
suspicious that we have seen this happen before a network disconnect by the
server so want to at least see it logged once by default in case it turns out to
be related.
I have seen few cases where normal use logs it - so with your suggested
wording change I doubt it will cause confusion.
On Wed, Aug 29, 2018 at 8:15 AM Tom Talpey <ttalpey@xxxxxxxxxxxxx> wrote:
>
> > -----Original Message-----
> > From: linux-cifs-owner@xxxxxxxxxxxxxxx <linux-cifs-owner@xxxxxxxxxxxxxxx> On
> > Behalf Of ronnie sahlberg
> > Sent: Tuesday, August 28, 2018 5:56 PM
> > To: Steve French <smfrench@xxxxxxxxx>
> > Cc: CIFS <linux-cifs@xxxxxxxxxxxxxxx>
> > Subject: Re: [PATCH] smb3: minor debugging clarifications in rfc1001 len
> > processing
> >
> > Reviewed-by: Ronnie Sahlberg <lsahlber@xxxxxxxxxx>
> >
> > On Wed, Aug 29, 2018 at 7:53 AM, Steve French <smfrench@xxxxxxxxx>
> > wrote:
> > > I ran into some cases where the server was returning the wrong length
> > > on frames but I couldn't easily match them to the command in the
> > > network trace (or server logs) since I need the command and/or
> > > multiplex id to find the offending SMB2/SMB3 command. Add these
> > > two fields to the log message.
> > >
> > > Signed-off-by: Steve French <stfrench@xxxxxxxxxxxxx>
> > > ---
> > > fs/cifs/smb2misc.c | 7 +++++--
> > > fs/cifs/smb2ops.c | 4 ++++
> > > 3 files changed, 10 insertions(+), 2 deletions(-)
> > >
> > > diff --git a/fs/cifs/smb2misc.c b/fs/cifs/smb2misc.c
> > > index db0453660ff6..9171720dc658 100644
> > > --- a/fs/cifs/smb2misc.c
> > > +++ b/fs/cifs/smb2misc.c
> > > @@ -254,10 +254,13 @@ smb2_check_message(char *buf, unsigned int len,
> > > struct TCP_Server_Info *srvr)
> > > */
> > > if (clc_len < len) {
> > > printk_once(KERN_WARNING
> > > - "SMB2 server sent bad RFC1001 len %d not %d\n",
> > > - len, clc_len);
> > > + "srv rsp too long %d not %d for cmd:%d mid:%llu\n",
> > > + len, clc_len, command, mid);
>
> Why is this a KERN_WARNING? It's not fatal, and not illegal.
> Seems to me it's a KERN_INFO.
>
> I'd suggest rather than "too long", a more informational wording
> such as "longer than expected" or similar.
>
> Tom.
>
> > > return 0;
> > > }
> > > + printk_once(KERN_WARNING
> > > + "srv rsp too short, len %d not %d. cmd:%d mid:%llu\n",
> > > + len, clc_len, command, mid);
> > >
> > > return 1;
> > > }
> > >
> > >
> > > --
> > > Thanks,
> > >
> > > Steve
--
Thanks,
Steve
From 2079d36729a741d0aa77d801907cfa414b7c2361 Mon Sep 17 00:00:00 2001
From: Steve French <stfrench@xxxxxxxxxxxxx>
Date: Wed, 29 Aug 2018 09:22:22 -0500
Subject: [PATCH 01/13] smb3: minor debugging clarifications in rfc1001 len
processing
I ran into some cases where server was returning the wrong length
on frames but I couldn't easily match them to the command in the
network trace (or server logs) since I need the command and/or
multiplex id to find the offending SMB2/SMB3 command. Add these
two fields to the log message. In the case of padding too much
it may not be a problem in all cases but might have correlated
to a network disconnect case in some problems we have been
looking at. In the case of frame too short is even more important.
Signed-off-by: Steve French <stfrench@xxxxxxxxxxxxx>
Reviewed-by: Ronnie Sahlberg <lsahlber@xxxxxxxxxx>
---
fs/cifs/smb2misc.c | 14 +++++++++-----
1 file changed, 9 insertions(+), 5 deletions(-)
diff --git a/fs/cifs/smb2misc.c b/fs/cifs/smb2misc.c
index db0453660ff6..6a9c47541c53 100644
--- a/fs/cifs/smb2misc.c
+++ b/fs/cifs/smb2misc.c
@@ -248,16 +248,20 @@ smb2_check_message(char *buf, unsigned int len, struct TCP_Server_Info *srvr)
* MacOS server pads after SMB2.1 write response with 3 bytes
* of junk. Other servers match RFC1001 len to actual
* SMB2/SMB3 frame length (header + smb2 response specific data)
- * Some windows servers do too when compounding is used.
- * Log the server error (once), but allow it and continue
+ * Some windows servers also pad up to 8 bytes when compounding.
+ * If pad is longer than eight bytes, log the server behavior
+ * (once), since may indicate a problem but allow it and continue
* since the frame is parseable.
*/
if (clc_len < len) {
- printk_once(KERN_WARNING
- "SMB2 server sent bad RFC1001 len %d not %d\n",
- len, clc_len);
+ pr_warn_once(
+ "srv rsp padded more than expected. Length %d not %d for cmd:%d mid:%llu\n",
+ len, clc_len, command, mid);
return 0;
}
+ pr_warn_once(
+ "srv rsp too short, len %d not %d. cmd:%d mid:%llu\n",
+ len, clc_len, command, mid);
return 1;
}
--
2.17.1
