0

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:

  1. The HDD is "bad" and has occasional errors and will fail soon.
  2. There is a problem with the USB to SATA connector.
  3. 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.

3
  • 1
    Previous models have not been able to deliver WRT conventions about power via USB. For the earlier ones this was pretty explicit; based on my experience w/ the Pi 4 I doubt very much it is an exception to this (I've had problems running a USB 3 SSD and a USB 2 wifi adapter at the same time). I think my opinion here is common, most other long term users would agree to some extent. Basically: Don't rely on it to power much beyond the trivial. Anything else needs it's own supply, eg. via a powered hub.
    – goldilocks
    Apr 11, 2021 at 14:07
  • 3. would not surprise me. While spinning up a drive needs power, so does changing bits. Usually to be on the safe side, add up all the currents and multiply by at least two.
    – Abel
    Apr 11, 2021 at 16:35
  • 1
    "well below the Maximum total USB peripheral current draw" -> To clarify a bit, that doesn't say you can expect to do that with impunity. It says that's the most you are going to be able to get no matter what. It could easily be less, eg., if the power supply to the board is insufficient and/or the SoC is working hard.
    – goldilocks
    Apr 11, 2021 at 17:49

0

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Browse other questions tagged or ask your own question.