Hi,
Scenario: I open a raw CAN socket, queue a bunch of frames for TX, then
close the socket as soon as possible. For the duration of the test, I
have another socket open listening for all frames (candump).
After the sending socket has been closed, and there are still frames in
the queue yet to be transmitted, I find candump reporting the remainder
of my sent frames as RX rather than TX.
For example, I send 1,000 8-byte classical CAN frames, immediately close
the socket and log the time at which I did so.
My application reports the socket closed:
| Socket closed at 15:02:45.987278
My candump log shows:
| (2021-05-10 15:02:45.327724) can0 TX - - 000 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:45.329578) can0 TX - - 001 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:45.330493) can0 TX - - 002 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:45.331341) can0 TX - - 003 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:45.332264) can0 TX - - 004 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:45.333148) can0 TX - - 005 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:45.334115) can0 TX - - 006 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:45.335061) can0 TX - - 007 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:45.336021) can0 TX - - 008 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:45.336951) can0 TX - - 009 [08] EE EE EE EE EE EE EE EE
|
| .... snip ....
|
| (2021-05-10 15:02:46.089177) can0 TX - - 399 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.090001) can0 TX - - 39A [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.090852) can0 TX - - 39B [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.091735) can0 TX - - 39C [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.092483) can0 TX - - 39D [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.093313) can0 RX - - 39E [08] EE EE EE EE EE EE EE EE <----- !!!!!
| (2021-05-10 15:02:46.094091) can0 RX - - 39F [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.094931) can0 RX - - 3A0 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.095774) can0 RX - - 3A1 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.096513) can0 RX - - 3A2 [08] EE EE EE EE EE EE EE EE
|
| .... snip ....
|
| (2021-05-10 15:02:46.143287) can0 RX - - 3DE [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.144046) can0 RX - - 3DF [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.144808) can0 RX - - 3E0 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.145570) can0 RX - - 3E1 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.146357) can0 RX - - 3E2 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.147117) can0 RX - - 3E3 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.147876) can0 RX - - 3E4 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.148635) can0 RX - - 3E5 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.149395) can0 RX - - 3E6 [08] EE EE EE EE EE EE EE EE
| (2021-05-10 15:02:46.150161) can0 RX - - 3E7 [08] EE EE EE EE EE EE EE EE
Why?
candump.c prints 'RX' if the received frame has no MSG_DONTROUTE flag.
| if (msg.msg_flags & MSG_DONTROUTE)
| printf (" TX %s", extra_m_info[frame.flags & 3]);
| else
| printf (" RX %s", extra_m_info[frame.flags & 3]);
In turn, MSG_DONTROUTE is set in net/can/raw.c: raw_rcv():
| /* add CAN specific message flags for raw_recvmsg() */
| pflags = raw_flags(skb);
| *pflags = 0;
| if (oskb->sk)
| *pflags |= MSG_DONTROUTE;
| if (oskb->sk == sk)
| *pflags |= MSG_CONFIRM;
So, I'm guessing, some 100 ms after my application begins to request
that the socket be closed, the socket's pointer becomes NULL in further
TX skbs in the queue, so the raw CAN layer can no longer differentiate
these skbs as TX. (Sorry if my pathways are a bit mixed up.)
Seems broken to me - is this known behaviour?
Test setup:
- kernel: v5.13-rc1 with some RPi-specific patches
- hardware: RPi CM4 with TCAN4550 (so, m_can driver in peripheral mode)
--
Regards,
Torin Cooper-Bennun
Software Engineer | maxiluxsystems.com
