Commit cb0fc0c9 authored by David Howells's avatar David Howells
Browse files

rxrpc: trace: Don't use __builtin_return_address for rxrpc_call tracing 



In rxrpc tracing, use enums to generate lists of points of interest rather
than __builtin_return_address() for the rxrpc_call tracepoint

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

include/trace/events/rxrpc.h

+49 −34
Original line number Diff line number Diff line
@@ -127,26 +127,44 @@ 
	E_(rxrpc_client_to_idle,		"->Idle")



#define rxrpc_call_traces \

	EM(rxrpc_call_connected,		"CON") \

	EM(rxrpc_call_error,			"*E*") \

	EM(rxrpc_call_got,			"GOT") \

	EM(rxrpc_call_got_kernel,		"Gke") \

	EM(rxrpc_call_got_timer,		"GTM") \

	EM(rxrpc_call_got_tx,			"Gtx") \

	EM(rxrpc_call_got_userid,		"Gus") \

	EM(rxrpc_call_new_client,		"NWc") \

	EM(rxrpc_call_new_service,		"NWs") \

	EM(rxrpc_call_put,			"PUT") \

	EM(rxrpc_call_put_kernel,		"Pke") \

	EM(rxrpc_call_put_noqueue,		"PnQ") \

	EM(rxrpc_call_put_notimer,		"PnT") \

	EM(rxrpc_call_put_timer,		"PTM") \

	EM(rxrpc_call_put_tx,			"Ptx") \

	EM(rxrpc_call_put_userid,		"Pus") \

	EM(rxrpc_call_queued,			"QUE") \

	EM(rxrpc_call_queued_ref,		"QUR") \

	EM(rxrpc_call_release,			"RLS") \

	E_(rxrpc_call_seen,			"SEE")

	EM(rxrpc_call_get_input,		"GET input   ") \

	EM(rxrpc_call_get_kernel_service,	"GET krnl-srv") \

	EM(rxrpc_call_get_notify_socket,	"GET notify  ") \

	EM(rxrpc_call_get_recvmsg,		"GET recvmsg ") \

	EM(rxrpc_call_get_release_sock,		"GET rel-sock") \

	EM(rxrpc_call_get_sendmsg,		"GET sendmsg ") \

	EM(rxrpc_call_get_send_ack,		"GET send-ack") \

	EM(rxrpc_call_get_timer,		"GET timer   ") \

	EM(rxrpc_call_get_userid,		"GET user-id ") \

	EM(rxrpc_call_new_client,		"NEW client  ") \

	EM(rxrpc_call_new_prealloc_service,	"NEW prealloc") \

	EM(rxrpc_call_put_already_queued,	"PUT alreadyq") \

	EM(rxrpc_call_put_discard_prealloc,	"PUT disc-pre") \

	EM(rxrpc_call_put_input,		"PUT input   ") \

	EM(rxrpc_call_put_kernel,		"PUT kernel  ") \

	EM(rxrpc_call_put_recvmsg,		"PUT recvmsg ") \

	EM(rxrpc_call_put_release_sock,		"PUT rls-sock") \

	EM(rxrpc_call_put_release_sock_tba,	"PUT rls-sk-a") \

	EM(rxrpc_call_put_send_ack,		"PUT send-ack") \

	EM(rxrpc_call_put_sendmsg,		"PUT sendmsg ") \

	EM(rxrpc_call_put_timer,		"PUT timer   ") \

	EM(rxrpc_call_put_timer_already,	"PUT timer-al") \

	EM(rxrpc_call_put_unnotify,		"PUT unnotify") \

	EM(rxrpc_call_put_userid_exists,	"PUT u-exists") \

	EM(rxrpc_call_put_work,			"PUT work    ") \

	EM(rxrpc_call_queue_abort,		"QUE abort   ") \

	EM(rxrpc_call_queue_requeue,		"QUE requeue ") \

	EM(rxrpc_call_queue_resend,		"QUE resend  ") \

	EM(rxrpc_call_queue_timer,		"QUE timer   ") \

	EM(rxrpc_call_see_accept,		"SEE accept  ") \

	EM(rxrpc_call_see_activate_client,	"SEE act-clnt") \

	EM(rxrpc_call_see_connect_failed,	"SEE con-fail") \

	EM(rxrpc_call_see_connected,		"SEE connect ") \

	EM(rxrpc_call_see_distribute_error,	"SEE dist-err") \

	EM(rxrpc_call_see_input,		"SEE input   ") \

	EM(rxrpc_call_see_release,		"SEE release ") \

	EM(rxrpc_call_see_userid_exists,	"SEE u-exists") \

	E_(rxrpc_call_see_zap,			"SEE zap     ")



#define rxrpc_txqueue_traces \

	EM(rxrpc_txqueue_await_reply,		"AWR") \
@@ -503,32 +521,29 @@ TRACE_EVENT(rxrpc_client, 
	    );



TRACE_EVENT(rxrpc_call,

	    TP_PROTO(unsigned int call_debug_id, enum rxrpc_call_trace op,

		     int usage, const void *where, const void *aux),

	    TP_PROTO(unsigned int call_debug_id, int ref, unsigned long aux,

		     enum rxrpc_call_trace why),



	    TP_ARGS(call_debug_id, op, usage, where, aux),

	    TP_ARGS(call_debug_id, ref, aux, why),



	    TP_STRUCT__entry(

		    __field(unsigned int,		call		)

		    __field(int,			op		)

		    __field(int,			usage		)

		    __field(const void *,		where		)

		    __field(const void *,		aux		)

		    __field(int,			ref		)

		    __field(int,			why		)

		    __field(unsigned long,		aux		)

			     ),



	    TP_fast_assign(

		    __entry->call = call_debug_id;

		    __entry->op = op;

		    __entry->usage = usage;

		    __entry->where = where;

		    __entry->ref = ref;

		    __entry->why = why;

		    __entry->aux = aux;

			   ),



	    TP_printk("c=%08x %s u=%d sp=%pSR a=%p",

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

		      __entry->call,

		      __print_symbolic(__entry->op, rxrpc_call_traces),

		      __entry->usage,

		      __entry->where,

		      __print_symbolic(__entry->why, rxrpc_call_traces),

		      __entry->ref,

		      __entry->aux)

	    );

net/rxrpc/ar-internal.h

+4 −4
Original line number Diff line number Diff line
@@ -847,10 +847,10 @@ void rxrpc_incoming_call(struct rxrpc_sock *, struct rxrpc_call *, 
			 struct sk_buff *);

void rxrpc_release_call(struct rxrpc_sock *, struct rxrpc_call *);

void rxrpc_release_calls_on_socket(struct rxrpc_sock *);

bool __rxrpc_queue_call(struct rxrpc_call *);

bool rxrpc_queue_call(struct rxrpc_call *);

void rxrpc_see_call(struct rxrpc_call *);

bool rxrpc_try_get_call(struct rxrpc_call *call, enum rxrpc_call_trace op);

bool __rxrpc_queue_call(struct rxrpc_call *, enum rxrpc_call_trace);

bool rxrpc_queue_call(struct rxrpc_call *, enum rxrpc_call_trace);

void rxrpc_see_call(struct rxrpc_call *, enum rxrpc_call_trace);

bool rxrpc_try_get_call(struct rxrpc_call *, enum rxrpc_call_trace);

void rxrpc_get_call(struct rxrpc_call *, enum rxrpc_call_trace);

void rxrpc_put_call(struct rxrpc_call *, enum rxrpc_call_trace);

void rxrpc_cleanup_call(struct rxrpc_call *);

net/rxrpc/call_accept.c

+7 −9
Original line number Diff line number Diff line
@@ -38,7 +38,6 @@ static int rxrpc_service_prealloc_one(struct rxrpc_sock *rx, 
				      unsigned long user_call_ID, gfp_t gfp,

				      unsigned int debug_id)

{

	const void *here = __builtin_return_address(0);

	struct rxrpc_call *call, *xcall;

	struct rxrpc_net *rxnet = rxrpc_net(sock_net(&rx->sk));

	struct rb_node *parent, **pp;
@@ -102,9 +101,8 @@ static int rxrpc_service_prealloc_one(struct rxrpc_sock *rx, 
	call->flags |= (1 << RXRPC_CALL_IS_SERVICE);

	call->state = RXRPC_CALL_SERVER_PREALLOC;



	trace_rxrpc_call(call->debug_id, rxrpc_call_new_service,

			 refcount_read(&call->ref),

			 here, (const void *)user_call_ID);

	trace_rxrpc_call(call->debug_id, refcount_read(&call->ref),

			 user_call_ID, rxrpc_call_new_prealloc_service);



	write_lock(&rx->call_lock);
@@ -125,11 +123,11 @@ static int rxrpc_service_prealloc_one(struct rxrpc_sock *rx, 
	call->user_call_ID = user_call_ID;

	call->notify_rx = notify_rx;

	if (user_attach_call) {

		rxrpc_get_call(call, rxrpc_call_got_kernel);

		rxrpc_get_call(call, rxrpc_call_get_kernel_service);

		user_attach_call(call, user_call_ID);

	}



	rxrpc_get_call(call, rxrpc_call_got_userid);

	rxrpc_get_call(call, rxrpc_call_get_userid);

	rb_link_node(&call->sock_node, parent, pp);

	rb_insert_color(&call->sock_node, &rx->calls);

	set_bit(RXRPC_CALL_HAS_USERID, &call->flags);
@@ -229,7 +227,7 @@ void rxrpc_discard_prealloc(struct rxrpc_sock *rx) 
		}

		rxrpc_call_completed(call);

		rxrpc_release_call(rx, call);

		rxrpc_put_call(call, rxrpc_call_put);

		rxrpc_put_call(call, rxrpc_call_put_discard_prealloc);

		tail = (tail + 1) & (size - 1);

	}
@@ -318,7 +316,7 @@ static struct rxrpc_call *rxrpc_alloc_incoming_call(struct rxrpc_sock *rx, 
	smp_store_release(&b->call_backlog_tail,

			  (call_tail + 1) & (RXRPC_BACKLOG_MAX - 1));



	rxrpc_see_call(call);

	rxrpc_see_call(call, rxrpc_call_see_accept);

	call->conn = conn;

	call->security = conn->security;

	call->security_ix = conn->security_ix;
@@ -430,7 +428,7 @@ struct rxrpc_call *rxrpc_new_incoming_call(struct rxrpc_local *local, 
	 * (recvmsg queue, to-be-accepted queue or user ID tree) or the kernel

	 * service to prevent the call from being deallocated too early.

	 */

	rxrpc_put_call(call, rxrpc_call_put);

	rxrpc_put_call(call, rxrpc_call_put_discard_prealloc);



	_leave(" = %p{%d}", call, call->debug_id);

	return call;

net/rxrpc/call_event.c

+4 −4
Original line number Diff line number Diff line
@@ -101,7 +101,7 @@ void rxrpc_send_ACK(struct rxrpc_call *call, u8 ack_reason, 
	txb->ack.reason		= ack_reason;

	txb->ack.nAcks		= 0;



	if (!rxrpc_try_get_call(call, rxrpc_call_got)) {

	if (!rxrpc_try_get_call(call, rxrpc_call_get_send_ack)) {

		rxrpc_put_txbuf(txb, rxrpc_txbuf_put_nomem);

		return;

	}
@@ -302,7 +302,7 @@ void rxrpc_process_call(struct work_struct *work) 
	unsigned int iterations = 0;

	rxrpc_serial_t ackr_serial;



	rxrpc_see_call(call);

	rxrpc_see_call(call, rxrpc_call_see_input);



	//printk("\n--------------------\n");

	_enter("{%d,%s,%lx}",
@@ -436,12 +436,12 @@ void rxrpc_process_call(struct work_struct *work) 
		goto requeue;



out_put:

	rxrpc_put_call(call, rxrpc_call_put);

	rxrpc_put_call(call, rxrpc_call_put_work);

out:

	_leave("");

	return;



requeue:

	__rxrpc_queue_call(call);

	__rxrpc_queue_call(call, rxrpc_call_queue_requeue);

	goto out;

}

net/rxrpc/call_object.c

+44 −58
Original line number Diff line number Diff line
@@ -53,9 +53,9 @@ static void rxrpc_call_timer_expired(struct timer_list *t) 


	if (call->state < RXRPC_CALL_COMPLETE) {

		trace_rxrpc_timer_expired(call, jiffies);

		__rxrpc_queue_call(call);

		__rxrpc_queue_call(call, rxrpc_call_queue_timer);

	} else {

		rxrpc_put_call(call, rxrpc_call_put);

		rxrpc_put_call(call, rxrpc_call_put_already_queued);

	}

}
@@ -64,10 +64,10 @@ void rxrpc_reduce_call_timer(struct rxrpc_call *call, 
			     unsigned long now,

			     enum rxrpc_timer_trace why)

{

	if (rxrpc_try_get_call(call, rxrpc_call_got_timer)) {

	if (rxrpc_try_get_call(call, rxrpc_call_get_timer)) {

		trace_rxrpc_timer(call, why, now);

		if (timer_reduce(&call->timer, expire_at))

			rxrpc_put_call(call, rxrpc_call_put_notimer);

			rxrpc_put_call(call, rxrpc_call_put_timer_already);

	}

}
@@ -110,7 +110,7 @@ struct rxrpc_call *rxrpc_find_call_by_user_ID(struct rxrpc_sock *rx, 
	return NULL;



found_extant_call:

	rxrpc_get_call(call, rxrpc_call_got);

	rxrpc_get_call(call, rxrpc_call_get_sendmsg);

	read_unlock(&rx->call_lock);

	_leave(" = %p [%d]", call, refcount_read(&call->ref));

	return call;
@@ -270,7 +270,6 @@ struct rxrpc_call *rxrpc_new_client_call(struct rxrpc_sock *rx, 
	struct rxrpc_net *rxnet;

	struct semaphore *limiter;

	struct rb_node *parent, **pp;

	const void *here = __builtin_return_address(0);

	int ret;



	_enter("%p,%lx", rx, p->user_call_ID);
@@ -291,9 +290,8 @@ struct rxrpc_call *rxrpc_new_client_call(struct rxrpc_sock *rx, 


	call->interruptibility = p->interruptibility;

	call->tx_total_len = p->tx_total_len;

	trace_rxrpc_call(call->debug_id, rxrpc_call_new_client,

			 refcount_read(&call->ref),

			 here, (const void *)p->user_call_ID);

	trace_rxrpc_call(call->debug_id, refcount_read(&call->ref),

			 p->user_call_ID, rxrpc_call_new_client);

	if (p->kernel)

		__set_bit(RXRPC_CALL_KERNEL, &call->flags);
@@ -322,7 +320,7 @@ struct rxrpc_call *rxrpc_new_client_call(struct rxrpc_sock *rx, 
	rcu_assign_pointer(call->socket, rx);

	call->user_call_ID = p->user_call_ID;

	__set_bit(RXRPC_CALL_HAS_USERID, &call->flags);

	rxrpc_get_call(call, rxrpc_call_got_userid);

	rxrpc_get_call(call, rxrpc_call_get_userid);

	rb_link_node(&call->sock_node, parent, pp);

	rb_insert_color(&call->sock_node, &rx->calls);

	list_add(&call->sock_link, &rx->sock_calls);
@@ -344,8 +342,7 @@ struct rxrpc_call *rxrpc_new_client_call(struct rxrpc_sock *rx, 
	if (ret < 0)

		goto error_attached_to_socket;



	trace_rxrpc_call(call->debug_id, rxrpc_call_connected,

			 refcount_read(&call->ref), here, NULL);

	rxrpc_see_call(call, rxrpc_call_see_connected);



	rxrpc_start_call_timer(call);
@@ -362,11 +359,11 @@ struct rxrpc_call *rxrpc_new_client_call(struct rxrpc_sock *rx, 
	release_sock(&rx->sk);

	__rxrpc_set_call_completion(call, RXRPC_CALL_LOCAL_ERROR,

				    RX_CALL_DEAD, -EEXIST);

	trace_rxrpc_call(call->debug_id, rxrpc_call_error,

			 refcount_read(&call->ref), here, ERR_PTR(-EEXIST));

	trace_rxrpc_call(call->debug_id, refcount_read(&call->ref), 0,

			 rxrpc_call_see_userid_exists);

	rxrpc_release_call(rx, call);

	mutex_unlock(&call->user_mutex);

	rxrpc_put_call(call, rxrpc_call_put);

	rxrpc_put_call(call, rxrpc_call_put_userid_exists);

	_leave(" = -EEXIST");

	return ERR_PTR(-EEXIST);
@@ -376,8 +373,8 @@ struct rxrpc_call *rxrpc_new_client_call(struct rxrpc_sock *rx, 
	 * leave the error to recvmsg() to deal with.

	 */

error_attached_to_socket:

	trace_rxrpc_call(call->debug_id, rxrpc_call_error,

			 refcount_read(&call->ref), here, ERR_PTR(ret));

	trace_rxrpc_call(call->debug_id, refcount_read(&call->ref), ret,

			 rxrpc_call_see_connect_failed);

	set_bit(RXRPC_CALL_DISCONNECTED, &call->flags);

	__rxrpc_set_call_completion(call, RXRPC_CALL_LOCAL_ERROR,

				    RX_CALL_DEAD, ret);
@@ -428,72 +425,65 @@ void rxrpc_incoming_call(struct rxrpc_sock *rx, 
/*

 * Queue a call's work processor, getting a ref to pass to the work queue.

 */

bool rxrpc_queue_call(struct rxrpc_call *call)

bool rxrpc_queue_call(struct rxrpc_call *call, enum rxrpc_call_trace why)

{

	const void *here = __builtin_return_address(0);

	int n;



	if (!__refcount_inc_not_zero(&call->ref, &n))

		return false;

	if (rxrpc_queue_work(&call->processor))

		trace_rxrpc_call(call->debug_id, rxrpc_call_queued, n + 1,

				 here, NULL);

		trace_rxrpc_call(call->debug_id, n + 1, 0, why);

	else

		rxrpc_put_call(call, rxrpc_call_put_noqueue);

		rxrpc_put_call(call, rxrpc_call_put_already_queued);

	return true;

}



/*

 * Queue a call's work processor, passing the callers ref to the work queue.

 */

bool __rxrpc_queue_call(struct rxrpc_call *call)

bool __rxrpc_queue_call(struct rxrpc_call *call, enum rxrpc_call_trace why)

{

	const void *here = __builtin_return_address(0);

	int n = refcount_read(&call->ref);



	ASSERTCMP(n, >=, 1);

	if (rxrpc_queue_work(&call->processor))

		trace_rxrpc_call(call->debug_id, rxrpc_call_queued_ref, n,

				 here, NULL);

		trace_rxrpc_call(call->debug_id, n, 0, why);

	else

		rxrpc_put_call(call, rxrpc_call_put_noqueue);

		rxrpc_put_call(call, rxrpc_call_put_already_queued);

	return true;

}



/*

 * Note the re-emergence of a call.

 */

void rxrpc_see_call(struct rxrpc_call *call)

void rxrpc_see_call(struct rxrpc_call *call, enum rxrpc_call_trace why)

{

	const void *here = __builtin_return_address(0);

	if (call) {

		int n = refcount_read(&call->ref);

		int r = refcount_read(&call->ref);



		trace_rxrpc_call(call->debug_id, rxrpc_call_seen, n,

				 here, NULL);

		trace_rxrpc_call(call->debug_id, r, 0, why);

	}

}



bool rxrpc_try_get_call(struct rxrpc_call *call, enum rxrpc_call_trace op)

bool rxrpc_try_get_call(struct rxrpc_call *call, enum rxrpc_call_trace why)

{

	const void *here = __builtin_return_address(0);

	int n;

	int r;



	if (!__refcount_inc_not_zero(&call->ref, &n))

	if (!__refcount_inc_not_zero(&call->ref, &r))

		return false;

	trace_rxrpc_call(call->debug_id, op, n + 1, here, NULL);

	trace_rxrpc_call(call->debug_id, r + 1, 0, why);

	return true;

}



/*

 * Note the addition of a ref on a call.

 */

void rxrpc_get_call(struct rxrpc_call *call, enum rxrpc_call_trace op)

void rxrpc_get_call(struct rxrpc_call *call, enum rxrpc_call_trace why)

{

	const void *here = __builtin_return_address(0);

	int n;

	int r;



	__refcount_inc(&call->ref, &n);

	trace_rxrpc_call(call->debug_id, op, n + 1, here, NULL);

	__refcount_inc(&call->ref, &r);

	trace_rxrpc_call(call->debug_id, r + 1, 0, why);

}



/*
@@ -510,15 +500,13 @@ static void rxrpc_cleanup_ring(struct rxrpc_call *call) 
 */

void rxrpc_release_call(struct rxrpc_sock *rx, struct rxrpc_call *call)

{

	const void *here = __builtin_return_address(0);

	struct rxrpc_connection *conn = call->conn;

	bool put = false;



	_enter("{%d,%d}", call->debug_id, refcount_read(&call->ref));



	trace_rxrpc_call(call->debug_id, rxrpc_call_release,

			 refcount_read(&call->ref),

			 here, (const void *)call->flags);

	trace_rxrpc_call(call->debug_id, refcount_read(&call->ref),

			 call->flags, rxrpc_call_see_release);



	ASSERTCMP(call->state, ==, RXRPC_CALL_COMPLETE);
@@ -544,14 +532,14 @@ void rxrpc_release_call(struct rxrpc_sock *rx, struct rxrpc_call *call) 


	write_unlock_bh(&rx->recvmsg_lock);

	if (put)

		rxrpc_put_call(call, rxrpc_call_put);

		rxrpc_put_call(call, rxrpc_call_put_unnotify);



	write_lock(&rx->call_lock);



	if (test_and_clear_bit(RXRPC_CALL_HAS_USERID, &call->flags)) {

		rb_erase(&call->sock_node, &rx->calls);

		memset(&call->sock_node, 0xdd, sizeof(call->sock_node));

		rxrpc_put_call(call, rxrpc_call_put_userid);

		rxrpc_put_call(call, rxrpc_call_put_userid_exists);

	}



	list_del(&call->sock_link);
@@ -580,17 +568,17 @@ void rxrpc_release_calls_on_socket(struct rxrpc_sock *rx) 
				  struct rxrpc_call, accept_link);

		list_del(&call->accept_link);

		rxrpc_abort_call("SKR", call, 0, RX_CALL_DEAD, -ECONNRESET);

		rxrpc_put_call(call, rxrpc_call_put);

		rxrpc_put_call(call, rxrpc_call_put_release_sock_tba);

	}



	while (!list_empty(&rx->sock_calls)) {

		call = list_entry(rx->sock_calls.next,

				  struct rxrpc_call, sock_link);

		rxrpc_get_call(call, rxrpc_call_got);

		rxrpc_get_call(call, rxrpc_call_get_release_sock);

		rxrpc_abort_call("SKT", call, 0, RX_CALL_DEAD, -ECONNRESET);

		rxrpc_send_abort_packet(call);

		rxrpc_release_call(rx, call);

		rxrpc_put_call(call, rxrpc_call_put);

		rxrpc_put_call(call, rxrpc_call_put_release_sock);

	}



	_leave("");
@@ -599,20 +587,18 @@ void rxrpc_release_calls_on_socket(struct rxrpc_sock *rx) 
/*

 * release a call

 */

void rxrpc_put_call(struct rxrpc_call *call, enum rxrpc_call_trace op)

void rxrpc_put_call(struct rxrpc_call *call, enum rxrpc_call_trace why)

{

	struct rxrpc_net *rxnet = call->rxnet;

	const void *here = __builtin_return_address(0);

	unsigned int debug_id = call->debug_id;

	bool dead;

	int n;

	int r;



	ASSERT(call != NULL);



	dead = __refcount_dec_and_test(&call->ref, &n);

	trace_rxrpc_call(debug_id, op, n, here, NULL);

	dead = __refcount_dec_and_test(&call->ref, &r);

	trace_rxrpc_call(debug_id, r - 1, 0, why);

	if (dead) {

		_debug("call %d dead", call->debug_id);

		ASSERTCMP(call->state, ==, RXRPC_CALL_COMPLETE);



		if (!list_empty(&call->link)) {
@@ -701,7 +687,7 @@ void rxrpc_destroy_all_calls(struct rxrpc_net *rxnet) 
					  struct rxrpc_call, link);

			_debug("Zapping call %p", call);



			rxrpc_see_call(call);

			rxrpc_see_call(call, rxrpc_call_see_zap);

			list_del_init(&call->link);



			pr_err("Call %p still in use (%d,%s,%lx,%lx)!\n",