From ff27e9f748303e8567bfceb6d7ff264cbcaca2ef Mon Sep 17 00:00:00 2001 From: Chuck Lever Date: Thu, 24 Oct 2019 09:34:10 -0400 Subject: SUNRPC: Trace gssproxy upcall results 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. Signed-off-by: Chuck Lever Reviewed-by: Bill Baker Signed-off-by: J. Bruce Fields --- 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 d1f7fe1b6fe4..9827f535f032 100644 --- a/include/trace/events/rpcgss.h +++ b/include/trace/events/rpcgss.h @@ -126,6 +126,34 @@ DEFINE_GSSAPI_EVENT(verify_mic); 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 @@ TRACE_EVENT(rpcgss_createauth, 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 ffa3c51dbb1a..c358a0af683b 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -14,6 +14,26 @@ #include #include +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 @@ TRACE_EVENT(svc_recv, 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 82060099a429..30b7de6f3d76 100644 --- a/net/sunrpc/auth_gss/gss_mech_switch.c +++ b/net/sunrpc/auth_gss/gss_mech_switch.c @@ -20,6 +20,7 @@ #include #include #include +#include #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 8be2f209982b..f1309905aed3 100644 --- a/net/sunrpc/auth_gss/svcauth_gss.c +++ b/net/sunrpc/auth_gss/svcauth_gss.c @@ -49,6 +49,9 @@ #include #include #include + +#include + #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 d11b70552c33..187dd4e73d64 100644 --- a/net/sunrpc/svc.c +++ b/net/sunrpc/svc.c @@ -1337,6 +1337,8 @@ svc_process_common(struct svc_rqst *rqstp, struct kvec *argv, struct kvec *resv) 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 550b214cb001..552617e3467b 100644 --- a/net/sunrpc/svcauth.c +++ b/net/sunrpc/svcauth.c @@ -19,6 +19,8 @@ #include #include +#include + #define RPCDBG_FACILITY RPCDBG_AUTH -- cgit v1.2.3