rxrpc: Split the rxrpc_recvmsg tracepoint
authorDavid Howells <dhowells@redhat.com>
Fri, 7 Oct 2022 16:22:40 +0000 (17:22 +0100)
committerDavid Howells <dhowells@redhat.com>
Tue, 8 Nov 2022 16:42:28 +0000 (16:42 +0000)
Split the rxrpc_recvmsg tracepoint so that the tracepoints that are about
data packet processing (and which have extra pieces of information) are
separate from the tracepoint that shows the general flow of recvmsg().

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

include/trace/events/rxrpc.h
net/rxrpc/recvmsg.c

index d32e9858c682fd072c2a2f0ccb35a1306bf38a38..84464b29e54ac57b33276f608a7a2ef4344fef28 100644 (file)
@@ -885,6 +885,30 @@ TRACE_EVENT(rxrpc_receive,
            );
 
 TRACE_EVENT(rxrpc_recvmsg,
            );
 
 TRACE_EVENT(rxrpc_recvmsg,
+           TP_PROTO(struct rxrpc_call *call, enum rxrpc_recvmsg_trace why,
+                    int ret),
+
+           TP_ARGS(call, why, ret),
+
+           TP_STRUCT__entry(
+                   __field(unsigned int,               call            )
+                   __field(enum rxrpc_recvmsg_trace,   why             )
+                   __field(int,                        ret             )
+                            ),
+
+           TP_fast_assign(
+                   __entry->call = call ? call->debug_id : 0;
+                   __entry->why = why;
+                   __entry->ret = ret;
+                          ),
+
+           TP_printk("c=%08x %s ret=%d",
+                     __entry->call,
+                     __print_symbolic(__entry->why, rxrpc_recvmsg_traces),
+                     __entry->ret)
+           );
+
+TRACE_EVENT(rxrpc_recvdata,
            TP_PROTO(struct rxrpc_call *call, enum rxrpc_recvmsg_trace why,
                     rxrpc_seq_t seq, unsigned int offset, unsigned int len,
                     int ret),
            TP_PROTO(struct rxrpc_call *call, enum rxrpc_recvmsg_trace why,
                     rxrpc_seq_t seq, unsigned int offset, unsigned int len,
                     int ret),
index 46e784edc0f441df2f1d9a0758417424f08a2076..77cde6311559b5e35da964d74afccea3f6a94c77 100644 (file)
@@ -173,8 +173,8 @@ static int rxrpc_recvmsg_term(struct rxrpc_call *call, struct msghdr *msg)
                break;
        }
 
                break;
        }
 
-       trace_rxrpc_recvmsg(call, rxrpc_recvmsg_terminal, call->rx_hard_ack,
-                           call->rx_pkt_offset, call->rx_pkt_len, ret);
+       trace_rxrpc_recvdata(call, rxrpc_recvmsg_terminal, call->rx_hard_ack,
+                            call->rx_pkt_offset, call->rx_pkt_len, ret);
        return ret;
 }
 
        return ret;
 }
 
@@ -380,8 +380,8 @@ static int rxrpc_recvmsg_data(struct socket *sock, struct rxrpc_call *call,
                ix = seq & RXRPC_RXTX_BUFF_MASK;
                skb = call->rxtx_buffer[ix];
                if (!skb) {
                ix = seq & RXRPC_RXTX_BUFF_MASK;
                skb = call->rxtx_buffer[ix];
                if (!skb) {
-                       trace_rxrpc_recvmsg(call, rxrpc_recvmsg_hole, seq,
-                                           rx_pkt_offset, rx_pkt_len, 0);
+                       trace_rxrpc_recvdata(call, rxrpc_recvmsg_hole, seq,
+                                            rx_pkt_offset, rx_pkt_len, 0);
                        rxrpc_transmit_ack_packets(call->peer->local);
                        break;
                }
                        rxrpc_transmit_ack_packets(call->peer->local);
                        break;
                }
@@ -404,15 +404,15 @@ static int rxrpc_recvmsg_data(struct socket *sock, struct rxrpc_call *call,
                                                 &call->rxtx_annotations[ix],
                                                 &rx_pkt_offset, &rx_pkt_len,
                                                 &rx_pkt_last);
                                                 &call->rxtx_annotations[ix],
                                                 &rx_pkt_offset, &rx_pkt_len,
                                                 &rx_pkt_last);
-                       trace_rxrpc_recvmsg(call, rxrpc_recvmsg_next, seq,
-                                           rx_pkt_offset, rx_pkt_len, ret2);
+                       trace_rxrpc_recvdata(call, rxrpc_recvmsg_next, seq,
+                                            rx_pkt_offset, rx_pkt_len, ret2);
                        if (ret2 < 0) {
                                ret = ret2;
                                goto out;
                        }
                } else {
                        if (ret2 < 0) {
                                ret = ret2;
                                goto out;
                        }
                } else {
-                       trace_rxrpc_recvmsg(call, rxrpc_recvmsg_cont, seq,
-                                           rx_pkt_offset, rx_pkt_len, 0);
+                       trace_rxrpc_recvdata(call, rxrpc_recvmsg_cont, seq,
+                                            rx_pkt_offset, rx_pkt_len, 0);
                }
 
                /* We have to handle short, empty and used-up DATA packets. */
                }
 
                /* We have to handle short, empty and used-up DATA packets. */
@@ -435,8 +435,8 @@ static int rxrpc_recvmsg_data(struct socket *sock, struct rxrpc_call *call,
                }
 
                if (rx_pkt_len > 0) {
                }
 
                if (rx_pkt_len > 0) {
-                       trace_rxrpc_recvmsg(call, rxrpc_recvmsg_full, seq,
-                                           rx_pkt_offset, rx_pkt_len, 0);
+                       trace_rxrpc_recvdata(call, rxrpc_recvmsg_full, seq,
+                                            rx_pkt_offset, rx_pkt_len, 0);
                        ASSERTCMP(*_offset, ==, len);
                        ret = 0;
                        break;
                        ASSERTCMP(*_offset, ==, len);
                        ret = 0;
                        break;
@@ -464,8 +464,8 @@ out:
                call->rx_pkt_last = rx_pkt_last;
        }
 done:
                call->rx_pkt_last = rx_pkt_last;
        }
 done:
-       trace_rxrpc_recvmsg(call, rxrpc_recvmsg_data_return, seq,
-                           rx_pkt_offset, rx_pkt_len, ret);
+       trace_rxrpc_recvdata(call, rxrpc_recvmsg_data_return, seq,
+                            rx_pkt_offset, rx_pkt_len, ret);
        if (ret == -EAGAIN)
                set_bit(RXRPC_CALL_RX_UNDERRUN, &call->flags);
        return ret;
        if (ret == -EAGAIN)
                set_bit(RXRPC_CALL_RX_UNDERRUN, &call->flags);
        return ret;
@@ -488,7 +488,7 @@ int rxrpc_recvmsg(struct socket *sock, struct msghdr *msg, size_t len,
 
        DEFINE_WAIT(wait);
 
 
        DEFINE_WAIT(wait);
 
-       trace_rxrpc_recvmsg(NULL, rxrpc_recvmsg_enter, 0, 0, 0, 0);
+       trace_rxrpc_recvmsg(NULL, rxrpc_recvmsg_enter, 0);
 
        if (flags & (MSG_OOB | MSG_TRUNC))
                return -EOPNOTSUPP;
 
        if (flags & (MSG_OOB | MSG_TRUNC))
                return -EOPNOTSUPP;
@@ -525,8 +525,7 @@ try_again:
                if (list_empty(&rx->recvmsg_q)) {
                        if (signal_pending(current))
                                goto wait_interrupted;
                if (list_empty(&rx->recvmsg_q)) {
                        if (signal_pending(current))
                                goto wait_interrupted;
-                       trace_rxrpc_recvmsg(NULL, rxrpc_recvmsg_wait,
-                                           0, 0, 0, 0);
+                       trace_rxrpc_recvmsg(NULL, rxrpc_recvmsg_wait, 0);
                        timeo = schedule_timeout(timeo);
                }
                finish_wait(sk_sleep(&rx->sk), &wait);
                        timeo = schedule_timeout(timeo);
                }
                finish_wait(sk_sleep(&rx->sk), &wait);
@@ -545,7 +544,7 @@ try_again:
                rxrpc_get_call(call, rxrpc_call_got);
        write_unlock_bh(&rx->recvmsg_lock);
 
                rxrpc_get_call(call, rxrpc_call_got);
        write_unlock_bh(&rx->recvmsg_lock);
 
-       trace_rxrpc_recvmsg(call, rxrpc_recvmsg_dequeue, 0, 0, 0, 0);
+       trace_rxrpc_recvmsg(call, rxrpc_recvmsg_dequeue, 0);
 
        /* We're going to drop the socket lock, so we need to lock the call
         * against interference by sendmsg.
 
        /* We're going to drop the socket lock, so we need to lock the call
         * against interference by sendmsg.
@@ -630,7 +629,7 @@ try_again:
 error_unlock_call:
        mutex_unlock(&call->user_mutex);
        rxrpc_put_call(call, rxrpc_call_put);
 error_unlock_call:
        mutex_unlock(&call->user_mutex);
        rxrpc_put_call(call, rxrpc_call_put);
-       trace_rxrpc_recvmsg(call, rxrpc_recvmsg_return, 0, 0, 0, ret);
+       trace_rxrpc_recvmsg(call, rxrpc_recvmsg_return, ret);
        return ret;
 
 error_requeue_call:
        return ret;
 
 error_requeue_call:
@@ -638,14 +637,14 @@ error_requeue_call:
                write_lock_bh(&rx->recvmsg_lock);
                list_add(&call->recvmsg_link, &rx->recvmsg_q);
                write_unlock_bh(&rx->recvmsg_lock);
                write_lock_bh(&rx->recvmsg_lock);
                list_add(&call->recvmsg_link, &rx->recvmsg_q);
                write_unlock_bh(&rx->recvmsg_lock);
-               trace_rxrpc_recvmsg(call, rxrpc_recvmsg_requeue, 0, 0, 0, 0);
+               trace_rxrpc_recvmsg(call, rxrpc_recvmsg_requeue, 0);
        } else {
                rxrpc_put_call(call, rxrpc_call_put);
        }
 error_no_call:
        release_sock(&rx->sk);
 error_trace:
        } else {
                rxrpc_put_call(call, rxrpc_call_put);
        }
 error_no_call:
        release_sock(&rx->sk);
 error_trace:
-       trace_rxrpc_recvmsg(call, rxrpc_recvmsg_return, 0, 0, 0, ret);
+       trace_rxrpc_recvmsg(call, rxrpc_recvmsg_return, ret);
        return ret;
 
 wait_interrupted:
        return ret;
 
 wait_interrupted: