Disk IDs change after intermittent unmount/remounts

#1

Hello!

I have set up my raspberry pi/sata hat - and everything is going great!

I have my clients connected to my nas and I sleep like a baby.

However, in the morning when I check, my clients have some errors (it looks like they are no longer connected to the nas… strange)

So I check to see what has happened in the “journalctl” and it seems pretty odd… but before I dive in, let me explain my configuration

SBC: Raspberry Pi 4 (4GB)
Hat: Quad Sata hat
NAS Storage: 4x 2TB MX200 plugged into hat
OS Storage: 1x 1tb Kingston storage

OS: Debian 11
Kernel: 5.15.79-v8+
I have installed OMV6 onto the OS (not OMV OS)
I am using OMV “mergerfs” plugin to “merge” my 4x storage drives into one mounted drive (like raid 0), which is exposed over SMB/CIFS/NFS

The 4 NAS drives are the following: (output from: “blkid”)

/dev/sdb1: UUID="2b1fa6c8-6052-4d14-af8a-5f8ae206e9ee" BLOCK_SIZE="4096" TYPE="ext4" PARTUUID="c0b1dc87-5d27-4376-b4cf-8272385ae34d"
/dev/sdc1: UUID="132e7114-961b-4cda-b9af-70947ba40914" BLOCK_SIZE="4096" TYPE="ext4" PARTUUID="41db4b96-a67f-480e-9fde-67337f378bcc"
/dev/sdd1: UUID="ed512728-130d-4ddb-80bc-1d744d8d0755" BLOCK_SIZE="4096" TYPE="ext4" PARTUUID="d27fc8a7-7fef-4409-9bf5-924fae397357"
/dev/sde1: UUID="53632973-1765-4839-aa3b-bd8fff3b1c33" BLOCK_SIZE="4096" TYPE="ext4" PARTUUID="534fe7a2-1603-46d4-ad66-0ff0c05edd3c"

I have set in the rockpi-sata.service to “run before” SMB/CIFS/mounting the SSDs:

[Unit]
Before=export-disk.mount srv-mergerfs-mergefs.mount srv-dev\\x2ddisk\\x2dby\\x2duuid\\x2d132e7114\\x2d961b\\x2d4cda\\x2db9af\\x2d70947ba40914.mount srv-dev\\x2ddisk\\x2dby\\x2duuid\\x2d2b1fa6c8\\x2d6052\\x2d4d14\\x2daf8a\\x2d5f8ae206e9ee.mount srv-dev\\x2ddisk\\x2dby\\x2duuid\\x2d53632973\\x2d1765\\x2d4839\\x2daa3b\\x2dbd8fff3b1c33.mount srv-dev\\x2ddisk\\x2dby\\x2duuid\\x2ded512728\\x2d130d\\x2d4ddb\\x2d80bc\\x2d1d744d8d0755.mount

I have also configured “mergerfs” to “run before” SMB/CIFS and create a dependency on rockpi-sata.service:

[Unit]
Requires=rockpi-sata.service
After=rockpi-sata.service
Before=export-disk.mount smbd.service nfs-server.service

Phew, now the preamble is done, onto the logs…

I (re)booted the Pi at 23:16:

-- Boot 026eb68f05b34051aafccb64e252b1df --
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Queued start job for default target Main User Target.
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Created slice User Application Slice.
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Reached target Paths.
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Reached target Timers.
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Listening on GnuPG network certificate management daemon.
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Listening on GnuPG cryptographic agent and passphrase cache.
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Reached target Sockets.
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Reached target Basic System.
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Reached target Main User Target.
Nov 19 23:16:42 rpi4-nas-usb systemd[3084]: Startup finished in 375ms.
Nov 19 23:17:48 rpi4-nas-usb sudo[3458]:       pi : TTY=pts/0 ; PWD=/home/pi ; USER=root ; COMMAND=/usr/bin/zsh
Nov 19 23:17:48 rpi4-nas-usb sudo[3458]: pam_unix(sudo:session): session opened for user root(uid=0) by pi(uid=1000)
Nov 19 23:22:07 rpi4-nas-usb sshd[3102]: Received disconnect from 10.0.0.18 port 57026:11: disconnected by user
Nov 19 23:22:07 rpi4-nas-usb sshd[3102]: Disconnected from user pi 10.0.0.18 port 57026
Nov 19 23:22:08 rpi4-nas-usb sudo[3458]: pam_unix(sudo:session): session closed for user root
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Stopped target Main User Target.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Stopped target Basic System.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Stopped target Paths.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Stopped target Sockets.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Stopped target Timers.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: dirmngr.socket: Succeeded.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Closed GnuPG network certificate management daemon.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: gpg-agent-browser.socket: Succeeded.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Closed GnuPG cryptographic agent and passphrase cache (access for web browsers).
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: gpg-agent-extra.socket: Succeeded.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: gpg-agent-ssh.socket: Succeeded.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Closed GnuPG cryptographic agent (ssh-agent emulation).
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: gpg-agent.socket: Succeeded.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Closed GnuPG cryptographic agent and passphrase cache.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Removed slice User Application Slice.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Reached target Shutdown.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: systemd-exit.service: Succeeded.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Finished Exit the Session.
Nov 19 23:22:18 rpi4-nas-usb systemd[3084]: Reached target Exit the Session.

Everything is working well, so time for bed
but while I slept the following happened:

Nov 20 03:13:14 rpi4-nas-usb kernel: EXT4-fs error: 1 callbacks suppressed
Nov 20 03:13:15 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100482: comm mergerfs: reading direct>
Nov 20 03:13:15 rpi4-nas-usb kernel: EXT4-fs error: 1 callbacks suppressed
Nov 20 03:13:15 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438850: comm mergerfs: reading directo>
Nov 20 03:13:15 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100483: comm mergerfs: reading direct>
Nov 20 03:13:15 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438852: comm mergerfs: reading directo>
Nov 20 03:13:15 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100482: comm mergerfs: reading direct>
Nov 20 03:13:15 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438850: comm mergerfs: reading directo>
Nov 20 03:13:15 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100483: comm mergerfs: reading direct>
Nov 20 03:13:15 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438852: comm mergerfs: reading directo>
Nov 20 03:13:15 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100482: comm mergerfs: reading direct>
Nov 20 03:13:15 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438850: comm mergerfs: reading directo>
Nov 20 03:13:16 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100482: comm mergerfs: reading direct>
Nov 20 03:13:16 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438850: comm mergerfs: reading directo>
Nov 20 03:13:16 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100482: comm mergerfs: reading direct>
Nov 20 03:13:16 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438850: comm mergerfs: reading directo>
Nov 20 03:13:16 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100482: comm mergerfs: reading direct>
Nov 20 03:13:16 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438850: comm mergerfs: reading directo>
Nov 20 03:13:16 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100482: comm mergerfs: reading direct>
Nov 20 03:13:16 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438850: comm mergerfs: reading directo>
Nov 20 03:13:16 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100482: comm mergerfs: reading direct>
Nov 20 03:13:16 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438850: comm mergerfs: reading directo>
Nov 20 03:13:22 rpi4-nas-usb monit[2550]: filesystem statistic error: cannot read /sys/dev/block/8:17/stat -- No such file or directory
Nov 20 03:13:22 rpi4-nas-usb monit[2550]: Filesystem '/srv/dev-disk-by-uuid-2b1fa6c8-6052-4d14-af8a-5f8ae206e9ee' not mounted
Nov 20 03:13:22 rpi4-nas-usb monit[2550]: 'filesystem_srv_dev-disk-by-uuid-2b1fa6c8-6052-4d14-af8a-5f8ae206e9ee' unable to read filesyste>
Nov 20 03:13:22 rpi4-nas-usb monit[2550]: 'filesystem_srv_dev-disk-by-uuid-2b1fa6c8-6052-4d14-af8a-5f8ae206e9ee' trying to restart
Nov 20 03:13:22 rpi4-nas-usb monit[2550]: filesystem statistic error: cannot read /sys/dev/block/8:33/stat -- No such file or directory
Nov 20 03:13:22 rpi4-nas-usb monit[2550]: Filesystem '/srv/dev-disk-by-uuid-132e7114-961b-4cda-b9af-70947ba40914' not mounted
Nov 20 03:13:22 rpi4-nas-usb monit[2550]: 'filesystem_srv_dev-disk-by-uuid-132e7114-961b-4cda-b9af-70947ba40914' unable to read filesyste>
Nov 20 03:13:22 rpi4-nas-usb monit[2550]: 'filesystem_srv_dev-disk-by-uuid-132e7114-961b-4cda-b9af-70947ba40914' trying to restart

this goes on and on until I wake up
Unfortunatly I didn’t grab the output of df -h, but there was no longer a /dev/sdb or /dev/sdc but there was a /dev/sdf and /dev/sdg! and I’ve just seen in the logs that there is /dev/sdh too!

Here are the logs:
<hit character limit, the first reply will be these logs>

So my question is (finally we get there!):

  1. Why does rockpi-sata.service mount the same drives on different mountpoints if the service is restarted? Is it because mergerfs is still using those mountpoints and needs to be stopped first?
  2. Why does this happen in the first place? I guess there may be some communication issues over USB (everywhere I read online says “don’t do raid over USB!”), but when/if the connection comes back, then the disk should re-mount onto the same mountpoint, and mergerfs should continue as normal right?

Thanks for reading this essay!

#2

logs:

Nov 20 10:47:48 rpi4-nas-usb systemd[1]: Stopping Rockpi SATA Hat...
Nov 20 10:47:52 rpi4-nas-usb systemd[1]: rockpi-sata.service: Succeeded.
Nov 20 10:47:52 rpi4-nas-usb systemd[1]: Stopped Rockpi SATA Hat.
Nov 20 10:47:52 rpi4-nas-usb systemd[1]: rockpi-sata.service: Consumed 11min 2.053s CPU time.
Nov 20 10:47:52 rpi4-nas-usb systemd[1]: Started Rockpi SATA Hat.
Nov 20 10:47:52 rpi4-nas-usb kernel: usb 2-2: USB disconnect, device number 4
Nov 20 10:47:17 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #2: comm mergerfs: reading directory lblo>
Nov 20 10:47:17 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #2: comm mergerfs: reading directory lblo>
Nov 20 10:47:17 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #2: comm mergerfs: reading directory lblo>
Nov 20 10:47:17 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #2: comm mergerfs: reading directory lblo>
Nov 20 10:47:17 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #2: comm mergerfs: reading directory lblo>
Nov 20 10:47:18 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #2: comm mergerfs: reading directory lblo>
Nov 20 10:47:22 rpi4-nas-usb openmediavault-webgui[189006]: Authorized login from 10.0.0.18 [username=admin, user-agent=Mozilla/5.0 (Wind>
Nov 20 10:47:30 rpi4-nas-usb kernel: EXT4-fs error: 2 callbacks suppressed
Nov 20 10:47:30 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100483: comm mergerfs: reading direct>
Nov 20 10:47:30 rpi4-nas-usb kernel: EXT4-fs error: 2 callbacks suppressed
Nov 20 10:47:30 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438852: comm mergerfs: reading directo>
Nov 20 10:47:30 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100483: comm mergerfs: reading direct>
Nov 20 10:47:30 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438852: comm mergerfs: reading directo>
Nov 20 10:47:30 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100483: comm mergerfs: reading direct>
Nov 20 10:47:30 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438852: comm mergerfs: reading directo>
Nov 20 10:47:30 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): __ext4_find_entry:1665: inode #110100483: comm mergerfs: reading direct>
Nov 20 10:47:30 rpi4-nas-usb kernel: EXT4-fs error (device sdc1): __ext4_find_entry:1665: inode #63438852: comm mergerfs: reading directo>
Nov 20 10:47:35 rpi4-nas-usb sudo[189395]:       pi : TTY=pts/0 ; PWD=/home/pi ; USER=root ; COMMAND=/usr/bin/zsh
Nov 20 10:47:35 rpi4-nas-usb sudo[189395]: pam_unix(sudo:session): session opened for user root(uid=0) by pi(uid=1000)
Nov 20 10:47:48 rpi4-nas-usb systemd[1]: Stopping Rockpi SATA Hat...
Nov 20 10:47:52 rpi4-nas-usb systemd[1]: rockpi-sata.service: Succeeded.
Nov 20 10:47:52 rpi4-nas-usb systemd[1]: Stopped Rockpi SATA Hat.
Nov 20 10:47:52 rpi4-nas-usb systemd[1]: rockpi-sata.service: Consumed 11min 2.053s CPU time.
Nov 20 10:47:52 rpi4-nas-usb systemd[1]: Started Rockpi SATA Hat.
Nov 20 10:47:52 rpi4-nas-usb kernel: usb 2-2: USB disconnect, device number 4
Nov 20 10:47:52 rpi4-nas-usb kernel: sd 3:0:0:0: [sdf] Synchronizing SCSI cache
Nov 20 10:47:52 rpi4-nas-usb systemd[1]: Unmounting /srv/dev-disk-by-uuid-2b1fa6c8-6052-4d14-af8a-5f8ae206e9ee...
Nov 20 10:47:53 rpi4-nas-usb systemd[188685]: srv-dev\x2ddisk\x2dby\x2duuid\x2d2b1fa6c8\x2d6052\x2d4d14\x2daf8a\x2d5f8ae206e9ee.mount: Su>
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): ext4_wait_block_bitmap:533: comm umount: Cannot read block bitmap - blo>
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): ext4_discard_preallocations:5037: comm umount: Error -5 loading buddy i>
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): ext4_wait_block_bitmap:533: comm umount: Cannot read block bitmap - blo>
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): ext4_discard_preallocations:5037: comm umount: Error -5 loading buddy i>
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): ext4_wait_block_bitmap:533: comm umount: Cannot read block bitmap - blo>
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): ext4_discard_preallocations:5037: comm umount: Error -5 loading buddy i>
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): ext4_wait_block_bitmap:533: comm umount: Cannot read block bitmap - blo>
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): ext4_discard_preallocations:5037: comm umount: Error -5 loading buddy i>
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): ext4_wait_block_bitmap:533: comm umount: Cannot read block bitmap - blo>
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs error (device sdb1): ext4_discard_preallocations:5037: comm umount: Error -5 loading buddy i>
Nov 20 10:47:53 rpi4-nas-usb kernel: sd 3:0:0:0: [sdf] Synchronize Cache(10) failed: Result: hostbyte=0x07 driverbyte=DRIVER_OK
Nov 20 10:47:53 rpi4-nas-usb kernel: sd 3:0:0:1: [sdg] Synchronizing SCSI cache
Nov 20 10:47:53 rpi4-nas-usb systemd[1]: srv-dev\x2ddisk\x2dby\x2duuid\x2d2b1fa6c8\x2d6052\x2d4d14\x2daf8a\x2d5f8ae206e9ee.mount: Failed >
Nov 20 10:47:53 rpi4-nas-usb systemd[1]: Unmounted /srv/dev-disk-by-uuid-2b1fa6c8-6052-4d14-af8a-5f8ae206e9ee.
Nov 20 10:47:53 rpi4-nas-usb umount[190120]: umount: /srv/dev-disk-by-uuid-132e7114-961b-4cda-b9af-70947ba40914: target is busy.
Nov 20 10:47:53 rpi4-nas-usb systemd[1]: Unmounting /srv/dev-disk-by-uuid-132e7114-961b-4cda-b9af-70947ba40914...
Nov 20 10:47:53 rpi4-nas-usb systemd[1]: srv-dev\x2ddisk\x2dby\x2duuid\x2d132e7114\x2d961b\x2d4cda\x2db9af\x2d70947ba40914.mount: Mount p>
Nov 20 10:47:53 rpi4-nas-usb systemd[1]: Failed unmounting /srv/dev-disk-by-uuid-132e7114-961b-4cda-b9af-70947ba40914.
Nov 20 10:47:53 rpi4-nas-usb kernel: sd 3:0:0:1: [sdg] Synchronize Cache(10) failed: Result: hostbyte=0x07 driverbyte=DRIVER_OK
Nov 20 10:47:53 rpi4-nas-usb kernel: usb 2-1: USB disconnect, device number 3
Nov 20 10:47:53 rpi4-nas-usb kernel: print_req_error: 100 callbacks suppressed
Nov 20 10:47:53 rpi4-nas-usb kernel: blk_update_request: I/O error, dev sdd, sector 1951810312 op 0x1:(WRITE) flags 0x800 phys_seg 6 prio>
Nov 20 10:47:53 rpi4-nas-usb kernel: blk_update_request: I/O error, dev sdd, sector 2512 op 0x1:(WRITE) flags 0x3000 phys_seg 1 prio clas>
Nov 20 10:47:53 rpi4-nas-usb kernel: Aborting journal on device sdd1-8.
Nov 20 10:47:53 rpi4-nas-usb kernel: buffer_io_error: 46 callbacks suppressed
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on dev sdd1, logical block 58, lost async page write
Nov 20 10:47:53 rpi4-nas-usb kernel: blk_update_request: I/O error, dev sdd, sector 1950615552 op 0x1:(WRITE) flags 0x20800 phys_seg 1 pr>
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on dev sdd1, logical block 243826688, lost sync page write
Nov 20 10:47:53 rpi4-nas-usb kernel: blk_update_request: I/O error, dev sdd, sector 2920 op 0x1:(WRITE) flags 0x3000 phys_seg 1 prio clas>
Nov 20 10:47:53 rpi4-nas-usb kernel: JBD2: Error -5 detected when updating journal superblock for sdd1-8.
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on dev sdd1, logical block 109, lost async page write
Nov 20 10:47:53 rpi4-nas-usb kernel: blk_update_request: I/O error, dev sdd, sector 12585216 op 0x1:(WRITE) flags 0x3000 phys_seg 1 prio >
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on dev sdd1, logical block 1572896, lost async page write
Nov 20 10:47:53 rpi4-nas-usb kernel: blk_update_request: I/O error, dev sdd, sector 41945344 op 0x1:(WRITE) flags 0x3000 phys_seg 1 prio >
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on dev sdd1, logical block 5242912, lost async page write
Nov 20 10:47:53 rpi4-nas-usb kernel: blk_update_request: I/O error, dev sdd, sector 42212968 op 0x1:(WRITE) flags 0x3000 phys_seg 1 prio >
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on dev sdd1, logical block 5276365, lost async page write
Nov 20 10:47:53 rpi4-nas-usb kernel: blk_update_request: I/O error, dev sdd, sector 79480496 op 0x1:(WRITE) flags 0x3000 phys_seg 1 prio >
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on dev sdd1, logical block 9934806, lost async page write
Nov 20 10:47:53 rpi4-nas-usb kernel: blk_update_request: I/O error, dev sdd, sector 968886392 op 0x1:(WRITE) flags 0x3000 phys_seg 1 prio>
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on dev sdd1, logical block 121110543, lost async page write
Nov 20 10:47:53 rpi4-nas-usb kernel: blk_update_request: I/O error, dev sdd, sector 1779577752 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio c>
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs warning (device sdd1): ext4_end_bio:348: I/O error 10 writing to inode 1048578 starting bloc>
Nov 20 10:47:53 rpi4-nas-usb kernel: buffer_io_error: 3 callbacks suppressed
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on device sdd1, logical block 222446963
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on dev sdd1, logical block 226492420, lost async page write
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs error (device sdd1) in ext4_writepages:2833: IO failure
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs error (device sdd1): ext4_journal_check_start:83: comm kworker/u8:0: Detected aborted journal
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on dev sdd1, logical block 0, lost sync page write
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs (sdd1): previous I/O error to superblock detected
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs (sdd1): I/O error while writing superblock
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs (sdd1): Remounting filesystem read-only
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs (sdd1): ext4_writepages: jbd2_start: 775 pages, ino 1048578; err -30
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs warning (device sdd1): ext4_end_bio:348: I/O error 10 writing to inode 1048578 starting bloc>
Nov 20 10:47:53 rpi4-nas-usb kernel: EXT4-fs (sdd1): failed to convert unwritten extents to written extents -- potential data loss!  (ino>
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on device sdd1, logical block 222446964
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on device sdd1, logical block 222446965
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on device sdd1, logical block 222446966
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on device sdd1, logical block 222446967
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on device sdd1, logical block 222446968
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on device sdd1, logical block 222446969
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on device sdd1, logical block 222446970
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on device sdd1, logical block 222446971
Nov 20 10:47:53 rpi4-nas-usb kernel: Buffer I/O error on device sdd1, logical block 222446972
Nov 20 10:47:53 rpi4-nas-usb kernel: sd 2:0:0:0: [sdd] Synchronizing SCSI cache
Nov 20 10:47:53 rpi4-nas-usb systemd[1]: Unmounting /srv/dev-disk-by-uuid-ed512728-130d-4ddb-80bc-1d744d8d0755...
Nov 20 10:47:53 rpi4-nas-usb systemd[1]: srv-dev\x2ddisk\x2dby\x2duuid\x2ded512728\x2d130d\x2d4ddb\x2d80bc\x2d1d744d8d0755.mount: Mount p>
Nov 20 10:47:53 rpi4-nas-usb umount[190129]: umount: /srv/dev-disk-by-uuid-ed512728-130d-4ddb-80bc-1d744d8d0755: target is busy.
Nov 20 10:47:53 rpi4-nas-usb systemd[1]: Failed unmounting /srv/dev-disk-by-uuid-ed512728-130d-4ddb-80bc-1d744d8d0755.
Nov 20 10:47:53 rpi4-nas-usb systemd[1]: systemd-fsck@dev-disk-by\x2duuid-ed512728\x2d130d\x2d4ddb\x2d80bc\x2d1d744d8d0755.service: Succe>
Nov 20 10:47:53 rpi4-nas-usb systemd[1]: Stopped File System Check on /dev/disk/by-uuid/ed512728-130d-4ddb-80bc-1d744d8d0755.
Nov 20 10:47:53 rpi4-nas-usb systemd[1]: systemd-fsck@dev-disk-by\x2duuid-ed512728\x2d130d\x2d4ddb\x2d80bc\x2d1d744d8d0755.service: Consu>
Nov 20 10:47:54 rpi4-nas-usb kernel: sd 2:0:0:0: [sdd] Synchronize Cache(10) failed: Result: hostbyte=0x07 driverbyte=DRIVER_OK
Nov 20 10:47:54 rpi4-nas-usb kernel: EXT4-fs warning (device sde1): ext4_end_bio:348: I/O error 10 writing to inode 25427975 starting blo>
Nov 20 10:47:54 rpi4-nas-usb kernel: EXT4-fs warning (device sde1): ext4_end_bio:348: I/O error 10 writing to inode 25427975 starting blo>
Nov 20 10:47:54 rpi4-nas-usb kernel: EXT4-fs warning (device sde1): ext4_end_bio:348: I/O error 10 writing to inode 26345474 starting blo>
Nov 20 10:47:54 rpi4-nas-usb kernel: Aborting journal on device sde1-8.
Nov 20 10:47:54 rpi4-nas-usb kernel: JBD2: Error -5 detected when updating journal superblock for sde1-8.
Nov 20 10:47:54 rpi4-nas-usb kernel: sd 2:0:0:1: [sde] Synchronizing SCSI cache
Nov 20 10:47:54 rpi4-nas-usb systemd[1]: Unmounting /srv/dev-disk-by-uuid-53632973-1765-4839-aa3b-bd8fff3b1c33...
Nov 20 10:47:54 rpi4-nas-usb umount[190134]: umount: /srv/dev-disk-by-uuid-53632973-1765-4839-aa3b-bd8fff3b1c33: target is busy.
Nov 20 10:47:54 rpi4-nas-usb systemd[1]: srv-dev\x2ddisk\x2dby\x2duuid\x2d53632973\x2d1765\x2d4839\x2daa3b\x2dbd8fff3b1c33.mount: Mount p>
Nov 20 10:47:54 rpi4-nas-usb systemd[1]: Failed unmounting /srv/dev-disk-by-uuid-53632973-1765-4839-aa3b-bd8fff3b1c33.
Nov 20 10:47:54 rpi4-nas-usb systemd[1]: systemd-fsck@dev-disk-by\x2duuid-53632973\x2d1765\x2d4839\x2daa3b\x2dbd8fff3b1c33.service: Succe>
Nov 20 10:47:54 rpi4-nas-usb systemd[1]: Stopped File System Check on /dev/disk/by-uuid/53632973-1765-4839-aa3b-bd8fff3b1c33.
Nov 20 10:47:54 rpi4-nas-usb systemd[1]: systemd-fsck@dev-disk-by\x2duuid-53632973\x2d1765\x2d4839\x2daa3b\x2dbd8fff3b1c33.service: Consu>
Nov 20 10:47:54 rpi4-nas-usb kernel: sd 2:0:0:1: [sde] Synchronize Cache(10) failed: Result: hostbyte=0x07 driverbyte=DRIVER_OK
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-2: new SuperSpeed USB device number 5 using xhci_hcd
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-2: New USB device found, idVendor=152d, idProduct=0561, bcdDevice=81.36
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=5
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-2: Product: External Disk 3.0
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-2: Manufacturer: JMicron
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-2: SerialNumber: RANDOM__EF5DA5313073
Nov 20 10:47:55 rpi4-nas-usb kernel: scsi host3: uas
Nov 20 10:47:55 rpi4-nas-usb kernel: scsi 3:0:0:0: Direct-Access     JMicron  Tech             8136 PQ: 0 ANSI: 6
Nov 20 10:47:55 rpi4-nas-usb kernel: scsi 3:0:0:0: Attached scsi generic sg1 type 0
Nov 20 10:47:55 rpi4-nas-usb kernel: scsi 3:0:0:1: Direct-Access     JMicron  Tech             8136 PQ: 0 ANSI: 6
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:0: [sdb] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:0: [sdb] Write Protect is off
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:0: [sdb] Mode Sense: 67 00 10 08
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:0: [sdb] Write cache: enabled, read cache: enabled, supports DPO and FUA
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:1: Attached scsi generic sg2 type 0
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:0: [sdb] Optimal transfer size 33553920 bytes
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:1: [sdf] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:1: [sdf] Write Protect is off
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:1: [sdf] Mode Sense: 67 00 10 08
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:1: [sdf] Write cache: enabled, read cache: enabled, supports DPO and FUA
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:1: [sdf] Optimal transfer size 33553920 bytes
Nov 20 10:47:55 rpi4-nas-usb kernel:  sdb: sdb1
Nov 20 10:47:55 rpi4-nas-usb kernel:  sdf: sdf1
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:0: [sdb] Attached SCSI disk
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:1: [sdf] Attached SCSI disk
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190193]: checking bus 2, device 5: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.>
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190193]: bus: 2, device: 5 was not an MTP device
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190200]: checking bus 2, device 5: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.>
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190200]: bus: 2, device: 5 was not an MTP device
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-1: new SuperSpeed USB device number 6 using xhci_hcd
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-1: New USB device found, idVendor=152d, idProduct=0561, bcdDevice=81.36
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=5
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-1: Product: External Disk 3.0
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-1: Manufacturer: JMicron
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-1: SerialNumber: RANDOM__04AD244B74CD
Nov 20 10:47:55 rpi4-nas-usb kernel: scsi host4: uas
Nov 20 10:47:55 rpi4-nas-usb kernel: scsi 4:0:0:0: Direct-Access     JMicron  Tech             8136 PQ: 0 ANSI: 6
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: Attached scsi generic sg3 type 0
Nov 20 10:47:55 rpi4-nas-usb kernel: scsi 4:0:0:1: Direct-Access     JMicron  Tech             8136 PQ: 0 ANSI: 6
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: [sdg] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: [sdg] Write Protect is off
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: [sdg] Mode Sense: 67 00 10 08
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: [sdg] Write cache: enabled, read cache: enabled, supports DPO and FUA
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: [sdg] Optimal transfer size 33553920 bytes
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: Attached scsi generic sg4 type 0
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: [sdh] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: [sdh] Write Protect is off
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: [sdh] Mode Sense: 67 00 10 08
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: [sdh] Write cache: enabled, read cache: enabled, supports DPO and FUA
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: [sdh] Optimal transfer size 33553920 bytes
Nov 20 10:47:55 rpi4-nas-usb kernel:  sdg: sdg1
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: [sdg] Attached SCSI disk
Nov 20 10:47:55 rpi4-nas-usb kernel:  sdh: sdh1
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190218]: checking bus 2, device 6: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.>
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190218]: bus: 2, device: 6 was not an MTP device
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: [sdh] Attached SCSI disk
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190219]: checking bus 2, device 6: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.>
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190219]: bus: 2, device: 6 was not an MTP device
Nov 20 10:47:55 rpi4-nas-usb kernel: EXT4-fs error (device sde1): ext4_journal_check_start:83: comm mergerfs: Detected aborted journal
Nov 20 10:47:55 rpi4-nas-usb kernel:  sdb: sdb1
Nov 20 10:47:55 rpi4-nas-usb kernel:  sdf: sdf1
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:0: [sdb] Attached SCSI disk
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 3:0:0:1: [sdf] Attached SCSI disk
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190193]: checking bus 2, device 5: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.>
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190193]: bus: 2, device: 5 was not an MTP device
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190200]: checking bus 2, device 5: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.>
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190200]: bus: 2, device: 5 was not an MTP device
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-1: new SuperSpeed USB device number 6 using xhci_hcd
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-1: New USB device found, idVendor=152d, idProduct=0561, bcdDevice=81.36
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=5
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-1: Product: External Disk 3.0
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-1: Manufacturer: JMicron
Nov 20 10:47:55 rpi4-nas-usb kernel: usb 2-1: SerialNumber: RANDOM__04AD244B74CD
Nov 20 10:47:55 rpi4-nas-usb kernel: scsi host4: uas
Nov 20 10:47:55 rpi4-nas-usb kernel: scsi 4:0:0:0: Direct-Access     JMicron  Tech             8136 PQ: 0 ANSI: 6
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: Attached scsi generic sg3 type 0
Nov 20 10:47:55 rpi4-nas-usb kernel: scsi 4:0:0:1: Direct-Access     JMicron  Tech             8136 PQ: 0 ANSI: 6
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: [sdg] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: [sdg] Write Protect is off
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: [sdg] Mode Sense: 67 00 10 08
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: [sdg] Write cache: enabled, read cache: enabled, supports DPO and FUA
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: [sdg] Optimal transfer size 33553920 bytes
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: Attached scsi generic sg4 type 0
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: [sdh] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: [sdh] Write Protect is off
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: [sdh] Mode Sense: 67 00 10 08
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: [sdh] Write cache: enabled, read cache: enabled, supports DPO and FUA
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: [sdh] Optimal transfer size 33553920 bytes
Nov 20 10:47:55 rpi4-nas-usb kernel:  sdg: sdg1
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:0: [sdg] Attached SCSI disk
Nov 20 10:47:55 rpi4-nas-usb kernel:  sdh: sdh1
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190218]: checking bus 2, device 6: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.>
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190218]: bus: 2, device: 6 was not an MTP device
Nov 20 10:47:55 rpi4-nas-usb kernel: sd 4:0:0:1: [sdh] Attached SCSI disk
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190219]: checking bus 2, device 6: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.>
Nov 20 10:47:55 rpi4-nas-usb mtp-probe[190219]: bus: 2, device: 6 was not an MTP device
#3

This problem happens nearly every day.

Here is the output from lsblk -f when this problem has occurred:

➜  / lsblk -f
NAME    FSTYPE FSVER LABEL  UUID                                 FSAVAIL FSUSE% MOUNTPOINT
sda
├─sda1  vfat   FAT32 boot   0F92-BECC                             205.2M    20% /boot
└─sda2  ext4   1.0   rootfs 41c98998-6a08-4389-bf74-79c9efcf0739  832.2G     1% /
sdb
└─sdb1  ext4   1.0          2b1fa6c8-6052-4d14-af8a-5f8ae206e9ee    1.3T    25% /srv/dev-disk-by-uuid-2b1fa6c8-6052-
sdc
└─sdc1  ext4   1.0          132e7114-961b-4cda-b9af-70947ba40914    1.3T    28% /srv/dev-disk-by-uuid-132e7114-961b-
sdf
└─sdf1  ext4   1.0          ed512728-130d-4ddb-80bc-1d744d8d0755
sdg
└─sdg1  ext4   1.0          53632973-1765-4839-aa3b-bd8fff3b1c33
mmcblk0
├─mmcblk0p1
│       vfat   FAT32 boot   5DE4-665C
└─mmcblk0p2
        ext4   1.0   rootfs 7295bbc3-bbc2-4267-9fa0-099e10ef5bf0

Output of df -h:

➜  / df -h
Filesystem                                    Size  Used Avail Use% Mounted on
/dev/root                                     880G   13G  833G   2% /
devtmpfs                                      763M     0  763M   0% /dev
tmpfs                                         925M   28K  925M   1% /dev/shm
tmpfs                                         370M  3.8M  366M   2% /run
tmpfs                                         5.0M  4.0K  5.0M   1% /run/lock
tmpfs                                          10G   64K   10G   1% /tmp
/dev/sda1                                     255M   50M  206M  20% /boot
folder2ram                                    925M  243M  682M  27% /var/log
folder2ram                                    925M     0  925M   0% /var/tmp
folder2ram                                    925M  1.1M  924M   1% /var/lib/openmediavault/rrd
folder2ram                                    925M  2.4M  922M   1% /var/spool
folder2ram                                    925M   20M  906M   3% /var/lib/rrdcached
folder2ram                                    925M  4.0K  925M   1% /var/lib/monit
folder2ram                                    925M   28K  925M   1% /var/cache/samba
mergefs:984de985-2e44-4466-a5d3-fff84f76cbe1  7.2T  2.0T  5.3T  27% /export/disk
//10.0.0.18/share                             114G   56G   59G  49% /srv/366a7bf1-8ad0-41cf-a252-1fd79a5baaa3
overlay                                       880G   13G  833G   2% /var/lib/docker/overlay2/20a2dd1cf0a9bd46e241d1cedcf8b5302e9b04c5b596d2e10d4f6003a80a88d8/merged
/dev/sdc1                                     1.8T  512G  1.3T  28% /srv/dev-disk-by-uuid-132e7114-961b-4cda-b9af-70947ba40914
/dev/sdb1                                     1.8T  458G  1.4T  25% /srv/dev-disk-by-uuid-2b1fa6c8-6052-4d14-af8a-5f8ae206e9ee
/dev/sde1                                     1.8T  504G  1.3T  28% /srv/dev-disk-by-uuid-53632973-1765-4839-aa3b-bd8fff3b1c33
/dev/sdd1                                     1.8T  482G  1.4T  27% /srv/dev-disk-by-uuid-ed512728-130d-4ddb-80bc-1d744d8d0755
tmpfs                                         185M     0  185M   0% /run/user/1000

I don’t know if there is a software problem in the rockpi-sata.service, or a hardware problem in the sata controller

when I perform an “ls” inside one of the unmounted and automatically remounted disks:

➜  dev-disk-by-uuid-ed512728-130d-4ddb-80bc-1d744d8d0755 ls -lah
ls: reading directory '.': Input/output error
total 0
#4

Hello, what power supply are you using? Let’s rule out if the power supply is insufficient.

#5

Hello setq, thanks for responding, I’ve felt a bit in the dark over the past week with this issue - so I appreciate your help

I am using the power supply provided with this kit:

So a 12V 5A PSU plugged into the sata hat (no power plugged into the raspberry pi)

#6

It looks like the power supply is adequate. I want to know how your 1t Kingston is connected, is it connected to usb2.0, is there extra power?

#7

The kingston disk is my OS disk
It is in this enclosure:

(with a usbc to usb A 3.1 adapter, plugged into a USB 2 port)

It doesn’t have external power

#8

USB 2.0 has only 500ma of current and may not make the enclosure work steadily. Or we can try to use an sd card to install the system.

#9

I’ll try that out this evening

In the mean time the error just happened while I was awake, so here is the dmesg output:

[12099.228807] sd 2:0:0:1: [sde] tag#2 uas_eh_abort_handler 0 uas-tag 11 inflight: IN
[12099.228840] sd 2:0:0:1: [sde] tag#2 CDB: opcode=0x28 28 00 08 6b f3 30 00 04 00 00
[12099.244848] scsi host2: uas_eh_device_reset_handler start
[12099.373749] usb 2-1: reset SuperSpeed USB device number 3 using xhci_hcd
[12099.397845] usb 2-1: device firmware changed
[12099.405697] scsi host2: uas_eh_device_reset_handler FAILED err -19
[12099.405736] sd 2:0:0:1: Device offlined - not ready after error recovery
[12099.405778] sd 2:0:0:1: [sde] tag#2 UNKNOWN(0x2003) Result: hostbyte=0x03 driverbyte=DRIVER_OK cmd_age=30s
[12099.405792] sd 2:0:0:1: [sde] tag#2 CDB: opcode=0x28 28 00 08 6b f3 30 00 04 00 00
[12099.405804] blk_update_request: I/O error, dev sde, sector 141292336 op 0x0:(READ) flags 0x84700 phys_seg 128 prio class 0
[12099.406002] sd 2:0:0:1: rejecting I/O to offline device
[12099.406013] blk_update_request: I/O error, dev sde, sector 1364660608 op 0x0:(READ) flags 0x84700 phys_seg 128 prio class 0
[12099.406041] blk_update_request: I/O error, dev sde, sector 1364661632 op 0x0:(READ) flags 0x84700 phys_seg 128 prio class 0
[12099.406066] blk_update_request: I/O error, dev sde, sector 1364662656 op 0x0:(READ) flags 0x84700 phys_seg 128 prio class 0
[12099.406081] blk_update_request: I/O error, dev sde, sector 1364663680 op 0x0:(READ) flags 0x84700 phys_seg 128 prio class 0
[12099.406084] blk_update_request: I/O error, dev sde, sector 1364664704 op 0x0:(READ) flags 0x84700 phys_seg 128 prio class 0
[12099.406103] blk_update_request: I/O error, dev sde, sector 1364665728 op 0x0:(READ) flags 0x84700 phys_seg 128 prio class 0
[12099.406107] blk_update_request: I/O error, dev sde, sector 1364666752 op 0x0:(READ) flags 0x84700 phys_seg 128 prio class 0
[12099.406121] blk_update_request: I/O error, dev sde, sector 1364667776 op 0x0:(READ) flags 0x84700 phys_seg 128 prio class 0
[12099.406128] blk_update_request: I/O error, dev sde, sector 1364668800 op 0x0:(READ) flags 0x84700 phys_seg 128 prio class 0
[12099.406512] usb 2-1: USB disconnect, device number 3
[12099.407758] Aborting journal on device sdd1-8.
[12099.407822] Buffer I/O error on dev sdd1, logical block 243826688, lost sync page write
[12099.407858] JBD2: Error -5 detected when updating journal superblock for sdd1-8.
[12099.408117] Buffer I/O error on dev sdd1, logical block 5, lost async page write
[12099.408153] Buffer I/O error on dev sdd1, logical block 52, lost async page write
[12099.408179] Buffer I/O error on dev sdd1, logical block 54, lost async page write
[12099.408207] Buffer I/O error on dev sdd1, logical block 86, lost async page write
[12099.408231] Buffer I/O error on dev sdd1, logical block 93, lost async page write
[12099.408248] Buffer I/O error on dev sdd1, logical block 94, lost async page write
[12099.408282] Buffer I/O error on dev sdd1, logical block 98, lost async page write
[12099.408302] Buffer I/O error on dev sdd1, logical block 61515, lost async page write
[12099.408323] Buffer I/O error on dev sdd1, logical block 61517, lost async page write
[12099.429381] sd 2:0:0:0: [sdd] Synchronizing SCSI cache
[12099.680786] sd 2:0:0:0: [sdd] Synchronize Cache(10) failed: Result: hostbyte=0x07 driverbyte=DRIVER_OK
[12099.701756] Aborting journal on device sde1-8.
[12099.701827] JBD2: Error -5 detected when updating journal superblock for sde1-8.
[12099.745747] sd 2:0:0:1: [sde] Synchronizing SCSI cache
[12099.984812] sd 2:0:0:1: [sde] Synchronize Cache(10) failed: Result: hostbyte=0x07 driverbyte=DRIVER_OK
[12100.181032] usb 2-1: new SuperSpeed USB device number 4 using xhci_hcd
[12100.182691] EXT4-fs error (device sde1): ext4_journal_check_start:83: comm mergerfs: Detected aborted journal
[12100.182712] EXT4-fs (sde1): Remounting filesystem read-only
[12100.202645] usb 2-1: New USB device found, idVendor=152d, idProduct=0561, bcdDevice=81.36
[12100.202663] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=5
[12100.202669] usb 2-1: Product: External Disk 3.0
[12100.202673] usb 2-1: Manufacturer: JMicron
[12100.202676] usb 2-1: SerialNumber: RANDOM__6A0840143833
[12100.210664] scsi host3: uas
[12100.211678] scsi 3:0:0:0: Direct-Access     JMicron  Tech             8136 PQ: 0 ANSI: 6
[12100.212918] sd 3:0:0:0: Attached scsi generic sg3 type 0
[12100.213996] scsi 3:0:0:1: Direct-Access     JMicron  Tech             8136 PQ: 0 ANSI: 6
[12100.214413] sd 3:0:0:0: [sdf] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
[12100.214678] sd 3:0:0:0: [sdf] Write Protect is off
[12100.214684] sd 3:0:0:0: [sdf] Mode Sense: 67 00 10 08
[12100.215299] sd 3:0:0:0: [sdf] Write cache: enabled, read cache: enabled, supports DPO and FUA
[12100.215384] sd 3:0:0:1: Attached scsi generic sg4 type 0
[12100.216214] sd 3:0:0:0: [sdf] Optimal transfer size 33553920 bytes
[12100.217172] sd 3:0:0:1: [sdg] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
[12100.217447] sd 3:0:0:1: [sdg] Write Protect is off
[12100.217458] sd 3:0:0:1: [sdg] Mode Sense: 67 00 10 08
[12100.217960] sd 3:0:0:1: [sdg] Write cache: enabled, read cache: enabled, supports DPO and FUA
[12100.218918] sd 3:0:0:1: [sdg] Optimal transfer size 33553920 bytes
[12100.226087]  sdf: sdf1
[12100.226709]  sdg: sdg1
[12100.229052] sd 3:0:0:1: [sdg] Attached SCSI disk
[12100.231125] sd 3:0:0:0: [sdf] Attached SCSI disk
[12101.280183] EXT4-fs error (device sdd1): __ext4_find_entry:1665: inode #393218: comm mergerfs: reading directory lblock 0
[12101.759542] EXT4-fs error (device sdd1): __ext4_find_entry:1665: inode #393218: comm mergerfs: reading directory lblock 0
[12102.215768] EXT4-fs error (device sdd1): __ext4_find_entry:1665: inode #393218: comm mergerfs: reading directory lblock 0
[12103.172653] EXT4-fs error (device sde1): __ext4_find_entry:1665: inode #20447235: comm mergerfs: reading directory lblock 0
[12103.173010] EXT4-fs error (device sdd1): ext4_journal_check_start:83: comm mergerfs: Detected aborted journal
[12103.173038] EXT4-fs (sdd1): Remounting filesystem read-only
[12103.173298] EXT4-fs error (device sde1): __ext4_find_entry:1665: inode #20447235: comm mergerfs: reading directory lblock 0
[12103.173779] EXT4-fs error (device sde1): __ext4_find_entry:1665: inode #20447235: comm mergerfs: reading directory lblock 0
[12103.174172] EXT4-fs error (device sde1): __ext4_find_entry:1665: inode #20447235: comm mergerfs: reading directory lblock 0
[12103.174694] EXT4-fs error (device sde1): __ext4_find_entry:1665: inode #20447235: comm mergerfs: reading directory lblock 0
[12103.175472] EXT4-fs error (device sde1): __ext4_find_entry:1665: inode #20447235: comm mergerfs: reading directory lblock 0
[12103.176565] EXT4-fs error (device sde1): __ext4_find_entry:1665: inode #20447235: comm mergerfs: reading directory lblock 0
[12103.177392] EXT4-fs error (device sde1): __ext4_find_entry:1665: inode #20447235: comm mergerfs: reading directory lblock 0
[12103.178142] EXT4-fs error (device sde1): __ext4_find_entry:1665: inode #20447235: comm mergerfs: reading directory lblock 0
[12103.220354] EXT4-fs error (device sdd1): __ext4_find_entry:1665: inode #393222: comm mergerfs: reading directory lblock 0
[12103.222063] EXT4-fs error (device sdd1): __ext4_find_entry:1665: inode #393222: comm mergerfs: reading directory lblock 0
[12127.322958] EXT4-fs error: 17 callbacks suppressed
#10

Hey,

I have (finally) tested with using an SD card as a boot OS

The Kingston SSD isn’t plugged in, and this problem still occurrs

I guess there is something wrong with the sata hat?

#11

I’m looking for the github project of rockpi-sata.service, because I wonder if there a newer version

it seems like: https://github.com/akgnah/rockpi-sata is 404ing for me

what is the location for this software? And what is the latest version?

@setq

1 Like
#12

Im having same issue with this and running OS(Debian 11) On raspberry pi 4b 4gb. Are you running any raid with your setting? Have you found any solution for it?

#13

I’m using MergerFS - but not any kind of RAID

I’m still having this issue, but I’ve set up some cronjob to detect disconnected drives and reboot. It’s by no means ideal. Especially when I have other clients connected via SMB/CIFS/NFS (although proxmox really doesn’t like NFS servers rebooting, so I’ve had to stop using NFS)

I think the 404ing on the rockpi-sata service, combined with the lack of replies on this support forum. This item cannot be recommended. I’ll update this thread with what I replace this quad-sata-hat with (likely some second hand NAS)