SUNRPC: Fix parsing failure in trace points with XIDs
authorChuck Lever <chuck.lever@oracle.com>
Fri, 20 Oct 2017 14:35:18 +0000 (10:35 -0400)
committerAnna Schumaker <Anna.Schumaker@Netapp.com>
Fri, 17 Nov 2017 21:43:44 +0000 (16:43 -0500)
mount.nf-11159   8....   905.248380: xprt_transmit:        [FAILED TO PARSE] xid=351291440 status=0 addr=192.168.2.5 port=20049
mount.nf-11159   8....   905.248381: rpc_task_sleep:       task:6210@1 flags=0e80 state=0005 status=0 timeout=60000 queue=xprt_pending
kworker/-1591    1....   905.248419: xprt_lookup_rqst:     [FAILED TO PARSE] xid=351291440 status=0 addr=192.168.2.5 port=20049
kworker/-1591    1....   905.248423: xprt_complete_rqst:   [FAILED TO PARSE] xid=351291440 status=24 addr=192.168.2.5 port=20049

Byte swapping is not available during trace-cmd report.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Signed-off-by: Anna Schumaker <Anna.Schumaker@Netapp.com>
include/trace/events/sunrpc.h

index 8a707f8a41c3df76b682032cf180eda869a49e1d..82e5057c7707377707c497f75f308a6cf428fd02 100644 (file)
@@ -341,21 +341,21 @@ DECLARE_EVENT_CLASS(rpc_xprt_event,
        TP_ARGS(xprt, xid, status),
 
        TP_STRUCT__entry(
-               __field(__be32, xid)
+               __field(u32, 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->xid = be32_to_cpu(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),
+       TP_printk("peer=[%s]:%s xid=0x%08x status=%d", __get_str(addr),
+                       __get_str(port), __entry->xid,
                        __entry->status)
 );
 
@@ -416,7 +416,7 @@ TRACE_EVENT(xs_tcp_data_recv,
        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(u32, xid)
                __field(unsigned long, flags)
                __field(unsigned long, copied)
                __field(unsigned int, reclen)
@@ -426,15 +426,15 @@ TRACE_EVENT(xs_tcp_data_recv,
        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->xid = be32_to_cpu(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),
+       TP_printk("peer=[%s]:%s xid=0x%08x flags=%s copied=%lu reclen=%u offset=%lu",
+                       __get_str(addr), __get_str(port), __entry->xid,
                        rpc_show_sock_xprt_flags(__entry->flags),
                        __entry->copied, __entry->reclen, __entry->offset)
 );
@@ -456,20 +456,20 @@ TRACE_EVENT(svc_recv,
 
        TP_STRUCT__entry(
                __field(struct sockaddr *, addr)
-               __field(__be32, xid)
+               __field(u32, xid)
                __field(int, status)
                __field(unsigned long, flags)
        ),
 
        TP_fast_assign(
                __entry->addr = (struct sockaddr *)&rqst->rq_addr;
-               __entry->xid = status > 0 ? rqst->rq_xid : 0;
+               __entry->xid = status > 0 ? be32_to_cpu(rqst->rq_xid) : 0;
                __entry->status = status;
                __entry->flags = rqst->rq_flags;
        ),
 
-       TP_printk("addr=%pIScp xid=0x%x status=%d flags=%s", __entry->addr,
-                       be32_to_cpu(__entry->xid), __entry->status,
+       TP_printk("addr=%pIScp xid=0x%08x status=%d flags=%s", __entry->addr,
+                       __entry->xid, __entry->status,
                        show_rqstp_flags(__entry->flags))
 );
 
@@ -480,21 +480,21 @@ DECLARE_EVENT_CLASS(svc_rqst_event,
        TP_ARGS(rqst),
 
        TP_STRUCT__entry(
-               __field(__be32, xid)
+               __field(u32, xid)
                __field(unsigned long, flags)
                __dynamic_array(unsigned char, addr, rqst->rq_addrlen)
        ),
 
        TP_fast_assign(
-               __entry->xid = rqst->rq_xid;
+               __entry->xid = be32_to_cpu(rqst->rq_xid);
                __entry->flags = rqst->rq_flags;
                memcpy(__get_dynamic_array(addr),
                        &rqst->rq_addr, rqst->rq_addrlen);
        ),
 
-       TP_printk("addr=%pIScp rq_xid=0x%x flags=%s",
+       TP_printk("addr=%pIScp rq_xid=0x%08x flags=%s",
                (struct sockaddr *)__get_dynamic_array(addr),
-               be32_to_cpu(__entry->xid),
+               __entry->xid,
                show_rqstp_flags(__entry->flags))
 );
 
@@ -514,7 +514,7 @@ DECLARE_EVENT_CLASS(svc_rqst_status,
 
        TP_STRUCT__entry(
                __field(struct sockaddr *, addr)
-               __field(__be32, xid)
+               __field(u32, xid)
                __field(int, dropme)
                __field(int, status)
                __field(unsigned long, flags)
@@ -522,13 +522,13 @@ DECLARE_EVENT_CLASS(svc_rqst_status,
 
        TP_fast_assign(
                __entry->addr = (struct sockaddr *)&rqst->rq_addr;
-               __entry->xid = rqst->rq_xid;
+               __entry->xid = be32_to_cpu(rqst->rq_xid);
                __entry->status = status;
                __entry->flags = rqst->rq_flags;
        ),
 
-       TP_printk("addr=%pIScp rq_xid=0x%x status=%d flags=%s",
-               __entry->addr, be32_to_cpu(__entry->xid),
+       TP_printk("addr=%pIScp rq_xid=0x%08x status=%d flags=%s",
+               __entry->addr, __entry->xid,
                __entry->status, show_rqstp_flags(__entry->flags))
 );
 
@@ -677,18 +677,19 @@ DECLARE_EVENT_CLASS(svc_deferred_event,
        TP_ARGS(dr),
 
        TP_STRUCT__entry(
-               __field(__be32, xid)
+               __field(u32, xid)
                __dynamic_array(unsigned char, addr, dr->addrlen)
        ),
 
        TP_fast_assign(
-               __entry->xid = *(__be32 *)(dr->args + (dr->xprt_hlen>>2));
+               __entry->xid = be32_to_cpu(*(__be32 *)(dr->args +
+                                                      (dr->xprt_hlen>>2)));
                memcpy(__get_dynamic_array(addr), &dr->addr, dr->addrlen);
        ),
 
-       TP_printk("addr=%pIScp xid=0x%x",
+       TP_printk("addr=%pIScp xid=0x%08x",
                (struct sockaddr *)__get_dynamic_array(addr),
-               be32_to_cpu(__entry->xid))
+               __entry->xid)
 );
 
 DEFINE_EVENT(svc_deferred_event, svc_drop_deferred,