Commit 4764c0da authored by David Howells's avatar David Howells
Browse files

rxrpc: Trace packet transmission 



Trace successful packet transmission (kernel_sendmsg() succeeded, that is)
in AF_RXRPC.  We can share the enum that defines the transmission points
with the trace_rxrpc_tx_fail() tracepoint, so rename its constants to be
applicable to both.

Also, save the internal call->debug_id in the rxrpc_channel struct so that
it can be used in retransmission trace lines.

Signed-off-by: default avatarDavid Howells <dhowells@redhat.com>
parent f3f8337c

include/trace/events/rxrpc.h

+72 −35
Original line number Diff line number Diff line
@@ -211,18 +211,18 @@ enum rxrpc_congest_change { 
	rxrpc_cong_saw_nack,

};



enum rxrpc_tx_fail_trace {

	rxrpc_tx_fail_call_abort,

	rxrpc_tx_fail_call_ack,

	rxrpc_tx_fail_call_data_frag,

	rxrpc_tx_fail_call_data_nofrag,

	rxrpc_tx_fail_call_final_resend,

	rxrpc_tx_fail_conn_abort,

	rxrpc_tx_fail_conn_challenge,

	rxrpc_tx_fail_conn_response,

	rxrpc_tx_fail_reject,

	rxrpc_tx_fail_version_keepalive,

	rxrpc_tx_fail_version_reply,

enum rxrpc_tx_point {

	rxrpc_tx_point_call_abort,

	rxrpc_tx_point_call_ack,

	rxrpc_tx_point_call_data_frag,

	rxrpc_tx_point_call_data_nofrag,

	rxrpc_tx_point_call_final_resend,

	rxrpc_tx_point_conn_abort,

	rxrpc_tx_point_rxkad_challenge,

	rxrpc_tx_point_rxkad_response,

	rxrpc_tx_point_reject,

	rxrpc_tx_point_version_keepalive,

	rxrpc_tx_point_version_reply,

};



#endif /* end __RXRPC_DECLARE_TRACE_ENUMS_ONCE_ONLY */
@@ -452,18 +452,18 @@ enum rxrpc_tx_fail_trace { 
	EM(RXRPC_CALL_LOCAL_ERROR,		"LocalError") \

	E_(RXRPC_CALL_NETWORK_ERROR,		"NetError")



#define rxrpc_tx_fail_traces \

	EM(rxrpc_tx_fail_call_abort,		"CallAbort") \

	EM(rxrpc_tx_fail_call_ack,		"CallAck") \

	EM(rxrpc_tx_fail_call_data_frag,	"CallDataFrag") \

	EM(rxrpc_tx_fail_call_data_nofrag,	"CallDataNofrag") \

	EM(rxrpc_tx_fail_call_final_resend,	"CallFinalResend") \

	EM(rxrpc_tx_fail_conn_abort,		"ConnAbort") \

	EM(rxrpc_tx_fail_conn_challenge,	"ConnChall") \

	EM(rxrpc_tx_fail_conn_response,		"ConnResp") \

	EM(rxrpc_tx_fail_reject,		"Reject") \

	EM(rxrpc_tx_fail_version_keepalive,	"VerKeepalive") \

	E_(rxrpc_tx_fail_version_reply,		"VerReply")

#define rxrpc_tx_points \

	EM(rxrpc_tx_point_call_abort,		"CallAbort") \

	EM(rxrpc_tx_point_call_ack,		"CallAck") \

	EM(rxrpc_tx_point_call_data_frag,	"CallDataFrag") \

	EM(rxrpc_tx_point_call_data_nofrag,	"CallDataNofrag") \

	EM(rxrpc_tx_point_call_final_resend,	"CallFinalResend") \

	EM(rxrpc_tx_point_conn_abort,		"ConnAbort") \

	EM(rxrpc_tx_point_reject,		"Reject") \

	EM(rxrpc_tx_point_rxkad_challenge,	"RxkadChall") \

	EM(rxrpc_tx_point_rxkad_response,	"RxkadResp") \

	EM(rxrpc_tx_point_version_keepalive,	"VerKeepalive") \

	E_(rxrpc_tx_point_version_reply,	"VerReply")



/*

 * Export enum symbols via userspace.
@@ -488,7 +488,7 @@ rxrpc_propose_ack_traces; 
rxrpc_propose_ack_outcomes;

rxrpc_congest_modes;

rxrpc_congest_changes;

rxrpc_tx_fail_traces;

rxrpc_tx_points;



/*

 * Now redefine the EM() and E_() macros to map the enums to the strings that
@@ -801,7 +801,7 @@ TRACE_EVENT(rxrpc_transmit, 
	    );



TRACE_EVENT(rxrpc_rx_data,

	    TP_PROTO(struct rxrpc_call *call, rxrpc_seq_t seq,

	    TP_PROTO(unsigned int call, rxrpc_seq_t seq,

		     rxrpc_serial_t serial, u8 flags, u8 anno),



	    TP_ARGS(call, seq, serial, flags, anno),
@@ -815,7 +815,7 @@ TRACE_EVENT(rxrpc_rx_data, 
			     ),



	    TP_fast_assign(

		    __entry->call = call->debug_id;

		    __entry->call = call;

		    __entry->seq = seq;

		    __entry->serial = serial;

		    __entry->flags = flags;
@@ -918,6 +918,37 @@ TRACE_EVENT(rxrpc_rx_rwind_change, 
		      __entry->wake ? " wake" : "")

	    );



TRACE_EVENT(rxrpc_tx_packet,

	    TP_PROTO(unsigned int call_id, struct rxrpc_wire_header *whdr,

		     enum rxrpc_tx_point where),



	    TP_ARGS(call_id, whdr, where),



	    TP_STRUCT__entry(

		    __field(unsigned int,			call	)

		    __field(enum rxrpc_tx_point,		where	)

		    __field_struct(struct rxrpc_wire_header,	whdr	)

			     ),



	    TP_fast_assign(

		    __entry->call = call_id;

		    memcpy(&__entry->whdr, whdr, sizeof(__entry->whdr));

			   ),



	    TP_printk("c=%08x %08x:%08x:%08x:%04x %08x %08x %02x %02x %s %s",

		      __entry->call,

		      ntohl(__entry->whdr.epoch),

		      ntohl(__entry->whdr.cid),

		      ntohl(__entry->whdr.callNumber),

		      ntohs(__entry->whdr.serviceId),

		      ntohl(__entry->whdr.serial),

		      ntohl(__entry->whdr.seq),

		      __entry->whdr.type, __entry->whdr.flags,

		      __entry->whdr.type <= 15 ?

		      __print_symbolic(__entry->whdr.type, rxrpc_pkts) : "?UNK",

		      __print_symbolic(__entry->where, rxrpc_tx_points))

	    );



TRACE_EVENT(rxrpc_tx_data,

	    TP_PROTO(struct rxrpc_call *call, rxrpc_seq_t seq,

		     rxrpc_serial_t serial, u8 flags, bool retrans, bool lose),
@@ -928,6 +959,8 @@ TRACE_EVENT(rxrpc_tx_data, 
		    __field(unsigned int,		call		)

		    __field(rxrpc_seq_t,		seq		)

		    __field(rxrpc_serial_t,		serial		)

		    __field(u32,			cid		)

		    __field(u32,			call_id		)

		    __field(u8,				flags		)

		    __field(bool,			retrans		)

		    __field(bool,			lose		)
@@ -935,6 +968,8 @@ TRACE_EVENT(rxrpc_tx_data, 


	    TP_fast_assign(

		    __entry->call = call->debug_id;

		    __entry->cid = call->cid;

		    __entry->call_id = call->call_id;

		    __entry->seq = seq;

		    __entry->serial = serial;

		    __entry->flags = flags;
@@ -942,8 +977,10 @@ TRACE_EVENT(rxrpc_tx_data, 
		    __entry->lose = lose;

			   ),



	    TP_printk("c=%08x DATA %08x q=%08x fl=%02x%s%s",

	    TP_printk("c=%08x DATA %08x:%08x %08x q=%08x fl=%02x%s%s",

		      __entry->call,

		      __entry->cid,

		      __entry->call_id,

		      __entry->serial,

		      __entry->seq,

		      __entry->flags,
@@ -952,7 +989,7 @@ TRACE_EVENT(rxrpc_tx_data, 
	    );



TRACE_EVENT(rxrpc_tx_ack,

	    TP_PROTO(struct rxrpc_call *call, rxrpc_serial_t serial,

	    TP_PROTO(unsigned int call, rxrpc_serial_t serial,

		     rxrpc_seq_t ack_first, rxrpc_serial_t ack_serial,

		     u8 reason, u8 n_acks),
@@ -968,7 +1005,7 @@ TRACE_EVENT(rxrpc_tx_ack, 
			     ),



	    TP_fast_assign(

		    __entry->call = call ? call->debug_id : 0;

		    __entry->call = call;

		    __entry->serial = serial;

		    __entry->ack_first = ack_first;

		    __entry->ack_serial = ack_serial;
@@ -1434,29 +1471,29 @@ TRACE_EVENT(rxrpc_rx_icmp, 


TRACE_EVENT(rxrpc_tx_fail,

	    TP_PROTO(unsigned int debug_id, rxrpc_serial_t serial, int ret,

		     enum rxrpc_tx_fail_trace what),

		     enum rxrpc_tx_point where),



	    TP_ARGS(debug_id, serial, ret, what),

	    TP_ARGS(debug_id, serial, ret, where),



	    TP_STRUCT__entry(

		    __field(unsigned int,		debug_id	)

		    __field(rxrpc_serial_t,		serial		)

		    __field(int,			ret		)

		    __field(enum rxrpc_tx_fail_trace,   what		)

		    __field(enum rxrpc_tx_point,	where		)

			     ),



	    TP_fast_assign(

		    __entry->debug_id = debug_id;

		    __entry->serial = serial;

		    __entry->ret = ret;

		    __entry->what = what;

		    __entry->where = where;

			   ),



	    TP_printk("c=%08x r=%x ret=%d %s",

		      __entry->debug_id,

		      __entry->serial,

		      __entry->ret,

		      __print_symbolic(__entry->what, rxrpc_tx_fail_traces))

		      __print_symbolic(__entry->where, rxrpc_tx_points))

	    );



TRACE_EVENT(rxrpc_call_reset,

net/rxrpc/ar-internal.h

+1 −0
Original line number Diff line number Diff line
@@ -420,6 +420,7 @@ struct rxrpc_connection { 
	struct rxrpc_channel {

		unsigned long		final_ack_at;	/* Time at which to issue final ACK */

		struct rxrpc_call __rcu	*call;		/* Active call */

		unsigned int		call_debug_id;	/* call->debug_id */

		u32			call_id;	/* ID of current call */

		u32			call_counter;	/* Call ID counter */

		u32			last_call;	/* ID of last call */

net/rxrpc/conn_client.c

+1 −0
Original line number Diff line number Diff line
@@ -590,6 +590,7 @@ static void rxrpc_activate_one_channel(struct rxrpc_connection *conn, 
	 */

	smp_wmb();

	chan->call_id	= call_id;

	chan->call_debug_id = call->debug_id;

	rcu_assign_pointer(chan->call, call);

	wake_up(&call->waitq);

}

net/rxrpc/conn_event.c

+9 −4
Original line number Diff line number Diff line
@@ -129,7 +129,7 @@ static void rxrpc_conn_retransmit_call(struct rxrpc_connection *conn, 
		_proto("Tx ABORT %%%u { %d } [re]", serial, conn->local_abort);

		break;

	case RXRPC_PACKET_TYPE_ACK:

		trace_rxrpc_tx_ack(NULL, serial,

		trace_rxrpc_tx_ack(chan->call_debug_id, serial,

				   ntohl(pkt.ack.firstPacket),

				   ntohl(pkt.ack.serial),

				   pkt.ack.reason, 0);
@@ -140,8 +140,11 @@ static void rxrpc_conn_retransmit_call(struct rxrpc_connection *conn, 
	ret = kernel_sendmsg(conn->params.local->socket, &msg, iov, ioc, len);

	conn->params.peer->last_tx_at = ktime_get_real();

	if (ret < 0)

		trace_rxrpc_tx_fail(conn->debug_id, serial, ret,

				    rxrpc_tx_fail_call_final_resend);

		trace_rxrpc_tx_fail(chan->call_debug_id, serial, ret,

				    rxrpc_tx_point_call_final_resend);

	else

		trace_rxrpc_tx_packet(chan->call_debug_id, &pkt.whdr,

				      rxrpc_tx_point_call_final_resend);



	_leave("");

}
@@ -242,11 +245,13 @@ static int rxrpc_abort_connection(struct rxrpc_connection *conn, 
	ret = kernel_sendmsg(conn->params.local->socket, &msg, iov, 2, len);

	if (ret < 0) {

		trace_rxrpc_tx_fail(conn->debug_id, serial, ret,

				    rxrpc_tx_fail_conn_abort);

				    rxrpc_tx_point_conn_abort);

		_debug("sendmsg failed: %d", ret);

		return -EAGAIN;

	}



	trace_rxrpc_tx_packet(conn->debug_id, &whdr, rxrpc_tx_point_conn_abort);



	conn->params.peer->last_tx_at = ktime_get_real();



	_leave(" = 0");

net/rxrpc/input.c

+10 −1
Original line number Diff line number Diff line
@@ -496,7 +496,7 @@ next_subpacket: 
			return rxrpc_proto_abort("LSA", call, seq);

	}



	trace_rxrpc_rx_data(call, seq, serial, flags, annotation);

	trace_rxrpc_rx_data(call->debug_id, seq, serial, flags, annotation);

	if (before_eq(seq, hard_ack)) {

		ack = RXRPC_ACK_DUPLICATE;

		ack_serial = serial;
@@ -592,6 +592,10 @@ ack: 
		rxrpc_propose_ACK(call, ack, skew, ack_serial,

				  immediate_ack, true,

				  rxrpc_propose_ack_input_data);

	else

		rxrpc_propose_ACK(call, RXRPC_ACK_DELAY, skew, serial,

				  false, true,

				  rxrpc_propose_ack_input_data);



	if (sp->hdr.seq == READ_ONCE(call->rx_hard_ack) + 1)

		rxrpc_notify_socket(call);
@@ -1262,6 +1266,11 @@ void rxrpc_data_ready(struct sock *udp_sk) 
			/* But otherwise we need to retransmit the final packet

			 * from data cached in the connection record.

			 */

			if (sp->hdr.type == RXRPC_PACKET_TYPE_DATA)

				trace_rxrpc_rx_data(chan->call_debug_id,

						    sp->hdr.seq,

						    sp->hdr.serial,

						    sp->hdr.flags, 0);

			rxrpc_post_packet_to_conn(conn, skb);

			goto out_unlock;

		}

CRA Git | Maintained and supported by SUSTech CRA and CCSE