XXV schläft ein

  • Hallo,


    habe bei meinem vdr-xxv (0.80+svn20061130-1) das Problem, dass es sich nach dem Start ganz normal verhält, dann aber nach ein paar Tagen oder neuerdings wenigen Stunden nichts mehr macht. D. h., über den Browser reagiert xxv nicht mehr. In der Prozessliste (top) steht es in der letzten Zeile und idelt vor sich hin, verbraucht konstant 55 MB und 0% CPU.


    Im log stehen ein paar Meldungen, die aber irgendwie "schon immer" kamen und nie gestört haben:


    ...usw.
    Irgendwann ist dann Schluss, das Logfile wächst nicht weiter:



    Was geht hier schief?


    frantic

    c't VDR: 1.5.8-1devel1; Kernel: 2.6.21.3

    2 * TT-DVB-C 2.1, 2 * CI, 2 * AlphaCrypt Light; 1 * TechniSat AirStar 2 TV

    Celeron 2,4 GHz; 256 MB; SAMSUNG HA250JC + SV1604N

  • jo das kenn ich auch.


    war vorn paar Wochen schon mal, dang gings, jetzt aktuell seit der 1050 ists wieder bei mir... keine Ahnung was da passiert. keine Logmeldungen, nix ....


    wenn der xxv-Neustart nicht wegen des epg-einlesens so lange dauern würde ...

  • Ist mir noch nicht untergekommen, das kann aber auch daran liegen das XXV entwicklungsbedingt ehe häufig neugestartet wird.


    Ein Einschlafen halte ich eher für unwahrscheinlich, wahrscheinlicher ist ein hängenbleiben in einer Funktion. ?(


    Das einzige was hilft, ist XXV mit verbose=5 laufen zulassen, um überhaupt einen Anhaltspunkt zu haben, was die letzte Aktion ist.


    Interessant wäre in diesem Zusammenhang, auch eine Zuordnung zur Aktion des Users im Browser.


    z.B Timer wurde gelöscht, dann ist die letzte Zeile des jeweiligen Vorgang der Status des HTTP Request. wenn die Aktion vollständig abgeschlossen ist.

    Code
    2311 (202) [20:40:42] HTTPD: Delete timer with title "nano"
    2312 (202) [20:40:42] TIMERS: EVT:270 Call command "delt 9" on svdrp
    2313 (202) [20:40:42] TIMERS: Connect to SVDRP Host: "localhost:2001"
    2314 (202) [20:40:42] TIMERS: SVDRP Socket closed ...
    2315 (202) [20:40:44] TIMERS: EVT:270 Call command "lstt" on svdrp
    2316 (202) [20:40:44] TIMERS: Connect to SVDRP Host: "localhost:2001"
    2317 (202) [20:40:45] TIMERS: SVDRP Socket closed ...
    2318 (202) [20:40:45] TIMERS: EVT:270 Reread 48 timers and written to DB
    2319 (202) [20:40:45] main: 192.168.0.1 - - "/?cmd=tdelete&data=9" 200 1051 "http://vdr:9000/?cmd=tl" "-"

    Fehlt diese letzte Zeile ist er innerhalb der Aktion hängengebleiben ...


    Das Format ist : ip/-/user/request/status/bytes/referer/-


    diesen Logeintrag gibt nur in der aktuellen dev-Version + verbose=5, bei den älteren Versionen sind diese Informationen über mehrere Zeilen verteilt.

  • hier der Log meines letzten restarts:



    seit 20:51:21 ist kein neuer Eintrag im Log. xxv reagiert nicht auf Browseranfragen. in top ist mysqld mit >95% CPU seit 20:51:21 aktiv ...

  • das "Einschlafen" passiert Stunden oder Tage nach der letzten Benutzeraktion.


    Werde erstmal den Loglevel anheben...

    c't VDR: 1.5.8-1devel1; Kernel: 2.6.21.3

    2 * TT-DVB-C 2.1, 2 * CI, 2 * AlphaCrypt Light; 1 * TechniSat AirStar 2 TV

    Celeron 2,4 GHz; 256 MB; SAMSUNG HA250JC + SV1604N

  • Nachtrag:


    Code
    55 (250) [20:51:21] main: CHRONICLE: Store recordings at chronicle ...
    56 (250) [20:51:21] : Dokumentation wurde in '/opt/XXV/doc' generiert
    57 (202) [21:07:25] AUTOTIMER: EVT:270 Call command "lstt" on svdrp
    58 (202) [21:07:27] AUTOTIMER: EVT:270 Reread 147 timers and written to DB!
  • sorry -


    hab eben mal svn update gemacht.


    das log nach dem Neustart:



    danach hab ich dann mal nen Autotimer angelegt und wieder gelöscht. Das wurde aber im Log nicht dargestellt .... in /opt/XXV/etc/xxvd steht "VERBOSE = "5" " ...


    und nun ?

  • 57 (550) [11:00:37] EPG: Can't call method "message" on unblessed reference at /usr/local/src/XXV/bin/../lib/XXV/MODULES/EPG.pm line 1074, <GEN33> line 11.
    58 (501) [11:00:37] Event: Event: trapped error in `?? HTTPD.pm:352': Can't call method "message" on unblessed reference at /usr/local/src/XXV/bin/../lib/XXV/MODULES/EPG.pm line 1074, <GEN33> line 11.


    Der ist mir heute zufällig aufgefallen. XXV generell läuft.



    Um in den Genuß aller Features zu kommen, habe ich noch folgendes installiert:


    Code
    perl -MCPAN -e 'install JSON'
    perl -MCPAN -e 'install Math::BigInt'
    perl -MCPAN -e 'install Math::BigInt::FastCalc'


    [EDIT] Die Vorschaubilder werden bei mir nicht mehr angezeigt (vdr2jpeg).

  • ...habe den Loglevel auf 5 gestellt. Dieses mal blieb xxv erst nach über einem Tag stehen, hier die letzten Einträge im Logfile:



    Heißt das, dass ein Hänger im Modul Event aufgetreten ist?

    c't VDR: 1.5.8-1devel1; Kernel: 2.6.21.3

    2 * TT-DVB-C 2.1, 2 * CI, 2 * AlphaCrypt Light; 1 * TechniSat AirStar 2 TV

    Celeron 2,4 GHz; 256 MB; SAMSUNG HA250JC + SV1604N

  • Zitat

    Original von frantic
    Heißt das, dass ein Hänger im Modul Event aufgetreten ist?


    Nicht ganz, die Meldung selber kommt aus dem HTTPD Modul, beim Zugriff durch den Browser.


    Mein Vermutung geht eher dahin, das der Browser den Socket nicht sauber schliesst und dadurch das der Socket offen bleibt, und deshalb keine weiteren Request ausgeführt werden. Sowas würde ich dem Browser aus Redmond glatt zutrauen :schiel.


    Vielleicht hilft es den Socket mit einem Timeout zu belegen, allerdings habe ich hier erstmal eine recht lange Timeoutzeit angesetzt, damit ein langer Request wie Autotimerupdate nicht vorzeigt abgebrochen wird.


    Diff
    --- HTTPD.pm    (Revision 1052)
    +++ HTTPD.pm    (Arbeitskopie)
    @@ -188,6 +192,7 @@
                    Listen          => $obj->{Clients},
                    LocalPort       => $obj->{Port},
         LocalAddr => $obj->{Interface},
    +    Timeout => 10 * 60,
                    Reuse           => 1
         ) or return error("Can't create Socket: $!");


    Allerdings sind die Aussagen im Internet zum Timeout des Perlmodul IO::Socket::INET sehr unverständlich und recht widersprüchlich, so da ich nicht garantieren kann das es a. was bringt und b. ob es überhaupt funktioniert ...




    sigiberlin
    mit verbose=5 ist der Kommandozeilenparameter von xxvd gemeint.
    http://www.vdr-wiki.de/wiki/index.php/Xxv#Parameter

  • Der Browserzugriff kam wohl vom Opera RSS Reader. Redmond war hier nicht beteiligt.
    (Es sei denn, jemand hackt meinen VDR aus dem Internet?!?)


    Werde mal RSS im XXV abschalten und den Newsfeed aus Opera rausnehmen. Mal sehen, ob die Hänger dann verschwinden...


    frantic

    c't VDR: 1.5.8-1devel1; Kernel: 2.6.21.3

    2 * TT-DVB-C 2.1, 2 * CI, 2 * AlphaCrypt Light; 1 * TechniSat AirStar 2 TV

    Celeron 2,4 GHz; 256 MB; SAMSUNG HA250JC + SV1604N

  • XXV hängt wieder, diesmal nach rund 50 h. Der Prozess ist noch da, tut nichts und verbraucht 0,1% CPU und 25% MEM (Memory ist normal).


    Hier die letzten Lebenszeichen im Log:


    Code
    23344 (202) [17:32:23] RECORDS: EVT:270 Call command "lstr" on svdrp
    23345 (202) [17:32:23] RECORDS: Connect to SVDRP Host: "localhost:2001"
    23346 (202) [17:32:23] RECORDS: SVDRP Socket closed ...
    23347 (202) [17:34:07] TIMERS: EVT:270 Call command "lstt" on svdrp
    23348 (202) [17:34:07] TIMERS: Connect to SVDRP Host: "localhost:2001"
    23349 (202) [17:34:07] TIMERS: SVDRP Socket closed ...
    23350 (202) [17:49:08] TIMERS: EVT:270 Call command "lstt" on svdrp
    23351 (202) [17:49:08] TIMERS: Connect to SVDRP Host: "localhost:2001"
    23352 (202) [17:49:09] TIMERS: SVDRP Socket closed ...
    23353 (202) [17:51:29] Event: Get Data from socket: 0,00 KB


    Eine Suche im Logfile nach "Event: Get Data" ergibt nur wenige Fundstellen, die ich hier mal aufliste:


    Ist daran etwas auffällig?


    Ach ja, hier noch die Startmeldungen:


    frantic


    PS: schade, dass kein Datum im Logfile steht :)

    c't VDR: 1.5.8-1devel1; Kernel: 2.6.21.3

    2 * TT-DVB-C 2.1, 2 * CI, 2 * AlphaCrypt Light; 1 * TechniSat AirStar 2 TV

    Celeron 2,4 GHz; 256 MB; SAMSUNG HA250JC + SV1604N

  • Auf Anregung von xpix ist SVDRP Schnittstelle komplett neu entstanden. Du könnest ja mal das angefügte MODUL testen, das ersetzt das bisherige Modul SVDRP.pm. Ich bin mir nur sicher ob es den gewünschten Effekt bringt, deshalb ist noch nicht im DEV-Zweig eingeflossen, da eine zusätzliche Abhängigkeit entsteht. Hier läuft es bisher auf die gleiche Art und Weise wie das alte Modul.


    Denn zusätzlich wird das Perlmodul NET::TELNET benötigt, welches z.B. per "apt-get install libnet-telnet-perl" oder per "perl -MCPAN -e 'install NET::TELNET'" nachinstalliert werden muss.


    Aber zur Sicherheit, ein Backup der alten Version von SVDRP.pm erstellen :arme

  • Zitat

    Original von sigiberlin
    weder aptitude install libnet-telnet-perl noch perl -MCPAN -e 'install NET::TELNET' bringen mir das auf die Platte ? ansonsten würde ich es gerne ausprobieren ..


    Too many fingertip on keyboard ? :whatever


    Denn das Paket gibt sowohl für Sarge, als auch für Etch ...


    http://packages.debian.org/stable/perl/libnet-telnet-perl
    http://packages.debian.org/unstable/perl/libnet-telnet-perl

  • Hallo Hulk,


    Zitat

    Du könnest ja mal das angefügte MODUL testen, das ersetzt das bisherige Modul SVDRP.pm


    O. K., es läuft!


    Ein Nebeneffekt ist, dass die Bedienung über den Browser subjektiv deutlich flüssiger geworden ist.
    Z. B. der Aufruf von Status, was immer einige s gedauert hat, ist viel schneller.
    Aber auch alles andere - sehr angenehm :)


    Ich melde mich, falls XXV wieder "einschläft"...


    frantic

    c't VDR: 1.5.8-1devel1; Kernel: 2.6.21.3

    2 * TT-DVB-C 2.1, 2 * CI, 2 * AlphaCrypt Light; 1 * TechniSat AirStar 2 TV

    Celeron 2,4 GHz; 256 MB; SAMSUNG HA250JC + SV1604N

Jetzt mitmachen!

Sie haben noch kein Benutzerkonto auf unserer Seite? Registrieren Sie sich kostenlos und nehmen Sie an unserer Community teil!