You are not logged in.
- Topics: Active | Unanswered
Pages: 1
#1 2026-04-23 21:39:13
- Shalrath
- Member
- Registered: 2020-05-26
- Posts: 16
HDD takes a 30s sleep when mounting
Hi,
I have an old HDD with an odd behavior. Whenever I try to mount it for the first time after powering it up, mounting takes about 30 seconds. This has been like this since a long time and there were no other problems with this disk ever. I used it in a USB case as an external drive and I just waited whenever using it. I thought it might be the cheap USB controller causing this.
Now I want to use the HDD internally and it causes the boot process to hang for about 30s before continuing, so I've started to investigate where this delay is coming from and I have no idea. I put it back into the external USB case but that is not the problem as the drive behaves the same when connected to an internal SATA directly.
I have reformatted it and repartitioned it but neither helped. Currently it is partitionless ext4 but I had the same behavior with the filesystem on an MBR partition.
Kernel log: Look at the timestamps of the last two lines
[ 4728.638142] usb 1-4: new high-speed USB device number 16 using xhci_hcd
[ 4728.785563] usb 1-4: New USB device found, idVendor=0c0b, idProduct=b159, bcdDevice= 1.03
[ 4728.785576] usb 1-4: New USB device strings: Mfr=2, Product=3, SerialNumber=1
[ 4728.785583] usb 1-4: Product: DataStation maxi m.u
[ 4728.785589] usb 1-4: Manufacturer: Trekstor
[ 4728.785594] usb 1-4: SerialNumber: 000391f4
[ 4728.789598] usb-storage 1-4:1.0: USB Mass Storage device detected
[ 4728.790153] scsi host6: usb-storage 1-4:1.0
[ 4729.860614] scsi 6:0:0:0: Direct-Access WDC WD20 EARS-00MVWB0 PQ: 0 ANSI: 2
[ 4729.861227] sd 6:0:0:0: Attached scsi generic sg2 type 0
[ 4729.891799] sd 6:0:0:0: [sdc] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
[ 4729.893878] sd 6:0:0:0: [sdc] Write Protect is off
[ 4729.893881] sd 6:0:0:0: [sdc] Mode Sense: 38 00 00 00
[ 4729.895798] sd 6:0:0:0: [sdc] No Caching mode page found
[ 4729.895801] sd 6:0:0:0: [sdc] Assuming drive cache: write through
[ 4729.917668] sd 6:0:0:0: [sdc] Attached SCSI disk
[ 4768.150491] EXT4-fs (sdc): mounted filesystem d7912aa5-4271-4c88-8eea-e04cb83a6cdd r/w with ordered data mode. Quota mode: none.This is the shell when mounting it. I timed it and used -v but that doesn't help much.
[root@ws2 mnt]# time mount -v /dev/sdc /mnt/misc
mount: /dev/sdc mounted on /mnt/misc.
real 0m36,132s
user 0m0,002s
sys 0m0,052s
[root@ws2 mnt]# time umount -v /mnt/misc
umount: /mnt/misc unmounted
real 0m18,679s
user 0m0,002s
sys 0m0,009sThis is the output of smartctl:
[root@ws2 mnt]# smartctl -a /dev/sdc
smartctl 7.5 2025-04-30 r5714 [x86_64-linux-6.19.12-arch1-1] (local build)
Copyright (C) 2002-25, Bruce Allen, Christian Franke, www.smartmontools.org
=== START OF INFORMATION SECTION ===
Model Family: Western Digital Caviar Green (AF)
Device Model: WDC WD20EARS-00MVWB0
Serial Number: WD-WMAZA1557732
LU WWN Device Id: 5 0014ee 600815f63
Firmware Version: 51.0AB51
User Capacity: 2.000.398.934.016 bytes [2,00 TB]
Sector Size: 512 bytes logical/physical
Device is: In smartctl database 7.5/5706
ATA Version is: ATA8-ACS (minor revision not indicated)
SATA Version is: SATA 2.6, 3.0 Gb/s
Local Time is: Thu Apr 23 23:21:35 2026 CEST
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: (0x82) Offline data collection activity
was completed without error.
Auto Offline Data Collection: Enabled.
Self-test execution status: ( 0) The previous self-test routine completed
without error or no self-test has ever
been run.
Total time to complete Offline
data collection: (38160) seconds.
Offline data collection
capabilities: (0x7b) SMART execute Offline immediate.
Auto Offline data collection on/off support.
Suspend Offline collection upon new
command.
Offline surface scan supported.
Self-test supported.
Conveyance Self-test supported.
Selective Self-test supported.
SMART capabilities: (0x0003) Saves SMART data before entering
power-saving mode.
Supports SMART auto save timer.
Error logging capability: (0x01) Error logging supported.
General Purpose Logging supported.
Short self-test routine
recommended polling time: ( 2) minutes.
Extended self-test routine
recommended polling time: ( 368) minutes.
Conveyance self-test routine
recommended polling time: ( 5) minutes.
SCT capabilities: (0x3035) SCT Status 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 0x002f 200 200 051 Pre-fail Always - 0
3 Spin_Up_Time 0x0027 167 162 021 Pre-fail Always - 6608
4 Start_Stop_Count 0x0032 099 099 000 Old_age Always - 1045
5 Reallocated_Sector_Ct 0x0033 200 200 140 Pre-fail Always - 0
7 Seek_Error_Rate 0x002e 200 200 000 Old_age Always - 0
9 Power_On_Hours 0x0032 097 097 000 Old_age Always - 2430
10 Spin_Retry_Count 0x0032 100 100 000 Old_age Always - 0
11 Calibration_Retry_Count 0x0032 100 100 000 Old_age Always - 0
12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 933
192 Power-Off_Retract_Count 0x0032 199 199 000 Old_age Always - 859
193 Load_Cycle_Count 0x0032 198 198 000 Old_age Always - 7075
194 Temperature_Celsius 0x0022 125 101 000 Old_age Always - 25
196 Reallocated_Event_Count 0x0032 200 200 000 Old_age Always - 0
197 Current_Pending_Sector 0x0032 200 200 000 Old_age Always - 0
198 Offline_Uncorrectable 0x0030 200 200 000 Old_age Offline - 0
199 UDMA_CRC_Error_Count 0x0032 200 200 000 Old_age Always - 5
200 Multi_Zone_Error_Rate 0x0008 200 200 000 Old_age Offline - 0
SMART Error Log Version: 1
No Errors Logged
SMART Self-test log structure revision number 1
Num Test_Description Status Remaining LifeTime(hours) LBA_of_first_error
# 1 Short offline Completed without error 00% 2424 -
SMART Selective self-test log data structure revision number 1
SPAN MIN_LBA MAX_LBA CURRENT_TEST_STATUS
1 0 0 Not_testing
2 0 0 Not_testing
3 0 0 Not_testing
4 0 0 Not_testing
5 0 0 Not_testing
Selective self-test flags (0x0):
After scanning selected spans, do NOT read-scan remainder of disk.
If Selective self-test is pending on power-up, resume after 0 minute delay.
The above only provides legacy SMART information - try 'smartctl -x' for moreEverything seems fine except the delay that shows in the timestamps.
Any ideas where I could continue digging, e.g. get more verbose logs for when the delay is happening?
Thank you in advance,
Stephan
Offline
#2 2026-04-23 22:57:48
- seth
- Member
- From: Won't reply 2 private help req
- Registered: 2012-09-03
- Posts: 75,177
Re: HDD takes a 30s sleep when mounting
Check the journal, not dmesg - could be in userspace (some udev rule)?
Online
#3 2026-04-23 23:25:08
- Shalrath
- Member
- Registered: 2020-05-26
- Posts: 16
Re: HDD takes a 30s sleep when mounting
[root@ws2 mnt]# journalctl -f
Apr 24 01:08:32 ws2 kernel: usb 1-4: new high-speed USB device number 17 using xhci_hcd
Apr 24 01:08:32 ws2 kernel: usb 1-4: New USB device found, idVendor=0c0b, idProduct=b159, bcdDevice= 1.03
Apr 24 01:08:32 ws2 kernel: usb 1-4: New USB device strings: Mfr=2, Product=3, SerialNumber=1
Apr 24 01:08:32 ws2 kernel: usb 1-4: Product: DataStation maxi m.u
Apr 24 01:08:32 ws2 kernel: usb 1-4: Manufacturer: Trekstor
Apr 24 01:08:32 ws2 kernel: usb 1-4: SerialNumber: 000391f4
Apr 24 01:08:32 ws2 kernel: usb-storage 1-4:1.0: USB Mass Storage device detected
Apr 24 01:08:32 ws2 kernel: scsi host6: usb-storage 1-4:1.0
Apr 24 01:08:33 ws2 mtp-probe[152142]: checking bus 1, device 17: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-4"
Apr 24 01:08:33 ws2 mtp-probe[152142]: bus: 1, device: 17 was not an MTP device
Apr 24 01:08:33 ws2 mtp-probe[152158]: checking bus 1, device 17: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-4"
Apr 24 01:08:33 ws2 mtp-probe[152158]: bus: 1, device: 17 was not an MTP device
Apr 24 01:08:34 ws2 kernel: scsi 6:0:0:0: Direct-Access WDC WD20 EARS-00MVWB0 PQ: 0 ANSI: 2
Apr 24 01:08:34 ws2 kernel: sd 6:0:0:0: Attached scsi generic sg2 type 0
Apr 24 01:08:34 ws2 kernel: sd 6:0:0:0: [sdc] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
Apr 24 01:08:34 ws2 kernel: sd 6:0:0:0: [sdc] Write Protect is off
Apr 24 01:08:34 ws2 kernel: sd 6:0:0:0: [sdc] Mode Sense: 38 00 00 00
Apr 24 01:08:34 ws2 kernel: sd 6:0:0:0: [sdc] No Caching mode page found
Apr 24 01:08:34 ws2 kernel: sd 6:0:0:0: [sdc] Assuming drive cache: write through
Apr 24 01:08:34 ws2 kernel: sd 6:0:0:0: [sdc] Attached SCSI disk
Apr 24 01:09:35 ws2 kernel: EXT4-fs (sdc): mounted filesystem d7912aa5-4271-4c88-8eea-e04cb83a6cdd r/w with ordered data mode. Quota mode: none.
Apr 24 01:09:46 ws2 systemd[1]: mnt-misc.mount: Deactivated successfully.
Apr 24 01:10:08 ws2 kernel: EXT4-fs (sdc): unmounting filesystem d7912aa5-4271-4c88-8eea-e04cb83a6cdd.No additional information in there except for the mtp-probe that is irrelevant.
Let's try with verbose, including the umount and the powerdown.
[root@ws2 mnt]# journalctl -f -o verbose
Fri 2026-04-24 01:20:19.127506 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ecb;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8ac101e;t=65028e44864d2;x=e0c4092e7655acef]
PRIORITY=6
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
_KERNEL_SUBSYSTEM=usb
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_KERNEL_DEVICE=+usb:1-4
_SOURCE_BOOTTIME_TIMESTAMP=11956694896
_SOURCE_MONOTONIC_TIMESTAMP=11956694896
MESSAGE=usb 1-4: new high-speed USB device number 20 using xhci_hcd
Fri 2026-04-24 01:20:19.271441 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ecc;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8ae425c;t=65028e44a9711;x=11544e18e33d522b]
PRIORITY=6
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
_KERNEL_SUBSYSTEM=usb
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_UDEV_SYSNAME=1-4
MESSAGE=usb 1-4: New USB device found, idVendor=0c0b, idProduct=b159, bcdDevice= 1.03
_KERNEL_DEVICE=c189:19
_UDEV_DEVNODE=/dev/bus/usb/001/020
_SOURCE_BOOTTIME_TIMESTAMP=11956839175
_SOURCE_MONOTONIC_TIMESTAMP=11956839175
Fri 2026-04-24 01:20:19.272564 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ecd;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8ae46bf;t=65028e44a9b74;x=2be8867ecc648722]
PRIORITY=6
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
_KERNEL_SUBSYSTEM=usb
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_UDEV_SYSNAME=1-4
MESSAGE=usb 1-4: New USB device strings: Mfr=2, Product=3, SerialNumber=1
_KERNEL_DEVICE=c189:19
_UDEV_DEVNODE=/dev/bus/usb/001/020
_SOURCE_BOOTTIME_TIMESTAMP=11956839188
_SOURCE_MONOTONIC_TIMESTAMP=11956839188
Fri 2026-04-24 01:20:19.273446 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ece;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8ae4a32;t=65028e44a9ee6;x=fe10501688764fda]
PRIORITY=6
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
_KERNEL_SUBSYSTEM=usb
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_UDEV_SYSNAME=1-4
MESSAGE=usb 1-4: Product: DataStation maxi m.u
_KERNEL_DEVICE=c189:19
_UDEV_DEVNODE=/dev/bus/usb/001/020
_SOURCE_BOOTTIME_TIMESTAMP=11956839195
_SOURCE_MONOTONIC_TIMESTAMP=11956839195
Fri 2026-04-24 01:20:19.274501 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ecf;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8ae4e50;t=65028e44aa305;x=bad7140750e138d6]
PRIORITY=6
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
_KERNEL_SUBSYSTEM=usb
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_UDEV_SYSNAME=1-4
MESSAGE=usb 1-4: Manufacturer: Trekstor
_KERNEL_DEVICE=c189:19
_UDEV_DEVNODE=/dev/bus/usb/001/020
_SOURCE_BOOTTIME_TIMESTAMP=11956839201
_SOURCE_MONOTONIC_TIMESTAMP=11956839201
Fri 2026-04-24 01:20:19.275624 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ed0;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8ae52b3;t=65028e44aa768;x=e53b5dab549feb3a]
PRIORITY=6
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
_KERNEL_SUBSYSTEM=usb
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_UDEV_SYSNAME=1-4
MESSAGE=usb 1-4: SerialNumber: 000391f4
_KERNEL_DEVICE=c189:19
_UDEV_DEVNODE=/dev/bus/usb/001/020
_SOURCE_BOOTTIME_TIMESTAMP=11956839206
_SOURCE_MONOTONIC_TIMESTAMP=11956839206
Fri 2026-04-24 01:20:19.276000 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ed1;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8ae542b;t=65028e44aa8e0;x=fb5aee6040d650e8]
PRIORITY=6
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
_KERNEL_SUBSYSTEM=usb
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_KERNEL_DEVICE=+usb:1-4:1.0
_UDEV_SYSNAME=1-4:1.0
MESSAGE=usb-storage 1-4:1.0: USB Mass Storage device detected
_SOURCE_BOOTTIME_TIMESTAMP=11956843344
_SOURCE_MONOTONIC_TIMESTAMP=11956843344
Fri 2026-04-24 01:20:19.276282 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ed2;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8ae5545;t=65028e44aa9fa;x=4504712fe5ba6c56]
PRIORITY=6
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
_KERNEL_SUBSYSTEM=scsi
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_KERNEL_DEVICE=+scsi:host7
_UDEV_SYSNAME=host7
MESSAGE=scsi host7: usb-storage 1-4:1.0
_SOURCE_BOOTTIME_TIMESTAMP=11956843909
_SOURCE_MONOTONIC_TIMESTAMP=11956843909
Fri 2026-04-24 01:20:19.287840 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ed3;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8ae8285;t=65028e44ad73a;x=893d2230f65b451a]
PRIORITY=6
_UID=0
_GID=0
_SYSTEMD_SLICE=system.slice
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_CAP_EFFECTIVE=1f7fdffffff
_SYSTEMD_CGROUP=/system.slice/systemd-udevd.service/udev
_SYSTEMD_UNIT=systemd-udevd.service
_TRANSPORT=syslog
SYSLOG_FACILITY=1
SYSLOG_IDENTIFIER=mtp-probe
_COMM=mtp-probe
_EXE=/usr/lib/udev/mtp-probe
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_SYSTEMD_INVOCATION_ID=66ec7b4958e44b87b88cde2559370a6a
SYSLOG_TIMESTAMP=Apr 24 01:20:19
MESSAGE=checking bus 1, device 20: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-4"
SYSLOG_RAW=<14>Apr 24 01:20:19 mtp-probe: checking bus 1, device 20: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-4"
_PID=159585
_CMDLINE=/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:14.0/usb1/1-4 1 20
_SOURCE_REALTIME_TIMESTAMP=1776986419287840
Fri 2026-04-24 01:20:19.288100 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ed4;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8ae8598;t=65028e44ada4d;x=3e018259fe8812e5]
PRIORITY=6
_UID=0
_GID=0
_SYSTEMD_SLICE=system.slice
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_CAP_EFFECTIVE=1f7fdffffff
_SYSTEMD_CGROUP=/system.slice/systemd-udevd.service/udev
_SYSTEMD_UNIT=systemd-udevd.service
_TRANSPORT=syslog
SYSLOG_FACILITY=1
SYSLOG_IDENTIFIER=mtp-probe
_COMM=mtp-probe
_EXE=/usr/lib/udev/mtp-probe
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_SYSTEMD_INVOCATION_ID=66ec7b4958e44b87b88cde2559370a6a
SYSLOG_TIMESTAMP=Apr 24 01:20:19
_PID=159585
_CMDLINE=/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:14.0/usb1/1-4 1 20
MESSAGE=bus: 1, device: 20 was not an MTP device
SYSLOG_RAW=<14>Apr 24 01:20:19 mtp-probe: bus: 1, device: 20 was not an MTP device
_SOURCE_REALTIME_TIMESTAMP=1776986419288100
Fri 2026-04-24 01:20:19.327795 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ed5;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8af1e99;t=65028e44b734e;x=6d172bce3a952c36]
PRIORITY=6
_UID=0
_GID=0
_SYSTEMD_SLICE=system.slice
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_CAP_EFFECTIVE=1f7fdffffff
_SYSTEMD_CGROUP=/system.slice/systemd-udevd.service/udev
_SYSTEMD_UNIT=systemd-udevd.service
_TRANSPORT=syslog
SYSLOG_FACILITY=1
SYSLOG_IDENTIFIER=mtp-probe
_COMM=mtp-probe
_EXE=/usr/lib/udev/mtp-probe
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_SYSTEMD_INVOCATION_ID=66ec7b4958e44b87b88cde2559370a6a
SYSLOG_TIMESTAMP=Apr 24 01:20:19
MESSAGE=checking bus 1, device 20: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-4"
SYSLOG_RAW=<14>Apr 24 01:20:19 mtp-probe: checking bus 1, device 20: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-4"
_CMDLINE=/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:14.0/usb1/1-4 1 20
_PID=159601
_SOURCE_REALTIME_TIMESTAMP=1776986419327795
Fri 2026-04-24 01:20:19.328023 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ed6;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8af1ff2;t=65028e44b74a7;x=f87201ac46c850e0]
PRIORITY=6
_UID=0
_GID=0
_SYSTEMD_SLICE=system.slice
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_CAP_EFFECTIVE=1f7fdffffff
_SYSTEMD_CGROUP=/system.slice/systemd-udevd.service/udev
_SYSTEMD_UNIT=systemd-udevd.service
_TRANSPORT=syslog
SYSLOG_FACILITY=1
SYSLOG_IDENTIFIER=mtp-probe
_COMM=mtp-probe
_EXE=/usr/lib/udev/mtp-probe
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_SYSTEMD_INVOCATION_ID=66ec7b4958e44b87b88cde2559370a6a
SYSLOG_TIMESTAMP=Apr 24 01:20:19
_CMDLINE=/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:14.0/usb1/1-4 1 20
MESSAGE=bus: 1, device: 20 was not an MTP device
SYSLOG_RAW=<14>Apr 24 01:20:19 mtp-probe: bus: 1, device: 20 was not an MTP device
_PID=159601
_SOURCE_REALTIME_TIMESTAMP=1776986419328023
Fri 2026-04-24 01:20:20.283474 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ed7;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8bdb39d;t=65028e45a0852;x=e741ed0bbcf27ac3]
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
PRIORITY=5
_KERNEL_SUBSYSTEM=scsi
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_KERNEL_DEVICE=+scsi:7:0:0:0
_UDEV_SYSNAME=7:0:0:0
MESSAGE=scsi 7:0:0:0: Direct-Access WDC WD20 EARS-00MVWB0 PQ: 0 ANSI: 2
_SOURCE_BOOTTIME_TIMESTAMP=11957851451
_SOURCE_MONOTONIC_TIMESTAMP=11957851451
Fri 2026-04-24 01:20:20.285183 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ed8;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8bdba4a;t=65028e45a0eff;x=23a4e3c8e13400d1]
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
PRIORITY=5
_KERNEL_SUBSYSTEM=scsi
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_KERNEL_DEVICE=+scsi:7:0:0:0
_UDEV_SYSNAME=7:0:0:0
MESSAGE=sd 7:0:0:0: Attached scsi generic sg2 type 0
_SOURCE_BOOTTIME_TIMESTAMP=11957852155
_SOURCE_MONOTONIC_TIMESTAMP=11957852155
Fri 2026-04-24 01:20:20.309425 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ed9;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8be18fc;t=65028e45a6db1;x=9b0eef22633d420]
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
PRIORITY=5
_KERNEL_SUBSYSTEM=scsi
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_KERNEL_DEVICE=+scsi:7:0:0:0
_UDEV_SYSNAME=7:0:0:0
MESSAGE=sd 7:0:0:0: [sdd] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
_SOURCE_BOOTTIME_TIMESTAMP=11957877333
_SOURCE_MONOTONIC_TIMESTAMP=11957877333
Fri 2026-04-24 01:20:20.311425 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480eda;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8be20cc;t=65028e45a7581;x=a37c106b463189de]
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
PRIORITY=5
_KERNEL_SUBSYSTEM=scsi
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_KERNEL_DEVICE=+scsi:7:0:0:0
_UDEV_SYSNAME=7:0:0:0
MESSAGE=sd 7:0:0:0: [sdd] Write Protect is off
_SOURCE_BOOTTIME_TIMESTAMP=11957879589
_SOURCE_MONOTONIC_TIMESTAMP=11957879589
Fri 2026-04-24 01:20:20.311750 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480edb;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8be2211;t=65028e45a76c6;x=b8ebd7fe46b1ce93]
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
PRIORITY=7
_KERNEL_SUBSYSTEM=scsi
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_KERNEL_DEVICE=+scsi:7:0:0:0
_UDEV_SYSNAME=7:0:0:0
MESSAGE=sd 7:0:0:0: [sdd] Mode Sense: 38 00 00 00
_SOURCE_BOOTTIME_TIMESTAMP=11957879592
_SOURCE_MONOTONIC_TIMESTAMP=11957879592
Fri 2026-04-24 01:20:20.313434 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480edc;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8be28a5;t=65028e45a7d5a;x=88c24ac498a3d428]
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
PRIORITY=4
_KERNEL_SUBSYSTEM=scsi
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_KERNEL_DEVICE=+scsi:7:0:0:0
_UDEV_SYSNAME=7:0:0:0
MESSAGE=sd 7:0:0:0: [sdd] No Caching mode page found
_SOURCE_BOOTTIME_TIMESTAMP=11957881723
_SOURCE_MONOTONIC_TIMESTAMP=11957881723
Fri 2026-04-24 01:20:20.313760 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480edd;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8be29eb;t=65028e45a7ea0;x=8a2db232b2bebb55]
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
PRIORITY=4
_KERNEL_SUBSYSTEM=scsi
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_KERNEL_DEVICE=+scsi:7:0:0:0
_UDEV_SYSNAME=7:0:0:0
MESSAGE=sd 7:0:0:0: [sdd] Assuming drive cache: write through
_SOURCE_BOOTTIME_TIMESTAMP=11957881725
_SOURCE_MONOTONIC_TIMESTAMP=11957881725
Fri 2026-04-24 01:20:20.344435 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ede;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2c8bea1bf;t=65028e45af673;x=ac973c307e6ea970]
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
PRIORITY=5
_KERNEL_SUBSYSTEM=scsi
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_KERNEL_DEVICE=+scsi:7:0:0:0
_UDEV_SYSNAME=7:0:0:0
MESSAGE=sd 7:0:0:0: [sdd] Attached SCSI disk
_SOURCE_BOOTTIME_TIMESTAMP=11957912659
_SOURCE_MONOTONIC_TIMESTAMP=11957912659
Fri 2026-04-24 01:21:19.816474 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480edf;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2cc4a1a65;t=65028e7e66f1a;x=9d8b1029f79bc0d0]
PRIORITY=6
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
MESSAGE=EXT4-fs (sdd): mounted filesystem d7912aa5-4271-4c88-8eea-e04cb83a6cdd r/w with ordered data mode. Quota mode: none.
_SOURCE_BOOTTIME_TIMESTAMP=12017384818
_SOURCE_MONOTONIC_TIMESTAMP=12017384818
Fri 2026-04-24 01:21:47.405472 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ee0;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2cdef13eb;t=65028e98b68a0;x=d513688693c3c6ac]
PRIORITY=6
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
MESSAGE=EXT4-fs (sdd): unmounting filesystem d7912aa5-4271-4c88-8eea-e04cb83a6cdd.
_SOURCE_BOOTTIME_TIMESTAMP=12044973577
_SOURCE_MONOTONIC_TIMESTAMP=12044973577
Fri 2026-04-24 01:21:58.511440 CEST [s=5f919a7402aa484da9fb5f6770606149;i=480ee1;b=fe209c10f47747f1a3e1b0aa1b4b7994;m=2ce988a9c;t=65028ea34df50;x=b1fc1aaa34a9da9]
PRIORITY=6
_MACHINE_ID=2cac1a02c53bc0a2bfabb9b100000370
_HOSTNAME=ws2
_RUNTIME_SCOPE=system
_TRANSPORT=kernel
SYSLOG_FACILITY=0
SYSLOG_IDENTIFIER=kernel
_KERNEL_SUBSYSTEM=usb
_BOOT_ID=fe209c10f47747f1a3e1b0aa1b4b7994
_UDEV_SYSNAME=1-4
_KERNEL_DEVICE=c189:19
_UDEV_DEVNODE=/dev/bus/usb/001/020
_SOURCE_BOOTTIME_TIMESTAMP=12056079633
_SOURCE_MONOTONIC_TIMESTAMP=12056079633
MESSAGE=usb 1-4: USB disconnect, device number 20... I don't see it. Especially during the delay, nothing is logged.
Offline
#4 2026-04-24 07:48:24
- dimich
- Member
- From: Kharkiv, Ukraine
- Registered: 2009-11-03
- Posts: 595
Re: HDD takes a 30s sleep when mounting
Shalrath wrote:
# time mount -v /dev/sdc /mnt/misc
Superdisk, no partitions? What if specify filesystem explicitly and mount r/o?
# mount -t ext4 -o ro /dev/sdc /mnt/micsAlso let's check where exactly delay happens:
# sudo strace -o mount.strace -ry mount /dev/sda /mnt/miscand show mount.strace
Please also show your /etc/fstab.
Does the same delay occur if you mount it from Arch ISO boot?
Offline
#5 2026-04-24 08:40:49
- seth
- Member
- From: Won't reply 2 private help req
- Registered: 2012-09-03
- Posts: 75,177
Re: HDD takes a 30s sleep when mounting
Let's try with verbose, including the umount and the powerdown.
https://wiki.archlinux.org/title/Udev#Debug_output
udevadm control --log-priority=debug
udevadm control --log-priority=infoPlease add "-tt" to the strace so we can see delays/gaps.
Online
#6 2026-04-24 09:04:35
- dimich
- Member
- From: Kharkiv, Ukraine
- Registered: 2009-11-03
- Posts: 595
Re: HDD takes a 30s sleep when mounting
seth wrote:
Please add "-tt" to the strace so we can see delays/gaps.
"-r" already enables relative timestamps, easier to spot delays. For microsecond precision "--relative-timestamps=us" can be used.
Edit: however, both "-r" and "-tt" will be even better. Nevermind.
Last edited by dimich (2026-04-24 09:07:32)
Offline
#7 2026-04-24 09:31:48
- cryptearth
- Member
- Registered: 2024-02-03
- Posts: 2,104
Re: HDD takes a 30s sleep when mounting
unless it's writing cached data unmounting taking nearly 20 seconds doesn't right
Offline
#8 2026-04-24 16:49:49
- Shalrath
- Member
- Registered: 2020-05-26
- Posts: 16
Re: HDD takes a 30s sleep when mounting
dimich wrote:
Superdisk, no partitions?
Shalrath wrote:
Currently it is partitionless ext4 but I had the same behavior with the filesystem on an MBR partition.
dimich wrote:
What if specify filesystem explicitly and mount r/o?
The same kind of delay is present.
seth wrote:
udevadm control --log-priority=debug udevadm control --log-priority=info
This creates no additional output in the journal.
Mounting with strace:
[root@ws2 rawjaw]# strace -ry mount -t ext4 -o ro /dev/sdc /mnt/misc
0.000000 execve("/usr/bin/mount", ["mount", "-t", "ext4", "-o", "ro", "/dev/sdc", "/mnt/misc"], 0x7fff8bc306e8 /* 55 vars */) = 0
0.000905 brk(NULL) = 0x5586bd299000
0.000259 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
0.001362 openat(AT_FDCWD</home/rawjaw>, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3</etc/ld.so.cache>
0.000558 fstat(3</etc/ld.so.cache>, {st_mode=S_IFREG|0644, st_size=210419, ...}) = 0
0.000280 mmap(NULL, 210419, PROT_READ, MAP_PRIVATE, 3</etc/ld.so.cache>, 0) = 0x7f5ae8c47000
0.000180 close(3</etc/ld.so.cache>) = 0
0.000151 openat(AT_FDCWD</home/rawjaw>, "/usr/lib/libmount.so.1", O_RDONLY|O_CLOEXEC) = 3</usr/lib/libmount.so.1.1.0>
0.000178 read(3</usr/lib/libmount.so.1.1.0>, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
0.000144 fstat(3</usr/lib/libmount.so.1.1.0>, {st_mode=S_IFREG|0755, st_size=359008, ...}) = 0
0.000114 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5ae8c45000
0.000114 mmap(NULL, 356960, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3</usr/lib/libmount.so.1.1.0>, 0) = 0x7f5ae8bed000
0.000111 mmap(0x7f5ae8bf7000, 245760, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libmount.so.1.1.0>, 0xa000) = 0x7f5ae8bf7000
0.000123 mmap(0x7f5ae8c33000, 61440, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libmount.so.1.1.0>, 0x46000) = 0x7f5ae8c33000
0.000113 mmap(0x7f5ae8c42000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libmount.so.1.1.0>, 0x55000) = 0x7f5ae8c42000
0.000163 close(3</usr/lib/libmount.so.1.1.0>) = 0
0.000133 openat(AT_FDCWD</home/rawjaw>, "/usr/lib/libc.so.6", O_RDONLY|O_CLOEXEC) = 3</usr/lib/libc.so.6>
0.000137 read(3</usr/lib/libc.so.6>, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0y\2\0\0\0\0\0"..., 832) = 832
0.000110 pread64(3</usr/lib/libc.so.6>, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 840, 64) = 840
0.000109 fstat(3</usr/lib/libc.so.6>, {st_mode=S_IFREG|0755, st_size=2010168, ...}) = 0
0.000110 pread64(3</usr/lib/libc.so.6>, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 840, 64) = 840
0.000117 mmap(NULL, 2034544, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3</usr/lib/libc.so.6>, 0) = 0x7f5ae89fc000
0.000110 mmap(0x7f5ae8a20000, 1511424, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libc.so.6>, 0x24000) = 0x7f5ae8a20000
0.000128 mmap(0x7f5ae8b91000, 319488, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libc.so.6>, 0x195000) = 0x7f5ae8b91000
0.000166 mmap(0x7f5ae8bdf000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libc.so.6>, 0x1e2000) = 0x7f5ae8bdf000
0.000229 mmap(0x7f5ae8be5000, 31600, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f5ae8be5000
0.000195 close(3</usr/lib/libc.so.6>) = 0
0.000159 openat(AT_FDCWD</home/rawjaw>, "/usr/lib/libblkid.so.1", O_RDONLY|O_CLOEXEC) = 3</usr/lib/libblkid.so.1.1.0>
0.000182 read(3</usr/lib/libblkid.so.1.1.0>, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
0.000146 fstat(3</usr/lib/libblkid.so.1.1.0>, {st_mode=S_IFREG|0755, st_size=244608, ...}) = 0
0.000184 mmap(NULL, 242568, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3</usr/lib/libblkid.so.1.1.0>, 0) = 0x7f5ae89c0000
0.000149 mmap(0x7f5ae89c5000, 159744, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libblkid.so.1.1.0>, 0x5000) = 0x7f5ae89c5000
0.000160 mmap(0x7f5ae89ec000, 36864, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libblkid.so.1.1.0>, 0x2c000) = 0x7f5ae89ec000
0.000172 mmap(0x7f5ae89f5000, 28672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libblkid.so.1.1.0>, 0x35000) = 0x7f5ae89f5000
0.000215 close(3</usr/lib/libblkid.so.1.1.0>) = 0
0.000157 openat(AT_FDCWD</home/rawjaw>, "/usr/lib/libsystemd.so.0", O_RDONLY|O_CLOEXEC) = 3</usr/lib/libsystemd.so.0.43.0>
0.000181 read(3</usr/lib/libsystemd.so.0.43.0>, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
0.000144 fstat(3</usr/lib/libsystemd.so.0.43.0>, {st_mode=S_IFREG|0755, st_size=1217976, ...}) = 0
0.000094 mmap(NULL, 1218968, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3</usr/lib/libsystemd.so.0.43.0>, 0) = 0x7f5ae8896000
0.000039 mmap(0x7f5ae88ab000, 811008, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libsystemd.so.0.43.0>, 0x15000) = 0x7f5ae88ab000
0.000042 mmap(0x7f5ae8971000, 278528, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libsystemd.so.0.43.0>, 0xdb000) = 0x7f5ae8971000
0.000039 mmap(0x7f5ae89b5000, 40960, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libsystemd.so.0.43.0>, 0x11f000) = 0x7f5ae89b5000
0.000044 mmap(0x7f5ae89bf000, 2456, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f5ae89bf000
0.000044 close(3</usr/lib/libsystemd.so.0.43.0>) = 0
0.000037 openat(AT_FDCWD</home/rawjaw>, "/usr/lib/libm.so.6", O_RDONLY|O_CLOEXEC) = 3</usr/lib/libm.so.6>
0.000043 read(3</usr/lib/libm.so.6>, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
0.000036 fstat(3</usr/lib/libm.so.6>, {st_mode=S_IFREG|0755, st_size=1165864, ...}) = 0
0.000037 mmap(NULL, 1167688, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3</usr/lib/libm.so.6>, 0) = 0x7f5ae8778000
0.000037 mmap(0x7f5ae8788000, 618496, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libm.so.6>, 0x10000) = 0x7f5ae8788000
0.000046 mmap(0x7f5ae881f000, 479232, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libm.so.6>, 0xa7000) = 0x7f5ae881f000
0.000040 mmap(0x7f5ae8894000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libm.so.6>, 0x11b000) = 0x7f5ae8894000
0.000053 close(3</usr/lib/libm.so.6>) = 0
0.000042 openat(AT_FDCWD</home/rawjaw>, "/usr/lib/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = 3</usr/lib/libgcc_s.so.1>
0.000044 read(3</usr/lib/libgcc_s.so.1>, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
0.000036 fstat(3</usr/lib/libgcc_s.so.1>, {st_mode=S_IFREG|0644, st_size=178416, ...}) = 0
0.000038 mmap(NULL, 180712, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3</usr/lib/libgcc_s.so.1>, 0) = 0x7f5ae874b000
0.000037 mmap(0x7f5ae874f000, 143360, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libgcc_s.so.1>, 0x4000) = 0x7f5ae874f000
0.000040 mmap(0x7f5ae8772000, 16384, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libgcc_s.so.1>, 0x27000) = 0x7f5ae8772000
0.000039 mmap(0x7f5ae8776000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libgcc_s.so.1>, 0x2a000) = 0x7f5ae8776000
0.000052 close(3</usr/lib/libgcc_s.so.1>) = 0
0.000049 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5ae8749000
0.000063 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5ae8747000
0.000041 arch_prctl(ARCH_SET_FS, 0x7f5ae8747c80) = 0
0.000030 set_tid_address(0x7f5ae87482a8) = 13808
0.000029 set_robust_list(0x7f5ae8747f60, 24) = 0
0.000029 rseq(0x7f5ae8747ae0, 0x20, 0, 0x53053053) = 0
0.000087 mprotect(0x7f5ae8bdf000, 16384, PROT_READ) = 0
0.000053 mprotect(0x7f5ae8776000, 4096, PROT_READ) = 0
0.000060 mprotect(0x7f5ae8894000, 4096, PROT_READ) = 0
0.000175 mprotect(0x7f5ae89b5000, 36864, PROT_READ) = 0
0.000097 mprotect(0x7f5ae89f5000, 24576, PROT_READ) = 0
0.000098 mprotect(0x7f5ae8c42000, 8192, PROT_READ) = 0
0.000065 mprotect(0x5586a9e42000, 4096, PROT_READ) = 0
0.000043 mprotect(0x7f5ae8cb9000, 8192, PROT_READ) = 0
0.000060 prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
0.000052 getrandom("\x1b\x23\xca\x6f\xe4\x95\xbf\x6f", 8, GRND_NONBLOCK) = 8
0.000037 munmap(0x7f5ae8c47000, 210419) = 0
0.000070 brk(NULL) = 0x5586bd299000
0.000027 brk(0x5586bd2ba000) = 0x5586bd2ba000
0.000060 openat(AT_FDCWD</home/rawjaw>, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3</usr/lib/locale/locale-archive>
0.000049 fstat(3</usr/lib/locale/locale-archive>, {st_mode=S_IFREG|0644, st_size=4441152, ...}) = 0
0.000038 mmap(NULL, 4441152, PROT_READ, MAP_PRIVATE, 3</usr/lib/locale/locale-archive>, 0) = 0x7f5ae8200000
0.000040 close(3</usr/lib/locale/locale-archive>) = 0
0.000061 getuid() = 0
0.000037 readlink("/dev", 0x7ffcf9f6dc70, 1023) = -1 EINVAL (Invalid argument)
0.000034 readlink("/dev/sdc", 0x7ffcf9f6dc70, 1023) = -1 EINVAL (Invalid argument)
0.000036 newfstatat(AT_FDCWD</home/rawjaw>, "/dev/sdc", {st_mode=S_IFBLK|0600, st_rdev=makedev(0x8, 0x20), ...}, 0) = 0
0.000065 readlink("/mnt", 0x7ffcf9f6dc70, 1023) = -1 EINVAL (Invalid argument)
0.000034 readlink("/mnt/misc", 0x7ffcf9f6dc70, 1023) = -1 EINVAL (Invalid argument)
0.000057 statx(AT_FDCWD</home/rawjaw>, "/usr/bin/mount.ext4", AT_STATX_DONT_SYNC|AT_NO_AUTOMOUNT, STATX_TYPE|STATX_MODE|STATX_INO, 0x7ffcf9f6cf40) = -1 ENOENT (No such file or directory)
0.000052 statx(AT_FDCWD</home/rawjaw>, "/usr/local/bin/mount.ext4", AT_STATX_DONT_SYNC|AT_NO_AUTOMOUNT, STATX_TYPE|STATX_MODE|STATX_INO, 0x7ffcf9f6cf40) = -1 ENOENT (No such file or directory)
0.000042 fsopen("ext4", FSOPEN_CLOEXEC) = 3<anon_inode:[fscontext]>
0.000045 read(3<anon_inode:[fscontext]>, 0x7ffcf9f6c060, 8191) = -1 ENODATA (No data available)
0.000041 uname({sysname="Linux", nodename="ws2", ...}) = 0
0.000038 mount_setattr(-1, NULL, 0, NULL, 0) = -1 EINVAL (Invalid argument)
0.000030 prctl(PR_GET_DUMPABLE) = 1 (SUID_DUMP_USER)
0.000028 newfstatat(AT_FDCWD</home/rawjaw>, "/run/mount/utab", 0x7ffcf9f6e180, AT_SYMLINK_NOFOLLOW) = -1 ENOENT (No such file or directory)
0.000040 mkdir("/run/mount", 0755) = -1 EEXIST (File exists)
0.000033 newfstatat(AT_FDCWD</home/rawjaw>, "/run/mount/utab", 0x7ffcf9f6e060, 0) = -1 ENOENT (No such file or directory)
0.000036 newfstatat(AT_FDCWD</home/rawjaw>, "/run/mount", {st_mode=S_IFDIR|0755, st_size=40, ...}, 0) = 0
0.000039 geteuid() = 0
0.000026 getegid() = 0
0.000026 getuid() = 0
0.000026 getgid() = 0
0.000025 access("/run/mount", R_OK|W_OK) = 0
0.000032 fsconfig(3<anon_inode:[fscontext]>, FSCONFIG_SET_STRING, "source", "/dev/sdc", 0) = 0
0.000043 read(3<anon_inode:[fscontext]>, 0x7ffcf9f6bf70, 8191) = -1 ENODATA (No data available)
0.000034 fsconfig(3<anon_inode:[fscontext]>, FSCONFIG_SET_FLAG, "ro", NULL, 0) = 0
0.000035 read(3<anon_inode:[fscontext]>, 0x7ffcf9f6bed0, 8191) = -1 ENODATA (No data available)
0.000035 fsconfig(3<anon_inode:[fscontext]>, FSCONFIG_CMD_CREATE, NULL, NULL, 0
-------------------------------------------------------- THIS IS WHERE THE DELAY OCCURS --------------------------------------------------------
) = 0
64.774879 read(3<anon_inode:[fscontext]>, 0x7ffcf9f6bf70, 8191) = -1 ENODATA (No data available)
0.000206 fsmount(3<anon_inode:[fscontext]>, FSMOUNT_CLOEXEC, 0) = 4</>
0.000277 read(3<anon_inode:[fscontext]>, 0x7ffcf9f6bf70, 8191) = -1 ENODATA (No data available)
0.000138 statx(4</>, "", AT_STATX_SYNC_AS_STAT|AT_EMPTY_PATH, STATX_MNT_ID, {stx_mask=STATX_TYPE|STATX_MODE|STATX_NLINK|STATX_UID|STATX_GID|STATX_ATIME|STATX_INO|STATX_SIZE|STATX_BLOCKS|STATX_MNT_ID, stx_attributes=STATX_ATTR_MOUNT_ROOT, stx_mode=S_IFDIR|0755, stx_size=4096, ...}) = 0
0.000165 mount_setattr(4</>, "", AT_EMPTY_PATH, {attr_set=MOUNT_ATTR_RDONLY, attr_clr=0, propagation=0 /* MS_??? */, userns_fd=0}, 32) = 0
0.000143 read(3<anon_inode:[fscontext]>, 0x7ffcf9f6bff0, 8191) = -1 ENODATA (No data available)
0.000117 move_mount(4</>, "", AT_FDCWD</home/rawjaw>, "/mnt/misc", MOVE_MOUNT_F_EMPTY_PATH) = 0
0.000266 read(3<anon_inode:[fscontext]>, 0x7ffcf9f6c180, 8191) = -1 ENODATA (No data available)
0.000165 close(3<anon_inode:[fscontext]>) = 0
0.000132 close(4</mnt/misc>) = 0
0.000130 ioctl(2</dev/pts/0>, TCGETS2, {c_iflag=ICRNL|IXON|IUTF8, c_oflag=NL0|CR0|TAB0|BS0|VT0|FF0|OPOST|ONLCR, c_cflag=B38400|CS8|CREAD, c_lflag=ISIG|ICANON|ECHO|ECHOE|ECHOK|IEXTEN|ECHOCTL|ECHOKE, ...}) = 0
0.000181 ioctl(1</dev/pts/0>, TCGETS2, {c_iflag=ICRNL|IXON|IUTF8, c_oflag=NL0|CR0|TAB0|BS0|VT0|FF0|OPOST|ONLCR, c_cflag=B38400|CS8|CREAD, c_lflag=ISIG|ICANON|ECHO|ECHOE|ECHOK|IEXTEN|ECHOCTL|ECHOKE, ...}) = 0
0.000167 newfstatat(AT_FDCWD</home/rawjaw>, "/run/systemd/systemd-units-load", {st_mode=S_IFREG|0444, st_size=0, ...}, 0) = 0
0.000161 newfstatat(AT_FDCWD</home/rawjaw>, "/etc/fstab", {st_mode=S_IFREG|0644, st_size=606, ...}, 0) = 0
0.000261 dup(1</dev/pts/0>) = 3</dev/pts/0>
0.000151 close(3</dev/pts/0>) = 0
0.000123 dup(2</dev/pts/0>) = 3</dev/pts/0>
0.000186 close(3</dev/pts/0>) = 0
0.000213 exit_group(0) = ?
0.000707 +++ exited with 0 +++My fstab contains nothing regarding this disk (it does not have an e2label):
[root@ws2 rawjaw]# cat /etc/fstab
tmpfs /tmp tmpfs nodev,nosuid 0 0
LABEL=efisystem /boot vfat rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=ascii,shortname=mixed,utf8,errors=remount-ro 0 2
/swapfile none swap defaults 0 0
LABEL=ssd1_root / ext4 defaults,noatime 0 1
LABEL=ssd2 /home ext4 defaults,noatime 0 1
LABEL=hdd1 /home_hdd ext4 defaults,noatime 0 1I will try with the Arch ISO boot, brb...
Offline
#9 2026-04-24 17:14:07
- Shalrath
- Member
- Registered: 2020-05-26
- Posts: 16
Re: HDD takes a 30s sleep when mounting
Same delay is present when booted from archlinux-2026.04.01-x86_64.iso
cryptearth wrote:
unless it's writing cached data unmounting taking nearly 20 seconds doesn't right
Yeah... I just figured out the disk needs 1-2 minutes to "warm up" before it works normally. Not only mounting is slow but also a simple 'ls' or creating an empty file. Everything seems to "hang" for a while before finishing. I umounted the disk immediately so it was still slow while I did it. But about 2 minutes after powering it up, the disk works perfectly and is as fast as you would expect.
Offline
#10 2026-04-24 18:32:10
- seth
- Member
- From: Won't reply 2 private help req
- Registered: 2012-09-03
- Posts: 75,177
Re: HDD takes a 30s sleep when mounting
https://wiki.archlinux.org/title/Hdparm … king_it_up
https://wiki.archlinux.org/title/Hdparm … figuration
https://www.google.com/search?q=WDC+WD2 … low+wakeup
https://superuser.com/questions/529436/ … to-disable
https://man.archlinux.org/man/hdparm.8#J
@dimich, I guess you figured that but while relative timestamps make it easy to spot extremely slow single functions (as actually is the case here) they're not that great when eg. 50 250ms calls are buried in 100 fast calls or so.
The absolute timestamps allow you to isolate the block where things slow down which I usually suggest them when having no idea what to expect at all.
Online
#11 2026-04-29 01:21:53
- Shalrath
- Member
- Registered: 2020-05-26
- Posts: 16
Re: HDD takes a 30s sleep when mounting
I don't understand why I would want to query the drive without spinning it up.
[root@ws2 rawjaw]# hdparm -B /dev/sdc
/dev/sdc:
APM_level = not supportedThe disk is never spinning down, I have it on my desk so I can hear it.
seth wrote:
[root@ws2 rawjaw]# hdparm -J /dev/sdc
/dev/sdc:
SG_IO: bad/missing sense data, sb[]: 70 00 05 00 00 00 00 0a 00 00 00 00 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
SG_IO: bad/missing sense data, sb[]: 70 00 05 00 00 00 00 0a 00 00 00 00 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
SG_IO: bad/missing sense data, sb[]: 70 00 05 00 00 00 00 0a 00 00 00 00 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
SG_IO: bad/missing sense data, sb[]: 70 00 05 00 00 00 00 0a 00 00 00 00 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wdidle3 = 8.5 secs
[root@ws2 rawjaw]# idle3ctl -g /dev/sdc
HDIO_DRIVE_CMD(identify) failed: Invalid argument
[root@ws2 rawjaw]# idle3ctl -g100 /dev/sdc
HDIO_DRIVE_CMD(identify) failed: Invalid argument
[root@ws2 rawjaw]# idle3ctl -g103 /dev/sdc
HDIO_DRIVE_CMD(identify) failed: Invalid argument
[root@ws2 rawjaw]# idle3ctl -g105 /dev/sdc
HDIO_DRIVE_CMD(identify) failed: Invalid argument
[root@ws2 rawjaw]# idle3ctl -d /dev/sdc
HDIO_DRIVE_CMD(identify) failed: Invalid argumentidle3ctl does not seem to support either my disk or the USB-constroller as they state in the doc that support of USB controllers is uncertain.
[root@ws2 rawjaw]# hdparm -J 30 /dev/sdc
/dev/sdc:
Use of -J is EXTREMELY DANGEROUS.
This implementation is not as thorough as the official WDIDLE3.EXE. Use at your own risk!
Please also supply the --please-destroy-my-drive flag if you really want this.
Program aborted.Alright, this is where I chicken out...
I have another WD green disk and I remember that I did the idle timer tweak on it because the default setting was giving it an excess amount of load cycles. I thought I did it on this one too, maybe I did and the readings of hdparm are wrong because of the USB controller. However, the idle3 timer is just parking the heads, it is not causing a very long lag. I never noticed a difference with my other drive when I changed the idle3 timer, except for the load cycle counter increasing slower.
Reading through some of the results, mostly forum threads, makes me believe that it's a firmware bug and WD doesn't supply firmware updates. Seems like there is no possible fix for this problem, or is there?
Thanks to everyone who replied to my question.
Last edited by Shalrath (2026-04-29 01:23:35)
Offline
#12 2026-04-29 05:38:22
- seth
- Member
- From: Won't reply 2 private help req
- Registered: 2012-09-03
- Posts: 75,177
Re: HDD takes a 30s sleep when mounting
I don't understand why I would want to query the drive without spinning it up.
To assess the state of the disk when slow and ok w/o impacting it.
maybe I did and the readings of hdparm are wrong because of the USB controller
drive behaves the same when connected to an internal SATA directly
I'd rather not do any of this through a USB controller - certainly not changing settings!
I have another WD green disk and I remember that I did the idle timer tweak on it
Did you perform the idle tweak on the other drive (same model/family?) using hdparm or the WD tool? (If you want to and can use the latter you certainly should)
Seems like there is no possible fix for this problem, or is there?
it causes the boot process to hang for about 30s before continuing
Don't auto-mount the drive via fstab, in doubt use "noauto,x-systemd.automount", https://wiki.archlinux.org/title/Fstab# … th_systemd
Online
Pages: 1