* [PATCH net-next 01/15] rxrpc: Preset timestamp on Tx sk_buffs
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
@ 2016-09-23 15:15 ` David Howells
2016-09-23 15:15 ` [PATCH net-next 02/15] rxrpc: Don't send an ACK at the end of service call response transmission David Howells
` (14 subsequent siblings)
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:15 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
Set the timestamp on sk_buffs holding packets to be transmitted before
queueing them because the moment the packet is on the queue it can be seen
by the retransmission algorithm - which may see a completely random
timestamp.
If the retransmission algorithm sees such a timestamp, it may retransmit
the packet and, in future, tell the congestion management algorithm that
the retransmit timer expired.
Signed-off-by: David Howells <dhowells@redhat.com>
---
net/rxrpc/sendmsg.c | 5 +++++
1 file changed, 5 insertions(+)
diff --git a/net/rxrpc/sendmsg.c b/net/rxrpc/sendmsg.c
index ca7c3be60ad2..ca3811bfbd17 100644
--- a/net/rxrpc/sendmsg.c
+++ b/net/rxrpc/sendmsg.c
@@ -99,6 +99,11 @@ static void rxrpc_queue_packet(struct rxrpc_call *call, struct sk_buff *skb,
ASSERTCMP(seq, ==, call->tx_top + 1);
+ /* We have to set the timestamp before queueing as the retransmit
+ * algorithm can see the packet as soon as we queue it.
+ */
+ skb->tstamp = ktime_get_real();
+
ix = seq & RXRPC_RXTX_BUFF_MASK;
rxrpc_get_skb(skb, rxrpc_skb_tx_got);
call->rxtx_annotations[ix] = RXRPC_TX_ANNO_UNACK;
^ permalink raw reply related [flat|nested] 21+ messages in thread* [PATCH net-next 02/15] rxrpc: Don't send an ACK at the end of service call response transmission
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
2016-09-23 15:15 ` [PATCH net-next 01/15] rxrpc: Preset timestamp on Tx sk_buffs David Howells
@ 2016-09-23 15:15 ` David Howells
2016-09-23 15:15 ` [PATCH net-next 03/15] rxrpc: Make sure sendmsg() is woken on call completion David Howells
` (13 subsequent siblings)
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:15 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
Don't send an IDLE ACK at the end of the transmission of the response to a
service call. The service end resends DATA packets until the client sends an
ACK that hard-acks all the send data. At that point, the call is complete.
Signed-off-by: David Howells <dhowells@redhat.com>
---
net/rxrpc/recvmsg.c | 2 --
1 file changed, 2 deletions(-)
diff --git a/net/rxrpc/recvmsg.c b/net/rxrpc/recvmsg.c
index 6ba4af5a8d95..99e4c0ae30f1 100644
--- a/net/rxrpc/recvmsg.c
+++ b/net/rxrpc/recvmsg.c
@@ -143,8 +143,6 @@ static void rxrpc_end_rx_phase(struct rxrpc_call *call)
if (call->state == RXRPC_CALL_CLIENT_RECV_REPLY) {
rxrpc_propose_ACK(call, RXRPC_ACK_IDLE, 0, 0, true, false);
rxrpc_send_call_packet(call, RXRPC_PACKET_TYPE_ACK);
- } else {
- rxrpc_propose_ACK(call, RXRPC_ACK_IDLE, 0, 0, false, false);
}
write_lock_bh(&call->state_lock);
^ permalink raw reply related [flat|nested] 21+ messages in thread* [PATCH net-next 03/15] rxrpc: Make sure sendmsg() is woken on call completion
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
2016-09-23 15:15 ` [PATCH net-next 01/15] rxrpc: Preset timestamp on Tx sk_buffs David Howells
2016-09-23 15:15 ` [PATCH net-next 02/15] rxrpc: Don't send an ACK at the end of service call response transmission David Howells
@ 2016-09-23 15:15 ` David Howells
2016-09-23 15:15 ` [PATCH net-next 04/15] rxrpc: Should be using ktime_add_ms() not ktime_add_ns() David Howells
` (12 subsequent siblings)
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:15 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
Make sure that sendmsg() gets woken up if the call it is waiting for
completes abnormally.
Signed-off-by: David Howells <dhowells@redhat.com>
---
net/rxrpc/ar-internal.h | 1 +
1 file changed, 1 insertion(+)
diff --git a/net/rxrpc/ar-internal.h b/net/rxrpc/ar-internal.h
index b13754a6dd7a..808ab750dc6b 100644
--- a/net/rxrpc/ar-internal.h
+++ b/net/rxrpc/ar-internal.h
@@ -758,6 +758,7 @@ static inline bool __rxrpc_set_call_completion(struct rxrpc_call *call,
call->error = error;
call->completion = compl,
call->state = RXRPC_CALL_COMPLETE;
+ wake_up(&call->waitq);
return true;
}
return false;
^ permalink raw reply related [flat|nested] 21+ messages in thread* [PATCH net-next 04/15] rxrpc: Should be using ktime_add_ms() not ktime_add_ns()
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (2 preceding siblings ...)
2016-09-23 15:15 ` [PATCH net-next 03/15] rxrpc: Make sure sendmsg() is woken on call completion David Howells
@ 2016-09-23 15:15 ` David Howells
2016-09-23 15:15 ` [PATCH net-next 05/15] rxrpc: Use before_eq() and friends to compare serial numbers David Howells
` (11 subsequent siblings)
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:15 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
ktime_add_ms() should be used to add the resend time (in ms) rather than
ktime_add_ns().
Signed-off-by: David Howells <dhowells@redhat.com>
---
net/rxrpc/call_event.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/net/rxrpc/call_event.c b/net/rxrpc/call_event.c
index 6e2ea8f4ae75..a2909da5d581 100644
--- a/net/rxrpc/call_event.c
+++ b/net/rxrpc/call_event.c
@@ -187,7 +187,7 @@ static void rxrpc_resend(struct rxrpc_call *call)
call->rxtx_annotations[ix] = RXRPC_TX_ANNO_RETRANS | annotation;
}
- resend_at = ktime_sub(ktime_add_ns(oldest, rxrpc_resend_timeout), now);
+ resend_at = ktime_sub(ktime_add_ms(oldest, rxrpc_resend_timeout), now);
call->resend_at = jiffies + nsecs_to_jiffies(ktime_to_ns(resend_at));
/* Now go through the Tx window and perform the retransmissions. We
^ permalink raw reply related [flat|nested] 21+ messages in thread* [PATCH net-next 05/15] rxrpc: Use before_eq() and friends to compare serial numbers
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (3 preceding siblings ...)
2016-09-23 15:15 ` [PATCH net-next 04/15] rxrpc: Should be using ktime_add_ms() not ktime_add_ns() David Howells
@ 2016-09-23 15:15 ` David Howells
2016-09-23 15:15 ` [PATCH net-next 06/15] rxrpc: Need to start the resend timer on initial transmission David Howells
` (10 subsequent siblings)
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:15 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
before_eq() and friends should be used to compare serial numbers (when not
checking for (non)equality) rather than casting to int, subtracting and
checking the result.
Signed-off-by: David Howells <dhowells@redhat.com>
---
net/rxrpc/input.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/net/rxrpc/input.c b/net/rxrpc/input.c
index cbb5d53f09d7..06027b6d9c19 100644
--- a/net/rxrpc/input.c
+++ b/net/rxrpc/input.c
@@ -578,7 +578,7 @@ static void rxrpc_input_ack(struct rxrpc_call *call, struct sk_buff *skb,
}
/* Discard any out-of-order or duplicate ACKs. */
- if ((int)sp->hdr.serial - (int)call->acks_latest <= 0) {
+ if (before_eq(sp->hdr.serial, call->acks_latest)) {
_debug("discard ACK %d <= %d",
sp->hdr.serial, call->acks_latest);
return;
^ permalink raw reply related [flat|nested] 21+ messages in thread* [PATCH net-next 06/15] rxrpc: Need to start the resend timer on initial transmission
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (4 preceding siblings ...)
2016-09-23 15:15 ` [PATCH net-next 05/15] rxrpc: Use before_eq() and friends to compare serial numbers David Howells
@ 2016-09-23 15:15 ` David Howells
2016-09-23 15:16 ` [PATCH net-next 07/15] rxrpc: Fix accidental cancellation of scheduled resend by ACK parser David Howells
` (9 subsequent siblings)
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:15 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
When a DATA packet has its initial transmission, we may need to start or
adjust the resend timer. Without this we end up relying on being sent a
NACK to initiate the resend.
Signed-off-by: David Howells <dhowells@redhat.com>
---
net/rxrpc/ar-internal.h | 1 +
net/rxrpc/call_event.c | 2 +-
net/rxrpc/sendmsg.c | 9 +++++++++
3 files changed, 11 insertions(+), 1 deletion(-)
diff --git a/net/rxrpc/ar-internal.h b/net/rxrpc/ar-internal.h
index 808ab750dc6b..9e3ba4dc9578 100644
--- a/net/rxrpc/ar-internal.h
+++ b/net/rxrpc/ar-internal.h
@@ -704,6 +704,7 @@ int rxrpc_reject_call(struct rxrpc_sock *);
/*
* call_event.c
*/
+void rxrpc_set_timer(struct rxrpc_call *);
void rxrpc_propose_ACK(struct rxrpc_call *, u8, u16, u32, bool, bool);
void rxrpc_process_call(struct work_struct *);
diff --git a/net/rxrpc/call_event.c b/net/rxrpc/call_event.c
index a2909da5d581..3a7f90a2659c 100644
--- a/net/rxrpc/call_event.c
+++ b/net/rxrpc/call_event.c
@@ -24,7 +24,7 @@
/*
* Set the timer
*/
-static void rxrpc_set_timer(struct rxrpc_call *call)
+void rxrpc_set_timer(struct rxrpc_call *call)
{
unsigned long t, now = jiffies;
diff --git a/net/rxrpc/sendmsg.c b/net/rxrpc/sendmsg.c
index ca3811bfbd17..7cb34b2dfba9 100644
--- a/net/rxrpc/sendmsg.c
+++ b/net/rxrpc/sendmsg.c
@@ -146,6 +146,15 @@ static void rxrpc_queue_packet(struct rxrpc_call *call, struct sk_buff *skb,
if (ret < 0) {
_debug("need instant resend %d", ret);
rxrpc_instant_resend(call, ix);
+ } else {
+ unsigned long resend_at;
+
+ resend_at = jiffies + msecs_to_jiffies(rxrpc_resend_timeout);
+
+ if (time_before(resend_at, call->resend_at)) {
+ call->resend_at = resend_at;
+ rxrpc_set_timer(call);
+ }
}
rxrpc_free_skb(skb, rxrpc_skb_tx_freed);
^ permalink raw reply related [flat|nested] 21+ messages in thread* [PATCH net-next 07/15] rxrpc: Fix accidental cancellation of scheduled resend by ACK parser
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (5 preceding siblings ...)
2016-09-23 15:15 ` [PATCH net-next 06/15] rxrpc: Need to start the resend timer on initial transmission David Howells
@ 2016-09-23 15:16 ` David Howells
2016-09-23 18:02 ` Sergei Shtylyov
2016-09-23 18:20 ` David Howells
2016-09-23 15:16 ` [PATCH net-next 08/15] rxrpc: Fix call timer David Howells
` (8 subsequent siblings)
15 siblings, 2 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:16 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
When rxrpc_input_soft_acks() is parsing the soft-ACKs from an ACK packet,
it updates the Tx packet annotations in the annotation buffer. If a
soft-ACK is an ACK, then we overwrite unack'd, nak'd or to-be-retransmitted
states and that is fine; but if the soft-ACK is an NACK, we overwrite the
to-be-retransmitted with a nak - which isn't.
Instead, we need to let any scheduled retransmission stand if the packet
was NAK'd.
Note that we don't reissue a resend if the annotation is in the
to-be-retransmitted state because someone else must've scheduled the
resend already.
Signed-off-by: David Howells <dhowells@redhat.com>
---
net/rxrpc/input.c | 2 ++
1 file changed, 2 insertions(+)
diff --git a/net/rxrpc/input.c b/net/rxrpc/input.c
index 06027b6d9c19..d3d69ab1f0a1 100644
--- a/net/rxrpc/input.c
+++ b/net/rxrpc/input.c
@@ -479,6 +479,8 @@ static void rxrpc_input_soft_acks(struct rxrpc_call *call, u8 *acks,
case RXRPC_ACK_TYPE_NACK:
if (anno_type == RXRPC_TX_ANNO_NAK)
continue;
+ if (anno_type == RXRPC_TX_ANNO_RETRANS)
+ continue;
call->rxtx_annotations[ix] =
RXRPC_TX_ANNO_NAK | annotation;
resend = true;
^ permalink raw reply related [flat|nested] 21+ messages in thread* Re: [PATCH net-next 07/15] rxrpc: Fix accidental cancellation of scheduled resend by ACK parser
2016-09-23 15:16 ` [PATCH net-next 07/15] rxrpc: Fix accidental cancellation of scheduled resend by ACK parser David Howells
@ 2016-09-23 18:02 ` Sergei Shtylyov
2016-09-23 18:20 ` David Howells
1 sibling, 0 replies; 21+ messages in thread
From: Sergei Shtylyov @ 2016-09-23 18:02 UTC (permalink / raw)
To: David Howells, netdev; +Cc: linux-afs, linux-kernel
Hello.
On 09/23/2016 06:16 PM, David Howells wrote:
> When rxrpc_input_soft_acks() is parsing the soft-ACKs from an ACK packet,
> it updates the Tx packet annotations in the annotation buffer. If a
> soft-ACK is an ACK, then we overwrite unack'd, nak'd or to-be-retransmitted
> states and that is fine; but if the soft-ACK is an NACK, we overwrite the
> to-be-retransmitted with a nak - which isn't.
>
> Instead, we need to let any scheduled retransmission stand if the packet
> was NAK'd.
>
> Note that we don't reissue a resend if the annotation is in the
> to-be-retransmitted state because someone else must've scheduled the
> resend already.
>
> Signed-off-by: David Howells <dhowells@redhat.com>
> ---
>
> net/rxrpc/input.c | 2 ++
> 1 file changed, 2 insertions(+)
>
> diff --git a/net/rxrpc/input.c b/net/rxrpc/input.c
> index 06027b6d9c19..d3d69ab1f0a1 100644
> --- a/net/rxrpc/input.c
> +++ b/net/rxrpc/input.c
> @@ -479,6 +479,8 @@ static void rxrpc_input_soft_acks(struct rxrpc_call *call, u8 *acks,
> case RXRPC_ACK_TYPE_NACK:
> if (anno_type == RXRPC_TX_ANNO_NAK)
> continue;
> + if (anno_type == RXRPC_TX_ANNO_RETRANS)
> + continue;
Why not fold the above 2 *if*s together? Or use *else if* at least?
MBR, Sergei
^ permalink raw reply [flat|nested] 21+ messages in thread* Re: [PATCH net-next 07/15] rxrpc: Fix accidental cancellation of scheduled resend by ACK parser
2016-09-23 15:16 ` [PATCH net-next 07/15] rxrpc: Fix accidental cancellation of scheduled resend by ACK parser David Howells
2016-09-23 18:02 ` Sergei Shtylyov
@ 2016-09-23 18:20 ` David Howells
1 sibling, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 18:20 UTC (permalink / raw)
To: Sergei Shtylyov; +Cc: dhowells, netdev, linux-afs, linux-kernel
Sergei Shtylyov <sergei.shtylyov@cogentembedded.com> wrote:
> > case RXRPC_ACK_TYPE_NACK:
> > if (anno_type == RXRPC_TX_ANNO_NAK)
> > continue;
> > + if (anno_type == RXRPC_TX_ANNO_RETRANS)
> > + continue;
>
> Why not fold the above 2 *if*s together? Or use *else if* at least?
I have a pending patch that adds something between them.
David
^ permalink raw reply [flat|nested] 21+ messages in thread
* [PATCH net-next 08/15] rxrpc: Fix call timer
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (6 preceding siblings ...)
2016-09-23 15:16 ` [PATCH net-next 07/15] rxrpc: Fix accidental cancellation of scheduled resend by ACK parser David Howells
@ 2016-09-23 15:16 ` David Howells
2016-09-23 18:04 ` Sergei Shtylyov
2016-09-23 18:21 ` David Howells
2016-09-23 15:16 ` [PATCH net-next 09/15] rxrpc: Pass the last Tx packet marker in the annotation buffer David Howells
` (7 subsequent siblings)
15 siblings, 2 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:16 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
Fix the call timer in the following ways:
(1) If call->resend_at or call->ack_at are before or equal to the current
time, then ignore that timeout.
(2) If call->expire_at is before or equal to the current time, then don't
set the timer at all (possibly we should queue the call).
(3) Don't skip modifying the timer if timer_pending() is true. This
indicates that the timer is working, not that it has expired and is
running/waiting to run its expiry handler.
Also call rxrpc_set_timer() to start the call timer going rather than
calling add_timer().
Signed-off-by: David Howells <dhowells@redhat.com>
---
net/rxrpc/call_event.c | 25 ++++++++++++++-----------
net/rxrpc/call_object.c | 4 ++--
2 files changed, 16 insertions(+), 13 deletions(-)
diff --git a/net/rxrpc/call_event.c b/net/rxrpc/call_event.c
index 3a7f90a2659c..8bc5c8e37ab4 100644
--- a/net/rxrpc/call_event.c
+++ b/net/rxrpc/call_event.c
@@ -28,24 +28,27 @@ void rxrpc_set_timer(struct rxrpc_call *call)
{
unsigned long t, now = jiffies;
- _enter("{%ld,%ld,%ld:%ld}",
- call->ack_at - now, call->resend_at - now, call->expire_at - now,
- call->timer.expires - now);
-
read_lock_bh(&call->state_lock);
if (call->state < RXRPC_CALL_COMPLETE) {
- t = call->ack_at;
- if (time_before(call->resend_at, t))
+ t = call->expire_at;
+ if (time_before_eq(t, now))
+ goto out;
+
+ if (time_after(call->resend_at, now) &&
+ time_before(call->resend_at, t))
t = call->resend_at;
- if (time_before(call->expire_at, t))
- t = call->expire_at;
- if (!timer_pending(&call->timer) ||
- time_before(t, call->timer.expires)) {
- _debug("set timer %ld", t - now);
+
+ if (time_after(call->ack_at, now) &&
+ time_before(call->ack_at, t))
+ t = call->ack_at;
+
+ if (call->timer.expires != t || !timer_pending(&call->timer)) {
mod_timer(&call->timer, t);
}
}
+
+out:
read_unlock_bh(&call->state_lock);
}
diff --git a/net/rxrpc/call_object.c b/net/rxrpc/call_object.c
index f50a6094e198..f2fadf667e19 100644
--- a/net/rxrpc/call_object.c
+++ b/net/rxrpc/call_object.c
@@ -199,8 +199,8 @@ static void rxrpc_start_call_timer(struct rxrpc_call *call)
call->expire_at = expire_at;
call->ack_at = expire_at;
call->resend_at = expire_at;
- call->timer.expires = expire_at;
- add_timer(&call->timer);
+ call->timer.expires = expire_at + 1;
+ rxrpc_set_timer(call);
}
/*
^ permalink raw reply related [flat|nested] 21+ messages in thread* Re: [PATCH net-next 08/15] rxrpc: Fix call timer
2016-09-23 15:16 ` [PATCH net-next 08/15] rxrpc: Fix call timer David Howells
@ 2016-09-23 18:04 ` Sergei Shtylyov
2016-09-23 18:21 ` David Howells
1 sibling, 0 replies; 21+ messages in thread
From: Sergei Shtylyov @ 2016-09-23 18:04 UTC (permalink / raw)
To: David Howells, netdev; +Cc: linux-afs, linux-kernel
On 09/23/2016 06:16 PM, David Howells wrote:
> Fix the call timer in the following ways:
>
> (1) If call->resend_at or call->ack_at are before or equal to the current
> time, then ignore that timeout.
>
> (2) If call->expire_at is before or equal to the current time, then don't
> set the timer at all (possibly we should queue the call).
>
> (3) Don't skip modifying the timer if timer_pending() is true. This
> indicates that the timer is working, not that it has expired and is
> running/waiting to run its expiry handler.
>
> Also call rxrpc_set_timer() to start the call timer going rather than
> calling add_timer().
>
> Signed-off-by: David Howells <dhowells@redhat.com>
> ---
>
> net/rxrpc/call_event.c | 25 ++++++++++++++-----------
> net/rxrpc/call_object.c | 4 ++--
> 2 files changed, 16 insertions(+), 13 deletions(-)
>
> diff --git a/net/rxrpc/call_event.c b/net/rxrpc/call_event.c
> index 3a7f90a2659c..8bc5c8e37ab4 100644
> --- a/net/rxrpc/call_event.c
> +++ b/net/rxrpc/call_event.c
> @@ -28,24 +28,27 @@ void rxrpc_set_timer(struct rxrpc_call *call)
> {
> unsigned long t, now = jiffies;
>
> - _enter("{%ld,%ld,%ld:%ld}",
> - call->ack_at - now, call->resend_at - now, call->expire_at - now,
> - call->timer.expires - now);
> -
> read_lock_bh(&call->state_lock);
>
> if (call->state < RXRPC_CALL_COMPLETE) {
> - t = call->ack_at;
> - if (time_before(call->resend_at, t))
> + t = call->expire_at;
> + if (time_before_eq(t, now))
> + goto out;
> +
> + if (time_after(call->resend_at, now) &&
> + time_before(call->resend_at, t))
> t = call->resend_at;
> - if (time_before(call->expire_at, t))
> - t = call->expire_at;
> - if (!timer_pending(&call->timer) ||
> - time_before(t, call->timer.expires)) {
> - _debug("set timer %ld", t - now);
> +
> + if (time_after(call->ack_at, now) &&
> + time_before(call->ack_at, t))
> + t = call->ack_at;
> +
> + if (call->timer.expires != t || !timer_pending(&call->timer)) {
> mod_timer(&call->timer, t);
> }
CodingStyle: {} not needed now.
[...]
MBR, Sergei
^ permalink raw reply [flat|nested] 21+ messages in thread* Re: [PATCH net-next 08/15] rxrpc: Fix call timer
2016-09-23 15:16 ` [PATCH net-next 08/15] rxrpc: Fix call timer David Howells
2016-09-23 18:04 ` Sergei Shtylyov
@ 2016-09-23 18:21 ` David Howells
1 sibling, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 18:21 UTC (permalink / raw)
To: Sergei Shtylyov; +Cc: dhowells, netdev, linux-afs, linux-kernel
Sergei Shtylyov <sergei.shtylyov@cogentembedded.com> wrote:
> > + if (call->timer.expires != t || !timer_pending(&call->timer)) {
> > mod_timer(&call->timer, t);
> > }
>
> CodingStyle: {} not needed now.
See patch 11.
David
^ permalink raw reply [flat|nested] 21+ messages in thread
* [PATCH net-next 09/15] rxrpc: Pass the last Tx packet marker in the annotation buffer
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (7 preceding siblings ...)
2016-09-23 15:16 ` [PATCH net-next 08/15] rxrpc: Fix call timer David Howells
@ 2016-09-23 15:16 ` David Howells
2016-09-23 15:16 ` [PATCH net-next 10/15] rxrpc: Don't call the tx_ack tracepoint if don't generate an ACK David Howells
` (6 subsequent siblings)
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:16 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
When the last packet of data to be transmitted on a call is queued, tx_top
is set and then the RXRPC_CALL_TX_LAST flag is set. Unfortunately, this
leaves a race in the ACK processing side of things because the flag affects
the interpretation of tx_top and also allows us to start receiving reply
data before we've finished transmitting.
To fix this, make the following changes:
(1) rxrpc_queue_packet() now sets a marker in the annotation buffer
instead of setting the RXRPC_CALL_TX_LAST flag.
(2) rxrpc_rotate_tx_window() detects the marker and sets the flag in the
same context as the routines that use it.
(3) rxrpc_end_tx_phase() is simplified to just shift the call state.
The Tx window must have been rotated before calling to discard the
last packet.
(4) rxrpc_receiving_reply() is added to handle the arrival of the first
DATA packet of a reply to a client call (which is an implicit ACK of
the Tx phase).
(5) The last part of rxrpc_input_ack() is reordered to perform Tx
rotation, then soft-ACK application and then to end the phase if we've
rotated the last packet. In the event of a terminal ACK, the soft-ACK
application will be skipped as nAcks should be 0.
(6) rxrpc_input_ackall() now has to rotate as well as ending the phase.
In addition:
(7) Alter the transmit tracepoint to log the rotation of the last packet.
(8) Remove the no-longer relevant queue_reqack tracepoint note. The
ACK-REQUESTED packet header flag is now set as needed when we actually
transmit the packet and may vary by retransmission.
Signed-off-by: David Howells <dhowells@redhat.com>
---
net/rxrpc/ar-internal.h | 7 ++-
net/rxrpc/input.c | 102 +++++++++++++++++++++++++++++++----------------
net/rxrpc/misc.c | 3 +
net/rxrpc/sendmsg.c | 14 +++---
4 files changed, 81 insertions(+), 45 deletions(-)
diff --git a/net/rxrpc/ar-internal.h b/net/rxrpc/ar-internal.h
index 9e3ba4dc9578..a494d56eb236 100644
--- a/net/rxrpc/ar-internal.h
+++ b/net/rxrpc/ar-internal.h
@@ -508,7 +508,9 @@ struct rxrpc_call {
#define RXRPC_TX_ANNO_NAK 2
#define RXRPC_TX_ANNO_RETRANS 3
#define RXRPC_TX_ANNO_MASK 0x03
-#define RXRPC_TX_ANNO_RESENT 0x04
+#define RXRPC_TX_ANNO_LAST 0x04
+#define RXRPC_TX_ANNO_RESENT 0x08
+
#define RXRPC_RX_ANNO_JUMBO 0x3f /* Jumbo subpacket number + 1 if not zero */
#define RXRPC_RX_ANNO_JLAST 0x40 /* Set if last element of a jumbo packet */
#define RXRPC_RX_ANNO_VERIFIED 0x80 /* Set if verified and decrypted */
@@ -621,9 +623,10 @@ extern const char rxrpc_call_traces[rxrpc_call__nr_trace][4];
enum rxrpc_transmit_trace {
rxrpc_transmit_wait,
rxrpc_transmit_queue,
- rxrpc_transmit_queue_reqack,
rxrpc_transmit_queue_last,
rxrpc_transmit_rotate,
+ rxrpc_transmit_rotate_last,
+ rxrpc_transmit_await_reply,
rxrpc_transmit_end,
rxrpc_transmit__nr_trace
};
diff --git a/net/rxrpc/input.c b/net/rxrpc/input.c
index d3d69ab1f0a1..fb3e2f6afa3b 100644
--- a/net/rxrpc/input.c
+++ b/net/rxrpc/input.c
@@ -59,6 +59,7 @@ static void rxrpc_rotate_tx_window(struct rxrpc_call *call, rxrpc_seq_t to)
{
struct sk_buff *skb, *list = NULL;
int ix;
+ u8 annotation;
spin_lock(&call->lock);
@@ -66,16 +67,22 @@ static void rxrpc_rotate_tx_window(struct rxrpc_call *call, rxrpc_seq_t to)
call->tx_hard_ack++;
ix = call->tx_hard_ack & RXRPC_RXTX_BUFF_MASK;
skb = call->rxtx_buffer[ix];
+ annotation = call->rxtx_annotations[ix];
rxrpc_see_skb(skb, rxrpc_skb_tx_rotated);
call->rxtx_buffer[ix] = NULL;
call->rxtx_annotations[ix] = 0;
skb->next = list;
list = skb;
+
+ if (annotation & RXRPC_TX_ANNO_LAST)
+ set_bit(RXRPC_CALL_TX_LAST, &call->flags);
}
spin_unlock(&call->lock);
- trace_rxrpc_transmit(call, rxrpc_transmit_rotate);
+ trace_rxrpc_transmit(call, (test_bit(RXRPC_CALL_TX_LAST, &call->flags) ?
+ rxrpc_transmit_rotate_last :
+ rxrpc_transmit_rotate));
wake_up(&call->waitq);
while (list) {
@@ -92,42 +99,65 @@ static void rxrpc_rotate_tx_window(struct rxrpc_call *call, rxrpc_seq_t to)
* This occurs when we get an ACKALL packet, the first DATA packet of a reply,
* or a final ACK packet.
*/
-static bool rxrpc_end_tx_phase(struct rxrpc_call *call, const char *abort_why)
+static bool rxrpc_end_tx_phase(struct rxrpc_call *call, bool reply_begun,
+ const char *abort_why)
{
- _enter("");
-
- switch (call->state) {
- case RXRPC_CALL_CLIENT_RECV_REPLY:
- return true;
- case RXRPC_CALL_CLIENT_AWAIT_REPLY:
- case RXRPC_CALL_SERVER_AWAIT_ACK:
- break;
- default:
- rxrpc_proto_abort(abort_why, call, call->tx_top);
- return false;
- }
- rxrpc_rotate_tx_window(call, call->tx_top);
+ ASSERT(test_bit(RXRPC_CALL_TX_LAST, &call->flags));
write_lock(&call->state_lock);
switch (call->state) {
- default:
- break;
+ case RXRPC_CALL_CLIENT_SEND_REQUEST:
case RXRPC_CALL_CLIENT_AWAIT_REPLY:
- call->tx_phase = false;
- call->state = RXRPC_CALL_CLIENT_RECV_REPLY;
+ if (reply_begun)
+ call->state = RXRPC_CALL_CLIENT_RECV_REPLY;
+ else
+ call->state = RXRPC_CALL_CLIENT_AWAIT_REPLY;
break;
+
case RXRPC_CALL_SERVER_AWAIT_ACK:
__rxrpc_call_completed(call);
rxrpc_notify_socket(call);
break;
+
+ default:
+ goto bad_state;
}
write_unlock(&call->state_lock);
- trace_rxrpc_transmit(call, rxrpc_transmit_end);
+ if (call->state == RXRPC_CALL_CLIENT_AWAIT_REPLY) {
+ trace_rxrpc_transmit(call, rxrpc_transmit_await_reply);
+ } else {
+ trace_rxrpc_transmit(call, rxrpc_transmit_end);
+ }
_leave(" = ok");
return true;
+
+bad_state:
+ write_unlock(&call->state_lock);
+ kdebug("end_tx %s", rxrpc_call_states[call->state]);
+ rxrpc_proto_abort(abort_why, call, call->tx_top);
+ return false;
+}
+
+/*
+ * Begin the reply reception phase of a call.
+ */
+static bool rxrpc_receiving_reply(struct rxrpc_call *call)
+{
+ rxrpc_seq_t top = READ_ONCE(call->tx_top);
+
+ if (!test_bit(RXRPC_CALL_TX_LAST, &call->flags))
+ rxrpc_rotate_tx_window(call, top);
+ if (!test_bit(RXRPC_CALL_TX_LAST, &call->flags)) {
+ rxrpc_proto_abort("TXL", call, top);
+ return false;
+ }
+ if (!rxrpc_end_tx_phase(call, true, "ETD"))
+ return false;
+ call->tx_phase = false;
+ return true;
}
/*
@@ -226,8 +256,9 @@ static void rxrpc_input_data(struct rxrpc_call *call, struct sk_buff *skb,
/* Received data implicitly ACKs all of the request packets we sent
* when we're acting as a client.
*/
- if (call->state == RXRPC_CALL_CLIENT_AWAIT_REPLY &&
- !rxrpc_end_tx_phase(call, "ETD"))
+ if ((call->state == RXRPC_CALL_CLIENT_SEND_REQUEST ||
+ call->state == RXRPC_CALL_CLIENT_AWAIT_REPLY) &&
+ !rxrpc_receiving_reply(call))
return;
call->ackr_prev_seq = seq;
@@ -587,27 +618,26 @@ static void rxrpc_input_ack(struct rxrpc_call *call, struct sk_buff *skb,
}
call->acks_latest = sp->hdr.serial;
- if (test_bit(RXRPC_CALL_TX_LAST, &call->flags) &&
- hard_ack == call->tx_top) {
- rxrpc_end_tx_phase(call, "ETA");
- return;
- }
-
if (before(hard_ack, call->tx_hard_ack) ||
after(hard_ack, call->tx_top))
return rxrpc_proto_abort("AKW", call, 0);
+ if (nr_acks > call->tx_top - hard_ack)
+ return rxrpc_proto_abort("AKN", call, 0);
if (after(hard_ack, call->tx_hard_ack))
rxrpc_rotate_tx_window(call, hard_ack);
- if (after(first_soft_ack, call->tx_top))
+ if (nr_acks > 0) {
+ if (skb_copy_bits(skb, sp->offset, buf.acks, nr_acks) < 0)
+ return rxrpc_proto_abort("XSA", call, 0);
+ rxrpc_input_soft_acks(call, buf.acks, first_soft_ack, nr_acks);
+ }
+
+ if (test_bit(RXRPC_CALL_TX_LAST, &call->flags)) {
+ rxrpc_end_tx_phase(call, false, "ETA");
return;
+ }
- if (nr_acks > call->tx_top - first_soft_ack + 1)
- nr_acks = first_soft_ack - call->tx_top + 1;
- if (skb_copy_bits(skb, sp->offset, buf.acks, nr_acks) < 0)
- return rxrpc_proto_abort("XSA", call, 0);
- rxrpc_input_soft_acks(call, buf.acks, first_soft_ack, nr_acks);
}
/*
@@ -619,7 +649,9 @@ static void rxrpc_input_ackall(struct rxrpc_call *call, struct sk_buff *skb)
_proto("Rx ACKALL %%%u", sp->hdr.serial);
- rxrpc_end_tx_phase(call, "ETL");
+ rxrpc_rotate_tx_window(call, call->tx_top);
+ if (test_bit(RXRPC_CALL_TX_LAST, &call->flags))
+ rxrpc_end_tx_phase(call, false, "ETL");
}
/*
diff --git a/net/rxrpc/misc.c b/net/rxrpc/misc.c
index 0d425e707f22..fe648711c2f7 100644
--- a/net/rxrpc/misc.c
+++ b/net/rxrpc/misc.c
@@ -155,9 +155,10 @@ const char rxrpc_client_traces[rxrpc_client__nr_trace][7] = {
const char rxrpc_transmit_traces[rxrpc_transmit__nr_trace][4] = {
[rxrpc_transmit_wait] = "WAI",
[rxrpc_transmit_queue] = "QUE",
- [rxrpc_transmit_queue_reqack] = "QRA",
[rxrpc_transmit_queue_last] = "QLS",
[rxrpc_transmit_rotate] = "ROT",
+ [rxrpc_transmit_rotate_last] = "RLS",
+ [rxrpc_transmit_await_reply] = "AWR",
[rxrpc_transmit_end] = "END",
};
diff --git a/net/rxrpc/sendmsg.c b/net/rxrpc/sendmsg.c
index 7cb34b2dfba9..93e6584cd751 100644
--- a/net/rxrpc/sendmsg.c
+++ b/net/rxrpc/sendmsg.c
@@ -94,11 +94,15 @@ static void rxrpc_queue_packet(struct rxrpc_call *call, struct sk_buff *skb,
struct rxrpc_skb_priv *sp = rxrpc_skb(skb);
rxrpc_seq_t seq = sp->hdr.seq;
int ret, ix;
+ u8 annotation = RXRPC_TX_ANNO_UNACK;
_net("queue skb %p [%d]", skb, seq);
ASSERTCMP(seq, ==, call->tx_top + 1);
+ if (last)
+ annotation |= RXRPC_TX_ANNO_LAST;
+
/* We have to set the timestamp before queueing as the retransmit
* algorithm can see the packet as soon as we queue it.
*/
@@ -106,18 +110,14 @@ static void rxrpc_queue_packet(struct rxrpc_call *call, struct sk_buff *skb,
ix = seq & RXRPC_RXTX_BUFF_MASK;
rxrpc_get_skb(skb, rxrpc_skb_tx_got);
- call->rxtx_annotations[ix] = RXRPC_TX_ANNO_UNACK;
+ call->rxtx_annotations[ix] = annotation;
smp_wmb();
call->rxtx_buffer[ix] = skb;
call->tx_top = seq;
- if (last) {
- set_bit(RXRPC_CALL_TX_LAST, &call->flags);
+ if (last)
trace_rxrpc_transmit(call, rxrpc_transmit_queue_last);
- } else if (sp->hdr.flags & RXRPC_REQUEST_ACK) {
- trace_rxrpc_transmit(call, rxrpc_transmit_queue_reqack);
- } else {
+ else
trace_rxrpc_transmit(call, rxrpc_transmit_queue);
- }
if (last || call->state == RXRPC_CALL_SERVER_ACK_REQUEST) {
_debug("________awaiting reply/ACK__________");
^ permalink raw reply related [flat|nested] 21+ messages in thread* [PATCH net-next 10/15] rxrpc: Don't call the tx_ack tracepoint if don't generate an ACK
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (8 preceding siblings ...)
2016-09-23 15:16 ` [PATCH net-next 09/15] rxrpc: Pass the last Tx packet marker in the annotation buffer David Howells
@ 2016-09-23 15:16 ` David Howells
2016-09-23 15:16 ` [PATCH net-next 11/15] rxrpc: Add a tracepoint for the call timer David Howells
` (5 subsequent siblings)
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:16 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
rxrpc_send_call_packet() is invoking the tx_ack tracepoint before it checks
whether there's an ACK to transmit (another thread may jump in and transmit
it).
Fix this by only invoking the tracepoint if we get a valid ACK to transmit.
Further, only allocate a serial number if we're going to actually transmit
something.
Signed-off-by: David Howells <dhowells@redhat.com>
---
net/rxrpc/output.c | 26 +++++++++++---------------
1 file changed, 11 insertions(+), 15 deletions(-)
diff --git a/net/rxrpc/output.c b/net/rxrpc/output.c
index 282cb1e36d06..5c1e008a5323 100644
--- a/net/rxrpc/output.c
+++ b/net/rxrpc/output.c
@@ -80,9 +80,6 @@ static size_t rxrpc_fill_out_ack(struct rxrpc_call *call,
pkt->ackinfo.rwind = htonl(call->rx_winsize);
pkt->ackinfo.jumbo_max = htonl(jmax);
- trace_rxrpc_tx_ack(call, hard_ack + 1, serial, call->ackr_reason,
- top - hard_ack);
-
*ackp++ = 0;
*ackp++ = 0;
*ackp++ = 0;
@@ -119,8 +116,6 @@ int rxrpc_send_call_packet(struct rxrpc_call *call, u8 type)
return -ENOMEM;
}
- serial = atomic_inc_return(&conn->serial);
-
msg.msg_name = &call->peer->srx.transport;
msg.msg_namelen = call->peer->srx.transport_len;
msg.msg_control = NULL;
@@ -131,7 +126,6 @@ int rxrpc_send_call_packet(struct rxrpc_call *call, u8 type)
pkt->whdr.cid = htonl(call->cid);
pkt->whdr.callNumber = htonl(call->call_id);
pkt->whdr.seq = 0;
- pkt->whdr.serial = htonl(serial);
pkt->whdr.type = type;
pkt->whdr.flags = conn->out_clientflag;
pkt->whdr.userStatus = 0;
@@ -157,14 +151,6 @@ int rxrpc_send_call_packet(struct rxrpc_call *call, u8 type)
spin_unlock_bh(&call->lock);
- _proto("Tx ACK %%%u { m=%hu f=#%u p=#%u s=%%%u r=%s n=%u }",
- serial,
- ntohs(pkt->ack.maxSkew),
- ntohl(pkt->ack.firstPacket),
- ntohl(pkt->ack.previousPacket),
- ntohl(pkt->ack.serial),
- rxrpc_acks(pkt->ack.reason),
- pkt->ack.nAcks);
iov[0].iov_len += sizeof(pkt->ack) + n;
iov[1].iov_base = &pkt->ackinfo;
@@ -176,7 +162,6 @@ int rxrpc_send_call_packet(struct rxrpc_call *call, u8 type)
case RXRPC_PACKET_TYPE_ABORT:
abort_code = call->abort_code;
pkt->abort_code = htonl(abort_code);
- _proto("Tx ABORT %%%u { %d }", serial, abort_code);
iov[0].iov_len += sizeof(pkt->abort_code);
len += sizeof(pkt->abort_code);
ioc = 1;
@@ -188,6 +173,17 @@ int rxrpc_send_call_packet(struct rxrpc_call *call, u8 type)
goto out;
}
+ serial = atomic_inc_return(&conn->serial);
+ pkt->whdr.serial = htonl(serial);
+ switch (type) {
+ case RXRPC_PACKET_TYPE_ACK:
+ trace_rxrpc_tx_ack(call,
+ ntohl(pkt->ack.firstPacket),
+ ntohl(pkt->ack.serial),
+ pkt->ack.reason, pkt->ack.nAcks);
+ break;
+ }
+
if (ping) {
call->ackr_ping = serial;
smp_wmb();
^ permalink raw reply related [flat|nested] 21+ messages in thread* [PATCH net-next 11/15] rxrpc: Add a tracepoint for the call timer
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (9 preceding siblings ...)
2016-09-23 15:16 ` [PATCH net-next 10/15] rxrpc: Don't call the tx_ack tracepoint if don't generate an ACK David Howells
@ 2016-09-23 15:16 ` David Howells
2016-09-23 15:16 ` [PATCH net-next 12/15] rxrpc: Add data Tx tracepoint and adjust Tx ACK tracepoint David Howells
` (4 subsequent siblings)
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:16 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
Add a tracepoint to log call timer initiation, setting and expiry.
Signed-off-by: David Howells <dhowells@redhat.com>
---
include/trace/events/rxrpc.h | 36 ++++++++++++++++++++++++++++++++++++
net/rxrpc/ar-internal.h | 13 ++++++++++++-
net/rxrpc/call_event.c | 7 ++++---
net/rxrpc/call_object.c | 6 ++++--
net/rxrpc/misc.c | 8 ++++++++
net/rxrpc/sendmsg.c | 2 +-
6 files changed, 65 insertions(+), 7 deletions(-)
diff --git a/include/trace/events/rxrpc.h b/include/trace/events/rxrpc.h
index e8f2afbbe0bf..57322897d745 100644
--- a/include/trace/events/rxrpc.h
+++ b/include/trace/events/rxrpc.h
@@ -414,6 +414,42 @@ TRACE_EVENT(rxrpc_rtt_rx,
__entry->avg)
);
+TRACE_EVENT(rxrpc_timer,
+ TP_PROTO(struct rxrpc_call *call, enum rxrpc_timer_trace why,
+ unsigned long now),
+
+ TP_ARGS(call, why, now),
+
+ TP_STRUCT__entry(
+ __field(struct rxrpc_call *, call )
+ __field(enum rxrpc_timer_trace, why )
+ __field(unsigned long, now )
+ __field(unsigned long, expire_at )
+ __field(unsigned long, ack_at )
+ __field(unsigned long, resend_at )
+ __field(unsigned 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->timer = call->timer.expires;
+ ),
+
+ TP_printk("c=%p %s now=%lx x=%ld a=%ld r=%ld t=%ld",
+ __entry->call,
+ rxrpc_timer_traces[__entry->why],
+ __entry->now,
+ __entry->expire_at - __entry->now,
+ __entry->ack_at - __entry->now,
+ __entry->resend_at - __entry->now,
+ __entry->timer - __entry->now)
+ );
+
#endif /* _TRACE_RXRPC_H */
/* This part must be outside protection */
diff --git a/net/rxrpc/ar-internal.h b/net/rxrpc/ar-internal.h
index a494d56eb236..e564eca75985 100644
--- a/net/rxrpc/ar-internal.h
+++ b/net/rxrpc/ar-internal.h
@@ -678,6 +678,17 @@ enum rxrpc_rtt_rx_trace {
extern const char rxrpc_rtt_rx_traces[rxrpc_rtt_rx__nr_trace][5];
+enum rxrpc_timer_trace {
+ rxrpc_timer_begin,
+ rxrpc_timer_expired,
+ rxrpc_timer_set_for_ack,
+ rxrpc_timer_set_for_resend,
+ rxrpc_timer_set_for_send,
+ rxrpc_timer__nr_trace
+};
+
+extern const char rxrpc_timer_traces[rxrpc_timer__nr_trace][8];
+
extern const char *const rxrpc_pkts[];
extern const char *rxrpc_acks(u8 reason);
@@ -707,7 +718,7 @@ int rxrpc_reject_call(struct rxrpc_sock *);
/*
* call_event.c
*/
-void rxrpc_set_timer(struct rxrpc_call *);
+void rxrpc_set_timer(struct rxrpc_call *, enum rxrpc_timer_trace);
void rxrpc_propose_ACK(struct rxrpc_call *, u8, u16, u32, bool, bool);
void rxrpc_process_call(struct work_struct *);
diff --git a/net/rxrpc/call_event.c b/net/rxrpc/call_event.c
index 8bc5c8e37ab4..90e970ba048a 100644
--- a/net/rxrpc/call_event.c
+++ b/net/rxrpc/call_event.c
@@ -24,7 +24,7 @@
/*
* Set the timer
*/
-void rxrpc_set_timer(struct rxrpc_call *call)
+void rxrpc_set_timer(struct rxrpc_call *call, enum rxrpc_timer_trace why)
{
unsigned long t, now = jiffies;
@@ -45,6 +45,7 @@ void rxrpc_set_timer(struct rxrpc_call *call)
if (call->timer.expires != t || !timer_pending(&call->timer)) {
mod_timer(&call->timer, t);
+ trace_rxrpc_timer(call, why, now);
}
}
@@ -120,7 +121,7 @@ static void __rxrpc_propose_ACK(struct rxrpc_call *call, u8 ack_reason,
_debug("deferred ACK %ld < %ld", expiry, call->ack_at - now);
if (time_before(ack_at, call->ack_at)) {
call->ack_at = ack_at;
- rxrpc_set_timer(call);
+ rxrpc_set_timer(call, rxrpc_timer_set_for_ack);
}
}
}
@@ -293,7 +294,7 @@ recheck_state:
goto recheck_state;
}
- rxrpc_set_timer(call);
+ rxrpc_set_timer(call, rxrpc_timer_set_for_resend);
/* other events may have been raised since we started checking */
if (call->events && call->state < RXRPC_CALL_COMPLETE) {
diff --git a/net/rxrpc/call_object.c b/net/rxrpc/call_object.c
index f2fadf667e19..a53f4c2c0025 100644
--- a/net/rxrpc/call_object.c
+++ b/net/rxrpc/call_object.c
@@ -76,8 +76,10 @@ static void rxrpc_call_timer_expired(unsigned long _call)
_enter("%d", call->debug_id);
- if (call->state < RXRPC_CALL_COMPLETE)
+ if (call->state < RXRPC_CALL_COMPLETE) {
+ trace_rxrpc_timer(call, rxrpc_timer_expired, jiffies);
rxrpc_queue_call(call);
+ }
}
/*
@@ -200,7 +202,7 @@ static void rxrpc_start_call_timer(struct rxrpc_call *call)
call->ack_at = expire_at;
call->resend_at = expire_at;
call->timer.expires = expire_at + 1;
- rxrpc_set_timer(call);
+ rxrpc_set_timer(call, rxrpc_timer_begin);
}
/*
diff --git a/net/rxrpc/misc.c b/net/rxrpc/misc.c
index fe648711c2f7..fa9942fabdf2 100644
--- a/net/rxrpc/misc.c
+++ b/net/rxrpc/misc.c
@@ -194,3 +194,11 @@ const char rxrpc_rtt_rx_traces[rxrpc_rtt_rx__nr_trace][5] = {
[rxrpc_rtt_rx_ping_response] = "PONG",
[rxrpc_rtt_rx_requested_ack] = "RACK",
};
+
+const char rxrpc_timer_traces[rxrpc_timer__nr_trace][8] = {
+ [rxrpc_timer_begin] = "Begin ",
+ [rxrpc_timer_expired] = "*EXPR*",
+ [rxrpc_timer_set_for_ack] = "SetAck",
+ [rxrpc_timer_set_for_send] = "SetTx ",
+ [rxrpc_timer_set_for_resend] = "SetRTx",
+};
diff --git a/net/rxrpc/sendmsg.c b/net/rxrpc/sendmsg.c
index 93e6584cd751..99939372b5a4 100644
--- a/net/rxrpc/sendmsg.c
+++ b/net/rxrpc/sendmsg.c
@@ -153,7 +153,7 @@ static void rxrpc_queue_packet(struct rxrpc_call *call, struct sk_buff *skb,
if (time_before(resend_at, call->resend_at)) {
call->resend_at = resend_at;
- rxrpc_set_timer(call);
+ rxrpc_set_timer(call, rxrpc_timer_set_for_send);
}
}
^ permalink raw reply related [flat|nested] 21+ messages in thread* [PATCH net-next 12/15] rxrpc: Add data Tx tracepoint and adjust Tx ACK tracepoint
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (10 preceding siblings ...)
2016-09-23 15:16 ` [PATCH net-next 11/15] rxrpc: Add a tracepoint for the call timer David Howells
@ 2016-09-23 15:16 ` David Howells
2016-09-23 15:16 ` [PATCH net-next 13/15] rxrpc: Add a tracepoint to log injected Rx packet loss David Howells
` (3 subsequent siblings)
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:16 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
Add a tracepoint to log transmission of DATA packets (including loss
injection).
Adjust the ACK transmission tracepoint to include the packet serial number
and to line this up with the DATA transmission display.
Signed-off-by: David Howells <dhowells@redhat.com>
---
include/trace/events/rxrpc.h | 50 +++++++++++++++++++++++++++++++++++-------
net/rxrpc/conn_event.c | 5 ++--
net/rxrpc/output.c | 5 +++-
3 files changed, 48 insertions(+), 12 deletions(-)
diff --git a/include/trace/events/rxrpc.h b/include/trace/events/rxrpc.h
index 57322897d745..6001bf93dc79 100644
--- a/include/trace/events/rxrpc.h
+++ b/include/trace/events/rxrpc.h
@@ -256,33 +256,67 @@ TRACE_EVENT(rxrpc_rx_ack,
__entry->n_acks)
);
+TRACE_EVENT(rxrpc_tx_data,
+ TP_PROTO(struct rxrpc_call *call, rxrpc_seq_t seq,
+ rxrpc_serial_t serial, u8 flags, bool lose),
+
+ TP_ARGS(call, seq, serial, flags, lose),
+
+ TP_STRUCT__entry(
+ __field(struct rxrpc_call *, call )
+ __field(rxrpc_seq_t, seq )
+ __field(rxrpc_serial_t, serial )
+ __field(u8, flags )
+ __field(bool, lose )
+ ),
+
+ TP_fast_assign(
+ __entry->call = call;
+ __entry->seq = seq;
+ __entry->serial = serial;
+ __entry->flags = flags;
+ __entry->lose = lose;
+ ),
+
+ TP_printk("c=%p DATA %08x q=%08x fl=%02x%s",
+ __entry->call,
+ __entry->serial,
+ __entry->seq,
+ __entry->flags,
+ __entry->lose ? " *LOSE*" : "")
+ );
+
TRACE_EVENT(rxrpc_tx_ack,
- TP_PROTO(struct rxrpc_call *call, rxrpc_seq_t first,
- rxrpc_serial_t serial, u8 reason, u8 n_acks),
+ TP_PROTO(struct rxrpc_call *call, rxrpc_serial_t serial,
+ rxrpc_seq_t ack_first, rxrpc_serial_t ack_serial,
+ u8 reason, u8 n_acks),
- TP_ARGS(call, first, serial, reason, n_acks),
+ TP_ARGS(call, serial, ack_first, ack_serial, reason, n_acks),
TP_STRUCT__entry(
__field(struct rxrpc_call *, call )
- __field(rxrpc_seq_t, first )
__field(rxrpc_serial_t, serial )
+ __field(rxrpc_seq_t, ack_first )
+ __field(rxrpc_serial_t, ack_serial )
__field(u8, reason )
__field(u8, n_acks )
),
TP_fast_assign(
__entry->call = call;
- __entry->first = first;
__entry->serial = serial;
+ __entry->ack_first = ack_first;
+ __entry->ack_serial = ack_serial;
__entry->reason = reason;
__entry->n_acks = n_acks;
),
- TP_printk("c=%p %s f=%08x r=%08x n=%u",
+ TP_printk(" c=%p ACK %08x %s f=%08x r=%08x n=%u",
__entry->call,
- rxrpc_acks(__entry->reason),
- __entry->first,
__entry->serial,
+ rxrpc_acks(__entry->reason),
+ __entry->ack_first,
+ __entry->ack_serial,
__entry->n_acks)
);
diff --git a/net/rxrpc/conn_event.c b/net/rxrpc/conn_event.c
index 75a15a4c74c3..a1cf1ec5f29e 100644
--- a/net/rxrpc/conn_event.c
+++ b/net/rxrpc/conn_event.c
@@ -98,9 +98,6 @@ static void rxrpc_conn_retransmit_call(struct rxrpc_connection *conn,
pkt.info.rwind = htonl(rxrpc_rx_window_size);
pkt.info.jumbo_max = htonl(rxrpc_rx_jumbo_max);
len += sizeof(pkt.ack) + sizeof(pkt.info);
-
- trace_rxrpc_tx_ack(NULL, chan->last_seq, 0,
- RXRPC_ACK_DUPLICATE, 0);
break;
}
@@ -122,6 +119,8 @@ 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, chan->last_seq, 0,
+ RXRPC_ACK_DUPLICATE, 0);
_proto("Tx ACK %%%u [re]", serial);
break;
}
diff --git a/net/rxrpc/output.c b/net/rxrpc/output.c
index 5c1e008a5323..e47fbd1c836d 100644
--- a/net/rxrpc/output.c
+++ b/net/rxrpc/output.c
@@ -177,7 +177,7 @@ int rxrpc_send_call_packet(struct rxrpc_call *call, u8 type)
pkt->whdr.serial = htonl(serial);
switch (type) {
case RXRPC_PACKET_TYPE_ACK:
- trace_rxrpc_tx_ack(call,
+ trace_rxrpc_tx_ack(call, serial,
ntohl(pkt->ack.firstPacket),
ntohl(pkt->ack.serial),
pkt->ack.reason, pkt->ack.nAcks);
@@ -275,6 +275,8 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, struct sk_buff *skb)
if (IS_ENABLED(CONFIG_AF_RXRPC_INJECT_LOSS)) {
static int lose;
if ((lose++ & 7) == 7) {
+ trace_rxrpc_tx_data(call, sp->hdr.seq, serial,
+ whdr.flags, true);
rxrpc_lose_skb(skb, rxrpc_skb_tx_lost);
_leave(" = 0 [lose]");
return 0;
@@ -302,6 +304,7 @@ int rxrpc_send_data_packet(struct rxrpc_call *call, struct sk_buff *skb)
goto send_fragmentable;
done:
+ trace_rxrpc_tx_data(call, sp->hdr.seq, serial, whdr.flags, false);
if (ret >= 0) {
ktime_t now = ktime_get_real();
skb->tstamp = now;
^ permalink raw reply related [flat|nested] 21+ messages in thread* [PATCH net-next 13/15] rxrpc: Add a tracepoint to log injected Rx packet loss
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (11 preceding siblings ...)
2016-09-23 15:16 ` [PATCH net-next 12/15] rxrpc: Add data Tx tracepoint and adjust Tx ACK tracepoint David Howells
@ 2016-09-23 15:16 ` David Howells
2016-09-23 15:16 ` [PATCH net-next 14/15] rxrpc: Add tracepoint for ACK proposal David Howells
` (2 subsequent siblings)
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:16 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
Add a tracepoint to log received packets that get discarded due to Rx
packet loss.
Signed-off-by: David Howells <dhowells@redhat.com>
---
include/trace/events/rxrpc.h | 21 +++++++++++++++++++++
net/rxrpc/input.c | 11 +++++------
2 files changed, 26 insertions(+), 6 deletions(-)
diff --git a/include/trace/events/rxrpc.h b/include/trace/events/rxrpc.h
index 6001bf93dc79..9413b17ba04b 100644
--- a/include/trace/events/rxrpc.h
+++ b/include/trace/events/rxrpc.h
@@ -484,6 +484,27 @@ TRACE_EVENT(rxrpc_timer,
__entry->timer - __entry->now)
);
+TRACE_EVENT(rxrpc_rx_lose,
+ TP_PROTO(struct rxrpc_skb_priv *sp),
+
+ TP_ARGS(sp),
+
+ TP_STRUCT__entry(
+ __field_struct(struct rxrpc_host_header, hdr )
+ ),
+
+ TP_fast_assign(
+ memcpy(&__entry->hdr, &sp->hdr, sizeof(__entry->hdr));
+ ),
+
+ TP_printk("%08x:%08x:%08x:%04x %08x %08x %02x %02x %s *LOSE*",
+ __entry->hdr.epoch, __entry->hdr.cid,
+ __entry->hdr.callNumber, __entry->hdr.serviceId,
+ __entry->hdr.serial, __entry->hdr.seq,
+ __entry->hdr.type, __entry->hdr.flags,
+ __entry->hdr.type <= 15 ? rxrpc_pkts[__entry->hdr.type] : "?UNK")
+ );
+
#endif /* _TRACE_RXRPC_H */
/* This part must be outside protection */
diff --git a/net/rxrpc/input.c b/net/rxrpc/input.c
index fb3e2f6afa3b..19b1e189f5dc 100644
--- a/net/rxrpc/input.c
+++ b/net/rxrpc/input.c
@@ -837,20 +837,19 @@ void rxrpc_data_ready(struct sock *udp_sk)
skb_orphan(skb);
sp = rxrpc_skb(skb);
+ /* dig out the RxRPC connection details */
+ if (rxrpc_extract_header(sp, skb) < 0)
+ goto bad_message;
+
if (IS_ENABLED(CONFIG_AF_RXRPC_INJECT_LOSS)) {
static int lose;
if ((lose++ & 7) == 7) {
+ trace_rxrpc_rx_lose(sp);
rxrpc_lose_skb(skb, rxrpc_skb_rx_lost);
return;
}
}
- _net("Rx UDP packet from %08x:%04hu",
- ntohl(ip_hdr(skb)->saddr), ntohs(udp_hdr(skb)->source));
-
- /* dig out the RxRPC connection details */
- if (rxrpc_extract_header(sp, skb) < 0)
- goto bad_message;
trace_rxrpc_rx_packet(sp);
_net("Rx RxRPC %s ep=%x call=%x:%x",
^ permalink raw reply related [flat|nested] 21+ messages in thread* [PATCH net-next 14/15] rxrpc: Add tracepoint for ACK proposal
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (12 preceding siblings ...)
2016-09-23 15:16 ` [PATCH net-next 13/15] rxrpc: Add a tracepoint to log injected Rx packet loss David Howells
@ 2016-09-23 15:16 ` David Howells
2016-09-23 15:17 ` [PATCH net-next 15/15] rxrpc: Add a tracepoint to log which packets will be retransmitted David Howells
2016-09-24 12:24 ` [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Miller
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:16 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
Add a tracepoint to log proposed ACKs, including whether the proposal is
used to update a pending ACK or is discarded in favour of an easlier,
higher priority ACK.
Whilst we're at it, get rid of the rxrpc_acks() function and access the
name array directly. We do, however, need to validate the ACK reason
number given to trace_rxrpc_rx_ack() to make sure we don't overrun the
array.
Signed-off-by: David Howells <dhowells@redhat.com>
---
include/rxrpc/packet.h | 1 +
include/trace/events/rxrpc.h | 42 ++++++++++++++++++++++++++++++++++++++++--
net/rxrpc/ar-internal.h | 25 +++++++++++++++++++++++--
net/rxrpc/call_event.c | 21 ++++++++++++++-------
net/rxrpc/input.c | 19 +++++++++++++------
net/rxrpc/misc.c | 30 +++++++++++++++++++-----------
net/rxrpc/output.c | 3 ++-
net/rxrpc/recvmsg.c | 3 ++-
8 files changed, 114 insertions(+), 30 deletions(-)
diff --git a/include/rxrpc/packet.h b/include/rxrpc/packet.h
index fd6eb3a60a8c..703a64b4681a 100644
--- a/include/rxrpc/packet.h
+++ b/include/rxrpc/packet.h
@@ -123,6 +123,7 @@ struct rxrpc_ackpacket {
#define RXRPC_ACK_PING_RESPONSE 7 /* response to RXRPC_ACK_PING */
#define RXRPC_ACK_DELAY 8 /* nothing happened since received packet */
#define RXRPC_ACK_IDLE 9 /* ACK due to fully received ACK window */
+#define RXRPC_ACK__INVALID 10 /* Representation of invalid ACK reason */
uint8_t nAcks; /* number of ACKs */
#define RXRPC_MAXACKS 255
diff --git a/include/trace/events/rxrpc.h b/include/trace/events/rxrpc.h
index 9413b17ba04b..d67a8c6b085a 100644
--- a/include/trace/events/rxrpc.h
+++ b/include/trace/events/rxrpc.h
@@ -251,7 +251,7 @@ TRACE_EVENT(rxrpc_rx_ack,
TP_printk("c=%p %s f=%08x n=%u",
__entry->call,
- rxrpc_acks(__entry->reason),
+ rxrpc_ack_names[__entry->reason],
__entry->first,
__entry->n_acks)
);
@@ -314,7 +314,7 @@ TRACE_EVENT(rxrpc_tx_ack,
TP_printk(" c=%p ACK %08x %s f=%08x r=%08x n=%u",
__entry->call,
__entry->serial,
- rxrpc_acks(__entry->reason),
+ rxrpc_ack_names[__entry->reason],
__entry->ack_first,
__entry->ack_serial,
__entry->n_acks)
@@ -505,6 +505,44 @@ TRACE_EVENT(rxrpc_rx_lose,
__entry->hdr.type <= 15 ? rxrpc_pkts[__entry->hdr.type] : "?UNK")
);
+TRACE_EVENT(rxrpc_propose_ack,
+ TP_PROTO(struct rxrpc_call *call, enum rxrpc_propose_ack_trace why,
+ u8 ack_reason, rxrpc_serial_t serial, bool immediate,
+ bool background, enum rxrpc_propose_ack_outcome outcome),
+
+ TP_ARGS(call, why, ack_reason, serial, immediate, background,
+ outcome),
+
+ TP_STRUCT__entry(
+ __field(struct rxrpc_call *, call )
+ __field(enum rxrpc_propose_ack_trace, why )
+ __field(rxrpc_serial_t, serial )
+ __field(u8, ack_reason )
+ __field(bool, immediate )
+ __field(bool, background )
+ __field(enum rxrpc_propose_ack_outcome, outcome )
+ ),
+
+ TP_fast_assign(
+ __entry->call = call;
+ __entry->why = why;
+ __entry->serial = serial;
+ __entry->ack_reason = ack_reason;
+ __entry->immediate = immediate;
+ __entry->background = background;
+ __entry->outcome = outcome;
+ ),
+
+ TP_printk("c=%p %s %s r=%08x i=%u b=%u%s",
+ __entry->call,
+ rxrpc_propose_ack_traces[__entry->why],
+ rxrpc_ack_names[__entry->ack_reason],
+ __entry->serial,
+ __entry->immediate,
+ __entry->background,
+ rxrpc_propose_ack_outcomes[__entry->outcome])
+ );
+
#endif /* _TRACE_RXRPC_H */
/* This part must be outside protection */
diff --git a/net/rxrpc/ar-internal.h b/net/rxrpc/ar-internal.h
index e564eca75985..042dbcc52654 100644
--- a/net/rxrpc/ar-internal.h
+++ b/net/rxrpc/ar-internal.h
@@ -689,8 +689,28 @@ enum rxrpc_timer_trace {
extern const char rxrpc_timer_traces[rxrpc_timer__nr_trace][8];
+enum rxrpc_propose_ack_trace {
+ rxrpc_propose_ack_input_data,
+ rxrpc_propose_ack_ping_for_params,
+ rxrpc_propose_ack_respond_to_ack,
+ rxrpc_propose_ack_respond_to_ping,
+ rxrpc_propose_ack_retry_tx,
+ rxrpc_propose_ack_terminal_ack,
+ rxrpc_propose_ack__nr_trace
+};
+
+enum rxrpc_propose_ack_outcome {
+ rxrpc_propose_ack_use,
+ rxrpc_propose_ack_update,
+ rxrpc_propose_ack_subsume,
+ rxrpc_propose_ack__nr_outcomes
+};
+
+extern const char rxrpc_propose_ack_traces[rxrpc_propose_ack__nr_trace][8];
+extern const char *const rxrpc_propose_ack_outcomes[rxrpc_propose_ack__nr_outcomes];
+
extern const char *const rxrpc_pkts[];
-extern const char *rxrpc_acks(u8 reason);
+extern const char const rxrpc_ack_names[RXRPC_ACK__INVALID + 1][4];
#include <trace/events/rxrpc.h>
@@ -719,7 +739,8 @@ int rxrpc_reject_call(struct rxrpc_sock *);
* call_event.c
*/
void rxrpc_set_timer(struct rxrpc_call *, enum rxrpc_timer_trace);
-void rxrpc_propose_ACK(struct rxrpc_call *, u8, u16, u32, bool, bool);
+void rxrpc_propose_ACK(struct rxrpc_call *, u8, u16, u32, bool, bool,
+ enum rxrpc_propose_ack_trace);
void rxrpc_process_call(struct work_struct *);
/*
diff --git a/net/rxrpc/call_event.c b/net/rxrpc/call_event.c
index 90e970ba048a..fd5b11339ffb 100644
--- a/net/rxrpc/call_event.c
+++ b/net/rxrpc/call_event.c
@@ -58,14 +58,13 @@ out:
*/
static void __rxrpc_propose_ACK(struct rxrpc_call *call, u8 ack_reason,
u16 skew, u32 serial, bool immediate,
- bool background)
+ bool background,
+ enum rxrpc_propose_ack_trace why)
{
+ enum rxrpc_propose_ack_outcome outcome = rxrpc_propose_ack_use;
unsigned long now, ack_at, expiry = rxrpc_soft_ack_delay;
s8 prior = rxrpc_ack_priority[ack_reason];
- _enter("{%d},%s,%%%x,%u",
- call->debug_id, rxrpc_acks(ack_reason), serial, immediate);
-
/* Update DELAY, IDLE, REQUESTED and PING_RESPONSE ACK serial
* numbers, but we don't alter the timeout.
*/
@@ -74,15 +73,18 @@ static void __rxrpc_propose_ACK(struct rxrpc_call *call, u8 ack_reason,
call->ackr_reason, rxrpc_ack_priority[call->ackr_reason]);
if (ack_reason == call->ackr_reason) {
if (RXRPC_ACK_UPDATEABLE & (1 << ack_reason)) {
+ outcome = rxrpc_propose_ack_update;
call->ackr_serial = serial;
call->ackr_skew = skew;
}
if (!immediate)
- return;
+ goto trace;
} else if (prior > rxrpc_ack_priority[call->ackr_reason]) {
call->ackr_reason = ack_reason;
call->ackr_serial = serial;
call->ackr_skew = skew;
+ } else {
+ outcome = rxrpc_propose_ack_subsume;
}
switch (ack_reason) {
@@ -124,17 +126,22 @@ static void __rxrpc_propose_ACK(struct rxrpc_call *call, u8 ack_reason,
rxrpc_set_timer(call, rxrpc_timer_set_for_ack);
}
}
+
+trace:
+ trace_rxrpc_propose_ack(call, why, ack_reason, serial, immediate,
+ background, outcome);
}
/*
* propose an ACK be sent, locking the call structure
*/
void rxrpc_propose_ACK(struct rxrpc_call *call, u8 ack_reason,
- u16 skew, u32 serial, bool immediate, bool background)
+ u16 skew, u32 serial, bool immediate, bool background,
+ enum rxrpc_propose_ack_trace why)
{
spin_lock_bh(&call->lock);
__rxrpc_propose_ACK(call, ack_reason, skew, serial,
- immediate, background);
+ immediate, background, why);
spin_unlock_bh(&call->lock);
}
diff --git a/net/rxrpc/input.c b/net/rxrpc/input.c
index 19b1e189f5dc..349698d87ad1 100644
--- a/net/rxrpc/input.c
+++ b/net/rxrpc/input.c
@@ -49,7 +49,8 @@ static void rxrpc_send_ping(struct rxrpc_call *call, struct sk_buff *skb,
if (call->peer->rtt_usage < 3 ||
ktime_before(ktime_add_ms(call->peer->rtt_last_req, 1000), now))
rxrpc_propose_ACK(call, RXRPC_ACK_PING, skew, sp->hdr.serial,
- true, true);
+ true, true,
+ rxrpc_propose_ack_ping_for_params);
}
/*
@@ -382,7 +383,8 @@ skip:
ack:
if (ack)
rxrpc_propose_ACK(call, ack, skew, ack_serial,
- immediate_ack, true);
+ immediate_ack, true,
+ rxrpc_propose_ack_input_data);
if (sp->hdr.seq == READ_ONCE(call->rx_hard_ack) + 1)
rxrpc_notify_socket(call);
@@ -539,6 +541,7 @@ static void rxrpc_input_soft_acks(struct rxrpc_call *call, u8 *acks,
static void rxrpc_input_ack(struct rxrpc_call *call, struct sk_buff *skb,
u16 skew)
{
+ u8 ack_reason;
struct rxrpc_skb_priv *sp = rxrpc_skb(skb);
union {
struct rxrpc_ackpacket ack;
@@ -561,8 +564,10 @@ static void rxrpc_input_ack(struct rxrpc_call *call, struct sk_buff *skb,
first_soft_ack = ntohl(buf.ack.firstPacket);
hard_ack = first_soft_ack - 1;
nr_acks = buf.ack.nAcks;
+ ack_reason = (buf.ack.reason < RXRPC_ACK__INVALID ?
+ buf.ack.reason : RXRPC_ACK__INVALID);
- trace_rxrpc_rx_ack(call, first_soft_ack, buf.ack.reason, nr_acks);
+ trace_rxrpc_rx_ack(call, first_soft_ack, ack_reason, nr_acks);
_proto("Rx ACK %%%u { m=%hu f=#%u p=#%u s=%%%u r=%s n=%u }",
sp->hdr.serial,
@@ -570,7 +575,7 @@ static void rxrpc_input_ack(struct rxrpc_call *call, struct sk_buff *skb,
first_soft_ack,
ntohl(buf.ack.previousPacket),
acked_serial,
- rxrpc_acks(buf.ack.reason),
+ rxrpc_ack_names[ack_reason],
buf.ack.nAcks);
if (buf.ack.reason == RXRPC_ACK_PING_RESPONSE)
@@ -583,10 +588,12 @@ static void rxrpc_input_ack(struct rxrpc_call *call, struct sk_buff *skb,
if (buf.ack.reason == RXRPC_ACK_PING) {
_proto("Rx ACK %%%u PING Request", sp->hdr.serial);
rxrpc_propose_ACK(call, RXRPC_ACK_PING_RESPONSE,
- skew, sp->hdr.serial, true, true);
+ skew, sp->hdr.serial, true, true,
+ rxrpc_propose_ack_respond_to_ping);
} else if (sp->hdr.flags & RXRPC_REQUEST_ACK) {
rxrpc_propose_ACK(call, RXRPC_ACK_REQUESTED,
- skew, sp->hdr.serial, true, true);
+ skew, sp->hdr.serial, true, true,
+ rxrpc_propose_ack_respond_to_ack);
}
offset = sp->offset + nr_acks + 3;
diff --git a/net/rxrpc/misc.c b/net/rxrpc/misc.c
index fa9942fabdf2..1ca14835d87f 100644
--- a/net/rxrpc/misc.c
+++ b/net/rxrpc/misc.c
@@ -91,17 +91,10 @@ const s8 rxrpc_ack_priority[] = {
[RXRPC_ACK_PING] = 9,
};
-const char *rxrpc_acks(u8 reason)
-{
- static const char *const str[] = {
- "---", "REQ", "DUP", "OOS", "WIN", "MEM", "PNG", "PNR", "DLY",
- "IDL", "-?-"
- };
-
- if (reason >= ARRAY_SIZE(str))
- reason = ARRAY_SIZE(str) - 1;
- return str[reason];
-}
+const char const rxrpc_ack_names[RXRPC_ACK__INVALID + 1][4] = {
+ "---", "REQ", "DUP", "OOS", "WIN", "MEM", "PNG", "PNR", "DLY",
+ "IDL", "-?-"
+};
const char rxrpc_skb_traces[rxrpc_skb__nr_trace][7] = {
[rxrpc_skb_rx_cleaned] = "Rx CLN",
@@ -202,3 +195,18 @@ const char rxrpc_timer_traces[rxrpc_timer__nr_trace][8] = {
[rxrpc_timer_set_for_send] = "SetTx ",
[rxrpc_timer_set_for_resend] = "SetRTx",
};
+
+const char rxrpc_propose_ack_traces[rxrpc_propose_ack__nr_trace][8] = {
+ [rxrpc_propose_ack_input_data] = "DataIn ",
+ [rxrpc_propose_ack_ping_for_params] = "Params ",
+ [rxrpc_propose_ack_respond_to_ack] = "Rsp2Ack",
+ [rxrpc_propose_ack_respond_to_ping] = "Rsp2Png",
+ [rxrpc_propose_ack_retry_tx] = "RetryTx",
+ [rxrpc_propose_ack_terminal_ack] = "ClTerm ",
+};
+
+const char *const rxrpc_propose_ack_outcomes[rxrpc_propose_ack__nr_outcomes] = {
+ [rxrpc_propose_ack_use] = "",
+ [rxrpc_propose_ack_update] = " Update",
+ [rxrpc_propose_ack_subsume] = " Subsume",
+};
diff --git a/net/rxrpc/output.c b/net/rxrpc/output.c
index e47fbd1c836d..0c563e325c9d 100644
--- a/net/rxrpc/output.c
+++ b/net/rxrpc/output.c
@@ -210,7 +210,8 @@ int rxrpc_send_call_packet(struct rxrpc_call *call, u8 type)
rxrpc_propose_ACK(call, pkt->ack.reason,
ntohs(pkt->ack.maxSkew),
ntohl(pkt->ack.serial),
- true, true);
+ true, true,
+ rxrpc_propose_ack_retry_tx);
break;
case RXRPC_PACKET_TYPE_ABORT:
break;
diff --git a/net/rxrpc/recvmsg.c b/net/rxrpc/recvmsg.c
index 99e4c0ae30f1..8c7f3de45bac 100644
--- a/net/rxrpc/recvmsg.c
+++ b/net/rxrpc/recvmsg.c
@@ -141,7 +141,8 @@ static void rxrpc_end_rx_phase(struct rxrpc_call *call)
ASSERTCMP(call->rx_hard_ack, ==, call->rx_top);
if (call->state == RXRPC_CALL_CLIENT_RECV_REPLY) {
- rxrpc_propose_ACK(call, RXRPC_ACK_IDLE, 0, 0, true, false);
+ rxrpc_propose_ACK(call, RXRPC_ACK_IDLE, 0, 0, true, false,
+ rxrpc_propose_ack_terminal_ack);
rxrpc_send_call_packet(call, RXRPC_PACKET_TYPE_ACK);
}
^ permalink raw reply related [flat|nested] 21+ messages in thread* [PATCH net-next 15/15] rxrpc: Add a tracepoint to log which packets will be retransmitted
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (13 preceding siblings ...)
2016-09-23 15:16 ` [PATCH net-next 14/15] rxrpc: Add tracepoint for ACK proposal David Howells
@ 2016-09-23 15:17 ` David Howells
2016-09-24 12:24 ` [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Miller
15 siblings, 0 replies; 21+ messages in thread
From: David Howells @ 2016-09-23 15:17 UTC (permalink / raw)
To: netdev; +Cc: dhowells, linux-afs, linux-kernel
Add a tracepoint to log in rxrpc_resend() which packets will be
retransmitted. Note that if a positive ACK comes in whilst we have dropped
the lock to retransmit another packet, the actual retransmission may not
happen, though some of the effects will (such as altering the congestion
management).
Signed-off-by: David Howells <dhowells@redhat.com>
---
include/trace/events/rxrpc.h | 27 +++++++++++++++++++++++++++
net/rxrpc/call_event.c | 2 ++
2 files changed, 29 insertions(+)
diff --git a/include/trace/events/rxrpc.h b/include/trace/events/rxrpc.h
index d67a8c6b085a..56475497043d 100644
--- a/include/trace/events/rxrpc.h
+++ b/include/trace/events/rxrpc.h
@@ -543,6 +543,33 @@ TRACE_EVENT(rxrpc_propose_ack,
rxrpc_propose_ack_outcomes[__entry->outcome])
);
+TRACE_EVENT(rxrpc_retransmit,
+ TP_PROTO(struct rxrpc_call *call, rxrpc_seq_t seq, u8 annotation,
+ s64 expiry),
+
+ TP_ARGS(call, seq, annotation, expiry),
+
+ TP_STRUCT__entry(
+ __field(struct rxrpc_call *, call )
+ __field(rxrpc_seq_t, seq )
+ __field(u8, annotation )
+ __field(s64, expiry )
+ ),
+
+ TP_fast_assign(
+ __entry->call = call;
+ __entry->seq = seq;
+ __entry->annotation = annotation;
+ __entry->expiry = expiry;
+ ),
+
+ TP_printk("c=%p q=%x a=%02x xp=%lld",
+ __entry->call,
+ __entry->seq,
+ __entry->annotation,
+ __entry->expiry)
+ );
+
#endif /* _TRACE_RXRPC_H */
/* This part must be outside protection */
diff --git a/net/rxrpc/call_event.c b/net/rxrpc/call_event.c
index fd5b11339ffb..a78a92fe5d77 100644
--- a/net/rxrpc/call_event.c
+++ b/net/rxrpc/call_event.c
@@ -196,6 +196,8 @@ static void rxrpc_resend(struct rxrpc_call *call)
/* Okay, we need to retransmit a packet. */
call->rxtx_annotations[ix] = RXRPC_TX_ANNO_RETRANS | annotation;
+ trace_rxrpc_retransmit(call, seq, annotation | anno_type,
+ ktime_to_ns(ktime_sub(skb->tstamp, max_age)));
}
resend_at = ktime_sub(ktime_add_ms(oldest, rxrpc_resend_timeout), now);
^ permalink raw reply related [flat|nested] 21+ messages in thread* Re: [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints
2016-09-23 15:15 [PATCH net-next 00/15] rxrpc: Bug fixes and tracepoints David Howells
` (14 preceding siblings ...)
2016-09-23 15:17 ` [PATCH net-next 15/15] rxrpc: Add a tracepoint to log which packets will be retransmitted David Howells
@ 2016-09-24 12:24 ` David Miller
15 siblings, 0 replies; 21+ messages in thread
From: David Miller @ 2016-09-24 12:24 UTC (permalink / raw)
To: dhowells; +Cc: netdev, linux-afs, linux-kernel
From: David Howells <dhowells@redhat.com>
Date: Fri, 23 Sep 2016 16:15:17 +0100
> Here are a bunch of bug fixes:
...
> Tagged thusly:
>
> git://git.kernel.org/pub/scm/linux/kernel/git/dhowells/linux-fs.git
> rxrpc-rewrite-20160923
Pulled, thanks David.
^ permalink raw reply [flat|nested] 21+ messages in thread