Commit 42aad0d7 authored by Chuck Lever's avatar Chuck Lever Committed by Anna Schumaker

SUNRPC: trace RPC client lifetime events

The "create" tracepoint records parts of the rpc_create arguments,
and the shutdown tracepoint records when the rpc_clnt is about to
signal pending tasks and destroy auths.
Signed-off-by: default avatarChuck Lever <chuck.lever@oracle.com>
Signed-off-by: default avatarAnna Schumaker <Anna.Schumaker@Netapp.com>
parent 911813d7
...@@ -65,6 +65,117 @@ DEFINE_RPCXDRBUF_EVENT(recvfrom); ...@@ -65,6 +65,117 @@ DEFINE_RPCXDRBUF_EVENT(recvfrom);
DEFINE_RPCXDRBUF_EVENT(reply_pages); DEFINE_RPCXDRBUF_EVENT(reply_pages);
DECLARE_EVENT_CLASS(rpc_clnt_class,
TP_PROTO(
const struct rpc_clnt *clnt
),
TP_ARGS(clnt),
TP_STRUCT__entry(
__field(unsigned int, client_id)
),
TP_fast_assign(
__entry->client_id = clnt->cl_clid;
),
TP_printk("clid=%u", __entry->client_id)
);
#define DEFINE_RPC_CLNT_EVENT(name) \
DEFINE_EVENT(rpc_clnt_class, \
rpc_clnt_##name, \
TP_PROTO( \
const struct rpc_clnt *clnt \
), \
TP_ARGS(clnt))
DEFINE_RPC_CLNT_EVENT(free);
DEFINE_RPC_CLNT_EVENT(killall);
DEFINE_RPC_CLNT_EVENT(shutdown);
DEFINE_RPC_CLNT_EVENT(release);
DEFINE_RPC_CLNT_EVENT(replace_xprt);
DEFINE_RPC_CLNT_EVENT(replace_xprt_err);
TRACE_EVENT(rpc_clnt_new,
TP_PROTO(
const struct rpc_clnt *clnt,
const struct rpc_xprt *xprt,
const char *program,
const char *server
),
TP_ARGS(clnt, xprt, program, server),
TP_STRUCT__entry(
__field(unsigned int, client_id)
__string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
__string(port, xprt->address_strings[RPC_DISPLAY_PORT])
__string(program, program)
__string(server, server)
),
TP_fast_assign(
__entry->client_id = clnt->cl_clid;
__assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
__assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
__assign_str(program, program)
__assign_str(server, server)
),
TP_printk("client=%u peer=[%s]:%s program=%s server=%s",
__entry->client_id, __get_str(addr), __get_str(port),
__get_str(program), __get_str(server))
);
TRACE_EVENT(rpc_clnt_new_err,
TP_PROTO(
const char *program,
const char *server,
int error
),
TP_ARGS(program, server, error),
TP_STRUCT__entry(
__field(int, error)
__string(program, program)
__string(server, server)
),
TP_fast_assign(
__entry->error = error;
__assign_str(program, program)
__assign_str(server, server)
),
TP_printk("program=%s server=%s error=%d",
__get_str(program), __get_str(server), __entry->error)
);
TRACE_EVENT(rpc_clnt_clone_err,
TP_PROTO(
const struct rpc_clnt *clnt,
int error
),
TP_ARGS(clnt, error),
TP_STRUCT__entry(
__field(unsigned int, client_id)
__field(int, error)
),
TP_fast_assign(
__entry->client_id = clnt->cl_clid;
__entry->error = error;
),
TP_printk("client=%u error=%d", __entry->client_id, __entry->error)
);
TRACE_DEFINE_ENUM(RPC_AUTH_OK); TRACE_DEFINE_ENUM(RPC_AUTH_OK);
TRACE_DEFINE_ENUM(RPC_AUTH_BADCRED); TRACE_DEFINE_ENUM(RPC_AUTH_BADCRED);
TRACE_DEFINE_ENUM(RPC_AUTH_REJECTEDCRED); TRACE_DEFINE_ENUM(RPC_AUTH_REJECTEDCRED);
......
...@@ -370,10 +370,6 @@ static struct rpc_clnt * rpc_new_client(const struct rpc_create_args *args, ...@@ -370,10 +370,6 @@ static struct rpc_clnt * rpc_new_client(const struct rpc_create_args *args,
const char *nodename = args->nodename; const char *nodename = args->nodename;
int err; int err;
/* sanity check the name before trying to print it */
dprintk("RPC: creating %s client for %s (xprt %p)\n",
program->name, args->servername, xprt);
err = rpciod_up(); err = rpciod_up();
if (err) if (err)
goto out_no_rpciod; goto out_no_rpciod;
...@@ -436,6 +432,8 @@ static struct rpc_clnt * rpc_new_client(const struct rpc_create_args *args, ...@@ -436,6 +432,8 @@ static struct rpc_clnt * rpc_new_client(const struct rpc_create_args *args,
goto out_no_path; goto out_no_path;
if (parent) if (parent)
atomic_inc(&parent->cl_count); atomic_inc(&parent->cl_count);
trace_rpc_clnt_new(clnt, xprt, program->name, args->servername);
return clnt; return clnt;
out_no_path: out_no_path:
...@@ -450,6 +448,7 @@ static struct rpc_clnt * rpc_new_client(const struct rpc_create_args *args, ...@@ -450,6 +448,7 @@ static struct rpc_clnt * rpc_new_client(const struct rpc_create_args *args,
out_no_rpciod: out_no_rpciod:
xprt_switch_put(xps); xprt_switch_put(xps);
xprt_put(xprt); xprt_put(xprt);
trace_rpc_clnt_new_err(program->name, args->servername, err);
return ERR_PTR(err); return ERR_PTR(err);
} }
...@@ -634,10 +633,8 @@ static struct rpc_clnt *__rpc_clone_client(struct rpc_create_args *args, ...@@ -634,10 +633,8 @@ static struct rpc_clnt *__rpc_clone_client(struct rpc_create_args *args,
args->nodename = clnt->cl_nodename; args->nodename = clnt->cl_nodename;
new = rpc_new_client(args, xps, xprt, clnt); new = rpc_new_client(args, xps, xprt, clnt);
if (IS_ERR(new)) { if (IS_ERR(new))
err = PTR_ERR(new); return new;
goto out_err;
}
/* Turn off autobind on clones */ /* Turn off autobind on clones */
new->cl_autobind = 0; new->cl_autobind = 0;
...@@ -650,7 +647,7 @@ static struct rpc_clnt *__rpc_clone_client(struct rpc_create_args *args, ...@@ -650,7 +647,7 @@ static struct rpc_clnt *__rpc_clone_client(struct rpc_create_args *args,
return new; return new;
out_err: out_err:
dprintk("RPC: %s: returned error %d\n", __func__, err); trace_rpc_clnt_clone_err(clnt, err);
return ERR_PTR(err); return ERR_PTR(err);
} }
...@@ -723,11 +720,8 @@ int rpc_switch_client_transport(struct rpc_clnt *clnt, ...@@ -723,11 +720,8 @@ int rpc_switch_client_transport(struct rpc_clnt *clnt,
int err; int err;
xprt = xprt_create_transport(args); xprt = xprt_create_transport(args);
if (IS_ERR(xprt)) { if (IS_ERR(xprt))
dprintk("RPC: failed to create new xprt for clnt %p\n",
clnt);
return PTR_ERR(xprt); return PTR_ERR(xprt);
}
xps = xprt_switch_alloc(xprt, GFP_KERNEL); xps = xprt_switch_alloc(xprt, GFP_KERNEL);
if (xps == NULL) { if (xps == NULL) {
...@@ -767,7 +761,7 @@ int rpc_switch_client_transport(struct rpc_clnt *clnt, ...@@ -767,7 +761,7 @@ int rpc_switch_client_transport(struct rpc_clnt *clnt,
rpc_release_client(parent); rpc_release_client(parent);
xprt_switch_put(oldxps); xprt_switch_put(oldxps);
xprt_put(old); xprt_put(old);
dprintk("RPC: replaced xprt for clnt %p\n", clnt); trace_rpc_clnt_replace_xprt(clnt);
return 0; return 0;
out_revert: out_revert:
...@@ -777,7 +771,7 @@ int rpc_switch_client_transport(struct rpc_clnt *clnt, ...@@ -777,7 +771,7 @@ int rpc_switch_client_transport(struct rpc_clnt *clnt,
rpc_client_register(clnt, pseudoflavor, NULL); rpc_client_register(clnt, pseudoflavor, NULL);
xprt_switch_put(xps); xprt_switch_put(xps);
xprt_put(xprt); xprt_put(xprt);
dprintk("RPC: failed to switch xprt for clnt %p\n", clnt); trace_rpc_clnt_replace_xprt_err(clnt);
return err; return err;
} }
EXPORT_SYMBOL_GPL(rpc_switch_client_transport); EXPORT_SYMBOL_GPL(rpc_switch_client_transport);
...@@ -844,10 +838,11 @@ void rpc_killall_tasks(struct rpc_clnt *clnt) ...@@ -844,10 +838,11 @@ void rpc_killall_tasks(struct rpc_clnt *clnt)
if (list_empty(&clnt->cl_tasks)) if (list_empty(&clnt->cl_tasks))
return; return;
dprintk("RPC: killing all tasks for client %p\n", clnt);
/* /*
* Spin lock all_tasks to prevent changes... * Spin lock all_tasks to prevent changes...
*/ */
trace_rpc_clnt_killall(clnt);
spin_lock(&clnt->cl_lock); spin_lock(&clnt->cl_lock);
list_for_each_entry(rovr, &clnt->cl_tasks, tk_task) list_for_each_entry(rovr, &clnt->cl_tasks, tk_task)
rpc_signal_task(rovr); rpc_signal_task(rovr);
...@@ -863,9 +858,7 @@ void rpc_shutdown_client(struct rpc_clnt *clnt) ...@@ -863,9 +858,7 @@ void rpc_shutdown_client(struct rpc_clnt *clnt)
{ {
might_sleep(); might_sleep();
dprintk_rcu("RPC: shutting down %s client for %s\n", trace_rpc_clnt_shutdown(clnt);
clnt->cl_program->name,
rcu_dereference(clnt->cl_xprt)->servername);
while (!list_empty(&clnt->cl_tasks)) { while (!list_empty(&clnt->cl_tasks)) {
rpc_killall_tasks(clnt); rpc_killall_tasks(clnt);
...@@ -884,6 +877,8 @@ static void rpc_free_client_work(struct work_struct *work) ...@@ -884,6 +877,8 @@ static void rpc_free_client_work(struct work_struct *work)
{ {
struct rpc_clnt *clnt = container_of(work, struct rpc_clnt, cl_work); struct rpc_clnt *clnt = container_of(work, struct rpc_clnt, cl_work);
trace_rpc_clnt_free(clnt);
/* These might block on processes that might allocate memory, /* These might block on processes that might allocate memory,
* so they cannot be called in rpciod, so they are handled separately * so they cannot be called in rpciod, so they are handled separately
* here. * here.
...@@ -901,9 +896,7 @@ rpc_free_client(struct rpc_clnt *clnt) ...@@ -901,9 +896,7 @@ rpc_free_client(struct rpc_clnt *clnt)
{ {
struct rpc_clnt *parent = NULL; struct rpc_clnt *parent = NULL;
dprintk_rcu("RPC: destroying %s client for %s\n", trace_rpc_clnt_release(clnt);
clnt->cl_program->name,
rcu_dereference(clnt->cl_xprt)->servername);
if (clnt->cl_parent != clnt) if (clnt->cl_parent != clnt)
parent = clnt->cl_parent; parent = clnt->cl_parent;
rpc_unregister_client(clnt); rpc_unregister_client(clnt);
...@@ -945,8 +938,6 @@ rpc_free_auth(struct rpc_clnt *clnt) ...@@ -945,8 +938,6 @@ rpc_free_auth(struct rpc_clnt *clnt)
void void
rpc_release_client(struct rpc_clnt *clnt) rpc_release_client(struct rpc_clnt *clnt)
{ {
dprintk("RPC: rpc_release_client(%p)\n", clnt);
do { do {
if (list_empty(&clnt->cl_tasks)) if (list_empty(&clnt->cl_tasks))
wake_up(&destroy_wait); wake_up(&destroy_wait);
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment