Bug 204161 - sdhci: Lenovo GL9750 SD Host Controller - low speed, a lot of messages in dmesg
Summary: sdhci: Lenovo GL9750 SD Host Controller - low speed, a lot of messages in dmesg
Status: NEW
Alias: None
Product: Drivers
Classification: Unclassified
Component: MMC/SD (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: drivers_mmc-sd
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-07-13 12:06 UTC by Oleksii Shevchuk
Modified: 2023-11-17 20:30 UTC (History)
8 users (show)

See Also:
Kernel Version: 5.2.0
Subsystem:
Regression: No
Bisected commit-id:


Attachments
dmesg output for kernel Linux noop 5.3.6 (1.01 KB, text/plain)
2019-10-17 22:12 UTC, siphr
Details

Description Oleksii Shevchuk 2019-07-13 12:06:43 UTC
# hdparm -t /dev/mmcblk0

/dev/mmcblk0:
 HDIO_DRIVE_CMD(identify) failed: Invalid argument
 Timing buffered disk reads:  24 MB in  3.14 seconds =   7.65 MB/sec


Jul 12 22:10:54 tachi kernel: sdhci: Secure Digital Host Controller Interface driver
Jul 12 22:10:54 tachi kernel: sdhci: Copyright(c) Pierre Ossman
Jul 12 22:10:54 tachi kernel: sdhci-pci 0000:01:00.0: SDHCI controller found [17a0:9750] (rev 1)
Jul 12 22:10:54 tachi kernel: sdhci-pci 0000:01:00.0: DMAR: 32bit DMA uses non-identity mapping
Jul 12 22:10:54 tachi kernel: mmc0: SDHCI controller on PCI [0000:01:00.0] using ADMA
Jul 13 14:27:20 tachi kernel: mmc0: 1.8V regulator output did not became stable
Jul 13 14:27:20 tachi kernel: mmc0: 1.8V regulator output did not became stable
Jul 13 14:27:20 tachi kernel: mmc0: 1.8V regulator output did not became stable
Jul 13 14:27:21 tachi kernel: mmc0: 1.8V regulator output did not became stable
Jul 13 14:27:21 tachi kernel: mmc0: 1.8V regulator output did not became stable
Jul 13 14:27:21 tachi kernel: mmc0: 1.8V regulator output did not became stable
Jul 13 14:27:21 tachi kernel: mmc0: 1.8V regulator output did not became stable
Jul 13 14:27:22 tachi kernel: mmc0: 1.8V regulator output did not became stable
Jul 13 14:27:22 tachi kernel: mmc0: 1.8V regulator output did not became stable
Jul 13 14:27:22 tachi kernel: mmc0: 1.8V regulator output did not became stable
Jul 13 14:27:22 tachi kernel: mmc0: Skipping voltage switch
Jul 13 14:27:23 tachi kernel: mmc0: new high speed SDHC card at address aaaa
Jul 13 14:27:23 tachi kernel: mmcblk0: mmc0:aaaa SP32G 29.7 GiB 
Jul 13 14:27:23 tachi kernel: mmc0: Got data interrupt 0x00600000 even though no data operation was in progress.
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Sys addr:  0x00000008 | Version:  0x00000005
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Blk size:  0x00007200 | Blk cnt:  0x00000000
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Argument:  0x00002080 | Trn mode: 0x0000003f
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Present:   0x010f0000 | Host ctl: 0x00000017
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Power:     0x0000000f | Blk gap:  0x00000000
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Wake-up:   0x00000000 | Clock:    0x00000327
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Timeout:   0x00000004 | Int stat: 0x00000000
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Int enab:  0x03ff008b | Sig enab: 0x03ff008b
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: ACmd stat: 0x00000000 | Slot int: 0x00000000
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Caps:      0x25693281 | Caps_1:   0x000305f7
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Cmd:       0x0000123a | Max curr: 0x00000000
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Resp[0]:   0x00000900 | Resp[1]:  0x00edc87f
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Resp[2]:   0x325b5900 | Resp[3]:  0x00400e00
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: Host ctl2: 0x00000800
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: ADMA Err:  0x00000000 | ADMA Ptr: 0xfffff208
Jul 13 14:27:23 tachi kernel: mmc0: sdhci: ============================================
Jul 13 14:28:07 tachi kernel: mmc0: Got data interrupt 0x00600000 even though no data operation was in progress.
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: Sys addr:  0x00000208 | Version:  0x00000005
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: Blk size:  0x00007200 | Blk cnt:  0x00000000
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: Argument:  0x00750cb0 | Trn mode: 0x0000003f
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: Present:   0x01ff0000 | Host ctl: 0x00000017
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: Power:     0x0000000f | Blk gap:  0x00000000
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: Wake-up:   0x00000000 | Clock:    0x00000327
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: Timeout:   0x00000004 | Int stat: 0x00000000
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: Int enab:  0x03ff008b | Sig enab: 0x03ff008b
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: ACmd stat: 0x00000000 | Slot int: 0x00000000
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: Caps:      0x25693281 | Caps_1:   0x000305f7
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: Cmd:       0x0000123a | Max curr: 0x00000000
Jul 13 14:28:07 tachi kernel: mmc0: sdhci: Resp[0]:   0x00000900 | Resp[1]:  0x00edc87f


01:00.0 SD Host controller: Genesys Logic, Inc GL9750 SD Host Controller (rev 01) (prog-if 01)
	Subsystem: Lenovo GL9750 SD Host Controller
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0
	Interrupt: pin A routed to IRQ 16
	Region 0: Memory at bd600000 (32-bit, non-prefetchable) [size=4K]
	Capabilities: [80] Express (v2) Endpoint, MSI 00
		DevCap:	MaxPayload 128 bytes, PhantFunc 0, Latency L0s <4us, L1 <64us
			ExtTag+ AttnBtn- AttnInd- PwrInd- RBE+ FLReset- SlotPowerLimit 10.000W
		DevCtl:	CorrErr- NonFatalErr- FatalErr- UnsupReq-
			RlxdOrd+ ExtTag+ PhantFunc- AuxPwr- NoSnoop+
			MaxPayload 128 bytes, MaxReadReq 512 bytes
		DevSta:	CorrErr+ NonFatalErr- FatalErr- UnsupReq- AuxPwr+ TransPend-
		LnkCap:	Port #80, Speed 2.5GT/s, Width x1, ASPM L0s L1, Exit Latency L0s unlimited, L1 <64us
			ClockPM+ Surprise- LLActRep- BwNot- ASPMOptComp+
		LnkCtl:	ASPM L1 Enabled; RCB 64 bytes Disabled- CommClk+
			ExtSynch- ClockPM+ AutWidDis- BWInt- AutBWInt-
		LnkSta:	Speed 2.5GT/s (ok), Width x1 (ok)
			TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
		DevCap2: Completion Timeout: Range ABCD, TimeoutDis+, LTR+, OBFF Via message/WAKE#
			 AtomicOpsCap: 32bit- 64bit- 128bitCAS-
		DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR+, OBFF Disabled
			 AtomicOpsCtl: ReqEn-
		LnkCtl2: Target Link Speed: 2.5GT/s, EnterCompliance- SpeedDis-
			 Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
			 Compliance De-emphasis: -6dB
		LnkSta2: Current De-emphasis Level: -6dB, EqualizationComplete-, EqualizationPhase1-
			 EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
	Capabilities: [e0] MSI: Enable- Count=1/1 Maskable- 64bit+
		Address: 0000000000000000  Data: 0000
	Capabilities: [f8] Power Management version 3
		Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=375mA PME(D0-,D1+,D2+,D3hot+,D3cold+)
		Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME+
	Kernel driver in use: sdhci-pci
	Kernel modules: sdhci_pci
Comment 1 Warren Togami 2019-10-04 23:30:14 UTC
Still broken with Kernel v5.3.2
Comment 2 Christoph Hoopmann 2019-10-11 09:23:53 UTC
Experiencing this on a ThinkPad T490, latest BIOS/UEFI firmware as of today.

uname -r:
5.3.5-arch1-1-ARCH

lspci -vvnnk:
01:00.0 SD Host controller [0805]: Genesys Logic, Inc GL9750 SD Host Controller [17a0:9750] (rev 01) (prog-if 01)
	Subsystem: Lenovo GL9750 SD Host Controller [17aa:2279]
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0
	Interrupt: pin A routed to IRQ 16
	Region 0: Memory at dd600000 (32-bit, non-prefetchable) [size=4K]
	Capabilities: <access denied>
	Kernel driver in use: sdhci-pci
	Kernel modules: sdhci_pci

dmesg:
[ 7428.145263] mmc0: 1.8V regulator output did not became stable
[ 7428.367871] mmc0: 1.8V regulator output did not became stable
[ 7428.610686] mmc0: 1.8V regulator output did not became stable
[ 7428.842653] mmc0: 1.8V regulator output did not became stable
[ 7429.066749] mmc0: 1.8V regulator output did not became stable
[ 7429.282374] mmc0: 1.8V regulator output did not became stable
[ 7429.524700] mmc0: 1.8V regulator output did not became stable
[ 7429.741971] mmc0: 1.8V regulator output did not became stable
[ 7429.963059] mmc0: 1.8V regulator output did not became stable
[ 7430.177432] mmc0: 1.8V regulator output did not became stable
[ 7430.252845] mmc0: Skipping voltage switch
[ 7430.428569] mmc0: new high speed SDHC card at address aaaa
[ 7430.446664] mmcblk0: mmc0:aaaa SC32G 29.7 GiB 
[ 7430.451540]  mmcblk0: p1
[ 7430.550182] mmc0: Got data interrupt 0x00600000 even though no data operation was in progress.
[ 7430.550188] mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
[ 7430.550464] mmc0: sdhci: Sys addr:  0x00000008 | Version:  0x00000005
[ 7430.550469] mmc0: sdhci: Blk size:  0x00007200 | Blk cnt:  0x00000000
[ 7430.550474] mmc0: sdhci: Argument:  0x00000800 | Trn mode: 0x0000003f
[ 7430.550480] mmc0: sdhci: Present:   0x010f0000 | Host ctl: 0x00000017
[ 7430.550485] mmc0: sdhci: Power:     0x0000000f | Blk gap:  0x00000000
[ 7430.550490] mmc0: sdhci: Wake-up:   0x00000000 | Clock:    0x00000327
[ 7430.550495] mmc0: sdhci: Timeout:   0x00000004 | Int stat: 0x00000000
[ 7430.550500] mmc0: sdhci: Int enab:  0x03ff008b | Sig enab: 0x03ff008b
[ 7430.550505] mmc0: sdhci: ACmd stat: 0x00000000 | Slot int: 0x00000000
[ 7430.550511] mmc0: sdhci: Caps:      0x25693281 | Caps_1:   0x000305f7
[ 7430.550516] mmc0: sdhci: Cmd:       0x0000123a | Max curr: 0x00000000
[ 7430.550521] mmc0: sdhci: Resp[0]:   0x00000900 | Resp[1]:  0x00edc87f
[ 7430.550526] mmc0: sdhci: Resp[2]:   0x325b5900 | Resp[3]:  0x00400e00
[ 7430.550530] mmc0: sdhci: Host ctl2: 0x00000801
[ 7430.550535] mmc0: sdhci: ADMA Err:  0x00000000 | ADMA Ptr: 0xfffff208
[ 7430.550537] mmc0: sdhci: ============================================
[ 7430.640628] mmc0: Got data interrupt 0x00600000 even though no data operation was in progress.
[ 7431.883368] mmc0: card aaaa remove
Comment 3 siphr 2019-10-17 22:12:06 UTC
Created attachment 285533 [details]
dmesg output for kernel Linux noop 5.3.6
Comment 4 siphr 2019-10-17 22:14:04 UTC
DMESG OUTPUT FOR KERNEL 5.3.6 / ARCH
------------------------------------

[   42.128749] mmc0: Tuning failed, falling back to fixed sampling clock
[   42.580471] mmc0: 1.8V regulator output did not became stable
[   42.796533] mmc0: 1.8V regulator output did not became stable
[   43.013212] mmc0: 1.8V regulator output did not became stable
[   43.231854] mmc0: 1.8V regulator output did not became stable
[   43.453921] mmc0: 1.8V regulator output did not became stable
[   43.672812] mmc0: 1.8V regulator output did not became stable
[   43.892453] mmc0: 1.8V regulator output did not became stable
[   44.102860] mmc0: 1.8V regulator output did not became stable
[   44.337086] mmc0: 1.8V regulator output did not became stable
[   44.554600] mmc0: 1.8V regulator output did not became stable
[   44.603683] mmc0: Skipping voltage switch
[   44.789418] blk_update_request: I/O error, dev mmcblk0, sector 32800 op 0x0:(READ) flags 0x80700 phys_seg 7 prio class 0
[   55.042431] mmc0: Card stuck in wrong state! mmcblk0 card_busy_detect status: 0xd00
[   55.070231] fuse: init (API version 7.31)
Comment 5 Christoph Hoopmann 2019-11-14 07:05:34 UTC
Still broken in 5.3.11-arch1-1
Comment 6 Sergey Yanovich 2019-12-04 06:51:24 UTC
Old slow cards work normally. New fast cards don't. Something is wrong with timers.

===8<===
$ uname -a
Linux host2 5.3.0-24-generic #26-Ubuntu SMP Thu Nov 14 01:33:18 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
===8<===

===8<===
[ 4730.780238] mmc0: new high speed SDHC card at address 59b4
[ 4730.781256] mmcblk0: mmc0:59b4 USD   3.75 GiB 
[ 4730.795216]  mmcblk0: p1 p2
[ 4840.804268] mmc0: card 59b4 removed
===8<===

===8<===
[    4.423644] mmc0: new ultra high speed SDR104 SDXC card at address 0007
[    4.428823] mmcblk0: mmc0:0007 SD128 117 GiB 
[    4.878286] mmc0: 1.8V regulator output did not became stable
[    5.073727] mmc0: tried to HW reset card, got error -2
[    5.099167] mmcblk0: error -110 requesting status
[    5.099169] mmcblk0: recovery failed!
[    5.099177] blk_update_request: I/O error, dev mmcblk0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[    5.099179] Buffer I/O error on dev mmcblk0, logical block 0, async page read
[    5.130379] mmcblk0: error -110 requesting status
[    5.130382] mmcblk0: recovery failed!
[    5.130388] blk_update_request: I/O error, dev mmcblk0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[    5.130390] Buffer I/O error on dev mmcblk0, logical block 0, async page read
[    5.159459] mmcblk0: error -110 requesting status
[    5.159462] mmcblk0: recovery failed!
[    5.159468] blk_update_request: I/O error, dev mmcblk0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[    5.159471] Buffer I/O error on dev mmcblk0, logical block 0, async page read
[    5.159478] ldm_validate_partition_table(): Disk read failed.
[    5.190298] mmcblk0: error -110 requesting status
[    5.190301] mmcblk0: recovery failed!
[    5.190309] blk_update_request: I/O error, dev mmcblk0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[    5.190312] Buffer I/O error on dev mmcblk0, logical block 0, async page read
[    5.223563] mmcblk0: error -110 requesting status
[    5.223566] mmcblk0: recovery failed!
[    5.223575] blk_update_request: I/O error, dev mmcblk0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[    5.223577] Buffer I/O error on dev mmcblk0, logical block 0, async page read
[    5.261177] mmcblk0: error -110 requesting status
[    5.261180] mmcblk0: recovery failed!
[    5.261188] blk_update_request: I/O error, dev mmcblk0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[    5.261191] Buffer I/O error on dev mmcblk0, logical block 0, async page read
[    5.296713] mmcblk0: error -110 requesting status
[    5.296715] mmcblk0: recovery failed!
[    5.296722] blk_update_request: I/O error, dev mmcblk0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[    5.296723] Buffer I/O error on dev mmcblk0, logical block 0, async page read
[    5.296777] Dev mmcblk0: unable to read RDB block 0
[    5.326798] mmcblk0: error -110 requesting status
[    5.326801] mmcblk0: recovery failed!
[    5.326807] blk_update_request: I/O error, dev mmcblk0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[    5.326809] Buffer I/O error on dev mmcblk0, logical block 0, async page read
[    5.358035] mmcblk0: error -110 requesting status
[    5.358037] mmcblk0: recovery failed!
[    5.358044] blk_update_request: I/O error, dev mmcblk0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[    5.358046] Buffer I/O error on dev mmcblk0, logical block 0, async page read
[    5.395859] mmcblk0: error -110 requesting status
[    5.395862] mmcblk0: recovery failed!
[    5.395871] blk_update_request: I/O error, dev mmcblk0, sector 24 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[    5.395873] Buffer I/O error on dev mmcblk0, logical block 3, async page read
[    5.430621] mmcblk0: error -110 requesting status
[    5.430625] mmcblk0: recovery failed!
[    5.466291] mmcblk0: error -110 requesting status
[    5.466294] mmcblk0: recovery failed!
[    5.466342]  mmcblk0: unable to read partition table
[    5.500077] mmcblk0: error -110 requesting status
[    5.500080] mmcblk0: recovery failed!
[    5.533872] mmcblk0: error -110 requesting status
[    5.533875] mmcblk0: recovery failed!
===8<===
Comment 7 gruberm 2023-11-17 20:30:43 UTC
Slightly OT:
could someone with a GL9750 based card reader test their device for data writing integrity on a recent kernel?
I'm on kernel 6.1.62 using the integrated GL9750 of a Lenovo Ideapad 5 Pro.
I tested 4 different SD cards:

1. cp some_ubuntu.iso /path/to/sdcard/1.iso
   cp some_ubuntu.iso /path/to/sdcard/2.iso
   cp some_ubuntu.iso /path/to/sdcard/3.iso

2. sha256sum some_ubuntu.iso && sha256sum /path/to/sdcard/*.iso

3. No matching checksum, the copies on the SD cards all differ.

When I run Windows 11 on the laptop, the GL9750 writes files with correct checksums to the cards, so I assume it's a bug and not a hardware issue.
I verified the SD cards also with an external SD card reader on a second computer, they're OK.

Note You need to log in before you can comment on or make changes to this bug.