linux-kernel - Occasional `READ LOG DMA EXT failed, trying PIO` with Crucial CT1000MX500SSD4

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [day] [month] [year] [list]

Date:   Mon, 23 Jul 2018 13:07:13 +0200
From:   Paul Menzel <pmenzel+linux-ide@...gen.mpg.de>
To:     Tejun Heo <tj@...nel.org>
Cc:     linux-ide@...r.kernel.org, linux-kernel@...r.kernel.org
Subject: Occasional `READ LOG DMA EXT failed, trying PIO` with Crucial
 CT1000MX500SSD4

Dear Linux folks,


On the MSI B350M MORTAR (MS-7A37) with Linux 4.18-rc5+ sometimes the Crucial
CT1000MX500SSD4 takes longer to be set up.

Please note the five second delay below.

[    1.173251] calling  ata_init+0x0/0x316 [libata] @ 131
[    1.173473] libata version 3.00 loaded.
[    1.173481] initcall ata_init+0x0/0x316 [libata] returned 0 after 216 usecs
[    1.197399] ata1: SATA max UDMA/133 abar m131072@...e880000 port 0xfe880100 irq 36
[    1.197783] ata2: SATA max UDMA/133 abar m131072@...e880000 port 0xfe880180 irq 36
[    1.198151] ata3: DUMMY
[    1.198513] ata4: DUMMY
[    1.198875] ata5: SATA max UDMA/133 abar m131072@...e880000 port 0xfe880300 irq 36
[    1.199262] ata6: SATA max UDMA/133 abar m131072@...e880000 port 0xfe880380 irq 36
[    1.199646] ata7: DUMMY
[    1.200063] ata8: DUMMY
[    1.214407] ata9: SATA max UDMA/133 abar m2048@...e900000 port 0xfe900100 irq 38
[    1.516055] ata1: SATA link down (SStatus 0 SControl 300)
[    1.692953] ata9: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[    1.694177] ata9.00: supports DRM functions and may not be fully accessible
[    1.694804] ata9.00: ATA-10: CT1000MX500SSD4, M3CR020, max UDMA/133
[    1.695384] ata9.00: 1953525168 sectors, multi 1: LBA48 NCQ (depth 32), AA
[    1.696425] ata9.00: READ LOG DMA EXT failed, trying PIO
[    1.697029] ata9.00: failed to get Identify Device Data, Emask 0x40
[    1.697030] ata9.00: ATA Identify Device Log not supported
[    1.697620] ata9.00: Security Log not supported
[    1.698229] ata9.00: failed to set xfermode (err_mask=0x40)
[    1.831151] ata2: SATA link down (SStatus 0 SControl 300)
[    2.147453] ata5: SATA link down (SStatus 0 SControl 300)
[    2.463944] ata6: SATA link down (SStatus 0 SControl 300)
[    7.352228] ata9: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[    7.353725] ata9.00: supports DRM functions and may not be fully accessible
[    7.355235] ata9.00: supports DRM functions and may not be fully accessible
[    7.356590] ata9.00: configured for UDMA/133

Please find the output in the desired case below.

[    2.908781] calling  ata_init+0x0/0x316 [libata] @ 126
[    2.914312] libata version 3.00 loaded.
[    2.919816] initcall ata_init+0x0/0x316 [libata] returned 0 after 5610 usecs
[    3.019944] ata1: SATA max UDMA/133 abar m131072@...e880000 port 0xfe880100 irq 36
[    3.028015] ata2: SATA max UDMA/133 abar m131072@...e880000 port 0xfe880180 irq 36
[    3.035887] ata3: DUMMY
[    3.038712] ata4: DUMMY
[    3.041539] ata5: SATA max UDMA/133 abar m131072@...e880000 port 0xfe880300 irq 36
[    3.049432] ata6: SATA max UDMA/133 abar m131072@...e880000 port 0xfe880380 irq 36
[    3.066803] ata7: DUMMY
[    3.078267] ata8: DUMMY
[    3.126502] ata9: SATA max UDMA/133 abar m2048@...e900000 port 0xfe900100 irq 39
[    3.406008] ata1: SATA link down (SStatus 0 SControl 300)
[    3.608309] ata9: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[    3.616565] ata9.00: supports DRM functions and may not be fully accessible
[    3.623971] ata9.00: ATA-10: CT1000MX500SSD4, M3CR020, max UDMA/133
[    3.630651] ata9.00: 1953525168 sectors, multi 1: LBA48 NCQ (depth 32), AA
[    3.638585] ata9.00: supports DRM functions and may not be fully accessible
[    3.646503] ata9.00: configured for UDMA/133
[    3.730171] ata2: SATA link down (SStatus 0 SControl 300)
[    4.053500] ata5: SATA link down (SStatus 0 SControl 300)
[    4.376028] ata6: SATA link down (SStatus 0 SControl 300)

The full Linux messages for both case are attached.

The problem in the slow case seems to be a failure in reading an
extension.

> READ LOG DMA EXT failed, trying PIO

Is that a drive firmware bug – and I should therefore return the device, as
upgrading the drive firmware is probably not easy – or something else?

Also, I found bug report *failed to set xfermode (err_mask=0x40) on some
SSDs* [1] in the Kernel.org bugzilla.


Kind regards,

Paul


[1]: https://bugzilla.kernel.org/show_bug.cgi?id=195895

View attachment "dmesg-fast-detection.txt" of type "text/plain" (152229 bytes)

View attachment "dmesg-slow-detection.txt" of type "text/plain" (146492 bytes)

Download attachment "smime.p7s" of type "application/pkcs7-signature" (5174 bytes)