vdr schmiert unregelmäßig ab [Ursache: vdr-plugin-avards]

fossy · Aug 26th 2009

Hi,

vor ein paar Wochen habe ich meine VDR softwaretechnisch per distupgrdade auf den neuesten Stand gebracht. Prinzipiell ist alles glatt gelaufen und der VDR läuft.

Zur Zeit läuft mein VDR 24h am Tag, da der SATA-Controler manchmal beim Booten hängen bleibt.

Nun tritt etwa alle ein bis zwei tage das Problem auf, dass sich der VDR-Prozess verabschiedet und nicht mehr erfolgreich wiederbelebt werden kann.

Zum Glück habe ich vor dem Update eine Sicherung auf eine andere Partition gemacht. Benutze ich diese, läuft der VDR Tage lang ohne Probleme.

Anbei die entsprechenden ctvdrinfo-Ausgaben der beiden Systeme und ein Auszug aus der syslog-Datei von solch einem "Aufhänger".

Ich hoffe, dass mir jemand helfen kann. Bei der Suche nach ähnlichen Problemen habe ich nix gefunden

cu
fossy

_Cyber_ · Aug 26th 2009

oom_kills sind out-of-memory-kills - der box geht der speicher aus.

wie viel ram hast denn da drinnen? aktivierten swap, wenn ja wie viel?

>>>cyber

fossy · Aug 26th 2009

hi,

aha, also Arbeitsspeicher sind 1 GB drin und die SWAP-Partition hat etwa 2GB.

... ich bin mir aber nicht ganz sicher, ob der SWAP richtig konfiguriert ist, da beim DistUpgrade nur 512 MB als Swap da waren und es irgendwo eine Meldung bzgl. SWAP gab, deren Sinn sich mir nicht so ganz erschlossen hat. Irgendwas konnte nicht richtig eingestellt werden, weil die SWAP-Partition zu klein wäre oder so. Deshalb hab ich nachträglich die SWAP-Partition vergrößert.

In der oom_trace-Datei steht was von
Free swap = 2078004kB

Gibt das den Moment des "Überlauf" oder was auch immer das ist wieder?

Danke für Deine Hilfe.

FireFly · Aug 26th 2009

was sacht denn "cat /proc/swaps" ?
Und "cat /proc/meminfo | grep Mem" ?

Läuft da evtl. ein Plugin Amok?

fossy · Aug 26th 2009

hi,

... sieht eigentlich alles gut aus denke ich.

SHF · Aug 27th 2009

Noad hatte bei mir mal so ähnliche Probleme ausgelöst, der Fehler ist bis jetzt noch immer nicht 100% gefunden/beseitigt.
Zum Test einfach mal noad deaktivieren.

Dann währe es hilfreich mal alle paar Minuten die Grösse der grössten Prozesse zu loggen, da müsste man den Übeltäter (Pugin-Prozess) eindeutig identifizieren können.
Das müsste sich recht schnell als Shellscript basteln lassen.
Parat hab ich das aber nicht, vielleicht jemand anders?

fossy · Aug 27th 2009

hi,

... hab gestern abend ein kleines Skript gebastelt (und heut morgen erweitert), was ich per cron alle halbe Stunde aufrufe.

Der Speicher scheint tatsächlich voll zu laufen. Aber womit?

... siehe Anhänge

anbr · Aug 27th 2009

Einfach mal per "top" die Anlastung dynamisch anzeigen lassen
(Tipp: Zur Laufzeit, per Tasten "Shift+F" + "n" Sortierung nach %MEM ändern)

fossy · Aug 27th 2009

hi,

... hab ich gemacht. Zeigt aber auch keine anderen Ergebnisse. Jetzt sind nur noch 16MB des Arbeitsspeichers frei. Aber ich sehe keine Prozess/Prozesse, die diesen Speicher belegen könnten.

Gibt es evtl. ein Programm, dass Speicher belegt und nicht wieder frei gibt? Aber wie kriegt man raus welches, wenn top und ps nicht anzeigen, welche Prozesse den Speicher belegen?

fossy · Aug 29th 2009

hi,

... heute nacht ist mein vdr wieder abgeschmiert.
und zwar um 1:24 Uhr.

1:20 Uhr
16MB FreeMem
245MB VDR-Prozess

1:25 Uhr
63MB FreeMem
kein VDR-Prozess mehr...

Hat vielleicht noch jemand einen Tip, wie ich relativ einfach eingrenzen kann, "wer" schuld an dem "speicherüberlauf" (oder wie heißt das?) ist?

SHF · Aug 30th 2009

Kann natürlich sein, dass der Prozess, der das Killen auslöst noch gar nicht so gross ist und man ihn deshalb nicht sieht.

Kannst du aus den Logs was sehen?
Ist Noad zu der Zeit gelaufen?

fossy · Aug 31st 2009

hi,

... also ich habe bzgl. noad mal nachgesehen: um 23:20 wurde er zum letzten mal vor dem oom_killer gestartet. Im log steht was, dass er für noad kein pidfile anlegen konnte (no such file or directroy). Sonst funzt noad aber eigentlich.

Die log-files lassen nix erkennen. Wie gesagt, der größte Prozess ist der vdr mit etwa 250MB und dann kommt named mit etwa 40MB. vier minuten vor dem oom_killer waren noch etwa 16MB FreeMem.

Wieso wird eigentlich der oom_killer angeworfen, wenn noch jede menge swap-space frei ist?

Kann man den irgendwie konfigurieren?

SHF · Sep 1st 2009

Quote

Original von fossy
... also ich habe bzgl. noad mal nachgesehen: um 23:20 wurde er zum letzten mal vor dem oom_killer gestartet. Im log steht was, dass er für noad kein pidfile anlegen konnte (no such file or directroy). Sonst funzt noad aber eigentlich.

Wurde noad auch korrekt beendet?
Da müsste eigentlich ein "noad done" kommen.

Quote

Die log-files lassen nix erkennen. Wie gesagt, der größte Prozess ist der vdr mit etwa 250MB und dann kommt named mit etwa 40MB. vier minuten vor dem oom_killer waren noch etwa 16MB FreeMem.

Ich bin inzwischen nicht mehr sicher ob FreeMem überhaupt aussagekräftig ist.
Wenn der Rechner ins Swap auslagert dürfte FreeMem immer sehr klein sein, was aber kein Problem ist.

Quote

Wieso wird eigentlich der oom_killer angeworfen, wenn noch jede menge swap-space frei ist?

Der OOM-Killer erkennt wohl irgendwie verdächtige Prozesse, bevor sie das System lahm legen.
Wie er genau arbeitet kann ich aber nicht sagen, damit habe ich mich noch nicht beschäftigt.

fossy · Sep 1st 2009

Hi,

anbei die logs vom letzten absturz. noad habe ich per dpkg-reconfiugre deaktiviert (irgendwie war aber komischerweise noad trotzdem danach noch bei aufnahmen im spiel - ich werd es weiter beobachten).

Gibt es noch andere Möglichkeiten, das Problem besser einzugrenzen? Kann jemand an den Log-Files mögliche Probleme erkennen?

SHF · Sep 2nd 2009

Die Pid 11269 vom ersten kill

Code

Aug 31 23:20:30 vdr kernel: [206652.584090] vdr invoked oom-killer: gfp_mask=0x200d4, order=0, oomkilladj=0
Aug 31 23:20:30 vdr kernel: [206652.584418] Pid: 11269, comm: vdr Not tainted 2.6.28-etobi.3-686 #1

scheint zum Avads-Plugin zu gehören.

Code

Aug 31 23:11:09 vdr vdr: [11269] avards: switching WSS to 16:9

fossy · Sep 3rd 2009

hi,

hab gestern avards deinstalliert. seit dem scheint der speicher nicht mehr so schnell voll zu laufen. es sieht so aus, als ob das plugin wirklich die ursache für das einspringen des oom_killer ist. ich werde dann wieder berichten, ob der vdr durchgelaufen ist - noch ist es etwas früh...

fossy · Sep 11th 2009

hi,

so, es sind nun ein paar Tage ins Land gegangen und ich wollte wieder berichten...

Seit dem das Avards-Plugin deinstalliert ist, wird der VDR nicht mehr gekillt!

Heißt das jetzt, dass in dem Plugin ein Fehler ist, der das wieder freigeben von Speicher verhinder?? Oder kann es sein, dass das Plugin sich mit einem andern behakt??? Warum hat das noch kein anderer gehabt???

TomJoad · Sep 11th 2009

Ich habe das gleiche Problem seit einiger Zeit, aber auch keine Lösung gefunden. Auf den ersten Blick macht avards nichts falsch. Das Problem könnte auch mit irgendeiner Revision der Kerneltreiber reingekommen sein, weil die ioctls sehr oft aufgerufen werden und das wahrscheinlich nie in einem anderen Umfeld getestet wurde.
Wenn ich viel Zeit habe, versuch ich mal den vdr mit valgrind zu starten.

heifisch · Sep 11th 2009

Aha, da stehe ich nun vielleicht doch nicht mehr alleine da...

Ich hatte schon vor längerer Zeit die Probleme mit avards, jedoch nur wenn die Umschaltung aktiviert war. Allerdings kam es bei mir dann gleich zu einem Kernel-oops.

[ANNOUNCE] Avards-Plugin 0.1.5

Auch mit der aktuellen Version 2.2 schmiert der VDR dann bei mir ab, allerdings schon viel früher wie bei Euch da ich nur 256 MB RAM drin habe und das System in einer Ramdisk auch noch 48 MB belegt.

Die Probleme habe ich auch noch mit der aktuellen HG-Treibern und Kernel 2.6.31-RC8.
An der Kernel-Konfiguration, habe ich schon einges ausprobiert, bin der Sache aber nicht näher gekommen.

Die Logs beim Crash sehen so aus:

Code

Sep 11 12:40:11 vdr user.warn kernel: saa7146_vv: saa7146 (0): registered device vbi0 [v4l2]
Sep 11 12:40:11 vdr user.warn kernel: ves1x93_attach: driver disabled by Kconfig            
Sep 11 12:40:11 vdr user.warn kernel: stv0299_attach: driver disabled by Kconfig            
Sep 11 12:40:11 vdr user.warn kernel: DVB: registering adapter 0 frontend 0 (Philips TDA8083 DVB-S)...
Sep 11 12:40:11 vdr user.info kernel: dvb-ttpci: found av7110-0.                                      
Sep 11 14:40:12 vdr user.err vdr: [914] cTimeMs: using monotonic clock (resolution is 3333116 ns)     
Sep 11 16:56:07 vdr user.alert kernel: BUG: unable to handle kernel paging request at 1313131a               
Sep 11 16:56:07 vdr user.alert kernel: IP: [<c10afe62>] rb_next+0x14/0x36                                    
Sep 11 16:56:07 vdr user.warn kernel: *pde = 00000000                                                        
Sep 11 16:56:07 vdr user.emerg kernel: Oops: 0000 [#1]                                                       
Sep 11 16:56:07 vdr user.emerg kernel: last sysfs file:                                                      
Sep 11 16:56:07 vdr user.warn kernel: Modules linked in: dvb_ttpci tda8083 ttpci_eeprom saa7146_vv videodev v4l1_compat videobuf_dma_sg videobuf_core saa7146 dvb_core lirc_serial lirc_dev                                                                                                                       
Sep 11 16:56:07 vdr user.warn kernel: Pid: 984, comm: vdr Not tainted (2.6.31-rc8 #6)                                                                    
Sep 11 16:56:07 vdr user.warn kernel: EIP: 0060:[<c10afe62>] EFLAGS: 00010206 CPU: 0                                                                     
Sep 11 16:56:07 vdr user.warn kernel: EIP is at rb_next+0x14/0x36                                                                                        
Sep 11 16:56:07 vdr user.warn kernel: EAX: 13131312 EBX: d06f8000 ECX: cb13bd8c EDX: 13131312                                                            
Sep 11 16:56:07 vdr user.warn kernel: ESI: d0600000 EDI: 00002000 EBP: 00001fff ESP: cf3d9c94                                                            
Sep 11 16:56:07 vdr user.warn kernel:  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068                                                                      
Sep 11 16:56:07 vdr user.emerg kernel: Process vdr (pid: 984, ti=cf3d8000 task=cf8c6120 task.ti=cf3d8000)                                                
Sep 11 16:56:07 vdr user.emerg kernel: Stack:                                                                                                            
Sep 11 16:56:07 vdr user.warn kernel:  c1048500 ffffffff 00000000 00000001 ca425700 00000000 ca425700 0000006b                                           
Sep 11 16:56:07 vdr user.warn kernel: <0> 00000001 cbc622e0 00000001 cbc622e0 00002000 c1048660 fffa3000 ffffffff                                        
Sep 11 16:56:07 vdr user.warn kernel: <0> 000000d2 d0600000 00000002 00001000 d066a95b ffffffff 000000d2 c1048b2a                                        
Sep 11 16:56:07 vdr user.emerg kernel: Call Trace:                                                                                                       
Sep 11 16:56:07 vdr user.warn kernel:  [<c1048500>] ? alloc_vmap_area+0xe3/0x194                                                                         
Sep 11 16:56:07 vdr user.warn kernel:  [<c1048660>] ? __get_vm_area_node+0xaf/0x127                                                                      
Sep 11 16:56:07 vdr user.warn kernel:  [<d066a95b>] ? videobuf_pages_to_sg+0x1d/0xb2 [videobuf_dma_sg]                                                   
Sep 11 16:56:07 vdr user.warn kernel:  [<c1048b2a>] ? __vmalloc_node+0x56/0x7c                                                                           
Sep 11 16:56:07 vdr user.warn kernel:  [<d066a95b>] ? videobuf_pages_to_sg+0x1d/0xb2 [videobuf_dma_sg]                                                   
Sep 11 16:56:07 vdr user.warn kernel:  [<c1048c48>] ? vmalloc+0x14/0x17                                                                                  
Sep 11 16:56:07 vdr user.warn kernel:  [<d066a95b>] ? videobuf_pages_to_sg+0x1d/0xb2 [videobuf_dma_sg]                                                   
Sep 11 16:56:07 vdr user.warn kernel:  [<d066aac5>] ? videobuf_dma_map+0x45/0x162 [videobuf_dma_sg]                                                      
Sep 11 16:56:07 vdr user.warn kernel:  [<d066abe2>] ? __videobuf_iolock+0x0/0xd2 [videobuf_dma_sg]                                                       
Sep 11 16:56:07 vdr user.warn kernel:  [<d065e27b>] ? videobuf_iolock+0x5d/0x61 [videobuf_core]                                                          
Sep 11 16:56:07 vdr user.warn kernel:  [<d06a2cef>] ? buffer_prepare+0x273/0x577 [saa7146_vv]                                                            
Sep 11 16:56:07 vdr user.warn kernel:  [<d066a50c>] ? __videobuf_alloc+0x12/0x5e [videobuf_dma_sg]                                                       
Sep 11 16:56:07 vdr user.warn kernel:  [<d065ede0>] ? videobuf_alloc+0x44/0x4f [videobuf_core]                                                           
Sep 11 16:56:07 vdr user.warn kernel:  [<d065f16d>] ? __videobuf_mmap_setup+0x4c/0xae [videobuf_core]                                                    
Sep 11 16:56:07 vdr user.warn kernel:  [<d06a3264>] ? vidioc_qbuf+0x0/0x2d [saa7146_vv]                                                                  
Sep 11 16:56:07 vdr user.warn kernel:  [<d065eac8>] ? videobuf_qbuf+0x275/0x323 [videobuf_core]                                                          
Sep 11 16:56:07 vdr user.warn kernel:  [<d06a3264>] ? vidioc_qbuf+0x0/0x2d [saa7146_vv]                                                                  
Sep 11 16:56:07 vdr user.warn kernel:  [<d0686bb1>] ? __video_do_ioctl+0x1031/0x2f89 [videodev]                                                          
Sep 11 16:56:07 vdr user.warn kernel:  [<c102be6b>] ? futex_wake+0xa6/0xb0                                                                               
Sep 11 16:56:07 vdr user.warn kernel:  [<d0688d81>] ? video_ioctl2+0x278/0x2ff [videodev]                                                                
Sep 11 16:56:07 vdr user.warn kernel:  [<c10afbc1>] ? rb_insert_color+0x51/0xb5                                                                          
Sep 11 16:56:07 vdr user.warn kernel:  [<d0688b09>] ? video_ioctl2+0x0/0x2ff [videodev]                                                                  
Sep 11 16:56:07 vdr user.warn kernel:  [<d068510f>] ? v4l2_ioctl+0x31/0x34 [videodev]                                                                    
Sep 11 16:56:07 vdr user.warn kernel:  [<d06850de>] ? v4l2_ioctl+0x0/0x34 [videodev]                                                                     
Sep 11 16:56:07 vdr user.warn kernel:  [<c105b173>] ? vfs_ioctl+0x37/0x42                                                                                
Sep 11 16:56:07 vdr user.warn kernel:  [<c105b9fb>] ? do_vfs_ioctl+0x46f/0x4a6                                                                           
Sep 11 16:56:07 vdr user.warn kernel:  [<c1045fa2>] ? mmap_region+0x304/0x406                                                                            
Sep 11 16:56:07 vdr user.warn kernel:  [<c105ba5e>] ? sys_ioctl+0x2c/0x42                                                                                
Sep 11 16:56:07 vdr user.warn kernel:  [<c10026e5>] ? syscall_call+0x7/0xb                                                                               
Sep 11 16:56:07 vdr user.emerg kernel: Code: 89 d0 eb f5 c3 8b 00 85 c0 74 0b 8b 50 04 85 d2 74 04 89 d0 eb f5 c3 89 c1 8b 00 31 d2 83 e0 fc 39 c1 74 26 8b 41 04 85 c0 74 11 <8b> 50 08 85 d2 74 04 89 d0 eb f5 89 c2 eb 10 89 d1 8b 01 89 c2
Sep 11 16:56:07 vdr user.emerg kernel: EIP: [<c10afe62>] rb_next+0x14/0x36 SS:ESP 0068:cf3d9c94
Sep 11 16:56:07 vdr user.emerg kernel: CR2: 000000001313131a
Sep 11 16:56:07 vdr user.warn kernel: ---[ end trace a4f091cf4192bdee ]---
Sep 11 16:56:07 vdr user.alert kernel: BUG: unable to handle kernel paging request at 1313131a
Sep 11 16:56:07 vdr user.alert kernel: IP: [<c10afe62>] rb_next+0x14/0x36
Sep 11 16:56:07 vdr user.warn kernel: *pde = 00000000
Sep 11 16:56:07 vdr user.emerg kernel: Oops: 0000 [#2]
Sep 11 16:56:07 vdr user.emerg kernel: last sysfs file:
Sep 11 16:56:07 vdr user.warn kernel: Modules linked in: dvb_ttpci tda8083 ttpci_eeprom saa7146_vv videodev v4l1_compat videobuf_dma_sg videobuf_core saa7146 dvb_core lirc_serial lirc_dev
Sep 11 16:56:07 vdr user.warn kernel: Pid: 920, comm: vdr Tainted: G      D    (2.6.31-rc8 #6)
Sep 11 16:56:07 vdr user.warn kernel: EIP: 0060:[<c10afe62>] EFLAGS: 00010206 CPU: 0
Sep 11 16:56:07 vdr user.warn kernel: EIP is at rb_next+0x14/0x36
Sep 11 16:56:07 vdr user.warn kernel: EAX: 13131312 EBX: d06f8000 ECX: cb13bd8c EDX: 13131312
Sep 11 16:56:07 vdr user.warn kernel: ESI: d0600000 EDI: 00003000 EBP: 00002fff ESP: cb565da8
Sep 11 16:56:07 vdr user.warn kernel:  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068
Sep 11 16:56:07 vdr user.emerg kernel: Process vdr (pid: 920, ti=cb564000 task=cf81e470 task.ti=cb564000)
Sep 11 16:56:07 vdr user.emerg kernel: Stack:
Sep 11 16:56:07 vdr user.warn kernel:  c1048500 ffffffff 00000000 00000001 ca4256c0 00000000 ca4256c0 d0634c8e
Sep 11 16:56:07 vdr user.warn kernel: <0> c11d5678 cbc622a0 00000001 cbc622a0 00003000 c1048660 fffa3000 ffffffff
Sep 11 16:56:07 vdr user.warn kernel: <0> 000000d2 d0600000 00000002 00002000 d0634204 ffffffff 000000d2 c1048b2a
Sep 11 16:56:07 vdr user.emerg kernel: Call Trace:
Sep 11 16:56:07 vdr user.warn kernel:  [<c1048500>] ? alloc_vmap_area+0xe3/0x194
Sep 11 16:56:07 vdr user.warn kernel:  [<d0634c8e>] ? dvb_dmx_swfilter_section_copy_dump+0x5e/0x1af [dvb_core]
Sep 11 16:56:07 vdr user.warn kernel:  [<c1048660>] ? __get_vm_area_node+0xaf/0x127
Sep 11 16:56:07 vdr user.warn kernel:  [<d0634204>] ? dvb_dmxdev_filter_start+0x37/0x280 [dvb_core]
Sep 11 16:56:07 vdr user.warn kernel:  [<c1048b2a>] ? __vmalloc_node+0x56/0x7c
Sep 11 16:56:07 vdr user.warn kernel:  [<d0634204>] ? dvb_dmxdev_filter_start+0x37/0x280 [dvb_core]
Sep 11 16:56:07 vdr user.warn kernel:  [<c1048c48>] ? vmalloc+0x14/0x17
Sep 11 16:56:07 vdr user.warn kernel:  [<d0634204>] ? dvb_dmxdev_filter_start+0x37/0x280 [dvb_core]
Sep 11 16:56:07 vdr user.warn kernel:  [<d06347cc>] ? dvb_demux_do_ioctl+0x181/0x488 [dvb_core]
Sep 11 16:56:07 vdr user.warn kernel:  [<d06341c3>] ? dvb_demux_open+0xc3/0xcd [dvb_core]
Sep 11 16:56:07 vdr user.warn kernel:  [<d063321d>] ? dvb_usercopy+0xa3/0xfb [dvb_core]
Sep 11 16:56:07 vdr user.warn kernel:  [<c105a566>] ? do_filp_open+0x3fd/0x796
Sep 11 16:56:07 vdr user.warn kernel:  [<c10b22e3>] ? copy_to_user+0x25/0x50
Sep 11 16:56:07 vdr user.warn kernel:  [<d0633b3f>] ? dvb_demux_ioctl+0x0/0x11 [dvb_core]
Sep 11 16:56:07 vdr user.warn kernel:  [<d0633b4d>] ? dvb_demux_ioctl+0xe/0x11 [dvb_core]
Sep 11 16:56:07 vdr user.warn kernel:  [<d063464b>] ? dvb_demux_do_ioctl+0x0/0x488 [dvb_core]
Sep 11 16:56:07 vdr user.warn kernel:  [<c105b173>] ? vfs_ioctl+0x37/0x42
Sep 11 16:56:07 vdr user.warn kernel:  [<c105b9fb>] ? do_vfs_ioctl+0x46f/0x4a6
Sep 11 16:56:07 vdr user.warn kernel:  [<c1050825>] ? do_sys_open+0x111/0x11a
Sep 11 16:56:07 vdr user.warn kernel:  [<c105ba5e>] ? sys_ioctl+0x2c/0x42
Sep 11 16:56:07 vdr user.warn kernel:  [<c10026e5>] ? syscall_call+0x7/0xb
Sep 11 16:56:07 vdr user.emerg kernel: Code: 89 d0 eb f5 c3 8b 00 85 c0 74 0b 8b 50 04 85 d2 74 04 89 d0 eb f5 c3 89 c1 8b 00 31 d2 83 e0 fc 39 c1 74 26 8b 41 04 85 c0 74 11 <8b> 50 08 85 d2 74 04 89 d0 eb f5 89 c2 eb 10 89 d1 8b 01 89 c2
Sep 11 16:56:07 vdr user.emerg kernel: EIP: [<c10afe62>] rb_next+0x14/0x36 SS:ESP 0068:cb565da8
Sep 11 16:56:07 vdr user.emerg kernel: CR2: 000000001313131a
Sep 11 16:56:07 vdr user.warn kernel: ---[ end trace a4f091cf4192bdef ]---

Display More

Nach 10-30 Minuten kommt es dann zum Crash

Groß debuggen kann ich leider mit dem System nicht, da es nur die minimal-Sachen an Bord hat...

Vielleicht kommt ja doch etwas Bewegung in die Sache...

vdr schmiert unregelmäßig ab [Ursache: vdr-plugin-avards]

Participate now!

Share