CAN messages being lost on i.MX25 with flexcan - continued (was CAN messages being lost on i.MX25 with flexcan - 2012-04-19)

Hello,
after more than year I'm back with CAN fifo overrun problems on i.MX25 board. (it was good enough earlier, if some frames were lost, but not this time)

I have 2 flexcan interfaces, each receiving around 1100 msgs/s (situation is a little better if I use just one iface, but I need both) I just configure them and then run:

I=0; while [ $I -le 20 ]; do dd if=/dev/zero of=/mnt/mmcblk0p1/test bs=512 count=200; sync; sleep 1; I=$(($I+1)); done (simulate writing to SDcard with 100KB blocks in 1 sec intervals)

and start sending data from another device.

I am not running any other program (like candump etc) to read from CAN.

this is what is shown after I finish sending 35777 packets (both interfaces now connected to same bus so they should receive same data) with ip -d -s link show can0/1

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0
RX: bytes packets errors dropped overrun mcast
151769 19000 1699 0 1699 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0
root@vmx25 /opt/waytracer$ /root/utils/ip -d -s link show can1 3: can1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 0 0 0
RX: bytes packets errors dropped overrun mcast
157377 19696 2664 0 2664 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

With just one iface used:

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0
RX: bytes packets errors dropped overrun mcast
233277 29201 1483 0 1483 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

Too many packets are lost.

I tried to play with FLEXCAN_NAPI_WEIGHT (quota for napi) and that didn't hepl too much, if I put it too high then the system response was slow and packets still lost, also tried to change priority of CAN interrupts with (don't know if correctly)

   // imx_irq_set_priority(43,14);
   // imx_irq_set_priority(44,14);

But it didn't help either.

Does anybody have any idea how not to lose any packets? :)

Thanks,
Martin

--
To unsubscribe from this list: send the line "unsubscribe linux-can" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Dne 24.10.2013 15:48, Martin Kozusky napsal(a):

Quoted 31 lines

Hello,
after more than year I'm back with CAN fifo overrun problems on i.MX25 board.
(it was good enough earlier, if some frames were lost, but not this time)

I have 2 flexcan interfaces, each receiving around 1100 msgs/s (situation is a little better if I use just one iface, but I need both) I just configure them and then run:

I=0; while [ $I -le 20 ]; do dd if=/dev/zero of=/mnt/mmcblk0p1/test bs=512 count=200; sync; sleep 1; I=$(($I+1)); done (simulate writing to SDcard with 100KB blocks in 1 sec intervals)

and start sending data from another device.

I am not running any other program (like candump etc) to read from CAN.

this is what is shown after I finish sending 35777 packets (both interfaces now connected to same bus so they should receive same data) with ip -d -s link show can0/1

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0

Quoted 50 lines

     RX: bytes  packets  errors  dropped overrun mcast
     151769     19000    1699    0       1699    0
     TX: bytes  packets  errors  dropped carrier collsns
     0          0        0       0       0       0

root@vmx25 /opt/waytracer$ /root/utils/ip -d -s link show can1 3: can1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 0 0 0
RX: bytes packets errors dropped overrun mcast
157377 19696 2664 0 2664 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

With just one iface used:

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0
RX: bytes packets errors dropped overrun mcast
233277 29201 1483 0 1483 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

Too many packets are lost.

I tried to play with FLEXCAN_NAPI_WEIGHT (quota for napi) and that didn't hepl too much, if I put it too high then the system response was slow and packets still lost, also tried to change priority of CAN interrupts with (don't know if correctly)

   // imx_irq_set_priority(43,14);
   // imx_irq_set_priority(44,14);

But it didn't help either.

Quoted 1 line

Does anybody have any idea how not to lose any packets? :)

Hello,
I tried to disable
//netif_receive_skb(skb); in flexcan_read_frame() and other functions so that data is not processed further in system

It didn't help.
So I tried to put time_start=ktime_get_real() at the begining of flexcan_read_frame(), then time_stop=ktime_get_real(); at the end and add their difference to the global variable time_total+=time_stop-time_start;
I divided this time_total by rx_packets count at flexcan_chip_stop and wrote with dev_info into log (variables were initialized in flexcan_chi_start, so I could just do ifconfig can0 up/down and reset those counters and write them to log), so now I had average time spent int flexcan_read_frame.
This time it was around 100usec! just with one CAN used, if both were connected, it was more than twice. And many CAN frames were lost.

So I tried to disable

    /*
        skb = alloc_can_skb(dev, &cf);
        if (unlikely(!skb)) {
                stats->rx_dropped++;
                return 0;
        }
     */

and made "struct can_frame cf" (not pointer, so that I can use it in flexcan_read_fifo call)
And tried to send data again.
Now - average time in flexcan_read_frame was not 100usec, but just 2 usec! 50x less ... no CAN frame was lost, even if I was using both CAN interfaces, each getting over 1100 msgs/sec and writing 100KB data to SD card.

So I am asking - how to make this alloc_can_skb faster (or is there any alternative)? Or if there is another way how to get data to user?

Hi Martin,

Quoted 32 lines · Martin Kozusky

Dne 24.10.2013 15:48, Martin Kozusky napsal(a):

Quoted 31 lines

Hello,
after more than year I'm back with CAN fifo overrun problems on i.MX25 board.
(it was good enough earlier, if some frames were lost, but not this time)

I have 2 flexcan interfaces, each receiving around 1100 msgs/s (situation is a little better if I use just one iface, but I need both) I just configure them and then run:

I=0; while [ $I -le 20 ]; do dd if=/dev/zero of=/mnt/mmcblk0p1/test bs=512 count=200; sync; sleep 1; I=$(($I+1)); done (simulate writing to SDcard with 100KB blocks in 1 sec intervals)

and start sending data from another device.

I am not running any other program (like candump etc) to read from CAN.

this is what is shown after I finish sending 35777 packets (both interfaces now connected to same bus so they should receive same data) with ip -d -s link show can0/1

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0

Do you have electrical problems on the bus? Or is reaching error-passive not related to this problem?

Quoted 50 lines

Quoted 50 lines

      RX: bytes  packets  errors  dropped overrun mcast
      151769     19000    1699    0       1699    0
      TX: bytes  packets  errors  dropped carrier collsns
      0          0        0       0       0       0

root@vmx25 /opt/waytracer$ /root/utils/ip -d -s link show can1 3: can1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 0 0 0
RX: bytes packets errors dropped overrun mcast
157377 19696 2664 0 2664 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

With just one iface used:

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0
RX: bytes packets errors dropped overrun mcast
233277 29201 1483 0 1483 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

Too many packets are lost.

I tried to play with FLEXCAN_NAPI_WEIGHT (quota for napi) and that didn't hepl too much, if I put it too high then the system response was slow and packets still lost, also tried to change priority of CAN interrupts with (don't know if correctly)

    // imx_irq_set_priority(43,14);
    // imx_irq_set_priority(44,14);

But it didn't help either.

Quoted 7 lines

Quoted 1 line

Does anybody have any idea how not to lose any packets? :)

Hello,
I tried to disable
//netif_receive_skb(skb); in flexcan_read_frame() and other functions so that data is not processed further in system

Well ...

Quoted 21 lines

It didn't help.
So I tried to put time_start=ktime_get_real() at the begining of flexcan_read_frame(), then time_stop=ktime_get_real(); at the end and add their difference to the global variable time_total+=time_stop-time_start;
I divided this time_total by rx_packets count at flexcan_chip_stop and wrote with dev_info into log (variables were initialized in flexcan_chi_start, so I could just do ifconfig can0 up/down and reset those counters and write them to log), so now I had average time spent int flexcan_read_frame.
This time it was around 100usec! just with one CAN used, if both were connected, it was more than twice. And many CAN frames were lost.

So I tried to disable

     /*
         skb = alloc_can_skb(dev, &cf);
         if (unlikely(!skb)) {
                 stats->rx_dropped++;
                 return 0;
         }
      */

Quoted 7 lines

and made "struct can_frame cf" (not pointer, so that I can use it in flexcan_read_fifo call)
And tried to send data again.
Now - average time in flexcan_read_frame was not 100usec, but just 2 usec! 50x less ... no CAN frame was lost, even if I was using both CAN interfaces, each getting over 1100 msgs/sec and writing 100KB data to SD card.

... but the messages need to be allocated, queued, delivered to and even processed by a user space task. What you messure it part of the network stack overhead but 100us just for alloc_can_skb() seems quite a lot to me. At what frequency is your CPU running? Is the system low of memory? Maybe your system is simply not fast enough. To see what code is involved just follow:

http://lxr.free-electrons.com/ident?i=alloc_can_skb

Quoted 2 lines

So I am asking - how to make this alloc_can_skb faster (or is there any alternative)? Or if there is another way how to get data to user?

Well, not with Linux-CAN. Anyway, messages arrive at a rate of approx. 1 KHz. So there is 1ms per message. I think it's a latency problem in the first place. The Flexcan on the i.MX25 can queue up to 5 messages. If the queue is full you loose messages. This obviously happens when the SDcard is accessed.

Could you take function traces on your system?

Wolfgang.

--
To unsubscribe from this list: send the line "unsubscribe linux-can" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Dne 25.10.2013 19:58, Wolfgang Grandegger napsal(a):

Quoted 37 lines

Hi Martin,

Quoted 33 lines · Martin Kozusky

Dne 24.10.2013 15:48, Martin Kozusky napsal(a):

Quoted 32 lines

Hello,
after more than year I'm back with CAN fifo overrun problems on i.MX25 board.
(it was good enough earlier, if some frames were lost, but not this time)

I have 2 flexcan interfaces, each receiving around 1100 msgs/s (situation is a little better if I use just one iface, but I need both) I just configure them and then run:

I=0; while [ $I -le 20 ]; do dd if=/dev/zero of=/mnt/mmcblk0p1/test bs=512 count=200; sync; sleep 1; I=$(($I+1)); done (simulate writing to SDcard with 100KB blocks in 1 sec intervals)

and start sending data from another device.

I am not running any other program (like candump etc) to read from CAN.

this is what is shown after I finish sending 35777 packets (both interfaces now connected to same bus so they should receive same data) with ip -d -s link show can0/1

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0

Quoted 2 lines

Do you have electrical problems on the bus? Or is reaching error-passive not related to this problem?

It is not related to this problem - there is only RX pin connected on can0 (RX is connected in parallel with Coldfire V1 MCU CAN, which is doing TX)

Quoted 89 lines

Quoted 50 lines

Quoted 50 lines

      RX: bytes  packets  errors  dropped overrun mcast
      151769     19000    1699    0       1699    0
      TX: bytes  packets  errors  dropped carrier collsns
      0          0        0       0       0       0

root@vmx25 /opt/waytracer$ /root/utils/ip -d -s link show can1 3: can1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 0 0 0
RX: bytes packets errors dropped overrun mcast
157377 19696 2664 0 2664 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

With just one iface used:

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0
RX: bytes packets errors dropped overrun mcast
233277 29201 1483 0 1483 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

Too many packets are lost.

I tried to play with FLEXCAN_NAPI_WEIGHT (quota for napi) and that didn't hepl too much, if I put it too high then the system response was slow and packets still lost, also tried to change priority of CAN interrupts with (don't know if correctly)

    // imx_irq_set_priority(43,14);
    // imx_irq_set_priority(44,14);

But it didn't help either.

Quoted 7 lines

Quoted 1 line

Does anybody have any idea how not to lose any packets? :)

Hello,
I tried to disable
//netif_receive_skb(skb); in flexcan_read_frame() and other functions so that data is not processed further in system

Well ...

Quoted 21 lines

It didn't help.
So I tried to put time_start=ktime_get_real() at the begining of flexcan_read_frame(), then time_stop=ktime_get_real(); at the end and add their difference to the global variable time_total+=time_stop-time_start;
I divided this time_total by rx_packets count at flexcan_chip_stop and wrote with dev_info into log (variables were initialized in flexcan_chi_start, so I could just do ifconfig can0 up/down and reset those counters and write them to log), so now I had average time spent int flexcan_read_frame.
This time it was around 100usec! just with one CAN used, if both were connected, it was more than twice. And many CAN frames were lost.

So I tried to disable

     /*
         skb = alloc_can_skb(dev, &cf);
         if (unlikely(!skb)) {
                 stats->rx_dropped++;
                 return 0;
         }
      */

Quoted 7 lines

and made "struct can_frame cf" (not pointer, so that I can use it in flexcan_read_fifo call)
And tried to send data again.
Now - average time in flexcan_read_frame was not 100usec, but just 2 usec! 50x less ... no CAN frame was lost, even if I was using both CAN interfaces, each getting over 1100 msgs/sec and writing 100KB data to SD card.

Quoted 6 lines

... but the messages need to be allocated, queued, delivered to and even processed by a user space task. What you messure it part of the network stack overhead but 100us just for alloc_can_skb() seems quite a lot to me. At what frequency is your CPU running? Is the system low of memory? Maybe your system is simply not fast enough. To see what code is involved just follow:

CPU is i.MX25, should be running at 400MHz. There is 64MB RAM totally and free enough :(

Quoted 5 lines

http://lxr.free-electrons.com/ident?i=alloc_can_skb

Quoted 2 lines

So I am asking - how to make this alloc_can_skb faster (or is there any alternative)? Or if there is another way how to get data to user?

Quoted 7 lines

Well, not with Linux-CAN. Anyway, messages arrive at a rate of approx. 1 KHz. So there is 1ms per message. I think it's a latency problem in the first place. The Flexcan on the i.MX25 can queue up to 5 messages. If the queue is full you loose messages. This obviously happens when the SDcard is accessed.

Could you take function traces on your system?

Is there any special tool for this or should I use my start/stop timers?

Quoted 148 lines

Dne 25.10.2013 19:58, Wolfgang Grandegger napsal(a):

Quoted 37 lines

Hi Martin,

Quoted 33 lines · Martin Kozusky

Dne 24.10.2013 15:48, Martin Kozusky napsal(a):

Quoted 32 lines

Hello,
after more than year I'm back with CAN fifo overrun problems on i.MX25 board.
(it was good enough earlier, if some frames were lost, but not this time)

I have 2 flexcan interfaces, each receiving around 1100 msgs/s (situation is a little better if I use just one iface, but I need both) I just configure them and then run:

I=0; while [ $I -le 20 ]; do dd if=/dev/zero of=/mnt/mmcblk0p1/test bs=512 count=200; sync; sleep 1; I=$(($I+1)); done (simulate writing to SDcard with 100KB blocks in 1 sec intervals)

and start sending data from another device.

I am not running any other program (like candump etc) to read from CAN.

this is what is shown after I finish sending 35777 packets (both interfaces now connected to same bus so they should receive same data) with ip -d -s link show can0/1

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0

Quoted 2 lines

Do you have electrical problems on the bus? Or is reaching error-passive not related to this problem?

It is not related to this problem - there is only RX pin connected on can0 (RX is connected in parallel with Coldfire V1 MCU CAN, which is doing TX)

Quoted 89 lines

Quoted 50 lines

Quoted 50 lines

       RX: bytes  packets  errors  dropped overrun mcast
       151769     19000    1699    0       1699    0
       TX: bytes  packets  errors  dropped carrier collsns
       0          0        0       0       0       0

root@vmx25 /opt/waytracer$ /root/utils/ip -d -s link show can1 3: can1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 0 0 0
RX: bytes packets errors dropped overrun mcast
157377 19696 2664 0 2664 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

With just one iface used:

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0
RX: bytes packets errors dropped overrun mcast
233277 29201 1483 0 1483 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

Too many packets are lost.

I tried to play with FLEXCAN_NAPI_WEIGHT (quota for napi) and that didn't hepl too much, if I put it too high then the system response was slow and packets still lost, also tried to change priority of CAN interrupts with (don't know if correctly)

     // imx_irq_set_priority(43,14);
     // imx_irq_set_priority(44,14);

But it didn't help either.

Quoted 7 lines

Quoted 1 line

Does anybody have any idea how not to lose any packets? :)

Hello,
I tried to disable
//netif_receive_skb(skb); in flexcan_read_frame() and other functions so that data is not processed further in system

Well ...

Quoted 21 lines

It didn't help.
So I tried to put time_start=ktime_get_real() at the begining of flexcan_read_frame(), then time_stop=ktime_get_real(); at the end and add their difference to the global variable time_total+=time_stop-time_start;
I divided this time_total by rx_packets count at flexcan_chip_stop and wrote with dev_info into log (variables were initialized in flexcan_chi_start, so I could just do ifconfig can0 up/down and reset those counters and write them to log), so now I had average time spent int flexcan_read_frame.
This time it was around 100usec! just with one CAN used, if both were connected, it was more than twice. And many CAN frames were lost.

So I tried to disable

      /*
          skb = alloc_can_skb(dev, &cf);
          if (unlikely(!skb)) {
                  stats->rx_dropped++;
                  return 0;
          }
       */

Quoted 7 lines

and made "struct can_frame cf" (not pointer, so that I can use it in flexcan_read_fifo call)
And tried to send data again.
Now - average time in flexcan_read_frame was not 100usec, but just 2 usec! 50x less ... no CAN frame was lost, even if I was using both CAN interfaces, each getting over 1100 msgs/sec and writing 100KB data to SD card.

Quoted 6 lines

... but the messages need to be allocated, queued, delivered to and even processed by a user space task. What you messure it part of the network stack overhead but 100us just for alloc_can_skb() seems quite a lot to me. At what frequency is your CPU running? Is the system low of memory? Maybe your system is simply not fast enough. To see what code is involved just follow:

CPU is i.MX25, should be running at 400MHz. There is 64MB RAM totally and free enough :(

Quoted 5 lines

http://lxr.free-electrons.com/ident?i=alloc_can_skb

Quoted 2 lines

So I am asking - how to make this alloc_can_skb faster (or is there any alternative)? Or if there is another way how to get data to user?

Quoted 8 lines

Quoted 7 lines

Well, not with Linux-CAN. Anyway, messages arrive at a rate of approx. 1 KHz. So there is 1ms per message. I think it's a latency problem in the first place. The Flexcan on the i.MX25 can queue up to 5 messages. If the queue is full you loose messages. This obviously happens when the SDcard is accessed.

Could you take function traces on your system?

Is there any special tool for this or should I use my start/stop timers?

Your start/stop timers will not show what other activity is disturbing the CAN messages reception. There is the Linux function tracer:

http://lxr.free-electrons.com/source/Documentation/trace/ftrace.txt

It need to be enabled in the kernel. Especially event and function tracing could help to better understand your problems.

Wolfgang.

--
To unsubscribe from this list: send the line "unsubscribe linux-can" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Dne 26.10.2013 21:40, Wolfgang Grandegger napsal(a):

Quoted 173 lines · Martin Kozusky

Quoted 164 lines

Dne 25.10.2013 19:58, Wolfgang Grandegger napsal(a):

Quoted 41 lines

Hi Martin,

Quoted 37 lines · Martin Kozusky

Dne 24.10.2013 15:48, Martin Kozusky napsal(a):

Quoted 36 lines

Hello,
after more than year I'm back with CAN fifo overrun problems on i.MX25
board.
(it was good enough earlier, if some frames were lost, but not this time)

I have 2 flexcan interfaces, each receiving around 1100 msgs/s (situation is a little better if I use just one iface, but I need both)
I just configure them and then run:

I=0; while [ $I -le 20 ]; do dd if=/dev/zero of=/mnt/mmcblk0p1/test bs=512 count=200; sync; sleep 1; I=$(($I+1)); done (simulate writing to SDcard with 100KB blocks in 1 sec intervals)

and start sending data from another device.

I am not running any other program (like candump etc) to read from CAN.

this is what is shown after I finish sending 35777 packets (both interfaces now connected to same bus so they should receive same data)
with ip -d -s link show can0/1

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0

Quoted 3 lines

Do you have electrical problems on the bus? Or is reaching error-passive
not related to this problem?

It is not related to this problem - there is only RX pin connected on can0 (RX is connected in parallel with Coldfire V1 MCU CAN, which is doing TX)

Quoted 91 lines

Quoted 50 lines

Quoted 50 lines

       RX: bytes  packets  errors  dropped overrun mcast
       151769     19000    1699    0       1699    0
       TX: bytes  packets  errors  dropped carrier collsns
       0          0        0       0       0       0

root@vmx25 /opt/waytracer$ /root/utils/ip -d -s link show can1 3: can1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 0 0 0
RX: bytes packets errors dropped overrun mcast
157377 19696 2664 0 2664 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

With just one iface used:

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0
RX: bytes packets errors dropped overrun mcast
233277 29201 1483 0 1483 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

Too many packets are lost.

I tried to play with FLEXCAN_NAPI_WEIGHT (quota for napi) and that didn't hepl too much, if I put it too high then the system response was slow and packets still lost, also tried to change priority of CAN interrupts with (don't know if correctly)

     // imx_irq_set_priority(43,14);
     // imx_irq_set_priority(44,14);

But it didn't help either.

Quoted 7 lines

Quoted 1 line

Does anybody have any idea how not to lose any packets? :)

Hello,
I tried to disable
//netif_receive_skb(skb); in flexcan_read_frame() and other functions so that data is not processed further in system

Well ...

Quoted 21 lines

It didn't help.
So I tried to put time_start=ktime_get_real() at the begining of flexcan_read_frame(), then time_stop=ktime_get_real(); at the end and add their difference to the global variable time_total+=time_stop-time_start;
I divided this time_total by rx_packets count at flexcan_chip_stop and wrote with dev_info into log (variables were initialized in flexcan_chi_start, so I could just do ifconfig can0 up/down and reset those counters and write them to log), so now I had average time spent int flexcan_read_frame.
This time it was around 100usec! just with one CAN used, if both were connected, it was more than twice. And many CAN frames were lost.

So I tried to disable

      /*
          skb = alloc_can_skb(dev, &cf);
          if (unlikely(!skb)) {
                  stats->rx_dropped++;
                  return 0;
          }
       */

Quoted 9 lines

and made "struct can_frame cf" (not pointer, so that I can use it in flexcan_read_fifo call)
And tried to send data again.
Now - average time in flexcan_read_frame was not 100usec, but just 2 usec! 50x less ... no CAN frame was lost, even if I was using both CAN
interfaces, each getting over 1100 msgs/sec and writing 100KB data to SD
card.

Quoted 7 lines

... but the messages need to be allocated, queued, delivered to and even
processed by a user space task. What you messure it part of the network stack overhead but 100us just for alloc_can_skb() seems quite a lot to me. At what frequency is your CPU running? Is the system low of memory? Maybe your system is simply not fast enough. To see what code is involved just follow:

CPU is i.MX25, should be running at 400MHz. There is 64MB RAM totally and free enough :(

Quoted 13 lines

http://lxr.free-electrons.com/ident?i=alloc_can_skb

Quoted 3 lines

So I am asking - how to make this alloc_can_skb faster (or is there any
alternative)? Or if there is another way how to get data to user?

Well, not with Linux-CAN. Anyway, messages arrive at a rate of approx. 1
KHz. So there is 1ms per message. I think it's a latency problem in the first place. The Flexcan on the i.MX25 can queue up to 5 messages. If the queue is full you loose messages. This obviously happens when the SDcard is accessed.

Quoted 2 lines

Quoted 1 line

Could you take function traces on your system?

Is there any special tool for this or should I use my start/stop timers?

Your start/stop timers will not show what other activity is disturbing the CAN messages reception. There is the Linux function tracer:

http://lxr.free-electrons.com/source/Documentation/trace/ftrace.txt

Quoted 2 lines

It need to be enabled in the kernel. Especially event and function tracing could help to better understand your problems.

Hello Wolfgang,
it seems that my architecture (arm/mx25 on 2.6.35 kernel) is missing HAVE_FUNCTION_GRAPH_TRACER, HAVE_DYNAMIC_FTRACE options so it won't be that easy, will be?
Timestamps that ftrace is showing me are in 10 miliseconds resolution, that won't help me much :(

Quoted 174 lines · Martin Kozusky

Dne 26.10.2013 21:40, Wolfgang Grandegger napsal(a):

Quoted 173 lines · Martin Kozusky

Quoted 164 lines

Dne 25.10.2013 19:58, Wolfgang Grandegger napsal(a):

Quoted 41 lines

Hi Martin,

Quoted 37 lines · Martin Kozusky

Dne 24.10.2013 15:48, Martin Kozusky napsal(a):

Quoted 36 lines

Hello,
after more than year I'm back with CAN fifo overrun problems on i.MX25
board.
(it was good enough earlier, if some frames were lost, but not this time)

I have 2 flexcan interfaces, each receiving around 1100 msgs/s (situation is a little better if I use just one iface, but I need both)
I just configure them and then run:

I=0; while [ $I -le 20 ]; do dd if=/dev/zero of=/mnt/mmcblk0p1/test bs=512 count=200; sync; sleep 1; I=$(($I+1)); done (simulate writing to SDcard with 100KB blocks in 1 sec intervals)

and start sending data from another device.

I am not running any other program (like candump etc) to read from CAN.

this is what is shown after I finish sending 35777 packets (both interfaces now connected to same bus so they should receive same data)
with ip -d -s link show can0/1

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0

Quoted 3 lines

Do you have electrical problems on the bus? Or is reaching error-passive
not related to this problem?

It is not related to this problem - there is only RX pin connected on can0 (RX is connected in parallel with Coldfire V1 MCU CAN, which is doing TX)

Quoted 91 lines

Quoted 50 lines

Quoted 50 lines

       RX: bytes  packets  errors  dropped overrun mcast
       151769     19000    1699    0       1699    0
       TX: bytes  packets  errors  dropped carrier collsns
       0          0        0       0       0       0

root@vmx25 /opt/waytracer$ /root/utils/ip -d -s link show can1 3: can1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 0 0 0
RX: bytes packets errors dropped overrun mcast
157377 19696 2664 0 2664 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

With just one iface used:

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0
RX: bytes packets errors dropped overrun mcast
233277 29201 1483 0 1483 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

Too many packets are lost.

I tried to play with FLEXCAN_NAPI_WEIGHT (quota for napi) and that didn't hepl too much, if I put it too high then the system response was slow and packets still lost, also tried to change priority of CAN interrupts with (don't know if correctly)

     // imx_irq_set_priority(43,14);
     // imx_irq_set_priority(44,14);

But it didn't help either.

Quoted 7 lines

Quoted 1 line

Does anybody have any idea how not to lose any packets? :)

Hello,
I tried to disable
//netif_receive_skb(skb); in flexcan_read_frame() and other functions so that data is not processed further in system

Well ...

Quoted 21 lines

It didn't help.
So I tried to put time_start=ktime_get_real() at the begining of flexcan_read_frame(), then time_stop=ktime_get_real(); at the end and add their difference to the global variable time_total+=time_stop-time_start;
I divided this time_total by rx_packets count at flexcan_chip_stop and wrote with dev_info into log (variables were initialized in flexcan_chi_start, so I could just do ifconfig can0 up/down and reset those counters and write them to log), so now I had average time spent int flexcan_read_frame.
This time it was around 100usec! just with one CAN used, if both were connected, it was more than twice. And many CAN frames were lost.

So I tried to disable

      /*
          skb = alloc_can_skb(dev, &cf);
          if (unlikely(!skb)) {
                  stats->rx_dropped++;
                  return 0;
          }
       */

Quoted 9 lines

and made "struct can_frame cf" (not pointer, so that I can use it in flexcan_read_fifo call)
And tried to send data again.
Now - average time in flexcan_read_frame was not 100usec, but just 2 usec! 50x less ... no CAN frame was lost, even if I was using both CAN
interfaces, each getting over 1100 msgs/sec and writing 100KB data to SD
card.

Quoted 7 lines

... but the messages need to be allocated, queued, delivered to and even
processed by a user space task. What you messure it part of the network stack overhead but 100us just for alloc_can_skb() seems quite a lot to me. At what frequency is your CPU running? Is the system low of memory? Maybe your system is simply not fast enough. To see what code is involved just follow:

CPU is i.MX25, should be running at 400MHz. There is 64MB RAM totally and free enough :(

Quoted 13 lines

http://lxr.free-electrons.com/ident?i=alloc_can_skb

Quoted 3 lines

So I am asking - how to make this alloc_can_skb faster (or is there any
alternative)? Or if there is another way how to get data to user?

Well, not with Linux-CAN. Anyway, messages arrive at a rate of approx. 1
KHz. So there is 1ms per message. I think it's a latency problem in the first place. The Flexcan on the i.MX25 can queue up to 5 messages. If the queue is full you loose messages. This obviously happens when the SDcard is accessed.

Quoted 2 lines

Quoted 1 line

Could you take function traces on your system?

Is there any special tool for this or should I use my start/stop timers?

Your start/stop timers will not show what other activity is disturbing the CAN messages reception. There is the Linux function tracer:

http://lxr.free-electrons.com/source/Documentation/trace/ftrace.txt

Quoted 8 lines

Quoted 2 lines

It need to be enabled in the kernel. Especially event and function tracing could help to better understand your problems.

Hello Wolfgang,
it seems that my architecture (arm/mx25 on 2.6.35 kernel) is missing HAVE_FUNCTION_GRAPH_TRACER, HAVE_DYNAMIC_FTRACE options so it won't be that easy, will be?
Timestamps that ftrace is showing me are in 10 miliseconds resolution, that won't help me much :(

Probably that version is to old for proper ftrace support. The 100us you measured for alloc_can_skb() is worst case, right? What is the mean value?

Quoted 184 lines · Martin Kozusky

Quoted 182 lines

Dne 26.10.2013 21:40, Wolfgang Grandegger napsal(a):

Quoted 168 lines · Martin Kozusky

Quoted 164 lines

Dne 25.10.2013 19:58, Wolfgang Grandegger napsal(a):

Quoted 41 lines

Hi Martin,

Quoted 37 lines · Martin Kozusky

Dne 24.10.2013 15:48, Martin Kozusky napsal(a):

Quoted 36 lines

Hello,
after more than year I'm back with CAN fifo overrun problems on i.MX25
board.
(it was good enough earlier, if some frames were lost, but not this time)

I have 2 flexcan interfaces, each receiving around 1100 msgs/s (situation is a little better if I use just one iface, but I need both)
I just configure them and then run:

I=0; while [ $I -le 20 ]; do dd if=/dev/zero of=/mnt/mmcblk0p1/test bs=512 count=200; sync; sleep 1; I=$(($I+1)); done (simulate writing to SDcard with 100KB blocks in 1 sec intervals)

and start sending data from another device.

I am not running any other program (like candump etc) to read from CAN.

this is what is shown after I finish sending 35777 packets (both interfaces now connected to same bus so they should receive same data)
with ip -d -s link show can0/1

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0

Quoted 3 lines

Do you have electrical problems on the bus? Or is reaching error-passive
not related to this problem?

It is not related to this problem - there is only RX pin connected on can0 (RX is connected in parallel with Coldfire V1 MCU CAN, which is doing TX)

Quoted 91 lines

Quoted 50 lines

Quoted 50 lines

        RX: bytes  packets  errors  dropped overrun mcast
        151769     19000    1699    0       1699    0
        TX: bytes  packets  errors  dropped carrier collsns
        0          0        0       0       0       0

root@vmx25 /opt/waytracer$ /root/utils/ip -d -s link show can1 3: can1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 0 0 0
RX: bytes packets errors dropped overrun mcast
157377 19696 2664 0 2664 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

With just one iface used:

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0
RX: bytes packets errors dropped overrun mcast
233277 29201 1483 0 1483 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

Too many packets are lost.

I tried to play with FLEXCAN_NAPI_WEIGHT (quota for napi) and that didn't hepl too much, if I put it too high then the system response was slow and packets still lost, also tried to change priority of CAN interrupts with (don't know if correctly)

      // imx_irq_set_priority(43,14);
      // imx_irq_set_priority(44,14);

But it didn't help either.

Quoted 7 lines

Quoted 1 line

Does anybody have any idea how not to lose any packets? :)

Hello,
I tried to disable
//netif_receive_skb(skb); in flexcan_read_frame() and other functions so that data is not processed further in system

Well ...

Quoted 21 lines

It didn't help.
So I tried to put time_start=ktime_get_real() at the begining of flexcan_read_frame(), then time_stop=ktime_get_real(); at the end and add their difference to the global variable time_total+=time_stop-time_start;
I divided this time_total by rx_packets count at flexcan_chip_stop and wrote with dev_info into log (variables were initialized in flexcan_chi_start, so I could just do ifconfig can0 up/down and reset those counters and write them to log), so now I had average time spent int flexcan_read_frame.
This time it was around 100usec! just with one CAN used, if both were connected, it was more than twice. And many CAN frames were lost.

So I tried to disable

       /*
           skb = alloc_can_skb(dev, &cf);
           if (unlikely(!skb)) {
                   stats->rx_dropped++;
                   return 0;
           }
        */

Quoted 9 lines

and made "struct can_frame cf" (not pointer, so that I can use it in flexcan_read_fifo call)
And tried to send data again.
Now - average time in flexcan_read_frame was not 100usec, but just 2 usec! 50x less ... no CAN frame was lost, even if I was using both CAN
interfaces, each getting over 1100 msgs/sec and writing 100KB data to SD
card.

Quoted 7 lines

... but the messages need to be allocated, queued, delivered to and even
processed by a user space task. What you messure it part of the network stack overhead but 100us just for alloc_can_skb() seems quite a lot to me. At what frequency is your CPU running? Is the system low of memory? Maybe your system is simply not fast enough. To see what code is involved just follow:

CPU is i.MX25, should be running at 400MHz. There is 64MB RAM totally and free enough :(

Quoted 13 lines

http://lxr.free-electrons.com/ident?i=alloc_can_skb

Quoted 3 lines

So I am asking - how to make this alloc_can_skb faster (or is there any
alternative)? Or if there is another way how to get data to user?

Well, not with Linux-CAN. Anyway, messages arrive at a rate of approx. 1
KHz. So there is 1ms per message. I think it's a latency problem in the first place. The Flexcan on the i.MX25 can queue up to 5 messages. If the queue is full you loose messages. This obviously happens when the SDcard is accessed.

Quoted 2 lines

Quoted 1 line

Could you take function traces on your system?

Is there any special tool for this or should I use my start/stop timers?

Quoted 7 lines

Your start/stop timers will not show what other activity is disturbing the CAN messages reception. There is the Linux function tracer:

http://lxr.free-electrons.com/source/Documentation/trace/ftrace.txt

It need to be enabled in the kernel. Especially event and function tracing could help to better understand your problems.

Hello Wolfgang,
it seems that my architecture (arm/mx25 on 2.6.35 kernel) is missing HAVE_FUNCTION_GRAPH_TRACER, HAVE_DYNAMIC_FTRACE options so it won't be that easy, will be?
Timestamps that ftrace is showing me are in 10 miliseconds resolution, that won't help me much :(

Quoted 2 lines

Probably that version is to old for proper ftrace support. The 100us you measured for alloc_can_skb() is worst case, right? What is the mean value?

Flexcan support was added to the mainline kernel 2.6.36. Where did you get your flexcan driver from? Could you post it please here? Any chance to switch to a (more) recent version of the Linux kernel?

Wolfgang.

--
To unsubscribe from this list: send the line "unsubscribe linux-can" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Dne 29.10.2013 13:22, Wolfgang Grandegger napsal(a):

Quoted 188 lines · Wolfgang Grandegger

Quoted 186 lines · Martin Kozusky

Quoted 174 lines

Dne 26.10.2013 21:40, Wolfgang Grandegger napsal(a):

Quoted 173 lines · Martin Kozusky

Quoted 164 lines

Dne 25.10.2013 19:58, Wolfgang Grandegger napsal(a):

Quoted 41 lines

Hi Martin,

Quoted 37 lines · Martin Kozusky

Dne 24.10.2013 15:48, Martin Kozusky napsal(a):

Quoted 36 lines

Hello,
after more than year I'm back with CAN fifo overrun problems on i.MX25
board.
(it was good enough earlier, if some frames were lost, but not this time)

I have 2 flexcan interfaces, each receiving around 1100 msgs/s (situation is a little better if I use just one iface, but I need both)
I just configure them and then run:

I=0; while [ $I -le 20 ]; do dd if=/dev/zero of=/mnt/mmcblk0p1/test bs=512 count=200; sync; sleep 1; I=$(($I+1)); done (simulate writing to SDcard with 100KB blocks in 1 sec intervals)

and start sending data from another device.

I am not running any other program (like candump etc) to read from CAN.

this is what is shown after I finish sending 35777 packets (both interfaces now connected to same bus so they should receive same data)
with ip -d -s link show can0/1

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0

Quoted 3 lines

Do you have electrical problems on the bus? Or is reaching error-passive
not related to this problem?

It is not related to this problem - there is only RX pin connected on can0 (RX is connected in parallel with Coldfire V1 MCU CAN, which is doing TX)

Quoted 91 lines

Quoted 50 lines

Quoted 50 lines

        RX: bytes  packets  errors  dropped overrun mcast
        151769     19000    1699    0       1699    0
        TX: bytes  packets  errors  dropped carrier collsns
        0          0        0       0       0       0

root@vmx25 /opt/waytracer$ /root/utils/ip -d -s link show can1 3: can1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 0 0 0
RX: bytes packets errors dropped overrun mcast
157377 19696 2664 0 2664 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

With just one iface used:

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0
RX: bytes packets errors dropped overrun mcast
233277 29201 1483 0 1483 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

Too many packets are lost.

I tried to play with FLEXCAN_NAPI_WEIGHT (quota for napi) and that didn't hepl too much, if I put it too high then the system response was slow and packets still lost, also tried to change priority of CAN interrupts with (don't know if correctly)

      // imx_irq_set_priority(43,14);
      // imx_irq_set_priority(44,14);

But it didn't help either.

Quoted 7 lines

Quoted 1 line

Does anybody have any idea how not to lose any packets? :)

Hello,
I tried to disable
//netif_receive_skb(skb); in flexcan_read_frame() and other functions so that data is not processed further in system

Well ...

Quoted 21 lines

It didn't help.
So I tried to put time_start=ktime_get_real() at the begining of flexcan_read_frame(), then time_stop=ktime_get_real(); at the end and add their difference to the global variable time_total+=time_stop-time_start;
I divided this time_total by rx_packets count at flexcan_chip_stop and wrote with dev_info into log (variables were initialized in flexcan_chi_start, so I could just do ifconfig can0 up/down and reset those counters and write them to log), so now I had average time spent int flexcan_read_frame.
This time it was around 100usec! just with one CAN used, if both were connected, it was more than twice. And many CAN frames were lost.

So I tried to disable

       /*
           skb = alloc_can_skb(dev, &cf);
           if (unlikely(!skb)) {
                   stats->rx_dropped++;
                   return 0;
           }
        */

Quoted 9 lines

and made "struct can_frame cf" (not pointer, so that I can use it in flexcan_read_fifo call)
And tried to send data again.
Now - average time in flexcan_read_frame was not 100usec, but just 2 usec! 50x less ... no CAN frame was lost, even if I was using both CAN
interfaces, each getting over 1100 msgs/sec and writing 100KB data to SD
card.

Quoted 7 lines

... but the messages need to be allocated, queued, delivered to and even
processed by a user space task. What you messure it part of the network stack overhead but 100us just for alloc_can_skb() seems quite a lot to me. At what frequency is your CPU running? Is the system low of memory? Maybe your system is simply not fast enough. To see what code is involved just follow:

CPU is i.MX25, should be running at 400MHz. There is 64MB RAM totally and free enough :(

Quoted 13 lines

http://lxr.free-electrons.com/ident?i=alloc_can_skb

Quoted 3 lines

So I am asking - how to make this alloc_can_skb faster (or is there any
alternative)? Or if there is another way how to get data to user?

Well, not with Linux-CAN. Anyway, messages arrive at a rate of approx. 1
KHz. So there is 1ms per message. I think it's a latency problem in the first place. The Flexcan on the i.MX25 can queue up to 5 messages. If the queue is full you loose messages. This obviously happens when the SDcard is accessed.

Quoted 2 lines

Quoted 1 line

Could you take function traces on your system?

Is there any special tool for this or should I use my start/stop timers?

Your start/stop timers will not show what other activity is disturbing the CAN messages reception. There is the Linux function tracer:

http://lxr.free-electrons.com/source/Documentation/trace/ftrace.txt

Quoted 8 lines

Quoted 2 lines

It need to be enabled in the kernel. Especially event and function tracing could help to better understand your problems.

Hello Wolfgang,
it seems that my architecture (arm/mx25 on 2.6.35 kernel) is missing HAVE_FUNCTION_GRAPH_TRACER, HAVE_DYNAMIC_FTRACE options so it won't be that easy, will be?
Timestamps that ftrace is showing me are in 10 miliseconds resolution, that won't help me much :(

Probably that version is to old for proper ftrace support. The 100us you measured for alloc_can_skb() is worst case, right? What is the mean value?

Quoted 3 lines

Flexcan support was added to the mainline kernel 2.6.36. Where did you get your flexcan driver from? Could you post it please here? Any chance to switch to a (more) recent version of the Linux kernel?

It is 2.6.35.9 kernel, I think flexcan was backported from 2.6.36 by board developer who made patch for this kernel. But I am keeping it "updated" with latest updates from 3.x kernel, so I think there should be no errors in this driver.
I tried to switch to 2.6.39 but I think there were some errors with the kernel patch that adds support for this board so I gave up. May be I should try again.

Quoted 189 lines

Dne 29.10.2013 13:22, Wolfgang Grandegger napsal(a):

Quoted 188 lines · Wolfgang Grandegger

Quoted 186 lines · Martin Kozusky

Quoted 174 lines

Dne 26.10.2013 21:40, Wolfgang Grandegger napsal(a):

Quoted 173 lines · Martin Kozusky

Quoted 164 lines

Dne 25.10.2013 19:58, Wolfgang Grandegger napsal(a):

Quoted 41 lines

Hi Martin,

Quoted 37 lines · Martin Kozusky

Dne 24.10.2013 15:48, Martin Kozusky napsal(a):

Quoted 36 lines

Hello,
after more than year I'm back with CAN fifo overrun problems on i.MX25
board.
(it was good enough earlier, if some frames were lost, but not this time)

I have 2 flexcan interfaces, each receiving around 1100 msgs/s (situation is a little better if I use just one iface, but I need both)
I just configure them and then run:

I=0; while [ $I -le 20 ]; do dd if=/dev/zero of=/mnt/mmcblk0p1/test bs=512 count=200; sync; sleep 1; I=$(($I+1)); done (simulate writing to SDcard with 100KB blocks in 1 sec intervals)

and start sending data from another device.

I am not running any other program (like candump etc) to read from CAN.

this is what is shown after I finish sending 35777 packets (both interfaces now connected to same bus so they should receive same data)
with ip -d -s link show can0/1

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0

Quoted 3 lines

Do you have electrical problems on the bus? Or is reaching error-passive
not related to this problem?

It is not related to this problem - there is only RX pin connected on can0 (RX is connected in parallel with Coldfire V1 MCU CAN, which is doing TX)

Quoted 91 lines

Quoted 50 lines

Quoted 50 lines

        RX: bytes  packets  errors  dropped overrun mcast
        151769     19000    1699    0       1699    0
        TX: bytes  packets  errors  dropped carrier collsns
        0          0        0       0       0       0

root@vmx25 /opt/waytracer$ /root/utils/ip -d -s link show can1 3: can1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 0 0 0
RX: bytes packets errors dropped overrun mcast
157377 19696 2664 0 2664 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

With just one iface used:

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0
RX: bytes packets errors dropped overrun mcast
233277 29201 1483 0 1483 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

Too many packets are lost.

I tried to play with FLEXCAN_NAPI_WEIGHT (quota for napi) and that didn't hepl too much, if I put it too high then the system response was slow and packets still lost, also tried to change priority of CAN interrupts with (don't know if correctly)

      // imx_irq_set_priority(43,14);
      // imx_irq_set_priority(44,14);

But it didn't help either.

Quoted 7 lines

Quoted 1 line

Does anybody have any idea how not to lose any packets? :)

Hello,
I tried to disable
//netif_receive_skb(skb); in flexcan_read_frame() and other functions so that data is not processed further in system

Well ...

Quoted 21 lines

It didn't help.
So I tried to put time_start=ktime_get_real() at the begining of flexcan_read_frame(), then time_stop=ktime_get_real(); at the end and add their difference to the global variable time_total+=time_stop-time_start;
I divided this time_total by rx_packets count at flexcan_chip_stop and wrote with dev_info into log (variables were initialized in flexcan_chi_start, so I could just do ifconfig can0 up/down and reset those counters and write them to log), so now I had average time spent int flexcan_read_frame.
This time it was around 100usec! just with one CAN used, if both were connected, it was more than twice. And many CAN frames were lost.

So I tried to disable

       /*
           skb = alloc_can_skb(dev, &cf);
           if (unlikely(!skb)) {
                   stats->rx_dropped++;
                   return 0;
           }
        */

Quoted 9 lines

and made "struct can_frame cf" (not pointer, so that I can use it in flexcan_read_fifo call)
And tried to send data again.
Now - average time in flexcan_read_frame was not 100usec, but just 2 usec! 50x less ... no CAN frame was lost, even if I was using both CAN
interfaces, each getting over 1100 msgs/sec and writing 100KB data to SD
card.

Quoted 7 lines

... but the messages need to be allocated, queued, delivered to and even
processed by a user space task. What you messure it part of the network stack overhead but 100us just for alloc_can_skb() seems quite a lot to me. At what frequency is your CPU running? Is the system low of memory? Maybe your system is simply not fast enough. To see what code is involved just follow:

CPU is i.MX25, should be running at 400MHz. There is 64MB RAM totally and free enough :(

Quoted 13 lines

http://lxr.free-electrons.com/ident?i=alloc_can_skb

Quoted 3 lines

So I am asking - how to make this alloc_can_skb faster (or is there any
alternative)? Or if there is another way how to get data to user?

Well, not with Linux-CAN. Anyway, messages arrive at a rate of approx. 1
KHz. So there is 1ms per message. I think it's a latency problem in the first place. The Flexcan on the i.MX25 can queue up to 5 messages. If the queue is full you loose messages. This obviously happens when the SDcard is accessed.

Quoted 2 lines

Quoted 1 line

Could you take function traces on your system?

Is there any special tool for this or should I use my start/stop timers?

Your start/stop timers will not show what other activity is disturbing the CAN messages reception. There is the Linux function tracer:

http://lxr.free-electrons.com/source/Documentation/trace/ftrace.txt

Quoted 8 lines

Quoted 2 lines

It need to be enabled in the kernel. Especially event and function tracing could help to better understand your problems.

Hello Wolfgang,
it seems that my architecture (arm/mx25 on 2.6.35 kernel) is missing HAVE_FUNCTION_GRAPH_TRACER, HAVE_DYNAMIC_FTRACE options so it won't be that easy, will be?
Timestamps that ftrace is showing me are in 10 miliseconds resolution, that won't help me much :(

Probably that version is to old for proper ftrace support. The 100us you measured for alloc_can_skb() is worst case, right? What is the mean value?

Quoted 7 lines

Quoted 3 lines

Flexcan support was added to the mainline kernel 2.6.36. Where did you get your flexcan driver from? Could you post it please here? Any chance to switch to a (more) recent version of the Linux kernel?

It is 2.6.35.9 kernel, I think flexcan was backported from 2.6.36 by board developer who made patch for this kernel. But I am keeping it "updated" with latest updates from 3.x kernel, so I think there should be no errors in this driver.
I tried to switch to 2.6.39 but I think there were some errors with the kernel patch that adds support for this board so I gave up. May be I should try again.

What board are you using?

I've had good success with the mainline kernel 3.4 on i.MX25 n.b. I haven't tried CAN with that board yet, but the flexcan driver is standard in that version.

Quoted 174 lines

Dne 26.10.2013 21:40, Wolfgang Grandegger napsal(a):

Quoted 173 lines · Martin Kozusky

Quoted 164 lines

Dne 25.10.2013 19:58, Wolfgang Grandegger napsal(a):

Quoted 41 lines

Hi Martin,

Quoted 37 lines · Martin Kozusky

Dne 24.10.2013 15:48, Martin Kozusky napsal(a):

Quoted 36 lines

Hello,
after more than year I'm back with CAN fifo overrun problems on i.MX25
board.
(it was good enough earlier, if some frames were lost, but not this time)

I have 2 flexcan interfaces, each receiving around 1100 msgs/s (situation is a little better if I use just one iface, but I need both)
I just configure them and then run:

I=0; while [ $I -le 20 ]; do dd if=/dev/zero of=/mnt/mmcblk0p1/test bs=512 count=200; sync; sleep 1; I=$(($I+1)); done (simulate writing to SDcard with 100KB blocks in 1 sec intervals)

and start sending data from another device.

I am not running any other program (like candump etc) to read from CAN.

this is what is shown after I finish sending 35777 packets (both interfaces now connected to same bus so they should receive same data)
with ip -d -s link show can0/1

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0

Quoted 3 lines

Do you have electrical problems on the bus? Or is reaching error-passive
not related to this problem?

It is not related to this problem - there is only RX pin connected on can0 (RX is connected in parallel with Coldfire V1 MCU CAN, which is doing TX)

Quoted 91 lines

Quoted 50 lines

Quoted 50 lines

        RX: bytes  packets  errors  dropped overrun mcast
        151769     19000    1699    0       1699    0
        TX: bytes  packets  errors  dropped carrier collsns
        0          0        0       0       0       0

root@vmx25 /opt/waytracer$ /root/utils/ip -d -s link show can1 3: can1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 0 0 0
RX: bytes packets errors dropped overrun mcast
157377 19696 2664 0 2664 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

With just one iface used:

2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN qlen 10
link/can
can <LISTEN-ONLY> state STOPPED (berr-counter tx 0 rx 0)
restart-ms 0
bitrate 250000 sample-point 0.857
tq 285 prop-seg 5 phase-seg1 6 phase-seg2 2 sjw 1
flexcan: tseg1 4..16 tseg2 2..8 sjw 1..4 brp 1..256 brp-inc 1 clock 66500000
re-started bus-errors arbit-lost error-warn error-pass bus-off
0 0 0 1 1 0
RX: bytes packets errors dropped overrun mcast
233277 29201 1483 0 1483 0
TX: bytes packets errors dropped carrier collsns
0 0 0 0 0 0

Too many packets are lost.

I tried to play with FLEXCAN_NAPI_WEIGHT (quota for napi) and that didn't hepl too much, if I put it too high then the system response was slow and packets still lost, also tried to change priority of CAN interrupts with (don't know if correctly)

      // imx_irq_set_priority(43,14);
      // imx_irq_set_priority(44,14);

But it didn't help either.

Quoted 7 lines

Quoted 1 line

Does anybody have any idea how not to lose any packets? :)

Hello,
I tried to disable
//netif_receive_skb(skb); in flexcan_read_frame() and other functions so that data is not processed further in system

Well ...

Quoted 21 lines

It didn't help.
So I tried to put time_start=ktime_get_real() at the begining of flexcan_read_frame(), then time_stop=ktime_get_real(); at the end and add their difference to the global variable time_total+=time_stop-time_start;
I divided this time_total by rx_packets count at flexcan_chip_stop and wrote with dev_info into log (variables were initialized in flexcan_chi_start, so I could just do ifconfig can0 up/down and reset those counters and write them to log), so now I had average time spent int flexcan_read_frame.
This time it was around 100usec! just with one CAN used, if both were connected, it was more than twice. And many CAN frames were lost.

So I tried to disable

       /*
           skb = alloc_can_skb(dev, &cf);
           if (unlikely(!skb)) {
                   stats->rx_dropped++;
                   return 0;
           }
        */

Quoted 9 lines

and made "struct can_frame cf" (not pointer, so that I can use it in flexcan_read_fifo call)
And tried to send data again.
Now - average time in flexcan_read_frame was not 100usec, but just 2 usec! 50x less ... no CAN frame was lost, even if I was using both CAN
interfaces, each getting over 1100 msgs/sec and writing 100KB data to SD
card.

Quoted 7 lines

... but the messages need to be allocated, queued, delivered to and even
processed by a user space task. What you messure it part of the network stack overhead but 100us just for alloc_can_skb() seems quite a lot to me. At what frequency is your CPU running? Is the system low of memory? Maybe your system is simply not fast enough. To see what code is involved just follow:

CPU is i.MX25, should be running at 400MHz. There is 64MB RAM totally and free enough :(

Quoted 13 lines

http://lxr.free-electrons.com/ident?i=alloc_can_skb

Quoted 3 lines

So I am asking - how to make this alloc_can_skb faster (or is there any
alternative)? Or if there is another way how to get data to user?

Well, not with Linux-CAN. Anyway, messages arrive at a rate of approx. 1
KHz. So there is 1ms per message. I think it's a latency problem in the first place. The Flexcan on the i.MX25 can queue up to 5 messages. If the queue is full you loose messages. This obviously happens when the SDcard is accessed.

Quoted 2 lines

Quoted 1 line

Could you take function traces on your system?

Is there any special tool for this or should I use my start/stop timers?

Your start/stop timers will not show what other activity is disturbing the CAN messages reception. There is the Linux function tracer:

http://lxr.free-electrons.com/source/Documentation/trace/ftrace.txt

Quoted 8 lines

Quoted 2 lines

It need to be enabled in the kernel. Especially event and function tracing could help to better understand your problems.

Hello Wolfgang,
it seems that my architecture (arm/mx25 on 2.6.35 kernel) is missing HAVE_FUNCTION_GRAPH_TRACER, HAVE_DYNAMIC_FTRACE options so it won't be that easy, will be?
Timestamps that ftrace is showing me are in 10 miliseconds resolution, that won't help me much :(

Probably that version is to old for proper ftrace support. The 100us you measured for alloc_can_skb() is worst case, right? What is the mean value?

Wolfgang.

--
To unsubscribe from this list: send the line "unsubscribe linux-can" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Dne 29.10.2013 13:03, Wolfgang Grandegger napsal(a):

Quoted 1 line · Martin Kozusky

Quoted 6 lines

Quoted 6 lines

Hello Wolfgang,
it seems that my architecture (arm/mx25 on 2.6.35 kernel) is missing HAVE_FUNCTION_GRAPH_TRACER, HAVE_DYNAMIC_FTRACE options so it won't be that easy, will be?
Timestamps that ftrace is showing me are in 10 miliseconds resolution, that won't help me much :(

Quoted 3 lines

Probably that version is to old for proper ftrace support. The 100us you measured for alloc_can_skb() is worst case, right? What is the mean value?

Now I checked again and logged every call (don't know if realy everything was logged but something was :) and I see that it is not 100usec, but only around 20usec (mean value - checked by eye). There were some very long calls (around 2ms!) that were puttings errors in my sum/count formula (may be I should filter out calls longer that 200usec), with this error it was not 100usec, but almost 1ms (my value was only 32bit and was overflowing when I wrote it first time). So normally around 20usec, but with very long calls around 2-3 ms (looks like those long are periodic - each 6th - 8th call is much longer, but not all the time)

But still with those 20usec call, there are many RX overflows, if I disable the call alloc_can_skb, there are no overflows and all is received (but still not processed further, because I don't have skb ... )

Quoted 2 lines

Dne 29.10.2013 13:03, Wolfgang Grandegger napsal(a):

Quoted 1 line · Martin Kozusky

...

Quoted 6 lines

Quoted 6 lines

Quoted 6 lines

Hello Wolfgang,
it seems that my architecture (arm/mx25 on 2.6.35 kernel) is missing HAVE_FUNCTION_GRAPH_TRACER, HAVE_DYNAMIC_FTRACE options so it won't be that easy, will be?
Timestamps that ftrace is showing me are in 10 miliseconds resolution, that won't help me much :(

Are high resolution timers enabled in the kernel? Still, event tracing could would already be useful.

Quoted 4 lines

Quoted 3 lines

Probably that version is to old for proper ftrace support. The 100us you measured for alloc_can_skb() is worst case, right? What is the mean value?

Quoted 10 lines

Now I checked again and logged every call (don't know if realy everything was logged but something was :) and I see that it is not 100usec, but only around 20usec (mean value - checked by eye). There were some very long calls (around 2ms!) that were puttings errors in my sum/count formula (may be I should filter out calls longer that 200usec), with this error it was not 100usec, but almost 1ms (my value was only 32bit and was overflowing when I wrote it first time). So normally around 20usec, but with very long calls around 2-3 ms (looks like those long are periodic - each 6th - 8th call is much longer, but not all the time)

Are these long latencies related to the SDcard accesses? I think the problem is the rather long latencies caused by other kernel activity. In your case caused by the MMC (SDcard) driver, I assume. The Flexcan controller does buffer up to 5 messages before loosing packets.

Quoted 3 lines

But still with those 20usec call, there are many RX overflows, if I disable the call alloc_can_skb, there are no overflows and all is received (but still not processed further, because I don't have skb ... )

Could you run this test for a longer time? The probability is just lower that RX gets interrupted for a longer time, I think.

I see a few approaches to overcome this problem:

- fix the MMC driver to cause less latency. If you are lucky this is already the case in more recent versions of the kernel.

- Use the "-rt" extension (CONFIG_PREEPMT_RT). It will then allow to adjust priorities of soft and hard irq threads.

- Do the RX processing in the interrupt context, which would require some custom modifications.

Wolfgang.

-------- Original Message --------
Subject: Re: CAN messages being lost on i.MX25 with flexcan - continued (was CAN messages being lost on i.MX25 with flexcan - 2012-04-19)
From: Wolfgang Grandegger
To: Martin Kozusky, [email protected]
Date: 29. Říjen 2013 15:30:08

Quoted 30 lines · Martin Kozusky

Quoted 2 lines

Dne 29.10.2013 13:03, Wolfgang Grandegger napsal(a):

Quoted 1 line · Martin Kozusky

...

Quoted 6 lines

Quoted 6 lines

Quoted 6 lines

Hello Wolfgang,
it seems that my architecture (arm/mx25 on 2.6.35 kernel) is missing HAVE_FUNCTION_GRAPH_TRACER, HAVE_DYNAMIC_FTRACE options so it won't be that easy, will be?
Timestamps that ftrace is showing me are in 10 miliseconds resolution, that won't help me much :(

Are high resolution timers enabled in the kernel? Still, event tracing could would already be useful.

Quoted 5 lines

Quoted 4 lines

Probably that version is to old for proper ftrace support. The 100us you
measured for alloc_can_skb() is worst case, right? What is the mean value?

Quoted 10 lines

Now I checked again and logged every call (don't know if realy everything was logged but something was :) and I see that it is not 100usec, but only around 20usec (mean value - checked by eye). There were some very long calls (around 2ms!) that were puttings errors in my sum/count formula (may be I should filter out calls longer that 200usec), with this error it was not 100usec, but almost 1ms (my value was only 32bit and was overflowing when I wrote it first time). So normally around 20usec, but with very long calls around 2-3 ms (looks like those long are periodic - each 6th - 8th call is much longer, but not all the time)

Quoted 4 lines

Are these long latencies related to the SDcard accesses? I think the problem is the rather long latencies caused by other kernel activity. In your case caused by the MMC (SDcard) driver, I assume. The Flexcan controller does buffer up to 5 messages before loosing packets.

I think it is not primary related to SD card, those tests I was doing lately were done when system was idle, no special processes were running. But when I do access SD card, problems get bigger.

Quoted 7 lines

Quoted 4 lines

But still with those 20usec call, there are many RX overflows, if I disable the call alloc_can_skb, there are no overflows and all is received (but still not processed further, because I don't have skb ... )

Could you run this test for a longer time? The probability is just lower that RX gets interrupted for a longer time, I think.

I have run it for a few minutes, problem is still the same :(

Quoted 4 lines

I see a few approaches to overcome this problem:

- fix the MMC driver to cause less latency. If you are lucky this is already the case in more recent versions of the kernel.

Hard to say if this helps when it's also doing in idle.

Quoted 2 lines

- Use the "-rt" extension (CONFIG_PREEPMT_RT). It will then allow to adjust priorities of soft and hard irq threads.

I don't know if there is a patch for this :(

Quoted 2 lines

- Do the RX processing in the interrupt context, which would require some custom modifications.

I was thinking about writing data directly to fifo file, my program would read from it

Quoted 52 lines

-------- Original Message --------
Subject: Re: CAN messages being lost on i.MX25 with flexcan - continued (was CAN messages being lost on i.MX25 with flexcan - 2012-04-19)
From: Wolfgang Grandegger
To: Martin Kozusky, [email protected]
Date: 29. Říjen 2013 15:30:08

Quoted 30 lines · Martin Kozusky

Quoted 2 lines

Dne 29.10.2013 13:03, Wolfgang Grandegger napsal(a):

Quoted 1 line · Martin Kozusky

...

Quoted 6 lines

Quoted 6 lines

Quoted 6 lines

Hello Wolfgang,
it seems that my architecture (arm/mx25 on 2.6.35 kernel) is missing HAVE_FUNCTION_GRAPH_TRACER, HAVE_DYNAMIC_FTRACE options so it won't be that easy, will be?
Timestamps that ftrace is showing me are in 10 miliseconds resolution, that won't help me much :(

Are high resolution timers enabled in the kernel? Still, event tracing could would already be useful.

Quoted 5 lines

Quoted 4 lines

Probably that version is to old for proper ftrace support. The 100us you
measured for alloc_can_skb() is worst case, right? What is the mean value?

Quoted 10 lines

Now I checked again and logged every call (don't know if realy everything was logged but something was :) and I see that it is not 100usec, but only around 20usec (mean value - checked by eye). There were some very long calls (around 2ms!) that were puttings errors in my sum/count formula (may be I should filter out calls longer that 200usec), with this error it was not 100usec, but almost 1ms (my value was only 32bit and was overflowing when I wrote it first time). So normally around 20usec, but with very long calls around 2-3 ms (looks like those long are periodic - each 6th - 8th call is much longer, but not all the time)

Quoted 4 lines

Are these long latencies related to the SDcard accesses? I think the problem is the rather long latencies caused by other kernel activity. In your case caused by the MMC (SDcard) driver, I assume. The Flexcan controller does buffer up to 5 messages before loosing packets.

I think it is not primary related to SD card, those tests I was doing lately were done when system was idle, no special processes were running. But when I do access SD card, problems get bigger.

Quoted 7 lines

Quoted 4 lines

But still with those 20usec call, there are many RX overflows, if I disable the call alloc_can_skb, there are no overflows and all is received (but still not processed further, because I don't have skb ... )

Could you run this test for a longer time? The probability is just lower that RX gets interrupted for a longer time, I think.

Quoted 7 lines

I have run it for a few minutes, problem is still the same :(

Quoted 4 lines

I see a few approaches to overcome this problem:

- fix the MMC driver to cause less latency. If you are lucky this is already the case in more recent versions of the kernel.

Hard to say if this helps when it's also doing in idle.

OK, then I misinterpreted your error description.

Quoted 6 lines

Quoted 2 lines

- Use the "-rt" extension (CONFIG_PREEPMT_RT). It will then allow to adjust priorities of soft and hard irq threads.

I don't know if there is a patch for this :(

Quoted 2 lines

- Do the RX processing in the interrupt context, which would require some custom modifications.

Quoted 2 lines

I was thinking about writing data directly to fifo file, my program would read from it

Well, before hacking something you should try to find out what is provoking the long latencies (> 1ms). FTrace is your friend. Therefore I would try to get a more recent version of the kernel running somehow. 2.6.39 should already be much better.

Wolfgang.

-------- Original Message --------
Subject: Re: CAN messages being lost on i.MX25 with flexcan - continued (was CAN messages being lost on i.MX25 with flexcan - 2012-04-19)
From: Wolfgang Grandegger
To: Martin Kožuský [KK micro s.r.o.], [email protected]
Date: 30. Říjen 2013 10:04:13

Quoted 59 lines · Martin Kožuský [KK micro s.r.o.]

Quoted 58 lines

-------- Original Message --------
Subject: Re: CAN messages being lost on i.MX25 with flexcan - continued (was CAN messages being lost on i.MX25 with flexcan - 2012-04-19)
From: Wolfgang Grandegger
To: Martin Kozusky, [email protected]
Date: 29. Říjen 2013 15:30:08

Quoted 33 lines · Martin Kozusky

Quoted 2 lines

Dne 29.10.2013 13:03, Wolfgang Grandegger napsal(a):

Quoted 1 line · Martin Kozusky

...

Quoted 8 lines

Quoted 8 lines

Quoted 8 lines

Hello Wolfgang,
it seems that my architecture (arm/mx25 on 2.6.35 kernel) is missing HAVE_FUNCTION_GRAPH_TRACER, HAVE_DYNAMIC_FTRACE options so it won't be
that easy, will be?
Timestamps that ftrace is showing me are in 10 miliseconds resolution,
that won't help me much :(

Are high resolution timers enabled in the kernel? Still, event tracing could would already be useful.

Quoted 5 lines

Quoted 4 lines

Probably that version is to old for proper ftrace support. The 100us you
measured for alloc_can_skb() is worst case, right? What is the mean value?

Quoted 11 lines

Now I checked again and logged every call (don't know if realy everything was logged but something was :) and I see that it is not 100usec, but only around 20usec (mean value - checked by eye). There were some very long calls (around 2ms!) that were puttings errors in my
sum/count formula (may be I should filter out calls longer that 200usec), with this error it was not 100usec, but almost 1ms (my value was only 32bit and was overflowing when I wrote it first time). So normally around 20usec, but with very long calls around 2-3 ms (looks like those long are periodic - each 6th - 8th call is much longer, but not all the time)

Quoted 5 lines

Are these long latencies related to the SDcard accesses? I think the problem is the rather long latencies caused by other kernel activity. In
your case caused by the MMC (SDcard) driver, I assume. The Flexcan controller does buffer up to 5 messages before loosing packets.

I think it is not primary related to SD card, those tests I was doing lately were done when system was idle, no special processes were running. But when I do access SD card, problems get bigger.

Quoted 8 lines

Quoted 4 lines

But still with those 20usec call, there are many RX overflows, if I disable the call alloc_can_skb, there are no overflows and all is received (but still not processed further, because I don't have skb ... )

Could you run this test for a longer time? The probability is just lower
that RX gets interrupted for a longer time, I think.

I have run it for a few minutes, problem is still the same :(

Quoted 15 lines

Quoted 6 lines

Quoted 5 lines

I see a few approaches to overcome this problem:

- fix the MMC driver to cause less latency. If you are lucky this is already the case in more recent versions of the kernel.

Hard to say if this helps when it's also doing in idle.

OK, then I misinterpreted your error description.

Quoted 6 lines

Quoted 2 lines

- Use the "-rt" extension (CONFIG_PREEPMT_RT). It will then allow to adjust priorities of soft and hard irq threads.

I don't know if there is a patch for this :(

Quoted 2 lines

- Do the RX processing in the interrupt context, which would require some custom modifications.

Quoted 7 lines

Quoted 2 lines

I was thinking about writing data directly to fifo file, my program would read from it

Well, before hacking something you should try to find out what is provoking the long latencies (> 1ms). FTrace is your friend. Therefore I would try to get a more recent version of the kernel running somehow. 2.6.39 should already be much better.

I will try to get new kernel running, but when I checked the patch for 2.6.35, I see some incompatibilites in directory structure and files, so I will have to go line-by-line and make my patch that will fit the new kernel. And when I do that, I will try it on latest 3.x kernel. I hope I will make it work.