SCTP seems to lose its socket state.

SCTP seems to lose its socket state.

[David Laight]

I've been looking at an ethernet trace from one of our customers.
They seem to have got an SCTP socket into a rather confused state.

There seem to be a significant number of transmit ethernet frames
that don't read the far end.
This shouldn't cause a real problem, but we end up with the following:
This trace was taken on the linux system:

39964   0.304473        ->      SCTP    INIT
39965   0.292669        <-      SCTP    INIT  (I think this has an invalid checksum)
39968   0.467935        <-      SCTP    INIT
39969   0.000093        ->      SCTP    INIT_ACK
39970   0.003947        <-      SCTP    COOKIE_ECHO
39971   0.000072        ->      SCTP    COOKIE_ACK
39972   0.000337        ->      M3UA    ASPUP
39979   0.809659        <-      SCTP    COOKIE_ECHO
39980   0.000058        ->      SCTP    COOKIE_ACK
shutdown() called here - seems to be ignored
39983   0.949471        <-      SCTP    COOKIE_ECHO
39984   0.000053        ->      SCTP    COOKIE_ACK
39986   0.730072        ->      M3UA    ASPUP           Same TSN as above
40002   0.270589        ->      M3UA    ASPUP           Same TSN as above
40008   3.689088        <-      SCTP    HEARTBEAT
40009   0.000027        ->      SCTP    HEARTBEAT_ACK
40014   0.261152        <-      SCTP    HEARTBEAT
40015   0.000033        ->      SCTP    HEARTBEAT_ACK
40026   0.123048        <-      SCTP    HEARTBEAT
40027   0.000030        ->      SCTP    HEARTBEAT_ACK
40036   1.615048        ->      M3UA    ASPUP           Same TSN as above

There are no signs of any SACKs for the ASPUP, I think they have the
correct TSN (the same value as in the INIT_ACK).
No signs of any shutdowns or aborts from either system.

As seems to be typical for M3UA the source and destination ports are
the same. No additional IP addresses appear in the INIT (etc) messages.

Some 80 seconds after the start of the above the remote sends us another INIT.
This is responded to (with new verification tags from both ends), but only
SCTP heartbeats get sent/received (both ways).

The remote sends a few heartbeats with the old verification tag they are
ignored.

The application is repeatedly trying to connect() - but the requests fail
immediately (errno unknown).
I think the system is RHEL 6.4, kernel: 2.6.32-358.el6.x86_64.

Does this 'ring any bells' ?
I think I've asked a similar question before - and 2.6.32 was thought
to be a late enough kernel.
It is, of course, possible they are running RHEL 5 on this system.

I can't think of an easy way to repeat the above sequence to verify
on a much more recent kernel.

	David

Re: SCTP seems to lose its socket state.

[Vlad Yasevich]

On 05/27/2014 11:10 AM, David Laight wrote:
> I've been looking at an ethernet trace from one of our customers.
> They seem to have got an SCTP socket into a rather confused state.
> 
> There seem to be a significant number of transmit ethernet frames
> that don't read the far end.
> This shouldn't cause a real problem, but we end up with the following:
> This trace was taken on the linux system:
> 
> 39964   0.304473        ->      SCTP    INIT
> 39965   0.292669        <-      SCTP    INIT  (I think this has an invalid checksum)
> 39968   0.467935        <-      SCTP    INIT
> 39969   0.000093        ->      SCTP    INIT_ACK
> 39970   0.003947        <-      SCTP    COOKIE_ECHO
> 39971   0.000072        ->      SCTP    COOKIE_ACK
> 39972   0.000337        ->      M3UA    ASPUP
> 39979   0.809659        <-      SCTP    COOKIE_ECHO

cookie_ack was dropped for some reason?

> 39980   0.000058        ->      SCTP    COOKIE_ACK
> shutdown() called here - seems to be ignored
> 39983   0.949471        <-      SCTP    COOKIE_ECHO

Cookie timer fired and resent the cookie_echo.

> 39984   0.000053        ->      SCTP    COOKIE_ACK
> 39986   0.730072        ->      M3UA    ASPUP           Same TSN as above
> 40002   0.270589        ->      M3UA    ASPUP           Same TSN as above

Hmm.. look like more retransmissions.

> 40008   3.689088        <-      SCTP    HEARTBEAT

This probably means that cookie_ack was finally accepted and
we are not heart-beating...

output of 'cat /proc/net/sctp/assocs' might help.  If the local
is running a recent enough kernel, then turning on dynamic debug
in sctp will also help.

> 40009   0.000027        ->      SCTP    HEARTBEAT_ACK
> 40014   0.261152        <-      SCTP    HEARTBEAT
> 40015   0.000033        ->      SCTP    HEARTBEAT_ACK
> 40026   0.123048        <-      SCTP    HEARTBEAT
> 40027   0.000030        ->      SCTP    HEARTBEAT_ACK
> 40036   1.615048        ->      M3UA    ASPUP           Same TSN as above
> 
> There are no signs of any SACKs for the ASPUP, I think they have the
> correct TSN (the same value as in the INIT_ACK).

Make sure that verification tags match what was negotiated in
init/init_ack, and the SSN starts at 0.


> No signs of any shutdowns or aborts from either system.
> 

What's strange is that some frames are simply not accepted.
Are the nics by any chance ixgbe that has checksum offload and
the checksums are corrupt for some reason?

-vlad

> As seems to be typical for M3UA the source and destination ports are
> the same. No additional IP addresses appear in the INIT (etc) messages.
> 
> Some 80 seconds after the start of the above the remote sends us another INIT.
> This is responded to (with new verification tags from both ends), but only
> SCTP heartbeats get sent/received (both ways).
> 
> The remote sends a few heartbeats with the old verification tag they are
> ignored.
> 
> The application is repeatedly trying to connect() - but the requests fail
> immediately (errno unknown).
> I think the system is RHEL 6.4, kernel: 2.6.32-358.el6.x86_64.
> 
> Does this 'ring any bells' ?
> I think I've asked a similar question before - and 2.6.32 was thought
> to be a late enough kernel.
> It is, of course, possible they are running RHEL 5 on this system.
> 
> I can't think of an easy way to repeat the above sequence to verify
> on a much more recent kernel.
> 
> 	David
> 
> 
> 
> --
> To unsubscribe from this list: send the line "unsubscribe netdev" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 

RE: SCTP seems to lose its socket state.

[David Laight]

From: Vlad Yasevich
> On 05/27/2014 11:10 AM, David Laight wrote:
> > I've been looking at an ethernet trace from one of our customers.
> > They seem to have got an SCTP socket into a rather confused state.
> >
> > There seem to be a significant number of transmit ethernet frames
> > that don't read the far end.
> > This shouldn't cause a real problem, but we end up with the following:
> > This trace was taken on the linux system:
> >
> > 39964   0.304473        ->      SCTP    INIT
> > 39965   0.292669        <-      SCTP    INIT  (I think this has an invalid checksum)
> > 39968   0.467935        <-      SCTP    INIT
> > 39969   0.000093        ->      SCTP    INIT_ACK
> > 39970   0.003947        <-      SCTP    COOKIE_ECHO
> > 39971   0.000072        ->      SCTP    COOKIE_ACK
> > 39972   0.000337        ->      M3UA    ASPUP
> > 39979   0.809659        <-      SCTP    COOKIE_ECHO
> 
> cookie_ack was dropped for some reason?

Most likely, as I said a moderate number of ethernet transmit are not
being received by the far end.
I think this is a 'real' network and they are 'real' discards somewhere
between the two systems.
Other parts of the trace show all sorts of retransmissions.

> > 39980   0.000058        ->      SCTP    COOKIE_ACK
> > shutdown() called here - seems to be ignored
> > 39983   0.949471        <-      SCTP    COOKIE_ECHO
> 
> Cookie timer fired and resent the cookie_echo.
> 
> > 39984   0.000053        ->      SCTP    COOKIE_ACK
> > 39986   0.730072        ->      M3UA    ASPUP           Same TSN as above
> > 40002   0.270589        ->      M3UA    ASPUP           Same TSN as above
> 
> Hmm.. look like more retransmissions.
> 
> > 40008   3.689088        <-      SCTP    HEARTBEAT
> 
> This probably means that cookie_ack was finally accepted and
> we are not heart-beating...
> 
> output of 'cat /proc/net/sctp/assocs' might help.  If the local
> is running a recent enough kernel, then turning on dynamic debug
> in sctp will also help.

This is a customer system, I think it is RHEL6 (2.6.32-358) so
running a newer kernel is a little tricky to arrange.
We have asked to double check the kernel version, it might be
RHEL5 (2.6.18 + patches) - which is likely to have a lot of bugs.

> > 40009   0.000027        ->      SCTP    HEARTBEAT_ACK
> > 40014   0.261152        <-      SCTP    HEARTBEAT
> > 40015   0.000033        ->      SCTP    HEARTBEAT_ACK
> > 40026   0.123048        <-      SCTP    HEARTBEAT
> > 40027   0.000030        ->      SCTP    HEARTBEAT_ACK
> > 40036   1.615048        ->      M3UA    ASPUP           Same TSN as above
> >
> > There are no signs of any SACKs for the ASPUP, I think they have the
> > correct TSN (the same value as in the INIT_ACK).
> 
> Make sure that verification tags match what was negotiated in
> init/init_ack, and the SSN starts at 0.

The tags match, SSN is zero.
I think the lack of SACK for the data is a bug in the remote system.
It shouldn't stop the outward disconnect.

> > No signs of any shutdowns or aborts from either system.
> >
> 
> What's strange is that some frames are simply not accepted.
> Are the nics by any chance ixgbe that has checksum offload and
> the checksums are corrupt for some reason?

The wireshark trace does show zero for all the transmitted SCTP
checksums. But the system works fine for hours, so I don't really
believe that is causing the packets to be lost.

I think the packet loss is caused by serious network congestion.

Not the least of the problems is that it seems to take a system
reboot to revover.

	David

Re: SCTP seems to lose its socket state.

[Daniel Borkmann]

On 05/29/2014 11:03 AM, David Laight wrote:
...
> The wireshark trace does show zero for all the transmitted SCTP
> checksums. But the system works fine for hours, so I don't really
> believe that is causing the packets to be lost.

Btw, sounds like checksumming turned off via module param.
I think we should probably remove that debugging feature
eventually ... :/

RE: SCTP seems to lose its socket state.

[David Laight]

From: David Laight
> I've been looking at an ethernet trace from one of our customers.
> They seem to have got an SCTP socket into a rather confused state.
> 
> There seem to be a significant number of transmit ethernet frames
> that don't read the far end.
> This shouldn't cause a real problem, but we end up with the following:
> This trace was taken on the linux system:
> 
> 39964   0.304473        ->      SCTP    INIT
> 39965   0.292669        <-      SCTP    INIT  (I think this has an invalid checksum)
> 39968   0.467935        <-      SCTP    INIT
> 39969   0.000093        ->      SCTP    INIT_ACK
> 39970   0.003947        <-      SCTP    COOKIE_ECHO
> 39971   0.000072        ->      SCTP    COOKIE_ACK
> 39972   0.000337        ->      M3UA    ASPUP
> 39979   0.809659        <-      SCTP    COOKIE_ECHO
> 39980   0.000058        ->      SCTP    COOKIE_ACK
> shutdown() called here - seems to be ignored
> 39983   0.949471        <-      SCTP    COOKIE_ECHO
> 39984   0.000053        ->      SCTP    COOKIE_ACK
> 39986   0.730072        ->      M3UA    ASPUP           Same TSN as above
> 40002   0.270589        ->      M3UA    ASPUP           Same TSN as above
> 40008   3.689088        <-      SCTP    HEARTBEAT
> 40009   0.000027        ->      SCTP    HEARTBEAT_ACK
> 40014   0.261152        <-      SCTP    HEARTBEAT
> 40015   0.000033        ->      SCTP    HEARTBEAT_ACK
> 40026   0.123048        <-      SCTP    HEARTBEAT
> 40027   0.000030        ->      SCTP    HEARTBEAT_ACK
> 40036   1.615048        ->      M3UA    ASPUP           Same TSN as above
> 
> There are no signs of any SACKs for the ASPUP, I think they have the
> correct TSN (the same value as in the INIT_ACK).
> No signs of any shutdowns or aborts from either system.
> 
> As seems to be typical for M3UA the source and destination ports are
> the same. No additional IP addresses appear in the INIT (etc) messages.

I think I've reproduced this on a 3.14.0 kernel.

System A: Bind to port 1234, connect to B:1234.
          If the connect fails, retry 10 seconds later.
          When the connection completes send some data.
          Disconnect if the reflected data isn't received within 2 seconds.
System B: Bind to port 1234, connect to A:1234.
          If the connect fails, retry 10 seconds later.
          Reflect any received data.

Initially the INIT chunks generate ABORTs (no listener) so both
programs just retry every 10 seconds.

On B run:
    iptables -A INPUT -p sctp --chunk-types any INIT -j DROP
    iptables -A INPUT -p sctp --chunk-types any DATA -j DROP
The first allows the connection to complete.
The second stops B acking the data.
The data is resent on timeout, and the systems exchange HBs.

I'd expect that a SHUTDOWN or ABORT be sent reasonably quickly.
But the systems just exchange HBs for over 5 minutes.
(I'm seeing an ABORT because B gives up waiting for the message.)

If I discard the COOKIE_ECHO then I do see an outwards disconnect
after a few retries.

I'm testing with sockets created by our M3UA kernel driver,
and system B is running a much older kernel (2.6.26).
Neither should make any difference.

	David

RE: SCTP seems to lose its socket state.

[David Laight]

From: David Laight
> From: David Laight
> > I've been looking at an ethernet trace from one of our customers.
> > They seem to have got an SCTP socket into a rather confused state.
> >
> > There seem to be a significant number of transmit ethernet frames
> > that don't read the far end.
> > This shouldn't cause a real problem, but we end up with the following:
> > This trace was taken on the linux system:
> >
> > 39964   0.304473        ->      SCTP    INIT
> > 39965   0.292669        <-      SCTP    INIT  (I think this has an invalid checksum)
> > 39968   0.467935        <-      SCTP    INIT
> > 39969   0.000093        ->      SCTP    INIT_ACK
> > 39970   0.003947        <-      SCTP    COOKIE_ECHO
> > 39971   0.000072        ->      SCTP    COOKIE_ACK
> > 39972   0.000337        ->      M3UA    ASPUP
> > 39979   0.809659        <-      SCTP    COOKIE_ECHO
> > 39980   0.000058        ->      SCTP    COOKIE_ACK
> > shutdown() called here - seems to be ignored
> > 39983   0.949471        <-      SCTP    COOKIE_ECHO
> > 39984   0.000053        ->      SCTP    COOKIE_ACK
> > 39986   0.730072        ->      M3UA    ASPUP           Same TSN as above
> > 40002   0.270589        ->      M3UA    ASPUP           Same TSN as above
> > 40008   3.689088        <-      SCTP    HEARTBEAT
> > 40009   0.000027        ->      SCTP    HEARTBEAT_ACK
> > 40014   0.261152        <-      SCTP    HEARTBEAT
> > 40015   0.000033        ->      SCTP    HEARTBEAT_ACK
> > 40026   0.123048        <-      SCTP    HEARTBEAT
> > 40027   0.000030        ->      SCTP    HEARTBEAT_ACK
> > 40036   1.615048        ->      M3UA    ASPUP           Same TSN as above
> >
> > There are no signs of any SACKs for the ASPUP, I think they have the
> > correct TSN (the same value as in the INIT_ACK).
> > No signs of any shutdowns or aborts from either system.
> >
> > As seems to be typical for M3UA the source and destination ports are
> > the same. No additional IP addresses appear in the INIT (etc) messages.
> 
> I think I've reproduced this on a 3.14.0 kernel.
> 
> System A: Bind to port 1234, connect to B:1234.
>           If the connect fails, retry 10 seconds later.
>           When the connection completes send some data.
>           Disconnect if the reflected data isn't received within 2 seconds.
> System B: Bind to port 1234, connect to A:1234.
>           If the connect fails, retry 10 seconds later.
>           Reflect any received data.
> 
> Initially the INIT chunks generate ABORTs (no listener) so both
> programs just retry every 10 seconds.
> 
> On B run:
>     iptables -A INPUT -p sctp --chunk-types any INIT -j DROP
>     iptables -A INPUT -p sctp --chunk-types any DATA -j DROP
> The first allows the connection to complete.
> The second stops B acking the data.
> The data is resent on timeout, and the systems exchange HBs.
> 
> I'd expect that a SHUTDOWN or ABORT be sent reasonably quickly.
> But the systems just exchange HBs for over 5 minutes.
> (I'm seeing an ABORT because B gives up waiting for the message.)

Seems I wasn't waiting long enough.
A does eventually send an ABORT after about 7 minutes.

In the customer's trace the remote (B) system has silently given up
and then resends an INIT well before the 7 minutes have elapsed.
I'm not sure how to go about reproducing that (without major
kernel hacking).

Maybe I can suppress the ABORT from B.

	David

Re: SCTP seems to lose its socket state.

[Vlad Yasevich]

On 06/06/2014 11:14 AM, David Laight wrote:
> From: David Laight
>> I've been looking at an ethernet trace from one of our customers.
>> They seem to have got an SCTP socket into a rather confused state.
>>
>> There seem to be a significant number of transmit ethernet frames
>> that don't read the far end.
>> This shouldn't cause a real problem, but we end up with the following:
>> This trace was taken on the linux system:
>>
>> 39964   0.304473        ->      SCTP    INIT
>> 39965   0.292669        <-      SCTP    INIT  (I think this has an invalid checksum)
>> 39968   0.467935        <-      SCTP    INIT
>> 39969   0.000093        ->      SCTP    INIT_ACK
>> 39970   0.003947        <-      SCTP    COOKIE_ECHO
>> 39971   0.000072        ->      SCTP    COOKIE_ACK
>> 39972   0.000337        ->      M3UA    ASPUP
>> 39979   0.809659        <-      SCTP    COOKIE_ECHO
>> 39980   0.000058        ->      SCTP    COOKIE_ACK
>> shutdown() called here - seems to be ignored
>> 39983   0.949471        <-      SCTP    COOKIE_ECHO
>> 39984   0.000053        ->      SCTP    COOKIE_ACK
>> 39986   0.730072        ->      M3UA    ASPUP           Same TSN as above
>> 40002   0.270589        ->      M3UA    ASPUP           Same TSN as above
>> 40008   3.689088        <-      SCTP    HEARTBEAT
>> 40009   0.000027        ->      SCTP    HEARTBEAT_ACK
>> 40014   0.261152        <-      SCTP    HEARTBEAT
>> 40015   0.000033        ->      SCTP    HEARTBEAT_ACK
>> 40026   0.123048        <-      SCTP    HEARTBEAT
>> 40027   0.000030        ->      SCTP    HEARTBEAT_ACK
>> 40036   1.615048        ->      M3UA    ASPUP           Same TSN as above
>>
>> There are no signs of any SACKs for the ASPUP, I think they have the
>> correct TSN (the same value as in the INIT_ACK).
>> No signs of any shutdowns or aborts from either system.
>>
>> As seems to be typical for M3UA the source and destination ports are
>> the same. No additional IP addresses appear in the INIT (etc) messages.
> 
> I think I've reproduced this on a 3.14.0 kernel.
> 
> System A: Bind to port 1234, connect to B:1234.
>           If the connect fails, retry 10 seconds later.
>           When the connection completes send some data.
>           Disconnect if the reflected data isn't received within 2 seconds.
> System B: Bind to port 1234, connect to A:1234.
>           If the connect fails, retry 10 seconds later.
>           Reflect any received data.
> 
> Initially the INIT chunks generate ABORTs (no listener) so both
> programs just retry every 10 seconds.
> 

Interesting...  I bet that if you drop the retry interval, or even
maybe remove it completely, you might get a connection faster.

You'll end up in the unexpected INIT cases, where the two ends are
trying to establish an association at the same time.

> On B run:
>     iptables -A INPUT -p sctp --chunk-types any INIT -j DROP
>     iptables -A INPUT -p sctp --chunk-types any DATA -j DROP
> The first allows the connection to complete.
> The second stops B acking the data.
> The data is resent on timeout, and the systems exchange HBs.
> 

Ok, that makes sense.

> I'd expect that a SHUTDOWN or ABORT be sent reasonably quickly.

Whey do expect that?  Since you drop the data at B, it is never
reflected back to A.  As such, A will continue retransmitting.
When you disconnect on A, you have unacknowledged data, so the
system will go into SHUTDOWN_PENDING state tying to get the remote
to ack the data and continue sending HB.  Which is I think what
you are observing.

> But the systems just exchange HBs for over 5 minutes.
> (I'm seeing an ABORT because B gives up waiting for the message.)

I think you might be seeing a shutdown_guard timer firing on A.
It defaults to 5 * rto_max and default rto_max is 1 min.

Tweak rto_max lower and you should see the ABORT faster.

I think for the above scenario applications, I'd recommend setting
SO_LINGER to on so that when A disconnects, it sends an ABORT
instead of waiting for unacked data to finish.

-vlad

> 
> If I discard the COOKIE_ECHO then I do see an outwards disconnect
> after a few retries.
> 
> I'm testing with sockets created by our M3UA kernel driver,
> and system B is running a much older kernel (2.6.26).
> Neither should make any difference.
> 
> 	David
> 
> 
> 
> --
> To unsubscribe from this list: send the line "unsubscribe netdev" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 

RE: SCTP seems to lose its socket state.

[David Laight]

I think I have now reproduced the problem.

> From: David Laight
> > I've been looking at an ethernet trace from one of our customers.
> > They seem to have got an SCTP socket into a rather confused state.
> >
> > There seem to be a significant number of transmit ethernet frames
> > that don't read the far end.
> > This shouldn't cause a real problem, but we end up with the following:
> > This trace was taken on the linux system:
> >
> > 39964   0.304473        ->      SCTP    INIT
> > 39965   0.292669        <-      SCTP    INIT  (I think this has an invalid checksum)
> > 39968   0.467935        <-      SCTP    INIT
> > 39969   0.000093        ->      SCTP    INIT_ACK
> > 39970   0.003947        <-      SCTP    COOKIE_ECHO
> > 39971   0.000072        ->      SCTP    COOKIE_ACK
> > 39972   0.000337        ->      M3UA    ASPUP
> > 39979   0.809659        <-      SCTP    COOKIE_ECHO
> > 39980   0.000058        ->      SCTP    COOKIE_ACK
> > shutdown() called here - seems to be ignored
> > 39983   0.949471        <-      SCTP    COOKIE_ECHO
> > 39984   0.000053        ->      SCTP    COOKIE_ACK
> > 39986   0.730072        ->      M3UA    ASPUP           Same TSN as above
> > 40002   0.270589        ->      M3UA    ASPUP           Same TSN as above
> > 40008   3.689088        <-      SCTP    HEARTBEAT
> > 40009   0.000027        ->      SCTP    HEARTBEAT_ACK
> > 40014   0.261152        <-      SCTP    HEARTBEAT
> > 40015   0.000033        ->      SCTP    HEARTBEAT_ACK
> > 40026   0.123048        <-      SCTP    HEARTBEAT
> > 40027   0.000030        ->      SCTP    HEARTBEAT_ACK
> > 40036   1.615048        ->      M3UA    ASPUP           Same TSN as above
> >
> > There are no signs of any SACKs for the ASPUP, I think they have the
> > correct TSN (the same value as in the INIT_ACK).
> > No signs of any shutdowns or aborts from either system.
> >
> > As seems to be typical for M3UA the source and destination ports are
> > the same. No additional IP addresses appear in the INIT (etc) messages.
> 
> I think I've reproduced this on a 3.14.0 kernel.
> 
> System A: Bind to port 1234, connect to B:1234.
>           If the connect fails, retry 10 seconds later.
>           When the connection completes send some data.
>           Disconnect if the reflected data isn't received within 2 seconds.
> System B: Bind to port 1234, connect to A:1234.
>           If the connect fails, retry 10 seconds later.
>           Reflect any received data.

Add here, setsockopt(sock, SO_LINGER, { 1, 0 }, ...);
If no data is received with a few seconds, close() the socket
(do not call shutdown()), and retry.

Initially the INIT chunks generate ABORTs (no listener) so both
programs just retry every 10 seconds.

On B run:
    iptables -A OUPUT -p sctp --chunk-types any ABORT -j DROP
    iptables -A INPUT -p sctp --chunk-types any DATA -j DROP
The first allows the connection to complete, and then drops the
ABORT sent by close().
The second stops B acking the data.

System A now receives a new INIT (with a different TSN) and responds with
an INIT_ACK (followed by a COOKIE_ECHO and COOKIE_ACK) even though
it doesn't have a socket in a suitable state for the connection.

I think the INIT should act as a received ABORT on the old connection,
and then be processed as a new connection - in this case generating
an ABORT because there is no listening socket.

With the code I'm running the INIT is repeated every 30 seconds.
No sign of any DATA retransmits after the first INIT (for over 20 minutes now).

I suspect that a simpler test of forcing a disconnect to use an ABORT and
using iptables to discard the ABORT would be enough to show the problem.

	David

Re: SCTP seems to lose its socket state.

[Vlad Yasevich]

On 06/09/2014 08:49 AM, David Laight wrote:
> I think I have now reproduced the problem.
> 
>> From: David Laight
>>> I've been looking at an ethernet trace from one of our customers.
>>> They seem to have got an SCTP socket into a rather confused state.
>>>
>>> There seem to be a significant number of transmit ethernet frames
>>> that don't read the far end.
>>> This shouldn't cause a real problem, but we end up with the following:
>>> This trace was taken on the linux system:
>>>
>>> 39964   0.304473        ->      SCTP    INIT
>>> 39965   0.292669        <-      SCTP    INIT  (I think this has an invalid checksum)
>>> 39968   0.467935        <-      SCTP    INIT
>>> 39969   0.000093        ->      SCTP    INIT_ACK
>>> 39970   0.003947        <-      SCTP    COOKIE_ECHO
>>> 39971   0.000072        ->      SCTP    COOKIE_ACK
>>> 39972   0.000337        ->      M3UA    ASPUP
>>> 39979   0.809659        <-      SCTP    COOKIE_ECHO
>>> 39980   0.000058        ->      SCTP    COOKIE_ACK
>>> shutdown() called here - seems to be ignored
>>> 39983   0.949471        <-      SCTP    COOKIE_ECHO
>>> 39984   0.000053        ->      SCTP    COOKIE_ACK
>>> 39986   0.730072        ->      M3UA    ASPUP           Same TSN as above
>>> 40002   0.270589        ->      M3UA    ASPUP           Same TSN as above
>>> 40008   3.689088        <-      SCTP    HEARTBEAT
>>> 40009   0.000027        ->      SCTP    HEARTBEAT_ACK
>>> 40014   0.261152        <-      SCTP    HEARTBEAT
>>> 40015   0.000033        ->      SCTP    HEARTBEAT_ACK
>>> 40026   0.123048        <-      SCTP    HEARTBEAT
>>> 40027   0.000030        ->      SCTP    HEARTBEAT_ACK
>>> 40036   1.615048        ->      M3UA    ASPUP           Same TSN as above
>>>
>>> There are no signs of any SACKs for the ASPUP, I think they have the
>>> correct TSN (the same value as in the INIT_ACK).
>>> No signs of any shutdowns or aborts from either system.
>>>
>>> As seems to be typical for M3UA the source and destination ports are
>>> the same. No additional IP addresses appear in the INIT (etc) messages.
>>
>> I think I've reproduced this on a 3.14.0 kernel.
>>
>> System A: Bind to port 1234, connect to B:1234.
>>           If the connect fails, retry 10 seconds later.
>>           When the connection completes send some data.
>>           Disconnect if the reflected data isn't received within 2 seconds.
>> System B: Bind to port 1234, connect to A:1234.
>>           If the connect fails, retry 10 seconds later.
>>           Reflect any received data.
> 
> Add here, setsockopt(sock, SO_LINGER, { 1, 0 }, ...);
> If no data is received with a few seconds, close() the socket
> (do not call shutdown()), and retry.
> 
> Initially the INIT chunks generate ABORTs (no listener) so both
> programs just retry every 10 seconds.
> 
> On B run:
>     iptables -A OUPUT -p sctp --chunk-types any ABORT -j DROP
>     iptables -A INPUT -p sctp --chunk-types any DATA -j DROP
> The first allows the connection to complete, and then drops the
> ABORT sent by close().
> The second stops B acking the data.

Not only that, but the second entry stops B from accepting DATA.
So, now system B is is guaranteed to destroy it's association after
it hasn't heard anything for a while, but ABORT is dropped so A
doesn't learn about it.

> 
> System A now receives a new INIT (with a different TSN) and responds with
> an INIT_ACK (followed by a COOKIE_ECHO and COOKIE_ACK) even though
> it doesn't have a socket in a suitable state for the connection.

It still has an association in a SHUTDOWN-PENDING state.
This is collision case A where one end has restarted while the other
remains open.

The troubling spot here is the ULP has closed the socket already, but
the association is still around waiting for DATA to be acked.

This appears to be a hole in the spec.  I think that the correct
sequence here would be to send a COOKIE-ACK followed by SHUTDOWN
so that the remote comes correctly configures an association and
immediately enters statefull close.

> 
> I think the INIT should act as a received ABORT on the old connection,
> and then be processed as a new connection - in this case generating
> an ABORT because there is no listening socket.

No.  The INIT almost never causes the ABORT itself.

> 
> With the code I'm running the INIT is repeated every 30 seconds.
> No sign of any DATA retransmits after the first INIT (for over 20 minutes now).
> 
> I suspect that a simpler test of forcing a disconnect to use an ABORT and
> using iptables to discard the ABORT would be enough to show the problem.
> 

The other solution would be to change the sending application to send
an ABORT if the data hasn't been reflected back.

I'll dig through the specs and see if I can come up with the proper
solution.

-vlad

> 	David
> 
> 
> 
> --
> To unsubscribe from this list: send the line "unsubscribe netdev" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 

Re: SCTP seems to lose its socket state.

[Vlad Yasevich]

[-- Attachment #1: Type: text/plain, Size: 103 bytes --]

David

Can you try the attached patch and let me know if it solves this problem
for you.

Thanks
-vlad

[-- Attachment #2: 0001-sctp-Handle-association-restart-in-SHUTDOWN-PENDING-.patch --]
[-- Type: text/x-patch, Size: 1700 bytes --]

>From 3f4f0c587c7dd131ea8d34c7c83931500aae6bbc Mon Sep 17 00:00:00 2001
From: Vlad Yasevich <vyasevic@redhat.com>
Date: Mon, 9 Jun 2014 17:38:23 -0400
Subject: [PATCH] sctp: Handle association restart in SHUTDOWN-PENDING state

Signed-off-by: Vlad Yasevich <vyasevic@redhat.com>
---
 net/sctp/sm_statefuns.c | 19 ++++++++++++++++---
 1 file changed, 16 insertions(+), 3 deletions(-)

diff --git a/net/sctp/sm_statefuns.c b/net/sctp/sm_statefuns.c
index 5170a1f..7194fe85 100644
--- a/net/sctp/sm_statefuns.c
+++ b/net/sctp/sm_statefuns.c
@@ -1775,9 +1775,22 @@ static sctp_disposition_t sctp_sf_do_dupcook_a(struct net *net,
 	/* Update the content of current association. */
 	sctp_add_cmd_sf(commands, SCTP_CMD_UPDATE_ASSOC, SCTP_ASOC(new_asoc));
 	sctp_add_cmd_sf(commands, SCTP_CMD_EVENT_ULP, SCTP_ULPEVENT(ev));
-	sctp_add_cmd_sf(commands, SCTP_CMD_NEW_STATE,
-			SCTP_STATE(SCTP_STATE_ESTABLISHED));
-	sctp_add_cmd_sf(commands, SCTP_CMD_REPLY, SCTP_CHUNK(repl));
+	if (sctp_state(asoc, SHUTDOWN_PENDING) &&
+	    (sctp_sstate(asoc->base.sk, CLOSING) ||
+	     sock_flag(asoc->base.sk, SOCK_DEAD))) {
+		/* if were currently in SHUTDOWN_PENDING, but the socket
+		 * has been closed by user, don't transition to ESTABLISHED.
+		 * Instead trigger SHUTDOWN bundled with COOKIE_ACK.
+		 */
+		sctp_add_cmd_sf(commands, SCTP_CMD_REPLY, SCTP_CHUNK(repl));
+		return sctp_sf_do_9_2_start_shutdown(net, ep, asoc,
+						     SCTP_ST_CHUNK(0), NULL,
+						     commands);
+	} else {
+		sctp_add_cmd_sf(commands, SCTP_CMD_NEW_STATE,
+				SCTP_STATE(SCTP_STATE_ESTABLISHED));
+		sctp_add_cmd_sf(commands, SCTP_CMD_REPLY, SCTP_CHUNK(repl));
+	}
 	return SCTP_DISPOSITION_CONSUME;
 
 nomem_ev:
-- 
1.9.0

RE: SCTP seems to lose its socket state.

[David Laight]

From: Vlad Yasevich
> On 06/09/2014 08:49 AM, David Laight wrote:
> > I think I have now reproduced the problem.
> >
> >> From: David Laight
> >>> I've been looking at an ethernet trace from one of our customers.
> >>> They seem to have got an SCTP socket into a rather confused state.
> >>>
> >>> There seem to be a significant number of transmit ethernet frames
> >>> that don't read the far end.
> >>> This shouldn't cause a real problem, but we end up with the following:
> >>> This trace was taken on the linux system:
> >>>
> >>> 39964   0.304473        ->      SCTP    INIT
> >>> 39965   0.292669        <-      SCTP    INIT  (I think this has an invalid checksum)
> >>> 39968   0.467935        <-      SCTP    INIT
> >>> 39969   0.000093        ->      SCTP    INIT_ACK
> >>> 39970   0.003947        <-      SCTP    COOKIE_ECHO
> >>> 39971   0.000072        ->      SCTP    COOKIE_ACK
> >>> 39972   0.000337        ->      M3UA    ASPUP
> >>> 39979   0.809659        <-      SCTP    COOKIE_ECHO
> >>> 39980   0.000058        ->      SCTP    COOKIE_ACK
> >>> shutdown() called here - seems to be ignored
> >>> 39983   0.949471        <-      SCTP    COOKIE_ECHO
> >>> 39984   0.000053        ->      SCTP    COOKIE_ACK
> >>> 39986   0.730072        ->      M3UA    ASPUP           Same TSN as above
> >>> 40002   0.270589        ->      M3UA    ASPUP           Same TSN as above
> >>> 40008   3.689088        <-      SCTP    HEARTBEAT
> >>> 40009   0.000027        ->      SCTP    HEARTBEAT_ACK
> >>> 40014   0.261152        <-      SCTP    HEARTBEAT
> >>> 40015   0.000033        ->      SCTP    HEARTBEAT_ACK
> >>> 40026   0.123048        <-      SCTP    HEARTBEAT
> >>> 40027   0.000030        ->      SCTP    HEARTBEAT_ACK
> >>> 40036   1.615048        ->      M3UA    ASPUP           Same TSN as above
> >>>
> >>> There are no signs of any SACKs for the ASPUP, I think they have the
> >>> correct TSN (the same value as in the INIT_ACK).
> >>> No signs of any shutdowns or aborts from either system.
> >>>
> >>> As seems to be typical for M3UA the source and destination ports are
> >>> the same. No additional IP addresses appear in the INIT (etc) messages.
> >>
> >> I think I've reproduced this on a 3.14.0 kernel.
> >>
> >> System A: Bind to port 1234, connect to B:1234.
> >>           If the connect fails, retry 10 seconds later.
> >>           When the connection completes send some data.
> >>           Disconnect if the reflected data isn't received within 2 seconds.
> >> System B: Bind to port 1234, connect to A:1234.
> >>           If the connect fails, retry 10 seconds later.
> >>           Reflect any received data.
> >
> > Add here, setsockopt(sock, SO_LINGER, { 1, 0 }, ...);
> > If no data is received with a few seconds, close() the socket
> > (do not call shutdown()), and retry.
> >
> > Initially the INIT chunks generate ABORTs (no listener) so both
> > programs just retry every 10 seconds.
> >
> > On B run:
> >     iptables -A OUPUT -p sctp --chunk-types any ABORT -j DROP
> >     iptables -A INPUT -p sctp --chunk-types any DATA -j DROP
> > The first allows the connection to complete, and then drops the
> > ABORT sent by close().
> > The second stops B acking the data.
> 
> Not only that, but the second entry stops B from accepting DATA.
> So, now system B is is guaranteed to destroy it's association after
> it hasn't heard anything for a while, but ABORT is dropped so A
> doesn't learn about it.

Indeed, that is carefully contrived so that A will receive a
duplicate INIT.

B shouldn't destroy the association, these should be TCP-like connections.
The application might give up, but nothing in the M3UA spec requires it
to run a timer (although our version does).

> > System A now receives a new INIT (with a different TSN) and responds with
> > an INIT_ACK (followed by a COOKIE_ECHO and COOKIE_ACK) even though
> > it doesn't have a socket in a suitable state for the connection.
> 
> It still has an association in a SHUTDOWN-PENDING state.
> This is collision case A where one end has restarted while the other
> remains open.
> 
> The troubling spot here is the ULP has closed the socket already, but
> the association is still around waiting for DATA to be acked.
> 
> This appears to be a hole in the spec.  I think that the correct
> sequence here would be to send a COOKIE-ACK followed by SHUTDOWN
> so that the remote comes correctly configures an association and
> immediately enters statefull close.
...
> The other solution would be to change the sending application to send
> an ABORT if the data hasn't been reflected back.

I will probably change our code to disconnect with ABORT rather than
SHUTDOWN, especially in the cases where the remote system doesn't
seem to be responding.

	David

RE: SCTP seems to lose its socket state.

[David Laight]

From: Vlad Yasevich 
> Can you try the attached patch and let me know if it solves this problem
> for you.

I've finally got around to trying it, and then fighting grub2 to get a
serial console (after finding a COM header and cables).
(Why can't I configure two entries for the same kernel, with and without
the serial console...)

As soon as the COOKIE_ECHO is received I get:

[   65.756811] kernel BUG at /home/dsl/linux/net/sctp/command.c:50!

It has hit the limit for SCTP_MAX_NUM_COMMANDS.
I increased it to 20 and traced the entries when the exceeded
the old limit (of 14).

[  102.250614] sctp_add_cmd_sf: seq  0, 36(          (null))
[  102.266575] sctp_add_cmd_sf: seq  1, 15(0000000000000008)
[  102.282500] sctp_add_cmd_sf: seq  2, 2b(          (null))
[  102.298426] sctp_add_cmd_sf: seq  3, 15(0000000000000005)
[  102.314352] sctp_add_cmd_sf: seq  4, 40(          (null))
[  102.330279] sctp_add_cmd_sf: seq  5, 2a(ffff88022f3b4000)
[  102.346206] sctp_add_cmd_sf: seq  6,  b(ffff8800bc4df128)
[  102.361874] sctp_add_cmd_sf: seq  7,  c(ffff8800bc4de800)
[  102.377540] sctp_add_cmd_sf: seq  8, 2c(ffff8800bc4df000)
[  102.393470] sctp_add_cmd_sf: seq  9, 12(0000000000000003)
[  102.409397] sctp_add_cmd_sf: seq 10, 14(0000000000000006)
[  102.425583] sctp_add_cmd_sf: seq 11,  3(0000000000000005)
[  102.441510] sctp_add_cmd_sf: seq 12, 20(          (null))
[  102.457699] sctp_add_cmd_sf: seq 13,  c(ffff8800bc4df000)
[  102.521433] sctp_add_cmd_sf: seq 14, 41(ffff88022f3b4000)
[  102.538658] sctp_add_cmd_sf: seq 15,  2(          (null))
[  102.555626] sctp_add_cmd_sf: seq 16, 41(ffff88023525e000)

I've not tried to see what these are.

tcpdump then shows it sending a shutdown bundled with the cookie ack
and the disconnect completes.

	David

Re: SCTP seems to lose its socket state.

[Vlad Yasevich]

On 06/13/2014 06:53 AM, David Laight wrote:
> From: Vlad Yasevich 
>> Can you try the attached patch and let me know if it solves this problem
>> for you.
> 
> I've finally got around to trying it, and then fighting grub2 to get a
> serial console (after finding a COM header and cables).
> (Why can't I configure two entries for the same kernel, with and without
> the serial console...)
> 
> As soon as the COOKIE_ECHO is received I get:
> 
> [   65.756811] kernel BUG at /home/dsl/linux/net/sctp/command.c:50!
> 
> It has hit the limit for SCTP_MAX_NUM_COMMANDS.
> I increased it to 20 and traced the entries when the exceeded
> the old limit (of 14).
> 
> [  102.250614] sctp_add_cmd_sf: seq  0, 36(          (null))
> [  102.266575] sctp_add_cmd_sf: seq  1, 15(0000000000000008)
> [  102.282500] sctp_add_cmd_sf: seq  2, 2b(          (null))
> [  102.298426] sctp_add_cmd_sf: seq  3, 15(0000000000000005)
> [  102.314352] sctp_add_cmd_sf: seq  4, 40(          (null))
> [  102.330279] sctp_add_cmd_sf: seq  5, 2a(ffff88022f3b4000)
> [  102.346206] sctp_add_cmd_sf: seq  6,  b(ffff8800bc4df128)
> [  102.361874] sctp_add_cmd_sf: seq  7,  c(ffff8800bc4de800)
> [  102.377540] sctp_add_cmd_sf: seq  8, 2c(ffff8800bc4df000)
> [  102.393470] sctp_add_cmd_sf: seq  9, 12(0000000000000003)
> [  102.409397] sctp_add_cmd_sf: seq 10, 14(0000000000000006)
> [  102.425583] sctp_add_cmd_sf: seq 11,  3(0000000000000005)
> [  102.441510] sctp_add_cmd_sf: seq 12, 20(          (null))
> [  102.457699] sctp_add_cmd_sf: seq 13,  c(ffff8800bc4df000)
> [  102.521433] sctp_add_cmd_sf: seq 14, 41(ffff88022f3b4000)
> [  102.538658] sctp_add_cmd_sf: seq 15,  2(          (null))
> [  102.555626] sctp_add_cmd_sf: seq 16, 41(ffff88023525e000)
> 
> I've not tried to see what these are.

Yeah.  We do end up queuing a bit more commands. Need to see if
all them are necessary..

> 
> tcpdump then shows it sending a shutdown bundled with the cookie ack
> and the disconnect completes.

Thanks.  I'll take a look at all the commands we queue up and make
an official submission.

-vlad

> 
> 	David
> 
> 
> 
> 

RE: SCTP seems to lose its socket state.

[David Laight]

From: Vlad Yasevich
...
> Yeah.  We do end up queuing a bit more commands. Need to see if
> all them are necessary..

I wonder why commands get queued, rather than just actioned with
an immediate function call?
I suspect it is steeped into the history of the code.

All of the commands have to be (and are) actioned before any other
packets (etc) can be processed otherwise there will be massive
problems with the socket/association state.

Simply calling the functions is likely change the order of the
actions - which might break things.
OTOH direct calls would make it much easier to audit the sequences.

	David

Re: SCTP seems to lose its socket state.

[Vlad Yasevich]

On 06/16/2014 04:40 AM, David Laight wrote:
> From: Vlad Yasevich
> ...
>> Yeah.  We do end up queuing a bit more commands. Need to see if
>> all them are necessary..
> 
> I wonder why commands get queued, rather than just actioned with
> an immediate function call?

I don't know precisely why this decision was make in the 2.5 days
(before my time).  If I had to guess, I'd say that it was simple
to do at the time to provide a kind of buffering of multiple
actions that resulted from processing of multiple chunks.

> I suspect it is steeped into the history of the code.
>

Yes, very much so.  There are some papers/presentations describing
the approach, but not the reasons fro why it was taken.

> All of the commands have to be (and are) actioned before any other
> packets (etc) can be processed otherwise there will be massive
> problems with the socket/association state.
> 
> Simply calling the functions is likely change the order of the
> actions - which might break things.
> OTOH direct calls would make it much easier to audit the sequences.
> 

I've been thinking for long time about how to change this, but it really
needs a very careful audit and implementation.

-vlad

RE: SCTP seems to lose its socket state.

[David Laight]

From: Vlad Yasevich [mailto:vyasevich@gmail.com]
> On 06/16/2014 04:40 AM, David Laight wrote:
...
> > I wonder why commands get queued, rather than just actioned with
> > an immediate function call?
> 
> I don't know precisely why this decision was make in the 2.5 days
> (before my time).  If I had to guess, I'd say that it was simple
> to do at the time to provide a kind of buffering of multiple
> actions that resulted from processing of multiple chunks.

It rather goes with the arrays of function pointers rather than
switch statements for the per-state actions.

I'd guess that originally the list of 'actions' was made of dynamically
allocated blocks. They might have been processed much later on, but that
would give lots of timing issues.
The other possible reason was to make it easier to trace actions,
but any generic trace ends up missing the important 'state' info
so is almost useless after the initial debug.

If the actions get accumulated across chunks, then the list will
never be large enough.
OTOH I think they are now cleared after each chunk has been processed.

	David

Re: SCTP seems to lose its socket state.

[Neil Horman]

On Mon, Jun 16, 2014 at 08:40:30AM +0000, David Laight wrote:
> From: Vlad Yasevich
> ...
> > Yeah.  We do end up queuing a bit more commands. Need to see if
> > all them are necessary..
> 
> I wonder why commands get queued, rather than just actioned with
> an immediate function call?
> I suspect it is steeped into the history of the code.
> 
> All of the commands have to be (and are) actioned before any other
> packets (etc) can be processed otherwise there will be massive
> problems with the socket/association state.
> 
> Simply calling the functions is likely change the order of the
> actions - which might break things.
> OTOH direct calls would make it much easier to audit the sequences.
> 
> 	David
> 
That last bit is the point. The stack was written to presume that the state of a
connection would be consistent while the state processing function executed, so
commands were queued to be handled as side effects after that was complete.
There should be no reason you can't call the command functions directly, as long as
you audit each state machine function to ensure it doesn't rely on any state
that the command alters after the call.

Neil

> 
> 
> --
> To unsubscribe from this list: send the line "unsubscribe netdev" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>