wrong CAN frame order in network layer due to SMP?

wrong CAN frame order in network layer due to SMP?

[Alexander Stein]

Hi,

I experienced a rather interesting problem while doing a CAN burst test.
This sends a bunch of CAN frames while each frame has a counter in it and the 
receiver checks if the counter are in correct order.
Now I got the error about wrong order:
> Error on MSG ID 0x251. Got counter 141606 and expected 141605
> Error on MSG ID 0x251. Got counter 141605 and expected 141607
> Error on MSG ID 0x251. Got counter 141607 and expected 141606

Here is the corresponding part from "candump -t d -a -x any -l"
> (1479993291.766686) can0 251#00022926
> (1479993291.766574) can0 251#00022925
> (1479993291.766816) can0 251#00022927

And in fact they are ordered wrongly. But the timestamps are correct, e.g. if 
you reorder the frame by timestamp the order of counters is ok. This also 
shows that the order is wrong on both sockets in the same way!

The used driver is systec_can (downloadable at [1] if you like).
But the driver is not to blame: In the URB complete callback a SKB is created 
and passed to network stack by netif_rx.
The timestamp is set by net_timestamp_check() directly at the beginning of 
netif_rx_internal() so at this point the frames are still in order.
In enqueue_to_backlog the skb are enqueued in some per_cpu softnet_data. I 
don't know the details.
Now per_cpu gave me a hint the problem might be caused by SMP. So I put 7 of 
my 8 cores offline:
> for i in $(seq 1 7); do echo 0 > /sys/bus/cpu/devices/cpu${i}/online; done
Repeating the test run resulted in no order problems. My guess is that the USB 
interrupt is done on different cores and that gathering the SKBs to be put in 
the sockets is somewhat racy.
This is supported by the fact after puttng the core online again:
> for i in $(seq 1 7); do echo 1 > /sys/bus/cpu/devices/cpu${i}/online; done
there are still no order problems. But this again is caused by the fact 
(probably a bug in ACPI tables of my local machine) that any CPU put back 
online serves no IO-APIC or MSI IRQs. This can easily be checked by calling:
> watch -d -n 1 cat /proc/interrupts
See that interrupts are handled on different CPUs. Put some CPUs (or all but 
one) offline and online again. The ones which went offline dont serve any IO-
APIC or MSI IRQs (so including the one for ehci_hcd).
Back to my CAN problem: Only a single core handles USB IRQs and there is 
apparently no softnet_data race.
The test about wrong CAN frame ordering was done on kernel 4.8.9-gentoo but I 
was also able to reproduce this problem on 3.14.58-gentoo-r1. 3.12.52-gentoo-
r1 apparently does not suffer from that problem, at least 3 tries were without 
errors. In buggy kernels this problems occured next to every time.

Any idea what got wrong in the network code about gathering the SKBs 
which might result in wrong order?

Best regards,
Alexander

[1] http://www.systec-electronic.com/en/products/industrial-communication/interfaces-and-gateways/can-usb-adapter-usb-canmodul1
-- 
Dipl.-Inf. Alexander Stein
SYS TEC electronic GmbH
alexander.stein@systec-electronic.com

Legal and Commercial Address:
Am Windrad 2
08468 Heinsdorfergrund
Germany

Office: +49 (0) 3765 38600-0
Fax:    +49 (0) 3765 38600-4100
 
Managing Directors:
	Director Technology/CEO: Dipl.-Phys. Siegmar Schmidt;
	Director Commercial Affairs/COO: Dipl. Ing. (FH) Armin von Collrepp
Commercial Registry:
	Amtsgericht Chemnitz, HRB 28082; USt.-Id Nr. DE150534010

Re: wrong CAN frame order in network layer due to SMP?

[Oliver Hartkopp]

Hello Alexander,

On 11/24/2016 04:49 PM, Alexander Stein wrote:
> Back to my CAN problem: Only a single core handles USB IRQs and there is
> apparently no softnet_data race.
> The test about wrong CAN frame ordering was done on kernel 4.8.9-gentoo but I
> was also able to reproduce this problem on 3.14.58-gentoo-r1. 3.12.52-gentoo-
> r1 apparently does not suffer from that problem, at least 3 tries were without
> errors. In buggy kernels this problems occured next to every time.
>
> Any idea what got wrong in the network code about gathering the SKBs
> which might result in wrong order?

I detected a similar issue in some 3.1x kernel and asked this question:

http://marc.info/?l=linux-can&m=143637774606287&w=2

When you follow the entire discussion at

http://marc.info/?t=143637789700002&r=1&w=2

you will see that they pushed me to implement NAPI on all CAN interfaces 
which neither makes no sense for CAN controllers that do not have a RX 
FIFO (e.g. sja1000) nor fixes the issue at it's root cause.

Your findings bring up the problem again - good :-)

When you look at the networking guys that like to speed up TCP traffic 
and also put skbs into percpu queues that are related to the receiving 
socket(!!!) instance then it should be possible to put CAN skbs related 
to their CAN interfaces into a percpu queue (to suppress out-of-order 
reception).

IMO the difference is not to queue the skbs for a specific socket but 
for a specific interface.
The 'endpoint' of CAN frames where they have to be in order is can_rcv() 
in af_can.c and not any TCP instance that needs to reassemble the TCP 
traffic for a specific socket.

Can you check whether my suggestion with skb_set_hash() in 
alloc_can_skb() works for you?

In any way I think we should start a new attempt to make clear that the 
skbs have to be in order for a specific interface at can_rcv().
And we need some solution that is enabled by default and fits to the 
netdev guys mindset.

Regards,
Oliver

Re: wrong CAN frame order in network layer due to SMP?

[Alexander Stein]

On Friday 25 November 2016 12:46:08, Oliver Hartkopp wrote:
> Hello Alexander,
> 
> On 11/24/2016 04:49 PM, Alexander Stein wrote:
> > Back to my CAN problem: Only a single core handles USB IRQs and there is
> > apparently no softnet_data race.
> > The test about wrong CAN frame ordering was done on kernel 4.8.9-gentoo
> > but I was also able to reproduce this problem on 3.14.58-gentoo-r1.
> > 3.12.52-gentoo- r1 apparently does not suffer from that problem, at least
> > 3 tries were without errors. In buggy kernels this problems occured next
> > to every time.
> > 
> > Any idea what got wrong in the network code about gathering the SKBs
> > which might result in wrong order?
> 
> I detected a similar issue in some 3.1x kernel and asked this question:
> 
> http://marc.info/?l=linux-can&m=143637774606287&w=2
> 
> When you follow the entire discussion at
> 
> http://marc.info/?t=143637789700002&r=1&w=2
> 
> you will see that they pushed me to implement NAPI on all CAN interfaces
> which neither makes no sense for CAN controllers that do not have a RX
> FIFO (e.g. sja1000) nor fixes the issue at it's root cause.
> 
> Your findings bring up the problem again - good :-)

Too bad I didn't know of that post earlier, well never searched for it :-/

> When you look at the networking guys that like to speed up TCP traffic
> and also put skbs into percpu queues that are related to the receiving
> socket(!!!) instance then it should be possible to put CAN skbs related
> to their CAN interfaces into a percpu queue (to suppress out-of-order
> reception).

But wouldn't using queues related to sockets result in different orderings in 
different sockets? I've yet to find an erroneous rest run with a non-
conforming candump.
Anyway I don't yet fully understand the complete code and/or data flow up to 
the socket once netif_rx() is called.

> IMO the difference is not to queue the skbs for a specific socket but
> for a specific interface.
> The 'endpoint' of CAN frames where they have to be in order is can_rcv()
> in af_can.c and not any TCP instance that needs to reassemble the TCP
> traffic for a specific socket.

Sure, TCP can handle OOO pretty fine. Even for UDP this is not a problem at 
all. But isn't using raw sockets on ethernet in promiscuous mode a somewhat 
similar scenario? Or to put it in another way: Wouldn't tcpdump or wireshark 
suffer from the same problem?

> Can you check whether my suggestion with skb_set_hash() in
> alloc_can_skb() works for you?

For ease of use I didn't change alloc_can_skb() but rather used the patched 
inlined below. Using this change and (!)
> echo f >  /sys/class/net/can0/queues/rx-0/rps_cpus

3 test runs didn't raise any OOO errors.

But shouldn't the hash type be rather PKT_HASH_TYPE_L4? Otherwise 
skb_get_hash() doesn't use skb->hash directly (or at all?). I am aware that L4 
is semantically wrong though.

> In any way I think we should start a new attempt to make clear that the
> skbs have to be in order for a specific interface at can_rcv().
> And we need some solution that is enabled by default and fits to the
> netdev guys mindset.

It should not only be enabled by default but rather the only solution with no 
way to be disabled/wrong.

Best regards,
Alexander

diff --git a/systec_can.c b/systec_can.c
index b6d9b74..51b2bf6 100644
--- a/systec_can.c
+++ b/systec_can.c
@@ -978,6 +978,8 @@ static void systec_can_rx_can_msg(struct systec_can_chan 
*chan, u8 *msg_buf)
                 return;
         }
 
+        skb_set_hash(skb, chan->netdev->ifindex, PKT_HASH_TYPE_L2);
+
         /* get size of data part of CAN message */
         cf->can_dlc = get_can_dlc(msg->format & USBCAN_DATAFF_DLC);
-- 
Dipl.-Inf. Alexander Stein
SYS TEC electronic GmbH
alexander.stein@systec-electronic.com

Legal and Commercial Address:
Am Windrad 2
08468 Heinsdorfergrund
Germany

Office: +49 (0) 3765 38600-0
Fax:    +49 (0) 3765 38600-4100
 
Managing Directors:
	Director Technology/CEO: Dipl.-Phys. Siegmar Schmidt;
	Director Commercial Affairs/COO: Dipl. Ing. (FH) Armin von Collrepp
Commercial Registry:
	Amtsgericht Chemnitz, HRB 28082; USt.-Id Nr. DE150534010

Re: wrong CAN frame order in network layer due to SMP?

[Oliver Hartkopp]

On 11/28/2016 10:01 AM, Alexander Stein wrote:
> On Friday 25 November 2016 12:46:08, Oliver Hartkopp wrote:

>> When you look at the networking guys that like to speed up TCP traffic
>> and also put skbs into percpu queues that are related to the receiving
>> socket(!!!) instance then it should be possible to put CAN skbs related
>> to their CAN interfaces into a percpu queue (to suppress out-of-order
>> reception).
>
> But wouldn't using queues related to sockets result in different orderings in
> different sockets? I've yet to find an erroneous rest run with a non-
> conforming candump.
> Anyway I don't yet fully understand the complete code and/or data flow up to
> the socket once netif_rx() is called.
>

/me too


>> IMO the difference is not to queue the skbs for a specific socket but
>> for a specific interface.
>> The 'endpoint' of CAN frames where they have to be in order is can_rcv()
>> in af_can.c and not any TCP instance that needs to reassemble the TCP
>> traffic for a specific socket.
>
> Sure, TCP can handle OOO pretty fine. Even for UDP this is not a problem at
> all. But isn't using raw sockets on ethernet in promiscuous mode a somewhat
> similar scenario? Or to put it in another way: Wouldn't tcpdump or wireshark
> suffer from the same problem?

Hm - I pushed Wireshark and libpcap to remove PF_CAN support and 
implement the CAN dissectors based on PF_PACKET:

Wireshark bug/feature request:
https://bugs.wireshark.org/bugzilla/show_bug.cgi?id=12687

libpcap:
https://github.com/the-tcpdump-group/libpcap/commit/93ca5ff7030aaf1219e1de05ec89a68384bfc50b

Wireshark CAN/CANFD dissector:
https://code.wireshark.org/review/#/c/16787/

Commit:
https://code.wireshark.org/review/gitweb?p=wireshark.git;a=commitdiff;h=7fad354a3e379382368cd1ef67b841315c29e050

But you need to build the latest libpcap & Wireshark to use the 
PF_PACKET flavour in Wireshark.

IIRC Wireshark puts the PF_PACKET socket into some special 'tpacket' 
mode and I don't know whether this has any impact on frame ordering.

At least you may check for:
https://github.com/linux-can/can-tests/blob/master/tst-packet.c

... if there's a difference between PF_PACKET and PF_CAN with your OOO 
setup.

Regards,
Oliver

Re: wrong CAN frame order in network layer due to SMP?

[Alexander Stein]

Hello Oliver,

On Monday 28 November 2016 21:36:09, Oliver Hartkopp wrote:
> >> IMO the difference is not to queue the skbs for a specific socket but
> >> for a specific interface.
> >> The 'endpoint' of CAN frames where they have to be in order is can_rcv()
> >> in af_can.c and not any TCP instance that needs to reassemble the TCP
> >> traffic for a specific socket.
> > 
> > Sure, TCP can handle OOO pretty fine. Even for UDP this is not a problem
> > at
> > all. But isn't using raw sockets on ethernet in promiscuous mode a
> > somewhat
> > similar scenario? Or to put it in another way: Wouldn't tcpdump or
> > wireshark suffer from the same problem?
> 
> Hm - I pushed Wireshark and libpcap to remove PF_CAN support and
> implement the CAN dissectors based on PF_PACKET:
> 
> Wireshark bug/feature request:
> https://bugs.wireshark.org/bugzilla/show_bug.cgi?id=12687
> 
> libpcap:
> https://github.com/the-tcpdump-group/libpcap/commit/93ca5ff7030aaf1219e1de05
> ec89a68384bfc50b
> 
> Wireshark CAN/CANFD dissector:
> https://code.wireshark.org/review/#/c/16787/
> 
> Commit:
> https://code.wireshark.org/review/gitweb?p=wireshark.git;a=commitdiff;h=7fad
> 354a3e379382368cd1ef67b841315c29e050
> 
> But you need to build the latest libpcap & Wireshark to use the
> PF_PACKET flavour in Wireshark.
> 
> IIRC Wireshark puts the PF_PACKET socket into some special 'tpacket'
> mode and I don't know whether this has any impact on frame ordering.
> 
> At least you may check for:
> https://github.com/linux-can/can-tests/blob/master/tst-packet.c
> 
> ... if there's a difference between PF_PACKET and PF_CAN with your OOO
> setup.

Nope, apparently there is no difference. Got similar results.

On a side note: I captured an 30 seconds iperf3 run with wireshark 2.2.2 using 
the "ASIX Electronics Corp. AX88179 Gigabit Ethernet" adapter (driver: 
ax88179_178a).
AFAICS this driver (well usbnet in the end) doesn't use NAPI either and 
therefore unsurprisingly I got OOO of TCP frames.
IMHO this is not acceptable at all.

Best regards,
Alexander
-- 
Dipl.-Inf. Alexander Stein
SYS TEC electronic GmbH
alexander.stein@systec-electronic.com

Legal and Commercial Address:
Am Windrad 2
08468 Heinsdorfergrund
Germany

Office: +49 (0) 3765 38600-0
Fax:    +49 (0) 3765 38600-4100
 
Managing Directors:
	Director Technology/CEO: Dipl.-Phys. Siegmar Schmidt;
	Director Commercial Affairs/COO: Dipl. Ing. (FH) Armin von Collrepp
Commercial Registry:
	Amtsgericht Chemnitz, HRB 28082; USt.-Id Nr. DE150534010

Re: wrong CAN frame order in network layer due to SMP?

[Oliver Hartkopp]

Hello Alexander,

On 11/29/2016 11:30 AM, Alexander Stein wrote:
> On Monday 28 November 2016 21:36:09, Oliver Hartkopp wrote:
>> IIRC Wireshark puts the PF_PACKET socket into some special 'tpacket'
>> mode and I don't know whether this has any impact on frame ordering.
>>
>> At least you may check for:
>> https://github.com/linux-can/can-tests/blob/master/tst-packet.c
>>
>> ... if there's a difference between PF_PACKET and PF_CAN with your OOO
>> setup.
>
> Nope, apparently there is no difference. Got similar results.
>
> On a side note: I captured an 30 seconds iperf3 run with wireshark 2.2.2 using
> the "ASIX Electronics Corp. AX88179 Gigabit Ethernet" adapter (driver:
> ax88179_178a).
> AFAICS this driver (well usbnet in the end) doesn't use NAPI either and
> therefore unsurprisingly I got OOO of TCP frames.
> IMHO this is not acceptable at all.

Did you have a TCP socket on the receiving host as endpoint for your 
communication?

Maybe this could be named a 'general regression' then. And when this is 
fixed our problem hopefully gets fixed too ;-)

Regards,
Oliver

Re: wrong CAN frame order in network layer due to SMP?

[Alexander Stein]

On Tuesday 29 November 2016 20:48:09, Oliver Hartkopp wrote:
> Hello Alexander,
> 
> On 11/29/2016 11:30 AM, Alexander Stein wrote:
> > On Monday 28 November 2016 21:36:09, Oliver Hartkopp wrote:
> >> IIRC Wireshark puts the PF_PACKET socket into some special 'tpacket'
> >> mode and I don't know whether this has any impact on frame ordering.
> >> 
> >> At least you may check for:
> >> https://github.com/linux-can/can-tests/blob/master/tst-packet.c
> >> 
> >> ... if there's a difference between PF_PACKET and PF_CAN with your OOO
> >> setup.
> > 
> > Nope, apparently there is no difference. Got similar results.
> > 
> > On a side note: I captured an 30 seconds iperf3 run with wireshark 2.2.2
> > using the "ASIX Electronics Corp. AX88179 Gigabit Ethernet" adapter
> > (driver: ax88179_178a).
> > AFAICS this driver (well usbnet in the end) doesn't use NAPI either and
> > therefore unsurprisingly I got OOO of TCP frames.
> > IMHO this is not acceptable at all.
> 
> Did you have a TCP socket on the receiving host as endpoint for your
> communication?

Yep. straight iperf3 run. Here is a snippet from the wireshark capture:
  82102 0.759823467    192.168.8.7           192.168.8.128         TCP      34564→5201 [ACK] Seq=79054502 Ack=1 Win=29312 Len=1448 TSval=409657 TSecr=411321992
  82103 0.759823627    192.168.8.7           192.168.8.128         TCP      34564→5201 [ACK] Seq=79055950 Ack=1 Win=29312 Len=1448 TSval=409657 TSecr=411321992
  82104 0.759831475    192.168.8.128         192.168.8.7           TCP      5201→34564 [ACK] Seq=1 Ack=79057398 Win=677760 Len=0 TSval=411321994 TSecr=409657
  82105 0.759823818    192.168.8.7           192.168.8.128         TCP      34564→5201 [ACK] Seq=79057398 Ack=1 Win=29312 Len=1448 TSval=409657 TSecr=411321992
  82106 0.759823894    192.168.8.7           192.168.8.128         TCP      34564→5201 [ACK] Seq=79058846 Ack=1 Win=29312 Len=1448 TSval=409657 TSecr=411321992
  82107 *REF*          192.168.8.128         192.168.8.7           TCP      5201→34564 [ACK] Seq=1 Ack=79060294 Win=677760 Len=0 TSval=411321994 TSecr=409657
  82108 -0.000012137   192.168.8.7           192.168.8.128         TCP      [TCP Out-Of-Order] 34564→5201 [ACK] Seq=78738838 Ack=1 Win=29312 Len=1448 TSval=409657 TSecr=411321992
  82109 0.000003981    192.168.8.128         192.168.8.7           TCP      [TCP Dup ACK 82107#1] 5201→34564 [ACK] Seq=1 Ack=79060294 Win=677760 Len=0 TSval=411321994 TSecr=409657 SLE=78738838 SRE=78740286
  82110 -0.000011999   192.168.8.7           192.168.8.128         TCP      [TCP Out-Of-Order] 34564→5201 [ACK] Seq=78740286 Ack=1 Win=29312 Len=1448 TSval=409657 TSecr=411321992
  82111 0.000007932    192.168.8.128         192.168.8.7           TCP      [TCP Dup ACK 82107#2] 5201→34564 [ACK] Seq=1 Ack=79060294 Win=677760 Len=0 TSval=411321994 TSecr=409657 SLE=78740286 SRE=78741734
  82112 0.000066782    192.168.8.7           192.168.8.128         TCP      [TCP Out-Of-Order] 34564→5201 [ACK] Seq=78741734 Ack=1 Win=29312 Len=1448 TSval=409657 TSecr=411321992
  82113 0.000069480    192.168.8.128         192.168.8.7           TCP      [TCP Dup ACK 82107#3] 5201→34564 [ACK] Seq=1 Ack=79060294 Win=677760 Len=0 TSval=411321995 TSecr=409657 SLE=78741734 SRE=78743182
  82114 0.000066949    192.168.8.7           192.168.8.128         TCP      [TCP Out-Of-Order] 34564→5201 [ACK] Seq=78743182 Ack=1 Win=29312 Len=1448 TSval=409657 TSecr=411321992
  82115 0.000071730    192.168.8.128         192.168.8.7           TCP      [TCP Dup ACK 82107#4] 5201→34564 [ACK] Seq=1 Ack=79060294 Win=677760 Len=0 TSval=411321995 TSecr=409657 SLE=78743182 SRE=78744630

192.168.8.128 is the receiver
192.168.8.128 is the sender
direct connection without any switch
TCP is used
I put a time ref at packet 82107 so you can see more easily the negative relative timestamp of some following packets.

> Maybe this could be named a 'general regression' then. And when this is
> fixed our problem hopefully gets fixed too ;-)

I guess the network guys will also say: Use NAPI. IMHO there shouldn't be an API which allows OOO in the first place.

Best regards,
Alexander
-- 
Dipl.-Inf. Alexander Stein
SYS TEC electronic GmbH
alexander.stein@systec-electronic.com

Legal and Commercial Address:
Am Windrad 2
08468 Heinsdorfergrund
Germany

Office: +49 (0) 3765 38600-0
Fax:    +49 (0) 3765 38600-4100
 
Managing Directors:
	Director Technology/CEO: Dipl.-Phys. Siegmar Schmidt;
	Director Commercial Affairs/COO: Dipl. Ing. (FH) Armin von Collrepp
Commercial Registry:
	Amtsgericht Chemnitz, HRB 28082; USt.-Id Nr. DE150534010