Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

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

rxrpc: Fix call timeouts 



Fix the rxrpc call expiration timeouts and make them settable from
userspace.  By analogy with other rx implementations, there should be three
timeouts:

 (1) "Normal timeout"

     This is set for all calls and is triggered if we haven't received any
     packets from the peer in a while.  It is measured from the last time
     we received any packet on that call.  This is not reset by any
     connection packets (such as CHALLENGE/RESPONSE packets).

     If a service operation takes a long time, the server should generate
     PING ACKs at a duration that's substantially less than the normal
     timeout so is to keep both sides alive.  This is set at 1/6 of normal
     timeout.

 (2) "Idle timeout"

     This is set only for a service call and is triggered if we stop
     receiving the DATA packets that comprise the request data.  It is
     measured from the last time we received a DATA packet.

 (3) "Hard timeout"

     This can be set for a call and specified the maximum lifetime of that
     call.  It should not be specified by default.  Some operations (such
     as volume transfer) take a long time.

Allow userspace to set/change the timeouts on a call with sendmsg, using a
control message:

	RXRPC_SET_CALL_TIMEOUTS

The data to the message is a number of 32-bit words, not all of which need
be given:

	u32 hard_timeout;	/* sec from first packet */
	u32 idle_timeout;	/* msec from packet Rx */
	u32 normal_timeout;	/* msec from data Rx */

This can be set in combination with any other sendmsg() that affects a
call.

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

include/trace/events/rxrpc.h

+47 −22
Original line number Diff line number Diff line
@@ -138,10 +138,20 @@ enum rxrpc_rtt_rx_trace { 


enum rxrpc_timer_trace {

	rxrpc_timer_begin,

	rxrpc_timer_exp_ack,

	rxrpc_timer_exp_hard,

	rxrpc_timer_exp_idle,

	rxrpc_timer_exp_normal,

	rxrpc_timer_exp_ping,

	rxrpc_timer_exp_resend,

	rxrpc_timer_expired,

	rxrpc_timer_init_for_reply,

	rxrpc_timer_init_for_send_reply,

	rxrpc_timer_restart,

	rxrpc_timer_set_for_ack,

	rxrpc_timer_set_for_hard,

	rxrpc_timer_set_for_idle,

	rxrpc_timer_set_for_normal,

	rxrpc_timer_set_for_ping,

	rxrpc_timer_set_for_resend,

	rxrpc_timer_set_for_send,
@@ -296,12 +306,22 @@ enum rxrpc_congest_change { 
#define rxrpc_timer_traces \

	EM(rxrpc_timer_begin,			"Begin ") \

	EM(rxrpc_timer_expired,			"*EXPR*") \

	EM(rxrpc_timer_exp_ack,			"ExpAck") \

	EM(rxrpc_timer_exp_hard,		"ExpHrd") \

	EM(rxrpc_timer_exp_idle,		"ExpIdl") \

	EM(rxrpc_timer_exp_normal,		"ExpNml") \

	EM(rxrpc_timer_exp_ping,		"ExpPng") \

	EM(rxrpc_timer_exp_resend,		"ExpRsn") \

	EM(rxrpc_timer_init_for_reply,		"IniRpl") \

	EM(rxrpc_timer_init_for_send_reply,	"SndRpl") \

	EM(rxrpc_timer_restart,			"Restrt") \

	EM(rxrpc_timer_set_for_ack,		"SetAck") \

	EM(rxrpc_timer_set_for_hard,		"SetHrd") \

	EM(rxrpc_timer_set_for_idle,		"SetIdl") \

	EM(rxrpc_timer_set_for_normal,		"SetNml") \

	EM(rxrpc_timer_set_for_ping,		"SetPng") \

	EM(rxrpc_timer_set_for_resend,		"SetRTx") \

	E_(rxrpc_timer_set_for_send,		"SetTx ")

	E_(rxrpc_timer_set_for_send,		"SetSnd")



#define rxrpc_propose_ack_traces \

	EM(rxrpc_propose_ack_client_tx_end,	"ClTxEnd") \
@@ -932,39 +952,44 @@ TRACE_EVENT(rxrpc_rtt_rx, 


TRACE_EVENT(rxrpc_timer,

	    TP_PROTO(struct rxrpc_call *call, enum rxrpc_timer_trace why,

		     ktime_t now, unsigned long now_j),

		     unsigned long now),



	    TP_ARGS(call, why, now, now_j),

	    TP_ARGS(call, why, now),



	    TP_STRUCT__entry(

		    __field(struct rxrpc_call *,		call		)

		    __field(enum rxrpc_timer_trace,		why		)

		    __field_struct(ktime_t,			now		)

		    __field_struct(ktime_t,			expire_at	)

		    __field_struct(ktime_t,			ack_at		)

		    __field_struct(ktime_t,			resend_at	)

		    __field(unsigned long,			now_j		)

		    __field(unsigned long,			timer		)

		    __field(long,				now		)

		    __field(long,				ack_at		)

		    __field(long,				resend_at	)

		    __field(long,				ping_at		)

		    __field(long,				expect_rx_by	)

		    __field(long,				expect_req_by	)

		    __field(long,				expect_term_by	)

		    __field(long,				timer		)

			     ),



	    TP_fast_assign(

		    __entry->call		= call;

		    __entry->why		= why;

		    __entry->now		= now;

		    __entry->expire_at	= call->expire_at;

		    __entry->ack_at		= call->ack_at;

		    __entry->resend_at		= call->resend_at;

		    __entry->now_j	= now_j;

		    __entry->expect_rx_by	= call->expect_rx_by;

		    __entry->expect_req_by	= call->expect_req_by;

		    __entry->expect_term_by	= call->expect_term_by;

		    __entry->timer		= call->timer.expires;

			   ),



	    TP_printk("c=%p %s x=%lld a=%lld r=%lld t=%ld",

	    TP_printk("c=%p %s a=%ld r=%ld xr=%ld xq=%ld xt=%ld t=%ld",

		      __entry->call,

		      __print_symbolic(__entry->why, rxrpc_timer_traces),

		      ktime_to_ns(ktime_sub(__entry->expire_at, __entry->now)),

		      ktime_to_ns(ktime_sub(__entry->ack_at, __entry->now)),

		      ktime_to_ns(ktime_sub(__entry->resend_at, __entry->now)),

		      __entry->timer - __entry->now_j)

		      __entry->ack_at - __entry->now,

		      __entry->resend_at - __entry->now,

		      __entry->expect_rx_by - __entry->now,

		      __entry->expect_req_by - __entry->now,

		      __entry->expect_term_by - __entry->now,

		      __entry->timer - __entry->now)

	    );



TRACE_EVENT(rxrpc_rx_lose,

include/uapi/linux/rxrpc.h

+1 −0
Original line number Diff line number Diff line
@@ -59,6 +59,7 @@ enum rxrpc_cmsg_type { 
	RXRPC_EXCLUSIVE_CALL	= 10,	/* s-: Call should be on exclusive connection */

	RXRPC_UPGRADE_SERVICE	= 11,	/* s-: Request service upgrade for client call */

	RXRPC_TX_LENGTH		= 12,	/* s-: Total length of Tx data */

	RXRPC_SET_CALL_TIMEOUT	= 13,	/* s-: Set one or more call timeouts */

	RXRPC__SUPPORTED

};

net/rxrpc/ar-internal.h

+24 −13
Original line number Diff line number Diff line
@@ -468,9 +468,9 @@ enum rxrpc_call_flag { 
enum rxrpc_call_event {

	RXRPC_CALL_EV_ACK,		/* need to generate ACK */

	RXRPC_CALL_EV_ABORT,		/* need to generate abort */

	RXRPC_CALL_EV_TIMER,		/* Timer expired */

	RXRPC_CALL_EV_RESEND,		/* Tx resend required */

	RXRPC_CALL_EV_PING,		/* Ping send required */

	RXRPC_CALL_EV_EXPIRED,		/* Expiry occurred */

};



/*
@@ -514,10 +514,14 @@ struct rxrpc_call { 
	struct rxrpc_peer	*peer;		/* Peer record for remote address */

	struct rxrpc_sock __rcu	*socket;	/* socket responsible */

	struct mutex		user_mutex;	/* User access mutex */

	ktime_t			ack_at;		/* When deferred ACK needs to happen */

	ktime_t			resend_at;	/* When next resend needs to happen */

	ktime_t			ping_at;	/* When next to send a ping */

	ktime_t			expire_at;	/* When the call times out */

	unsigned long		ack_at;		/* When deferred ACK needs to happen */

	unsigned long		resend_at;	/* When next resend needs to happen */

	unsigned long		ping_at;	/* When next to send a ping */

	unsigned long		expect_rx_by;	/* When we expect to get a packet by */

	unsigned long		expect_req_by;	/* When we expect to get a request DATA packet by */

	unsigned long		expect_term_by;	/* When we expect call termination by */

	u32			next_rx_timo;	/* Timeout for next Rx packet (jif) */

	u32			next_req_timo;	/* Timeout for next Rx request packet (jif) */

	struct timer_list	timer;		/* Combined event timer */

	struct work_struct	processor;	/* Event processor */

	rxrpc_notify_rx_t	notify_rx;	/* kernel service Rx notification function */
@@ -697,12 +701,19 @@ int rxrpc_reject_call(struct rxrpc_sock *); 
/*

 * call_event.c

 */

void __rxrpc_set_timer(struct rxrpc_call *, enum rxrpc_timer_trace, ktime_t);

void rxrpc_set_timer(struct rxrpc_call *, enum rxrpc_timer_trace, ktime_t);

void rxrpc_propose_ACK(struct rxrpc_call *, u8, u16, u32, bool, bool,

		       enum rxrpc_propose_ack_trace);

void rxrpc_process_call(struct work_struct *);



static inline void rxrpc_reduce_call_timer(struct rxrpc_call *call,

					   unsigned long expire_at,

					   unsigned long now,

					   enum rxrpc_timer_trace why)

{

	trace_rxrpc_timer(call, why, now);

	timer_reduce(&call->timer, expire_at);

}



/*

 * call_object.c

 */
@@ -843,8 +854,8 @@ static inline bool __rxrpc_abort_eproto(struct rxrpc_call *call, 
 */

extern unsigned int rxrpc_max_client_connections;

extern unsigned int rxrpc_reap_client_connections;

extern unsigned int rxrpc_conn_idle_client_expiry;

extern unsigned int rxrpc_conn_idle_client_fast_expiry;

extern unsigned long rxrpc_conn_idle_client_expiry;

extern unsigned long rxrpc_conn_idle_client_fast_expiry;

extern struct idr rxrpc_client_conn_ids;



void rxrpc_destroy_client_conn_ids(void);
@@ -976,13 +987,13 @@ static inline void rxrpc_queue_local(struct rxrpc_local *local) 
 * misc.c

 */

extern unsigned int rxrpc_max_backlog __read_mostly;

extern unsigned int rxrpc_requested_ack_delay;

extern unsigned int rxrpc_soft_ack_delay;

extern unsigned int rxrpc_idle_ack_delay;

extern unsigned long rxrpc_requested_ack_delay;

extern unsigned long rxrpc_soft_ack_delay;

extern unsigned long rxrpc_idle_ack_delay;

extern unsigned int rxrpc_rx_window_size;

extern unsigned int rxrpc_rx_mtu;

extern unsigned int rxrpc_rx_jumbo_max;

extern unsigned int rxrpc_resend_timeout;

extern unsigned long rxrpc_resend_timeout;



extern const s8 rxrpc_ack_priority[];

net/rxrpc/call_event.c

+84 −95
Original line number Diff line number Diff line
@@ -21,80 +21,6 @@ 
#include <net/af_rxrpc.h>

#include "ar-internal.h"



/*

 * Set the timer

 */

void __rxrpc_set_timer(struct rxrpc_call *call, enum rxrpc_timer_trace why,

		       ktime_t now)

{

	unsigned long t_j, now_j = jiffies;

	ktime_t t;

	bool queue = false;



	if (call->state < RXRPC_CALL_COMPLETE) {

		t = call->expire_at;

		if (!ktime_after(t, now)) {

			trace_rxrpc_timer(call, why, now, now_j);

			queue = true;

			goto out;

		}



		if (!ktime_after(call->resend_at, now)) {

			call->resend_at = call->expire_at;

			if (!test_and_set_bit(RXRPC_CALL_EV_RESEND, &call->events))

				queue = true;

		} else if (ktime_before(call->resend_at, t)) {

			t = call->resend_at;

		}



		if (!ktime_after(call->ack_at, now)) {

			call->ack_at = call->expire_at;

			if (!test_and_set_bit(RXRPC_CALL_EV_ACK, &call->events))

				queue = true;

		} else if (ktime_before(call->ack_at, t)) {

			t = call->ack_at;

		}



		if (!ktime_after(call->ping_at, now)) {

			call->ping_at = call->expire_at;

			if (!test_and_set_bit(RXRPC_CALL_EV_PING, &call->events))

				queue = true;

		} else if (ktime_before(call->ping_at, t)) {

			t = call->ping_at;

		}



		t_j = nsecs_to_jiffies(ktime_to_ns(ktime_sub(t, now)));

		t_j += jiffies;



		/* We have to make sure that the calculated jiffies value falls

		 * at or after the nsec value, or we may loop ceaselessly

		 * because the timer times out, but we haven't reached the nsec

		 * timeout yet.

		 */

		t_j++;



		if (call->timer.expires != t_j || !timer_pending(&call->timer)) {

			mod_timer(&call->timer, t_j);

			trace_rxrpc_timer(call, why, now, now_j);

		}

	}



out:

	if (queue)

		rxrpc_queue_call(call);

}



/*

 * Set the timer

 */

void rxrpc_set_timer(struct rxrpc_call *call, enum rxrpc_timer_trace why,

		     ktime_t now)

{

	read_lock_bh(&call->state_lock);

	__rxrpc_set_timer(call, why, now);

	read_unlock_bh(&call->state_lock);

}



/*

 * Propose a PING ACK be sent.

 */
@@ -106,12 +32,13 @@ static void rxrpc_propose_ping(struct rxrpc_call *call, 
		    !test_and_set_bit(RXRPC_CALL_EV_PING, &call->events))

			rxrpc_queue_call(call);

	} else {

		ktime_t now = ktime_get_real();

		ktime_t ping_at = ktime_add_ms(now, rxrpc_idle_ack_delay);

		unsigned long now = jiffies;

		unsigned long ping_at = now + rxrpc_idle_ack_delay;



		if (ktime_before(ping_at, call->ping_at)) {

			call->ping_at = ping_at;

			rxrpc_set_timer(call, rxrpc_timer_set_for_ping, now);

		if (time_before(ping_at, call->ping_at)) {

			WRITE_ONCE(call->ping_at, ping_at);

			rxrpc_reduce_call_timer(call, ping_at, now,

						rxrpc_timer_set_for_ping);

		}

	}

}
@@ -125,8 +52,7 @@ static void __rxrpc_propose_ACK(struct rxrpc_call *call, u8 ack_reason, 
				enum rxrpc_propose_ack_trace why)

{

	enum rxrpc_propose_ack_outcome outcome = rxrpc_propose_ack_use;

	unsigned int expiry = rxrpc_soft_ack_delay;

	ktime_t now, ack_at;

	unsigned long now, ack_at, expiry = rxrpc_soft_ack_delay;

	s8 prior = rxrpc_ack_priority[ack_reason];



	/* Pings are handled specially because we don't want to accidentally
@@ -190,11 +116,12 @@ static void __rxrpc_propose_ACK(struct rxrpc_call *call, u8 ack_reason, 
		    background)

			rxrpc_queue_call(call);

	} else {

		now = ktime_get_real();

		ack_at = ktime_add_ms(now, expiry);

		if (ktime_before(ack_at, call->ack_at)) {

			call->ack_at = ack_at;

			rxrpc_set_timer(call, rxrpc_timer_set_for_ack, now);

		now = jiffies;

		ack_at = jiffies + expiry;

		if (time_before(ack_at, call->ack_at)) {

			WRITE_ONCE(call->ack_at, ack_at);

			rxrpc_reduce_call_timer(call, ack_at, now,

						rxrpc_timer_set_for_ack);

		}

	}
@@ -227,18 +154,20 @@ static void rxrpc_congestion_timeout(struct rxrpc_call *call) 
/*

 * Perform retransmission of NAK'd and unack'd packets.

 */

static void rxrpc_resend(struct rxrpc_call *call, ktime_t now)

static void rxrpc_resend(struct rxrpc_call *call, unsigned long now_j)

{

	struct rxrpc_skb_priv *sp;

	struct sk_buff *skb;

	unsigned long resend_at;

	rxrpc_seq_t cursor, seq, top;

	ktime_t max_age, oldest, ack_ts;

	ktime_t now, max_age, oldest, ack_ts;

	int ix;

	u8 annotation, anno_type, retrans = 0, unacked = 0;



	_enter("{%d,%d}", call->tx_hard_ack, call->tx_top);



	max_age = ktime_sub_ms(now, rxrpc_resend_timeout);

	now = ktime_get_real();

	max_age = ktime_sub_ms(now, rxrpc_resend_timeout * 1000 / HZ);



	spin_lock_bh(&call->lock);
@@ -282,7 +211,9 @@ static void rxrpc_resend(struct rxrpc_call *call, ktime_t now) 
				       ktime_to_ns(ktime_sub(skb->tstamp, max_age)));

	}



	call->resend_at = ktime_add_ms(oldest, rxrpc_resend_timeout);

	resend_at = nsecs_to_jiffies(ktime_to_ns(ktime_sub(oldest, now)));

	resend_at += jiffies + rxrpc_resend_timeout;

	WRITE_ONCE(call->resend_at, resend_at);



	if (unacked)

		rxrpc_congestion_timeout(call);
@@ -292,7 +223,8 @@ static void rxrpc_resend(struct rxrpc_call *call, ktime_t now) 
	 * retransmitting data.

	 */

	if (!retrans) {

		rxrpc_set_timer(call, rxrpc_timer_set_for_resend, now);

		rxrpc_reduce_call_timer(call, resend_at, now,

					rxrpc_timer_set_for_resend);

		spin_unlock_bh(&call->lock);

		ack_ts = ktime_sub(now, call->acks_latest_ts);

		if (ktime_to_ns(ack_ts) < call->peer->rtt)
@@ -364,7 +296,7 @@ void rxrpc_process_call(struct work_struct *work) 
{

	struct rxrpc_call *call =

		container_of(work, struct rxrpc_call, processor);

	ktime_t now;

	unsigned long now, next, t;



	rxrpc_see_call(call);
@@ -384,8 +316,50 @@ void rxrpc_process_call(struct work_struct *work) 
		goto out_put;

	}



	now = ktime_get_real();

	if (ktime_before(call->expire_at, now)) {

	/* Work out if any timeouts tripped */

	now = jiffies;

	t = READ_ONCE(call->expect_rx_by);

	if (time_after_eq(now, t)) {

		trace_rxrpc_timer(call, rxrpc_timer_exp_normal, now);

		set_bit(RXRPC_CALL_EV_EXPIRED, &call->events);

	}



	t = READ_ONCE(call->expect_req_by);

	if (call->state == RXRPC_CALL_SERVER_RECV_REQUEST &&

	    time_after_eq(now, t)) {

		trace_rxrpc_timer(call, rxrpc_timer_exp_idle, now);

		set_bit(RXRPC_CALL_EV_EXPIRED, &call->events);

	}



	t = READ_ONCE(call->expect_term_by);

	if (time_after_eq(now, t)) {

		trace_rxrpc_timer(call, rxrpc_timer_exp_hard, now);

		set_bit(RXRPC_CALL_EV_EXPIRED, &call->events);

	}



	t = READ_ONCE(call->ack_at);

	if (time_after_eq(now, t)) {

		trace_rxrpc_timer(call, rxrpc_timer_exp_ack, now);

		cmpxchg(&call->ack_at, t, now + MAX_JIFFY_OFFSET);

		set_bit(RXRPC_CALL_EV_ACK, &call->events);

	}



	t = READ_ONCE(call->ping_at);

	if (time_after_eq(now, t)) {

		trace_rxrpc_timer(call, rxrpc_timer_exp_ping, now);

		cmpxchg(&call->ping_at, t, now + MAX_JIFFY_OFFSET);

		set_bit(RXRPC_CALL_EV_PING, &call->events);

	}



	t = READ_ONCE(call->resend_at);

	if (time_after_eq(now, t)) {

		trace_rxrpc_timer(call, rxrpc_timer_exp_resend, now);

		cmpxchg(&call->resend_at, t, now + MAX_JIFFY_OFFSET);

		set_bit(RXRPC_CALL_EV_RESEND, &call->events);

	}



	/* Process events */

	if (test_and_clear_bit(RXRPC_CALL_EV_EXPIRED, &call->events)) {

		rxrpc_abort_call("EXP", call, 0, RX_USER_ABORT, -ETIME);

		set_bit(RXRPC_CALL_EV_ABORT, &call->events);

		goto recheck_state;
@@ -408,7 +382,22 @@ void rxrpc_process_call(struct work_struct *work) 
		goto recheck_state;

	}



	rxrpc_set_timer(call, rxrpc_timer_set_for_resend, now);

	/* Make sure the timer is restarted */

	next = call->expect_rx_by;



#define set(T) { t = READ_ONCE(T); if (time_before(t, next)) next = t; }

	

	set(call->expect_req_by);

	set(call->expect_term_by);

	set(call->ack_at);

	set(call->resend_at);

	set(call->ping_at);



	now = jiffies;

	if (time_after_eq(now, next))

		goto recheck_state;



	rxrpc_reduce_call_timer(call, next, now, rxrpc_timer_restart);



	/* other events may have been raised since we started checking */

	if (call->events && call->state < RXRPC_CALL_COMPLETE) {

net/rxrpc/call_object.c

+16 −11
Original line number Diff line number Diff line
@@ -51,8 +51,10 @@ static void rxrpc_call_timer_expired(unsigned long _call) 


	_enter("%d", call->debug_id);



	if (call->state < RXRPC_CALL_COMPLETE)

		rxrpc_set_timer(call, rxrpc_timer_expired, ktime_get_real());

	if (call->state < RXRPC_CALL_COMPLETE) {

		trace_rxrpc_timer(call, rxrpc_timer_expired, jiffies);

		rxrpc_queue_call(call);

	}

}



static struct lock_class_key rxrpc_call_user_mutex_lock_class_key;
@@ -139,6 +141,8 @@ struct rxrpc_call *rxrpc_alloc_call(struct rxrpc_sock *rx, gfp_t gfp) 
	atomic_set(&call->usage, 1);

	call->debug_id = atomic_inc_return(&rxrpc_debug_id);

	call->tx_total_len = -1;

	call->next_rx_timo = 20 * HZ;

	call->next_req_timo = 1 * HZ;



	memset(&call->sock_node, 0xed, sizeof(call->sock_node));
@@ -189,15 +193,16 @@ static struct rxrpc_call *rxrpc_alloc_client_call(struct rxrpc_sock *rx, 
 */

static void rxrpc_start_call_timer(struct rxrpc_call *call)

{

	ktime_t now = ktime_get_real(), expire_at;



	expire_at = ktime_add_ms(now, rxrpc_max_call_lifetime);

	call->expire_at = expire_at;

	call->ack_at = expire_at;

	call->ping_at = expire_at;

	call->resend_at = expire_at;

	call->timer.expires = jiffies + LONG_MAX / 2;

	rxrpc_set_timer(call, rxrpc_timer_begin, now);

	unsigned long now = jiffies;

	unsigned long j = now + MAX_JIFFY_OFFSET;



	call->ack_at = j;

	call->resend_at = j;

	call->ping_at = j;

	call->expect_rx_by = j;

	call->expect_req_by = j;

	call->expect_term_by = j;

	call->timer.expires = now;

}



/*