rxrpc: Record the Tx serial in the rxrpc_txbuf and retransmit trace

Each Rx protocol packet contains a per-connection monotonically increasing
serial number used to correlate outgoing messages with their replies -
something that can be used for RTT calculation.

Note this value in the rxrpc_txbuf struct in addition to the wire header
and then log it in the rxrpc_retransmit trace for reference.

Signed-off-by: David Howells <dhowells@redhat.com>
cc: Marc Dionne <marc.dionne@auristor.com>
cc: "David S. Miller" <davem@davemloft.net>
cc: Eric Dumazet <edumazet@google.com>
cc: Jakub Kicinski <kuba@kernel.org>
cc: Paolo Abeni <pabeni@redhat.com>
cc: linux-afs@lists.infradead.org
cc: netdev@vger.kernel.org

diff --git a/include/trace/events/rxrpc.h b/include/trace/events/rxrpc.h
index 87b8de9b6c1c440ce4a8b2fe6072b4d81cbc1cf4..9add56980485eb4318e3e8b56d521aa0e8720f97 100644 (file)
--- a/include/trace/events/rxrpc.h
+++ b/include/trace/events/rxrpc.h
@@ -1506,25 +1506,29 @@ TRACE_EVENT(rxrpc_drop_ack,
            );
 
 TRACE_EVENT(rxrpc_retransmit,
-           TP_PROTO(struct rxrpc_call *call, rxrpc_seq_t seq, s64 expiry),
+           TP_PROTO(struct rxrpc_call *call, rxrpc_seq_t seq,
+                    rxrpc_serial_t serial, s64 expiry),
 
-           TP_ARGS(call, seq, expiry),
+           TP_ARGS(call, seq, serial, expiry),
 
            TP_STRUCT__entry(
                    __field(unsigned int,       call)
                    __field(rxrpc_seq_t,        seq)
+                   __field(rxrpc_serial_t,     serial)
                    __field(s64,                expiry)
                             ),
 
            TP_fast_assign(
                    __entry->call = call->debug_id;
                    __entry->seq = seq;
+                   __entry->serial = serial;
                    __entry->expiry = expiry;
                           ),
 
-           TP_printk("c=%08x q=%x xp=%lld",
+           TP_printk("c=%08x q=%x r=%x xp=%lld",
                      __entry->call,
                      __entry->seq,
+                     __entry->serial,
                      __entry->expiry)
            );
 

diff --git a/net/rxrpc/ar-internal.h b/net/rxrpc/ar-internal.h
index 7818aae1be8e00c1e9b15c918868ca11b40a7213..f761257558101b66e2fb2c2d9fe8d2268ad10825 100644 (file)
--- a/net/rxrpc/ar-internal.h
+++ b/net/rxrpc/ar-internal.h
@@ -794,6 +794,7 @@ struct rxrpc_txbuf {
        ktime_t                 last_sent;      /* Time at which last transmitted */
        refcount_t              ref;
        rxrpc_seq_t             seq;            /* Sequence number of this packet */
+       rxrpc_serial_t          serial;         /* Last serial number transmitted with */
        unsigned int            call_debug_id;
        unsigned int            debug_id;
        unsigned int            len;            /* Amount of data in buffer */

diff --git a/net/rxrpc/call_event.c b/net/rxrpc/call_event.c
index 0f78544d043be9327ea13cc91fbfa532d6ef4002..a4c3099767198e7812cbf60a1d1c975e9da86129 100644 (file)
--- a/net/rxrpc/call_event.c
+++ b/net/rxrpc/call_event.c
@@ -160,7 +160,7 @@ void rxrpc_resend(struct rxrpc_call *call, struct sk_buff *ack_skb)
                        goto no_further_resend;
 
                found_txb:
-                       if (after(ntohl(txb->wire.serial), call->acks_highest_serial))
+                       if (after(txb->serial, call->acks_highest_serial))
                                continue; /* Ack point not yet reached */
 
                        rxrpc_see_txbuf(txb, rxrpc_txbuf_see_unacked);
@@ -170,7 +170,7 @@ void rxrpc_resend(struct rxrpc_call *call, struct sk_buff *ack_skb)
                                set_bit(RXRPC_TXBUF_RESENT, &txb->flags);
                        }
 
-                       trace_rxrpc_retransmit(call, txb->seq,
+                       trace_rxrpc_retransmit(call, txb->seq, txb->serial,
                                               ktime_to_ns(ktime_sub(txb->last_sent,
                                                                     max_age)));
 
@@ -197,7 +197,7 @@ void rxrpc_resend(struct rxrpc_call *call, struct sk_buff *ack_skb)
                        break; /* Not transmitted yet */
 
                if (ack && ack->reason == RXRPC_ACK_PING_RESPONSE &&
-                   before(ntohl(txb->wire.serial), ntohl(ack->serial)))
+                   before(txb->serial, ntohl(ack->serial)))
                        goto do_resend; /* Wasn't accounted for by a more recent ping. */
 
                if (ktime_after(txb->last_sent, max_age)) {

diff --git a/net/rxrpc/output.c b/net/rxrpc/output.c
index 4a292f860ae37a41bddcd99f7e3bdc6a2c092d29..bad96a983e12f8baa6e6f1b7e92ae081b2e93514 100644 (file)
--- a/net/rxrpc/output.c
+++ b/net/rxrpc/output.c
@@ -189,7 +189,6 @@ int rxrpc_send_ack_packet(struct rxrpc_call *call, struct rxrpc_txbuf *txb)
        struct rxrpc_connection *conn;
        struct msghdr msg;
        struct kvec iov[1];
-       rxrpc_serial_t serial;
        size_t len, n;
        int ret, rtt_slot = -1;
        u16 rwind;
@@ -216,15 +215,15 @@ int rxrpc_send_ack_packet(struct rxrpc_call *call, struct rxrpc_txbuf *txb)
        iov[0].iov_len  = sizeof(txb->wire) + sizeof(txb->ack) + n;
        len = iov[0].iov_len;
 
-       serial = rxrpc_get_next_serial(conn);
-       txb->wire.serial = htonl(serial);
-       trace_rxrpc_tx_ack(call->debug_id, serial,
+       txb->serial = rxrpc_get_next_serial(conn);
+       txb->wire.serial = htonl(txb->serial);
+       trace_rxrpc_tx_ack(call->debug_id, txb->serial,
                           ntohl(txb->ack.firstPacket),
                           ntohl(txb->ack.serial), txb->ack.reason, txb->ack.nAcks,
                           rwind);
 
        if (txb->ack.reason == RXRPC_ACK_PING)
-               rtt_slot = rxrpc_begin_rtt_probe(call, serial, rxrpc_rtt_tx_ping);
+               rtt_slot = rxrpc_begin_rtt_probe(call, txb->serial, rxrpc_rtt_tx_ping);
 
        rxrpc_inc_stat(call->rxnet, stat_tx_ack_send);
 
@@ -235,7 +234,7 @@ int rxrpc_send_ack_packet(struct rxrpc_call *call, struct rxrpc_txbuf *txb)
        ret = do_udp_sendmsg(conn->local->socket, &msg, len);
        call->peer->last_tx_at = ktime_get_seconds();
        if (ret < 0) {
-               trace_rxrpc_tx_fail(call->debug_id, serial, ret,
+               trace_rxrpc_tx_fail(call->debug_id, txb->serial, ret,
                                    rxrpc_tx_point_call_ack);
        } else {
                trace_rxrpc_tx_packet(call->debug_id, &txb->wire,
@@ -247,7 +246,7 @@ int rxrpc_send_ack_packet(struct rxrpc_call *call, struct rxrpc_txbuf *txb)
 
        if (!__rxrpc_call_is_complete(call)) {
                if (ret < 0)
-                       rxrpc_cancel_rtt_probe(call, serial, rtt_slot);
+                       rxrpc_cancel_rtt_probe(call, txb->serial, rtt_slot);
                rxrpc_set_keepalive(call);
        }
 
@@ -327,15 +326,14 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, struct rxrpc_txbuf *txb)
        struct rxrpc_connection *conn = call->conn;
        struct msghdr msg;
        struct kvec iov[1];
-       rxrpc_serial_t serial;
        size_t len;
        int ret, rtt_slot = -1;
 
        _enter("%x,{%d}", txb->seq, txb->len);
 
-       /* Each transmission of a Tx packet needs a new serial number */
-       serial = rxrpc_get_next_serial(conn);
-       txb->wire.serial = htonl(serial);
+       /* Each transmission of a Tx packet+ needs a new serial number */
+       txb->serial = rxrpc_get_next_serial(conn);
+       txb->wire.serial = htonl(txb->serial);
 
        if (test_bit(RXRPC_CONN_PROBING_FOR_UPGRADE, &conn->flags) &&
            txb->seq == 1)
@@ -388,7 +386,7 @@ dont_set_request_ack:
                static int lose;
                if ((lose++ & 7) == 7) {
                        ret = 0;
-                       trace_rxrpc_tx_data(call, txb->seq, serial,
+                       trace_rxrpc_tx_data(call, txb->seq, txb->serial,
                                            txb->wire.flags,
                                            test_bit(RXRPC_TXBUF_RESENT, &txb->flags),
                                            true);
@@ -396,7 +394,7 @@ dont_set_request_ack:
                }
        }
 
-       trace_rxrpc_tx_data(call, txb->seq, serial, txb->wire.flags,
+       trace_rxrpc_tx_data(call, txb->seq, txb->serial, txb->wire.flags,
                            test_bit(RXRPC_TXBUF_RESENT, &txb->flags), false);
 
        /* Track what we've attempted to transmit at least once so that the
@@ -415,7 +413,7 @@ dont_set_request_ack:
 
        txb->last_sent = ktime_get_real();
        if (txb->wire.flags & RXRPC_REQUEST_ACK)
-               rtt_slot = rxrpc_begin_rtt_probe(call, serial, rxrpc_rtt_tx_data);
+               rtt_slot = rxrpc_begin_rtt_probe(call, txb->serial, rxrpc_rtt_tx_data);
 
        /* send the packet by UDP
         * - returns -EMSGSIZE if UDP would have to fragment the packet
@@ -429,8 +427,8 @@ dont_set_request_ack:
 
        if (ret < 0) {
                rxrpc_inc_stat(call->rxnet, stat_tx_data_send_fail);
-               rxrpc_cancel_rtt_probe(call, serial, rtt_slot);
-               trace_rxrpc_tx_fail(call->debug_id, serial, ret,
+               rxrpc_cancel_rtt_probe(call, txb->serial, rtt_slot);
+               trace_rxrpc_tx_fail(call->debug_id, txb->serial, ret,
                                    rxrpc_tx_point_call_data_nofrag);
        } else {
                trace_rxrpc_tx_packet(call->debug_id, &txb->wire,
@@ -489,7 +487,7 @@ send_fragmentable:
 
        txb->last_sent = ktime_get_real();
        if (txb->wire.flags & RXRPC_REQUEST_ACK)
-               rtt_slot = rxrpc_begin_rtt_probe(call, serial, rxrpc_rtt_tx_data);
+               rtt_slot = rxrpc_begin_rtt_probe(call, txb->serial, rxrpc_rtt_tx_data);
 
        switch (conn->local->srx.transport.family) {
        case AF_INET6:
@@ -508,8 +506,8 @@ send_fragmentable:
 
        if (ret < 0) {
                rxrpc_inc_stat(call->rxnet, stat_tx_data_send_fail);
-               rxrpc_cancel_rtt_probe(call, serial, rtt_slot);
-               trace_rxrpc_tx_fail(call->debug_id, serial, ret,
+               rxrpc_cancel_rtt_probe(call, txb->serial, rtt_slot);
+               trace_rxrpc_tx_fail(call->debug_id, txb->serial, ret,
                                    rxrpc_tx_point_call_data_frag);
        } else {
                trace_rxrpc_tx_packet(call->debug_id, &txb->wire,

diff --git a/net/rxrpc/txbuf.c b/net/rxrpc/txbuf.c
index d43be85123864092b3654b06f886f19cc6e194ef..f2903c81cf5b438e14ef7768a011198389fd66ae 100644 (file)
--- a/net/rxrpc/txbuf.c
+++ b/net/rxrpc/txbuf.c
@@ -34,6 +34,7 @@ struct rxrpc_txbuf *rxrpc_alloc_txbuf(struct rxrpc_call *call, u8 packet_type,
                txb->flags              = 0;
                txb->ack_why            = 0;
                txb->seq                = call->tx_prepared + 1;
+               txb->serial             = 0;
                txb->wire.epoch         = htonl(call->conn->proto.epoch);
                txb->wire.cid           = htonl(call->cid);
                txb->wire.callNumber    = htonl(call->call_id);