netdev - Re: CAN: TX frames marked as RX after the sending socket is closed

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <20210510153540.52uzcndqyp6yu7ve@pengutronix.de>
Date:   Mon, 10 May 2021 17:35:40 +0200
From:   Marc Kleine-Budde <mkl@...gutronix.de>
To:     Torin Cooper-Bennun <torin@...iluxsystems.com>
Cc:     linux-can@...r.kernel.org, netdev@...r.kernel.org
Subject: Re: CAN: TX frames marked as RX after the sending socket is closed

On 10.05.2021 15:23:02, Torin Cooper-Bennun wrote:
> 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.

Can you provide the program to reproduce the issue?
Have you increased the CAN interface's txqueuelen?

> 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?

Looks like a unknown bug to me!

> Test setup:
>  - kernel: v5.13-rc1 with some RPi-specific patches
>  - hardware: RPi CM4 with TCAN4550 (so, m_can driver in peripheral mode)

regards,
Marc

-- 
Pengutronix e.K.                 | Marc Kleine-Budde           |
Embedded Linux                   | https://www.pengutronix.de  |
Vertretung West/Dortmund         | Phone: +49-231-2826-924     |
Amtsgericht Hildesheim, HRA 2686 | Fax:   +49-5121-206917-5555 |

Download attachment "signature.asc" of type "application/pgp-signature" (489 bytes)