I have a Raspberry Pi 4B with 4 GB of RAM with the official power supply. Using an old HDD from a laptop I want to build a NAS. The HDD is a Hitachi Travelstar 5K750 750GB and connected with a SATA to USB connector attached to a USB 3 port.
However sometimes, especially when I write a lot of stuff, the HDD disconnects. The HDD disappears as a block device and usually appears a few seconds later again.
I did run a few tests on the HDD (using a Linux laptop) but I am not sure how to interpret the results. Superficially the HDD appears to be fine, however there where multiple recent (?) errors.
/etc/fstab
:
proc /proc proc defaults 0 0
PARTUUID=12f2b688-01 /boot vfat defaults 0 2
PARTUUID=12f2b688-02 / ext4 defaults,noatime 0 1
UUID=1c56145c-9e20-4c97-9431-4bbc1c09c638 /srv/data ext4 defaults,nofail 0 2
smartctl 7.2 2020-12-30 r5155 [x86_64-linux-5.11.12-arch1-1] (local build)
Copyright (C) 2002-20, Bruce Allen, Christian Franke, www.smartmontools.org
=== START OF READ SMART DATA SECTION ===
SMART Status not supported: Incomplete response, ATA output registers missing
SMART overall-health self-assessment test result: PASSED
Warning: This result is based on an Attribute check.
smartctl 7.2 2020-12-30 r5155 [x86_64-linux-5.11.12-arch1-1] (local build)
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 Short offline Completed without error 00% 6258 -
# 2 Short offline Completed without error 00% 1540 -
smartctl 7.2 2020-12-30 r5155 [x86_64-linux-5.11.12-arch1-1] (local build)
Copyright (C) 2002-20, Bruce Allen, Christian Franke, www.smartmontools.org
=== START OF READ SMART DATA SECTION ===
SMART Error Log Version: 1
ATA Error Count: 6 (device log contains only the most recent five errors)
CR = Command Register [HEX]
FR = Features Register [HEX]
SC = Sector Count Register [HEX]
SN = Sector Number Register [HEX]
CL = Cylinder Low Register [HEX]
CH = Cylinder High Register [HEX]
DH = Device/Head Register [HEX]
DC = Device Command Register [HEX]
ER = Error register [HEX]
ST = Status register [HEX]
Powered_Up_Time is measured from power on, and printed as
DDd+hh:mm:SS.sss where DD=days, hh=hours, mm=minutes,
SS=sec, and sss=millisec. It "wraps" after 49.710 days.
Error 6 occurred at disk power-on lifetime: 6257 hours (260 days + 17 hours)
When the command that caused the error occurred, the device was active or idle.
After command completion occurred, registers were:
ER ST SC SN CL CH DH
-- -- -- -- -- -- --
84 51 18 98 09 01 08 Error: ICRC, ABRT at LBA = 0x08010998 = 134285720
Commands leading to the command that caused the error were:
CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name
-- -- -- -- -- -- -- -- ---------------- --------------------
61 18 78 98 09 01 40 00 00:06:51.208 WRITE FPDMA QUEUED
61 08 70 00 09 01 40 00 00:06:51.208 WRITE FPDMA QUEUED
61 08 68 00 08 00 40 00 00:06:51.208 WRITE FPDMA QUEUED
61 10 60 28 09 c1 40 00 00:06:51.208 WRITE FPDMA QUEUED
61 10 58 10 09 c1 40 00 00:06:51.208 WRITE FPDMA QUEUED
Error 5 occurred at disk power-on lifetime: 6257 hours (260 days + 17 hours)
When the command that caused the error occurred, the device was active or idle.
After command completion occurred, registers were:
ER ST SC SN CL CH DH
-- -- -- -- -- -- --
84 51 08 a8 09 01 08 Error: ICRC, ABRT at LBA = 0x080109a8 = 134285736
Commands leading to the command that caused the error were:
CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name
-- -- -- -- -- -- -- -- ---------------- --------------------
61 18 78 98 09 01 40 00 00:06:51.208 WRITE FPDMA QUEUED
61 08 70 00 09 01 40 00 00:06:51.208 WRITE FPDMA QUEUED
61 08 68 00 08 00 40 00 00:06:51.208 WRITE FPDMA QUEUED
61 10 60 28 09 c1 40 00 00:06:51.208 WRITE FPDMA QUEUED
61 10 58 10 09 c1 40 00 00:06:51.208 WRITE FPDMA QUEUED
Error 4 occurred at disk power-on lifetime: 6257 hours (260 days + 17 hours)
When the command that caused the error occurred, the device was active or idle.
After command completion occurred, registers were:
ER ST SC SN CL CH DH
-- -- -- -- -- -- --
84 51 10 20 44 84 0b Error: ICRC, ABRT at LBA = 0x0b844420 = 193217568
Commands leading to the command that caused the error were:
CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name
-- -- -- -- -- -- -- -- ---------------- --------------------
61 40 00 f0 43 84 40 00 00:20:06.668 WRITE FPDMA QUEUED
61 20 00 90 cd 93 40 00 00:20:06.668 WRITE FPDMA QUEUED
ea 00 00 00 00 00 00 00 00:20:06.655 FLUSH CACHE EXT
61 08 00 e8 43 84 40 00 00:20:06.655 WRITE FPDMA QUEUED
ea 00 00 00 00 00 00 00 00:20:06.601 FLUSH CACHE EXT
Error 3 occurred at disk power-on lifetime: 6257 hours (260 days + 17 hours)
When the command that caused the error occurred, the device was active or idle.
After command completion occurred, registers were:
ER ST SC SN CL CH DH
-- -- -- -- -- -- --
84 51 d0 80 10 1c 01 Error: ICRC, ABRT at LBA = 0x011c1080 = 18616448
Commands leading to the command that caused the error were:
CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name
-- -- -- -- -- -- -- -- ---------------- --------------------
60 08 08 18 19 41 40 00 00:05:53.081 READ FPDMA QUEUED
60 08 18 50 0f 41 40 00 00:05:53.077 READ FPDMA QUEUED
60 08 30 80 15 c1 40 00 00:05:53.054 READ FPDMA QUEUED
60 08 20 20 11 81 40 00 00:05:53.050 READ FPDMA QUEUED
60 08 10 f0 12 81 40 00 00:05:53.048 READ FPDMA QUEUED
Error 2 occurred at disk power-on lifetime: 6257 hours (260 days + 17 hours)
When the command that caused the error occurred, the device was active or idle.
After command completion occurred, registers were:
ER ST SC SN CL CH DH
-- -- -- -- -- -- --
84 51 01 07 08 84 0b Error: ICRC, ABRT at LBA = 0x0b840807 = 193202183
Commands leading to the command that caused the error were:
CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name
-- -- -- -- -- -- -- -- ---------------- --------------------
61 08 18 00 08 84 40 00 00:00:12.642 WRITE FPDMA QUEUED
61 c0 10 08 08 00 40 00 00:00:12.642 WRITE FPDMA QUEUED
60 10 08 f0 65 54 40 00 00:00:12.637 READ FPDMA QUEUED
60 e8 00 00 64 54 40 00 00:00:12.637 READ FPDMA QUEUED
60 20 00 00 08 84 40 00 00:00:12.616 READ FPDMA QUEUED
Lengthy log from journalctl
when the disk disconnected (I already remove some repeated lines):
Apr 11 14:29:43 raspi-nas kernel: xhci_hcd 0000:01:00.0: ERROR Transfer event for unknown stream ring slot 2 ep 7
Apr 11 14:29:43 raspi-nas kernel: xhci_hcd 0000:01:00.0: @00000004413a7010 00000000 00000000 05000000 02088000
Apr 11 14:30:01 raspi-nas CRON[1621]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 11 14:30:01 raspi-nas CRON[1622]: (root) CMD ( /opt/monitor-raspi.sh >> /var/log/monitor-raspi)
Apr 11 14:30:11 raspi-nas sshd[1640]: Accepted publickey for pi from 192.168.178.34 port 58668 ssh2: RSA SHA256:8AzhKhEyV9UBimjDTaO8JydVDnkr/IrfYsF5vQ15zdg
Apr 11 14:30:11 raspi-nas sshd[1642]: Received disconnect from 192.168.178.34 port 58668:11: disconnected by user
Apr 11 14:30:11 raspi-nas sshd[1642]: Disconnected from user pi 192.168.178.34 port 58668
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#28 uas_eh_abort_handler 0 uas-tag 13 inflight: CMD OUT
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#28 CDB: opcode=0x2a 2a 00 01 e6 08 00 00 04 00 00
Apr 11 14:30:14 raspi-nas kernel: xhci_hcd 0000:01:00.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#27 uas_eh_abort_handler 0 uas-tag 11 inflight: CMD OUT
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#27 CDB: opcode=0x2a 2a 00 01 e6 00 00 00 04 00 00
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#26 uas_eh_abort_handler 0 uas-tag 10 inflight: CMD OUT
Apr 11 14:30:14 raspi-nas kernel: xhci_hcd 0000:01:00.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#8 uas_eh_abort_handler 0 uas-tag 22 inflight: CMD OUT
Apr 11 14:30:14 raspi-nas kernel: xhci_hcd 0000:01:00.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#8 CDB: opcode=0x2a 2a 00 01 e5 c0 00 00 04 00 00
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#7 uas_eh_abort_handler 0 uas-tag 18 inflight: CMD OUT
Apr 11 14:30:14 raspi-nas kernel: xhci_hcd 0000:01:00.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#4 CDB: opcode=0x2a 2a 00 01 e5 b4 00 00 04 00 00
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#3 uas_eh_abort_handler 0 uas-tag 17 inflight: CMD OUT
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#3 CDB: opcode=0x2a 2a 00 01 e5 ac 00 00 04 00 00
Apr 11 14:30:14 raspi-nas kernel: xhci_hcd 0000:01:00.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#2 uas_eh_abort_handler 0 uas-tag 16 inflight: CMD OUT
Apr 11 14:30:14 raspi-nas kernel: xhci_hcd 0000:01:00.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#2 CDB: opcode=0x2a 2a 00 01 e5 a8 00 00 04 00 00
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#1 uas_eh_abort_handler 0 uas-tag 15 inflight: CMD OUT
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#1 CDB: opcode=0x2a 2a 00 01 e5 9c 00 00 04 00 00
Apr 11 14:30:14 raspi-nas kernel: xhci_hcd 0000:01:00.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#0 uas_eh_abort_handler 0 uas-tag 14 inflight: CMD OUT
Apr 11 14:30:14 raspi-nas kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x2a 2a 00 01 e5 98 00 00 04 00 00
Apr 11 14:30:14 raspi-nas kernel: xhci_hcd 0000:01:00.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Apr 11 14:30:14 raspi-nas kernel: xhci_hcd 0000:01:00.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Apr 11 14:30:14 raspi-nas kernel: scsi host0: uas_eh_device_reset_handler start
Apr 11 14:30:14 raspi-nas kernel: usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
Apr 11 14:30:15 raspi-nas kernel: scsi host0: uas_eh_device_reset_handler success
Apr 11 14:30:29 raspi-nas sshd[1675]: Accepted publickey for pi from 192.168.178.34 port 58670 ssh2: RSA SHA256:8AzhKhEyV9UBimjDTaO8JydVDnkr/IrfYsF5vQ15zdg
Apr 11 14:30:29 raspi-nas sshd[1677]: Received disconnect from 192.168.178.34 port 58670:11: disconnected by user
Apr 11 14:30:29 raspi-nas sshd[1677]: Disconnected from user pi 192.168.178.34 port 58670
Apr 11 14:30:45 raspi-nas kernel: sd 0:0:0:0: [sda] tag#26 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD OUT
Apr 11 14:30:45 raspi-nas kernel: sd 0:0:0:0: [sda] tag#26 CDB: opcode=0x2a 2a 00 01 e6 10 00 00 04 00 00
Apr 11 14:30:45 raspi-nas kernel: sd 0:0:0:0: [sda] tag#25 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD OUT
Apr 11 14:30:45 raspi-nas kernel: sd 0:0:0:0: [sda] tag#25 CDB: opcode=0x2a 2a 00 01 e6 0c 00 00 04 00 00
Apr 11 14:30:45 raspi-nas kernel: sd 0:0:0:0: [sda] tag#1 uas_eh_abort_handler 0 uas-tag 6 inflight: CMD OUT
Apr 11 14:30:45 raspi-nas kernel: sd 0:0:0:0: [sda] tag#1 CDB: opcode=0x2a 2a 00 01 e6 18 00 00 04 00 00
Apr 11 14:30:45 raspi-nas kernel: sd 0:0:0:0: [sda] tag#0 uas_eh_abort_handler 0 uas-tag 5 inflight: CMD OUT
Apr 11 14:30:45 raspi-nas kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x2a 2a 00 01 e6 14 00 00 04 00 00
Apr 11 14:31:01 raspi-nas CRON[1720]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 11 14:31:01 raspi-nas CRON[1721]: (root) CMD ( /opt/monitor-raspi.sh >> /var/log/monitor-raspi)
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#27 uas_eh_abort_handler 0 uas-tag 4 inflight: CMD IN
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#27 CDB: opcode=0x85 85 08 0e 00 d0 00 01 00 00 00 4f 00 c2 00 b0 00
Apr 11 14:31:16 raspi-nas kernel: scsi host0: uas_eh_device_reset_handler start
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#24 uas_zap_pending 0 uas-tag 1 inflight: CMD
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#24 CDB: opcode=0x2a 2a 00 01 e5 98 00 00 04 00 00
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#2 uas_zap_pending 0 uas-tag 7 inflight: CMD
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#2 CDB: opcode=0x2a 2a 00 01 e5 f0 00 00 04 00 00
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#3 uas_zap_pending 0 uas-tag 8 inflight: CMD
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#19 CDB: opcode=0x2a 2a 00 01 e5 bc 00 00 04 00 00
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#20 uas_zap_pending 0 uas-tag 25 inflight: CMD
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#20 CDB: opcode=0x2a 2a 00 01 e5 b8 00 00 04 00 00
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#21 uas_zap_pending 0 uas-tag 26 inflight: CMD
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#21 CDB: opcode=0x2a 2a 00 01 e5 b4 00 00 04 00 00
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#22 uas_zap_pending 0 uas-tag 27 inflight: CMD
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#22 CDB: opcode=0x2a 2a 00 01 e5 ac 00 00 04 00 00
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#23 uas_zap_pending 0 uas-tag 28 inflight: CMD
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#23 CDB: opcode=0x2a 2a 00 01 e5 a8 00 00 04 00 00
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#28 uas_zap_pending 0 uas-tag 29 inflight: CMD
Apr 11 14:31:16 raspi-nas kernel: sd 0:0:0:0: [sda] tag#28 CDB: opcode=0x2a 2a 00 01 e5 9c 00 00 04 00 00
Apr 11 14:31:21 raspi-nas kernel: usb 2-2: Disable of device-initiated U1 failed.
Apr 11 14:31:26 raspi-nas kernel: usb 2-2: Disable of device-initiated U2 failed.
Apr 11 14:31:26 raspi-nas kernel: usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
Apr 11 14:31:31 raspi-nas kernel: usb 2-2: device descriptor read/8, error -110
Apr 11 14:31:32 raspi-nas kernel: usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
Apr 11 14:31:37 raspi-nas kernel: usb 2-2: device descriptor read/8, error -110
Apr 11 14:31:37 raspi-nas kernel: usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
Apr 11 14:31:42 raspi-nas kernel: usb 2-2: device descriptor read/8, error -110
Apr 11 14:31:43 raspi-nas kernel: usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
Apr 11 14:31:43 raspi-nas kernel: scsi host0: uas_eh_device_reset_handler FAILED err -19
Apr 11 14:31:43 raspi-nas kernel: sd 0:0:0:0: Device offlined - not ready after error recovery
Apr 11 14:31:43 raspi-nas kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x06 cmd_age=87s
Apr 11 14:31:43 raspi-nas kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x2a 2a 00 01 e6 14 00 00 04 00 00
Apr 11 14:31:43 raspi-nas kernel: blk_update_request: I/O error, dev sda, sector 31855616 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 0
Apr 11 14:31:43 raspi-nas kernel: sd 0:0:0:0: rejecting I/O to offline device
Apr 11 14:31:43 raspi-nas kernel: blk_update_request: I/O error, dev sda, sector 31857664 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 0
Apr 11 14:31:43 raspi-nas kernel: blk_update_request: I/O error, dev sda, sector 31858688 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 0
Apr 11 14:31:43 raspi-nas kernel: blk_update_request: I/O error, dev sda, sector 31859712 op 0x1:(WRITE) flags 0x0 phys_seg 128 prio class 0
Apr 11 14:31:43 raspi-nas kernel: blk_update_request: I/O error, dev sda, sector 730073928 op 0x1:(WRITE) flags 0x800 phys_seg 7 prio class 0
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on dev sda1, logical block 91258985, lost sync page write
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs error (device sda1): ext4_check_bdev_write_error:216: comm kworker/u8:0: Error while async write back metadata
Apr 11 14:31:43 raspi-nas kernel: Aborting journal on device sda1-8.
Apr 11 14:31:43 raspi-nas kernel: sd 0:0:0:0: [sda] tag#1 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x06 cmd_age=87s
Apr 11 14:31:43 raspi-nas kernel: sd 0:0:0:0: [sda] tag#1 CDB: opcode=0x2a 2a 00 01 e6 18 00 00 04 00 00
Apr 11 14:31:43 raspi-nas kernel: blk_update_request: I/O error, dev sda, sector 31856640 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 0
Apr 11 14:31:43 raspi-nas kernel: sd 0:0:0:0: [sda] tag#25 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x06 cmd_age=87s
Apr 11 14:31:43 raspi-nas kernel: sd 0:0:0:0: [sda] tag#25 CDB: opcode=0x2a 2a 00 01 e6 0c 00 00 04 00 00
Apr 11 14:31:43 raspi-nas kernel: blk_update_request: I/O error, dev sda, sector 31853568 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 0
Apr 11 14:31:43 raspi-nas kernel: sd 0:0:0:0: [sda] tag#26 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x06 cmd_age=87s
Apr 11 14:31:43 raspi-nas kernel: sd 0:0:0:0: [sda] tag#26 CDB: opcode=0x2a 2a 00 01 e6 10 00 00 04 00 00
Apr 11 14:31:43 raspi-nas kernel: blk_update_request: I/O error, dev sda, sector 31854592 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 0
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs warning (device sda1): ext4_end_bio:349: I/O error 10 writing to inode 15 starting block 3982592)
Apr 11 14:31:43 raspi-nas kernel: blk_update_request: I/O error, dev sda, sector 31824896 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 0
Apr 11 14:31:43 raspi-nas kernel: blk_update_request: I/O error, dev sda, sector 31823872 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 0
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs warning (device sda1): ext4_end_bio:349: I/O error 10 writing to inode 15 starting block 3979520)
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs warning (device sda1): ext4_end_bio:349: I/O error 10 writing to inode 15 starting block 3981568)
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on dev sda1, logical block 0, lost sync page write
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs (sda1): I/O error while writing superblock
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs error (device sda1): ext4_journal_check_start:83: Detected aborted journal
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs error (device sda1): ext4_journal_check_start:83: Detected aborted journal
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on dev sda1, logical block 91258880, lost sync page write
Apr 11 14:31:43 raspi-nas kernel: JBD2: Error -5 detected when updating journal superblock for sda1-8.
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on dev sda1, logical block 0, lost sync page write
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs (sda1): I/O error while writing superblock
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs (sda1): Delayed block allocation failed for inode 15 at logical offset 17408 with max blocks 2048 with error 30
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs (sda1): This should not happen!! Data will be lost
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs error (device sda1) in ext4_writepages:2814: Journal has aborted
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on dev sda1, logical block 0, lost sync page write
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs (sda1): I/O error while writing superblock
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs (sda1): Remounting filesystem read-only
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs (sda1): Remounting filesystem read-only
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs (sda1): failed to convert unwritten extents to written extents -- potential data loss! (inode 15, error -30)
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on device sda1, logical block 3981312
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on device sda1, logical block 3981313
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on device sda1, logical block 3981314
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on device sda1, logical block 3981315
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on device sda1, logical block 3981316
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on device sda1, logical block 3981317
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on device sda1, logical block 3981318
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on device sda1, logical block 3981319
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on device sda1, logical block 3981320
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on device sda1, logical block 3981321
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs (sda1): failed to convert unwritten extents to written extents -- potential data loss! (inode 15, error -30)
Apr 11 14:31:43 raspi-nas CRON[1621]: pam_unix(cron:session): session closed for user root
Apr 11 14:31:43 raspi-nas CRON[1720]: pam_unix(cron:session): session closed for user root
Apr 11 14:31:43 raspi-nas kernel: EXT4-fs (sda1): failed to convert unwritten extents to written extents -- potential data loss! (inode 15, error -30)
Apr 11 14:31:43 raspi-nas kernel: usb 2-2: USB disconnect, device number 2
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on dev sda1, logical block 1129, lost async page write
Apr 11 14:31:43 raspi-nas kernel: Buffer I/O error on dev sda1, logical block 9337, lost async page write
Apr 11 14:31:43 raspi-nas kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache
Apr 11 14:31:43 raspi-nas systemd[1]: Unmounting /srv/data...
Apr 11 14:31:43 raspi-nas umount[1782]: umount: /srv/data: target is busy.
Apr 11 14:31:43 raspi-nas systemd[1]: srv-data.mount: Mount process exited, code=exited, status=32/n/a
Apr 11 14:31:43 raspi-nas systemd[1]: Failed unmounting /srv/data.
Apr 11 14:31:43 raspi-nas systemd[1]: srv-data.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-1c56145c\x2d9e20\x2d4c97\x2d9431\x2d4bbc1c09c638.device. Stopping, too.
Apr 11 14:31:43 raspi-nas systemd[1]: Unmounting /srv/data...Apr 11 14:31:43 raspi-nas systemd[1]: Unmounting /srv/data...
Apr 11 14:31:43 raspi-nas umount[1797]: umount: /srv/data: target is busy.
Apr 11 14:31:43 raspi-nas systemd[1]: srv-data.mount: Mount process exited, code=exited, status=32/n/a
Apr 11 14:31:43 raspi-nas systemd[1]: Failed unmounting /srv/data.
Apr 11 14:31:43 raspi-nas systemd[1]: srv-data.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-1c56145c\x2d9e20\x2d4c97\x2d9431\x2d4bbc1c09c638.device. Stopping, too.
Apr 11 14:31:43 raspi-nas systemd[1]: Unmounting /srv/data...
Apr 11 14:31:43 raspi-nas umount[1798]: umount: /srv/data: target is busy.
Apr 11 14:31:43 raspi-nas systemd[1]: srv-data.mount: Mount process exited, code=exited, status=32/n/a
Apr 11 14:31:43 raspi-nas systemd[1]: Failed unmounting /srv/data.
Apr 11 14:31:43 raspi-nas systemd[1]: srv-data.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-1c56145c\x2d9e20\x2d4c97\x2d9431\x2d4bbc1c09c638.device, but not stopping since we tried this too often recently.
Apr 11 14:31:43 raspi-nas systemd[1]: systemd-fsck@dev-disk-by\x2duuid-1c56145c\x2d9e20\x2d4c97\x2d9431\x2d4bbc1c09c638.service: Succeeded.
Apr 11 14:31:43 raspi-nas systemd[1]: Stopped File System Check on /dev/disk/by-uuid/1c56145c-9e20-4c97-9431-4bbc1c09c638.
Apr 11 14:31:43 raspi-nas kernel: sd 0:0:0:0: [sda] Synchronize Cache(10) failed: Result: hostbyte=0x07 driverbyte=0x00
Apr 11 14:31:44 raspi-nas kernel: usb 2-2: new SuperSpeed Gen 1 USB device number 3 using xhci_hcd
Apr 11 14:31:49 raspi-nas kernel: usb 2-2: device descriptor read/8, error -110
Apr 11 14:31:49 raspi-nas kernel: usb 2-2: new SuperSpeed Gen 1 USB device number 3 using xhci_hcd
Apr 11 14:31:50 raspi-nas kernel: usb 2-2: new SuperSpeed Gen 1 USB device number 4 using xhci_hcd
Apr 11 14:31:55 raspi-nas kernel: usb 2-2: device descriptor read/8, error -110
Apr 11 14:31:55 raspi-nas kernel: usb 2-2: new SuperSpeed Gen 1 USB device number 4 using xhci_hcd
Apr 11 14:31:55 raspi-nas kernel: usb usb2-port2: attempt power cycle
Apr 11 14:32:00 raspi-nas kernel: usb usb2-port2: Cannot enable. Maybe the USB cable is bad?
Apr 11 14:32:01 raspi-nas CRON[1800]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 11 14:32:01 raspi-nas CRON[1801]: (root) CMD ( /opt/monitor-raspi.sh >> /var/log/monitor-raspi)
Apr 11 14:32:01 raspi-nas CRON[1800]: pam_unix(cron:session): session closed for user root
Apr 11 14:32:04 raspi-nas kernel: usb usb2-port2: Cannot enable. Maybe the USB cable is bad?
Apr 11 14:32:04 raspi-nas kernel: usb usb2-port2: unable to enumerate USB device
Apr 11 14:32:04 raspi-nas kernel: usb 1-1: reset high-speed USB device number 2 using xhci_hcd
Apr 11 14:32:09 raspi-nas kernel: usb 1-1: device descriptor read/64, error -110
Apr 11 14:32:20 raspi-nas sshd[1815]: Accepted publickey for pi from 192.168.178.34 port 58686 ssh2: RSA SHA256:8AzhKhEyV9UBimjDTaO8JydVDnkr/IrfYsF5vQ15zdg
Apr 11 14:32:20 raspi-nas sshd[1817]: Received disconnect from 192.168.178.34 port 58686:11: disconnected by user
Apr 11 14:32:20 raspi-nas sshd[1817]: Disconnected from user pi 192.168.178.34 port 58686
Apr 11 14:32:25 raspi-nas kernel: usb 1-1: device descriptor read/64, error -110
Apr 11 14:32:25 raspi-nas kernel: usb 1-1: reset high-speed USB device number 2 using xhci_hcd
Apr 11 14:32:30 raspi-nas kernel: usb 1-1: device descriptor read/64, error -110
Apr 11 14:32:46 raspi-nas kernel: usb 1-1: device descriptor read/64, error -110
Apr 11 14:32:46 raspi-nas kernel: usb 2-2: new SuperSpeed Gen 1 USB device number 7 using xhci_hcd
Apr 11 14:32:51 raspi-nas kernel: usb 2-2: device descriptor read/8, error -110
Apr 11 14:32:51 raspi-nas kernel: usb 2-2: new SuperSpeed Gen 1 USB device number 7 using xhci_hcd
Apr 11 14:32:57 raspi-nas kernel: usb 2-2: device descriptor read/8, error -110
Apr 11 14:32:57 raspi-nas kernel: usb 1-1: reset high-speed USB device number 2 using xhci_hcd
Apr 11 14:33:01 raspi-nas CRON[1840]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 11 14:33:01 raspi-nas CRON[1841]: (root) CMD ( /opt/monitor-raspi.sh >> /var/log/monitor-raspi)
Apr 11 14:33:01 raspi-nas CRON[1840]: pam_unix(cron:session): session closed for user root
Apr 11 14:33:02 raspi-nas kernel: usb 1-1: device descriptor read/8, error -110
Apr 11 14:33:08 raspi-nas kernel: usb 1-1: device descriptor read/8, error -110
Apr 11 14:33:08 raspi-nas kernel: usb 1-1: reset high-speed USB device number 2 using xhci_hcd
Apr 11 14:33:13 raspi-nas kernel: usb 1-1: device descriptor read/8, error -110
Apr 11 14:33:18 raspi-nas kernel: usb 1-1: device descriptor read/8, error -110
Apr 11 14:33:19 raspi-nas kernel: usb 1-1: USB disconnect, device number 2
Apr 11 14:33:19 raspi-nas kernel: usb 2-2: new SuperSpeed Gen 1 USB device number 8 using xhci_hcd
Apr 11 14:33:24 raspi-nas kernel: usb 2-2: device descriptor read/8, error -110
Apr 11 14:33:24 raspi-nas kernel: usb 2-2: new SuperSpeed Gen 1 USB device number 8 using xhci_hcd
Apr 11 14:33:24 raspi-nas kernel: usb usb2-port2: attempt power cycle
Apr 11 14:33:24 raspi-nas kernel: usb 1-1: new high-speed USB device number 3 using xhci_hcd
Apr 11 14:33:30 raspi-nas kernel: usb 1-1: device descriptor read/64, error -110
My theories to the source of the problem:
- The HDD is "bad" and has occasional errors and will fail soon.
- There is a problem with the USB to SATA connector.
- The power supply is insufficient. This would surprise me as the test linked above reports the power consumption under load as 2.4 Watts, in addition I would expect the disk to consume most power during startup.
EDIT: The hard drive label states the power requirements as "5V 700mA DC" which is well below the Maximum total USB peripheral current draw.