nicht angemeldet
Hallo Leute,
vor ein paar Tagen ist der apache auf einem meiner Webserver verreckt und der Server musste neu gestartet werden. Ich würde gerne genau wissen was passiert ist und habe die Logs nach Hinweisen durchsucht. In den apache logs steht überhaupt nichts Interessantes, bis auf die Lücke wo der apache nicht erreichbar war. In dem messages Logs stehen allerdings schon ein paar Sachen, die folgende Fragen aufwerfen.
Hier sieht man wie mein selbst gestricktes Backup Skript vom cron gestartet wird. Das Skript versucht einfach alles ab / zu targzen. Direkt darauf folgen ein paar Meldungen über cdrom open failed und mount failures. Ich bin 100% sicher, dass die Fehlermeldungen zur selben Zeit entstehen wie das tar Programm abläuft. Was kann ich machen, um diese Fehler zu vermeiden? Warum passiert sowas überhaupt bei einem einfachen Lesezugriff?
Jun 7 03:00:01 shop /usr/sbin/cron[27921]: (root) CMD (nice /backup/backup.sh)
Jun 7 03:07:21 shop submountd: resmgr: server response code 200
Jun 7 03:07:21 shop kernel: cdrom: open failed.
Jun 7 03:07:21 shop submountd: resmgr: server response code 200
Jun 7 03:07:21 shop kernel: cdrom: open failed.
Jun 7 03:07:21 shop submountd: mount failure, No medium found
Jun 7 03:07:21 shop kernel: subfs: unsuccessful attempt to mount media (256)
Jun 7 03:07:21 shop submountd: resmgr: server response code 200
Jun 7 03:07:21 shop kernel: end_request: I/O error, dev fd0, sector 0
Jun 7 03:07:21 shop submountd: resmgr: server response code 200
Jun 7 03:07:21 shop kernel: end_request: I/O error, dev fd0, sector 0
Jun 7 03:07:21 shop submountd: resmgr: server response code 200
Jun 7 03:07:21 shop submountd: mount failure, No such device or address
Jun 7 03:07:21 shop kernel: end_request: I/O error, dev fd0, sector 0
Jun 7 03:07:21 shop kernel: subfs: unsuccessful attempt to mount media (256)
Ich bin ziemlich sicher, dass der Ausfall mit diesem Backup Skript in Verbindung steht. Ich habe ihn einmal testweise manuell gestartet und das ist dabei rausgekommen:
Jun 7 13:25:05 shop sshd[29891]: Accepted keyboard-interactive/pam for marcell from ::ffff:87.78.201.18 port 1069
Jun 7 13:25:12 shop su: (to root) marcell on /dev/pts/0
Jun 7 13:25:12 shop su: pam_unix2: session started for user root, service su
Jun 7 13:27:05 shop crontab[29927]: (root) LIST (root)
Jun 7 13:35:00 shop submountd: resmgr: server response code 200
Jun 7 13:35:00 shop kernel: cdrom: open failed.
Jun 7 13:35:00 shop submountd: resmgr: server response code 200
Jun 7 13:35:00 shop kernel: cdrom: open failed.
Jun 7 13:35:00 shop submountd: mount failure, No medium found
Jun 7 13:35:00 shop kernel: subfs: unsuccessful attempt to mount media (256)
Jun 7 13:35:00 shop submountd: resmgr: server response code 200
Jun 7 13:35:02 shop kernel: Badness in out_of_memory at mm/oom_kill.c:235
Jun 7 13:35:02 shop kernel: [<c01463a9>] out_of_memory+0x39/0x130
Jun 7 13:35:02 shop kernel: [<c014f5c6>] try_to_free_pages+0x196/0x1a0
Jun 7 13:35:02 shop kernel: [<c0147700>] __alloc_pages+0x290/0x3c0
Jun 7 13:35:02 shop kernel: [<c010a380>] request_irq+0x80/0xd0
[... usw ...]
Es kommt jede Menge von diesem Zeug. Out of memory wird mir subtil klar, aber genaueres sagt mir das alles nicht. Welcher Prozess hat das verursacht sehe ich z.B. konkret nicht? Und dazwischen dann auch nochmal sowas:
Jun 7 13:35:06 shop kernel: [<c018042b>] sys_mount+0x9b/0x120
Jun 7 13:35:06 shop kernel: [<c0107029>] sysenter_past_esp+0x52/0x79
Jun 7 13:35:06 shop kernel: oom-killer: gfp_mask=0xd1
Jun 7 13:35:06 shop kernel: DMA per-cpu:
Jun 7 13:35:06 shop kernel: cpu 0 hot: low 2, high 6, batch 1
Jun 7 13:35:06 shop kernel: cpu 0 cold: low 0, high 2, batch 1
Jun 7 13:35:06 shop kernel: cpu 1 hot: low 2, high 6, batch 1
Jun 7 13:35:06 shop kernel: cpu 1 cold: low 0, high 2, batch 1
Jun 7 13:35:06 shop kernel: Normal per-cpu:
Jun 7 13:35:06 shop kernel: cpu 0 hot: low 32, high 96, batch 16
Jun 7 13:35:06 shop kernel: cpu 0 cold: low 0, high 32, batch 16
Jun 7 13:35:06 shop kernel: cpu 1 hot: low 32, high 96, batch 16
Jun 7 13:35:06 shop kernel: cpu 1 cold: low 0, high 32, batch 16
Jun 7 13:35:06 shop kernel: HighMem per-cpu:
Jun 7 13:35:06 shop kernel: cpu 0 hot: low 14, high 42, batch 7
Jun 7 13:35:06 shop kernel: cpu 0 cold: low 0, high 14, batch 7
Jun 7 13:35:06 shop kernel: cpu 1 hot: low 14, high 42, batch 7
Jun 7 13:35:06 shop kernel: cpu 1 cold: low 0, high 14, batch 7
Jun 7 13:35:06 shop kernel:
Jun 7 13:35:06 shop kernel: Free pages: 513792kB (81452kB HighMem)
Jun 7 13:35:06 shop kernel: Active:12121 inactive:108233 dirty:0 writeback:0 unstable:0 free:128448 slab:7067 mapped:8258 pagetables:202
Jun 7 13:35:06 shop kernel: DMA free:5652kB min:16kB low:32kB high:48kB active:1788kB inactive:1860kB present:16384kB
Jun 7 13:35:06 shop kernel: protections[]: 0 0 0
Jun 7 13:35:06 shop kernel: Normal free:426688kB min:936kB low:1872kB high:2808kB active:31036kB inactive:403768kB present:901120kB
Jun 7 13:35:06 shop kernel: protections[]: 0 0 0
Jun 7 13:35:06 shop kernel: HighMem free:81452kB min:128kB low:256kB high:384kB active:15660kB inactive:27304kB present:130496kB
Jun 7 13:35:06 shop kernel: protections[]: 0 0 0
Jun 7 13:35:06 shop kernel: DMA: 795*4kB 247*8kB 31*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 5652kB
Jun 7 13:35:06 shop kernel: Normal: 29926*4kB 22625*8kB 6636*16kB 557*32kB 7*64kB 2*128kB 3*256kB 1*512kB 0*1024kB 0*2048kB 0*4096kB = 426688kB
Jun 7 13:35:06 shop kernel: HighMem: 5649*4kB 3795*8kB 1341*16kB 210*32kB 5*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 81452kB
Jun 7 13:35:06 shop kernel: Swap cache: add 10997123, delete 10992670, find 24587286/25016155, race 49+1183
Was ist das und warum kam es in den Log? Und dann steht da noch stellenweise:
Jun 7 13:35:06 shop kernel: Out of Memory: Killed process 28777 (httpd2-prefork).
Das wird wohl der Grund sein warum der apache danach nicht mehr lief.
Und die wichtigste Frage überhaupt ist: Wie ist der Speicherüberlauf zur Stande gekommen? Das Backup Skript läuft seit zwei Jahren wunderbar und lief auch noch 4 Stunden vor diesem Vorfall durch. Jetzt habe ich es einmal manuell gestartet (trotzdem mit nice!) und dann fliegt es mir so um die Ohren. Ich bin etwas ratlos was ich machen soll, um sicher zu sein, dass das nicht mehr passiert.
Gruß,
Cruz