Netdev List
 help / color / mirror / Atom feed
From: Torin Cooper-Bennun <torin@maxiluxsystems.com>
To: linux-can@vger.kernel.org, netdev@vger.kernel.org
Subject: CAN: TX frames marked as RX after the sending socket is closed
Date: Mon, 10 May 2021 15:23:02 +0100	[thread overview]
Message-ID: <20210510142302.ijbwowv4usoiqkxq@bigthink> (raw)

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


             reply	other threads:[~2021-05-10 15:05 UTC|newest]

Thread overview: 6+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2021-05-10 14:23 Torin Cooper-Bennun [this message]
2021-05-10 15:35 ` CAN: TX frames marked as RX after the sending socket is closed Marc Kleine-Budde
2021-05-11  9:20   ` Torin Cooper-Bennun
2021-05-10 18:18 ` Marc Kleine-Budde
2021-05-11  9:28   ` Torin Cooper-Bennun
2021-05-11 10:01     ` Marc Kleine-Budde

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20210510142302.ijbwowv4usoiqkxq@bigthink \
    --to=torin@maxiluxsystems.com \
    --cc=linux-can@vger.kernel.org \
    --cc=netdev@vger.kernel.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox