HS 210 bricht Kopiervorgänge ab und startet neu

  • Hallo zusammen,


    Wenn es das falsche Unterthema ist bitte verschieben.


    Ich habe seit geraumer Zeit das Problem, dass sich mein NAS beim kopieren von größeren Datenmengen via W-Lan (Edit: Mittlerweile auch via LAN) einfach abschlatet und neu startet. Die passiert v.a. beim kopieren von größeren Dateien. Wenn ich gleichzeitig vom TV aus zugreife ich die Sache noch schneller vorbei und der NAS schaltet ab und startet neu.


    Ich hatte erst verschiendene Prozesse auf dem NAS im Verdacht und habe diese nun ausgestellt. Videostation, Musicstation etc. habe ich ausgeschlatet und dadurch ging die Auslastung zurück auf ca. 10-20% Das Problem blieb aber dennoch. In den ersten drei Monaten der Nutzung gabe es keinerlei Probleme, obwohl alle Stationen an waren und ich meine Musikbibliothek und andere Sachen auf den NAS kopiert habe.


    Heute Morgen ist es noch einmal passiert und nun befindet sich auf einer Festplatte eine Anomalie :( und die CPU Auslastung liegt bei 95-100%. Kann mir jemand helfen? Vielen Dank im Vorraus!


    Edit: Die CPU Auslastung ist wieder zurück gegangen und liegt nun im Normalbereich (s.o.) Das Problem, dass sich der NAS von alleine ausstellt habe ich leider immer noch. Gibt es bei der Festplatte noch irgendetwas zu retten?



    ---Edit---



    Neues Problem. :(


    Nachdem ich auf der defekten Festplatte einen Bad Block Scan gestartet habe wurde dieser heute Nacht durchgeführt. Er wurde abgeschlossen und als ich dann auf den NAS zugreifen wollte kam die Meldung, dass nun auch auf der anderen Festplatte ein Lese und Schreibfehler festgestellt wurde. Auf die Daten kann ich mittel Finder noch zugreifen.


    Nun habe ich aber große Angst, dass beide Festplatten hinüber sind. Ich habe gestern eine neue Festplatte bestellt, aber dieser ist vor Dienstag nicht da. Kann ich meine Daten retten, wenn ich die ursprünglich defekte Festplatte austausche? Oder ist dadurch, dass beide Festplatten einen Lesefehler haben, nun ein Rebuild nicht mehr möglich?

    Einmal editiert, zuletzt von bladekiller () aus folgendem Grund: Editierfunktion nutzen und doppelte Beiträge vermeiden, siehe Forenregeln!

  • Moin,


    Ist doch alles kein Problem,..


    Poste mal was in deinem Systemprotokoll steht,... wollen doch mal schauen, was die NAS zu Meckern hat.


    Daten,... Wiederherstellen, wozu die mühe, du hast doch ein Backup

  • Hallo und Danke fürs editieren. :)


    Nun zu meinen Problemen:


    1.Systemprotokolle:
    Bei den Kopierabbrüchen gab es immer folgende Meldung:

    Code
    "Warning","2014-06-15","19:18:59","System","127.0.0.1","localhost","[Mirror Disk Volume: Drive 1 2] The file system is not clean. It is suggested that you go to [Storage Manager] to run "Check File System".""Information","2014-06-15","19:18:20","System","127.0.0.1","localhost","[Media Library] Media Library Server started.""Information","2014-06-15","19:17:08","System","127.0.0.1","localhost","System started."


    Die Meldung mit dem Fehler auf der ersten Festplatte (im NAS war es der Datenträger Nr.2):

    Code
    "Warning","2014-06-28","10:31:51","System","127.0.0.1","localhost","[Mirror Disk Volume: Drive 1 2] Resyncing skipped.""Information","2014-06-28","10:31:50","System","127.0.0.1","localhost","[Mirror Disk Volume: Drive 1 2] Start resyncing.""Warning","2014-06-28","10:31:47","System","127.0.0.1","localhost","[Mirror Disk Volume: Drive 1 2] Resyncing skipped.""Information","2014-06-28","10:31:44","System","127.0.0.1","localhost","[Mirror Disk Volume: Drive 1 2] Start resyncing.""Warning","2014-06-28","10:31:00","System","127.0.0.1","localhost","[Mirror Disk Volume: Drive 1 2] RAID device in degraded mode.""Warning","2014-06-28","10:30:59","System","127.0.0.1","localhost","[Mirror Disk Volume: Drive 1 2] The file system is not clean. It is suggested that you go to [Storage Manager] to run "Check File System".""Warning","2014-06-28","10:29:04","System","127.0.0.1","localhost","The system was not shut down properly last time.""Information","2014-06-28","10:30:17","System","127.0.0.1","localhost","[Media Library] Media Library Server started.""Warning","2014-06-28","10:29:08","System","127.0.0.1","localhost","[Harddisk 2] medium error. Please run bad block scan on this drive or replace the drive if the error persists.""Warning","2014-06-28","10:29:08","System","127.0.0.1","localhost","[Harddisk 2] I/O error, sense_key=0x3, asc=0x11, ascq=0x4, CDB=28 00 00 08 17 10 00 00 08 00 .""Information","2014-06-28","10:29:05","System","127.0.0.1","localhost","System started."


    Daraufhin habe ich einen Bad Block Scan auf dem Datenträger 2 gestartet und dabei gabe es folgende Bemerkungen im Systemprotokoll:


    Ich hoffe, das Dilemma lässt sich irgendwie beheben. Ich bin für jede Hilfe dankbar!


    2.Backup der Daten
    Bzgl. des Backups geht es in erster Linie um die ganze Arbeit bzw. Zeit, die mit dem erneuten kopieren verbunden ist. Die möchte ich mir zumindest gerne sparen. Die allerwichtigstes Dateien (Dokumente, Fotos, etc.) sind auf anderen externen Festplatten gespeichert. Daher die Frage, ob ich durch eine neue Festplatte die Daten retten kann oder ob die Spiegelung durch die Lesefehler auf beiden Festplatten nicht mehr funktioniert.

    Einmal editiert, zuletzt von bladekiller () aus folgendem Grund: Code Block hinzugefügt, siehe Forenregeln!

  • Jo, die Platte scheint defekt,...


    Was sagen die Smartwerte?


    Ansonsten mal eine Ersatzplatte einstecken und ein sauberes Rebuild abwarten.

  • hmm Mist. Zuerst waren die Schreibfehler nur auf dem zweiten Datenträger. Nach dem Bad Block Scan auf eben diesem und dem Neustart hat er mir die gleiche Meldung auch für den ersten Datenträger gezeigt. Also Schreib- und Lesefehler auf beiden Datenträgern. Ist ein Rebuild dann noch möglich? Die Smart-Werte sind bei beiden Platten weiterhin auf "gut"


    Eine neue Platte muss ich erst besorgen. Wahrscheinlich wird es erst am Dienstag was. Dann werde ich den Rebuild auf jeden Fall ausprobieren. Danke schonmal soweit!

  • Auf dem NAS läuft mit der FW 4.1.0 Build 20140416, die aktuellste Version.


    Gefühlt fingen die Probleme mit den Kopierabbrüchen mit dem Update auf eben diese Version an. Ganz genau kann ich es aber leider nicht sagen.

  • Zitat von "TheMcLusky"

    FW 4.1.0 Build 20140416, die aktuellste Version.


    Nicht die aktuellste - aktuell ist die FW 4.1.0 Build 20140612.
    Eventuell mal updaten.
    Vorher sobald als möglich Daten sichern.
    Welcher Plattentyp ist verbaut?

  • Ich hatte gestern über den Webzugriff nach einer aktuelleren FW gesucht und mir wurde gesagt, dass ich die aktuellste habe. Nun ja mit ein bisschen quer lesen hier habe ich gemerkt, dass es nicht der Fall ist. Ich werde versuchen sicher was zu sichern ist und dann die neue FW aufzuspielen.


    Ich benutze zwei WD RED mit 3 TB. Um genau zu sein zwei WDC WD30EFRX-68EUZN080.0


    Danke schon einmal!

  • die Platte sollten zumindest hoch kompatibel sein.

  • Der erste Post kam etwas voreilig, daher stand hier bis vor kurzem noch ein "edit"


    Nun zu meinem Problem. Heute hatte ich endlich die Gelegenheit die neue Festplatte in den NAS einzubauen, was ich dann auch gleich gemacht habe. Der Rebuild startete und brach dann aber nach ca. 20 Minuten ab. Dies passte zu meinen Befürchtungen. Da ich aber die meisten Sachen gesicherte hatte (bis auf ein paar Kleinigkeiten, die nicht weh tun) habe ich mich entschlossen, dass System neu aufzusetzen.


    Bis dato läuft die Kiste wieder und der NAS wieder. Eine Festplatte, die einen Schreib und Lesefehler haben sollte wird jetzt wieder ohne Problem bzw. Warnung angezeigt. Kann ich den Status der Festplatte mit einem Bad Block Scan überprüfen oder wie kann ich sichergehen, dass die Platte wirklich in Ordnung ist?

  • So, nachdem alle Daten wieder aufm NAS sind hat sich mein Problem, was im Threadtitel steht leider nicht erledigt.


    Mittlerweile startet der NAS bei jedem Kopiergang mit mehr als 500 MB neu. Es ist egal ob ich via LAN oder W-Lan auf den NAS zugreife (SMB oder AFP spielt keine Rolle). Gibt es da irgendeine Erklärung dafür? Ich bin für jede Hilfe dankbar!

  • Im Verzeichnis /mnt/HDA_ROOT/.logs gibt es die Kernel-Logdateien kmsg, kmsg.1 und häufig auch kmsg.2.
    Diese mal hier gezippt anhängen.

  • Zitat von "TheMcLusky"

    aber meinen Urlaub wollte ich mir nicht mit Ärger über meinen NAS versauen


    Das ist verständlich. Gleichwohl ist nicht ausgeschlossen, dass sich der Ärger auch gegen die Festplatten richten könnte und das NAS unschuldig ist. ;)

    Zitat von "TheMcLusky"

    Anbei die beiden ksmg files. Ich hoffe, dass dort etwas brauchbares drin steht.


    Nun, brauchbar ist relativ. Jedoch kann man schon paar Informationen entnehmen.
    Als Erstes fasse ich mal das aktuelle Bootlog (aktuell zum Zeitpunkt, als du es kopiert hast) eingedampft auf die datenträgerrelevanten Informationen zusammen. Anschliessend gehe ich auf einzelne Punkte daraus und aus der im Zip vorhandenen kmsg.1 ein.


    kmsg von 2014-07-11 18:59:36 UTC bis 2014-07-12 04:06:42 UTC:

    Code
    <6>[    7.813541] rtc-s35390a 0-0030: setting system clock to 2014-07-11 18:59:36 UTC (1405105176)<6>[    8.076614] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl F330)<6>[    8.096810] ata1.00: ATA-9: WDC WD30EFRX-68EUZN0, 80.00A80, max UDMA/133<6>[    8.103541] ata1.00: 5860533168 sectors, multi 0: LBA48 NCQ (depth 31/32)<6>[    8.126800] ata1.00: configured for UDMA/133<5>[    8.131332] scsi 0:0:0:0: Direct-Access     WDC      WD30EFRX-68EUZN0 80.0 PQ: 0 ANSI: 5<4>[    8.139800] Check proc_name[sata_mv].<5>[    8.143805] sd 0:0:0:0: [sda] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)<5>[    8.151591] sd 0:0:0:0: [sda] 4096-byte physical blocks<4>[    8.156997] Check proc_name[sata_mv].<5>[    8.160822] sd 0:0:0:0: Attached scsi generic sg0 type 0<5>[    8.166552] sd 0:0:0:0: [sda] Write Protect is off<7>[    8.171380] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00<5>[    8.171460] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA<6>[    8.231384]  sda: sda1 sda2 sda3 sda4<5>[    8.236299] sd 0:0:0:0: [sda] Attached SCSI disk<6>[    8.666613] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl F330)<6>[    8.686796] ata2.00: ATA-9: WDC WD30EFRX-68EUZN0, 80.00A80, max UDMA/133<6>[    8.693527] ata2.00: 5860533168 sectors, multi 0: LBA48 NCQ (depth 31/32)<6>[    8.716789] ata2.00: configured for UDMA/133<5>[    8.721277] scsi 1:0:0:0: Direct-Access     WDC      WD30EFRX-68EUZN0 80.0 PQ: 0 ANSI: 5<4>[    8.729729] Check proc_name[sata_mv].<5>[    8.733707] sd 1:0:0:0: [sdb] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)<5>[    8.741499] sd 1:0:0:0: [sdb] 4096-byte physical blocks<4>[    8.746840] Check proc_name[sata_mv].<5>[    8.750654] sd 1:0:0:0: Attached scsi generic sg1 type 0<5>[    8.756280] sd 1:0:0:0: [sdb] Write Protect is off<7>[    8.761101] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00<5>[    8.761178] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA<6>[    9.502232]  sdb: sdb1 sdb2 sdb3 sdb4<5>[    9.507081] sd 1:0:0:0: [sdb] Attached SCSI disk<6>[    9.511745] md: Skipping autodetection of RAID arrays. (raid=autodetect will force)<6>[   10.873508] EXT3-fs (sda1): recovery required on readonly filesystem<6>[   10.879910] EXT3-fs (sda1): write access will be enabled during recovery<6>[   11.104268] kjournald starting.  Commit interval 5 seconds<6>[   11.109826] EXT3-fs (sda1): orphan cleanup on readonly fs<7>[   11.139072] ext3_orphan_cleanup: deleting unreferenced inode 6879<6>[   11.139351] EXT3-fs (sda1): 1 orphan inode deleted<6>[   11.157415] EXT3-fs (sda1): recovery complete<6>[   11.161791] EXT3-fs (sda1): mounted filesystem with writeback data mode<6>[   11.306530] EXT3-fs (sdb1): recovery required on readonly filesystem<6>[   11.312939] EXT3-fs (sdb1): write access will be enabled during recovery<6>[   11.497076] kjournald starting.  Commit interval 5 seconds<6>[   11.502613] EXT3-fs (sdb1): orphan cleanup on readonly fs<7>[   11.514197] ext3_orphan_cleanup: deleting unreferenced inode 6879<6>[   11.514400] EXT3-fs (sdb1): 1 orphan inode deleted<6>[   11.527408] EXT3-fs (sdb1): recovery complete<6>[   11.531782] EXT3-fs (sdb1): mounted filesystem with writeback data mode<6>[   11.704889] md: md9 stopped.<6>[   11.736851] md: bind<sdb1><6>[   11.739789] md: bind<sda1><5>[   11.749397] md/raid1:md9: not clean -- starting background reconstruction<6>[   11.756217] md/raid1:md9: active with 2 out of 2 mirrors<6>[   11.761732] created bitmap (65 pages) for device md9<6>[   11.773410] md9: bitmap initialized from disk: read 5/5 pages, set 83 of 132512 bits<6>[   11.796706] md9: detected capacity change from 0 to 542769152<6>[   11.812712] md: resync of RAID array md9<6>[   11.816733] md: minimum _guaranteed_	speed: 5000 KB/sec/disk.<6>[   11.822506] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for resync.<6>[   11.831950] md: using 128k window, over a total of 530048k.<6>[   11.842001]  md9: unknown partition table<6>[   12.167292] md: md9: resync done.<7>[   12.246733] RAID1 conf printout:<7>[   12.246742]  --- wd:2 rd:2<7>[   12.246749]  disk 0, wo:0, o:1, dev:sda1<7>[   12.246755]  disk 1, wo:0, o:1, dev:sdb1<6>[   14.019307] kjournald starting.  Commit interval 5 seconds<6>[   14.026755] EXT3-fs (md9): using internal journal<6>[   14.031484] EXT3-fs (md9): mounted filesystem with writeback data mode<6>[   14.337162] md: md13 stopped.<6>[   14.396143] md: bind<sdb4><6>[   14.399094] md: bind<sda4><6>[   14.404482] md/raid1:md13: active with 2 out of 2 mirrors<6>[   14.410097] created bitmap (57 pages) for device md13<6>[   14.420973] md13: bitmap initialized from disk: read 4/4 pages, set 0 of 114720 bits<6>[   14.506673] md13: detected capacity change from 0 to 469893120<6>[   14.544925]  md13: unknown partition table<6>[   15.963666] kjournald starting.  Commit interval 5 seconds<6>[   16.047401] EXT3-fs (md9): using internal journal<6>[   16.052125] EXT3-fs (md9): mounted filesystem with writeback data mode<6>[   16.437229] kjournald starting.  Commit interval 5 seconds<6>[   16.476925] EXT3-fs (md9): using internal journal<6>[   16.481655] EXT3-fs (md9): mounted filesystem with ordered data mode<6>[   16.887184] kjournald starting.  Commit interval 5 seconds<6>[   16.967104] EXT3-fs (md13): using internal journal<7>[   17.040006] ext3_orphan_cleanup: deleting unreferenced inode 2331<7>[   17.049519] ext3_orphan_cleanup: deleting unreferenced inode 1317<6>[   17.049547] EXT3-fs (md13): 2 orphan inodes deleted<6>[   17.167498] EXT3-fs (md13): recovery complete<6>[   17.171877] EXT3-fs (md13): mounted filesystem with writeback data mode<6>[   49.107130] md: linear personality registered for level -1<6>[   49.174717] md: raid0 personality registered for level 0<6>[   49.240022] xor: measuring software checksum speed<6>[   49.286600]    arm4regs  :  1447.600 MB/sec<6>[   49.336598]    8regs     :  1007.200 MB/sec<6>[   49.386597]    32regs    :  1189.200 MB/sec<6>[   49.390795] xor: using function: arm4regs (1447.600 MB/sec)<4>[   49.766880] raid6: int32x1    116 MB/s<4>[   49.936914] raid6: int32x2    160 MB/s<4>[   50.106821] raid6: int32x4    176 MB/s<4>[   50.276843] raid6: int32x8    158 MB/s<4>[   50.280600] raid6: using algorithm int32x4 (176 MB/s)<4>[   50.285666] raid6: using intx1 recovery algorithm<6>[   50.562049] md: raid6 personality registered for level 6<6>[   50.567405] md: raid5 personality registered for level 5<6>[   50.572738] md: raid4 personality registered for level 4<6>[   53.136656] usb 2-1: new high-speed USB device number 2 using etxhci_hcd_140219<6>[   53.251183] usb-storage 2-1:1.0: Quirks match for vid 152d pid 2329: 8020<6>[   53.330383] scsi2 : usb-storage 2-1:1.0<5>[   54.347552] scsi 2:0:0:0: Direct-Access     SAMSUNG  HM641JI               PQ: 0 ANSI: 2 CCS<5>[   54.377732] sd 2:0:0:0: [sdq] 1250263728 512-byte logical blocks: (640 GB/596 GiB)<5>[   54.402565] sd 2:0:0:0: Attached scsi generic sg16 type 0<5>[   54.442341] sd 2:0:0:0: [sdq] Write Protect is off<7>[   54.447184] sd 2:0:0:0: [sdq] Mode Sense: 28 00 00 00<3>[   54.459488] sd 2:0:0:0: [sdq] No Caching mode page present<3>[   54.464998] sd 2:0:0:0: [sdq] Assuming drive cache: write through<3>[   54.513534] sd 2:0:0:0: [sdq] No Caching mode page present<3>[   54.519121] sd 2:0:0:0: [sdq] Assuming drive cache: write through<6>[   54.553145]  sdq: sdq1<3>[   54.573440] sd 2:0:0:0: [sdq] No Caching mode page present<3>[   54.578975] sd 2:0:0:0: [sdq] Assuming drive cache: write through<5>[   54.585091] sd 2:0:0:0: [sdq] Attached SCSI disk<4>[   54.589736] [#] set usb polling mode (sdq)<6>[   71.009984] kjournald starting.  Commit interval 5 seconds<6>[   71.025795] EXT3-fs (md9): using internal journal<6>[   71.030613] EXT3-fs (md9): mounted filesystem with ordered data mode<6>[   77.866897] md: bind<sda2><6>[   77.872485] md/raid1:md2: active with 1 out of 1 mirrors<6>[   77.877910] md2: detected capacity change from 0 to 542769152<6>[   78.946988]  md2: unknown partition table<6>[   80.794161] md: md0 stopped.<6>[   80.835046] md: md0 stopped.<6>[   81.099586] Adding 530044k swap on /dev/md2.  Priority:-1 extents:1 across:530044k <6>[   81.110518] md: bind<sdb3><6>[   81.113456] md: bind<sda3><5>[   81.131905] md/raid1:md0: not clean -- starting background reconstruction<6>[   81.138754] md/raid1:md0: active with 2 out of 2 mirrors<6>[   81.144155] md0: detected capacity change from 0 to 2998986297344<6>[   81.163638] md: resync of RAID array md0<6>[   81.167607] md: minimum _guaranteed_	speed: 5000 KB/sec/disk.<6>[   81.173372] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for resync.<6>[   81.182813] md: Resyncing started: md0<6>[   81.186638] md: using 128k window, over a total of 2928697556k.<6>[   82.253505]  md0: unknown partition table<6>[   86.086851] md: bind<sdb2><7>[   86.106985] RAID1 conf printout:<7>[   86.106996]  --- wd:1 rd:2<7>[   86.107003]  disk 0, wo:0, o:1, dev:sda2<7>[   86.107010]  disk 1, wo:1, o:1, dev:sdb2<6>[   86.116957] md: delaying recovery of md2 until md0 has finished (they share one or more physical units)<4>[   90.648118] ext4_init_reserve_inode_table0: md0, 22345<4>[   90.653287] ext4_init_reserve_inode_table2: md0, 22345, 0, 0, 4096<7>[   90.719951] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180788443<7>[   90.729833] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748395<7>[   90.729905] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748391<7>[   90.729957] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748390<7>[   90.730013] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748389<6>[   90.730052] EXT4-fs (md0): 5 orphan inodes deleted<6>[   90.807037] EXT4-fs (md0): recovery complete<6>[   91.016704] EXT4-fs (md0): mounted filesystem with ordered data mode. Opts: usrjquota=aquota.user,jqfmt=vfsv0,user_xattr,data=ordered,delalloc,noacl<1>[  812.871104] md/raid1:md2: Disk failure on sdb2, disabling device.<1>[  812.871110] md/raid1:md2: Operation continuing on 1 devices.<4>[  814.897508] md: cannot remove active disk sdb2 from md2 ...<4>[  820.917361] raid1: some error occurred in a active device:0 of md2.<4>[  822.937342] md: cannot remove active disk sda2 from md2 ...<6>[ 1091.518012] usb 2-1: USB disconnect, device number 2<4>[ 1539.884978] ext4_init_reserve_inode_table0: md0, 22345<4>[ 1539.890160] ext4_init_reserve_inode_table2: md0, 22345, 0, 0, 4096<6>[ 1539.896418] EXT4-fs (md0): mounted filesystem with ordered data mode. Opts: usrjquota=aquota.user,jqfmt=vfsv0,user_xattr,data=ordered,delalloc,noacl<6>[17582.136666] usb 2-1: new high-speed USB device number 3 using etxhci_hcd_140219<6>[17582.185778] usb-storage 2-1:1.0: Quirks match for vid 152d pid 2329: 8020<6>[17582.200973] scsi3 : usb-storage 2-1:1.0<5>[17583.217885] scsi 3:0:0:0: Direct-Access     SAMSUNG  HM641JI               PQ: 0 ANSI: 2 CCS<5>[17583.244654] sd 3:0:0:0: [sdq] 1250263728 512-byte logical blocks: (640 GB/596 GiB)<5>[17583.266870] sd 3:0:0:0: Attached scsi generic sg16 type 0<5>[17583.297368] sd 3:0:0:0: [sdq] Write Protect is off<7>[17583.302181] sd 3:0:0:0: [sdq] Mode Sense: 28 00 00 00<3>[17583.320477] sd 3:0:0:0: [sdq] No Caching mode page present<3>[17583.326311] sd 3:0:0:0: [sdq] Assuming drive cache: write through<3>[17583.349305] sd 3:0:0:0: [sdq] No Caching mode page present<3>[17583.354813] sd 3:0:0:0: [sdq] Assuming drive cache: write through<6>[17583.394575]  sdq: sdq1<3>[17583.405736] sd 3:0:0:0: [sdq] No Caching mode page present<3>[17583.411582] sd 3:0:0:0: [sdq] Assuming drive cache: write through<5>[17583.418045] sd 3:0:0:0: [sdq] Attached SCSI disk<4>[17583.422682] [#] set usb polling mode (sdq)<6>[32826.529042] md: md0: resync done.<6>[32826.532371] md: Resyncing done: md0<6>[32826.618414] md: recovery skipped: md2 <7>[32826.736840] RAID1 conf printout:<7>[32826.736851]  --- wd:2 rd:2<7>[32826.736859]  disk 0, wo:0, o:1, dev:sda3<7>[32826.736865]  disk 1, wo:0, o:1, dev:sdb3<7>[32826.836760] RAID1 conf printout:<7>[32826.836771]  --- wd:1 rd:2<7>[32826.836778]  disk 0, wo:0, o:1, dev:sda2<7>[32826.836784]  disk 1, wo:1, o:0, dev:sdb2<7>[32826.836790] RAID1 conf printout:<7>[32826.836795]  --- wd:1 rd:2<7>[32826.836800]  disk 0, wo:0, o:1, dev:sda2


    Dieses Log deutet darauf hin, dass beide Platten Probleme haben, wobei dies aber auch an einem unsauberen Reboot liegen kann.
    - Recovery der beiden Systempartitonen sda1 und sdb1

    Code
    <6>[   10.873508] EXT3-fs (sda1): recovery required on readonly filesystem<6>[   10.879910] EXT3-fs (sda1): write access will be enabled during recovery<6>[   11.109826] EXT3-fs (sda1): orphan cleanup on readonly fs<7>[   11.139072] ext3_orphan_cleanup: deleting unreferenced inode 6879<6>[   11.139351] EXT3-fs (sda1): 1 orphan inode deleted<6>[   11.157415] EXT3-fs (sda1): recovery complete<6>[   11.306530] EXT3-fs (sdb1): recovery required on readonly filesystem<6>[   11.312939] EXT3-fs (sdb1): write access will be enabled during recovery<6>[   11.502613] EXT3-fs (sdb1): orphan cleanup on readonly fs<7>[   11.514197] ext3_orphan_cleanup: deleting unreferenced inode 6879<6>[   11.514400] EXT3-fs (sdb1): 1 orphan inode deleted<6>[   11.527408] EXT3-fs (sdb1): recovery complete


    - Recovery des System-RAID md9

    Code
    <5>[   11.749397] md/raid1:md9: not clean -- starting background reconstruction


    - Recovery des Application-RAID md13

    Code
    <7>[   17.040006] ext3_orphan_cleanup: deleting unreferenced inode 2331<7>[   17.049519] ext3_orphan_cleanup: deleting unreferenced inode 1317<6>[   17.049547] EXT3-fs (md13): 2 orphan inodes deleted<6>[   17.167498] EXT3-fs (md13): recovery complete


    - Recovery des Daten-RAID md0

    Code
    <5>[   81.131905] md/raid1:md0: not clean -- starting background reconstruction<7>[   90.719951] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180788443<7>[   90.729833] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748395<7>[   90.729905] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748391<7>[   90.729957] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748390<7>[   90.730013] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748389<6>[   90.730052] EXT4-fs (md0): 5 orphan inodes deleted<6>[   90.807037] EXT4-fs (md0): recovery complete


    - Recovery des SWAP-RAID md2

    Code
    <6>[   86.116957] md: delaying recovery of md2 until md0 has finished (they share one or more physical units)


    wobei dies Aufgrund eines Laufwerksfehlers fehlschlägt

    Code
    <1>[  812.871104] md/raid1:md2: Disk failure on sdb2, disabling device.
    <1>[  812.871110] md/raid1:md2: Operation continuing on 1 devices.
    <4>[  814.897508] md: cannot remove active disk sdb2 from md2 ...
    <4>[  820.917361] raid1: some error occurred in a active device:0 of md2.
    <4>[  822.937342] md: cannot remove active disk sda2 from md2 ...
    <6>[32826.618414] md: recovery skipped: md2


    Soweit zum aktuellen Bootlog.
    --- Fortsetzung im nächsten Post ---

  • --- Fortsetzung ---


    Nun ein paar Anmerkungen zu den vorherigen Logs in kmsg.1.


    02.07.2014 01:12:16 UTC

    Code
    <6>[    8.582619] rtc-s35390a 0-0030: setting system clock to 2014-07-02 01:12:16 UTC (1404263536)<6>[    8.685698] ata1: SATA link down (SStatus 0 SControl F330)<6>[    9.035692] ata2: SATA link down (SStatus 0 SControl F330)<3>[   89.706428] ata1: exception Emask 0x10 SAct 0x0 SErr 0x4010000 action 0xe frozen<3>[   89.713859] ata1: edma_err_cause=00000010 pp_flags=00000000, dev connect<6>[   89.720625] ata1: hard resetting link<3>[   92.385774] ata2: exception Emask 0x10 SAct 0x0 SErr 0x4010000 action 0xe frozen<3>[   92.393201] ata2: edma_err_cause=00000010 pp_flags=00000000, dev connect<6>[   92.399960] ata2: hard resetting link<3>[   95.485725] ata1: SRST failed (errno=-16)<6>[   95.489753] ata1: hard resetting link<3>[   98.165714] ata2: SRST failed (errno=-16)<6>[   98.169742] ata2: hard resetting link<6>[   99.695713] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl F330)<6>[   99.895732] ata1.00: ATA-9: WDC WD30EFRX-68EUZN0, 80.00A80, max UDMA/133<6>[   99.902465] ata1.00: 5860533168 sectors, multi 0: LBA48 NCQ (depth 31/32)<6>[   99.925915] ata1.00: configured for UDMA/133<6>[   99.930212] ata1: EH complete<5>[   99.933433] scsi 0:0:0:0: Direct-Access     WDC      WD30EFRX-68EUZN0 80.0 PQ: 0 ANSI: 5<4>[   99.945951] Check proc_name[sata_mv].<5>[   99.958986] sd 0:0:0:0: [sda] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)<5>[   99.966798] sd 0:0:0:0: [sda] 4096-byte physical blocks<4>[   99.975994] Check proc_name[sata_mv].<5>[   99.992469] sd 0:0:0:0: Attached scsi generic sg0 type 0<5>[  100.005965] sd 0:0:0:0: [sda] Write Protect is off<7>[  100.010786] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00<5>[  100.013894] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA<6>[  100.089496]  sda: sda1 sda2<5>[  100.106540] sd 0:0:0:0: [sda] Attached SCSI disk<6>[  102.435709] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl F330)<6>[  102.655730] ata2.00: ATA-9: WDC WD30EFRX-68EUZN0, 80.00A80, max UDMA/133<6>[  102.662458] ata2.00: 5860533168 sectors, multi 0: LBA48 NCQ (depth 31/32)<6>[  102.685931] ata2.00: configured for UDMA/133<6>[  102.690231] ata2: EH complete<5>[  102.693429] scsi 1:0:0:0: Direct-Access     WDC      WD30EFRX-68EUZN0 80.0 PQ: 0 ANSI: 5<4>[  102.706012] Check proc_name[sata_mv].<5>[  102.716188] sd 1:0:0:0: [sdb] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)<5>[  102.723968] sd 1:0:0:0: [sdb] 4096-byte physical blocks<4>[  102.735964] Check proc_name[sata_mv].<5>[  102.752410] sd 1:0:0:0: Attached scsi generic sg1 type 0<5>[  102.768889] sd 1:0:0:0: [sdb] Write Protect is off<7>[  102.773709] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00<5>[  102.773788] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA<6>[  102.843595]  sdb: sdb1 sdb2<5>[  102.860847] sd 1:0:0:0: [sdb] Attached SCSI disk<6>[  120.699429]  sda:<6>[  120.868484]  sda: sda1<6>[  121.039086]  sda: sda1 sda2<6>[  121.246024]  sda: sda1 sda2 sda3<6>[  121.442789]  sda: sda1 sda2 sda3 sda4<6>[  121.714415] md: bind<sda1><6>[  121.724130] md/raid1:md9: active with 1 out of 1 mirrors<6>[  121.729680] md9: bitmap file is out of date (0 < 1) -- forcing full recovery<6>[  121.736778] created bitmap (65 pages) for device md9<6>[  121.741850] md9: bitmap file is out of date, doing full recovery<6>[  121.996818] md9: bitmap initialized from disk: read 5/5 pages, set 132512 of 132512 bits<6>[  122.035760] md9: detected capacity change from 0 to 542769152<6>[  123.078820]  md9:<6>[  129.708451] kjournald starting.  Commit interval 5 seconds<6>[  129.715885] EXT3-fs (md9): using internal journal<6>[  129.720609] EXT3-fs (md9): mounted filesystem with writeback data mode<6>[  130.944456] md: bind<sda4><6>[  130.950166] md/raid1:md13: active with 1 out of 2 mirrors<6>[  130.955756] md13: bitmap file is out of date (0 < 1) -- forcing full recovery<6>[  130.962921] created bitmap (57 pages) for device md13<6>[  130.968100] md13: bitmap file is out of date, doing full recovery<6>[  131.161817] md13: bitmap initialized from disk: read 4/4 pages, set 114720 of 114720 bits<6>[  131.186687] md13: detected capacity change from 0 to 469893120<6>[  136.248790]  md13: unknown partition table<4>[  140.039872] active port 0 :139<4>[  140.042942] active port 1 :445<4>[  140.046041] active port 2 :20<6>[  144.376102] md: bind<sda2><6>[  144.400697] md/raid1:md2: active with 1 out of 1 mirrors<6>[  144.406257] md2: detected capacity change from 0 to 542769152<6>[  145.435496]  md2: unknown partition table<6>[  147.555661] Adding 530044k swap on /dev/md2.  Priority:-1 extents:1 across:530044k <6>[  157.966248]  sdb:<6>[  158.078577]  sdb: sdb1<6>[  158.179266]  sdb: sdb1 sdb2<6>[  158.316100]  sdb: sdb1 sdb2 sdb3<6>[  158.483181]  sdb: sdb1 sdb2 sdb3 sdb4<6>[  158.751421] md: bind<sdb1><6>[  158.906605] md: recovery of RAID array md9<6>[  158.910897] md: minimum _guaranteed_	speed: 5000 KB/sec/disk.<6>[  158.916690] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for recovery.<6>[  158.926302] md: using 128k window, over a total of 530048k.<6>[  165.288330] md: bind<sdb4><6>[  165.328299] md: delaying recovery of md13 until md9 has finished (they share one or more physical units)<6>[  175.337502] md: bind<sdb2><6>[  175.377143] md: delaying recovery of md2 until md13 has finished (they share one or more physical units)<6>[  178.940582] md: md9: recovery done.<6>[  178.955188] md: delaying recovery of md2 until md13 has finished (they share one or more physical units)<6>[  178.964782] md: delaying recovery of md13 until md2 has finished (they share one or more physical units)<6>[  178.974676] md: recovery of RAID array md2<6>[  178.978933] md: minimum _guaranteed_	speed: 5000 KB/sec/disk.<6>[  178.984701] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for recovery.<6>[  178.994326] md: Recovering started: md2<6>[  178.998183] md: using 128k window, over a total of 530048k.<6>[  186.254590] md: md2: recovery done.<6>[  186.258511] md: Recovering done: md2, degraded=1<6>[  186.269049] md: recovery of RAID array md13<6>[  186.273587] md: minimum _guaranteed_	speed: 5000 KB/sec/disk.<6>[  186.280014] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for recovery.<6>[  186.290575] md: using 128k window, over a total of 458880k.<6>[  222.885776] md: md13: recovery done.<6>[  717.406048] md: bind<sda3><6>[  717.445993] md: bind<sdb3><5>[  717.451473] md/raid1:md0: not clean -- starting background reconstruction<6>[  717.458329] md/raid1:md0: active with 2 out of 2 mirrors<6>[  717.463725] md0: detected capacity change from 0 to 2998986297344<6>[  717.476535] md: resync of RAID array md0<6>[  717.480479] md: minimum _guaranteed_	speed: 5000 KB/sec/disk.<6>[  717.486272] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for resync.<6>[  717.495719] md: Resyncing started: md0<6>[  717.499484] md: using 128k window, over a total of 2928697556k.<6>[  759.462257]  md0: unknown partition table<4>[ 1425.350926] ext4_init_reserve_inode_table0: md0, 22345<4>[ 1425.356107] ext4_init_reserve_inode_table2: md0, 22345, 0, 0, 4096<6>[ 1425.362365] EXT4-fs (md0): mounted filesystem with ordered data mode. Opts: usrjquota=aquota.user,jqfmt=vfsv0,user_xattr,data=ordered,delalloc,noacl<6>[ 1425.686034] EXT4-fs (md0): re-mounted. Opts: (null)<6>[ 1425.735497] EXT4-fs (md0): re-mounted. Opts: (null)<6>[ 1434.286012] EXT4-fs (md0): re-mounted. Opts: (null)<6>[ 1434.334437] EXT4-fs (md0): re-mounted. Opts: (null)

    Hier wurde wohl das NAS ohne Platten gestartet und die Platten anschliessend eingeschoben. Das Recovery aller RAID's läuft ohne Probleme durch und md0 wird gemounted. Auffällig sind zwei Punkte:
    - das Swap md2 ist nach erfolgtem Recovery im degraded Mode

    Code
    <6>[  186.258511] md: Recovering done: md2, degraded=1


    - nach erfolgreichem Mount von md0 wird dieses mehrmals ohne Optionen re-mounted und anschliessend erfolgt ein Neustart. Nicht zu erkennen ist, ob der Neustart manuell erfolgte oder das System von sich aus neu startete.


    02.07.2014 01:40:58 UTC

    Code
    <6>[    8.284693] rtc-s35390a 0-0030: setting system clock to 2014-07-02 01:40:58 UTC (1404265258)<6>[  125.538970] md: recovery of RAID array md2<6>[  125.558623] md: Recovering started: md2<5>[  125.991189] md/raid1:md0: not clean -- starting background reconstruction<6>[  126.017546] md: delaying resync of md0 until md2 has finished (they share one or more physical units)<6>[  139.805775] md: md2: recovery done.<6>[  139.809460] md: Recovering done: md2, degraded=1<6>[  139.819733] md: resync of RAID array md0<6>[  139.838904] md: Resyncing started: md0<3>[61906.828844] ata1.00: exception Emask 0x10 SAct 0x1 SErr 0x100000 action 0x6 frozen<3>[61906.836453] ata1.00: edma_err_cause=02000020 pp_flags=00000003, SError=00100000<3>[61906.843833] ata1.00: cmd 60/00:00:08:51:bb/04:00:c0:00:00/40 tag 0 ncq 524288 in<3>[61906.843839]          res 40/00:04:08:51:bb/00:00:c0:00:00/40 Emask 0x10 (ATA bus error)<6>[61906.859447] ata1: hard resetting link<4>[61906.863146] Speed down due to signal issue.<4>[61906.867347] Speed down due to signal issue.<6>[61907.377863] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl F320)<6>[61907.418050] ata1.00: configured for UDMA/133<6>[61907.422518] ata1: EH complete<3>[61908.128779] ata1: exception Emask 0x10 SAct 0x0 SErr 0x100000 action 0x6 frozen<3>[61908.136125] ata1: edma_err_cause=00000020 pp_flags=00000000, SError=00100000<6>[61908.143234] ata1: hard resetting link<4>[61908.146938] Speed down due to signal issue.<4>[61908.151150] Speed down due to signal issue.<6>[61908.657885] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl F320)<6>[61908.698146] ata1.00: configured for UDMA/133<6>[61908.702445] ata1: EH complete<6>[61912.768246] usb 3-2: new SuperSpeed USB device number 2 using etxhci_hcd_140219<6>[61912.815185] scsi3 : usb-storage 3-2:1.0<5>[61913.828778] scsi 3:0:0:0: Direct-Access     ASMT     2105             0    PQ: 0 ANSI: 6<5>[61913.855668] sd 3:0:0:0: [sdr] Very big device. Trying to use READ CAPACITY(16).<5>[61913.875679] sd 3:0:0:0: Attached scsi generic sg17 type 0<5>[61913.897888] sd 3:0:0:0: [sdr] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)<5>[61913.910900] sd 3:0:0:0: [sdr] Write Protect is off<7>[61913.915717] sd 3:0:0:0: [sdr] Mode Sense: 43 00 00 00<5>[61913.916385] sd 3:0:0:0: [sdr] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA<5>[61913.945547] sd 3:0:0:0: [sdr] Very big device. Trying to use READ CAPACITY(16).<6>[61914.005178]  sdr: sdr1 sdr2<5>[61914.028631] sd 3:0:0:0: [sdr] Very big device. Trying to use READ CAPACITY(16).<5>[61914.052117] sd 3:0:0:0: [sdr] Attached SCSI disk<4>[61914.056763] [#] set usb polling mode (sdr)<4>[61914.801170] mount: sending ioctl 5310 to a partition!<4>[61914.806245] mount: sending ioctl 5310 to a partition!<6>[107763.558330] usb 3-2: reset SuperSpeed USB device number 2 using etxhci_hcd_140219<6>[107794.628347] usb 3-2: reset SuperSpeed USB device number 2 using etxhci_hcd_140219<6>[107825.588385] usb 3-2: reset SuperSpeed USB device number 2 using etxhci_hcd_140219<6>[107858.548337] usb 3-2: reset SuperSpeed USB device number 2 using etxhci_hcd_140219<6>[107889.588365] usb 3-2: reset SuperSpeed USB device number 2 using etxhci_hcd_140219<6>[107920.629652] usb 3-2: reset SuperSpeed USB device number 2 using etxhci_hcd_140219<6>[107951.588935] usb 3-2: reset SuperSpeed USB device number 2 using etxhci_hcd_140219<6>[107982.628326] usb 3-2: reset SuperSpeed USB device number 2 using etxhci_hcd_140219<6>[108013.588565] usb 3-2: reset SuperSpeed USB device number 2 using etxhci_hcd_140219<6>[108014.135713] sd 3:0:0:0: [sdr] Unhandled error code<6>[108014.140844] sd 3:0:0:0: [sdr]  Result: hostbyte=0x05 driverbyte=0x00<6>[108014.147639] sd 3:0:0:0: [sdr] CDB: cdb[0]=0x28: 28 00 05 fa b4 78 00 00 f0 00<3>[108014.155189] end_request: I/O error, dev sdr, sector 100316280<3>[108014.161064] Buffer I/O error on device sdr2, logical block 12488330<3>[108014.167452] Buffer I/O error on device sdr2, logical block 12488331<3>[108014.173843] Buffer I/O error on device sdr2, logical block 12488332<3>[108014.180230] Buffer I/O error on device sdr2, logical block 12488333<3>[108014.186614] Buffer I/O error on device sdr2, logical block 12488334<3>[108014.193007] Buffer I/O error on device sdr2, logical block 12488335<3>[108014.199458] Buffer I/O error on device sdr2, logical block 12488336<3>[108014.205842] Buffer I/O error on device sdr2, logical block 12488337<3>[108014.212232] Buffer I/O error on device sdr2, logical block 12488338<6>[108017.609631] sd 3:0:0:0: [sdr] Unhandled sense code<6>[108017.614532] sd 3:0:0:0: [sdr]  Result: hostbyte=0x00 driverbyte=0x08<6>[108017.621024] sd 3:0:0:0: [sdr]  Sense Key : 0x3 [current] <6>[108017.626556] sd 3:0:0:0: [sdr]  ASC=0x11 ASCQ=0x0<6>[108017.631300] sd 3:0:0:0: [sdr] CDB: cdb[0]=0x28: 28 00 05 fa b5 48 00 00 08 00<3>[108017.638661] end_request: critical target error, dev sdr, sector 100316488<6>[108021.120991] sd 3:0:0:0: [sdr] Unhandled sense code<6>[108021.125893] sd 3:0:0:0: [sdr]  Result: hostbyte=0x00 driverbyte=0x08<6>[108021.132389] sd 3:0:0:0: [sdr]  Sense Key : 0x3 [current] <6>[108021.137923] sd 3:0:0:0: [sdr]  ASC=0x11 ASCQ=0x0<6>[108021.142660] sd 3:0:0:0: [sdr] CDB: cdb[0]=0x28: 28 00 05 fa b5 48 00 00 08 00<3>[108021.150023] end_request: critical target error, dev sdr, sector 100316488<4>[108021.156927] quiet_error: 22 callbacks suppressed<3>[108021.161652] Buffer I/O error on device sdr2, logical block 12488356<6>[110395.568541] usb 3-2: USB disconnect, device number 2<6>[110395.587968] sd 3:0:0:0: [sdr] Unhandled error code<6>[110395.592892] sd 3:0:0:0: [sdr]  Result: hostbyte=0x01 driverbyte=0x00<6>[110395.599404] sd 3:0:0:0: [sdr] CDB: cdb[0]=0x28: 28 00 00 06 40 28 00 00 02 00<3>[110395.606771] end_request: I/O error, dev sdr, sector 409640<3>[110395.787774] end_request: I/O error, dev sdr, sector 0<5>[110395.836940] sd 3:0:0:0: [sdr] Synchronizing SCSI cache<6>[110395.857655] sd 3:0:0:0: [sdr]  Result: hostbyte=0x01 driverbyte=0x00<1>[110412.966228] Unable to handle kernel NULL pointer dereference at virtual address 00000150<1>[110412.974486] pgd = d1f70000<1>[110412.977289] [00000150] *pgd=0f41b831, *pte=00000000, *ppte=00000000<0>[110412.983701] Internal error: Oops: 17 [#1] ARM<4>[110412.988162] Modules linked in: iscsi_tcp(O) libiscsi_tcp(O) libiscsi(O) scsi_transport_iscsi(O) fbdisk(O) uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_core v4l2_common videodev v4l2_int_device snd_usb_caiaq snd_usb_audio hid_logitech snd_usbmidi_lib snd_hwdep snd_pcm_oss snd_mixer_oss snd_pcm snd_seq_oss snd_seq_midi snd_seq_midi_event snd_seq snd_rawmidi snd_page_alloc snd_seq_device snd_timer snd soundcore md4 ecb hmac mac80211 cfg80211 lib80211 fnotify(PO) etxhci_hcd xhci_hcd cifs nfsd exportfs nfs auth_rpcgss lockd sunrpc udf isofs thfsplus(O) tntfs(PO) ext4 jbd2 sysinfo(O) usblp usbhid cryptodev(O) mv_cesa sha512_generic sha256_generic sha1_generic aes_generic dm_crypt dm_mod raid456 async_raid6_recov async_pq async_xor async_memcpy async_tx raid6_pq xor raid0 linear nls_utf8 nls_iso8859_2 nls_cp850 nls_cp437 vfat fat appletalk psnap llc hal_netlink(O) hid ehci_hcd ext3 jbd<4>[110413.067944] CPU: 0    Tainted: P           O  (3.4.6 #1)<4>[110413.073373] PC is at get_dump_page+0x64/0xa8<4>[110413.077759] LR is at 0x1ffff1cb<4>[110413.080998] pc : [<c008ddfc>]    lr : [<1ffff1cb>]    psr: 20000013<4>[110413.081002] sp : c4257ce0  ip : 00000055  fp : c4257d0c<4>[110413.092707] r10: 00000000  r9 : 00000000  r8 : ffff1000<4>[110413.098035] r7 : 00000001  r6 : ffff0000  r5 : 00000000  r4 : ffff0000<4>[110413.104680] r3 : 00000000  r2 : c4257cf4  r1 : c0421e90  r0 : 00000001<4>[110413.111325] Flags: nzCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment kernel<4>[110413.118755] Control: 0005397f  Table: 11f70000  DAC: 00000017<0>[110413.124614] Process smbd (pid: 23586, stack limit = 0xc4256270)<0>[110413.130639] Stack: (0xc4257ce0 to 0xc4258000)<0>[110413.135100] 7ce0: 0000001c c4257cf0 c4257cf4 00000000 c085cfe0 c0421e90 ffff0000 c0421e90<0>[110413.143401] 7d00: c4257ddc c4257d10 c00eb8c4 c008dda8 c4257dac 01000000 00000000 c4256000<0>[110413.151702] 7d20: c4257e28 bf000000 c0421e90 dcd70b20 0000009c 00000264 d4b4aea0 dab8b6c0<0>[110413.160003] 7d40: dcdf6ac0 c02f349c 00000006 0000009c 00000000 dcc4e6e0 c037c148 00000003<0>[110413.168304] 7d60: 0000007c dab8b6c0 c037c148 00000006 00000090 dedea700 00000264 00000002<0>[110413.176607] 7d80: 00000001 000ef000 ffff0000 00000000 00001000 00001000 00000005 00001000<0>[110413.184908] 7da0: 00001618 00000000 53b4f650 000af3b4 53b4f650 c0405330 00000000 c4256000<0>[110413.193218] 7dc0: c4257e28 dedea660 c040570c 00000000 c4257e84 c4257de0 c00ab23c c00eab58<0>[110413.201520] 7de0: 00000000 c2c5be40 d39c2138 00000006 00000006 dedea660 c4ec5c20 c4ffcde0<0>[110413.209820] 7e00: 00000000 00000000 00000000 c4ffcde0 00000000 dcdf6ac0 00000000 00000000<0>[110413.218123] 7e20: c4257e20 c4257e20 00000006 c4257fb0 c2c5be40 01000000 0000008d dab8b0c0<0>[110413.226424] 7e40: 00000004 00000080 00000000 dcdf6cb8 c4257e8c c4257e60 c003d78c c4e1d570<0>[110413.234726] 7e60: 00000078 00000006 c4e1d5e8 c4256000 c4d05d40 c4257ee0 c4257ec4 c4257e88<0>[110413.243027] 7e80: c003e924 c00aad04 c003d8a4 c4257fb0 c4257f60 c4e1d580 c4257ecc c0010208<0>[110413.251329] 7ea0: b674aa54 c4257fb0 00000000 b674aa58 c4256000 00000001 c4257fac c4257ec8<0>[110413.259630] 7ec0: c0012b94 c003e6ec c003d97c c003d8bc 00000000 00005c22 dcdf6ac0 00000006<0>[110413.267931] 7ee0: 00000006 00000000 fffffffa 00005c22 00000000 c003bc78 c4257f50 dcdf6ac0<0>[110413.276233] 7f00: c4257f3c c4257f20 c003cd2c c003ccbc c003c450 c003bae8 dcdf6ac0 00000000<0>[110413.284535] 7f20: c4257f4c c4257f40 c003cdb8 c003cd04 c4257f6c c4257f50 c003ce44 c003cd98<0>[110413.292836] 7f40: 00001880 00000000 c4257f70 c4256000 c4257fa4 c4257f70 c003fb34 c003cdd8<0>[110413.301137] 7f60: c4257fa4 c4257f70 c003fb34 c003cdd8 00000020 00005c22 00000006 b684f000<0>[110413.309439] 7f80: 0000010c 00005c22 00000006 b684f000 0000010c 00000000 c4256000 00000000<0>[110413.317740] 7fa0: 00000000 c4257fb0 c00100b4 c0012abc 00000000 00005c22 00000006 b67104a0<0>[110413.326041] 7fc0: 00005c22 00000006 b684f000 0000010c 00000002 008defc0 b6710000 beca6fd4<0>[110413.334342] 7fe0: beca6e60 beca6ea8 b674aa00 b674aa58 20000010 00005c22 00000000 00000000<4>[110413.342638] Backtrace: <4>[110413.345194] [<c008dd98>] (get_dump_page+0x0/0xa8) from [<c00eb8c4>] (elf_core_dump+0xd7c/0xefc)<4>[110413.354019]  r5:c0421e90 r4:ffff0000<4>[110413.357713] [<c00eab48>] (elf_core_dump+0x0/0xefc) from [<c00ab23c>] (do_coredump+0x548/0xa08)<4>[110413.366453] [<c00aacf4>] (do_coredump+0x0/0xa08) from [<c003e924>] (get_signal_to_deliver+0x248/0x4bc)<4>[110413.375898] [<c003e6dc>] (get_signal_to_deliver+0x0/0x4bc) from [<c0012b94>] (do_notify_resume+0xe8/0x5b8)<4>[110413.385688] [<c0012aac>] (do_notify_resume+0x0/0x5b8) from [<c00100b4>] (work_pending+0x24/0x28)<0>[110413.394597] Code: e1500005 da00000f e51b1018 e5913000 (e5932150) <4>[110413.400886] ---[ end trace f8253175aeb4e3a6 ]---<6>[122812.907752] md: md0: resync done.<6>[122812.911200] md: Resyncing done: md0


    Hier startet das NAS mit dem Recovery von md2 welches wieder mit dem Status degraded endet.
    Ausserdem wird md0 resynced, da ein not clean erkannt wird. Während des Resync tritt als erstes ein Signalfehler an ata1 (Platte 1) auf. Kurz darauf wird ein USB-Laufwerk erkannt. Hier ligt die Vermutung nahe, dass die mechanische Signalleitungsverbindung zur Platte 1 nicht stabil ist und durch die Erschütterung beim Einstecken des USB-Laufwerks Kontaktfehler auftraten.
    Im weiteren Verlauf kommt es auf dem USB(3?)-Laufwerk zu Fehlern, welche auf eine Überlastung der USB-Stromversorgung hindeuten

    Code
    <6>[108017.609631] sd 3:0:0:0: [sdr] Unhandled sense code<6>[108017.614532] sd 3:0:0:0: [sdr]  Result: hostbyte=0x00 driverbyte=0x08<6>[108017.621024] sd 3:0:0:0: [sdr]  Sense Key : 0x3 [current]

    und zu einem Kernel Fehler führen

    Code
    <1>[110412.966228] Unable to handle kernel NULL pointer dereference at virtual address 00000150<1>[110412.974486] pgd = d1f70000<1>[110412.977289] [00000150] *pgd=0f41b831, *pte=00000000, *ppte=00000000<0>[110412.983701] Internal error: Oops: 17 [#1] ARM


    All dies wärend des Resync von md0, welches abgeschlossen wird und anschliessend ein Neustart erfolgt.
    Diese Neustarts weisen dann alle ähnliche Fehler auf wie:
    - Fehlerhafte Zuweisung von Inodes (orphan inodes)
    - Disk failure beim Recovern des Swap-RAID md2 was dazu führt, dass md2 Recovery nicht erfolgt (skipped) und somit dem NAS kein bzw. unzuverlässiger virtueller Speicher zur Verfügung steht, was wiederum zu den Abstürzen beim Kopieren grosser Datenmengen führen kann/führt.


    Code
    <6>[    7.670514] rtc-s35390a 0-0030: setting system clock to 2014-07-03 18:45:11 UTC (1404413111)<6>[   10.741037] EXT3-fs (sda1): recovery required on readonly filesystem<6>[   10.747439] EXT3-fs (sda1): write access will be enabled during recovery<6>[   11.153434] EXT3-fs (sda1): orphan cleanup on readonly fs<7>[   11.158864] ext3_orphan_cleanup: deleting unreferenced inode 6815<7>[   11.158961] ext3_orphan_cleanup: deleting unreferenced inode 6816<6>[   11.158992] EXT3-fs (sda1): 2 orphan inodes deleted<6>[   11.174742] EXT3-fs (sda1): recovery complete<6>[   11.244906] EXT3-fs (sdb1): recovery required on readonly filesystem<6>[   11.251286] EXT3-fs (sdb1): write access will be enabled during recovery<6>[   11.587269] EXT3-fs (sdb1): orphan cleanup on readonly fs<7>[   11.592701] ext3_orphan_cleanup: deleting unreferenced inode 6815<7>[   11.592778] ext3_orphan_cleanup: deleting unreferenced inode 6816<6>[   11.592810] EXT3-fs (sdb1): 2 orphan inodes deleted<6>[   11.603751] EXT3-fs (sdb1): recovery complete<7>[   17.219464] ext3_orphan_cleanup: deleting unreferenced inode 2095<7>[   17.219684] ext3_orphan_cleanup: deleting unreferenced inode 1965<6>[   17.219711] EXT3-fs (md13): 2 orphan inodes deleted<6>[   17.344031] EXT3-fs (md13): recovery complete<5>[   73.541751] md/raid1:md0: not clean -- starting background reconstruction<6>[   73.567636] md: resync of RAID array md0<6>[   73.586876] md: Resyncing started: md0<6>[   78.413227] md: delaying recovery of md2 until md0 has finished (they share one or more physical units)<7>[   84.766648] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180788443<7>[   84.776684] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748395<7>[   84.776755] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748391<7>[   84.776802] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748390<7>[   84.776854] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748389<6>[   84.776890] EXT4-fs (md0): 5 orphan inodes deleted<6>[   84.863573] EXT4-fs (md0): recovery complete


    Code
    <6>[    7.689107] rtc-s35390a 0-0030: setting system clock to 2014-07-03 18:51:56 UTC (1404413516)<6>[   10.738285] EXT3-fs (sda1): recovery required on readonly filesystem<6>[   10.744694] EXT3-fs (sda1): write access will be enabled during recovery<6>[   10.846497] EXT3-fs (sda1): orphan cleanup on readonly fs<7>[   10.851929] ext3_orphan_cleanup: deleting unreferenced inode 6819<6>[   10.852012] EXT3-fs (sda1): 1 orphan inode deleted<6>[   10.862803] EXT3-fs (sda1): recovery complete<6>[   10.935032] EXT3-fs (sdb1): recovery required on readonly filesystem<6>[   10.941414] EXT3-fs (sdb1): write access will be enabled during recovery<6>[   11.087771] EXT3-fs (sdb1): orphan cleanup on readonly fs<7>[   11.093222] ext3_orphan_cleanup: deleting unreferenced inode 6819<6>[   11.116134] EXT3-fs (sdb1): 1 orphan inode deleted<6>[   11.145441] EXT3-fs (sdb1): recovery complete<7>[   17.677781] ext3_orphan_cleanup: deleting unreferenced inode 2268<7>[   17.677834] ext3_orphan_cleanup: deleting unreferenced inode 2343<6>[   17.677857] EXT3-fs (md13): 2 orphan inodes deleted<6>[   17.793366] EXT3-fs (md13): recovery complete<5>[   69.086086] md/raid1:md0: not clean -- starting background reconstruction<6>[   69.111836] md: resync of RAID array md0<6>[   69.131018] md: Resyncing started: md0<6>[   76.472505] md: delaying recovery of md2 until md0 has finished (they share one or more physical units)<7>[   81.513877] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180788443<7>[   81.524219] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748395<7>[   81.524313] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748391<7>[   81.524365] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748390<7>[   81.524426] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748389<6>[   81.524466] EXT4-fs (md0): 5 orphan inodes deleted<6>[   81.602595] EXT4-fs (md0): recovery complete<1>[ 5120.577321] md/raid1:md2: Disk failure on sdb2, disabling device.<1>[ 5120.577328] md/raid1:md2: Operation continuing on 1 devices.<4>[ 5122.657031] md: cannot remove active disk sdb2 from md2 ...<4>[ 5122.799551] raid1: some error occurred in a active device:0 of md2.<4>[ 5124.862372] md: cannot remove active disk sda2 from md2 ...<6>[51570.682536] md: md0: resync done.<6>[51570.685870] md: Resyncing done: md0<6>[51570.710874] md: recovery skipped: md2


    Code
    <6>[    7.748543] rtc-s35390a 0-0030: setting system clock to 2014-07-05 00:41:46 UTC (1404520906)<6>[   10.808395] EXT3-fs (sda1): recovery required on readonly filesystem<6>[   10.814797] EXT3-fs (sda1): write access will be enabled during recovery<6>[   10.974975] EXT3-fs (sda1): orphan cleanup on readonly fs<7>[   10.986869] ext3_orphan_cleanup: deleting unreferenced inode 6775<6>[   10.987159] EXT3-fs (sda1): 1 orphan inode deleted<6>[   11.001775] EXT3-fs (sda1): recovery complete<6>[   11.167938] EXT3-fs (sdb1): recovery required on readonly filesystem<6>[   11.174352] EXT3-fs (sdb1): write access will be enabled during recovery<6>[   11.369439] EXT3-fs (sdb1): orphan cleanup on readonly fs<7>[   11.393405] ext3_orphan_cleanup: deleting unreferenced inode 6775<6>[   11.393680] EXT3-fs (sdb1): 1 orphan inode deleted<6>[   11.402355] EXT3-fs (sdb1): recovery complete<5>[   11.606519] md/raid1:md9: not clean -- starting background reconstruction<6>[   11.667252] md: resync of RAID array md9<6>[   12.051599] md: md9: resync done.<7>[   16.992098] ext3_orphan_cleanup: deleting unreferenced inode 2331<7>[   16.992150] ext3_orphan_cleanup: deleting unreferenced inode 2267<6>[   16.992173] EXT3-fs (md13): 2 orphan inodes deleted<6>[   17.072351] EXT3-fs (md13): recovery complete<5>[   74.189265] md/raid1:md0: not clean -- starting background reconstruction<6>[   74.215039] md: resync of RAID array md0<6>[   74.234219] md: Resyncing started: md0<6>[   81.651602] md: delaying recovery of md2 until md0 has finished (they share one or more physical units)<7>[   86.490471] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180788443<7>[   86.500345] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748395<7>[   86.500421] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748391<7>[   86.500473] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748390<7>[   86.500532] EXT4-fs (md0): ext4_orphan_cleanup: deleting unreferenced inode 180748389<6>[   86.500572] EXT4-fs (md0): 5 orphan inodes deleted<6>[   86.590738] EXT4-fs (md0): recovery complete<1>[  985.381363] md/raid1:md2: Disk failure on sdb2, disabling device.<1>[  985.381369] md/raid1:md2: Operation continuing on 1 devices.<4>[  987.478759] md: cannot remove active disk sdb2 from md2 ...<4>[  987.661328] raid1: some error occurred in a active device:0 of md2.<4>[  989.701916] md: cannot remove active disk sda2 from md2 ...



    Was kannst du tun:
    - als Erstes überprüfe den korrekten Sitz der Platten/Kabelverbindungen zur Platte
    - da der Bereich, in dem die Swap-Partition liegt, wohl Fehler aufweisst, überprüfe die Platten mit einem Herstellertool auf fehlerhafte Sektoren
    - da das System in diesem Zustand wohl nicht vernünftig wiederhergestellt werden kann, am besten beide Platten komplett leeren (Partitionen löschen) und das System neu aufsetzen
    - sollte der Fehler weiterhin bestehen, kontaktiere den QNAP Support über das Online-Formular und verweise auf dieses Thema

  • Wow. Vielen Dank schon einmal für deine Mühen! Das ist beileibe nicht selbstverständlich. :thumb:


    Zitat

    als Erstes überprüfe den korrekten Sitz der Platten/Kabelverbindungen zur Platte


    Wie muss ich mir das vorstellen? Ich habe die Platten im Schacht festgeschraubt. Die Plattenschächte sitzen zumindest richtig, da sie eingerastet sind. Um die korrekte Kabelverbindung zu prüfen müsste ich den NAS aufschrauben, korrekt?


    Zitat

    - da der Bereich, in dem die Swap-Partition liegt, wohl Fehler aufweisst, überprüfe die Platten mit einem Herstellertool auf fehlerhafte Sektoren
    - da das System in diesem Zustand wohl nicht vernünftig wiederhergestellt werden kann, am besten beide Platten komplett leeren (Partitionen löschen) und das System neu aufsetzen


    Das Protokoll startet nach einem kompletten Reset des NAS. Die Festplatte im Schacht 1 ist dabei komplett neu. Nach dem Reset habe ich daraufhin via USB alle Dateien wieder auf den NAS kopiert und das klappte sehr gut. Nur wenn es via Netzwerk geht gibt es Probleme.
    Aber um deinen Ratschlag zu folgen sollte ich das komplette System besser komplett neu aufsetzen?


    Zitat

    - sollte der Fehler weiterhin bestehen, kontaktiere den QNAP Support über das Online-Formular und verweise auf dieses Thema


    Ich habe den Support schon kontaktiert und werde auf diesen Thread verweisen. Vielen Dank noch einmal!

  • Zitat von "TheMcLusky"

    Um die korrekte Kabelverbindung zu prüfen müsste ich den NAS aufschrauben, korrekt?


    Nein, ich kenne das HS210 nicht. Daher der Schrägstrich Platten vs Kabel. ;)


    Zitat von "TheMcLusky"

    Ich habe die Platten im Schacht festgeschraubt.


    Eventuell die Plattenschrauben leicht lösen, die Platten in Richtung Anschlüsse drücken und wieder festschrauben, um Toleranzfehler zu minimieren.


    Zitat von "TheMcLusky"

    sollte ich das komplette System besser komplett neu aufsetzen?


    So war es gemeint - ja.


    Zitat von "TheMcLusky"

    Vielen Dank noch einmal!


    Bitteschön!

  • Ich werde mich am Ende der Woche mal dran wagen. Dann sollte auch meine Backupfestplatte wieder bei mir sein (nach erfolgreicher Reklamation bei WD). Mal schauen ob ich eine Verbessung erreichen kann. Ansonsten wird das Ding zwecks Reparatur/Austausch eingeschickt.


    Danke an alle die mir bis dato geholfen haben!

  • Hallo Zusammen,


    ich habe seit dem Upgrade auf die FW 4.1 auf meiner TS-412 genau das gleiche Problem. Immer wenn ich größere Datenmengen kopiere, boote das Gerät selbstständig neu und kommt hinterher mit den gleichen Fehlermeldungen wie von TheMcLusky beschrieben wieder hoch.


    Da eine FP (RAID 1) SMART Fehler aufwies, habe ich beide Platten (vorher WD Green 2,5 TB, jetzt WD Red 3 TB) getauscht und das System komplett neu aufgesetzt. Beim Kopieren der Backup-Daten traten dann die gleichen Fehler wieder auf.


    Bevor ich jetzt ein neues NAS von der Konkurrenz kaufe, die Frage an TheMcLusky: Konnte der QNAP-Support Dir helfen?


    Danke für eine kurze Rückmeldung!