Re: [PATCH 2/3] sctp_diag: export timer value only if it is active

[Phil Sutter]

On Wed, Aug 03, 2016 at 04:46:52PM -0300, Marcelo Ricardo Leitner wrote:
> On Wed, Aug 03, 2016 at 09:28:13PM +0200, Phil Sutter wrote:
> > Hi,
> > 
> > On Sat, Jul 30, 2016 at 09:25:42PM +0800, Xin Long wrote:
> > [...]
> > > Now for the transport's info,  we only choose primary_path to dump.
> > > It means we should fix this by getting the left time to expire from
> > > primary transport t->T3_rtx_timer. like:
> > > 
> > > r->idiag_expires = jiffies_to_msecs(
> > > -   asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);
> > > +   asoc->peer.primary_path->T3_rtx_timer.expires - jiffies);
> > > 
> > > but yes, need to check with timer_pending firstly.
> > 
> > I have changed the code to this:
> > 
> > | struct timer_list *t3_rtx = >peer.primary_path->T3_rtx_timer;
> > | 
> > | [...]
> > | 
> > | if (timer_pending(t3_rtx)) {
> > |   r->idiag_timer = SCTP_EVENT_TIMEOUT_T3_RTX;
> > |   r->idiag_retrans = asoc->rtx_data_chunks;
> > |   r->idiag_expires = jiffies_to_msecs(t3_rtx->expires - jiffies);
> > | }
> > 
> > And I'm still getting what appears to be negative values sometimes. Here
> > are some of the common values in hex when busy looping sctp_diag
> > requests:
> > 
> > 0
> > 7530
> > 100
> > 300
> > 600
> > 1400
> > 9400
> > ed69
> > ea00
> 
> Are these for the same asoc? I wouldn't expect it to vary that much.
> Even the 100 it's already just too big to be reasonable. That's
> 16777 seconds. Only 0x7530 is reasonable, 30 seconds.

Nope, those are not for the same asoc. Also, I piped the gathered values
through 'sort -u', so they are not in chronological order.

> > While I wonder a bit about the zero, the last two seem to be unsigned
> > underruns. Do I still have to check for 't3_rtx->expires > jiffies' or
> > am I missing something?
> 
> You shouldn't have to because then the timer wouldn't be pending. 
> 
> I don't know what can be wrong in there. Could it be the application not
> checking if the timer was exported or not before dumping it? 

Nope, the application is 'ss' in that case (with added debug output to
get the raw values), but your shot wasn't that long after all: I
discovered that in sctp_diag.ko, the inet_diag_msg object to be sent to
userspace is not cleared initially. So by populating r->idiag_timer
conditionally, I managed to leak random data to user space. DOH!

Thanks for the pointer,

Phil

Re: [PATCH 2/3] sctp_diag: export timer value only if it is active

[Marcelo Ricardo Leitner]

On Wed, Aug 03, 2016 at 09:28:13PM +0200, Phil Sutter wrote:
> Hi,
> 
> On Sat, Jul 30, 2016 at 09:25:42PM +0800, Xin Long wrote:
> [...]
> > Now for the transport's info,  we only choose primary_path to dump.
> > It means we should fix this by getting the left time to expire from
> > primary transport t->T3_rtx_timer. like:
> > 
> > r->idiag_expires = jiffies_to_msecs(
> > -   asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);
> > +   asoc->peer.primary_path->T3_rtx_timer.expires - jiffies);
> > 
> > but yes, need to check with timer_pending firstly.
> 
> I have changed the code to this:
> 
> | struct timer_list *t3_rtx = >peer.primary_path->T3_rtx_timer;
> | 
> | [...]
> | 
> | if (timer_pending(t3_rtx)) {
> | r->idiag_timer = SCTP_EVENT_TIMEOUT_T3_RTX;
> | r->idiag_retrans = asoc->rtx_data_chunks;
> | r->idiag_expires = jiffies_to_msecs(t3_rtx->expires - jiffies);
> | }
> 
> And I'm still getting what appears to be negative values sometimes. Here
> are some of the common values in hex when busy looping sctp_diag
> requests:
> 
> 0
> 7530
> 100
> 300
> 600
> 1400
> 9400
> ed69
> ea00

Are these for the same asoc? I wouldn't expect it to vary that much.
Even the 100 it's already just too big to be reasonable. That's
16777 seconds. Only 0x7530 is reasonable, 30 seconds.

> 
> While I wonder a bit about the zero, the last two seem to be unsigned
> underruns. Do I still have to check for 't3_rtx->expires > jiffies' or
> am I missing something?

You shouldn't have to because then the timer wouldn't be pending. 

I don't know what can be wrong in there. Could it be the application not
checking if the timer was exported or not before dumping it? 

  Marcelo

Re: [PATCH 2/3] sctp_diag: export timer value only if it is active

[Phil Sutter]

Hi,

On Sat, Jul 30, 2016 at 09:25:42PM +0800, Xin Long wrote:
[...]
> Now for the transport's info,  we only choose primary_path to dump.
> It means we should fix this by getting the left time to expire from
> primary transport t->T3_rtx_timer. like:
> 
> r->idiag_expires = jiffies_to_msecs(
> -   asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);
> +   asoc->peer.primary_path->T3_rtx_timer.expires - jiffies);
> 
> but yes, need to check with timer_pending firstly.

I have changed the code to this:

| struct timer_list *t3_rtx = >peer.primary_path->T3_rtx_timer;
| 
| [...]
| 
| if (timer_pending(t3_rtx)) {
|   r->idiag_timer = SCTP_EVENT_TIMEOUT_T3_RTX;
|   r->idiag_retrans = asoc->rtx_data_chunks;
|   r->idiag_expires = jiffies_to_msecs(t3_rtx->expires - jiffies);
| }

And I'm still getting what appears to be negative values sometimes. Here
are some of the common values in hex when busy looping sctp_diag
requests:

0
7530
100
300
600
1400
9400
ed69
ea00

While I wonder a bit about the zero, the last two seem to be unsigned
underruns. Do I still have to check for 't3_rtx->expires > jiffies' or
am I missing something?

Thanks, Phil

Re: [PATCH 2/3] sctp_diag: export timer value only if it is active

[Xin Long]

>
> I'll look into this next week. One early question: Does the above mean
> we are printing the primary path's timer value for every assoc? If so,
> shouldn't we do that for just the EP or the primary path's assoc even?
>
Nope, we can't say "the primary path's assoc".

Every assoc has their own primary path, even these assocs belong
to one EP.  you can see it from (asoc->peer.primary_path).

Re: [PATCH 2/3] sctp_diag: export timer value only if it is active

[Phil Sutter]

On Sat, Jul 30, 2016 at 10:33:48AM -0300, Marcelo Ricardo Leitner wrote:
> 
> 
> Em 30-07-2016 10:25, Xin Long escreveu:
> >>> diff --git a/net/sctp/sctp_diag.c b/net/sctp/sctp_diag.c
> >>> index f69edcf219e51..0ad6033a7330c 100644
> >>> --- a/net/sctp/sctp_diag.c
> >>> +++ b/net/sctp/sctp_diag.c
> >>> @@ -40,10 +40,12 @@ static void inet_diag_msg_sctpasoc_fill(struct 
> >>> inet_diag_msg *r,
> >>>   }
> >>>
> >>>   r->idiag_state = asoc->state;
> >>> - r->idiag_timer = SCTP_EVENT_TIMEOUT_T3_RTX;
> >>> - r->idiag_retrans = asoc->rtx_data_chunks;
> >>> - r->idiag_expires = jiffies_to_msecs(
> >>> - asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);
> >>
> >> I think we have two issues here, prior to your patch, but I noticed
> >> while reviewing it :-)
> >>
> >> This array is actually not based on jiffies but on intervals instead, as
> >> per:
> >>
> >> sm_sideeffect.c:
> >> case SCTP_CMD_TIMER_START:   [1]
> >> timer = >timers[cmd->obj.to];
> >> timeout = asoc->timeouts[cmd->obj.to];   <---
> >> BUG_ON(!timeout);
> >>
> >> timer->expires = jiffies + timeout;  <---
> > understood.
> >
> >>
> >> But more importantly, this array is actually not used for this timeout
> >> and the timeout is sctp_transport dependant, as per:
> >>
> >> /* Schedule retransmission on the given transport */
> >> void sctp_transport_immediate_rtx(struct sctp_transport *t)
> >> {
> >> /* Stop pending T3_rtx_timer */
> >> if (del_timer(>T3_rtx_timer))
> >> sctp_transport_put(t);
> >>
> >> sctp_retransmit(>asoc->outqueue, t, SCTP_RTXR_T3_RTX);
> >> if (!timer_pending(>T3_rtx_timer)) {
> >> if (!mod_timer(>T3_rtx_timer, jiffies + t->rto))
> >>  
> >> sctp_transport_hold(t);
> >>
> >> Note how on sctp_get_sctp_info() it fetches the RTO (which is T3_RTX)
> >> this way:
> >> info->sctpi_p_rto = jiffies_to_msecs(prim->rto);
> >> If we want to know how long is left for the timer to expire, we have to
> >> read directly from it.
> > you are right, 3 timers (T3_tx, hb, rtx_data_chunks) are per transport.
> >
> >>
> >> With git grep -A 1 TIMER_START we can confirm that [1] is never hit for
> >> SCTP_EVENT_TIMEOUT_T3_RTX. Yet, the asoc is allocated with kzalloc(), so
> >> I guess you were just reading -jiffies in there.
> >>
> >> Note however that the stats rtx_data_chunks is the accumulated stats,
> >> it's good, and that we may have multiple T3 timers running at once, with
> >> different timeouts.
> >>
> >> Xin, ideas on how we can fix this? I'm not sure if we can dump
> >> per-transport info in there. Not as it is now, I guess.
> > It's not that easy to dump all transports info besed on current sctp_diag 
> > codes.
> 
> Okay
> 
> >
> > Now for the transport's info,  we only choose primary_path to dump.
> 
> Okay
> 
> > It means we should fix this by getting the left time to expire from
> > primary transport t->T3_rtx_timer. like:
> >
> > r->idiag_expires = jiffies_to_msecs(
> > -   asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);
> > +   asoc->peer.primary_path->T3_rtx_timer.expires - jiffies);
> >
> > but yes, need to check with timer_pending firstly.
> 
> Yes :)
> 
> >
> > what do  you think ?
> >
> 
> Makes sense, LGTM.
> 
> Phil, not sure how you want to proceed here. Wanna handle the change above?

I'll look into this next week. One early question: Does the above mean
we are printing the primary path's timer value for every assoc? If so,
shouldn't we do that for just the EP or the primary path's assoc even?

Thanks, Phil

Re: [PATCH 2/3] sctp_diag: export timer value only if it is active

[Marcelo Ricardo Leitner]

Em 30-07-2016 10:25, Xin Long escreveu:

diff --git a/net/sctp/sctp_diag.c b/net/sctp/sctp_diag.c
index f69edcf219e51..0ad6033a7330c 100644
--- a/net/sctp/sctp_diag.c
+++ b/net/sctp/sctp_diag.c
@@ -40,10 +40,12 @@ static void inet_diag_msg_sctpasoc_fill(struct 
inet_diag_msg *r,
  }

  r->idiag_state = asoc->state;
- r->idiag_timer = SCTP_EVENT_TIMEOUT_T3_RTX;
- r->idiag_retrans = asoc->rtx_data_chunks;
- r->idiag_expires = jiffies_to_msecs(
- asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);


I think we have two issues here, prior to your patch, but I noticed
while reviewing it :-)

This array is actually not based on jiffies but on intervals instead, as
per:

sm_sideeffect.c:
case SCTP_CMD_TIMER_START:   [1]
timer = >timers[cmd->obj.to];
timeout = asoc->timeouts[cmd->obj.to];   <---
BUG_ON(!timeout);

timer->expires = jiffies + timeout;  <---

understood.



But more importantly, this array is actually not used for this timeout
and the timeout is sctp_transport dependant, as per:

/* Schedule retransmission on the given transport */
void sctp_transport_immediate_rtx(struct sctp_transport *t)
{
/* Stop pending T3_rtx_timer */
if (del_timer(>T3_rtx_timer))
sctp_transport_put(t);

sctp_retransmit(>asoc->outqueue, t, SCTP_RTXR_T3_RTX);
if (!timer_pending(>T3_rtx_timer)) {
if (!mod_timer(>T3_rtx_timer, jiffies + t->rto))
 
sctp_transport_hold(t);

Note how on sctp_get_sctp_info() it fetches the RTO (which is T3_RTX)
this way:
info->sctpi_p_rto = jiffies_to_msecs(prim->rto);
If we want to know how long is left for the timer to expire, we have to
read directly from it.

you are right, 3 timers (T3_tx, hb, rtx_data_chunks) are per transport.



With git grep -A 1 TIMER_START we can confirm that [1] is never hit for
SCTP_EVENT_TIMEOUT_T3_RTX. Yet, the asoc is allocated with kzalloc(), so
I guess you were just reading -jiffies in there.

Note however that the stats rtx_data_chunks is the accumulated stats,
it's good, and that we may have multiple T3 timers running at once, with
different timeouts.

Xin, ideas on how we can fix this? I'm not sure if we can dump
per-transport info in there. Not as it is now, I guess.

It's not that easy to dump all transports info besed on current sctp_diag codes.


Okay



Now for the transport's info,  we only choose primary_path to dump.


Okay


It means we should fix this by getting the left time to expire from
primary transport t->T3_rtx_timer. like:

r->idiag_expires = jiffies_to_msecs(
-   asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);
+   asoc->peer.primary_path->T3_rtx_timer.expires - jiffies);

but yes, need to check with timer_pending firstly.


Yes :)



what do  you think ?



Makes sense, LGTM.

Phil, not sure how you want to proceed here. Wanna handle the change above?

Re: [PATCH 2/3] sctp_diag: export timer value only if it is active

[Xin Long]

>> diff --git a/net/sctp/sctp_diag.c b/net/sctp/sctp_diag.c
>> index f69edcf219e51..0ad6033a7330c 100644
>> --- a/net/sctp/sctp_diag.c
>> +++ b/net/sctp/sctp_diag.c
>> @@ -40,10 +40,12 @@ static void inet_diag_msg_sctpasoc_fill(struct 
>> inet_diag_msg *r,
>>   }
>>
>>   r->idiag_state = asoc->state;
>> - r->idiag_timer = SCTP_EVENT_TIMEOUT_T3_RTX;
>> - r->idiag_retrans = asoc->rtx_data_chunks;
>> - r->idiag_expires = jiffies_to_msecs(
>> - asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);
>
> I think we have two issues here, prior to your patch, but I noticed
> while reviewing it :-)
>
> This array is actually not based on jiffies but on intervals instead, as
> per:
>
> sm_sideeffect.c:
> case SCTP_CMD_TIMER_START:   [1]
> timer = >timers[cmd->obj.to];
> timeout = asoc->timeouts[cmd->obj.to];   <---
> BUG_ON(!timeout);
>
> timer->expires = jiffies + timeout;  <---
understood.

>
> But more importantly, this array is actually not used for this timeout
> and the timeout is sctp_transport dependant, as per:
>
> /* Schedule retransmission on the given transport */
> void sctp_transport_immediate_rtx(struct sctp_transport *t)
> {
> /* Stop pending T3_rtx_timer */
> if (del_timer(>T3_rtx_timer))
> sctp_transport_put(t);
>
> sctp_retransmit(>asoc->outqueue, t, SCTP_RTXR_T3_RTX);
> if (!timer_pending(>T3_rtx_timer)) {
> if (!mod_timer(>T3_rtx_timer, jiffies + t->rto))
>  
> sctp_transport_hold(t);
>
> Note how on sctp_get_sctp_info() it fetches the RTO (which is T3_RTX)
> this way:
> info->sctpi_p_rto = jiffies_to_msecs(prim->rto);
> If we want to know how long is left for the timer to expire, we have to
> read directly from it.
you are right, 3 timers (T3_tx, hb, rtx_data_chunks) are per transport.

>
> With git grep -A 1 TIMER_START we can confirm that [1] is never hit for
> SCTP_EVENT_TIMEOUT_T3_RTX. Yet, the asoc is allocated with kzalloc(), so
> I guess you were just reading -jiffies in there.
>
> Note however that the stats rtx_data_chunks is the accumulated stats,
> it's good, and that we may have multiple T3 timers running at once, with
> different timeouts.
>
> Xin, ideas on how we can fix this? I'm not sure if we can dump
> per-transport info in there. Not as it is now, I guess.
It's not that easy to dump all transports info besed on current sctp_diag codes.

Now for the transport's info,  we only choose primary_path to dump.
It means we should fix this by getting the left time to expire from
primary transport t->T3_rtx_timer. like:

r->idiag_expires = jiffies_to_msecs(
-   asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);
+   asoc->peer.primary_path->T3_rtx_timer.expires - jiffies);

but yes, need to check with timer_pending firstly.

what do  you think ?

Re: [PATCH 2/3] sctp_diag: export timer value only if it is active

[Marcelo Ricardo Leitner]

On Fri, Jul 29, 2016 at 06:59:39PM +0200, Phil Sutter wrote:
> Since it is exported as unsigned value, userspace has no way detecting
> whether it is negative or just very large. Therefore do this in kernel
> space where it is a simple comparison.
> 
> Signed-off-by: Phil Sutter 
> ---
>  net/sctp/sctp_diag.c | 10 ++
>  1 file changed, 6 insertions(+), 4 deletions(-)
> 
> diff --git a/net/sctp/sctp_diag.c b/net/sctp/sctp_diag.c
> index f69edcf219e51..0ad6033a7330c 100644
> --- a/net/sctp/sctp_diag.c
> +++ b/net/sctp/sctp_diag.c
> @@ -40,10 +40,12 @@ static void inet_diag_msg_sctpasoc_fill(struct 
> inet_diag_msg *r,
>   }
>  
>   r->idiag_state = asoc->state;
> - r->idiag_timer = SCTP_EVENT_TIMEOUT_T3_RTX;
> - r->idiag_retrans = asoc->rtx_data_chunks;
> - r->idiag_expires = jiffies_to_msecs(
> - asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);

I think we have two issues here, prior to your patch, but I noticed
while reviewing it :-)

This array is actually not based on jiffies but on intervals instead, as
per:

sm_sideeffect.c:
case SCTP_CMD_TIMER_START:   [1]
timer = >timers[cmd->obj.to];
timeout = asoc->timeouts[cmd->obj.to];   <---
BUG_ON(!timeout);

timer->expires = jiffies + timeout;  <---

But more importantly, this array is actually not used for this timeout
and the timeout is sctp_transport dependant, as per:

/* Schedule retransmission on the given transport */
void sctp_transport_immediate_rtx(struct sctp_transport *t)
{
/* Stop pending T3_rtx_timer */
if (del_timer(>T3_rtx_timer))
sctp_transport_put(t);

sctp_retransmit(>asoc->outqueue, t, SCTP_RTXR_T3_RTX);
if (!timer_pending(>T3_rtx_timer)) {
if (!mod_timer(>T3_rtx_timer, jiffies + t->rto))
 
sctp_transport_hold(t);

Note how on sctp_get_sctp_info() it fetches the RTO (which is T3_RTX)
this way:
info->sctpi_p_rto = jiffies_to_msecs(prim->rto);
If we want to know how long is left for the timer to expire, we have to
read directly from it.

With git grep -A 1 TIMER_START we can confirm that [1] is never hit for
SCTP_EVENT_TIMEOUT_T3_RTX. Yet, the asoc is allocated with kzalloc(), so
I guess you were just reading -jiffies in there.

Note however that the stats rtx_data_chunks is the accumulated stats,
it's good, and that we may have multiple T3 timers running at once, with
different timeouts.

Xin, ideas on how we can fix this? I'm not sure if we can dump
per-transport info in there. Not as it is now, I guess.

> + if (asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] > jiffies) {
> + r->idiag_timer = SCTP_EVENT_TIMEOUT_T3_RTX;
> + r->idiag_retrans = asoc->rtx_data_chunks;
> + r->idiag_expires = jiffies_to_msecs(
> + asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);
> + }
>  }
>  
>  static int inet_diag_msg_sctpladdrs_fill(struct sk_buff *skb,
> -- 
> 2.8.2
> 

[PATCH 2/3] sctp_diag: export timer value only if it is active

[Phil Sutter]

Since it is exported as unsigned value, userspace has no way detecting
whether it is negative or just very large. Therefore do this in kernel
space where it is a simple comparison.

Signed-off-by: Phil Sutter 
---
 net/sctp/sctp_diag.c | 10 ++
 1 file changed, 6 insertions(+), 4 deletions(-)

diff --git a/net/sctp/sctp_diag.c b/net/sctp/sctp_diag.c
index f69edcf219e51..0ad6033a7330c 100644
--- a/net/sctp/sctp_diag.c
+++ b/net/sctp/sctp_diag.c
@@ -40,10 +40,12 @@ static void inet_diag_msg_sctpasoc_fill(struct 
inet_diag_msg *r,
}
 
r->idiag_state = asoc->state;
-   r->idiag_timer = SCTP_EVENT_TIMEOUT_T3_RTX;
-   r->idiag_retrans = asoc->rtx_data_chunks;
-   r->idiag_expires = jiffies_to_msecs(
-   asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);
+   if (asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] > jiffies) {
+   r->idiag_timer = SCTP_EVENT_TIMEOUT_T3_RTX;
+   r->idiag_retrans = asoc->rtx_data_chunks;
+   r->idiag_expires = jiffies_to_msecs(
+   asoc->timeouts[SCTP_EVENT_TIMEOUT_T3_RTX] - jiffies);
+   }
 }
 
 static int inet_diag_msg_sctpladdrs_fill(struct sk_buff *skb,
-- 
2.8.2