Bug 215137

Summary: Since 5.15.5 asking for cache data fails on one disk
Product: IO/Storage Reporter: Martin (bugs)
Component: Serial ATAAssignee: Tejun Heo (tj)
Status: RESOLVED ANSWERED    
Severity: normal CC: aros, bojan, bugs, damien.lemoal, debohman, fmscott1, kernel_bugzilla, pmargeti34, richard
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 5.15.5 Subsystem:
Regression: Yes Bisected commit-id:
Attachments: dmesg from 5.15.5 session
dmesg for 5.15.5
dmesg for 5.15.5 with e15de347faf4a9f494cbd4e9a623d343dc1b5851 reverted
commit c749301ebee82eb5e97dec14b6ab31a4aabe37a6

Description Martin 2021-11-25 21:12:22 UTC
When booting 5.15.5, dmesg reproducably shows me these lines while loading the second disk in my laptop:
[    2.606827] scsi 0:0:0:0: Direct-Access     ATA      CT1000MX500SSD1  023  PQ: 0 ANSI: 5
[    2.607005] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    2.607054] sd 0:0:0:0: [sda] 1953525168 512-byte logical blocks: (1.00 TB/932 GiB)
[    2.607058] sd 0:0:0:0: [sda] 4096-byte physical blocks
[    2.607066] sd 0:0:0:0: [sda] Write Protect is off
[    2.607068] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
[    2.607070] sd 0:0:0:0: [sda] Asking for cache data failed
[    2.607109] sd 0:0:0:0: [sda] Assuming drive cache: write through

In 5.15.4 and before this is:
[    2.467770] scsi 0:0:0:0: Direct-Access     ATA      CT1000MX500SSD1  023  PQ: 0 ANSI: 5
[    2.467974] sd 0:0:0:0: [sda] 1953525168 512-byte logical blocks: (1.00 TB/932 GiB)
[    2.467977] sd 0:0:0:0: [sda] 4096-byte physical blocks
[    2.467982] sd 0:0:0:0: [sda] Write Protect is off
[    2.467984] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
[    2.467988] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    2.467992] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA

For the time being, I'll be running 5.15.4 until I know what's going on in 5.15.5
Comment 1 pmargeti34 2021-11-26 03:51:51 UTC
Created attachment 299719 [details]
dmesg from 5.15.5 session

~ ▶ uname -a
Linux machine 5.15.5-arch1-1 #1 SMP PREEMPT Thu, 25 Nov 2021 22:09:33 +0000 x86_64 GNU/Linux

~ ▶ sudo journalctl -b -p3
-- Journal begins at Thu 2021-11-18 00:45:49 PST, ends at Fri 2021-11-26 11:42:09 PST. --
Nov 26 11:18:42 machine kernel: sd 0:0:0:0: [sda] Asking for cache data failed
Nov 26 11:18:42 machine kernel: sd 0:0:0:0: [sda] Assuming drive cache: write through
Comment 2 Artem S. Tashkinov 2021-11-26 11:26:55 UTC
Could you revert either or all:

Damien Le Moal (3):
      scsi: core: Fix scsi_mode_sense() buffer length handling
      ata: libata: improve ata_read_log_page() error message
      ata: libata: add missing ata_identify_page_supported() calls

And check whether it helps?

CC'ing Damien since these patches are most likely to have caused this regression.
Comment 3 Martin 2021-11-26 13:44:55 UTC
Reverting
    scsi: core: Fix scsi_mode_sense() buffer length handling

fixes (at least the output of) the initialisation in 5.15.5+

$ uname -a
Linux minivanes 5.15.5+ #1 SMP Fri Nov 26 14:16:28 CET 2021 x86_64 x86_64 x86_64 GNU/Linux

$ dmesg | grep sda
[    2.086768] sd 0:0:0:0: [sda] 1953525168 512-byte logical blocks: (1.00 TB/932 GiB)
[    2.086771] sd 0:0:0:0: [sda] 4096-byte physical blocks
[    2.086778] sd 0:0:0:0: [sda] Write Protect is off
[    2.086781] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
[    2.086792] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    2.116331]  sda: sda1
[    2.116458] sd 0:0:0:0: [sda] Attached SCSI disk
[    7.196275] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null). Quota mode: disabled.
Comment 4 David Bohman 2021-11-26 17:57:11 UTC
I am seeing this also on Arch Linux with linux-5.15.5.

Nov 26 06:49:11 hyper kernel: sd 0:0:0:0: [sda] Assuming drive cache: write through
Nov 26 06:49:11 hyper kernel: sd 0:0:0:0: [sda] Asking for cache data failed
Nov 26 06:49:11 hyper kernel: sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
Nov 26 06:49:11 hyper kernel: sd 0:0:0:0: [sda] Write Protect is off
Nov 26 06:49:11 hyper kernel: sd 0:0:0:0: [sda] 4096-byte physical blocks
Nov 26 06:49:11 hyper kernel: sd 0:0:0:0: [sda] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)

It would be great to get an idea how serious this is. For now I have reverted to linux-5.15.4.
Comment 5 MB 2021-11-26 19:44:48 UTC
Dear Maintainer,

the same here on Debian Sid with 5.15.5,
5.15.4 does not have this message.

regards
Comment 6 loqs 2021-11-26 21:16:36 UTC
Created attachment 299737 [details]
dmesg for 5.15.5
Comment 7 loqs 2021-11-26 21:17:40 UTC
Created attachment 299739 [details]
dmesg for 5.15.5 with e15de347faf4a9f494cbd4e9a623d343dc1b5851 reverted
Comment 8 loqs 2021-11-26 21:19:17 UTC
Reverting only e15de347faf4a9f494cbd4e9a623d343dc1b5851 and the messages are no longer produced.  I attached dmesg output both with and without the commit for comparison.
Comment 9 loqs 2021-11-26 21:42:21 UTC
Confirming the finding of Tom Yan in [1] fixed by cherry-picking c749301ebee82eb5e97dec14b6ab31a4aabe37a6

[1] https://lore.kernel.org/linux-scsi/CAGnHSEmkTyq_QqP9S6TemsHOKxj2Gzq3R7X6+PxbQs_R-iBB7Q@mail.gmail.com/
Comment 10 Artem S. Tashkinov 2021-11-27 01:26:53 UTC
Most likely going to be fixed in 5.15.6 or later.

5.15.5 still can be used but requires commit c749301ebee82eb5e97dec14b6ab31a4aabe37a6 as well.

https://lore.kernel.org/linux-scsi/92cc74fd-ce93-b844-830f-71e744e0c084@opensource.wdc.com/
Comment 11 Martin 2021-11-27 08:21:27 UTC
I can confirm that cherry-picking c749301ebee82eb5e97dec14b6ab31a4aabe37a6 (also) fixes the regression on 5.15.5 for me:

# dmesg | grep sda
[    2.121943] sd 0:0:0:0: [sda] 1953525168 512-byte logical blocks: (1.00 TB/932 GiB)
[    2.121947] sd 0:0:0:0: [sda] 4096-byte physical blocks
[    2.121958] sd 0:0:0:0: [sda] Write Protect is off
[    2.121960] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
[    2.121971] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    2.125689]  sda: sda1
[    2.126616] sd 0:0:0:0: [sda] Attached SCSI disk
[    7.337471] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null). Quota mode: disabled.

Thx for the quick response!
Comment 12 Artem S. Tashkinov 2021-11-27 12:04:58 UTC
Created attachment 299747 [details]
commit c749301ebee82eb5e97dec14b6ab31a4aabe37a6

In case people have troubles finding this patch/commit.
Comment 13 Martin 2021-12-01 08:53:06 UTC
The fix got merged in 5.15.6:

# uname -a
Linux minivanes 5.15.6 #6 SMP Wed Dec 1 09:36:43 CET 2021 x86_64 x86_64 x86_64 GNU/Linux
# dmesg  | grep sda
[    2.692286] sd 0:0:0:0: [sda] 1953525168 512-byte logical blocks: (1.00 TB/932 GiB)
[    2.692290] sd 0:0:0:0: [sda] 4096-byte physical blocks
[    2.692297] sd 0:0:0:0: [sda] Write Protect is off
[    2.692299] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
[    2.692309] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    2.695475]  sda: sda1
[    2.695604] sd 0:0:0:0: [sda] Attached SCSI disk
[    6.914274] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null). Quota mode: disabled.

Thx!