Hallo Leute,
Ich hatte offenbar in der Nacht auf Montag (26.02.2024) auch einen Absturz auf Raten bei meinem TVS-672X (FW 5.1.5.2645 build 20240116 vom 2024-01-25).
Auf Raten darum, weil
- nach Mitternacht nichts mehr im Log protokolliert wurde
- das Backup um 02:30 nicht durchgeführt wurde
- Snapshots nicht mehr durchgeführt wurden
- irgendwann ab 05:00 auch keine SNMP Abfragen mehr beantwortet wurden
- als ich um ~19:00 mich verbinden wollte das nicht mehr möglich war und dann auch keine Pings mehr beantwortet wurden (das dürfe bis dahin der Fall gewesen sein)
Als ich mir das Gerät dann angesehen habe, hat selbst das LCD Display nichts mehr angezeigt.
Lange auf den Ein-/Ausschaltknopf zu drücken hat das Teil dann abgewürgt (~19:25), ein Neustart hat dann zu einem Raid-Resync (WD Red pro's, ~3 Jahre alt, Raid 6, 1 Hot Spare) geführt, der kurz vor Mitternacht fertig war.
Eigentlich hatte ich für die Zeit danach einen Filesystemcheck eingetaktet und für die Zeit nach dem Backup ein Raid-Scrubbing um sicherzustellen, dass wieder ein sauberer Zustand vorherrscht.
Diese Plattenausfallsvorhersage habe ich dann deaktiviert.
Interessanterweise hat das Teil aber nach dem Raid-Resync einen Raid Rebuild durchgeführt - wodurch der Filesystemcheck nicht ausgeführt wurde.
Das Backup und neue Snapshots wurden aber erfolgreich angelegt, das Raid-Scrubbing lief um 3.30 ebenso.
Ich habe dann am Dienstag, als ich dieses Vorgänge festgestellt habe, den Filesystemcheck ohne Probleme nachgezogen, allerdings hat sich das Hot-spare von Slot 6 auf Slot 5 verändert - also irgendetwas ist da schon geschehen.
Um potentielle FW-Zusammenhänge auszuschließen, habe ich dann auch auf die neue FW (5.1.5.2679 build 20240219 vom 2024-02-26) aktualisiert - Probleme waren keine zu erkennen.
Alle Disks wurden als OK angezeigt.
Nachdem mir das Verhalten aber keine Ruhe gelassen hat, in dem Standard-Eventlog aber nichts zu sehen war, habe ich mir einen Export der Logs, den die Helpdesk-App erzeugt angesehen und bin im kmsg bzw dem offenbar vorherigen gezippten kmsg auf etliche interessante Einträge gestoßen:
2024-02-26 02:01:10 +01:00 <3> [2480309.976320] sd 1:0:0:0: rejecting I/O to offline device
2024-02-26 02:01:10 +01:00 <3> [2480309.976522] blk_update_request: I/O error, dev sdb, sector 3889510640 op 0x0:(READ) flags 0x0 phys_seg 4 prio class 0
2024-02-26 02:01:10 +01:00 <3> [2480309.981781] blk_update_request: I/O error, dev sdb, sector 1060256 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
...
2024-02-26 02:01:10 +01:00 <2> [2480310.003331] md/raid1:md9: Disk failure on sdb1, disabling device.
...
2024-02-26 02:01:11 +01:00 <5> [2480310.120773] sd 1:0:0:0: [sdb] Stopping disk
2024-02-26 02:01:11 +01:00 <6> [2480310.120947] sd 1:0:0:0: [sdb] Start/Stop Unit failed: Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK
...
2024-02-26 02:01:11 +01:00 <6> [2480310.147090] md/raid1:md13: redirecting sector 908000 to other mirror: sde4
2024-02-26 02:01:18 +01:00 <6> [2480317.297026] usb 2-2: reset SuperSpeed Gen 1 USB device number 3 using xhci_hcd
2024-02-26 02:01:38 +01:00 <0> [2480337.338751] watchdog: BUG: soft lockup - CPU#2 stuck for 23s! [md1_raid6:6585]
2024-02-26 02:01:38 +01:00 <4> [2480337.346130] Modules linked in: rfcomm usdm_drv(O) intel_qat(O) uio iscsi_tcp(O) libiscsi_tcp(O) libiscsi(O) scsi_transport_iscsi(O) fbdisk(O) cfg80211 dummy br_netfilter bridge stp bonding xt_connmark xt_TCPMSS xt_LOG xt_set ip_set_hash_netiface ip_set_hash_net ip_set xt_MASQUERADE xt_REDIRECT iptable_nat nf_nat xt_policy xt_mark 8021q ipv6 uvcvideo videobuf2_v4l2 videobuf2_vmalloc videobuf2_memops videobuf2_common snd_usb_caiaq snd_usb_audio snd_usbmidi_lib snd_seq_midi snd_rawmidi fnotify(O) nfsd nfsd_qlog udf isofs iTCO_wdt vfio_pci irqbypass vfio_virqfd vfio dm_cache_smq dm_cache exfat ufsd(PO) jnl(O) cdc_acm pl2303 usbserial qm2_i2c(O) i2c_imc(O) intel_ips drbd lru_cache flashcache(O) dm_tier_hro_algo dm_thin_pool dm_bio_prison dm_persistent_data hal_netlink(O) apex(C) gasket(C) atlantic(O) r8152(O) usbnet mii igb e1000e mv14xx(O) mpt3sas(O) scsi_transport_sas raid_class qla2xxx scsi_transport_fc k10temp coretemp uas usb_storage xhci_pci xhci_hcd usblp uhci_hcd ehci_pci e
...
2024-02-26 19:25:00 +01:00 <2> [ 117.975363] md/raid1:md9: Disk failure on sda1, disabling device.
...
2024-02-26 23:01:45 +01:00 <6> [13310.369582] md: md1: requested-resync done.
2024-02-26 23:01:45 +01:00 <6> [13310.373768] md: Resyncing done: md1
Alles anzeigen
Was ich als relevant erachtet habe, waren die Disk failure Einträge. Nachdem in den Exports auch folgende Info steht:
/sbin/qcli_storage -d
Enclosure Port Sys_Name Type Size Alias Signature Partitions Model
NAS_HOST 1 /dev/sde HDD:data 1.82 TB 3.5" SATA HDD 1 QNAP FLEX 5 WDC WD2002FFSX-68PF8N0
NAS_HOST 2 /dev/sdd HDD:data 1.82 TB 3.5" SATA HDD 2 QNAP FLEX 5 WDC WD2002FFSX-68PF8N0
NAS_HOST 3 /dev/sdc HDD:data 1.82 TB 3.5" SATA HDD 3 QNAP FLEX 5 WDC WD2002FFSX-68PF8N0
NAS_HOST 4 /dev/sdf HDD:data 1.82 TB 3.5" SATA HDD 4 QNAP FLEX 5 WDC WD2002FFSX-68PF8N0
NAS_HOST 5 /dev/sdb HDD:spare 1.82 TB 3.5" SATA HDD 5 -- FLEX 5 WDC WD2002FFSX-68PF8N0
NAS_HOST 6 /dev/sda HDD:data 1.82 TB 3.5" SATA HDD 6 QNAP 5 WDC WD2002FFSX-68PF8N0
NAS_HOST 7 /dev/nvme0n1 SSD:cache 476.94 GB M.2 PCIe SSD 1 QNAP FLEX 5 Samsung SSD 970 PRO 512GB
NAS_HOST 8 /dev/nvme1n1 SSD:cache 476.94 GB M.2 PCIe SSD 2 QNAP FLEX 5 Samsung SSD 970 PRO 512GB
Habe ich Dienstag Abends zuerst das Laufwerk im Slot 5 ersetzt (sdb, also neues Hot-Spare) und im Anschluss das im Slot 6 (sda).
Raid Rebuild lief gut durch, auch sonst konnte ich bisher keine Fehler feststellen.
Was mich aber massiv irritiert ist, dass bei einem Ausfall einer Platte doch bitte
- eine entsprechende Meldung im Eventlog zu finden sein sollte
- ein Raid 6 mit Hot-Spare zwar temporär degraded sein wird, aber sonst wohl eher unbeeindruckt sein sollte
- im Anschluss an die ganze Übung bitte doch nicht alle Platten als OK klassifiziert sein sollten
- folgender Eintrag im kmsg doch schräg aussieht (kam im übrigen mehrfach vor):
2024-02-26 02:01:38 +01:00 <0> [2480337.338751] watchdog: BUG: soft lockup - CPU#2 stuck for 23s! [md1_raid6:6585]
oder sehe ich das falsch?
Ach ja - die Platte SDB habe ich im Anschluss am PC (USB) mit diskpart clean all gelöscht - ohne irgendwelche Probleme.
Wie seht Ihr das?
Vielen lieben Dank für eure Meinung!