rxrpc: Split call timer-expiration from call timer-set tracepoint

Split the tracepoint for call timer-set to separate out the call
timer-expiration event

Signed-off-by: David Howells <dhowells@redhat.com>
cc: Marc Dionne <marc.dionne@auristor.com>
cc: linux-afs@lists.infradead.org

diff --git a/include/trace/events/rxrpc.h b/include/trace/events/rxrpc.h
index 4c501c6..a72f04e 100644 (file)
--- a/include/trace/events/rxrpc.h
+++ b/include/trace/events/rxrpc.h
@@ -133,7 +133,6 @@
 
 #define rxrpc_timer_traces \
        EM(rxrpc_timer_begin,                   "Begin ") \
-       EM(rxrpc_timer_expired,                 "*EXPR*") \
        EM(rxrpc_timer_exp_ack,                 "ExpAck") \
        EM(rxrpc_timer_exp_hard,                "ExpHrd") \
        EM(rxrpc_timer_exp_idle,                "ExpIdl") \
@@ -1019,6 +1018,47 @@ TRACE_EVENT(rxrpc_timer,
                      __entry->timer - __entry->now)
            );
 
+TRACE_EVENT(rxrpc_timer_expired,
+           TP_PROTO(struct rxrpc_call *call, unsigned long now),
+
+           TP_ARGS(call, now),
+
+           TP_STRUCT__entry(
+                   __field(unsigned int,                       call            )
+                   __field(long,                               now             )
+                   __field(long,                               ack_at          )
+                   __field(long,                               ack_lost_at     )
+                   __field(long,                               resend_at       )
+                   __field(long,                               ping_at         )
+                   __field(long,                               expect_rx_by    )
+                   __field(long,                               expect_req_by   )
+                   __field(long,                               expect_term_by  )
+                   __field(long,                               timer           )
+                            ),
+
+           TP_fast_assign(
+                   __entry->call               = call->debug_id;
+                   __entry->now                = now;
+                   __entry->ack_at             = call->ack_at;
+                   __entry->ack_lost_at        = call->ack_lost_at;
+                   __entry->resend_at          = call->resend_at;
+                   __entry->expect_rx_by       = call->expect_rx_by;
+                   __entry->expect_req_by      = call->expect_req_by;
+                   __entry->expect_term_by     = call->expect_term_by;
+                   __entry->timer              = call->timer.expires;
+                          ),
+
+           TP_printk("c=%08x EXPIRED a=%ld la=%ld r=%ld xr=%ld xq=%ld xt=%ld t=%ld",
+                     __entry->call,
+                     __entry->ack_at - __entry->now,
+                     __entry->ack_lost_at - __entry->now,
+                     __entry->resend_at - __entry->now,
+                     __entry->expect_rx_by - __entry->now,
+                     __entry->expect_req_by - __entry->now,
+                     __entry->expect_term_by - __entry->now,
+                     __entry->timer - __entry->now)
+           );
+
 TRACE_EVENT(rxrpc_rx_lose,
            TP_PROTO(struct rxrpc_skb_priv *sp),
 

diff --git a/net/rxrpc/call_object.c b/net/rxrpc/call_object.c
index 6401cdf..a75861a 100644 (file)
--- a/net/rxrpc/call_object.c
+++ b/net/rxrpc/call_object.c
@@ -52,7 +52,7 @@ static void rxrpc_call_timer_expired(struct timer_list *t)
        _enter("%d", call->debug_id);
 
        if (call->state < RXRPC_CALL_COMPLETE) {
-               trace_rxrpc_timer(call, rxrpc_timer_expired, jiffies);
+               trace_rxrpc_timer_expired(call, jiffies);
                __rxrpc_queue_call(call);
        } else {
                rxrpc_put_call(call, rxrpc_call_put);