From ae67bd3821bb0a54d97e7883d211196637d487a9 Mon Sep 17 00:00:00 2001 From: Trond Myklebust Date: Sun, 7 Apr 2019 13:58:44 -0400 Subject: SUNRPC: Fix up task signalling The RPC_TASK_KILLED flag should really not be set from another context because it can clobber data in the struct task when task->tk_flags is changed non-atomically. Let's therefore swap out RPC_TASK_KILLED with an atomic flag, and add a function to set that flag and safely wake up the task. Signed-off-by: Trond Myklebust Signed-off-by: Anna Schumaker --- include/trace/events/sunrpc.h | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h index 7e899e635d33..5e3b77d9daa7 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -82,7 +82,6 @@ TRACE_DEFINE_ENUM(RPC_TASK_SWAPPER); TRACE_DEFINE_ENUM(RPC_CALL_MAJORSEEN); TRACE_DEFINE_ENUM(RPC_TASK_ROOTCREDS); TRACE_DEFINE_ENUM(RPC_TASK_DYNAMIC); -TRACE_DEFINE_ENUM(RPC_TASK_KILLED); TRACE_DEFINE_ENUM(RPC_TASK_SOFT); TRACE_DEFINE_ENUM(RPC_TASK_SOFTCONN); TRACE_DEFINE_ENUM(RPC_TASK_SENT); @@ -97,7 +96,6 @@ TRACE_DEFINE_ENUM(RPC_TASK_NO_RETRANS_TIMEOUT); { RPC_CALL_MAJORSEEN, "MAJORSEEN" }, \ { RPC_TASK_ROOTCREDS, "ROOTCREDS" }, \ { RPC_TASK_DYNAMIC, "DYNAMIC" }, \ - { RPC_TASK_KILLED, "KILLED" }, \ { RPC_TASK_SOFT, "SOFT" }, \ { RPC_TASK_SOFTCONN, "SOFTCONN" }, \ { RPC_TASK_SENT, "SENT" }, \ @@ -111,6 +109,7 @@ TRACE_DEFINE_ENUM(RPC_TASK_ACTIVE); TRACE_DEFINE_ENUM(RPC_TASK_NEED_XMIT); TRACE_DEFINE_ENUM(RPC_TASK_NEED_RECV); TRACE_DEFINE_ENUM(RPC_TASK_MSG_PIN_WAIT); +TRACE_DEFINE_ENUM(RPC_TASK_SIGNALLED); #define rpc_show_runstate(flags) \ __print_flags(flags, "|", \ @@ -119,7 +118,8 @@ TRACE_DEFINE_ENUM(RPC_TASK_MSG_PIN_WAIT); { (1UL << RPC_TASK_ACTIVE), "ACTIVE" }, \ { (1UL << RPC_TASK_NEED_XMIT), "NEED_XMIT" }, \ { (1UL << RPC_TASK_NEED_RECV), "NEED_RECV" }, \ - { (1UL << RPC_TASK_MSG_PIN_WAIT), "MSG_PIN_WAIT" }) + { (1UL << RPC_TASK_MSG_PIN_WAIT), "MSG_PIN_WAIT" }, \ + { (1UL << RPC_TASK_SIGNALLED), "SIGNALLED" }) DECLARE_EVENT_CLASS(rpc_task_running, -- cgit v1.2.3 From 5efd1876e61fe61b61e2d056782027c11bcd0982 Mon Sep 17 00:00:00 2001 From: Trond Myklebust Date: Sun, 7 Apr 2019 13:58:50 -0400 Subject: SUNRPC: Fix up tracking of timeouts Add a helper to ensure that debugfs and friends print out the correct current task timeout value. Signed-off-by: Trond Myklebust Signed-off-by: Anna Schumaker --- include/linux/sunrpc/sched.h | 1 + include/trace/events/sunrpc.h | 2 +- net/sunrpc/clnt.c | 2 +- net/sunrpc/debugfs.c | 2 +- net/sunrpc/sched.c | 14 ++++++++++++++ 5 files changed, 18 insertions(+), 3 deletions(-) (limited to 'include/trace') diff --git a/include/linux/sunrpc/sched.h b/include/linux/sunrpc/sched.h index 61ba533ec058..c5ad02c7a4b3 100644 --- a/include/linux/sunrpc/sched.h +++ b/include/linux/sunrpc/sched.h @@ -226,6 +226,7 @@ void rpc_execute(struct rpc_task *); void rpc_init_priority_wait_queue(struct rpc_wait_queue *, const char *); void rpc_init_wait_queue(struct rpc_wait_queue *, const char *); void rpc_destroy_wait_queue(struct rpc_wait_queue *); +unsigned long rpc_task_timeout(const struct rpc_task *task); void rpc_sleep_on_timeout(struct rpc_wait_queue *queue, struct rpc_task *task, rpc_action action, diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h index 5e3b77d9daa7..dd301db64521 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -186,7 +186,7 @@ DECLARE_EVENT_CLASS(rpc_task_queued, __entry->client_id = task->tk_client ? task->tk_client->cl_clid : -1; __entry->task_id = task->tk_pid; - __entry->timeout = task->tk_timeout; + __entry->timeout = rpc_task_timeout(task); __entry->runstate = task->tk_runstate; __entry->status = task->tk_status; __entry->flags = task->tk_flags; diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c index 216d5e5e3b54..b25f317d0ee2 100644 --- a/net/sunrpc/clnt.c +++ b/net/sunrpc/clnt.c @@ -2874,7 +2874,7 @@ static void rpc_show_task(const struct rpc_clnt *clnt, printk(KERN_INFO "%5u %04x %6d %8p %8p %8ld %8p %sv%u %s a:%ps q:%s\n", task->tk_pid, task->tk_flags, task->tk_status, - clnt, task->tk_rqstp, task->tk_timeout, task->tk_ops, + clnt, task->tk_rqstp, rpc_task_timeout(task), task->tk_ops, clnt->cl_program->name, clnt->cl_vers, rpc_proc_name(task), task->tk_action, rpc_waitq); } diff --git a/net/sunrpc/debugfs.c b/net/sunrpc/debugfs.c index 19bb356230ed..95ebd76b132d 100644 --- a/net/sunrpc/debugfs.c +++ b/net/sunrpc/debugfs.c @@ -33,7 +33,7 @@ tasks_show(struct seq_file *f, void *v) seq_printf(f, "%5u %04x %6d 0x%x 0x%x %8ld %ps %sv%u %s a:%ps q:%s\n", task->tk_pid, task->tk_flags, task->tk_status, - clnt->cl_clid, xid, task->tk_timeout, task->tk_ops, + clnt->cl_clid, xid, rpc_task_timeout(task), task->tk_ops, clnt->cl_program->name, clnt->cl_vers, rpc_proc_name(task), task->tk_action, rpc_waitq); return 0; diff --git a/net/sunrpc/sched.c b/net/sunrpc/sched.c index 7e0f7b83262f..40944c34a9e4 100644 --- a/net/sunrpc/sched.c +++ b/net/sunrpc/sched.c @@ -58,6 +58,20 @@ static struct rpc_wait_queue delay_queue; struct workqueue_struct *rpciod_workqueue __read_mostly; struct workqueue_struct *xprtiod_workqueue __read_mostly; +unsigned long +rpc_task_timeout(const struct rpc_task *task) +{ + unsigned long timeout = READ_ONCE(task->tk_timeout); + + if (timeout != 0) { + unsigned long now = jiffies; + if (time_before(now, timeout)) + return timeout - now; + } + return 0; +} +EXPORT_SYMBOL_GPL(rpc_task_timeout); + /* * Disable the timer for a given RPC task. Should be called with * queue->lock and bh_disabled in order to avoid races within -- cgit v1.2.3 From 17e4c443c0b433354016df60a7bd3f1c6aac759c Mon Sep 17 00:00:00 2001 From: Chuck Lever Date: Wed, 24 Apr 2019 09:39:48 -0400 Subject: xprtrdma: Trace marshaling failures Record an event when rpcrdma_marshal_req returns a non-zero return value to help track down why an xprt close might have occurred. Signed-off-by: Chuck Lever Signed-off-by: Anna Schumaker --- include/trace/events/rpcrdma.h | 27 +++++++++++++++++++++++++++ net/sunrpc/xprtrdma/rpc_rdma.c | 1 + 2 files changed, 28 insertions(+) (limited to 'include/trace') diff --git a/include/trace/events/rpcrdma.h b/include/trace/events/rpcrdma.h index 962975b4313f..df9851cb82b2 100644 --- a/include/trace/events/rpcrdma.h +++ b/include/trace/events/rpcrdma.h @@ -511,6 +511,33 @@ TRACE_EVENT(xprtrdma_marshal, ) ); +TRACE_EVENT(xprtrdma_marshal_failed, + TP_PROTO(const struct rpc_rqst *rqst, + int ret + ), + + TP_ARGS(rqst, ret), + + TP_STRUCT__entry( + __field(unsigned int, task_id) + __field(unsigned int, client_id) + __field(u32, xid) + __field(int, ret) + ), + + TP_fast_assign( + __entry->task_id = rqst->rq_task->tk_pid; + __entry->client_id = rqst->rq_task->tk_client->cl_clid; + __entry->xid = be32_to_cpu(rqst->rq_xid); + __entry->ret = ret; + ), + + TP_printk("task:%u@%u xid=0x%08x: ret=%d", + __entry->task_id, __entry->client_id, __entry->xid, + __entry->ret + ) +); + TRACE_EVENT(xprtrdma_post_send, TP_PROTO( const struct rpcrdma_req *req, diff --git a/net/sunrpc/xprtrdma/rpc_rdma.c b/net/sunrpc/xprtrdma/rpc_rdma.c index 231a44b9c152..45cba06655ea 100644 --- a/net/sunrpc/xprtrdma/rpc_rdma.c +++ b/net/sunrpc/xprtrdma/rpc_rdma.c @@ -875,6 +875,7 @@ rpcrdma_marshal_req(struct rpcrdma_xprt *r_xprt, struct rpc_rqst *rqst) return 0; out_err: + trace_xprtrdma_marshal_failed(rqst, ret); switch (ret) { case -EAGAIN: xprt_wait_for_buffer_space(rqst->rq_xprt); -- cgit v1.2.3