problem with g_iob_sem.semcount in socketCAN

[haitomatic]

Hi, I am using Nuttx SocketCAN together with UAVCAN in PX4 and got into a problem with g_iob_sem.semcount either exceeds the CONFIG_IOB_NBUFFERS or gets as low as 1. These happen expecially at high data rate (~1000fps for standard 2.0B CAN frame). When they occur, socketCAN network iface stops functional and no more RX/TX.

Regarding semcount oveflow issue, I dug into the code and noticed that in the TX path, iob_update_pktlen sporadically while doing trimming, frees up an amount of CONFIG_IOB_NBUFFERS or currently free iob buffers (most of the time equal to CONFIG_IOB_BUFFERS )

nuttx/net/devif/devif_send.c

Line 105 in c60dd72

iob_update_pktlen(dev->d_iob, offset);

This leads to g_iob_sem.semcount being increased to much higher than CONFIG_IOB_NBUFFERS.

I changed that part to

//iob_update_pktlen(dev->d_iob, offset);

  ret = iob_trycopyin(dev->d_iob, buf, len, offset, false);

  if (ret < 0 || dev->d_iob->io_pktlen != len)
    {
      netdev_iob_release(dev);
      goto errout;
    }

and I was able to get rid of the overflowed semcount problem
This is really weird since before that with netdev_iob_prepare, the new iob handle should always have io_flink NULL. And it actually does when I do a check before the line iob_update_pktlen but somehow, in that function, the whole amount of iob in g_iob_freelist is always freed up.

And for the g_iob_sem.semcount drop to 1 issue, when it happens, usually after 10mins of operation at high rate, suddenly semcount drops to 1 from a long lasting stable level around CONFIG_IOB_NBUFFERS. This issue is much harder to debug and currently I don't have any fix/workaround

Both issue happen regardless of CONFIG_IOB_NBUFFERS value, with/without CONFIG_IOB_THROTTLE, with/without CONFIG_NET_TIMESTAMP and seemingly independent of each other.

[haitomatic]

Ah, I forget to mention that this most likely is not from iob_trycopyin as one can frame fits perfectly into one buffer so there is no need for creating a chain with more than one buffer. For every new can frame, a container with a chain is allocated.
With that said, I think the problem might be instead from the execution of netdev_iob_prepare since these are the two points that call iob alloc function in socketCAN

[zhhyu7]

Can you repeat the problem with below patch? It is possible to provide new information to analyze the problem.
#9360

[acassis]

@haitomatic thank you for finding the issue very fast! If you have some idea of creating some SocketCAN performance test, please let us know. It could be useful to catch regressions like this.

[haitomatic]

I applied the patch but none of it was triggered if I also have my fixes applied.
Another news is that yesterday during enabling your assertions, I found out that one assertion https://github.com/apache/nuttx/blob/35b597ec2c0154ca675d2cd73f969c717aa3d739/mm/iob/iob_trimhead.c#LL85C32-L85C34 that I missed previously.
The fix for it is to remove the use of iob_trimhead_queue haitomatic@f932ef9#diff-3d47aba7e9a80209012a45cdcd7b1c79268783ea29b5930fb17d9f17dd64cfddL280

With all of fixes, there is no assertion at all and no free iob overflow or reaching 1. Yesterday, though it was late but I managed to have 3 test run around > 10mins each without any issue :D . I will test further today!
I justify the reasons for each hack in the code comments. Hope that it shreds some light on this.
haitomatic@f932ef9

If I use the vanilla master branch code without my fixes, then the first assertion is always violated at https://github.com/apache/nuttx/blob/35b597ec2c0154ca675d2cd73f969c717aa3d739/mm/iob/iob_free.c#LL147C6-L147C41
This is because the most common fault is freeing a problematic chain of iob with the length of ~ IOB_NBUFFERS. I dont know if it's actually freeing the whole iob free list or some other chain with roughly the same length.

[haitomatic]

And during each test, I also try to verify that the current number of free iob buffers stays approximately close to CONFIG_IOB_NBUFFERS

For instance, now using CONFIG_IOB_NBUFFERS = 128

total iob buffer : 128 ; free iob buffer : 127
total iob buffer : 128 ; free iob buffer : 124
total iob buffer : 128 ; free iob buffer : 126
total iob buffer : 128 ; free iob buffer : 125
total iob buffer : 128 ; free iob buffer : 125
total iob buffer : 128 ; free iob buffer : 127

p/s: without the fixes, when the problematic iob chain is freed, iob semcount exceeds CONFIG_IOB_NBUFFERS with a step of CONFIG_IOB_NBUFFERS each time

total iob buffer : 128 ; free iob buffer : 611
total iob buffer : 128 ; free iob buffer : 613
total iob buffer : 128 ; free iob buffer : 613
total iob buffer : 128 ; free iob buffer : 613
total iob buffer : 128 ; free iob buffer : 729
total iob buffer : 128 ; free iob buffer : 729
total iob buffer : 128 ; free iob buffer : 729
total iob buffer : 128 ; free iob buffer : 729
total iob buffer : 128 ; free iob buffer : 726
total iob buffer : 128 ; free iob buffer : 729
total iob buffer : 128 ; free iob buffer : 729
total iob buffer : 128 ; free iob buffer : 845
total iob buffer : 128 ; free iob buffer : 956
total iob buffer : 128 ; free iob buffer : 956
total iob buffer : 128 ; free iob buffer : 956
total iob buffer : 128 ; free iob buffer : 1072
total iob buffer : 128 ; free iob buffer : 1189
total iob buffer : 128 ; free iob buffer : 1189
total iob buffer : 128 ; free iob buffer : 1189
total iob buffer : 128 ; free iob buffer : 1189

free iob is retrieved from iob_getstats nfree

[haitomatic]

@acassis , maybe a test app for socketCAN like https://github.com/apache/nuttx-apps/blob/master/testing/drivertest/drivertest_uart.c just to test the middle network CAN interface. The interface to high level UAVCAN and low level CAN driver could be mocked...

[acassis]

@haitomatic yes, a drivertest_socketcan.c will be useful! To create a "sktcanperf" will require another board to receive the packet and send back another, so it is not practical for a CI test. Your suggestion is better!