Commit ba132d84 authored by David Howells's avatar David Howells

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: default avatarDavid 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
parent 489645d3
......@@ -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)
);
......
......@@ -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 */
......
......@@ -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)) {
......
......@@ -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 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, struct rxrpc_txbuf *txb)
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 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, struct rxrpc_txbuf *txb)
}
}
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 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, struct rxrpc_txbuf *txb)
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 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, struct rxrpc_txbuf *txb)
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 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, struct rxrpc_txbuf *txb)
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 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, struct rxrpc_txbuf *txb)
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,
......
......@@ -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);
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment