Regression due to "libata: implement SECURITY PROTOCOL IN/OUT"

Regression due to "libata: implement SECURITY PROTOCOL IN/OUT"

[Ido Schimmel]

Hi,

Booting kernel v4.13-rc6 on my system results in the following errors in
the kernel log:

ata5.00: qc timeout (cmd 0x47)
ata5.00: READ LOG DMA EXT failed, trying PIO
ata5.00: ATA Identify Device Log not supported
ata5.00: Security Log not supported
ata5.00: failed to set xfermode (err_mask=0x40)
ata5: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
ata5.00: qc timeout (cmd 0xec)
ata5.00: failed to IDENTIFY (I/O error, err_mask=0x5)
ata5.00: revalidation failed (errno=-5)
ata5: limiting SATA link speed to 3.0 Gbps
ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
ata5.00: qc timeout (cmd 0xec)
ata5.00: failed to IDENTIFY (I/O error, err_mask=0x5)
ata5.00: revalidation failed (errno=-5)
ata5.00: disabled
ata5: hard resetting link
ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
ata5: EH complete

And a dracut shell. Bisected this down to commit 818831c8b22f ("libata:
implement SECURITY PROTOCOL IN/OUT"). Can you please look into it? I can
easily test your patches.

I didn't find any relevant patches in patchwork or similar reports
beside this one:
https://www.spinics.net/lists/kernel/msg2533719.html

To which no one replied.

Thanks!

More info that might help:

Full bisection log:

git bisect start
# bad: [5771a8c08880cdca3bfb4a3fc6d309d6bba20877] Linux v4.13-rc1
git bisect bad 5771a8c08880cdca3bfb4a3fc6d309d6bba20877
# good: [6f7da290413ba713f0cdd9ff1a2a9bb129ef4f6c] Linux 4.12
git bisect good 6f7da290413ba713f0cdd9ff1a2a9bb129ef4f6c
# good: [e5f76a2e0e84ca2a215ecbf6feae88780d055c56] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/ebiederm/user-namespace
git bisect good e5f76a2e0e84ca2a215ecbf6feae88780d055c56
# bad: [bd78acad8e866e1167f9de97c9b090ee6c2c96a7] parisc: move generic-y of exported headers to uapi/asm/Kbuild
git bisect bad bd78acad8e866e1167f9de97c9b090ee6c2c96a7
# bad: [e0f25a3f2d052e36ff67a9b4db835c3e27e950d8] Merge tag 'hwlock-v4.13' of git://github.com/andersson/remoteproc
git bisect bad e0f25a3f2d052e36ff67a9b4db835c3e27e950d8
# bad: [920f2ecdf6c3b3526f60fbd38c68597953cad3ee] Merge tag 'sound-4.13-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/tiwai/sound
git bisect bad 920f2ecdf6c3b3526f60fbd38c68597953cad3ee
# good: [b821d298f8864dc3c3d42643812df43289159507] Merge remote-tracking branch 'asoc/topic/inte' into asoc-next
git bisect good b821d298f8864dc3c3d42643812df43289159507
# good: [7fc8e7c1d9787ab8cb0f91adb3bc9c2c64c00ef8] Merge branch 'for-linus' into for-next
git bisect good 7fc8e7c1d9787ab8cb0f91adb3bc9c2c64c00ef8
# good: [9b51f04424e17051a89ab32d892ca66b2a104825] Merge branch 'parisc-4.13-2' of git://git.kernel.org/pub/scm/linux/kernel/git/deller/parisc-linux
git bisect good 9b51f04424e17051a89ab32d892ca66b2a104825
# bad: [109a5db5042c035ded330b948a710b9a0c20934d] Merge branch 'for-4.13' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/libata
git bisect bad 109a5db5042c035ded330b948a710b9a0c20934d
# bad: [79af3ae6e293855321dcd1a43c73be316fdff1a9] ata: pata_octeon_cf: make of_device_ids const.
git bisect bad 79af3ae6e293855321dcd1a43c73be316fdff1a9
# good: [f01f62c257cc343246a5a9b2df8135f01fc044ab] libata: move ata_read_log_page to libata-core.c
git bisect good f01f62c257cc343246a5a9b2df8135f01fc044ab
# bad: [af36ddc988922adc00221b37662120cd78f4aa7d] ata: Add DT bindings for Faraday Technology FTIDE010
git bisect bad af36ddc988922adc00221b37662120cd78f4aa7d
# good: [1d51d5f3907abf86ef0521971bcddf5853564263] libata: clarify log page naming / grouping
git bisect good 1d51d5f3907abf86ef0521971bcddf5853564263
# bad: [818831c8b22f75353f59a63a484e20736c0567c9] libata: implement SECURITY PROTOCOL IN/OUT
git bisect bad 818831c8b22f75353f59a63a484e20736c0567c9
# good: [a0fd2454a36ffab2ce39b3a91c1385a5f98e63f0] libata: factor out a ata_identify_page_supported helper
git bisect good a0fd2454a36ffab2ce39b3a91c1385a5f98e63f0
# first bad commit: [818831c8b22f75353f59a63a484e20736c0567c9] libata: implement SECURITY PROTOCOL IN/OUT

Relevant hardware info:

$ lshw -class disk
  *-disk                    
       description: ATA Disk
       product: M.2 (S42) 3ME3
       physical id: 0.0.0
       bus info: scsi@4:0.0.0
       logical name: /dev/sda
       version: 19
       serial: 20161029AA101511210E
       size: 14GiB (16GB)
       capabilities: partitioned partitioned:dos
       configuration: ansiversion=5 logicalsectorsize=512 sectorsize=512 signature=8de6ec69
$ lshw -class storage
  *-storage:0               
       description: SATA controller
       product: Atom processor C2000 AHCI SATA2 Controller
       vendor: Intel Corporation
       physical id: 17
       bus info: pci@0000:00:17.0
       version: 02
       width: 32 bits
       clock: 66MHz
       capabilities: storage msi pm ahci_1.0 bus_master cap_list
       configuration: driver=ahci latency=0
       resources: irq:27 ioport:f0f0(size=8) ioport:f0e0(size=4) ioport:f0d0(size=8) ioport:f0c0(size=4) ioport:f040(size=32) memory:dfcaa000-dfcaa7ff
  *-storage:1
       description: SATA controller
       product: Atom processor C2000 AHCI SATA3 Controller
       vendor: Intel Corporation
       physical id: 18
       bus info: pci@0000:00:18.0
       version: 02
       width: 32 bits
       clock: 66MHz
       capabilities: storage msi pm ahci_1.0 bus_master cap_list
       configuration: driver=ahci latency=0
       resources: irq:28 ioport:f0b0(size=8) ioport:f0a0(size=4) ioport:f090(size=8) ioport:f080(size=4) ioport:f020(size=32) memory:dfca9000-dfca97ff
  *-scsi
       physical id: 1
       logical name: scsi4
       capabilities: emulated

Re: Regression due to "libata: implement SECURITY PROTOCOL IN/OUT"

[Christoph Hellwig]

What kind of device is this?   Seems like we need to blacklist it
as it chokes when we tried to read the Identify Devіce Log.

Re: Regression due to "libata: implement SECURITY PROTOCOL IN/OUT"

[Ido Schimmel]

On Thu, Aug 24, 2017 at 02:07:29PM +0200, Christoph Hellwig wrote:
> What kind of device is this?   Seems like we need to blacklist it
> as it chokes when we tried to read the Identify Devіce Log.

Is the below enough or do you need more info?

$ smartctl -a /dev/sda

=== START OF INFORMATION SECTION ===
Model Family:     Innodisk 3IE3/3ME3 SSDs
Device Model:     M.2 (S42) 3ME3
Serial Number:    20161029AA101511210E
LU WWN Device Id: 5 24693e 2016a210e
Firmware Version: S15A19
User Capacity:    16,013,942,784 bytes [16.0 GB]
Sector Size:      512 bytes logical/physical
Rotation Rate:    Solid State Device
Form Factor:      2.5 inches
Device is:        In smartctl database [for details use: -P show]
ATA Version is:   ATA8-ACS (minor revision not indicated)
SATA Version is:  SATA 3.0, 6.0 Gb/s (current: 6.0 Gb/s)
Local Time is:    Thu Aug 24 15:10:44 2017 IDT
SMART support is: Available - device has SMART capability.
SMART support is: Enabled

=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED

General SMART Values:
Offline data collection status:  (0x00) Offline data collection activity
                                        was never started.
                                        Auto Offline Data Collection: Disabled.
Total time to complete Offline 
data collection:                (   32) seconds.
Offline data collection
capabilities:                    (0x00)         Offline data collection not supported.
SMART capabilities:            (0x0003) Saves SMART data before entering
                                        power-saving mode.
                                        Supports SMART auto save timer.
Error logging capability:        (0x00) Error logging NOT supported.
                                        General Purpose Logging supported.
SCT capabilities:              (0x0039) SCT Status supported.
                                        SCT Error Recovery Control supported.
                                        SCT Feature Control supported.
                                        SCT Data Table supported.

SMART Attributes Data Structure revision number: 16
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE      UPDATED  WHEN_FAILED RAW_VALUE
  1 Raw_Read_Error_Rate     0x0000   000   000   000    Old_age   Offline      -       0
  2 Throughput_Performance  0x0000   000   000   000    Old_age   Offline      -       0
  3 Spin_Up_Time            0x0000   000   000   000    Old_age   Offline      -       0
  5 Later_Bad_Block         0x0013   100   100   001    Pre-fail  Always       -       0
  7 Seek_Error_Rate         0x0000   000   000   000    Old_age   Offline      -       0
  8 Seek_Time_Performance   0x0000   000   000   000    Old_age   Offline      -       0
  9 Power_On_Hours          0x0002   255   000   000    Old_age   Always       -       255
 10 Spin_Retry_Count        0x0000   000   000   000    Old_age   Offline      -       0
 12 Power_Cycle_Count       0x0002   097   000   000    Old_age   Always       -       97
163 Total_Bad_Block_Count   0x0000   000   000   000    Old_age   Offline      -       13
168 SATA_PHY_Error_Count    0x0000   000   000   000    Old_age   Offline      -       0
169 Remaining_Lifetime_Perc 0x0000   099   000   000    Old_age   Offline      -       99
175 Bad_Cluster_Table_Count 0x0000   000   000   000    Old_age   Offline      -       0
192 Power-Off_Retract_Count 0x0000   000   000   000    Old_age   Offline      -       0
194 Temperature_Celsius     0x0000   030   100   000    Old_age   Offline      -       30 (2 100 0 0 0)
197 Current_Pending_Sector  0x0012   000   100   000    Old_age   Always       -       0
225 Data_Log_Write_Count    0x0000   000   240   000    Old_age   Offline      -       272040
240 Write_Head              0x0000   000   000   000    Old_age   Offline      -       0
165 Max_Erase_Count         0x0002   010   001   000    Old_age   Always       -       10
167 Average_Erase_Count     0x0002   005   001   000    Old_age   Always       -       5
170 Spare_Block_Count       0x0003   100   001   000    Pre-fail  Always       -       65
171 Program_Fail_Count      0x0002   000   001   000    Old_age   Always       -       0
172 Erase_Fail_Count        0x0002   000   001   000    Old_age   Always       -       0
176 RANGE_RECORD_Count      0x0000   100   001   000    Old_age   Offline      -       0
187 Reported_Uncorrect      0x0002   000   001   000    Old_age   Always       -       0
229 Flash_ID                0x0002   100   001   000    Old_age   Always       -       0x51769394de98
232 Spares_Remaining_Perc   0x0003   100   001   000    Pre-fail  Always       -       0
235 Later_Bad_Blk_Inf_R/W/E 0x0002   000   000   000    Old_age   Always       -       0 0 0
241 Host_Writes_32MiB       0x0002   100   001   000    Old_age   Always       -       1062
242 Host_Reads_32MiB        0x0002   100   001   000    Old_age   Always       -       762

Re: Regression due to "libata: implement SECURITY PROTOCOL IN/OUT"

[Ido Schimmel]

On Thu, Aug 24, 2017 at 03:18:04PM +0300, Ido Schimmel wrote:
> On Thu, Aug 24, 2017 at 02:07:29PM +0200, Christoph Hellwig wrote:
> > What kind of device is this?   Seems like we need to blacklist it
> > as it chokes when we tried to read the Identify Devіce Log.
> 
> Is the below enough or do you need more info?

Ping?

Re: Regression due to "libata: implement SECURITY PROTOCOL IN/OUT"

[Christoph Hellwig]

On Sat, Aug 26, 2017 at 08:15:37PM +0300, Ido Schimmel wrote:
> On Thu, Aug 24, 2017 at 03:18:04PM +0300, Ido Schimmel wrote:
> > On Thu, Aug 24, 2017 at 02:07:29PM +0200, Christoph Hellwig wrote:
> > > What kind of device is this?   Seems like we need to blacklist it
> > > as it chokes when we tried to read the Identify Devіce Log.
> > 
> > Is the below enough or do you need more info?
> 
> Ping?

Sorry, been a bit busy.  Is this an actual SSD connected to a real
controller, or a PCIe SSD that implements ahci itself?

Can you send the full dmesg output, plus lspci -v, plus the output of
hdparm -i /dev/sdN for the device after a working boot?

Re: Regression due to "libata: implement SECURITY PROTOCOL IN/OUT"

[Ido Schimmel]

Hi Christoph,

On Sun, Aug 27, 2017 at 11:05:46AM +0200, Christoph Hellwig wrote:
> On Sat, Aug 26, 2017 at 08:15:37PM +0300, Ido Schimmel wrote:
> > On Thu, Aug 24, 2017 at 03:18:04PM +0300, Ido Schimmel wrote:
> > > On Thu, Aug 24, 2017 at 02:07:29PM +0200, Christoph Hellwig wrote:
> > > > What kind of device is this?   Seems like we need to blacklist it
> > > > as it chokes when we tried to read the Identify Devіce Log.
> > > 
> > > Is the below enough or do you need more info?
> > 
> > Ping?
> 
> Sorry, been a bit busy.  Is this an actual SSD connected to a real
> controller, or a PCIe SSD that implements ahci itself?

Yes, it's an actual SSD. Not PCIe.

> Can you send the full dmesg output, plus lspci -v, plus the output of
> hdparm -i /dev/sdN for the device after a working boot?

dmesg from 4.12.8 kernel:
https://pastebin.com/HjMFqrP8

lspci -v from 4.12.8 kernel:
https://pastebin.com/UFnKVmg9

hdparm -i from 4.12.8 kernel:
https://pastebin.com/GdCVcj3G

dmesg from 4.13-rc6 kernel where the error is showed:
https://pastebin.com/uVLRsybx

Thank you for your time.

Re: Regression due to "libata: implement SECURITY PROTOCOL IN/OUT"

[Christoph Hellwig]

Does this make your boot issue go away?

diff --git a/drivers/ata/libata-core.c b/drivers/ata/libata-core.c
index fa7dd4394c02..697f5f896b19 100644
--- a/drivers/ata/libata-core.c
+++ b/drivers/ata/libata-core.c
@@ -2079,6 +2079,8 @@ unsigned int ata_read_log_page(struct ata_device *dev, u8 log,
 	 */
 	if (ap_flags & ATA_FLAG_NO_LOG_PAGE)
 		return AC_ERR_DEV;
+	if (dev->horkage & ATA_HORKAGE_NO_LOG_PAGE)
+		return AC_ERR_DEV;
 
 retry:
 	ata_tf_init(dev, &tf);
@@ -4578,6 +4580,8 @@ static const struct ata_blacklist_entry ata_device_blacklist [] = {
 	{ "WDC WD3000JD-*",		NULL,	ATA_HORKAGE_WD_BROKEN_LPM },
 	{ "WDC WD3200JD-*",		NULL,	ATA_HORKAGE_WD_BROKEN_LPM },
 
+
+	{ "M.2 (S42) 3ME3",		NULL,	ATA_HORKAGE_NO_LOG_PAGE },
 	/* End Marker */
 	{ }
 };
diff --git a/include/linux/libata.h b/include/linux/libata.h
index 931c32f1f18d..9e927ae7fced 100644
--- a/include/linux/libata.h
+++ b/include/linux/libata.h
@@ -438,6 +438,7 @@ enum {
 	ATA_HORKAGE_NO_DMA_LOG	= (1 << 23),	/* don't use DMA for log read */
 	ATA_HORKAGE_NOTRIM	= (1 << 24),	/* don't use TRIM */
 	ATA_HORKAGE_MAX_SEC_1024 = (1 << 25),	/* Limit max sects to 1024 */
+	ATA_HORKAGE_NO_LOG_PAGE = (1 << 26),	/* Doesn't like Get Log Page */
 
 	 /* DMA mask for user DMA control: User visible values; DO NOT
 	    renumber */

Re: Regression due to "libata: implement SECURITY PROTOCOL IN/OUT"

[Ido Schimmel]

On Sun, Aug 27, 2017 at 07:03:48PM +0200, Christoph Hellwig wrote:
> Does this make your boot issue go away?

Yes.

Feel free to submit officially with my tag:

Tested-by: Ido Schimmel <idosch@mellanox.com>

Hopefully the patch can be sent to Linus sometime this week, before 4.13
is released.

Thanks a lot Christoph!