Mute SDHCI REGISTER DUMP

[dwrobel]

kernel: 4.19.120

I'm running rpi4 directly from the usb storage and see this log in: serial console, journald and dmesg:

Jun 03 18:29:18 dw-rpi4 kernel: mmc0: Timeout waiting for hardware cmd interrupt.
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Sys addr:  0x00000000 | Version:  0x00001002
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Blk size:  0x00000000 | Blk cnt:  0x00000000
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Argument:  0x00000000 | Trn mode: 0x00000000
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Present:   0x1fff0001 | Host ctl: 0x00000001
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Power:     0x0000000f | Blk gap:  0x00000080
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Wake-up:   0x00000000 | Clock:    0x0000f447
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Timeout:   0x00000000 | Int stat: 0x00000000
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Int enab:  0x00ff1003 | Sig enab: 0x00ff1003
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: ACmd stat: 0x00000000 | Slot int: 0x00000000
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Caps:      0x45ee6432 | Caps_1:   0x0000a525
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Cmd:       0x00000502 | Max curr: 0x00080008
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Resp[0]:   0x00000000 | Resp[1]:  0x00000000
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Resp[2]:   0x00000000 | Resp[3]:  0x00000000
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: Host ctl2: 0x00000000
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: ADMA Err:  0x00000000 | ADMA Ptr: 0x00000000
Jun 03 18:29:18 dw-rpi4 kernel: mmc0: sdhci: ============================================
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: Timeout waiting for hardware cmd interrupt.
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Sys addr:  0x00000000 | Version:  0x00001002
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Blk size:  0x00000000 | Blk cnt:  0x00000000
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Argument:  0x00000000 | Trn mode: 0x00000000
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Present:   0x1fff0001 | Host ctl: 0x00000001
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Power:     0x0000000f | Blk gap:  0x00000080
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Wake-up:   0x00000000 | Clock:    0x0000f447
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Timeout:   0x00000000 | Int stat: 0x00000000
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Int enab:  0x00ff1003 | Sig enab: 0x00ff1003
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: ACmd stat: 0x00000000 | Slot int: 0x00000000
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Caps:      0x45ee6432 | Caps_1:   0x0000a525
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Cmd:       0x00000502 | Max curr: 0x00080008
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Resp[0]:   0x00000000 | Resp[1]:  0x00000000
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Resp[2]:   0x00000000 | Resp[3]:  0x00000000
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: Host ctl2: 0x00000000
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: ADMA Err:  0x00000000 | ADMA Ptr: 0x00000000
Jun 03 18:30:24 dw-rpi4 kernel: mmc0: sdhci: ============================================
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: Timeout waiting for hardware cmd interrupt.
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Sys addr:  0x00000000 | Version:  0x00001002
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Blk size:  0x00000000 | Blk cnt:  0x00000000
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Argument:  0x80000c08 | Trn mode: 0x00000000
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Present:   0x1fff0001 | Host ctl: 0x00000001
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Power:     0x0000000f | Blk gap:  0x00000080
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Wake-up:   0x00000000 | Clock:    0x0000f447
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Timeout:   0x00000000 | Int stat: 0x00000000
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Int enab:  0x00ff1003 | Sig enab: 0x00ff1003
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: ACmd stat: 0x00000000 | Slot int: 0x00000000
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Caps:      0x45ee6432 | Caps_1:   0x0000a525
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Cmd:       0x0000341a | Max curr: 0x00080008
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Resp[0]:   0x00000000 | Resp[1]:  0x00000000
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Resp[2]:   0x00000000 | Resp[3]:  0x00000000
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: Host ctl2: 0x00000000
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: ADMA Err:  0x00000000 | ADMA Ptr: 0x00000000
Jun 03 18:32:43 dw-rpi4 kernel: mmc0: sdhci: ============================================

Would you please consider to mute this repetitive message?

[timg236]

dtparam=sd_poll_once

[JamesH65]

Although I beleive that will disable SD card hotplug?

[pelwell]

Yes it will:

spi@raspberrypi:~$ dtparam -h sd_poll_once
sd_poll_once            Looks for a card once after booting. Useful
                        for network booting scenarios to avoid the
                        overhead of continuous polling. N.B. Using
                        this option restricts the system to using a
                        single card per boot (or none at all).
                        (default off)

Are you suggesting we should alter the upstream SDHCI driver?

[JamesH65]

Seems odd that simply polling for it produces such a large error message, I would expect polling to be quiet unless there was actually something wrong.

[dwrobel]

I would expect polling to be quiet unless there was actually something wrong.

I second this approach.

[pelwell]

The MMC/SD standard is pretty horrible. In order to work out what kind of card is present you have to try a bunch of things and if they timeout then you know it wasn't one of them. The MMC framework (or perhaps just the driver) doesn't distinguish between expected and unexpected timeouts, and the driver reports both the same.

The issue

[timg236]

Perhaps we disable the broken-cd property if the root file system is NFS or USB-MSD since Pi 4 has card-detect so it shouldn't need to poll. Although, if card-detect is muxed with something else that could cause problems.