2024-05-06 15:00:51

by Vitor Soares

[permalink] [raw]
Subject: [PATCH v4] can: mcp251xfd: fix infinite loop when xmit fails

From: Vitor Soares <[email protected]>

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: [email protected]
Signed-off-by: Vitor Soares <[email protected]>
---
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?

V3->V4:
- Leave can_put_echo_skb() and stop the queue if needed, before mcp251xfd_tx_obj_write().
- Re-sync head and remove echo skb if mcp251xfd_tx_obj_write() fails.
- Revert -> return NETDEV_TX_BUSY if mcp251xfd_tx_obj_write() == -EBUSY.

V2->V3:
- Add tx_dropped stats.
- netdev_sent_queue() only if can_put_echo_skb() succeed.

V1->V2:
- Return NETDEV_TX_BUSY if mcp251xfd_tx_obj_write() == -EBUSY.
- Rework the commit message to address the change above.
- Change can_put_echo_skb() to be called after mcp251xfd_tx_obj_write() succeed.
Otherwise, we get Kernel NULL pointer dereference error.

drivers/net/can/spi/mcp251xfd/mcp251xfd-tx.c | 26 ++++++++++++++------
1 file changed, 18 insertions(+), 8 deletions(-)

diff --git a/drivers/net/can/spi/mcp251xfd/mcp251xfd-tx.c b/drivers/net/can/spi/mcp251xfd/mcp251xfd-tx.c
index 160528d3cc26..9909e23de7b9 100644
--- a/drivers/net/can/spi/mcp251xfd/mcp251xfd-tx.c
+++ b/drivers/net/can/spi/mcp251xfd/mcp251xfd-tx.c
@@ -166,11 +166,12 @@ netdev_tx_t mcp251xfd_start_xmit(struct sk_buff *skb,
struct net_device *ndev)
{
struct mcp251xfd_priv *priv = netdev_priv(ndev);
+ struct net_device_stats *stats = &ndev->stats;
struct mcp251xfd_tx_ring *tx_ring = priv->tx;
struct mcp251xfd_tx_obj *tx_obj;
unsigned int frame_len;
+ int err, echo_err;
u8 tx_head;
- int err;

if (can_dev_dropped_skb(ndev, skb))
return NETDEV_TX_OK;
@@ -188,18 +189,27 @@ netdev_tx_t mcp251xfd_start_xmit(struct sk_buff *skb,
netif_stop_queue(ndev);

frame_len = can_skb_get_frame_len(skb);
- err = can_put_echo_skb(skb, ndev, tx_head, frame_len);
- if (!err)
+ echo_err = can_put_echo_skb(skb, ndev, tx_head, frame_len);
+ if (!echo_err)
netdev_sent_queue(priv->ndev, frame_len);

err = mcp251xfd_tx_obj_write(priv, tx_obj);
- if (err)
- goto out_err;
+ if (err) {
+ tx_ring->head--;

- return NETDEV_TX_OK;
+ 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);

- out_err:
- netdev_err(priv->ndev, "ERROR in %s: %d\n", __func__, err);
+ stats->tx_dropped++;
+ if (net_ratelimit())
+ netdev_err(priv->ndev,
+ "ERROR in %s: %d\n", __func__, err);
+ }

return NETDEV_TX_OK;
}
--
2.34.1



2024-05-06 15:15:19

by Marc Kleine-Budde

[permalink] [raw]
Subject: Re: [PATCH v4] can: mcp251xfd: fix infinite loop when xmit fails

On 06.05.2024 15:49:18, Vitor Soares wrote:
> From: Vitor Soares <[email protected]>
>
> 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: [email protected]
> Signed-off-by: Vitor Soares <[email protected]>
> ---
> 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);

Another option would be to start a workqueue and use spi_sync() in case
the spi_async() is busy.

regards,
Marc

--
Pengutronix e.K. | Marc Kleine-Budde |
Embedded Linux | https://www.pengutronix.de |
Vertretung Nürnberg | Phone: +49-5121-206917-129 |
Amtsgericht Hildesheim, HRA 2686 | Fax: +49-5121-206917-9 |


Attachments:
(No filename) (2.61 kB)
signature.asc (499.00 B)
Download all attachments

2024-05-07 14:04:38

by Vitor Soares

[permalink] [raw]
Subject: Re: [PATCH v4] can: mcp251xfd: fix infinite loop when xmit fails

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 <[email protected]>
> >
> > 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: [email protected]
> > Signed-off-by: Vitor Soares <[email protected]>
> > ---
> > 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