Hi Marc,
On Mon, 2024-05-06 at 17:14 +0200, Marc Kleine-Budde wrote:
On 06.05.2024 15:49:18, Vitor Soares wrote:
From: Vitor Soares vitor.soares@toradex.com
When the mcp251xfd_start_xmit() function fails, the driver stops processing messages, and the interrupt routine does not return, running indefinitely even after killing the running application.
Error messages: [ 441.298819] mcp251xfd spi2.0 can0: ERROR in mcp251xfd_start_xmit: -16 [ 441.306498] mcp251xfd spi2.0 can0: Transmit Event FIFO buffer not empty. (seq=0x000017c7, tef_tail=0x000017cf, tef_head=0x000017d0, tx_head=0x000017d3). ... and repeat forever.
The issue can be triggered when multiple devices share the same SPI interface. And there is concurrent access to the bus.
The problem occurs because tx_ring->head increments even if mcp251xfd_start_xmit() fails. Consequently, the driver skips one TX package while still expecting a response in mcp251xfd_handle_tefif_one().
This patch resolves the issue by decreasing tx_ring->head and removing the skb from the echo stack if mcp251xfd_start_xmit() fails. Consequently, the package is dropped not been possible to re-transmit.
Fixes: 55e5b97f003e ("can: mcp25xxfd: add driver for Microchip MCP25xxFD SPI CAN") Cc: stable@vger.kernel.org Signed-off-by: Vitor Soares vitor.soares@toradex.com
With this approach, some packages get lost in concurrent SPI bus access due to can_put_echo_skb() being called before mcp251xfd_tx_obj_write(). The can_put_echo_skb() calls can_create_echo_skb() that consumes the original skb resulting in a Kernel NULL pointer dereference error if return NETDEV_TX_BUSY on mcp251xfd_tx_obj_write() failure. A potential solution would be to change the code to use spi_sync(), which would wait for SPI bus to be unlocked. Any thoughts about this?
This is not an option. I think you need a echo_skb function that does the necessary cleanup, something like:
void can_remove_echo_skb(struct net_device *dev, unsigned int idx) { struct can_priv *priv = netdev_priv(dev);
priv->echo_skb[idx] = NULL; }
I think you can open-code the "priv->echo_skb[idx] = NULL;" directly in the driver.
And you have to take care of calling netdev_completed_queue(priv->ndev, 1, frame_len);
I have tried this approach and got the following trace:
------------[ cut here ]------------ refcount_t: underflow; use-after-free. WARNING: CPU: 0 PID: 858 at lib/refcount.c:28 refcount_warn_saturate+0xf4/0x144 Modules linked in: can_raw can tpm_tis_spi tpm_tis_core 8021q garp stp mrp llc rf6 CPU: 0 PID: 858 Comm: cansend Not tainted 6.9.0-rc6-00132-g31a65174a15c-dirty #16 Hardware name: Toradex Verdin iMX8M Mini WB on Verdin Development Board (DT) pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--) pc : refcount_warn_saturate+0xf4/0x144 lr : refcount_warn_saturate+0xf4/0x144 sp : ffff800080003cc0 x29: ffff800080003cc0 x28: 0000000000000101 x27: ffff0000060ba0ac x26: 0000000000000000 x25: 0000000000000000 x24: ffff800080003ea4 x23: ffff8000816f9000 x22: 0000000000000000 x21: 0000000000000000 x20: ffff000009e8196c x19: ffff000009e81800 x18: 0000000000000006 x17: ffff7ffffe6dc000 x16: ffff800080000000 x15: 072007200720072e x14: 0765076507720766 x13: ffff8000817124e0 x12: 000000000000056a x11: 00000000000001ce x10: ffff80008176a4e0 x9 : ffff8000817124e0 x8 : 00000000ffffefff x7 : ffff80008176a4e0 x6 : 80000000fffff000 x5 : 0000000000000000 x4 : 0000000000000000 x3 : 0000000000000000 x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffff000003754500 Call trace refcount_warn_saturate+0xf4/0x144 sock_wfree+0x158/0x248 skb_release_head_state+0x2c/0x144 kfree_skb_reason+0x30/0xb0 can_dropped_invalid_skb+0x3c/0x17c [can_dev] mcp251xfd_start_xmit+0x78/0x4e0 [mcp251xfd] dev_hard_start_xmit+0x98/0x118 sch_direct_xmit+0x88/0x37c __qdisc_run+0x118/0x66c net_tx_action+0x158/0x218 __do_softirq+0x10c/0x264 ____do_softirq+0x10/0x1c call_on_irq_stack+0x24/0x4c do_softirq_own_stack+0x1c/0x28 do_softirq+0x54/0x6c __local_bh_enable_ip+0x8c/0x98 __dev_queue_xmit+0x224/0xd84 can_send+0xd4/0x2a4 [can raw_sendmsg+0x270/0x3a0 [can_raw] sock_write_iter+0xa4/0x110 vfs_write+0x2f0/0x358 ksys_write+0xe8/0x104 __arm64_sys_write+0x1c/0x28 invoke_syscall+0x48/0x118 el0_svc_common.constprop.0+0xc0/0xe0 do_el0_svc+0x1c/0x28 el0_svc+0x34/0xdc el0t_64_sync_handler+0x100/0x12c el0t_64_sync+0x190/0x194 --[ end trace 0000000000000000 ]---
My understanding is that can_create_echo_skb() does consume_skb(), which frees the original skb and when the stack retry to transmit again it is not there.
In consequence of this, I moved the consume_skb() from can_create_echo_skb() to the driver and I could do can_free_echo_skb() and return NETDEV_TX_BUSY without issues on my tests.
... err = mcp251xfd_tx_obj_write(priv, tx_obj); if (err) { tx_ring->head--;
if (!echo_err) { can_free_echo_skb(ndev, tx_head, &frame_len); netdev_completed_queue(ndev, 1, frame_len); }
if (mcp251xfd_get_tx_free(tx_ring)) netif_wake_queue(ndev);
if (err == -EBUSY) return NETDEV_TX_BUSY;
stats->tx_dropped++; if (net_ratelimit()) netdev_err(priv->ndev, "ERROR in %s: %d\n", __func__, err); }
consume_skb(skb); ...
Another option would be to start a workqueue and use spi_sync() in case the spi_async() is busy.
regards, Marc
Meanwhile, I wonder if there is anything to add to the current patch so I can address this topic in another patchset.
Best regards, Vitor Soares