dmesg shows i2c and spidev errors on bookworm 2023-12-11

[mgrouch]

Describe the bug

[36179.397186] i2c_designware 1f00074000.i2c: timeout waiting for bus ready
[36179.417868] i2c_designware 1f00074000.i2c: timeout waiting for bus ready
[36179.438707] i2c_designware 1f00074000.i2c: timeout waiting for bus ready
[36179.458975] i2c_designware 1f00074000.i2c: timeout waiting for bus ready
[36179.480084] i2c_designware 1f00074000.i2c: timeout waiting for bus ready
[36179.500519] i2c_designware 1f00074000.i2c: timeout waiting for bus ready
[36179.520695] i2c_designware 1f00074000.i2c: timeout waiting for bus ready
[36179.540765] i2c_designware 1f00074000.i2c: timeout waiting for bus ready
[36179.561087] i2c_designware 1f00074000.i2c: timeout waiting for bus ready
[36179.581862] i2c_designware 1f00074000.i2c: timeout waiting for bus ready
[36179.784769] spidev spi0.0: SPI transfer timed out
[36179.784782] spi_master spi0: failed to transfer one message from queue
[36179.988772] spidev spi0.0: SPI transfer timed out
[36179.988783] spi_master spi0: failed to transfer one message from queue
[36180.192775] spidev spi0.1: SPI transfer timed out
[36180.192787] spi_master spi0: failed to transfer one message from queue
[36180.396781] spidev spi0.1: SPI transfer timed out
[36180.396797] spi_master spi0: failed to transfer one message from queue
[36180.417872] i2c_designware 1f00074000.i2c: timeout waiting for bus ready
[36180.438976] i2c_designware 1f00074000.i2c: timeout waiting for bus ready

Steps to reproduce the behaviour

Was simply running and started happening after some time on raspberry pi5 rev 1

Device (s)

Other

System

user@lysmarine:~ $ cat /etc/rpi-issue
Raspberry Pi reference 2023-12-11
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 2acf7afcba7d11500313a7b93bb55a2aae20b2d6, stage2
user@lysmarine:~ $ vcgencmd version
2024/01/05 15:57:40
Copyright (c) 2012 Broadcom
version 30cc5f37 (release) (embedded)
user@lysmarine:~ $ uname -a
Linux lysmarine 6.1.0-rpi7-rpi-2712 #1 SMP PREEMPT Debian 1:6.1.63-1+rpt1 (2023-11-24) aarch64 GNU/Linux

Logs

Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:37 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready
Jan 17 15:43:38 lysmarine kernel: spidev spi0.0: SPI transfer timed out
Jan 17 15:43:38 lysmarine kernel: spi_master spi0: failed to transfer one message from queue
Jan 17 15:43:38 lysmarine kernel: spidev spi0.0: SPI transfer timed out
Jan 17 15:43:38 lysmarine kernel: spi_master spi0: failed to transfer one message from queue
Jan 17 15:43:38 lysmarine kernel: spidev spi0.1: SPI transfer timed out
Jan 17 15:43:38 lysmarine kernel: spi_master spi0: failed to transfer one message from queue
Jan 17 15:43:38 lysmarine kernel: spidev spi0.1: SPI transfer timed out
Jan 17 15:43:38 lysmarine kernel: spi_master spi0: failed to transfer one message from queue
Jan 17 15:43:38 lysmarine kernel: i2c_designware 1f00074000.i2c: timeout waiting for bus ready

Additional context

No response

[pelwell]

What hardware was attached? Neither I2c1 nor spi0 would normally be enabled and active.

[mgrouch]

No i2c or spi hardware is attached but kernel modules are enabled

[pelwell]

So there should have been nothing accessing the I2C an SPI busses, unless some software is probing them. Any thoughts?

Roughly how long had the Pi 5 been up when this happened? Seconds, minutes or hours?

[mgrouch]

Software called Pypilot is probing them.
https://github.com/pypilot/pypilot

However errors start after hours of probing and running without kernel errors.

So it looks there is some kind of kernel bug in drivers.

Thanks

[pelwell]

It's very suspicious that both fail at the same time - either one has failed and taken down the other (perhaps by failing to acknowledge an interrupt etc.), or some common infrastructure has failed and taken both out.

I'll have a look at what pypilot is doing and try to do more of it.

[pelwell]

Possibly caused by #5865.

[pelwell]

Probably fixed by #6044.