SUNRPC: Trace GSS context lifetimes
authorChuck Lever <chuck.lever@oracle.com>
Tue, 12 May 2020 21:13:07 +0000 (17:13 -0400)
committerAnna Schumaker <Anna.Schumaker@Netapp.com>
Thu, 11 Jun 2020 17:33:47 +0000 (13:33 -0400)
Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Signed-off-by: Anna Schumaker <Anna.Schumaker@Netapp.com>
include/trace/events/rpcgss.h
net/sunrpc/auth_gss/auth_gss.c
net/sunrpc/auth_gss/trace.c

index 421b14db87ae32a251526b5436f5cbbdcdd05568..b9b51a4b1db143029fa33f2aa6aa8f0211c2cf0c 100644 (file)
  ** GSS-API related trace events
  **/
 
+TRACE_DEFINE_ENUM(RPC_GSS_SVC_NONE);
+TRACE_DEFINE_ENUM(RPC_GSS_SVC_INTEGRITY);
+TRACE_DEFINE_ENUM(RPC_GSS_SVC_PRIVACY);
+
+#define show_gss_service(x)                                            \
+       __print_symbolic(x,                                             \
+               { RPC_GSS_SVC_NONE,             "none" },               \
+               { RPC_GSS_SVC_INTEGRITY,        "integrity" },          \
+               { RPC_GSS_SVC_PRIVACY,          "privacy" })
+
 TRACE_DEFINE_ENUM(GSS_S_BAD_MECH);
 TRACE_DEFINE_ENUM(GSS_S_BAD_NAME);
 TRACE_DEFINE_ENUM(GSS_S_BAD_NAMETYPE);
@@ -126,6 +136,40 @@ DEFINE_GSSAPI_EVENT(verify_mic);
 DEFINE_GSSAPI_EVENT(wrap);
 DEFINE_GSSAPI_EVENT(unwrap);
 
+DECLARE_EVENT_CLASS(rpcgss_ctx_class,
+       TP_PROTO(
+               const struct gss_cred *gc
+       ),
+
+       TP_ARGS(gc),
+
+       TP_STRUCT__entry(
+               __field(const void *, cred)
+               __field(unsigned long, service)
+               __string(principal, gc->gc_principal)
+       ),
+
+       TP_fast_assign(
+               __entry->cred = gc;
+               __entry->service = gc->gc_service;
+               __assign_str(principal, gc->gc_principal)
+       ),
+
+       TP_printk("cred=%p service=%s principal='%s'",
+               __entry->cred, show_gss_service(__entry->service),
+               __get_str(principal))
+);
+
+#define DEFINE_CTX_EVENT(name)                                         \
+       DEFINE_EVENT(rpcgss_ctx_class, rpcgss_ctx_##name,               \
+                       TP_PROTO(                                       \
+                               const struct gss_cred *gc               \
+                       ),                                              \
+                       TP_ARGS(gc))
+
+DEFINE_CTX_EVENT(init);
+DEFINE_CTX_EVENT(destroy);
+
 TRACE_EVENT(rpcgss_svc_accept_upcall,
        TP_PROTO(
                __be32 xid,
@@ -405,6 +449,7 @@ TRACE_EVENT(rpcgss_upcall_result,
 
 TRACE_EVENT(rpcgss_context,
        TP_PROTO(
+               u32 window_size,
                unsigned long expiry,
                unsigned long now,
                unsigned int timeout,
@@ -412,12 +457,13 @@ TRACE_EVENT(rpcgss_context,
                const u8 *data
        ),
 
-       TP_ARGS(expiry, now, timeout, len, data),
+       TP_ARGS(window_size, expiry, now, timeout, len, data),
 
        TP_STRUCT__entry(
                __field(unsigned long, expiry)
                __field(unsigned long, now)
                __field(unsigned int, timeout)
+               __field(u32, window_size)
                __field(int, len)
                __string(acceptor, data)
        ),
@@ -426,13 +472,14 @@ TRACE_EVENT(rpcgss_context,
                __entry->expiry = expiry;
                __entry->now = now;
                __entry->timeout = timeout;
+               __entry->window_size = window_size;
                __entry->len = len;
                strncpy(__get_str(acceptor), data, len);
        ),
 
-       TP_printk("gc_expiry=%lu now=%lu timeout=%u acceptor=%.*s",
-               __entry->expiry, __entry->now, __entry->timeout,
-               __entry->len, __get_str(acceptor))
+       TP_printk("win_size=%u expiry=%lu now=%lu timeout=%u acceptor=%.*s",
+               __entry->window_size, __entry->expiry, __entry->now,
+               __entry->timeout, __entry->len, __get_str(acceptor))
 );
 
 
index 5f097c8cacd1bc83586cf5056f545a4e788ab6e2..429f17459ae395699d122bbca950f3dfb4f3b6a0 100644 (file)
@@ -254,7 +254,7 @@ gss_fill_context(const void *p, const void *end, struct gss_cl_ctx *ctx, struct
        if (IS_ERR(p))
                goto err;
 done:
-       trace_rpcgss_context(ctx->gc_expiry, now, timeout,
+       trace_rpcgss_context(window_size, ctx->gc_expiry, now, timeout,
                             ctx->gc_acceptor.len, ctx->gc_acceptor.data);
 err:
        return p;
@@ -697,10 +697,12 @@ retry:
                }
                schedule();
        }
-       if (gss_msg->ctx)
+       if (gss_msg->ctx) {
+               trace_rpcgss_ctx_init(gss_cred);
                gss_cred_set_ctx(cred, gss_msg->ctx);
-       else
+       } else {
                err = gss_msg->msg.errno;
+       }
        spin_unlock(&pipe->lock);
 out_intr:
        finish_wait(&gss_msg->waitqueue, &wait);
@@ -1284,6 +1286,7 @@ gss_send_destroy_context(struct rpc_cred *cred)
        if (new) {
                ctx->gc_proc = RPC_GSS_PROC_DESTROY;
 
+               trace_rpcgss_ctx_destroy(gss_cred);
                task = rpc_call_null(gss_auth->client, &new->gc_base,
                                RPC_TASK_ASYNC|RPC_TASK_SOFT);
                if (!IS_ERR(task))
@@ -1349,7 +1352,6 @@ gss_destroy_nullcred(struct rpc_cred *cred)
 static void
 gss_destroy_cred(struct rpc_cred *cred)
 {
-
        if (test_and_clear_bit(RPCAUTH_CRED_UPTODATE, &cred->cr_flags) != 0)
                gss_send_destroy_context(cred);
        gss_destroy_nullcred(cred);
index 5576f1e66de925327d9ac33d05d5f24db283637c..49fa583d7f91b81f08b3c6d04f14d9d8e6271fbd 100644 (file)
@@ -6,6 +6,7 @@
 #include <linux/sunrpc/clnt.h>
 #include <linux/sunrpc/sched.h>
 #include <linux/sunrpc/gss_err.h>
+#include <linux/sunrpc/auth_gss.h>
 
 #define CREATE_TRACE_POINTS
 #include <trace/events/rpcgss.h>