kernel: [ 2533.900695] vdr[4810] general protection ip:510303 sp:7fff4ef97b20 error:0 in vdr[400000+170000]

ako673de · 17. Februar 2015

Hallo,

habe seit einiger Zeit sporadisch obigen Fehler im syslog, verbunden natürlich jedes mal mit Neustart des VDR. Woran kann das liegen? Ist immer genau der gleiche Fehler. Nur die Zahl hinter "sp:" variiert...

Danke schon mal für Eure Hilfe
ako673de

P.S: Ich erkenne auch so etwas wie ein Schema. Die Fehler kommen oft in Gruppen mit (einigermassen) konstanten zeitlichen Abständen. von etwas in der Gegend von 6min:

Code

Feb 15 20:35:45 AndiMedia kernel: [  376.134534] vdr[1405] general protection ip:510303 sp:7fffbf7baf40 error:0 in vdr[400000+170000]
Feb 15 20:41:59 AndiMedia kernel: [  749.400263] vdr[2810] general protection ip:510303 sp:7fff1c613a40 error:0 in vdr[400000+170000]
Feb 15 20:48:00 AndiMedia kernel: [ 1110.079644] vdr[3232] general protection ip:510303 sp:7fffa1b57540 error:0 in vdr[400000+170000]
Feb 15 21:00:02 AndiMedia kernel: [  377.353946] vdr[1792] general protection ip:510303 sp:7fff13deab90 error:0 in vdr[400000+170000]
Feb 15 21:06:01 AndiMedia kernel: [  736.376791] vdr[2745] general protection ip:510303 sp:7fffec8e19c0 error:0 in vdr[400000+170000]
Feb 15 21:12:02 AndiMedia kernel: [ 1096.424866] vdr[3164] general protection ip:510303 sp:7ffff10f33f0 error:0 in vdr[400000+170000]
Feb 15 21:18:02 AndiMedia kernel: [ 1455.912438] vdr[3589] general protection ip:510303 sp:7fffaf5e65f0 error:0 in vdr[400000+170000]
Feb 15 21:24:01 AndiMedia kernel: [ 1814.799629] vdr[3996] general protection ip:510303 sp:7fff66482610 error:0 in vdr[400000+170000]
Feb 15 21:30:01 AndiMedia kernel: [ 2174.233275] vdr[4401] general protection ip:510303 sp:7fffb898ded0 error:0 in vdr[400000+170000]
Feb 15 21:36:01 AndiMedia kernel: [ 2533.900695] vdr[4810] general protection ip:510303 sp:7fff4ef97b20 error:0 in vdr[400000+170000]
Feb 15 21:43:42 AndiMedia kernel: [  385.689136] vdr[1516] general protection ip:510303 sp:7fff09836700 error:0 in vdr[400000+170000]
Feb 15 22:45:03 AndiMedia kernel: [ 4061.684953] vdr[2371] general protection ip:510303 sp:7fffcb330760 error:0 in vdr[400000+170000]
Feb 15 23:50:12 AndiMedia kernel: [ 7965.586788] vdr[2862] general protection ip:510303 sp:7fff63be1e40 error:0 in vdr[400000+170000]
Feb 15 23:56:55 AndiMedia kernel: [ 8368.491878] vdr[3390] general protection ip:510303 sp:7fff5e3dc9c0 error:0 in vdr[400000+170000]
Feb 16 00:03:37 AndiMedia kernel: [ 8769.183770] vdr[3863] general protection ip:510303 sp:7fffe542c630 error:0 in vdr[400000+170000]
Feb 16 00:10:18 AndiMedia kernel: [ 9169.970010] vdr[4275] general protection ip:510303 sp:7fff8c6db2f0 error:0 in vdr[400000+170000]
Feb 16 00:17:02 AndiMedia kernel: [ 9573.710564] vdr[4698] general protection ip:510303 sp:7fffc7e33c20 error:0 in vdr[400000+170000]
Feb 16 00:24:50 AndiMedia kernel: [  411.808392] vdr[1641] general protection ip:510303 sp:7fff1fcdb930 error:0 in vdr[400000+170000]
Feb 16 00:33:35 AndiMedia kernel: [  412.925264] vdr[1929] general protection ip:510303 sp:7fff06235e70 error:0 in vdr[400000+170000]
Feb 16 00:40:15 AndiMedia kernel: [  812.515799] vdr[2468] general protection ip:510303 sp:7ffff816d460 error:0 in vdr[400000+170000]
Feb 16 00:47:37 AndiMedia kernel: [ 1253.847391] vdr[2895] general protection ip:510303 sp:7ffff7eccb60 error:0 in vdr[400000+170000]
Feb 16 00:54:18 AndiMedia kernel: [ 1654.889161] vdr[3312] general protection ip:510303 sp:7fffca6a2520 error:0 in vdr[400000+170000]
Feb 16 01:01:04 AndiMedia kernel: [ 2060.291487] vdr[3720] general protection ip:510303 sp:7fff3ea7ea40 error:0 in vdr[400000+170000]
Feb 16 01:07:46 AndiMedia kernel: [ 2461.659784] vdr[4190] general protection ip:510303 sp:7ffffaeae200 error:0 in vdr[400000+170000]
Feb 16 01:15:38 AndiMedia kernel: [ 2932.639807] vdr[4601] general protection ip:510303 sp:7fff0dd3a0c0 error:0 in vdr[400000+170000]
Feb 16 20:05:56 AndiMedia kernel: [  457.288714] vdr[1455] general protection ip:510303 sp:7fff1ed1b9e0 error:0 in vdr[400000+170000]
Feb 17 00:59:20 AndiMedia kernel: [18038.297020] vdr[2968] general protection ip:510303 sp:7fff5cb053d0 error:0 in vdr[400000+170000]
Feb 17 00:59:41 AndiMedia kernel: [18058.927977] vdr[4606] general protection ip:510303 sp:7fff6891eeb0 error:0 in vdr[400000+170000]
Feb 17 01:00:05 AndiMedia kernel: [18083.458678] vdr[4784] general protection ip:510303 sp:7fffc0b50e80 error:0 in vdr[400000+170000]
Feb 17 01:16:02 AndiMedia kernel: [19038.908367] vdr[5213] general protection ip:510303 sp:7fff086a7410 error:0 in vdr[400000+170000]
Feb 17 01:51:52 AndiMedia kernel: [21186.073304] vdr[5591] general protection ip:510303 sp:7fff37f72860 error:0 in vdr[400000+170000]

Alles anzeigen

mini73 · 17. Februar 2015

Doku über Debug-Pakete und wie man ein Crashlog erstellt lesen und dann den enthaltenen Backtrace posten.

Lars

ako673de · 17. Februar 2015

Danke für den Hinweis. Kommt in Kürze (denke ich)...

ako673de · 17. Februar 2015

Vor ner halben Stunde:

Code

Feb 17 09:25:52 AndiMedia vdr: [15307] epg data writer thread started (pid=14680, tid=15307, prio=low)
Feb 17 09:25:52 AndiMedia kernel: [48391.358899] epg data writer[15307]: segfault at 7f37e7b95aa8 ip 000000000049ed47 sp 00007f3f65ffacc0 error 4 in vdr[400000+170000]

Der Crash-Log davon:

Code

Crashlog from Tue Feb 17 09:25:54 CET 2015
----------------------------------


Environment details:
TERM=linux
EXIT_SIGNAL=SEGV
PATH=/usr/local/sbin:/usr/local/bin:/usr/bin:/usr/sbin:/sbin:/bin
PWD=/
JOB=vdr
RESULT=failed
SHLVL=1
PROCESS=main
UPSTART_INSTANCE=
UPSTART_EVENTS=stopped
UPSTART_JOB=vdr-dbg
INSTANCE=
_=/usr/bin/env


Backtrace:
----------

Alles anzeigen

enthält leider nur einen leeren Backtrace-Absatz... nur 800MB core dump hätte ich zu bieten.

Aber dieses mal war es auch eine andere Art von Crash. Was mir sofort auffällt, ist, dass dieses mal der "epg data writer" explizit genannt wird. Und so hab ich mal in der "Umgebung" der früheren Crashs im Syslog gesucht. Und in der Tat, stehen da immer die gleichen Zeilen in der Nähe, z.B.

Code

...
Feb 15 23:50:11 AndiMedia vdr: [2940] HandleEitEvent:65 EEPG: !!!Deleting Event id:42603 title:RÃ¤tselburg start_time:1424240700 new_start_time:1424240942 duration:300 new_duration:300
Feb 15 23:50:11 AndiMedia vdr: [2940] HandleEitEvent:73 EEPG: !!!End Deleting Event
Feb 15 23:50:11 AndiMedia vdr: [2940] HandleEitEvent:65 EEPG: !!!Deleting Event id:42604 title:Disneys Duck Tales - Neues aus Entenhausen start_time:1424241000 new_start_time:1424241242 duration:1500 new_dur
Feb 15 23:50:11 AndiMedia vdr: [2940] HandleEitEvent:73 EEPG: !!!End Deleting Event
Feb 15 23:50:11 AndiMedia vdr: [2940] HandleEitEvent:65 EEPG: !!!Deleting Event id:42605 title:Alles okidoki start_time:1424242500 new_start_time:1424242645 duration:300 new_duration:155
Feb 15 23:50:11 AndiMedia vdr: [2940] HandleEitEvent:73 EEPG: !!!End Deleting Event
Feb 15 23:50:12 AndiMedia kernel: [ 7965.586788] vdr[2862] general protection ip:510303 sp:7fff63be1e40 error:0 in vdr[400000+170000]
Feb 15 23:50:12 AndiMedia LCDd: sock_send: socket write error

Ob die letzte Zeile ("LCDd") relevant ist? Ich glaube eher, dass das schon die Auswirkung des VDR-Beendens ist.
Aber für mich eindeutig erkennbar ist der Zusammenhang mit EEPG. Was ist an dem Plugin in letzter Zeit geändert worden, oder auf was für "Umgebungsbedingungen" könnte dieses Plugin so unentspannt reagieren?

gda · 17. Februar 2015

Zitat von ako673de

enthält leider nur einen leeren Backtrace-Absatz... nur 800MB core dump hätte ich zu bieten.

Den coredump eben mit gdb aufrufen.

Zitat von ako673de

Aber für mich eindeutig erkennbar ist der Zusammenhang mit EEPG. Was ist an dem Plugin in letzter Zeit geändert worden, oder auf was für "Umgebungsbedingungen" könnte dieses Plugin so unentspannt reagieren?

Dazu können wir nichts sagen. Das Plugin wird von uns nicht genutzt und ist auch nicht Bestandteil der Distribution und deshalb nicht von uns supported.

Gerald

mini73 · 17. Februar 2015

Ich kenne mich mit dem eepg-Plugin auch nicht aus, da musst du dich auf die Suche nach anderen Benutzern machen, die da mehr zu wissen.

Lars.

ako673de · 17. Februar 2015

Tschuldigung, bin nicht so vertraut mit sowas. Hier das Ergebnis von "gdb" -> "bt full":

Code

GNU gdb (Ubuntu/Linaro 7.4-2012.04-0ubuntu2.1) 7.4-2012.04
Copyright (C) 2012 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
For bug reporting instructions, please see:
<http://bugs.launchpad.net/gdb-linaro/>...
Reading symbols from /usr/bin/vdr-dbg...Reading symbols from /usr/lib/debug/.build-id/9c/15df63fdd8b74477ebc5d919896c072e2483c8.de                                                                              bug...done.
done.
[New LWP 15307]
...
warning: Can't read pathname for load map: Eingabe-/Ausgabefehler.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/bin/vdr-dbg -v /srv/vdr/video.00 -c /var/lib/vdr -L /usr/lib/vdr/plugins -'.
Program terminated with signal 11, Segmentation fault.
#0  0x000000000049ed47 in cEvent::Dump (this=0x7f37e7b95a50, f=0x7f3f5e1c3500, Prefix=0x52e07f "", InfoOnly=false) at epg.c:449
449     epg.c: Datei oder Verzeichnis nicht gefunden.
(gdb) bt full


#0  0x000000000049ed47 in cEvent::Dump (this=0x7f37e7b95a50, f=0x7f3f5e1c3500, Prefix=0x52e07f "", InfoOnly=false) at epg.c:449
No locals.
#1  0x00000000004a0a70 in cSchedule::Dump (this=<optimized out>, f=0x7f3f5e1c3500, Prefix=0x52e07f "", DumpMode=dmAll, AtTime=0)
    at epg.c:1101
        p = 0x7f37e7b95a50
        channel = <optimized out>
        __FUNCTION__ = "Dump"
#2  0x00000000004a0d54 in cSchedules::Dump (f=0x7f3f5e1c3500, Prefix=0x52e07f "", DumpMode=dmAll, AtTime=0) at epg.c:1299
        p = 0x7f3fe7b1aa60
        sf = 0x7f3f5e131070
        SchedulesLock = {locked = true}
        s = <optimized out>
#3  0x00000000004a0edb in cEpgDataWriter::Perform (this=0x78b7e0) at epg.c:1201
        MutexLock = {mutex = 0x78b840, locked = true}
#4  0x000000000050d92d in cThread::StartThread (Thread=0x78b7e0) at thread.c:262
No locals.
#5  0x00007f4019c82e9a in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#6  0x00007f40186bb2ed in clone () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#7  0x0000000000000000 in ?? ()
No symbol table info available.
(gdb)

Alles anzeigen

Also epg, soviel ist sicher, aber EEPG ist doch eher nur ein Verdacht. Oder könnt Ihr da sicher was raus lesen?

Danke
ako673de

mini73 · 17. Februar 2015

Wo liegt denn deine epg.data? Ist da genug Platz auf der Platte?

Lars.

gda · 17. Februar 2015

Zitat von ako673de

Also epg, soviel ist sicher, aber EEPG ist doch eher nur ein Verdacht.

Dann entferne doch das besagte Plugin und teste ob es immer noch kracht.

Zitat von ako673de

Oder könnt Ihr da sicher was raus lesen?

Das wollen wir doch gar nicht.

Gerald

ako673de · 17. Februar 2015

Zitat von mini73

Wo liegt denn deine epg.data? Ist da genug Platz auf der Platte?

/var/cache/vdr. Und soweit ich das sehe, ist das ein Unterverzeichnis des unter / gemounteten Systemlaufwerks. Alles also so, wie es nach der Installation halt auch sein sollte. 9GB sind derzeit frei auf / und epg.data ist ca. 42MB gross.

Zitat von gda

Dann entferne doch das besagte Plugin und teste ob es immer noch kracht.

Nun ja, dazu kracht es zu selten. Dass heute früh nur 30min vergangen sind, war eh schon ein riesen Zufall. Wenn ich's aus mache, und dann nichts weiter passiert, dann weiss ich halt somit - nicht mehr als auch jetzt schon. Nur wenn es dann immer noch kracht, aber dann hätte es ja auch nichts gebracht es auszumachen... vdr(-dbg) läuft jetzt übrigens schon seit 9:30Uhr ohne Krachen durch. Ach ja, vdr-dbg kommt nach dem Krachen nicht automatisch wieder hoch. Bekannt?

ako673de

mini73 · 17. Februar 2015

Zitat von ako673de

Ach ja, vdr-dbg kommt nach dem Krachen nicht automatisch wieder hoch. Bekannt?

Funktioniert hier eigentlich. Nutzt du stable oder testing?

Lars.

seahawk1986 · 17. Februar 2015

Ich lasse gerade ein aktualisiertes Paket für das eepg-Plugin bauen - da hat sich im Git ja einiges seit November 2012 getan: http://projects.vdr-developer.…/vdr-plugin-eepg.git/log/

ako673de · 17. Februar 2015

mini73: Ich täte mal sagen "stable". Sicherheitshalber: Ausser Treiber zu kompilieren für meine etwas exotische Twin-SAT-Karte, ein paar Plugins zusätzlich zu aktivieren und dist-upgrade hab ich nichts (am System) gemacht nach der Basis-Installation von der 0.5.0a ISO.

seahawk1986 · 17. Februar 2015

Falls du mal mit dem aktuellen Stand des eepg-Plugin testen willst, hier habe ich das Plugin mal gegen den VDR aus stable-vdr bauen lassen: https://launchpad.net/~seahawk…archive/ubuntu/stable-vdr

ako673de · 22. Februar 2015

Läuft seit mehreren Tagen ohne Absturz. Frage am Rande: Da sind noch zwei weitere Pakete in Deinem PPA: XVDR-server und VNSI-server. Die wollte mir aber apt-get update nicht aktualisieren. Gründe? Oder alles normal?

seahawk1986 · 22. Februar 2015

Die beiden Pakete sind mittlerweile auch in der gleichen Version in stable-vdr, daher holt er sich die nicht.

ako673de · 22. Februar 2015

Als wenn der VDR hier mitlesen würde kommen genau jetzt wieder im 6 Minuten Takt Abstürze. Dieses mal wurden sie alle brav ge-backtraced. Ich hab das File angehängt. Alle (bislang) 5 dieser Reports gleichen wie ein Ei dem anderen.
Sicherheitshalber, denn evtl. sind sie von Bedeutung, die genauen Zeitpunkte der letzten Crashs:
2015-02-22/20:39:14, 2015-02-22/20:45:15, 2015-02-22/20:51:16, 2015-02-22/20:57:18, 2015-02-22/21:03:21, 2015-02-22/21:09:24

gda · 22. Februar 2015

PresetSeenWithin ist völlig harmlos:

Code

bool PresentSeenWithin(int Seconds) const { return time(NULL) - presentSeen < Seconds; }

Ich sehe da keinen Grund für einen Segfault. Ich würde mal das Memory checken.

Gerald

ako673de · 22. Februar 2015

Meinst Du wirklich? Memory, das im 6 Minuten-Takt - sozusagen pünktlich - seinen Dienst verweigert? Immer an exakt der gleichen Stelle im VDR-Code? Selten hab ich einen Absturz gesehen, der weniger mit Hardware zu tun haben kann.

Weitere Untersuchungen (ich sitze seit 2h vor der Kiste und warte auf den nächsten Absturz) haben ergeben:
- dass weder Reboot noch Herunterfahren etwas geändert haben
- dass die 6 min immer ab (Re)Start des VDR gezählt werden müssen

Angehängt habe ich das syslog, das sich so tatsächlich reproduzierbar fast vollständig in genau dieser Form wiederholt (auch die laufenden Zahlen vor den "delete"-Ereignissen!).

Sodann habe ich das EEPG-Plugin deinstalliert, und /var/cache/epg.data und /var/lib/vdr/plugins/eepg gelöscht und danach wieder installiert.

Seither (20 min) sind keine dieser seltsamen Meldungen wieder aufgetaucht. Ach ja, und auch kein Crash...

ako673de · 28. Februar 2015

Gestern abend um praktisch die gleiche (!) Uhrzeit wie am 22.2. hat es wieder angefangen. Wieder an exakt der gleichen Stelle im syslog, also beim Löschen von irgendwelchen EEPG-Events. Tut mir leid, aber da ist definitiv was faul am Code und zwar erst neuerdings! Ich hab das Plugin jetzt deinstalliert, bis das gefixt ist. Nur am Rande: Sehr wahrscheinlich ist nicht das Plugin buggy, denn das lief bei mir vorher schon seit Jahren problemfrei. Das muss irgendwas am VDR sein.

Ich hoffe der Verlust ist nicht allzu gross (so recht weiss ich gar nicht was der Gewinn war)...

Grüsse
ako673de

kernel: [ 2533.900695] vdr[4810] general protection ip:510303 sp:7fff4ef97b20 error:0 in vdr[400000+170000]

Jetzt mitmachen!

Teilen

Tags

Benutzer online in diesem Thema