backup-strategy (the entry point) still described nuc pulling the ks4 replicas: the leg, its WireGuard peer and the target pool now live on nas with the 4 TB on direct SATA. Also: ks4 README flow chart redrawn for the new topology, incus-copy leg 2 retargeted, usb4t-dropouts marked RESOLVED (kept for the diagnosis method and the alerting gap), and ks2/plan records that the interim push was deliberately not re-enabled. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
157 lines
6.7 KiB
Markdown
157 lines
6.7 KiB
Markdown
# usb4t: USB dropouts suspend the pool (2026-08) — RESOLVED
|
||
|
||
> **Outcome (2026-08-30): the disk moved off USB entirely.** It now
|
||
> runs on **direct SATA** in the new host `nas`
|
||
> ([nas/README.md](../nas/README.md)), as pool `tank`, and the ks4
|
||
> pull leg plus its WireGuard tunnel moved with it
|
||
> ([ks2/nas-seed.md](../ks2/nas-seed.md)). Everything below is the
|
||
> investigation that led there — worth keeping for the diagnosis
|
||
> method and for the alerting gap it exposed, which applies to any
|
||
> host.
|
||
|
||
Symptom seen first in the nightly backup log
|
||
(`/var/log/incus-copy.log`, job in `/etc/cron.d/incus-copy`): every
|
||
instance fails with
|
||
|
||
```
|
||
Error: Refresh instance: Create instance volume from copy failed:
|
||
Volume exists in database but not on storage
|
||
```
|
||
|
||
That message is misleading — incus is fine. The `usb4t` pool underneath
|
||
was **SUSPENDED**, so the replica volumes incus has in its database had
|
||
no storage behind them.
|
||
|
||
## Diagnosis (2026-08-28)
|
||
|
||
The disk is healthy, the USB link is not:
|
||
|
||
- `smartctl -a -d sat /dev/sdc`: **PASSED**, 0 reallocated, 0 pending,
|
||
0 offline-uncorrectable, **0 UDMA CRC errors**, 463 power-on hours.
|
||
- `dmesg`: `usb 4-3: USB disconnect` followed by immediate
|
||
re-enumeration — the enclosure drops off the bus and comes back as a
|
||
new device. Bridge is **JMicron 152d:0578** (the kernel already
|
||
disables UAS for it and applies quirks).
|
||
- **61 USB disconnects in 30 days**; pool suspensions on Aug 17
|
||
(resilver), 19, 21, 27 (×2) and 28.
|
||
- While suspended, anything touching the pool hangs — the journal
|
||
shows tasks blocked for 1000+ seconds.
|
||
|
||
Blast radius each time: nuc's own replicas (`usb4t/backup/nuc`) stop
|
||
being refreshed, `/srv/media` disappears from the Jellyfin containers,
|
||
and — once seeded — the ks4 pull leg (`usb4t/backup/ks4`) would stop
|
||
too. **The pool holding the off-site copy of ks4 must not be the least
|
||
reliable device in the setup.**
|
||
|
||
## Recovery
|
||
|
||
```sh
|
||
zpool clear usb4t # device is back; ZFS resumes IO
|
||
zpool status -v usb4t # lists files damaged by the interrupted writes
|
||
zpool scrub usb4t # validate the whole pool
|
||
```
|
||
|
||
If `clear` hangs: `zpool export usb4t && zpool import usb4t`, reboot as
|
||
a last resort. Datasets remount by themselves once the pool resumes.
|
||
|
||
Damage from the 2026-08-28 incident, as first reported: two
|
||
pool-metadata objects (`<metadata>:<0x0>`, `<metadata>:<0x3d>`) and
|
||
one media file. **The scrub cleared all of it** — 1.08 T verified in
|
||
2 h 29 m, `0 B repaired, 0 errors`, and the error list is now
|
||
`No known data errors`. Those entries were artefacts of the
|
||
interrupted writes, not real corruption; nothing had to be restored.
|
||
(One CKSUM count remains on the vdev — a single checksum ZFS fixed
|
||
from its own redundant metadata copy.)
|
||
|
||
The scrub also served as a 2.5-hour soak test of the new cable:
|
||
**zero USB disconnects** during it.
|
||
|
||
## Fixes, in order
|
||
|
||
1. ~~**Cable + port**~~ — replaced 2026-08-28 with a short quality
|
||
cable straight into a rear USB-3 port, no hub. It survived a 2.5 h
|
||
scrub, then **dropped again on 2026-08-29 16:22** (pool suspended,
|
||
cleared 08-30 00:32). **Cable ruled out.**
|
||
2. ~~**Disable USB autosuspend**~~ — **done, and ruled out**: the
|
||
kernel cmdline carries `usb-storage.quirks=152d:0578:u` (UAS
|
||
disabled for this bridge) and the device sits at
|
||
`power/control=on`. It still dropped on 2026-08-29, so neither
|
||
power management nor UAS explains this.
|
||
3. **Replace the enclosure — now the prime candidate.** With the cable
|
||
ruled out and the disk SMART-clean (0 reallocated/pending/CRC), the
|
||
JMicron 152d:0578 bridge is what remains. An ASMedia-based
|
||
enclosure (or a direct SATA connection) is the durable fix.
|
||
⚠️ Until this is settled, this pool is not a trustworthy home for
|
||
the ks4 off-site replica leg — treat it as a gate before seeding
|
||
over FTTH.
|
||
|
||
## Alerting (why nobody noticed for 11 days)
|
||
|
||
`zfs-zed` was installed, enabled and running — but the host had **no
|
||
MTA**, so its notifications went nowhere for 11 days. Fixed
|
||
2026-08-28; the working chain is:
|
||
|
||
```
|
||
zed → mail (bsd-mailx) → /usr/sbin/sendmail = msmtp → mail.lutran.fr:587 (auth, STARTTLS)
|
||
```
|
||
|
||
- `apt install msmtp msmtp-mta bsd-mailx`
|
||
- **`/etc/msmtprc` (mode 600) holds the SMTP account** — host
|
||
`mail.lutran.fr`, port **587 (submission)**, user `zed@lutran.fr`,
|
||
STARTTLS, `aliases /etc/aliases`.
|
||
- `/etc/zfs/zed.d/zed.rc` (mode 600): `ZED_EMAIL_ADDR="julien@lutran.fr"`,
|
||
`ZED_EMAIL_PROG="mail"`, `ZED_EMAIL_OPTS="-s '@SUBJECT@' @ADDRESS@"`,
|
||
`ZED_NOTIFY_VERBOSE=1` (so scrub/resilver results are mailed too, not
|
||
only failures), `ZED_NOTIFY_INTERVAL_SECS=3600`. Original kept as
|
||
`zed.rc.orig`. **No credentials in this file** — they live only in
|
||
`/etc/msmtprc`.
|
||
|
||
**Why nuc differs from ks2/ks4** (which mail via s-nail straight to
|
||
port 25, and work fine): it is not the zed config, it is the source
|
||
address. ks4 *is* the mail server's host (internal client,
|
||
`mynetworks`); ks2 is a datacenter IP with a PTR. nuc sends from a
|
||
**dynamic home IP with no PTR and no SPF alignment**, so the inbound
|
||
MX path treats it like any stranger. Hence submission + auth here,
|
||
deliberately different from the other two hosts.
|
||
|
||
Two dead ends worth remembering:
|
||
|
||
- **Port 25 is the wrong port for alerts.** Authentication succeeds,
|
||
then rspamd rejects the message: `554 5.7.1 Spam message rejected` —
|
||
a short mail from a dynamic home IP with no SPF alignment scores
|
||
badly on the inbound MX path. Submission (587) does not apply those
|
||
rules.
|
||
- **The home IP has no PTR**, so postfix's reverse lookup delays the
|
||
587 greeting by several seconds. Probes with short timeouts look
|
||
like a firewall block (`lost connection after CONNECT, commands=0/0`
|
||
in the server log) — give SMTP tests ≥30 s before concluding
|
||
anything.
|
||
|
||
### ZED does not report everything — hence the watchdog
|
||
|
||
The 2026-08-29 suspension produced **no email**, although the mail path
|
||
demonstrably worked (the scrub-finish notification arrived the evening
|
||
before). Two reasons:
|
||
|
||
- a suspended pool keeps its vdev marked **ONLINE**, so
|
||
`statechange-notify.sh` never fires;
|
||
- the `data`-class events ZED *did* raise were muted because
|
||
`ZED_NOTIFY_DATA` was unset (now `=1`).
|
||
|
||
Fixed 2026-08-30 by adding
|
||
[`zpool-health.sh`](https://git.lutran.fr/julien/scripts/src/branch/main/zpool-health.sh),
|
||
run every 15 min from `/etc/cron.d/zpool-health`. It mails only on
|
||
`healthy <-> problem` **transitions**, so it is silent in normal
|
||
operation and cannot spam; `-t` sends a test. Worth deploying on ks4
|
||
too — its `data` pool is single-disk and has the same blind spot.
|
||
|
||
Verify:
|
||
|
||
```sh
|
||
/root/scripts/zpool-health.sh -m julien@lutran.fr -t
|
||
tail -2 /var/log/msmtp.log # expect smtpstatus=250
|
||
```
|
||
|
||
End-to-end proof: with `ZED_NOTIFY_VERBOSE=1`, the next scrub
|
||
completion arrives as a mail by itself.
|