From: Bruce Fields <bfields@fieldses.org>
To: Chuck Lever <chuck.lever@oracle.com>
Cc: Linux NFS Mailing List <linux-nfs@vger.kernel.org>
Subject: Re: [PATCH v1 1/2] SUNRPC: Trace gssproxy upcall results
Date: Mon, 28 Oct 2019 12:45:41 -0400 [thread overview]
Message-ID: <20191028164541.GC5339@fieldses.org> (raw)
In-Reply-To: <CBBEAFFB-584C-4196-B24B-6664EABE5E39@oracle.com>
On Thu, Oct 24, 2019 at 01:08:20PM -0400, Chuck Lever wrote:
>
>
> > On Oct 24, 2019, at 11:38 AM, J. Bruce Fields <bfields@fieldses.org> wrote:
> >
> > On Thu, Oct 24, 2019 at 09:34:10AM -0400, Chuck Lever wrote:
> >> Record results of a GSS proxy ACCEPT_SEC_CONTEXT upcall and the
> >> svc_authenticate() function to make field debugging of NFS server
> >> Kerberos issues easier.
> >
> > Inclined to apply.
> >
> > The only thing that bugs me a bit is that this is just summarizing
> > information that's passing between the kernel and userspace--so it seems
> > like a job for strace or wireshark or something.
>
> You could use those tools. However:
>
> - strace probably isn't going to provide symbolic values for the GSS major status
>
> - wireshark is unwieldy for initial debugging on servers with no graphics capability
I don't think tcpdump, copy the file, then run wireshark, is that bad,
and there are probably ways to automate that if necessary.
The bigger problem seems to be that there's no way to do the capture:
https://unix.stackexchange.com/questions/219853/how-to-passively-capture-from-unix-domain-sockets-af-unix-socket-monitoring
I wish we could fix that somehow.
--b.
>
> The upcall trace point is built into the kernel. Flip it on and it will tell a
> system administrator immediately what the upcall result was.
>
>
> > --b.
> >
> >>
> >> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
> >> Reviewed-by: Bill Baker <bill.baker@oracle.com>
> >> ---
> >> include/trace/events/rpcgss.h | 45 +++++++++++++++++++++++++++
> >> include/trace/events/sunrpc.h | 55 +++++++++++++++++++++++++++++++++
> >> net/sunrpc/auth_gss/gss_mech_switch.c | 4 ++
> >> net/sunrpc/auth_gss/svcauth_gss.c | 8 +++--
> >> net/sunrpc/svc.c | 2 +
> >> net/sunrpc/svcauth.c | 2 +
> >> 6 files changed, 112 insertions(+), 4 deletions(-)
> >>
> >> diff --git a/include/trace/events/rpcgss.h b/include/trace/events/rpcgss.h
> >> index d1f7fe1..9827f53 100644
> >> --- a/include/trace/events/rpcgss.h
> >> +++ b/include/trace/events/rpcgss.h
> >> @@ -126,6 +126,34 @@
> >> DEFINE_GSSAPI_EVENT(wrap);
> >> DEFINE_GSSAPI_EVENT(unwrap);
> >>
> >> +TRACE_EVENT(rpcgss_accept_upcall,
> >> + TP_PROTO(
> >> + __be32 xid,
> >> + u32 major_status,
> >> + u32 minor_status
> >> + ),
> >> +
> >> + TP_ARGS(xid, major_status, minor_status),
> >> +
> >> + TP_STRUCT__entry(
> >> + __field(u32, xid)
> >> + __field(u32, minor_status)
> >> + __field(unsigned long, major_status)
> >> + ),
> >> +
> >> + TP_fast_assign(
> >> + __entry->xid = be32_to_cpu(xid);
> >> + __entry->minor_status = minor_status;
> >> + __entry->major_status = major_status;
> >> + ),
> >> +
> >> + TP_printk("xid=0x%08x major_status=%s (0x%08lx) minor_status=%u",
> >> + __entry->xid, __entry->major_status == 0 ? "GSS_S_COMPLETE" :
> >> + show_gss_status(__entry->major_status),
> >> + __entry->major_status, __entry->minor_status
> >> + )
> >> +);
> >> +
> >>
> >> /**
> >> ** GSS auth unwrap failures
> >> @@ -355,6 +383,23 @@
> >> show_pseudoflavor(__entry->flavor), __entry->error)
> >> );
> >>
> >> +TRACE_EVENT(rpcgss_oid_to_mech,
> >> + TP_PROTO(
> >> + const char *oid
> >> + ),
> >> +
> >> + TP_ARGS(oid),
> >> +
> >> + TP_STRUCT__entry(
> >> + __string(oid, oid)
> >> + ),
> >> +
> >> + TP_fast_assign(
> >> + __assign_str(oid, oid);
> >> + ),
> >> +
> >> + TP_printk("mech for oid %s was not found", __get_str(oid))
> >> +);
> >>
> >> #endif /* _TRACE_RPCGSS_H */
> >>
> >> diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
> >> index ffa3c51..c358a0a 100644
> >> --- a/include/trace/events/sunrpc.h
> >> +++ b/include/trace/events/sunrpc.h
> >> @@ -14,6 +14,26 @@
> >> #include <linux/net.h>
> >> #include <linux/tracepoint.h>
> >>
> >> +TRACE_DEFINE_ENUM(RPC_AUTH_OK);
> >> +TRACE_DEFINE_ENUM(RPC_AUTH_BADCRED);
> >> +TRACE_DEFINE_ENUM(RPC_AUTH_REJECTEDCRED);
> >> +TRACE_DEFINE_ENUM(RPC_AUTH_BADVERF);
> >> +TRACE_DEFINE_ENUM(RPC_AUTH_REJECTEDVERF);
> >> +TRACE_DEFINE_ENUM(RPC_AUTH_TOOWEAK);
> >> +TRACE_DEFINE_ENUM(RPCSEC_GSS_CREDPROBLEM);
> >> +TRACE_DEFINE_ENUM(RPCSEC_GSS_CTXPROBLEM);
> >> +
> >> +#define rpc_show_auth_stat(status) \
> >> + __print_symbolic(status, \
> >> + { RPC_AUTH_OK, "AUTH_OK" }, \
> >> + { RPC_AUTH_BADCRED, "BADCRED" }, \
> >> + { RPC_AUTH_REJECTEDCRED, "REJECTEDCRED" }, \
> >> + { RPC_AUTH_BADVERF, "BADVERF" }, \
> >> + { RPC_AUTH_REJECTEDVERF, "REJECTEDVERF" }, \
> >> + { RPC_AUTH_TOOWEAK, "TOOWEAK" }, \
> >> + { RPCSEC_GSS_CREDPROBLEM, "GSS_CREDPROBLEM" }, \
> >> + { RPCSEC_GSS_CTXPROBLEM, "GSS_CTXPROBLEM" }) \
> >> +
> >> DECLARE_EVENT_CLASS(rpc_task_status,
> >>
> >> TP_PROTO(const struct rpc_task *task),
> >> @@ -866,6 +886,41 @@
> >> show_rqstp_flags(__entry->flags))
> >> );
> >>
> >> +#define svc_show_status(status) \
> >> + __print_symbolic(status, \
> >> + { SVC_GARBAGE, "SVC_GARBAGE" }, \
> >> + { SVC_SYSERR, "SVC_SYSERR" }, \
> >> + { SVC_VALID, "SVC_VALID" }, \
> >> + { SVC_NEGATIVE, "SVC_NEGATIVE" }, \
> >> + { SVC_OK, "SVC_OK" }, \
> >> + { SVC_DROP, "SVC_DROP" }, \
> >> + { SVC_CLOSE, "SVC_CLOSE" }, \
> >> + { SVC_DENIED, "SVC_DENIED" }, \
> >> + { SVC_PENDING, "SVC_PENDING" }, \
> >> + { SVC_COMPLETE, "SVC_COMPLETE" })
> >> +
> >> +TRACE_EVENT(svc_authenticate,
> >> + TP_PROTO(const struct svc_rqst *rqst, int auth_res, __be32 auth_stat),
> >> +
> >> + TP_ARGS(rqst, auth_res, auth_stat),
> >> +
> >> + TP_STRUCT__entry(
> >> + __field(u32, xid)
> >> + __field(unsigned long, svc_status)
> >> + __field(unsigned long, auth_stat)
> >> + ),
> >> +
> >> + TP_fast_assign(
> >> + __entry->xid = be32_to_cpu(rqst->rq_xid);
> >> + __entry->svc_status = auth_res;
> >> + __entry->auth_stat = be32_to_cpu(auth_stat);
> >> + ),
> >> +
> >> + TP_printk("xid=0x%08x auth_res=%s auth_stat=%s",
> >> + __entry->xid, svc_show_status(__entry->svc_status),
> >> + rpc_show_auth_stat(__entry->auth_stat))
> >> +);
> >> +
> >> TRACE_EVENT(svc_process,
> >> TP_PROTO(const struct svc_rqst *rqst, const char *name),
> >>
> >> diff --git a/net/sunrpc/auth_gss/gss_mech_switch.c b/net/sunrpc/auth_gss/gss_mech_switch.c
> >> index 8206009..30b7de6 100644
> >> --- a/net/sunrpc/auth_gss/gss_mech_switch.c
> >> +++ b/net/sunrpc/auth_gss/gss_mech_switch.c
> >> @@ -20,6 +20,7 @@
> >> #include <linux/sunrpc/sched.h>
> >> #include <linux/sunrpc/gss_api.h>
> >> #include <linux/sunrpc/clnt.h>
> >> +#include <trace/events/rpcgss.h>
> >>
> >> #if IS_ENABLED(CONFIG_SUNRPC_DEBUG)
> >> # define RPCDBG_FACILITY RPCDBG_AUTH
> >> @@ -158,7 +159,6 @@ struct gss_api_mech *gss_mech_get_by_OID(struct rpcsec_gss_oid *obj)
> >>
> >> if (sprint_oid(obj->data, obj->len, buf, sizeof(buf)) < 0)
> >> return NULL;
> >> - dprintk("RPC: %s(%s)\n", __func__, buf);
> >> request_module("rpc-auth-gss-%s", buf);
> >>
> >> rcu_read_lock();
> >> @@ -172,6 +172,8 @@ struct gss_api_mech *gss_mech_get_by_OID(struct rpcsec_gss_oid *obj)
> >> }
> >> }
> >> rcu_read_unlock();
> >> + if (!gm)
> >> + trace_rpcgss_oid_to_mech(buf);
> >> return gm;
> >> }
> >>
> >> diff --git a/net/sunrpc/auth_gss/svcauth_gss.c b/net/sunrpc/auth_gss/svcauth_gss.c
> >> index 8be2f20..f130990 100644
> >> --- a/net/sunrpc/auth_gss/svcauth_gss.c
> >> +++ b/net/sunrpc/auth_gss/svcauth_gss.c
> >> @@ -49,6 +49,9 @@
> >> #include <linux/sunrpc/svcauth.h>
> >> #include <linux/sunrpc/svcauth_gss.h>
> >> #include <linux/sunrpc/cache.h>
> >> +
> >> +#include <trace/events/rpcgss.h>
> >> +
> >> #include "gss_rpc_upcall.h"
> >>
> >>
> >> @@ -1270,9 +1273,8 @@ static int svcauth_gss_proxy_init(struct svc_rqst *rqstp,
> >> if (status)
> >> goto out;
> >>
> >> - dprintk("RPC: svcauth_gss: gss major status = %d "
> >> - "minor status = %d\n",
> >> - ud.major_status, ud.minor_status);
> >> + trace_rpcgss_accept_upcall(rqstp->rq_xid, ud.major_status,
> >> + ud.minor_status);
> >>
> >> switch (ud.major_status) {
> >> case GSS_S_CONTINUE_NEEDED:
> >> diff --git a/net/sunrpc/svc.c b/net/sunrpc/svc.c
> >> index d11b705..187dd4e 100644
> >> --- a/net/sunrpc/svc.c
> >> +++ b/net/sunrpc/svc.c
> >> @@ -1337,6 +1337,8 @@ static __printf(2,3) void svc_printk(struct svc_rqst *rqstp, const char *fmt, ..
> >> auth_stat = rpc_autherr_badcred;
> >> auth_res = progp->pg_authenticate(rqstp);
> >> }
> >> + if (auth_res != SVC_OK)
> >> + trace_svc_authenticate(rqstp, auth_res, auth_stat);
> >> switch (auth_res) {
> >> case SVC_OK:
> >> break;
> >> diff --git a/net/sunrpc/svcauth.c b/net/sunrpc/svcauth.c
> >> index 550b214..552617e 100644
> >> --- a/net/sunrpc/svcauth.c
> >> +++ b/net/sunrpc/svcauth.c
> >> @@ -19,6 +19,8 @@
> >> #include <linux/err.h>
> >> #include <linux/hash.h>
> >>
> >> +#include <trace/events/sunrpc.h>
> >> +
> >> #define RPCDBG_FACILITY RPCDBG_AUTH
> >>
> >>
>
> --
> Chuck Lever
>
>
next prev parent reply other threads:[~2019-10-28 16:45 UTC|newest]
Thread overview: 9+ messages / expand[flat|nested] mbox.gz Atom feed top
2019-10-24 13:34 [PATCH v1 1/2] SUNRPC: Trace gssproxy upcall results Chuck Lever
2019-10-24 13:34 ` [PATCH v1 2/2] SUNRPC: Fix svcauth_gss_proxy_init() Chuck Lever
2019-10-24 13:35 ` Chuck Lever
2019-10-24 14:02 ` Simo Sorce
2019-10-30 20:33 ` Bruce Fields
2019-10-24 15:38 ` [PATCH v1 1/2] SUNRPC: Trace gssproxy upcall results J. Bruce Fields
2019-10-24 17:08 ` Chuck Lever
2019-10-28 16:45 ` Bruce Fields [this message]
2019-10-30 20:34 ` Bruce Fields
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20191028164541.GC5339@fieldses.org \
--to=bfields@fieldses.org \
--cc=chuck.lever@oracle.com \
--cc=linux-nfs@vger.kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox