Mounting External Hard Drives in Docking Station Caues Temporary "Thrashing" After 15.4 Upgrade

English Install/Boot/Login
1

I updated from 15.3 to 15.4 a few days ago. Aside from the issue I had earlier, resolved here, about the Yast password prompt, I’ve had no other problems (well, other than that my music player, KPlayer, appears to no longer exist, forcing me to rebuild my playlists - but I digress.)

I have noticed some unusual behavior with my external hard drives. I have three two-socket hard drive docks, with a hard drive in each socket, that I use to back up my internal drives. I boot them up at night, let the system run the fwbackups program overnight, and shut them down in the morning.

Usually when I turn on the docking stations, they mount fine with no extraneous noise or messages. After updating to 15.4, I’ve noticed that a short while after they boot, they begin to “thrash”, i.e., there appears to be some sort of scan going on, the drive activity lights flash continuously for about five minutes or so, then stop. No messages or indications of what is going on.

I considered the possibility that a file system check was going on.as the drives have a 2 in the file system check order field in /etc/fstab. But if that is the case, why didn’t this occur in 15.3? I can’t remember if I had a 2 in 15.3, so I suppose it’s possible that’s why it didn’t happen in 15.3. But I didn’t edit /etc/fstab between 15.3 and 15.4. Did the upgrade change the /etc/fstab? Doesn’t seem to me like it should. So I discounted that - but it does seem to be the most likely explanation for the thrashing.

I checked dmesg - nothing logged except the turning on the drives. Same with the journal. Same with /var/log/messages.

The only thing I see in the logs is that the drives were mounted, kded started smart, dolphin reported it couldn’t access the “lost+found:” folders on each drive (permission denied), then the smartd daemon reported connecting to the drives and updating the Powered On Hours and Loaded Hours. Beyond that, nothing to indicate why the drives were thrashing. The only other messages are stuff like ncsd monitoring /etc/resolv.conf, Network Manager doing something and the like. Nothing about the drives except as I indicated.

Is there some other log I can look at to see what is going on? Is there a log that records a fsck check on boot of an external drive?

I don’t think this is a big issue, but I’d kinda like to know what;s going on.

2

Nothing? No one has an idea? No log I can look at?

3

Anything in systemctl list-timers output now that wasn’t there before the upgrade?

4

Show system units:

**erlangen:~ #** **systemctl list-units --type service --type scope --legend=no --no-pager**  
  init.scope                           loaded active running System and Service Manager 
  session-7.scope                      loaded active running Session 7 of User karl 
  session-9.scope                      loaded active running Session 9 of User karl                        
  apache2.service                      loaded active running The Apache Webserver 
  apparmor.service                     loaded active exited  Load AppArmor profiles 
  auditd.service                       loaded active running Security Auditing Service 
  augenrules.service                   loaded active exited  auditd rules generation 
  chronyd.service                      loaded active running NTP client/server 
  cron.service                         loaded active running Command Scheduler 
  cups.service                         loaded active running CUPS Scheduler 
  dbus.service                         loaded active running D-Bus System Message Bus 
  display-manager.service              loaded active running X Display Manager 
  dracut-shutdown.service              loaded active exited  Restore /run/initramfs on shutdown 
  fetchmail.service                    loaded active running A remote-mail retrieval utility 
  getty@tty1.service                   loaded active running Getty on tty1 
  hd-idle.service                      loaded active running hd-idle disk spindown service 
  irqbalance.service                   loaded active running irqbalance daemon 
  kbdsettings.service                  loaded active exited  Apply settings from /etc/sysconfig/keyboard 
  kernel-sysctl.service                loaded active exited  Apply Kernel Variables for 5.19.10-1-default 
  kmod-static-nodes.service            loaded active exited  Create List of Static Device Nodes 
  lm_sensors.service                   loaded active exited  Initialize hardware monitoring sensors 
  mcelog.service                       loaded active running Machine Check Exception Logging Daemon 
  minidlna.service                     loaded active running MiniDLNA is a DLNA/UPnP-AV server software 
  plymouth-quit-wait.service           loaded active exited  Hold until boot process finishes up 
  plymouth-read-write.service          loaded active exited  Tell Plymouth To Write Out Runtime Data 
  polkit.service                       loaded active running Authorization Manager 
  postfix.service                      loaded active running Postfix Mail Transport Agent 
  rpcbind.service                      loaded active running RPC Bind 
  rsyncd.service                       loaded active running Start the rsync server daemon 
  rtkit-daemon.service                 loaded active running RealtimeKit Scheduling Policy Service 
  sshd.service                         loaded active running OpenSSH Daemon 
  systemd-journal-flush.service        loaded active exited  Flush Journal to Persistent Storage 
  systemd-journald.service             loaded active running Journal Service 
  systemd-logind.service               loaded active running User Login Management 
  systemd-modules-load.service         loaded active exited  Load Kernel Modules 
  systemd-networkd-wait-online.service loaded active exited  Wait for Network to be Configured 
  systemd-networkd.service             loaded active running Network Configuration 
  systemd-random-seed.service          loaded active exited  Load/Save Random Seed 
  systemd-remount-fs.service           loaded active exited  Remount Root and Kernel File Systems 
  systemd-resolved.service             loaded active running Network Name Resolution 
  systemd-sysctl.service               loaded active exited  Apply Kernel Variables 
  systemd-tmpfiles-setup-dev.service   loaded active exited  Create Static Device Nodes in /dev 
  systemd-tmpfiles-setup.service       loaded active exited  Create Volatile Files and Directories 
  systemd-udev-trigger.service         loaded active exited  Coldplug All udev Devices 
  systemd-udevd.service                loaded active running Rule-based Manager for Device Events and Files 
  systemd-update-utmp.service          loaded active exited  Record System Boot/Shutdown in UTMP 
  systemd-user-sessions.service        loaded active exited  Permit User Sessions 
  systemd-vconsole-setup.service       loaded active exited  Setup Virtual Console 
  udisks2.service                      loaded active running Disk Manager 
  upower.service                       loaded active running Daemon for power management 
  user-runtime-dir@1000.service        loaded active exited  User Runtime Directory /run/user/1000 
  user@1000.service                    loaded active running User Manager for UID 1000 
**erlangen:~ #**

Show user units:

karl@erlangen:~> **systemctl --user list-units --type service --type scope --legend=no --no-pager** 
  app-firefox-a5f64af5ec3c475fac92f5134448946c.scope         loaded active running Firefox - Web Browser 
  app-firefox-c2e528707bca4f58a72dab0415b68ab0.scope         loaded active running Firefox - Web Browser 
  app-jalbum-b106d3fc0c5243f09dbdd59a14089bf2.scope          loaded active running jAlbum - Make web photo albums with thumbnail pages and slide shows 
  app-org.kde.kmail2-72c05cd874bd4a4f8bb2c0fcacbfca23.scope  loaded active running KMail - Mail Client 
  app-org.kde.kmail2-c99f0a4246634cccbb0aaa111075689b.scope  loaded active running KMail - Mail Client 
  app-org.kde.konsole-9b013369fcc943778f0ee0964e676343.scope loaded active running Konsole - Terminal 
  app-org.kde.konsole-ee9926b0f74144d791900130dd9c3086.scope loaded active running Konsole - Terminal 
  init.scope                                                 loaded active running System and Service Manager                                         
  app-geoclue\x2ddemo\x2dagent@autostart.service             loaded active running Geoclue Demo agent 
  app-kaccess@autostart.service                              loaded active running Accessibility 
  app-org.kde.kalendarac@autostart.service                   loaded active running Calendar Reminders 
  at-spi-dbus-bus.service                                    loaded active running Accessibility services bus 
  dbus.service                                               loaded active running D-Bus User Message Bus 
  dconf.service                                              loaded active running User preferences database 
  gvfs-daemon.service                                        loaded active running Virtual filesystem service 
  gvfs-metadata.service                                      loaded active running Virtual filesystem metadata service 
  kde-baloo.service                                          loaded active running Baloo File Indexer Daemon 
  pipewire-pulse.service                                     loaded active running PipeWire PulseAudio 
  pipewire.service                                           loaded active running PipeWire Multimedia Service 
  plasma-baloorunner.service                                 loaded active running KRunner provider for baloo file indexer 
  plasma-dolphin.service                                     loaded active running Dolphin file manager 
  plasma-gmenudbusmenuproxy.service                          loaded active running Proxies GTK DBus menus to a Plasma readable format 
  plasma-kactivitymanagerd.service                           loaded active running KActivityManager Activity manager Service 
  plasma-kded.service                                        loaded active running KDE Daemon 
  plasma-kglobalaccel.service                                loaded active running KDE Global Shortcuts Server 
  plasma-kscreen.service                                     loaded active running KScreen 
  plasma-ksmserver.service                                   loaded active running KDE Session Management Server 
  plasma-kwin_x11.service                                    loaded active running KDE Window Manager 
  plasma-plasmashell.service                                 loaded active running KDE Plasma Workspace 
  plasma-polkit-agent.service                                loaded active running KDE PolicyKit Authentication Agent 
  plasma-powerdevil.service                                  loaded active running Powerdevil 
  plasma-xdg-desktop-portal-kde.service                      loaded active running Xdg Desktop Portal For KDE 
  plasma-xembedsniproxy.service                              loaded active running Handle legacy xembed system tray icons 
  save-jalbum-settings.service                               loaded active running Save jAlbum Project Files 
  systemd-tmpfiles-setup.service                             loaded active exited  Create User's Volatile Files and Directories 
  wireplumber.service                                        loaded active running Multimedia Service Session Manager 
  xdg-desktop-portal-gtk.service                             loaded active running Portal service (GTK/GNOME implementation) 
  xdg-desktop-portal.service                                 loaded active running Portal service 
  xdg-document-portal.service                                loaded active running flatpak document portal service 
  xdg-permission-store.service                               loaded active running sandboxed app permission store 
karl@erlangen:~>

Search the journal:

**erlangen:~ #** **journalctl -q -u udisks2.service -g /dev/sda** 
Sep 20 12:58:02 erlangen udisksd[1255]: **Mounted ****/dev/sda****1 at /media/DMC-TZ71 on behalf of uid 1000**
Sep 21 07:32:05 erlangen udisksd[1249]: **Mounted ****/dev/sda****1 at /media/DMC-TZ71 on behalf of uid 1000**
Sep 21 18:03:52 erlangen udisksd[1249]: **Mounted ****/dev/sda**** (system) at /FR735 on behalf of uid 1000**
Sep 22 21:28:50 erlangen udisksd[1246]: **Mounted ****/dev/sda**** (system) at /FR735 on behalf of uid 1000**
Sep 23 17:30:36 erlangen udisksd[1250]: **Mounted ****/dev/sda****2 at /media/openSUSE-Leap-15.4-NET-x86_64243 on behalf of uid 1000**
Sep 23 17:53:22 erlangen udisksd[1250]: **Mounted ****/dev/sda**** (system) at /FR735 on behalf of uid 1000**
Sep 24 19:03:41 erlangen udisksd[1250]: **Mounted ****/dev/sda**** (system) at /FR735 on behalf of uid 1000**
Sep 25 18:13:11 erlangen udisksd[1250]: **Mounted ****/dev/sda****1 at /media/DMC-TZ71 on behalf of uid 1000**
Sep 26 12:18:38 erlangen udisksd[1319]: **Mounted ****/dev/sda**** (system) at /FR735 on behalf of uid 1000**
Sep 27 15:08:28 erlangen udisksd[1241]: **Mounted ****/dev/sda****1 at /media/DMC-TZ71 on behalf of uid 1000**
Sep 27 16:24:27 erlangen udisksd[1241]: **Mounted ****/dev/sda****2 at /media/openSUSE-Tumbleweed-NET-x86_6433 on behalf of uid 1000**
Sep 27 16:51:43 erlangen udisksd[1241]: **Mounted ****/dev/sda****1 at /media/Fedora-WS-Live-36-1-5 on behalf of uid 1000**
Sep 28 08:19:16 erlangen udisksd[1241]: **Mounted ****/dev/sda****1 at /media/Fedora-WS-Live-36-1-5 on behalf of uid 1000**
Sep 28 18:39:31 erlangen udisksd[1241]: **Mounted ****/dev/sda**** (system) at /FR735 on behalf of uid 1000**
**erlangen:~ #**

Yet another example:

**erlangen:~ #** journalctl -q -g sda --since 9:00 
Sep 30 09:28:58 erlangen kernel: **sd 6:0:0:0: ****sda****] 20646 512-byte logical blocks: (10.6 MB/10.1 MiB)** 
Sep 30 09:28:58 erlangen kernel: **sd 6:0:0:0: ****sda****] Write Protect is off** 
Sep 30 09:28:58 erlangen kernel: sd 6:0:0:0: **sda**] Mode Sense: 23 00 00 00 
Sep 30 09:28:58 erlangen kernel: **sd 6:0:0:0: ****sda****] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA** 
Sep 30 09:28:58 erlangen kernel:  sda: 
Sep 30 09:28:58 erlangen kernel: **sd 6:0:0:0: ****sda****] Attached SCSI removable disk** 
Sep 30 09:28:59 erlangen udisksd[1241]: **Mounted /dev/****sda**** (system) at /FR735 on behalf of uid 1000** 
Sep 30 09:28:59 erlangen kernel: **FAT-fs (****sda****): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.** 
**erlangen:~ #**
5

The iotop tool might also give some useful info.


>LANG=C zypper se iotop 
Loading repository data... 
Reading installed packages... 

S  | Name  | Summary                                      | Type 
---+-------+----------------------------------------------+-------- 
i+ | iotop | Top Like UI to Show Per-Process I/O Going on | package
> sudo /usr/sbin/iotop
6

What am I looking for here?

System Units: https://paste.opensuse.org/17883400

And here? User Units: https://paste.opensuse.org/43970557

Journal Search - Note /dev/sda is mounted as one of the backup drives - as of 18:00 when I tested the situation all it shows is it was mounted.

rhack@localhost:/Data2/Work> journalctl -q -u udisks2.service -g /dev/sda 
Sep 28 05:06:38 localhost.localdomain udisksd[2211]: **Mounted ****/dev/sda****1 at /run/media/rhack/Backup5 on behalf of uid 1000**
Sep 28 11:24:39 localhost.localdomain udisksd[2211]: **Unmounted ****/dev/sda****1 on behalf of uid 1000**
Sep 29 00:20:50 localhost.localdomain udisksd[2211]: **Mounted ****/dev/sda****1 at /run/media/rhack/Backup4 on behalf of uid 1000**
Sep 29 13:37:19 localhost.localdomain udisksd[2211]: **Unmounted ****/dev/sda****1 on behalf of uid 1000**
Sep 29 13:37:22 localhost.localdomain udisksd[2211]: **Successfully sent SCSI command SYNCHRONIZE CACHE to ****/dev/sda**
Sep 29 13:37:24 localhost.localdomain udisksd[2211]: **Successfully sent SCSI command START STOP UNIT to ****/dev/sda**
Sep 29 13:37:25 localhost.localdomain udisksd[2211]: **Powered off ****/dev/sda**** - successfully wrote to sysfs path /sys/devices/pci0000:00/0000:00:07.1/0000:0c:00.3/usb8/8-2/remove**
Sep 30 02:08:25 localhost.localdomain udisksd[2211]: **Mounted ****/dev/sda****1 at /run/media/rhack/Backup4 on behalf of uid 1000**
Sep 30 10:41:08 localhost.localdomain udisksd[2211]: **Unmounted ****/dev/sda****1 on behalf of uid 1000**
Sep 30 10:41:11 localhost.localdomain udisksd[2211]: **Successfully sent SCSI command SYNCHRONIZE CACHE to ****/dev/sda**
Sep 30 10:41:13 localhost.localdomain udisksd[2211]: **Successfully sent SCSI command START STOP UNIT to ****/dev/sda**
Sep 30 10:41:14 localhost.localdomain udisksd[2211]: **Powered off ****/dev/sda**** - successfully wrote to sysfs path /sys/devices/pci0000:00/0000:00:07.1/0000:0c:00.3/usb8/8-2/remove**
Sep 30 18:05:51 localhost.localdomain udisksd[2211]: **Mounted ****/dev/sda****1 at /run/media/rhack/Backup4 on behalf of uid 1000**

journalctl -q -g sda --since 9:00 Note that it’s the same here - all we see is that it was mounted.

Sep 30 10:41:08 localhost.localdomain udisksd[2211]: **Unmounted /dev/****sda****1 on behalf of uid 1000**
Sep 30 10:41:11 localhost.localdomain udisksd[2211]: **Successfully sent SCSI command SYNCHRONIZE CACHE to /dev/****sda**
Sep 30 10:41:13 localhost.localdomain udisksd[2211]: **Successfully sent SCSI command START STOP UNIT to /dev/****sda**
Sep 30 10:41:13 localhost.localdomain kernel: **sd 11:0:0:0: ****sda****] Synchronizing SCSI cache**
Sep 30 10:41:13 localhost.localdomain kernel: sd 11:0:0:0: [sda] Synchronize Cache(10) failed: Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK 
Sep 30 10:41:14 localhost.localdomain udisksd[2211]: **Powered off /dev/****sda**** - successfully wrote to sysfs path /sys/devices/pci0000:00/0000:00:07.1/0000:0c:00.3/usb8/8-2/remove**
Sep 30 11:06:22 localhost.localdomain smartd[1283]: Device: /dev/sda [SAT], removed ATA device: No such device 
Sep 30 18:05:50 localhost.localdomain kernel: **sd 11:0:0:0: ****sda****] 15628053168 512-byte logical blocks: (8.00 TB/7.28 TiB)**
Sep 30 18:05:50 localhost.localdomain kernel: **sd 11:0:0:0: ****sda****] 4096-byte physical blocks**
Sep 30 18:05:50 localhost.localdomain kernel: **sd 11:0:0:0: ****sda****] Write Protect is off**
Sep 30 18:05:50 localhost.localdomain kernel: sd 11:0:0:0: **sda**] Mode Sense: 43 00 00 00
Sep 30 18:05:50 localhost.localdomain kernel: **sd 11:0:0:0: ****sda****] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA**
Sep 30 18:05:50 localhost.localdomain kernel: **sd 11:0:0:0: ****sda****] Optimal transfer size 33553920 bytes not a multiple of physical block size (4096 bytes)**
Sep 30 18:05:50 localhost.localdomain kernel:  sda: sda1 
Sep 30 18:05:51 localhost.localdomain kernel: **sd 11:0:0:0: ****sda****] Attached SCSI disk**
Sep 30 18:05:51 localhost.localdomain udisksd[2211]: **Mounted /dev/****sda****1 at /run/media/rhack/Backup4 on behalf of uid 1000**
Sep 30 18:05:51 localhost.localdomain kernel: EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: errors=remount-ro. Quota mode: none. 
Sep 30 18:06:22 localhost.localdomain smartd[1283]: Device: /dev/sda [SAT], reconnected ATA device
7

I just found the problem using iotop as suggested above.

Powering up the drives and running iotop, I see ext4lazyinit running as the top drive IO. When the drives stop thrashing, lazyinit is no longer running.

Looking up what lazyinit is, I see it is supposed to be a background file system initializer that runs after a file system is created on first mount.

If it’s on first mount, why the hell is it running on a mount that already has a formatted file system and has had one for a year or more?

AH… Just found this with a Google search:

Re: ext4lazyinit reads HDD data on mount since 5.13

It’s a new feature which optimizes block allocations for very large file systems. The work being done by ext4lazyinit is to read the block allocation bitmaps so we can cache the buddy bitmaps and how fragmented (or not) various block groups are, which is used to optimize the block allocator.

To disable this behavior you can mount with the option -o no_prefetch_block_bitmaps, but there may be some performance loss.

OK, so that explains it. Apparently there’s no harm in letting it run for a few minutes. These are 8TB drives, so I’m not surprised it takes a while longer. I’m just not sure why this wasn’t happening in Leap 15.3,

I think we can mark this one explained (more or less).

8
  • Use “journal -g ext4” to find out more
  • More: ext4lazyinit - Google Suche
  • Never observed such annoyances with a 8 TB btrfs system. Mount is always instantaneous:
**erlangen:~ #** journalctl --boot f6dd27dd3f5c44cc8557b5fe05cbc738 --unit backup-home.service  
Sep 22 00:00:07 erlangen systemd[1]: Starting Backup /home... 
Sep 22 00:00:11 erlangen systemd[1]: Started Backup /home. 
Sep 22 00:01:23 erlangen systemd[1]: backup-home.service: Deactivated successfully. 
Sep 22 00:01:23 erlangen systemd[1]: backup-home.service: Consumed 13.324s CPU time. 
**erlangen:~ #**