Hallo,
ich hatte am Sonntag beim Fernsehen das Problem, dass der VDR auf einmal nicht mehr auf die Fernbedienung reagieren wollte und die Festplatte die ganze Zeit arbeitete.
Top zeigte an, dass ein noad-Prozess auf über 150Mb angewachsen war, blieb dann aber stehen. Da der Rechner auch nicht mehr auf Tastatur eingaben reagierte, war ich schon am überlegen, ob ich ihn ausschalte. Als plötzlich die Festplatte zu rattern aufhörte und auch der VDR wieder funktionierte.
Etwas später habe ich dann festgestellt, dass der Rechner nicht über das Netzwerk erreichbar war, VDR lief aber noch immer einwandfrei.
Ein Blick in die Logfile brachte folgendes zu Tage:
(/var/log/messages (gekürzt))
Jun 4 18:10:00 vdr vdr: [1950] timer 5 (7 1630-1810 'Busters - Die Wissensjäger') stop
Jun 4 18:10:00 vdr vdr: [1950] executing '/opt/vdr/bin/noad --OSD --backupmarks --asd --statisticfile=/media/video/noadstat after "/media/video/Busters_-_Die_Wissensjäger/_/2006-06-04.16.30.30.05.rec"'
Jun 4 18:10:01 vdr noad[10521]: noad arg[0]: /opt/vdr/bin/noad
Jun 4 18:10:01 vdr noad[10521]: noad arg[1]: --OSD
Jun 4 18:10:01 vdr noad[10521]: noad arg[2]: --backupmarks
Jun 4 18:10:01 vdr noad[10521]: noad arg[3]: --asd
Jun 4 18:10:01 vdr noad[10521]: noad arg[4]: --statisticfile=/media/video/noadstat
Jun 4 18:10:01 vdr noad[10521]: noad arg[5]: after
Jun 4 18:10:01 vdr noad[10521]: noad arg[6]: /media/video/Busters_-_Die_Wissensjäger/_/2006-06-04.16.30.30.05.rec
Jun 4 18:10:01 vdr noad[10521]: noad args done
Jun 4 18:10:01 vdr noad[10521]: noad forked to pid 10522
Jun 4 18:10:01 vdr noad[10522]: nice ERROR(19,14): Success
Jun 4 18:10:01 vdr noad[10522]: Sunday,04.06.2006 18:10:01 start noad-0.6.0 for /media/video/Busters_-_Die_Wissensjäger/_/2006-06-04.16.30.30.05.rec
- Aufzeichnung beendet, noad startet.
[...]
Jun 4 18:11:28 vdr vdr: [10095] non blocking file reader thread ended (pid=10095, tid=10095)
Jun 4 18:11:28 vdr vdr: [10094] dvbplayer thread ended (pid=10094, tid=10094)
Jun 4 18:11:28 vdr vdr: [1950] switching to channel 6
Jun 4 18:11:28 vdr vdr: [10504] receiver on device 2 thread ended (pid=10504, tid=10504)
Jun 4 18:11:28 vdr vdr: [1950] buffer stats: 0 (0%) used
Jun 4 18:11:28 vdr vdr: [10524] receiver on device 2 thread started (pid=10524, tid=10524)
Jun 4 18:11:30 vdr vdr: [1950] confirm: Aufzeichnung löschen?
Jun 4 18:11:30 vdr vdr: [1950] warning: Aufzeichnung löschen?
Jun 4 18:11:31 vdr vdr: [1950] confirmed
Jun 4 18:11:31 vdr vdr: [1950] deleting recording /media/video/Busters_-_Die_Wissensjäger/_/2006-06-04.16.30.30.05.rec
- Aufzeichnung gelöscht.
[...]
Jun 4 18:17:09 vdr apcsmart[1219]: select: Cannot allocate memory
Jun 4 18:17:10 vdr kernel: __alloc_pages: 1-order allocation failed (gfp=0x1f0/0)
- Beginn der Fehlermeldungen. Noad füllt inzwischen fast den kompletten Speicher. Hohe Festplattenaktivität (swap).
[...]
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1d2/0)
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1f0/0)
Jun 4 18:17:38 vdr last message repeated 6 times
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1d2/0)
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0xf0/0)
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1d2/0)
Jun 4 18:17:38 vdr kernel: VM: killing process named
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0xf0/0)
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1d2/0)
Jun 4 18:17:38 vdr kernel: VM: killing process sh
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1f0/0)
Jun 4 18:17:38 vdr last message repeated 14 times
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1d2/0)
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1f0/0)
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1d2/0)
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1f0/0)
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1f0/0)
Jun 4 18:17:38 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1d2/0)
Jun 4 18:17:38 vdr kernel: VM: killing process named
[... hier wird dann noch so einiges gekillt, unter anderem auch ssh, samba, ...]
Jun 4 18:19:14 vdr kernel: VM: killing process lpstat
Jun 4 18:19:14 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1d2/0)
Jun 4 18:19:14 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1f0/0)
Jun 4 18:19:14 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0xf0/0)
Jun 4 18:19:14 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1d2/0)
Jun 4 18:19:14 vdr kernel: VM: killing process sh
Jun 4 18:19:15 vdr upsmon[1231]: Poll UPS [localhost] failed - Data stale
Jun 4 18:19:16 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1f0/0)
Jun 4 18:19:17 vdr kernel: __alloc_pages: 0-order allocation failed (gfp=0x1d2/0)
Jun 4 18:19:17 vdr kernel: VM: killing process noad
- Ende der Fehlermeldungen. Der Rechner läuft, bis auf die gekillten Prozesse, weiter als währe nichts gewesen.
Alles anzeigen
Daraufhin hab ich die Logs des letzten halben Jahres nach "kernel: VM: killing process" durchsucht und bin öfters fündig gewordern. Das Problem dürfte bei mir für fast alle Abstürze verantwortlich sein!
Die Gemeinsamkeiten:
- VM killt Prozesse bis enweder noad erwischt wird oder der Watchdog-Timer den Rechner neu startet.
- Meistens (nicht immer) wurde die Aufnahme, an der noad arbeitet gelöscht.
Ich konnte den Absturz inzwischen auch reproduzieren. Es klappt nicht bei jedem Versuch, die Chancen stehen aber nicht schlecht.
Auch andere scheinen davon betroffen zu sein:
Hilfe! 100% CPU-Last durch VDR
Löschen von 8 Aufnahmen kurz nacheinander führt zum Absturz
[ANNOUNCE] noad-0.5.2
Nur eine Lösung konnte ich bislang noch nicht finden.
Ich glaube das Finden des Speicherloch in noad dürfte mich etwas überfordern. Ich will es daher erstmal mit einem Skript versuchen, was noad bei überschreiten einer gewissen Grösse killt (es scheint das es einige minuten dauert, bis noad eine kritische grösse erreicht hat, sollte daher machbar sein).
Hat jemand zufallig soetwas schon umgesetzt oder eine Idee wie das am unkompliziertesten (mit überschaubaren sed und cut aufrufen ;)) geht?
Oder gibt es eine elegantere Möglichkeit?
Kann man die Killreinfolge des Kernels beeinflussen?
Vielen Dank im voraus.