These patches add some tracepoints that I recently used when tracking
down the hang that Christoph reported recently. At this point, I still
haven't followed the trail to completion, but I think the problem is
not likely to be in the RPC code.
Please consider these for v3.19? Some of these are for client RPC and
some for server-side. I'll assume that Trond will merge these, but
review by others would be appreciated as well.
Jeff Layton (3):
sunrpc: add some tracepoints in svc_rqst handling functions
sunrpc: add new tracepoints in xprt handling code
sunrpc: add tracepoints in xs_tcp_data_recv
include/linux/sunrpc/xprtsock.h | 59 +++++++++++++++
include/trace/events/sunrpc.h | 160 ++++++++++++++++++++++++++++++++++++++++
net/sunrpc/svc.c | 21 +++---
net/sunrpc/svc_xprt.c | 31 +++++---
net/sunrpc/xprt.c | 9 ++-
net/sunrpc/xprtsock.c | 69 +++--------------
6 files changed, 269 insertions(+), 80 deletions(-)
--
1.9.3
...just around svc_send, svc_recv and svc_process for now.
Signed-off-by: Jeff Layton <[email protected]>
---
include/trace/events/sunrpc.h | 55 +++++++++++++++++++++++++++++++++++++++++++
net/sunrpc/svc.c | 21 ++++++++++-------
net/sunrpc/svc_xprt.c | 31 ++++++++++++++++--------
3 files changed, 88 insertions(+), 19 deletions(-)
diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index 1fef3e6e9436..6260f5134212 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -6,6 +6,7 @@
#include <linux/sunrpc/sched.h>
#include <linux/sunrpc/clnt.h>
+#include <linux/sunrpc/svc.h>
#include <net/tcp_states.h>
#include <linux/net.h>
#include <linux/tracepoint.h>
@@ -306,6 +307,60 @@ DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_reset_connection);
DEFINE_RPC_SOCKET_EVENT(rpc_socket_close);
DEFINE_RPC_SOCKET_EVENT(rpc_socket_shutdown);
+TRACE_EVENT(svc_recv,
+ TP_PROTO(struct svc_rqst *rqst, int status),
+
+ TP_ARGS(rqst, status),
+
+ TP_STRUCT__entry(
+ __field(struct sockaddr *, addr)
+ __field(__be32, xid)
+ __field(int, status)
+ ),
+
+ TP_fast_assign(
+ __entry->addr = (struct sockaddr *)&rqst->rq_addr;
+ __entry->xid = status > 0 ? rqst->rq_xid : 0;
+ __entry->status = status;
+ ),
+
+ TP_printk("addr=%pIScp xid=0x%x status=%d", __entry->addr,
+ be32_to_cpu(__entry->xid), __entry->status)
+);
+
+DECLARE_EVENT_CLASS(svc_rqst_status,
+
+ TP_PROTO(struct svc_rqst *rqst, int status),
+
+ TP_ARGS(rqst, status),
+
+ TP_STRUCT__entry(
+ __field(struct sockaddr *, addr)
+ __field(__be32, xid)
+ __field(int, dropme)
+ __field(int, status)
+ ),
+
+ TP_fast_assign(
+ __entry->addr = (struct sockaddr *)&rqst->rq_addr;
+ __entry->xid = rqst->rq_xid;
+ __entry->dropme = (int)rqst->rq_dropme;
+ __entry->status = status;
+ ),
+
+ TP_printk("addr=%pIScp rq_xid=0x%x dropme=%d status=%d",
+ __entry->addr, be32_to_cpu(__entry->xid), __entry->dropme,
+ __entry->status)
+);
+
+DEFINE_EVENT(svc_rqst_status, svc_process,
+ TP_PROTO(struct svc_rqst *rqst, int status),
+ TP_ARGS(rqst, status));
+
+DEFINE_EVENT(svc_rqst_status, svc_send,
+ TP_PROTO(struct svc_rqst *rqst, int status),
+ TP_ARGS(rqst, status));
+
#endif /* _TRACE_SUNRPC_H */
#include <trace/define_trace.h>
diff --git a/net/sunrpc/svc.c b/net/sunrpc/svc.c
index ca8a7958f4e6..371a8bbb43d6 100644
--- a/net/sunrpc/svc.c
+++ b/net/sunrpc/svc.c
@@ -28,6 +28,8 @@
#include <linux/sunrpc/clnt.h>
#include <linux/sunrpc/bc_xprt.h>
+#include <trace/events/sunrpc.h>
+
#define RPCDBG_FACILITY RPCDBG_SVCDSP
static void svc_unregister(const struct svc_serv *serv, struct net *net);
@@ -1314,24 +1316,25 @@ svc_process(struct svc_rqst *rqstp)
rqstp->rq_res.tail[0].iov_base = NULL;
rqstp->rq_res.tail[0].iov_len = 0;
- rqstp->rq_xid = svc_getu32(argv);
-
dir = svc_getnl(argv);
if (dir != 0) {
/* direction != CALL */
svc_printk(rqstp, "bad direction %d, dropping request\n", dir);
serv->sv_stats->rpcbadfmt++;
- svc_drop(rqstp);
- return 0;
+ goto out_drop;
}
/* Returns 1 for send, 0 for drop */
- if (svc_process_common(rqstp, argv, resv))
- return svc_send(rqstp);
- else {
- svc_drop(rqstp);
- return 0;
+ if (likely(svc_process_common(rqstp, argv, resv))) {
+ int ret = svc_send(rqstp);
+
+ trace_svc_process(rqstp, ret);
+ return ret;
}
+out_drop:
+ trace_svc_process(rqstp, 0);
+ svc_drop(rqstp);
+ return 0;
}
#if defined(CONFIG_SUNRPC_BACKCHANNEL)
diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
index c179ca2a5aa4..bbb3b044b877 100644
--- a/net/sunrpc/svc_xprt.c
+++ b/net/sunrpc/svc_xprt.c
@@ -15,6 +15,7 @@
#include <linux/sunrpc/svcsock.h>
#include <linux/sunrpc/xprt.h>
#include <linux/module.h>
+#include <trace/events/sunrpc.h>
#define RPCDBG_FACILITY RPCDBG_SVCXPRT
@@ -773,35 +774,43 @@ int svc_recv(struct svc_rqst *rqstp, long timeout)
err = svc_alloc_arg(rqstp);
if (err)
- return err;
+ goto out;
try_to_freeze();
cond_resched();
+ err = -EINTR;
if (signalled() || kthread_should_stop())
- return -EINTR;
+ goto out;
xprt = svc_get_next_xprt(rqstp, timeout);
- if (IS_ERR(xprt))
- return PTR_ERR(xprt);
+ if (IS_ERR(xprt)) {
+ err = PTR_ERR(xprt);
+ goto out;
+ }
len = svc_handle_xprt(rqstp, xprt);
/* No data, incomplete (TCP) read, or accept() */
+ err = -EAGAIN;
if (len <= 0)
- goto out;
+ goto out_release;
clear_bit(XPT_OLD, &xprt->xpt_flags);
rqstp->rq_secure = xprt->xpt_ops->xpo_secure_port(rqstp);
rqstp->rq_chandle.defer = svc_defer;
+ rqstp->rq_xid = svc_getu32(&rqstp->rq_arg.head[0]);
if (serv->sv_stats)
serv->sv_stats->netcnt++;
+ trace_svc_recv(rqstp, len);
return len;
-out:
+out_release:
rqstp->rq_res.len = 0;
svc_xprt_release(rqstp);
- return -EAGAIN;
+out:
+ trace_svc_recv(rqstp, err);
+ return err;
}
EXPORT_SYMBOL_GPL(svc_recv);
@@ -821,12 +830,12 @@ EXPORT_SYMBOL_GPL(svc_drop);
int svc_send(struct svc_rqst *rqstp)
{
struct svc_xprt *xprt;
- int len;
+ int len = -EFAULT;
struct xdr_buf *xb;
xprt = rqstp->rq_xprt;
if (!xprt)
- return -EFAULT;
+ goto out;
/* release the receive skb before sending the reply */
rqstp->rq_xprt->xpt_ops->xpo_release_rqst(rqstp);
@@ -849,7 +858,9 @@ int svc_send(struct svc_rqst *rqstp)
svc_xprt_release(rqstp);
if (len == -ECONNREFUSED || len == -ENOTCONN || len == -EAGAIN)
- return 0;
+ len = 0;
+out:
+ trace_svc_send(rqstp, len);
return len;
}
--
1.9.3
Add tracepoints inside the main loop on xs_tcp_data_recv that allow
us to keep an eye on what's happening during each phase of it.
Signed-off-by: Jeff Layton <[email protected]>
---
include/linux/sunrpc/xprtsock.h | 59 +++++++++++++++++++++++++++++++++++++++
include/trace/events/sunrpc.h | 44 ++++++++++++++++++++++++++++-
net/sunrpc/xprtsock.c | 61 ++---------------------------------------
3 files changed, 104 insertions(+), 60 deletions(-)
diff --git a/include/linux/sunrpc/xprtsock.h b/include/linux/sunrpc/xprtsock.h
index 1ad36cc25b2e..7591788e9fbf 100644
--- a/include/linux/sunrpc/xprtsock.h
+++ b/include/linux/sunrpc/xprtsock.h
@@ -17,6 +17,65 @@ void cleanup_socket_xprt(void);
#define RPC_DEF_MIN_RESVPORT (665U)
#define RPC_DEF_MAX_RESVPORT (1023U)
+struct sock_xprt {
+ struct rpc_xprt xprt;
+
+ /*
+ * Network layer
+ */
+ struct socket * sock;
+ struct sock * inet;
+
+ /*
+ * State of TCP reply receive
+ */
+ __be32 tcp_fraghdr,
+ tcp_xid,
+ tcp_calldir;
+
+ u32 tcp_offset,
+ tcp_reclen;
+
+ unsigned long tcp_copied,
+ tcp_flags;
+
+ /*
+ * Connection of transports
+ */
+ struct delayed_work connect_worker;
+ struct sockaddr_storage srcaddr;
+ unsigned short srcport;
+
+ /*
+ * UDP socket buffer size parameters
+ */
+ size_t rcvsize,
+ sndsize;
+
+ /*
+ * Saved socket callback addresses
+ */
+ void (*old_data_ready)(struct sock *);
+ void (*old_state_change)(struct sock *);
+ void (*old_write_space)(struct sock *);
+ void (*old_error_report)(struct sock *);
+};
+
+/*
+ * TCP receive state flags
+ */
+#define TCP_RCV_LAST_FRAG (1UL << 0)
+#define TCP_RCV_COPY_FRAGHDR (1UL << 1)
+#define TCP_RCV_COPY_XID (1UL << 2)
+#define TCP_RCV_COPY_DATA (1UL << 3)
+#define TCP_RCV_READ_CALLDIR (1UL << 4)
+#define TCP_RCV_COPY_CALLDIR (1UL << 5)
+
+/*
+ * TCP RPC flags
+ */
+#define TCP_RPC_REPLY (1UL << 6)
+
#endif /* __KERNEL__ */
#endif /* _LINUX_SUNRPC_XPRTSOCK_H */
diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index 5edb16bcd836..171ca4ff6d99 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -7,6 +7,7 @@
#include <linux/sunrpc/sched.h>
#include <linux/sunrpc/clnt.h>
#include <linux/sunrpc/svc.h>
+#include <linux/sunrpc/xprtsock.h>
#include <net/tcp_states.h>
#include <linux/net.h>
#include <linux/tracepoint.h>
@@ -326,7 +327,7 @@ DECLARE_EVENT_CLASS(rpc_xprt_event,
__assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
),
- TP_printk("peer=%s/%s xid=0x%x status=%d", __get_str(addr),
+ TP_printk("peer=[%s]:%s xid=0x%x status=%d", __get_str(addr),
__get_str(port), be32_to_cpu(__entry->xid),
__entry->status)
);
@@ -370,6 +371,47 @@ TRACE_EVENT(xs_tcp_data_ready,
__get_str(port), __entry->err, __entry->total)
);
+#define rpc_show_sock_xprt_flags(flags) \
+ __print_flags(flags, "|", \
+ { TCP_RCV_LAST_FRAG, "TCP_RCV_LAST_FRAG" }, \
+ { TCP_RCV_COPY_FRAGHDR, "TCP_RCV_COPY_FRAGHDR" }, \
+ { TCP_RCV_COPY_XID, "TCP_RCV_COPY_XID" }, \
+ { TCP_RCV_COPY_DATA, "TCP_RCV_COPY_DATA" }, \
+ { TCP_RCV_READ_CALLDIR, "TCP_RCV_READ_CALLDIR" }, \
+ { TCP_RCV_COPY_CALLDIR, "TCP_RCV_COPY_CALLDIR" }, \
+ { TCP_RPC_REPLY, "TCP_RPC_REPLY" })
+
+TRACE_EVENT(xs_tcp_data_recv,
+ TP_PROTO(struct sock_xprt *xs),
+
+ TP_ARGS(xs),
+
+ TP_STRUCT__entry(
+ __string(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR])
+ __string(port, xs->xprt.address_strings[RPC_DISPLAY_PORT])
+ __field(__be32, xid)
+ __field(unsigned long, flags)
+ __field(unsigned long, copied)
+ __field(unsigned int, reclen)
+ __field(unsigned long, offset)
+ ),
+
+ TP_fast_assign(
+ __assign_str(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR]);
+ __assign_str(port, xs->xprt.address_strings[RPC_DISPLAY_PORT]);
+ __entry->xid = xs->tcp_xid;
+ __entry->flags = xs->tcp_flags;
+ __entry->copied = xs->tcp_copied;
+ __entry->reclen = xs->tcp_reclen;
+ __entry->offset = xs->tcp_offset;
+ ),
+
+ TP_printk("peer=[%s]:%s xid=0x%x flags=%s copied=%lu reclen=%u offset=%lu",
+ __get_str(addr), __get_str(port), be32_to_cpu(__entry->xid),
+ rpc_show_sock_xprt_flags(__entry->flags),
+ __entry->copied, __entry->reclen, __entry->offset)
+);
+
TRACE_EVENT(svc_recv,
TP_PROTO(struct svc_rqst *rqst, int status),
diff --git a/net/sunrpc/xprtsock.c b/net/sunrpc/xprtsock.c
index b63e26272dc2..31c015196a29 100644
--- a/net/sunrpc/xprtsock.c
+++ b/net/sunrpc/xprtsock.c
@@ -216,65 +216,6 @@ static inline void xs_pktdump(char *msg, u32 *packet, unsigned int count)
}
#endif
-struct sock_xprt {
- struct rpc_xprt xprt;
-
- /*
- * Network layer
- */
- struct socket * sock;
- struct sock * inet;
-
- /*
- * State of TCP reply receive
- */
- __be32 tcp_fraghdr,
- tcp_xid,
- tcp_calldir;
-
- u32 tcp_offset,
- tcp_reclen;
-
- unsigned long tcp_copied,
- tcp_flags;
-
- /*
- * Connection of transports
- */
- struct delayed_work connect_worker;
- struct sockaddr_storage srcaddr;
- unsigned short srcport;
-
- /*
- * UDP socket buffer size parameters
- */
- size_t rcvsize,
- sndsize;
-
- /*
- * Saved socket callback addresses
- */
- void (*old_data_ready)(struct sock *);
- void (*old_state_change)(struct sock *);
- void (*old_write_space)(struct sock *);
- void (*old_error_report)(struct sock *);
-};
-
-/*
- * TCP receive state flags
- */
-#define TCP_RCV_LAST_FRAG (1UL << 0)
-#define TCP_RCV_COPY_FRAGHDR (1UL << 1)
-#define TCP_RCV_COPY_XID (1UL << 2)
-#define TCP_RCV_COPY_DATA (1UL << 3)
-#define TCP_RCV_READ_CALLDIR (1UL << 4)
-#define TCP_RCV_COPY_CALLDIR (1UL << 5)
-
-/*
- * TCP RPC flags
- */
-#define TCP_RPC_REPLY (1UL << 6)
-
static inline struct rpc_xprt *xprt_from_sock(struct sock *sk)
{
return (struct rpc_xprt *) sk->sk_user_data;
@@ -1415,6 +1356,7 @@ static int xs_tcp_data_recv(read_descriptor_t *rd_desc, struct sk_buff *skb, uns
dprintk("RPC: xs_tcp_data_recv started\n");
do {
+ trace_xs_tcp_data_recv(transport);
/* Read in a new fragment marker if necessary */
/* Can we ever really expect to get completely empty fragments? */
if (transport->tcp_flags & TCP_RCV_COPY_FRAGHDR) {
@@ -1439,6 +1381,7 @@ static int xs_tcp_data_recv(read_descriptor_t *rd_desc, struct sk_buff *skb, uns
/* Skip over any trailing bytes on short reads */
xs_tcp_read_discard(transport, &desc);
} while (desc.count);
+ trace_xs_tcp_data_recv(transport);
dprintk("RPC: xs_tcp_data_recv done\n");
return len - desc.count;
}
--
1.9.3
...so we can keep track of when calls are sent and replies received.
Signed-off-by: Jeff Layton <[email protected]>
---
include/trace/events/sunrpc.h | 63 +++++++++++++++++++++++++++++++++++++++++++
net/sunrpc/xprt.c | 9 ++++++-
net/sunrpc/xprtsock.c | 8 +++++-
3 files changed, 78 insertions(+), 2 deletions(-)
diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index 6260f5134212..5edb16bcd836 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -307,6 +307,69 @@ DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_reset_connection);
DEFINE_RPC_SOCKET_EVENT(rpc_socket_close);
DEFINE_RPC_SOCKET_EVENT(rpc_socket_shutdown);
+DECLARE_EVENT_CLASS(rpc_xprt_event,
+ TP_PROTO(struct rpc_xprt *xprt, __be32 xid, int status),
+
+ TP_ARGS(xprt, xid, status),
+
+ TP_STRUCT__entry(
+ __field(__be32, xid)
+ __field(int, status)
+ __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
+ __string(port, xprt->address_strings[RPC_DISPLAY_PORT])
+ ),
+
+ TP_fast_assign(
+ __entry->xid = xid;
+ __entry->status = status;
+ __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
+ __assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
+ ),
+
+ TP_printk("peer=%s/%s xid=0x%x status=%d", __get_str(addr),
+ __get_str(port), be32_to_cpu(__entry->xid),
+ __entry->status)
+);
+
+DEFINE_EVENT(rpc_xprt_event, xprt_lookup_rqst,
+ TP_PROTO(struct rpc_xprt *xprt, __be32 xid, int status),
+ TP_ARGS(xprt, xid, status));
+
+DEFINE_EVENT(rpc_xprt_event, xprt_transmit,
+ TP_PROTO(struct rpc_xprt *xprt, __be32 xid, int status),
+ TP_ARGS(xprt, xid, status));
+
+DEFINE_EVENT(rpc_xprt_event, xprt_complete_rqst,
+ TP_PROTO(struct rpc_xprt *xprt, __be32 xid, int status),
+ TP_ARGS(xprt, xid, status));
+
+TRACE_EVENT(xs_tcp_data_ready,
+ TP_PROTO(struct rpc_xprt *xprt, int err, unsigned int total),
+
+ TP_ARGS(xprt, err, total),
+
+ TP_STRUCT__entry(
+ __field(int, err)
+ __field(unsigned int, total)
+ __string(addr, xprt ? xprt->address_strings[RPC_DISPLAY_ADDR] :
+ "(null)")
+ __string(port, xprt ? xprt->address_strings[RPC_DISPLAY_PORT] :
+ "(null)")
+ ),
+
+ TP_fast_assign(
+ __entry->err = err;
+ __entry->total = total;
+ __assign_str(addr, xprt ?
+ xprt->address_strings[RPC_DISPLAY_ADDR] : "(null)");
+ __assign_str(port, xprt ?
+ xprt->address_strings[RPC_DISPLAY_PORT] : "(null)");
+ ),
+
+ TP_printk("peer=[%s]:%s err=%d total=%u", __get_str(addr),
+ __get_str(port), __entry->err, __entry->total)
+);
+
TRACE_EVENT(svc_recv,
TP_PROTO(struct svc_rqst *rqst, int status),
diff --git a/net/sunrpc/xprt.c b/net/sunrpc/xprt.c
index 56e4e150e80e..1b2e5e616cae 100644
--- a/net/sunrpc/xprt.c
+++ b/net/sunrpc/xprt.c
@@ -49,6 +49,8 @@
#include <linux/sunrpc/metrics.h>
#include <linux/sunrpc/bc_xprt.h>
+#include <trace/events/sunrpc.h>
+
#include "sunrpc.h"
/*
@@ -772,11 +774,14 @@ struct rpc_rqst *xprt_lookup_rqst(struct rpc_xprt *xprt, __be32 xid)
struct rpc_rqst *entry;
list_for_each_entry(entry, &xprt->recv, rq_list)
- if (entry->rq_xid == xid)
+ if (entry->rq_xid == xid) {
+ trace_xprt_lookup_rqst(xprt, xid, 0);
return entry;
+ }
dprintk("RPC: xprt_lookup_rqst did not find xid %08x\n",
ntohl(xid));
+ trace_xprt_lookup_rqst(xprt, xid, -ENOENT);
xprt->stat.bad_xids++;
return NULL;
}
@@ -810,6 +815,7 @@ void xprt_complete_rqst(struct rpc_task *task, int copied)
dprintk("RPC: %5u xid %08x complete (%d bytes received)\n",
task->tk_pid, ntohl(req->rq_xid), copied);
+ trace_xprt_complete_rqst(xprt, req->rq_xid, copied);
xprt->stat.recvs++;
req->rq_rtt = ktime_sub(ktime_get(), req->rq_xtime);
@@ -926,6 +932,7 @@ void xprt_transmit(struct rpc_task *task)
req->rq_xtime = ktime_get();
status = xprt->ops->send_request(task);
+ trace_xprt_transmit(xprt, req->rq_xid, status);
if (status != 0) {
task->tk_status = status;
return;
diff --git a/net/sunrpc/xprtsock.c b/net/sunrpc/xprtsock.c
index 3b305ab17afe..b63e26272dc2 100644
--- a/net/sunrpc/xprtsock.c
+++ b/net/sunrpc/xprtsock.c
@@ -1454,12 +1454,15 @@ static void xs_tcp_data_ready(struct sock *sk)
struct rpc_xprt *xprt;
read_descriptor_t rd_desc;
int read;
+ unsigned long total = 0;
dprintk("RPC: xs_tcp_data_ready...\n");
read_lock_bh(&sk->sk_callback_lock);
- if (!(xprt = xprt_from_sock(sk)))
+ if (!(xprt = xprt_from_sock(sk))) {
+ read = 0;
goto out;
+ }
/* Any data means we had a useful conversation, so
* the we don't need to delay the next reconnect
*/
@@ -1471,8 +1474,11 @@ static void xs_tcp_data_ready(struct sock *sk)
do {
rd_desc.count = 65536;
read = tcp_read_sock(sk, &rd_desc, xs_tcp_data_recv);
+ if (read > 0)
+ total += read;
} while (read > 0);
out:
+ trace_xs_tcp_data_ready(xprt, read, total);
read_unlock_bh(&sk->sk_callback_lock);
}
--
1.9.3
On Thu, 6 Nov 2014 15:20:09 -0500
"J. Bruce Fields" <[email protected]> wrote:
> On Tue, Oct 28, 2014 at 02:24:11PM -0400, Jeff Layton wrote:
> > These patches add some tracepoints that I recently used when tracking
> > down the hang that Christoph reported recently. At this point, I still
> > haven't followed the trail to completion, but I think the problem is
> > not likely to be in the RPC code.
> >
> > Please consider these for v3.19? Some of these are for client RPC and
> > some for server-side. I'll assume that Trond will merge these, but
> > review by others would be appreciated as well.
>
> Looks fine to me, thanks, I'll assume Trond's applying all three unless
> I hear otherwise.
>
> (Separate issue: the server-side rpc dprintk's need review: they're much
> too frequent to be useful, I think.)
>
Thanks.
Yeah. Probably best to just slowly phase those out in favor of
tracepoints. Is there any way to do that that's less labor intensive?
> --b.
>
> >
> > Jeff Layton (3):
> > sunrpc: add some tracepoints in svc_rqst handling functions
> > sunrpc: add new tracepoints in xprt handling code
> > sunrpc: add tracepoints in xs_tcp_data_recv
> >
> > include/linux/sunrpc/xprtsock.h | 59 +++++++++++++++
> > include/trace/events/sunrpc.h | 160 ++++++++++++++++++++++++++++++++++++++++
> > net/sunrpc/svc.c | 21 +++---
> > net/sunrpc/svc_xprt.c | 31 +++++---
> > net/sunrpc/xprt.c | 9 ++-
> > net/sunrpc/xprtsock.c | 69 +++--------------
> > 6 files changed, 269 insertions(+), 80 deletions(-)
> >
> > --
> > 1.9.3
> >
> --
> To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
--
Jeff Layton <[email protected]>
On Tue, Oct 28, 2014 at 02:24:11PM -0400, Jeff Layton wrote:
> These patches add some tracepoints that I recently used when tracking
> down the hang that Christoph reported recently. At this point, I still
> haven't followed the trail to completion, but I think the problem is
> not likely to be in the RPC code.
>
> Please consider these for v3.19? Some of these are for client RPC and
> some for server-side. I'll assume that Trond will merge these, but
> review by others would be appreciated as well.
Looks fine to me, thanks, I'll assume Trond's applying all three unless
I hear otherwise.
(Separate issue: the server-side rpc dprintk's need review: they're much
too frequent to be useful, I think.)
--b.
>
> Jeff Layton (3):
> sunrpc: add some tracepoints in svc_rqst handling functions
> sunrpc: add new tracepoints in xprt handling code
> sunrpc: add tracepoints in xs_tcp_data_recv
>
> include/linux/sunrpc/xprtsock.h | 59 +++++++++++++++
> include/trace/events/sunrpc.h | 160 ++++++++++++++++++++++++++++++++++++++++
> net/sunrpc/svc.c | 21 +++---
> net/sunrpc/svc_xprt.c | 31 +++++---
> net/sunrpc/xprt.c | 9 ++-
> net/sunrpc/xprtsock.c | 69 +++--------------
> 6 files changed, 269 insertions(+), 80 deletions(-)
>
> --
> 1.9.3
>
On Thu, Nov 06, 2014 at 04:58:34PM -0500, Jeff Layton wrote:
> On Thu, 6 Nov 2014 15:20:09 -0500
> "J. Bruce Fields" <[email protected]> wrote:
>
> > On Tue, Oct 28, 2014 at 02:24:11PM -0400, Jeff Layton wrote:
> > > These patches add some tracepoints that I recently used when tracking
> > > down the hang that Christoph reported recently. At this point, I still
> > > haven't followed the trail to completion, but I think the problem is
> > > not likely to be in the RPC code.
> > >
> > > Please consider these for v3.19? Some of these are for client RPC and
> > > some for server-side. I'll assume that Trond will merge these, but
> > > review by others would be appreciated as well.
> >
> > Looks fine to me, thanks, I'll assume Trond's applying all three unless
> > I hear otherwise.
> >
> > (Separate issue: the server-side rpc dprintk's need review: they're much
> > too frequent to be useful, I think.)
> >
>
> Thanks.
>
> Yeah. Probably best to just slowly phase those out in favor of
> tracepoints. Is there any way to do that that's less labor intensive?
No idea.
I'm hoping we can just get of some of them entirely, but I don't know, I
really haven't tried to look through them.
(I've just noticed that there's usually a ton of output, and recall it
interfering with testing in some cases--admittedly I might just be
remembering cases where someone was trying to use a slow serial
interface for logging.)
--b.