PowerPC (ppc_85xx) Werden RAID Reperaturen irgendwo geloggt?

[jahlives]

Gestern ist mir mitten während der Arbeit die DS408 (RAID5) abgeschmiert. Kein Service war mehr zu erreichen und die Festplatten ratterten die ganze Zeit. Also beherzt mal den Power Button gedrückt bis der Pieps kam und dann musste ich sicher 15 Minuten warten ehe die DS runtergefahren war. Auch der folgende Start ging eine Ewigkeit. Zwar hat die DS relativ schnell den "ich bin bereit Pieps" hören lassen, aber auf den Platten wurde permanent rumgeschrieben/gelesen. Der DSM funzte zwar, aber sobald ich auf Volume oder HD-Verwaltung klickte ging rein gar nichts mehr.
Danach die DS wieder runtergefahren was wiederum sicherlich 10 Minuten dauerte und die DS neugestartet. Nach dem Neustart sicherlich 30 Minuten gewartet und dann haben sich die HD-LEDs wieder beruhigt und die DS war wieder normal erreichbar.
Kann es sein, dass diese Schreibzugriffe den Zweck hatten den RAID zu reparieren? In den Logs habe ich nix gefunden und auch die Volume Verwaltung zeigte danach keinerlei Probleme. Werden solche automatischen Reperaturen irgendwo geloggt?

 

[Supaman]

wenn defekte sektoren seitens der synology repariert werden, steht das auch im log. wenn es plattenintern abläuft, natürlich nicht.

 

[jahlives]

wenn defekte sektoren seitens der synology repariert werden, steht das auch im log. wenn es plattenintern abläuft, natürlich nicht.

Da ich in den Logs nichts gefunden habe würde das heissen, dass es Platten- resp RAID-intern gemacht wurde?

 

[itari]

Werden solche automatischen Reperaturen irgendwo geloggt?

Welche log-level fährst denn? (/etc/syslog.deny)
Was sagt dmesg?

Itari

 

[jahlives]

Welche log-level fährst denn? (/etc/syslog.deny)
Was sagt dmesg?

Itari

dmesg habe ich noch nicht probiert. Werde ich mir heute Abend mal anschauen.
Logmässig sollte eigentlich jede Bewegung auf der DS mitgeschnitten werden. Ich verwende syslog-ng und der schreibt echt alles mit. Werde aber heute abend mal noch schauen ob ggf ein spezielles Logfile für RAID Sachen verwendet wird. Im syslog habe ich auf jeden Fall soweit nix gefunden.

 

[jahlives]

Also zum ersten habe ich das falsche Log File angeschaut. kern.log zeigt folgende Meldungen:

Jun 4 15:28:37 home postgres invoked oom-killer: gfp_mask=0x1201d2, order=0, oomkilladj=0
Jun 4 15:28:38 home Call Trace:
Jun 4 15:28:38 home [bbea9c50] [a000705c] show_stack+0x48/0x19c (unreliable)
Jun 4 15:28:38 home [bbea9c80] [a005aa74] oom_kill_process+0x11c/0x124
Jun 4 15:28:38 home [bbea9ca0] [a005ac80] out_of_memory+0x114/0x1f4
Jun 4 15:28:38 home [bbea9ce0] [a005d0ac] __alloc_pages+0x290/0x318
Jun 4 15:28:38 home [bbea9d30] [a005f494] __do_page_cache_readahead+0xf4/0x250
Jun 4 15:28:38 home [bbea9d70] [a0057638] filemap_fault+0x2f4/0x3b4
Jun 4 15:28:38 home [bbea9db0] [a00671fc] __do_fault+0x7c/0x418
Jun 4 15:28:38 home [bbea9e20] [a0067ab0] handle_mm_fault+0x3ec/0x6b4
Jun 4 15:28:51 home [bbea9e70] [a00112e8] do_page_fault+0x27c/0x4d0
Jun 4 15:28:51 home [bbea9f40] [a000e690] handle_page_fault+0xc/0x80
Jun 4 15:28:51 home Mem-info:
Jun 4 15:28:51 home DMA per-cpu:
Jun 4 15:28:51 home CPU 0: Hot: hi: 186, btch: 31 usd: 182 Cold: hi: 62, btch: 15 usd: 61
Jun 4 15:28:51 home Active:60017 inactive:59843 dirty:0 writeback:0 unstable:0
Jun 4 15:28:51 home free:1031 slab:1781 mapped:19 pagetables:575 bounce:0
Jun 4 15:28:51 home DMA free:4124kB min:4096kB low:8192kB high:16384kB active:240068kB inactive:239372
kB present:520192kB pages_scanned:764688 all_unreclaimable? yes
Jun 4 15:28:51 home lowmem_reserve[]: 0 0 0
Jun 4 15:28:51 home DMA: 39*4kB 4*8kB 0*16kB 1*32kB 1*64kB 0*128kB 1*256kB 1*512kB 1*1024kB 1*2048kB 0
*4096kB = 4124kB
Jun 4 15:28:51 home Swap cache: add 140107, delete 140107, find 3579/4672, race 0+0
Jun 4 15:28:51 home Free swap = 0kB
Jun 4 15:28:51 home Total swap = 522040kB
Jun 4 15:28:51 home Free swap: 0kB
Jun 4 15:28:51 home 131072 pages of RAM
Jun 4 15:28:51 home 2027 reserved pages
Jun 4 15:28:51 home 1148 pages shared
Jun 4 15:28:51 home 0 pages swap cached
Jun 4 15:28:51 home Out of memory: kill process 1885 (postgres) score 8627 or a child
Jun 4 15:28:51 home Killed process 1885 (postgres)
Jun 4 15:30:10 home cron invoked oom-killer: gfp_mask=0x1201d2, order=0, oomkilladj=0
Jun 4 15:30:10 home Call Trace:
Jun 4 15:30:10 home [a0c35b50] [a000705c] show_stack+0x48/0x19c (unreliable)
Jun 4 15:30:10 home [a0c35b80] [a005aa74] oom_kill_process+0x11c/0x124
Jun 4 15:30:10 home [a0c35ba0] [a005ac80] out_of_memory+0x114/0x1f4
Jun 4 15:30:10 home [a0c35be0] [a005d0ac] __alloc_pages+0x290/0x318
Jun 4 15:30:10 home [a0c35c30] [a005f494] __do_page_cache_readahead+0xf4/0x250
Jun 4 15:30:10 home [a0c35c70] [a0057638] filemap_fault+0x2f4/0x3b4
Jun 4 15:30:10 home [a0c35cb0] [a00671fc] __do_fault+0x7c/0x418
Jun 4 15:30:10 home [a0c35d20] [a0067ab0] handle_mm_fault+0x3ec/0x6b4
Jun 4 15:30:11 home [a0c35d70] [a00112e8] do_page_fault+0x27c/0x4d0
Jun 4 15:30:11 home [a0c35e40] [a000e690] handle_page_fault+0xc/0x80
Jun 4 15:30:11 home [a0c35f00] [a0083be8] getname+0x28/0xd8
Jun 4 15:30:11 home [a0c35f20] [a0079c2c] do_sys_open+0x24/0x110
Jun 4 15:30:11 home [a0c35f40] [a000e250] ret_from_syscall+0x0/0x3c

mit diesen Speicherproblemen scheint alles angefangen zu haben. Die wiederholen sich regelmässig wieder und jedesmal wurde ein anderer Prozess abgeschossen.
Später kamen Meldungen des RAID

Jun 4 15:43:09 home md: linear personality registered for level -1
Jun 4 15:43:09 home md: raid0 personality registered for level 0
Jun 4 15:43:09 home md: raid1 personality registered for level 1
Jun 4 15:43:09 home md: raid6 personality registered for level 6
Jun 4 15:43:09 home md: raid5 personality registered for level 5
Jun 4 15:43:09 home md: raid4 personality registered for level 4
Jun 4 15:43:09 home md: Autodetecting RAID arrays.
Jun 4 15:43:09 home md: Scanned 12 and added 12 devices.
Jun 4 15:43:09 home md: autorun ...
Jun 4 15:43:09 home md: considering sda1 ...
Jun 4 15:43:09 home md: adding sda1 ...
Jun 4 15:43:09 home md: sda2 has different UUID to sda1
Jun 4 15:43:09 home md: sda3 has different UUID to sda1
Jun 4 15:43:09 home md: adding sdb1 ...
Jun 4 15:43:09 home md: sdb2 has different UUID to sda1
Jun 4 15:43:09 home md: sdb3 has different UUID to sda1
Jun 4 15:43:09 home md: adding sdc1 ...
Jun 4 15:43:09 home md: sdc2 has different UUID to sda1
Jun 4 15:43:09 home md: sdc3 has different UUID to sda1
Jun 4 15:43:09 home md: adding sdd1 ...
Jun 4 15:43:09 home md: sdd2 has different UUID to sda1
Jun 4 15:43:09 home md: sdd3 has different UUID to sda1

dmesg erwähnt die Speicherfehler auch und ebenfalls die Prozesse die abgeschossen wurden. free meldet aktuell 32MB freien Speicher und 470MB Platz in Swap. Alle Fehlermeldungen hören um 16:30 auf. Zu dieser Zeit ungefähr haben die HD-LEDs und die Schreibgeräusche der Platten aufgehört. Per heute sind keinerlei solche Meldungen mehr in den Logs zu finden.
Sollte ich da mal Synology ranlassen oder war das nur ein einmaliges Ereignis? Oder kennt jemand solche Fehlermeldungen und deren Ursachen? Mir sagt das nichts, erklärt aber wenigstens warum die Prozesse one-by-one nicht mehr erreichbar waren. Muss vielleicht noch anfügen, dass die DS bis gestern 59 Tage durchgelaufen ist.

Danke für jeden Tipp

tobi

 

[itari]

Lass doch den Synology-Support mal ran ... wäre doch interessant mal zu sehen, warum nach 59 Tagen (wenn du nichts an dem System geändert hast) da auf einmal ein Problem auftritt.

Itari

 

[jahlives]

Sorry, dass ich mich erst jetzt wieder dazu melde. Wie es scheint treten diese Speicherfehler bei jedem Neustart auf. Am WE nach dem "ich bin bereit"-Beep mit free mal den Speicher angeschaut: RAM randvoll und Swap zu 99% gefüllt. Immer werden andere Prozesse abgeschossen. Sobald die HD LEDs zur Ruhe kommen geht auch der Speicherverbrauch wieder in den grünen Bereich (ca 230 MB frei)
Werde mich heute mal an Synology wenden.