Require assistance in understanding a file system 'error'...

Since upgrading one of my Leap machines 15.3 → 15.4 I’m frequently noticing at boot fsck running on the root partition, although this could be coincidence and unrelated to the upgrade. Apologies for the length of post, but I’ve been trying to understand this issue for the last few days :\ …

This machine uses an ext4 file system with “/” and “/home” on the same physical ssd. Smartctl indicates no problems with the drive and in use the machine shows no obvious signs of problems.

The fsck at boot is being triggered by systemd-fsck-root.service.

Looking through the journal I see this for when systemd-fsck ran:

Oct 23 10:52:17 HP255G7 systemd-fsck[445]: 32G-ROOT contains a file system with errors, check forced.

and looking further back this I believe is the source of the error that triggered the check:

Oct 23 10:13:42 HP255G7 kernel: EXT4-fs error (device sda2): __ext4_find_entry:1660: inode #1966862: comm plasmashell: reading directory lblock 0

“Plasmashell” encompasses rather a lot, so not particularly helpful

I am always able to find a preceding “… kernel: EXT4-fs error (device sda2): …” prior to a boot on which fsck ran, the error message, disregarding date/time, is always almost identical, the inode # is either #1966862 as shown above, or is #1966863.

During a typical KDE session I will generally use the same applications, there is no indication of any problems at all, so I have no idea if the ‘error’ has occurred or not until the next boot/reboot. It’s a system level problem rather user level as this is liable to happen irrespective of which user was logged in.

In a bid to gain further insight I began logging out of KDE switching to a VT and using:

tune2fs -l /dev/sda2 | grep -i 'filesystem state'

prior to shutting down.

When the error did occur in that KDE session:

paul@HP255G7:~> sudo tune2fs -l /dev/sda2 | grep -i 'filesystem state'
Filesystem state:         clean with errors
paul@HP255G7:~>

I shutdown the system and booted from a live USB, established the drive identity and rans fsck manually with the -n (don’t fix) option:

linux@localhost:~> su -
localhost:~ # lsblk
NAME   MAJ:MIN RM   SIZE RO TYPE MOUNTPOINTS
loop0    7:0    0 814.1M  1 loop /run/overlay/squashfs_container
loop1    7:1    0   4.8G  1 loop /run/overlay/rootfsbase
sda      8:0    0 223.6G  0 disk
├─sda1   8:1    0   500M  0 part
├─sda2   8:2    0    32G  0 part
└─sda3   8:3    0   184G  0 part /run/media/linux/184G-HOME
sdb      8:16   1  57.7G  0 disk
├─sdb1   8:17   1 927.5M  0 part /run/overlay/live
├─sdb2   8:18   1    20M  0 part
└─sdb3   8:19   1  56.8G  0 part /run/overlay/overlayfs
localhost:~ # fsck -n -v /dev/sda2
fsck from util-linux 2.37.2
e2fsck 1.46.4 (18-Aug-2021)
32G-ROOT contains a file system with errors, check forced.
Pass 1: Checking inodes, blocks, and sizes
Pass 2: Checking directory structure
Pass 3: Checking directory connectivity
Pass 4: Checking reference counts
Pass 5: Checking group summary information

      205566 inodes used (9.80%, out of 2097152)
         830 non-contiguous files (0.4%)
         202 non-contiguous directories (0.1%)
             # of inodes with ind/dind/tind blocks: 0/0/0
             Extent depth histogram: 184667/91
     1999069 blocks used (23.83%, out of 8388608)
           0 bad blocks
           1 large file

      149925 regular files
       21059 directories
           0 character device files
           0 block device files
           2 fifos
       11299 links
       34237 symbolic links (20464 fast symbolic links)
         334 sockets
------------
      216856 files
localhost:~ #

Given my limited knowledge of fsck output, that to me looked as if there were no errors found(?)

Running fsck again, this time without the -n option:

localhost:~ # fsck -v /dev/sda2
fsck from util-linux 2.37.2
e2fsck 1.46.4 (18-Aug-2021)
32G-ROOT contains a file system with errors, check forced.
Pass 1: Checking inodes, blocks, and sizes
Pass 2: Checking directory structure
Pass 3: Checking directory connectivity
Pass 4: Checking reference counts
Pass 5: Checking group summary information

      205566 inodes used (9.80%, out of 2097152)
         830 non-contiguous files (0.4%)
         202 non-contiguous directories (0.1%)
             # of inodes with ind/dind/tind blocks: 0/0/0
             Extent depth histogram: 184667/91
     1999069 blocks used (23.83%, out of 8388608)
           0 bad blocks
           1 large file

      149925 regular files
       21059 directories
           0 character device files
           0 block device files
           2 fifos
       11299 links
       34237 symbolic links (20464 fast symbolic links)
         334 sockets
------------
      216856 files
localhost:~ # 

Finally running once more and the filesystem is clean with no ‘errors’:

localhost:~ # fsck -v /dev/sda2
fsck from util-linux 2.37.2
e2fsck 1.46.4 (18-Aug-2021)
32G-ROOT: clean, 205566/2097152 files, 1999069/8388608 blocks
localhost:~ #

Wondering where to go next… I don’t really want to reformat the root partition and reinstall unless absolutely necessary.

Restricting myself to the last part, I am amazed like you.

It says there is an error. It does not report any repair. Then you repeat the fsck and it reports clean. So it must have done something. Only setting the “clean” status? But then, who is making it “dirty”? Because I assume that after running KDE again it shows the same problem at boot?

Not every time. Looking through the journal it’s happened 16 times in the last 7 days, average of 2.3 times per day, and I’ve yet to find any correlation between what I do in a KDE session and it occurring… although I suppose it could be “something” that KDE/Plasmashell is doing in the background…

But then, who is making it “dirty”?

My guess is it relates to the error I showed in the first post: “… kernel: EXT4-fs error (device sda2): …”

This is most likely follow up error caused by something else. Check logs for any other previous kernel messages. Post full log if you are not sure.

Filesystem was marked as dirty because driver failed to read its content. It does not mean filesystem on disk is actually corrupted. It could be software bug (less likely) or it could be transient hardware error almost anywhere - RAM, SSD itself, cables, power supply, …

If your disk is not a rotating HDD but some SSD then it might be worth to have a look at this and this.

Regards

susejunky

And what are those inodes? “find -inum 1966862”.

This error is unrelated to being HDD or SSD.

and this.

Well, this contains explanation of what this error means - kernel failed to read block requested by ext4 driver. It usually does not happen without any error message, although error message may not reach disk if /var is on the same filesystem. As a troubleshooting aid one may consider moving logs to somewhere else to have hard copy, at least temporary. Actually, if system remains accessible after this error, even disabling persistent journal may help - logs will be in /run then. Or just dump dmesg output on another disk before reboot.

This is a portion of the log prior to the error line which looks perhaps relevant:

Oct 24 13:25:04 HP255G7 plasmashell[1130]: Plasma Shell startup completed
Oct 24 13:25:04 HP255G7 kernel: ata2.00: READ LOG DMA EXT failed, trying PIO
Oct 24 13:25:04 HP255G7 kernel: ata2.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x0
Oct 24 13:25:04 HP255G7 kernel: ata2.00: irq_stat 0x40000008
Oct 24 13:25:04 HP255G7 kernel: ata2.00: failed command: READ FPDMA QUEUED
Oct 24 13:25:04 HP255G7 kernel: ata2.00: cmd 60/08:00:48:b3:d0/00:00:03:00:00/40 tag 0 ncq dma 4096 in
                                         res 41/40:00:48:b3:d0/00:00:03:00:00/00 Emask 0x409 (media error) <F>
Oct 24 13:25:04 HP255G7 kernel: ata2.00: status: { DRDY ERR }
Oct 24 13:25:04 HP255G7 kernel: ata2.00: error: { UNC }
Oct 24 13:25:04 HP255G7 kernel: ata2.00: configured for UDMA/133
Oct 24 13:25:04 HP255G7 kernel: sd 1:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
Oct 24 13:25:04 HP255G7 kernel: sd 1:0:0:0: [sda] tag#0 Sense Key : Medium Error [current] 
Oct 24 13:25:04 HP255G7 kernel: sd 1:0:0:0: [sda] tag#0 Add. Sense: Unrecovered read error - auto reallocate failed
Oct 24 13:25:04 HP255G7 kernel: sd 1:0:0:0: [sda] tag#0 CDB: Read(10) 28 00 03 d0 b3 48 00 00 08 00
Oct 24 13:25:04 HP255G7 kernel: blk_update_request: I/O error, dev sda, sector 64009032 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0
Oct 24 13:25:04 HP255G7 kernel: ata2: EH complete
Oct 24 13:25:04 HP255G7 kernel: EXT4-fs error (device sda2): __ext4_find_entry:1660: inode #1966862: comm plasmashell: reading directory lblock 0

Full journal for that boot: https://paste.opensuse.org/view/raw/ff86de5a

… or it could be transient hardware error almost anywhere - RAM, SSD itself, cables, power supply, …

Whilst I certainly wouldn’t dismiss that I would expect to see other errors, this, when it does manifest itself is always the same, relating to “those inodes”

And what are those inodes? “find -inum 1966862”.

Apparently, nothing (?)

paul@HP255G7:~> find -inum 1966862
paul@HP255G7:~> find -inum 1966863
paul@HP255G7:~>

Actually, if system remains accessible after this error, even disabling persistent journal may help - logs will be in /run then. Or just dump dmesg output on another disk before reboot.

The system is fully accessible and apparently working normally after the error. The only indication it had previously happened (on current boot -1) is fsck running at the start of the current boot.

Edit: in the bug report linked by @susejunky there is a comment that:

*“I’m suspicious of this being exclusively a hardware error because it is always the same error at the same spot. Might it be an unexpected call or unexpected function arguments? (I have no knowledge of ext4 internals, so it’s likely I’m talking nonsense.)”

*Which goes along with my own thoughts this may not be a hardware issue.

What exactly is not clear? This is hardware error, kernel failed to read requested data. Some part of your SSD is physically corrupted which explains why failure is always for the same inodes (which were located in failed area). fsck does not make exhaustive scan and so may not hit this spot.

Boot from live medium, run “dd if=/dev/sdXXX of=/dev/null” for your SSD (and no, I do not expect you to copy-paste it verbatim) and see if it fails.

Whilst I certainly wouldn’t dismiss that I would expect to see other errors

You have other errors.

I don’t entirely agree with that, presupposing there is a failed area of the ssd then the (ssd) controller would remap those sectors and the bad block count would increase. From smartctl output the bad block count is the same now as it was in 20190822 when I first installed the drive. Additionally take into account the wear levelling the drive controller performs, data is moved around on the drive (independent of the OS), statistically I can’t believe the same inode(s) are at the same (physical) location as they were when first written.

The drive also passes the smartctl “long” test:

paul@HP255G7:~> sudo smartctl -t long /dev/sda
[sudo] password for root: 
smartctl 7.2 2021-09-14 r5237 [x86_64-linux-5.14.21-150400.24.21-default] (SUSE RPM)
Copyright (C) 2002-20, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF OFFLINE IMMEDIATE AND SELF-TEST SECTION ===
Sending command: "Execute SMART Extended self-test routine immediately in off-line mode".
Drive command "Execute SMART Extended self-test routine immediately in off-line mode" successful.
Testing has begun.
Please wait 42 minutes for test to complete.
Test will complete after Mon Oct 24 16:40:49 2022 BST
Use smartctl -X to abort test.
paul@HP255G7:~> sudo smartctl -l selftest /dev/sda
[sudo] password for root: 
smartctl 7.2 2021-09-14 r5237 [x86_64-linux-5.14.21-150400.24.21-default] (SUSE RPM)
Copyright (C) 2002-20, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF READ SMART DATA SECTION ===
SMART Self-test log structure revision number 1
Num  Test_Description    Status                  Remaining  LifeTime(hours)  LBA_of_first_error
# 1  Extended offline    Completed without error       00%      1168         -
# 2  Extended offline    Self-test routine in progress 10%      1168         -
# 3  Extended offline    Self-test routine in progress 40%      1167         -
# 4  Short offline       Completed without error       00%      1167         -
...
#21  Short offline       Completed without error       00%        47         -

paul@HP255G7:~> 

Boot from live medium, run “dd if=/dev/sdXXX of=/dev/null” for your SSD (and no, I do not expect you to copy-paste it verbatim) and see if it fails.

You have other errors.

That also runs to completion on the 3 partitions on that drive without errors:

linux@localhost:~> su -
localhost:~ # lsblk
NAME   MAJ:MIN RM   SIZE RO TYPE MOUNTPOINTS
loop0    7:0    0 814.1M  1 loop /run/overlay/squashfs_container
loop1    7:1    0   4.8G  1 loop /run/overlay/rootfsbase
sda      8:0    0 223.6G  0 disk
├─sda1   8:1    0   500M  0 part
├─sda2   8:2    0    32G  0 part
└─sda3   8:3    0   184G  0 part /run/media/linux/184G-HOME
sdb      8:16   1  57.7G  0 disk
├─sdb1   8:17   1 927.5M  0 part /run/overlay/live
├─sdb2   8:18   1    20M  0 part
└─sdb3   8:19   1  56.8G  0 part /run/overlay/overlayfs
localhost:~ # dd if=/dev/sda1 of=/dev/null
1024000+0 records in
1024000+0 records out
524288000 bytes (524 MB, 500 MiB) copied, 1.08753 s, 482 MB/s
localhost:~ # dd if=/dev/sda2 of=/dev/null
67108864+0 records in
67108864+0 records out
34359738368 bytes (34 GB, 32 GiB) copied, 80.551 s, 427 MB/s
localhost:~ # umount /dev/sda3
localhost:~ # dd if=/dev/sda3 of=/dev/null
385873920+0 records in
385873920+0 records out
197567447040 bytes (198 GB, 184 GiB) copied, 409.34 s, 483 MB/s
localhost:~ # exit
logout
linux@localhost:~> 

Whilst it may be, in this instance I’m having difficulty in believing this is a hardware issue.

Hmm… looking at my own posting of the errors:

Oct 24 13:25:04 HP255G7 kernel: ata2.00: failed command: READ FPDMA QUEUED
Oct 24 13:25:04 HP255G7 kernel: ata2.00: cmd 60/08:00:48:b3:d0/00:00:03:00:00/40 tag 0 ncq dma

Reminds me of a problem I had a few years ago on completely different hardware which caused occasional errors when Native Command Queuing was enabled.

I’m going to run this machine for a few days with:

libata.force=noncq

added to the kernel command line and see if that makes any difference - although this machine has worked flawlessly without that for just over 3 years…

I regularly backup my /home on this machine so I’m not too worried if it fails, an inconvenience rather than disaster.

@tannington:

lsblk --fs” could be a little bit more helpful – no need to execute it from the user “root”.

  • From “lsblk --fs” UUID of the ext4 System partition will be available – grep for that UUID in the systemd Journal with an additional grep pipe for “systemd”.
journalctl --no-hostname --output=short-monotonic -b 0 | grep -iE -B 4 -A 4 'Mounting /sysroot|Mounted /sysroot|File System Check|EXT4'

may also give some explanation of what’s going on.

Please be aware of the following:


    6.189866] systemd[1]: Finished dracut initqueue hook.
    6.190112] systemd[1]: Reached target Preparation for Remote File Systems.
    6.190169] systemd[1]: Reached target Remote File Systems.
    6.190223] systemd[1]: Condition check resulted in dracut pre-mount hook being skipped.
    6.191030] systemd[1]: **Starting File System Check on /dev/disk/by-uuid/c59a64bf-b464-4ea2-bf3a-d3fd9dded03f...**
    6.207279] systemd-fsck[528]: System_Root: clean, 875208/7168000 files, 11871295/28652544 blocks
    6.211105] systemd[1]: Finished File System Check on /dev/disk/by-uuid/c59a64bf-b464-4ea2-bf3a-d3fd9dded03f.
    6.212051] systemd[1]: **Mounting /sysroot...**
    6.272332] systemd[1]: Mounted /sysroot.
    6.272526] systemd[1]: Condition check resulted in OSTree Prepare OS/ being skipped.
    6.272571] systemd[1]: Reached target Initrd Root File System.
    6.273335] systemd[1]: Starting Reload Configuration from the Real Root...
    6.271979] kernel: EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
    6.277289] systemd[1]: Reloading.
    6.452753] systemd[1]: initrd-parse-etc.service: Deactivated successfully.
    6.453078] systemd[1]: Finished Reload Configuration from the Real Root.
    6.453291] systemd[1]: Reached target Initrd File Systems.

In other words, the systemd fsck check, checks the system partition before it mounts the sysroot partition – presumably it’s loaded with the initial Kernel image …

Later during the boot, the following should also be appearing:


    7.264560] systemd[1]: Mounting FUSE Control File System...
    7.265371] systemd[1]: Mounting Kernel Configuration File System...
    7.266645] systemd[1]: Mounted FUSE Control File System.
    7.267304] systemd[1]: Mounted Kernel Configuration File System.
    7.269090] kernel: EXT4-fs (sda2): re-mounted. Opts: (null). Quota mode: none.
    7.270312] systemd[1]: Finished Remount Root and Kernel File Systems.
    7.270744] systemd[1]: Condition check resulted in One time configuration for iscsid.service being skipped.
    7.270794] systemd[1]: Condition check resulted in First Boot Wizard being skipped.
    7.272118] systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.

In other words, later during the boot, before the remaining partitions are mounted, the system partition is remounted …
[HR][/HR]I was going to suggest that, you could boot an installation image and then use the Rescue System to run fsck on the unmounted System partition https://doc.opensuse.org/documentation/leap/startup/html/book-startup/cha-trouble.html#sec-trouble-data-recover-rescue.
But, because the systemd boot process runs fsck on the unmounted System partition during boot, this isn’t really necessary …

  • Catch 22, the default Filesystem settings are such, that a Filesystem check isn’t run at every boot and/or often …

openSUSE Leap uses “systemd” → therefore, using “tune2fs” doesn’t force a Filesystem check at the next boot.

  • You have to add the following to the Kernel’s Command Line:
fsck.mode=force fsck.repair=yes

So, therefore, maybe, using the Rescue System to run fsck on the System partition may be the more desirable option …

I appreciate your input, but, did you read my initial post in this thread?

It’s not a file system error. It’s the kernel scsi subsystem. Filter journal:

**erlangen:~ #** journalctl -b0 _KERNEL_SUBSYSTEM=scsi -g sdb 
Oct 24 18:01:21 erlangen kernel: **sd 1:0:0:0: ****sdb****] 15628053168 512-byte logical blocks: (8.00 TB/7.28 TiB)**
Oct 24 18:01:21 erlangen kernel: **sd 1:0:0:0: ****sdb****] 4096-byte physical blocks**
Oct 24 18:01:21 erlangen kernel: **sd 1:0:0:0: ****sdb****] Write Protect is off**
Oct 24 18:01:21 erlangen kernel: sd 1:0:0:0: **sdb**] Mode Sense: 00 3a 00 00
Oct 24 18:01:21 erlangen kernel: **sd 1:0:0:0: ****sdb****] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA**
Oct 24 18:01:21 erlangen kernel: **sd 1:0:0:0: ****sdb****] Attached SCSI disk**
Oct 24 18:01:24 erlangen kernel: **sd 1:0:0:0: ****sdb****] Synchronizing SCSI cache**
Oct 24 18:01:24 erlangen kernel: **sd 1:0:0:0: ****sdb****] Stopping disk**
Oct 24 20:32:44 erlangen kernel: **sd 6:0:0:0: ****sdb****] 20646 512-byte logical blocks: (10.6 MB/10.1 MiB)**
Oct 24 20:32:44 erlangen kernel: **sd 6:0:0:0: ****sdb****] Write Protect is off**
Oct 24 20:32:44 erlangen kernel: sd 6:0:0:0: **sdb**] Mode Sense: 23 00 00 00
Oct 24 20:32:44 erlangen kernel: **sd 6:0:0:0: ****sdb****] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA**
Oct 24 20:32:44 erlangen kernel: **sd 6:0:0:0: ****sdb****] Attached SCSI removable disk**
Oct 24 20:44:01 erlangen kernel: **sd 6:0:0:0: ****sdb****] Synchronizing SCSI cache**
Oct 24 20:44:01 erlangen kernel: sd 6:0:0:0: [sdb] Synchronize Cache(10) failed: Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK 
**erlangen:~ #**

On re-reading your initial post, it seems that, stand-alone fsck did find something on the first “fix it” pass – which was repaired and, confirmed with the 2nd stand-alone “fix-it” pass.
But, did the SSD decide to move at least one bad block, or not?

  • Rather than using the generic “fsck” it’s better to use the ext2/3/4-specific “e2fsck” –

From a Rescue System, execute “e2fsck -c -v /dev/sd??” to perform a read-only bad blocks scan.
If there are enough reliable backups of the system partition, execute “e2fsck -c -c -v /dev/sd??” to perform a non-destructive read-write bad blocks scan.
Finish with “e2fsck -f -v /dev/sd??” to perform a forced (even if the filesystem is flagged as being “clean”) filesystem check.
To find out if, the ext4 system partition has any entries in the bad blocks list, execute “dumpe2fs -b /dev/sd??”.
To check what SMART believes the disk supports, execute “smartctl --identify /dev/sd?”

  • “smartctl --log=error /dev/sd?” may point to an issue with the device’s SMART error log.

You’re correct in the assumption that, when an SSD moves failing blocks, the bad block count of the affected filesystem will not change –

  • Which is why, running an e2fsck bad blocks scan will possibly not report any bad blocks found, even though, the SMART logs may well increment an error counter …

@tannington:

FYI, the Kernel’s SCSI sub-system on this Leap 15.4 system is currently reporting the following for the system disk:


 # journalctl -b 0 --no-hostname --output=short-monotonic _KERNEL_SUBSYSTEM=scsi --grep 'sdb'
    4.239311] kernel: sd 0:0:0:0: [sdb] 234441648 512-byte logical blocks: (120 GB/112 GiB)
    4.239326] kernel: sd 0:0:0:0: [sdb] Write Protect is off
    4.239328] kernel: sd 0:0:0:0: [sdb] Mode Sense: 00 3a 00 00
    4.239350] kernel: sd 0:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
    4.315131] kernel: sd 0:0:0:0: [sdb] Attached SCSI disk
 # 

/dev/sdb information:


 > lsblk --fs /dev/sdb
NAME   FSTYPE FSVER LABEL       UUID                                 FSAVAIL FSUSE% MOUNTPOINTS
sdb                                                                                 
├─sdb1 vfat   FAT16             2539-7D44                             494,7M     1% /boot/efi
├─sdb2 ext4   1.0   System_Root c59a64bf-b464-4ea2-bf3a-d3fd9dded03f   58,5G    40% /
└─sdb3 swap   1                 e96bee61-d116-4700-a761-c72153babfde                [SWAP]
 > 

Scanning the complete systemd Journal for SCSI cache issues with any of the disks attached to this system, didn’t reveal anything …

@dcurtisfra, @karlmistelberger

Thanks both, I’m not ignoring you :slight_smile:

It does seem the use of NCQ is implicated in this issue, but I need a few days and reasonable number of boot/reboots to conclusively prove it.

As a reference, with a system with an SSD system disk that doesn’t seem to be suffering from Native Command Queueing woes – <Solid state drive - ArchWiki; – today’s systemd Journal:


 # journalctl -b 0 --no-hostname --output=short-monotonic | grep -i 'ncq' -B 3 -A 3
    1.365602] kernel: ahci 0000:01:00.1: version 3.0
    1.365769] kernel: ahci 0000:01:00.1: SSS flag set, parallel bus scan disabled
    1.365816] kernel: ahci 0000:01:00.1: AHCI 0001.0301 32 slots 6 ports 6 Gbps 0x3f impl SATA mode
    1.365819] kernel: ahci 0000:01:00.1: flags: 64bit **ncq** sntf stag pm led clo only pmp pio slum part sxs deso sadm sds apst 
    1.367382] kernel: ccp 0000:06:00.2: ccp enabled
    1.367818] kernel: sp5100-tco sp5100-tco: initialized. heartbeat=60 sec (nowayout=0)
    1.373917] kernel: scsi host0: ahci
--
    1.694674] kernel: usb 1-6: new full-speed USB device number 2 using xhci_hcd
    1.858699] kernel: ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
    1.865551] kernel: ata1.00: ATA-9: Intenso SSD Sata III, S0222A0, max UDMA/133
    1.865557] kernel: ata1.00: 234441648 sectors, multi 1: LBA48 **NCQ** (depth 32), AA
    1.876133] kernel: ata1.00: configured for UDMA/133
    1.876354] kernel: scsi 0:0:0:0: Direct-Access     ATA      Intenso SSD Sata 2A0  PQ: 0 ANSI: 5
    1.876707] kernel: scsi 0:0:0:0: Attached scsi generic sg0 type 0
--
    2.334365] kernel: hub 1-7:1.0: 4 ports detected
    2.350697] kernel: ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
    2.351810] kernel: ata2.00: ATA-9: WDC WD10EZEX-60M2NA0, 03.01A03, max UDMA/100
    2.351815] kernel: ata2.00: 1953525168 sectors, multi 16: LBA48 **NCQ** (depth 32), AA
    2.353003] kernel: ata2.00: configured for UDMA/100
    2.353243] kernel: scsi 1:0:0:0: Direct-Access     ATA      WDC WD10EZEX-60M 1A03 PQ: 0 ANSI: 5
    2.353585] kernel: scsi 1:0:0:0: Attached scsi generic sg1 type 0
--
    2.727275] kernel: usb 1-9: New USB device strings: Mfr=0, Product=0, SerialNumber=0
    2.830933] kernel: ata3: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
    2.831751] kernel: ata3.00: ATA-10: WDC WD40EZRZ-22GXCB0, 80.00A80, max UDMA/133
    2.831754] kernel: ata3.00: 7814037168 sectors, multi 16: LBA48 **NCQ** (depth 32), AA
    2.832671] kernel: ata3.00: configured for UDMA/133
    2.832853] kernel: scsi 2:0:0:0: Direct-Access     ATA      WDC WD40EZRZ-22G 0A80 PQ: 0 ANSI: 5
    2.833093] kernel: scsi 2:0:0:0: Attached scsi generic sg2 type 0
 # 

And, no more than that …

Yep: Solid state drive - ArchWiki

Perhaps premature, but based on the frequency of happening, after almost 2 days use and some 35 boots/reboots I think I can fairly safely say that disabling NCQ has ‘cured’ (and I use the term very loosely), the problem. Reinforced by the fact that after again enabling NCQ the problem appeared after only 3 reboots.

Frequent running of fsck at boot, together with these ‘error’ messages:

systemd-fsck[445]: 32G-ROOT contains a file system with errors, check forced.
kernel: EXT4-fs error (device sda2): __ext4_find_entry:1660: inode #1966862: comm plasmashell: reading directory lblock 0

were rather a red herring, although they did alert me to the problem.

This seems to have been the root cause:

kernel: ata2.00: failed command: READ FPDMA QUEUED

Which, as I wrote back in post #10, reminded me of a very similar problem a few years ago on completely different hardware which caused occasional errors when Native Command Queuing was enabled. (Also, as in this case a Western Digital drive…)

My ssd no longer likes NCQ…

As I wrote initially, this problem first manifested itself after a Leap 15.3 -> 15.4 upgrade.

Prior to that (on both 15.2 & 15.3) this machine had been using NCQ without any issues.

My assumption is that after the 15.4 upgrade ‘something’ within the underlying OS relating to the way NCQ is implemented has changed; resulting in either a regression bug in said software, or, more likely, a latent bug in my ssd’s firmware has been revealed.

I have other machines with 15.4 and ssds (of a differing make/model to this machine) that use NCQ without issues.

For the moment I’ll continue to run with NCQ disabled, there is a very slight performance hit barely noticeable at cold boot, takes approx 1 sec longer from switch on to a working desktop environment - can live with that.

I may experiment with reducing the NCQ queue length… but I need more motivation than I have at present for that.

@all

Thanks for useful comments

@arvidjaar

Hardware / software /firmware issue, so it seems. Failing hardware or ssd media wear-out, it seems not.

Or, a combination of the NCQ implementation in the SSD and, the pipeline behaviour in the CPU …

  • Whether or not a CPU Firmware issue is influencing the queuing behaviour of the SSD?