Message ID | CAH2r5ms2jpBVtpYaE2hOgnfnjx73MnmPW2pQZnY-42ARYMf9ZQ@mail.gmail.com |
---|---|
State | New |
Headers | show |
Series | [SMB3,client] minor updates to "stop flooding dmesg" patch | expand |
Steve French <smfrench@gmail.com> writes: > I was not as comfortable with taking out where the error is logged on > session setup, but the other parts of the two patches below were fine. > So have added them back into for-next after the one small change to " > smb: client: stop flooding dmesg on failed session setups" NAK. These changes just invalidated the patch entirely. Either remove it or make the "Send error in SessSetup" error messages being printed out only once. The client can still flood dmesg with "\\<hostname> Send error in SessSetup = ..." messages over failed session setups with this patch. Just try it yourself: kinit ... for i in `seq 300`; do mount.cifs //srv/share /mnt -o sec=krb5,echo_interval=5,nosharesock,nohandlecache; done # disconnect srv sleep 30 kdestroy -A # reconnect srv journalctl -k -f ... CIFS: VFS: \\srv has not responded in 15 seconds. Reconnecting... CIFS: VFS: \\srv has not responded in 15 seconds. Reconnecting... CIFS: VFS: \\srv has not responded in 15 seconds. Reconnecting... CIFS: VFS: \\srv has not responded in 15 seconds. Reconnecting... CIFS: VFS: \\srv has not responded in 15 seconds. Reconnecting... CIFS: VFS: \\srv has not responded in 15 seconds. Reconnecting... CIFS: VFS: \\srv has not responded in 15 seconds. Reconnecting... CIFS: VFS: \\srv has not responded in 15 seconds. Reconnecting... CIFS: VFS: \\srv has not responded in 15 seconds. Reconnecting... CIFS: VFS: \\srv has not responded in 15 seconds. Reconnecting... cifs_setup_session: 23 callbacks suppressed CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 cifs_setup_session: 1618 callbacks suppressed CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 cifs_setup_session: 1786 callbacks suppressed CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 cifs_setup_session: 1728 callbacks suppressed CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 CIFS: VFS: \\srv Send error in SessSetup = -126 ...
Steve French <smfrench@gmail.com> writes: > We still will need to have a way to log these messages at least every few > minutes if error in session setup. That is Clifton critical information for > user to know Agreed. I just think that "\\<srv> Send error in SessSetup = ..." doesn't really mean anything to the user. Further I/Os from the user will fail with -ENOKEY, which also doesn't tell much. Without this message we at least have VFS: \\srv has not responded in N seconds. Reconnecting... which tells the user that connection was lost. And, in case server dropped the session (e.g. STATUS_USER_SESSION_DELETED), we'll also have the above message printed out as we currently mark tcp ses for reconnect. We still need to handle these excessive upcalls as in my example we have several kworkers attempting to reconnect a SMB session (on every 2s) and then repeatedly failing due to expired key. This could be done in a different patch, though.
Paulo Alcantara <pc@manguebit.com> writes: > Without this message we at least have > > VFS: \\srv has not responded in N seconds. Reconnecting... > > which tells the user that connection was lost. And, in case server > dropped the session (e.g. STATUS_USER_SESSION_DELETED), we'll also have > the above message printed out as we currently mark tcp ses for > reconnect. Err, no. I forgot that we only print this in server_unresponsive(). We call cifs_reconnect() when the session is dropped and don't print anything.
my goal was to at least get the non-controversial debug message spamming improvements in, even if figuring out the rest of them (to make sure we are logging important session setup failures enough for users to see the error at least once) will take more work to improve. On Tue, Oct 8, 2024 at 3:25 PM Paulo Alcantara <pc@manguebit.com> wrote: > > Paulo Alcantara <pc@manguebit.com> writes: > > > Without this message we at least have > > > > VFS: \\srv has not responded in N seconds. Reconnecting... > > > > which tells the user that connection was lost. And, in case server > > dropped the session (e.g. STATUS_USER_SESSION_DELETED), we'll also have > > the above message printed out as we currently mark tcp ses for > > reconnect. > > Err, no. I forgot that we only print this in server_unresponsive(). We > call cifs_reconnect() when the session is dropped and don't print > anything.
From 2f34f5e966f7d99418b42b8c67cffbbbde94704b Mon Sep 17 00:00:00 2001 From: Paulo Alcantara <pc@manguebit.com> Date: Wed, 18 Sep 2024 02:04:12 -0300 Subject: [PATCH 1/2] smb: client: stop flooding dmesg on failed session setups Stop flooding dmesg over failed session setups as kerberos tickets getting expired or passwords being rotated is a very common scenario. Signed-off-by: Paulo Alcantara (Red Hat) <pc@manguebit.com> Signed-off-by: Steve French <stfrench@microsoft.com> --- fs/smb/client/connect.c | 2 ++ fs/smb/client/smb2pdu.c | 4 ++-- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/fs/smb/client/connect.c b/fs/smb/client/connect.c index 15d94ac4095e..48e87f3a7b24 100644 --- a/fs/smb/client/connect.c +++ b/fs/smb/client/connect.c @@ -3374,6 +3374,8 @@ int cifs_mount_get_session(struct cifs_mount_ctx *mnt_ctx) ses = cifs_get_smb_ses(server, ctx); if (IS_ERR(ses)) { rc = PTR_ERR(ses); + if (rc == -ENOKEY && ctx->sectype == Kerberos) + cifs_dbg(VFS, "Verify user has a krb5 ticket and keyutils is installed\n"); ses = NULL; goto out; } diff --git a/fs/smb/client/smb2pdu.c b/fs/smb/client/smb2pdu.c index b2f16a7b696d..6f7f9a1f0a1f 100644 --- a/fs/smb/client/smb2pdu.c +++ b/fs/smb/client/smb2pdu.c @@ -1636,8 +1636,8 @@ SMB2_auth_kerberos(struct SMB2_sess_data *sess_data) spnego_key = cifs_get_spnego_key(ses, server); if (IS_ERR(spnego_key)) { rc = PTR_ERR(spnego_key); - if (rc == -ENOKEY) - cifs_dbg(VFS, "Verify user has a krb5 ticket and keyutils is installed\n"); + cifs_dbg(FYI, "%s: couldn't auth with kerberos: %d\n", + __func__, rc); spnego_key = NULL; goto out; } -- 2.43.0