rxrpc: Add a tracepoint to follow packets in the Rx buffer
authorDavid Howells <dhowells@redhat.com>
Sat, 17 Sep 2016 09:49:13 +0000 (10:49 +0100)
committerDavid Howells <dhowells@redhat.com>
Sat, 17 Sep 2016 10:24:03 +0000 (11:24 +0100)
Add a tracepoint to follow the life of packets that get added to a call's
receive buffer.

Signed-off-by: David Howells <dhowells@redhat.com>
include/trace/events/rxrpc.h
net/rxrpc/ar-internal.h
net/rxrpc/call_accept.c
net/rxrpc/input.c
net/rxrpc/misc.c
net/rxrpc/recvmsg.c

index d545d69..7dd5f01 100644 (file)
@@ -290,6 +290,39 @@ TRACE_EVENT(rxrpc_tx_ack,
                      __entry->n_acks)
            );
 
+TRACE_EVENT(rxrpc_receive,
+           TP_PROTO(struct rxrpc_call *call, enum rxrpc_receive_trace why,
+                    rxrpc_serial_t serial, rxrpc_seq_t seq),
+
+           TP_ARGS(call, why, serial, seq),
+
+           TP_STRUCT__entry(
+                   __field(struct rxrpc_call *,        call            )
+                   __field(enum rxrpc_receive_trace,   why             )
+                   __field(rxrpc_serial_t,             serial          )
+                   __field(rxrpc_seq_t,                seq             )
+                   __field(rxrpc_seq_t,                hard_ack        )
+                   __field(rxrpc_seq_t,                top             )
+                            ),
+
+           TP_fast_assign(
+                   __entry->call = call;
+                   __entry->why = why;
+                   __entry->serial = serial;
+                   __entry->seq = seq;
+                   __entry->hard_ack = call->rx_hard_ack;
+                   __entry->top = call->rx_top;
+                          ),
+
+           TP_printk("c=%p %s r=%08x q=%08x w=%08x-%08x",
+                     __entry->call,
+                     rxrpc_receive_traces[__entry->why],
+                     __entry->serial,
+                     __entry->seq,
+                     __entry->hard_ack,
+                     __entry->top)
+           );
+
 #endif /* _TRACE_RXRPC_H */
 
 /* This part must be outside protection */
index afa5dcc..e5d2f2f 100644 (file)
@@ -605,6 +605,18 @@ enum rxrpc_transmit_trace {
 
 extern const char rxrpc_transmit_traces[rxrpc_transmit__nr_trace][4];
 
+enum rxrpc_receive_trace {
+       rxrpc_receive_incoming,
+       rxrpc_receive_queue,
+       rxrpc_receive_queue_last,
+       rxrpc_receive_front,
+       rxrpc_receive_rotate,
+       rxrpc_receive_end,
+       rxrpc_receive__nr_trace
+};
+
+extern const char rxrpc_receive_traces[rxrpc_receive__nr_trace][4];
+
 extern const char *const rxrpc_pkts[];
 extern const char *rxrpc_acks(u8 reason);
 
index 3e47450..a8d39d7 100644 (file)
@@ -367,6 +367,9 @@ found_service:
                goto out;
        }
 
+       trace_rxrpc_receive(call, rxrpc_receive_incoming,
+                           sp->hdr.serial, sp->hdr.seq);
+
        /* Make the call live. */
        rxrpc_incoming_call(rx, call, skb);
        conn = call->conn;
index 7b18ca1..b690220 100644 (file)
@@ -284,8 +284,12 @@ next_subpacket:
        call->rxtx_buffer[ix] = skb;
        if (after(seq, call->rx_top))
                smp_store_release(&call->rx_top, seq);
-       if (flags & RXRPC_LAST_PACKET)
+       if (flags & RXRPC_LAST_PACKET) {
                set_bit(RXRPC_CALL_RX_LAST, &call->flags);
+               trace_rxrpc_receive(call, rxrpc_receive_queue_last, serial, seq);
+       } else {
+               trace_rxrpc_receive(call, rxrpc_receive_queue, serial, seq);
+       }
        queued = true;
 
        if (after_eq(seq, call->rx_expect_next)) {
index dca8999..db5f1d5 100644 (file)
@@ -141,3 +141,12 @@ const char rxrpc_transmit_traces[rxrpc_transmit__nr_trace][4] = {
        [rxrpc_transmit_rotate]         = "ROT",
        [rxrpc_transmit_end]            = "END",
 };
+
+const char rxrpc_receive_traces[rxrpc_receive__nr_trace][4] = {
+       [rxrpc_receive_incoming]        = "INC",
+       [rxrpc_receive_queue]           = "QUE",
+       [rxrpc_receive_queue_last]      = "QLS",
+       [rxrpc_receive_front]           = "FRN",
+       [rxrpc_receive_rotate]          = "ROT",
+       [rxrpc_receive_end]             = "END",
+};
index 8b8d7e1..22d5108 100644 (file)
@@ -134,6 +134,7 @@ static void rxrpc_end_rx_phase(struct rxrpc_call *call)
 {
        _enter("%d,%s", call->debug_id, rxrpc_call_states[call->state]);
 
+       trace_rxrpc_receive(call, rxrpc_receive_end, 0, call->rx_top);
        ASSERTCMP(call->rx_hard_ack, ==, call->rx_top);
 
        if (call->state == RXRPC_CALL_CLIENT_RECV_REPLY) {
@@ -167,6 +168,7 @@ static void rxrpc_rotate_rx_window(struct rxrpc_call *call)
 {
        struct rxrpc_skb_priv *sp;
        struct sk_buff *skb;
+       rxrpc_serial_t serial;
        rxrpc_seq_t hard_ack, top;
        u8 flags;
        int ix;
@@ -183,6 +185,10 @@ static void rxrpc_rotate_rx_window(struct rxrpc_call *call)
        rxrpc_see_skb(skb);
        sp = rxrpc_skb(skb);
        flags = sp->hdr.flags;
+       serial = sp->hdr.serial;
+       if (call->rxtx_annotations[ix] & RXRPC_RX_ANNO_JUMBO)
+               serial += (call->rxtx_annotations[ix] & RXRPC_RX_ANNO_JUMBO) - 1;
+
        call->rxtx_buffer[ix] = NULL;
        call->rxtx_annotations[ix] = 0;
        /* Barrier against rxrpc_input_data(). */
@@ -191,6 +197,7 @@ static void rxrpc_rotate_rx_window(struct rxrpc_call *call)
        rxrpc_free_skb(skb);
 
        _debug("%u,%u,%02x", hard_ack, top, flags);
+       trace_rxrpc_receive(call, rxrpc_receive_rotate, serial, hard_ack);
        if (flags & RXRPC_LAST_PACKET)
                rxrpc_end_rx_phase(call);
 }
@@ -309,6 +316,10 @@ static int rxrpc_recvmsg_data(struct socket *sock, struct rxrpc_call *call,
                rxrpc_see_skb(skb);
                sp = rxrpc_skb(skb);
 
+               if (!(flags & MSG_PEEK))
+                       trace_rxrpc_receive(call, rxrpc_receive_front,
+                                           sp->hdr.serial, seq);
+
                if (msg)
                        sock_recv_timestamp(msg, sock->sk, skb);