From nobody Sun Feb 8 11:26:14 2026 Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [170.10.129.124]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.subspace.kernel.org (Postfix) with ESMTPS id 5FD421B27A for ; Mon, 4 Mar 2024 08:43:33 +0000 (UTC) Authentication-Results: smtp.subspace.kernel.org; arc=none smtp.client-ip=170.10.129.124 ARC-Seal: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1709541815; cv=none; b=FhfLF/LAW50h0K+Zd9tqwTth3bCXBaTR12rDYshnuUfEUZXiCsdRsrV6OtUilZFKaZakIZNw3WlqrEXatYJAD5QTB4eoFqUB4H8fw3qW98fMQVUSQJ2kw76B8JXRmTqexh0MNBcKChD6OTBjT/GlQmEBPUsy/+6y5MNt9kE+/lk= ARC-Message-Signature: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1709541815; c=relaxed/simple; bh=buGQQIqwfDOjT2V25LdvmamRLILtg2fDY6qrTYz9e6I=; h=From:To:Cc:Subject:Date:Message-ID:In-Reply-To:References: MIME-Version; b=FTSRfg/Y3kO/7iBfLMwbwwwPqYzffN0Gfc3qIiBuH8i03ARjknK+Ln7f5mhzD0sdenIHOc43gFIogQfieH/QWKI69zTnqSBTPESY4eKJbaioHu+G6pkx0/eGa0p6G0DxQR0m/mR0RAnXlrmX6zey/4/Tfr9f4eXr9FSvx1LcoAY= ARC-Authentication-Results: i=1; smtp.subspace.kernel.org; dmarc=pass (p=none dis=none) header.from=redhat.com; spf=pass smtp.mailfrom=redhat.com; dkim=pass (1024-bit key) header.d=redhat.com header.i=@redhat.com header.b=CG62LVAL; arc=none smtp.client-ip=170.10.129.124 Authentication-Results: smtp.subspace.kernel.org; dmarc=pass (p=none dis=none) header.from=redhat.com Authentication-Results: smtp.subspace.kernel.org; spf=pass smtp.mailfrom=redhat.com Authentication-Results: smtp.subspace.kernel.org; dkim=pass (1024-bit key) header.d=redhat.com header.i=@redhat.com header.b="CG62LVAL" DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1709541812; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=SInqaLs7+HuZGhZ5JkGiSMY+PTSraJJ+xEdb815D0Ac=; b=CG62LVALkrpavPS9wdW7+RfM2GTZ1Dh1iYqeld1BsD/QX2svAv94Abb0oCIF61QzsnGbL3 6XWfiPTexOsA4sifz8GRjmfTHDCZjXvhf0Pp3M3/AWeNNpijPxuAMyWMJ32sr7IW/aiTjq Pml2FgP7DFQnFvtA7TT5FGYfF09Kdj0= Received: from mimecast-mx02.redhat.com (mx-ext.redhat.com [66.187.233.73]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384) id us-mta-439-7ppsfzbsOtSWxQ1KaPhk2Q-1; Mon, 04 Mar 2024 03:43:28 -0500 X-MC-Unique: 7ppsfzbsOtSWxQ1KaPhk2Q-1 Received: from smtp.corp.redhat.com (int-mx02.intmail.prod.int.rdu2.redhat.com [10.11.54.2]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256) (No client certificate requested) by mimecast-mx02.redhat.com (Postfix) with ESMTPS id E594E38212C5; Mon, 4 Mar 2024 08:43:27 +0000 (UTC) Received: from warthog.procyon.org.com (unknown [10.42.28.114]) by smtp.corp.redhat.com (Postfix) with ESMTP id C2A1740C6EBA; Mon, 4 Mar 2024 08:43:26 +0000 (UTC) From: David Howells To: netdev@vger.kernel.org Cc: David Howells , Marc Dionne , "David S. Miller" , Eric Dumazet , Jakub Kicinski , Paolo Abeni , linux-afs@lists.infradead.org, linux-kernel@vger.kernel.org Subject: [PATCH net-next v2 01/21] rxrpc: Record the Tx serial in the rxrpc_txbuf and retransmit trace Date: Mon, 4 Mar 2024 08:42:58 +0000 Message-ID: <20240304084322.705539-2-dhowells@redhat.com> In-Reply-To: <20240304084322.705539-1-dhowells@redhat.com> References: <20240304084322.705539-1-dhowells@redhat.com> Precedence: bulk X-Mailing-List: linux-kernel@vger.kernel.org List-Id: List-Subscribe: List-Unsubscribe: MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable X-Scanned-By: MIMEDefang 3.4.1 on 10.11.54.2 Content-Type: text/plain; charset="utf-8" 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 cc: Marc Dionne cc: "David S. Miller" cc: Eric Dumazet cc: Jakub Kicinski cc: Paolo Abeni cc: linux-afs@lists.infradead.org cc: netdev@vger.kernel.org --- include/trace/events/rxrpc.h | 10 +++++++--- net/rxrpc/ar-internal.h | 1 + net/rxrpc/call_event.c | 6 +++--- net/rxrpc/output.c | 36 +++++++++++++++++------------------- net/rxrpc/txbuf.c | 1 + 5 files changed, 29 insertions(+), 25 deletions(-) diff --git a/include/trace/events/rxrpc.h b/include/trace/events/rxrpc.h index 87b8de9b6c1c..9add56980485 100644 --- a/include/trace/events/rxrpc.h +++ b/include/trace/events/rxrpc.h @@ -1506,25 +1506,29 @@ TRACE_EVENT(rxrpc_drop_ack, ); =20 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), =20 - TP_ARGS(call, seq, expiry), + TP_ARGS(call, seq, serial, expiry), =20 TP_STRUCT__entry( __field(unsigned int, call) __field(rxrpc_seq_t, seq) + __field(rxrpc_serial_t, serial) __field(s64, expiry) ), =20 TP_fast_assign( __entry->call =3D call->debug_id; __entry->seq =3D seq; + __entry->serial =3D serial; __entry->expiry =3D expiry; ), =20 - TP_printk("c=3D%08x q=3D%x xp=3D%lld", + TP_printk("c=3D%08x q=3D%x r=3D%x xp=3D%lld", __entry->call, __entry->seq, + __entry->serial, __entry->expiry) ); =20 diff --git a/net/rxrpc/ar-internal.h b/net/rxrpc/ar-internal.h index 7818aae1be8e..f76125755810 100644 --- 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 0f78544d043b..a4c309976719 100644 --- 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_bu= ff *ack_skb) goto no_further_resend; =20 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 */ =20 rxrpc_see_txbuf(txb, rxrpc_txbuf_see_unacked); @@ -170,7 +170,7 @@ void rxrpc_resend(struct rxrpc_call *call, struct sk_bu= ff *ack_skb) set_bit(RXRPC_TXBUF_RESENT, &txb->flags); } =20 - trace_rxrpc_retransmit(call, txb->seq, + trace_rxrpc_retransmit(call, txb->seq, txb->serial, ktime_to_ns(ktime_sub(txb->last_sent, max_age))); =20 @@ -197,7 +197,7 @@ void rxrpc_resend(struct rxrpc_call *call, struct sk_bu= ff *ack_skb) break; /* Not transmitted yet */ =20 if (ack && ack->reason =3D=3D 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. */ =20 if (ktime_after(txb->last_sent, max_age)) { diff --git a/net/rxrpc/output.c b/net/rxrpc/output.c index 4a292f860ae3..bad96a983e12 100644 --- a/net/rxrpc/output.c +++ b/net/rxrpc/output.c @@ -189,7 +189,6 @@ int rxrpc_send_ack_packet(struct rxrpc_call *call, stru= ct 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 =3D -1; u16 rwind; @@ -216,15 +215,15 @@ int rxrpc_send_ack_packet(struct rxrpc_call *call, st= ruct rxrpc_txbuf *txb) iov[0].iov_len =3D sizeof(txb->wire) + sizeof(txb->ack) + n; len =3D iov[0].iov_len; =20 - serial =3D rxrpc_get_next_serial(conn); - txb->wire.serial =3D htonl(serial); - trace_rxrpc_tx_ack(call->debug_id, serial, + txb->serial =3D rxrpc_get_next_serial(conn); + txb->wire.serial =3D 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); =20 if (txb->ack.reason =3D=3D RXRPC_ACK_PING) - rtt_slot =3D rxrpc_begin_rtt_probe(call, serial, rxrpc_rtt_tx_ping); + rtt_slot =3D rxrpc_begin_rtt_probe(call, txb->serial, rxrpc_rtt_tx_ping); =20 rxrpc_inc_stat(call->rxnet, stat_tx_ack_send); =20 @@ -235,7 +234,7 @@ int rxrpc_send_ack_packet(struct rxrpc_call *call, stru= ct rxrpc_txbuf *txb) ret =3D do_udp_sendmsg(conn->local->socket, &msg, len); call->peer->last_tx_at =3D 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, stru= ct rxrpc_txbuf *txb) =20 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); } =20 @@ -327,15 +326,14 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, s= truct rxrpc_txbuf *txb) struct rxrpc_connection *conn =3D call->conn; struct msghdr msg; struct kvec iov[1]; - rxrpc_serial_t serial; size_t len; int ret, rtt_slot =3D -1; =20 _enter("%x,{%d}", txb->seq, txb->len); =20 - /* Each transmission of a Tx packet needs a new serial number */ - serial =3D rxrpc_get_next_serial(conn); - txb->wire.serial =3D htonl(serial); + /* Each transmission of a Tx packet+ needs a new serial number */ + txb->serial =3D rxrpc_get_next_serial(conn); + txb->wire.serial =3D htonl(txb->serial); =20 if (test_bit(RXRPC_CONN_PROBING_FOR_UPGRADE, &conn->flags) && txb->seq =3D=3D 1) @@ -388,7 +386,7 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, str= uct rxrpc_txbuf *txb) static int lose; if ((lose++ & 7) =3D=3D 7) { ret =3D 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, str= uct rxrpc_txbuf *txb) } } =20 - 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); =20 /* 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, str= uct rxrpc_txbuf *txb) =20 txb->last_sent =3D ktime_get_real(); if (txb->wire.flags & RXRPC_REQUEST_ACK) - rtt_slot =3D rxrpc_begin_rtt_probe(call, serial, rxrpc_rtt_tx_data); + rtt_slot =3D rxrpc_begin_rtt_probe(call, txb->serial, rxrpc_rtt_tx_data); =20 /* 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, str= uct rxrpc_txbuf *txb) =20 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, str= uct rxrpc_txbuf *txb) =20 txb->last_sent =3D ktime_get_real(); if (txb->wire.flags & RXRPC_REQUEST_ACK) - rtt_slot =3D rxrpc_begin_rtt_probe(call, serial, rxrpc_rtt_tx_data); + rtt_slot =3D rxrpc_begin_rtt_probe(call, txb->serial, rxrpc_rtt_tx_data); =20 switch (conn->local->srx.transport.family) { case AF_INET6: @@ -508,8 +506,8 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, str= uct rxrpc_txbuf *txb) =20 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 d43be8512386..f2903c81cf5b 100644 --- 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 =3D 0; txb->ack_why =3D 0; txb->seq =3D call->tx_prepared + 1; + txb->serial =3D 0; txb->wire.epoch =3D htonl(call->conn->proto.epoch); txb->wire.cid =3D htonl(call->cid); txb->wire.callNumber =3D htonl(call->call_id);