frontend timed out while tuning to channel

    Hallo zusammen,


    mittlerweile betreibe ich meinen headless Server mit 4 vtuner-ng devices und 2 Sundtek Sticks.

    Seitdem fallen mir im Log jede Menge Einträge mit frontend time-outs auf. Quer durch die Bank auf alle frontends verteilt:


    Vorher (mit Satip-Plugin) hatte ich diese Meldungen nicht, bzw. kaum, sondern "nur" massig diese Meldeungen:

    Code
    Dez 30 10:38:47 server01 vdr[1647]: [1672] SATIP-ERROR: Detected invalid status code 503: rtsp://192.168.241.119/ [device 5]
Dez 30 10:38:47 server01 vdr[1647]: [1672] SATIP-ERROR: Connect failed [device 5]

    Ist das ein Problem? Falls ja, woran kann das liegen? Ich sehe, dass viele Tunes auf alte/obsolete Channel gehen, die sollte ich wohl mal rausnehmen? Aber auch ZDF oder Das Erste sind mit dabei, die definitiv vorhanden sein sollten.

    Ich hatte jetzt auch erstmalig den Fall, dass 3 aufeinander folgende Timer Aufnahmen ohne Länge produziert haben, kann aber tatsächtlich den Zusammenhang nicht mehr nachweisen.


    Ideen?


    Danke

    Andreas

    Empfangsstörungen sind da der Klassiker - z.B. aktuell Schnee vor/auf der SAT-Schüssel - mit den Sundtek-Sticks kannst du dir mit Hilfe des mediaclient die Signalstatistiken ansehen: https://sundtek.de/wiki/index.…Reading_Signal_statistics

    yaVDR-Dokumentation (Ceterum censeo enchiridia esse lectitanda.)

    Quote from rell

    Dez 30 10:38:47 server01 vdr[1647]: [1672] SATIP-ERROR: Detected invalid status code 503: rtsp://192.168.241.119/ [device 5]

    Der Klassiker. "Invalid" gibt es nicht. 503 bedeutet Service Unavailable. Beit satip kannste (falls mit Log gestartet) in den Logs nachschauen was drin steht...

    Wenn ich das richtig lese, geht der tuner die Frequenzen durch (EPG Scan?). Ist das gut, schlecht oder normal:

    Ich würde dann die Masse an Meldungen mal auf die out-of-date-channels in der channels.conf schieben und die timeouts bei z.B. ZDF evtl. auf Empfangsstörungen...

    Oder der ZDF tune hängt mit dem fehlerhaften Versuch zusammen, auf ".. OBSOLETE" zu tunen. Das kommt nämlich immer in der gleichen Reihenfolge:


    Quote from Joe_D

    Der Klassiker. "Invalid" gibt es nicht. 503 bedeutet Service Unavailable. Beit satip kannste (falls mit Log gestartet) in den Logs nachschauen was drin steht...

    Hab ich ja jetzt nicht mehr dank vtuner ;)

    Also, ich tue mich etwas schwer mit den logs, weil ich da keine Zeitstempel habe ;)

    Hier wäre mal ein komplettes Log...

    Ich glaube, dass es hier losgehen müsste, der betroffene Sender hat zumindest die frequenz 12603. timed out passiert aber auch auf Sat 1.

    sollte dazu passen:

    Code
    Jan 09 15:25:39 server01 vdr[15312]: [15323] frontend 2/0 timed out while tuning to channel 49 (Sky News Intl), tp 112603

    Insgesamt habe ich die Meldungen sehr oft, geschätzt steht das alle 1-2 Minuten im Log. Und gestern habe ich die channels.conf mal stark eingeschränkt und lasse sie VDR wieder selbst auffüllen. Aber wie gesagt, es sind auch insgesamt 6 Tuner.


    Etwas seltsam finde ich auch:

    Code
    Jan 09 15:28:25 server01 vdr[15312]: [15323] frontend 2/0 lost lock on channel 0 (), tp 211686

    Also im satip-Log sehe ich nur das:

    Code
    [15308 satip_rtp.c:162] debug: RTCP: update status=1 signallevel=0 quality=0
[15308 satip_rtp.c:162] debug: RTCP: update status=31 signallevel=190 quality=15

    Ob das "lange" ist oder nicht kann ich nicht sagen, mit debug=1 im vtuner wird das mit Zeitstempel auch ins dmesg und syslog geschrieben...

    Ansonsten mal mit 2 Tunern von derselben Sorte starten und schauen wie es sich dann verhält...

    Ok, hier nochmal ein kombiniertes Log. Nur mit 2 vtuner devices.

    Ist da was Verdächtiges?

    Wenn die timeouts nichts an der Funktionalität ändern, habe ich nur ein Problem mit der Menge der Logs. Wenn ich VDR nur mit den beiden Sundteks starte, sehe ich dass pids geändert werden, der VDR also durch die Kanäle schaltet, timeouts kommen aber keine. Also schiebe ich es mal auf vtuner/satip und nicht auf vermeintlich schlechten Empfang ? ;)


    EDIT: Im Log sinds noch 4 Devices und wohl nicht ganz sauber geladen, ich machs nochmal mit 2...

    Edited once, last by rell ().

    Also was ich da sehe ist ein SAT>IP-Receiver der "ewig" braucht ein LOCK zu senden.

    Code
    Jan 09 17:10:13 server01 kernel: vtunerc0: MSG_SET_FRONTEND, set signal NONE (internal)
Jan 09 17:10:13 server01 kernel: vtunerc0: set signal SIGNAL
Jan 09 17:10:17 server01 kernel: vtunerc0: set signal SIGNAL CARRIER VITERBI SYNC LOCK

    Was ist denn das für eine Wunderkiste?


    Das hier sieht auch nicht gut aus:

    Code
    Jan 09 06:14:03 server01 kernel: vtunerc1: Data not start on packet boundary: index=2 data=80 60 00 19 81 ...
Jan 09 06:14:00 server01 kernel: vtunerc1: Data not start on packet boundary: index=1 data=04 00 00 3f 29 ...
Jan 09 06:13:54 server01 kernel: vtunerc1: Data not start on packet boundary: index=1 data=00 00 00 d3 15 ...
Jan 09 06:13:52 server01 kernel: vtunerc1: Data not start on packet boundary: index=1 data=00 00 00 d9 65 ...
Jan 09 06:13:52 server01 kernel: vtunerc1: Data not start on packet boundary: index=2 data=00 00 00 ba a1 ...


    Aber irgendwie kann ich in dem Log vtuner-Meldungen nicht mit den frontend-Meldungen zusammenbringen.

    Ich bin mir nicht mehr sicher, aber evtl. hatte ich ein Durcheinander in meinen systemd services drin und das Anlegen der Tuner von sundtek und vtuner-ng hat sich irgendwie gehakelt.

    Ich habe jetzt die ersten 4 mit vtuner und die letzten beiden mit sundtek eingerichtet. Das Log sieht bis auf ca. 15-20 timed out Meldungen pro Stunde gut aus. Die Timeouts tauchen fast ausschließlich bei "alten" Kanaleinträgen oder verschlüsselten Sendern auf. Zwischendrin sind ein paar wenige Einträge von Sendern, die eigentlich funktionieren sollten, aber das kann ich verschmerzen. Ich werde die channels.conf nochmal ausdünnen.


    Ca. 40x pro h habe ich allerdings so eine Meldung - aber nur auf den Frequenzen 12552 und 11778...

    Code
    Jan 10 05:46:06 server01 vdr[20550]: [20566] tp 212552 (18/FF) read incomplete section - len = 4098, r = 4096
Jan 10 05:44:46 server01 vdr[20550]: [20566] tp 211778 (18/FF) read incomplete section - len = 4098, r = 4096

    Offene Frage für mich wäre momentan "nur" noch, wo die incomplete section Meldungen herkommen. Die anderen Meldungen versuche ich erstmal zu minimieren. Außerdem werde ich nochmal versuchen, die Reihenfolge der frontends zu tauschen. Evtl. lag es daran. Ich werde berichten.


    ...und die Wunderkiste ist ein Kathrein EXIP 418 ;)


    EDIT: Ich sehe gerade, dass ich schonmal dazu angefragt habe: Log Meldungen - Analyse

    Sundtek Mich würde noch deine Antwort auf den letzten Post aus dem Thread interessieren ;)

    Edited once, last by rell ().

    Ja, das passt jetzt mit den devices.

    Sieht auch so aus. Als wären die Meldungen seit ca. 18:00 weg... Ich schaue mir morgen mal das log an...

    Update: Obwohl ich alle Kanäle auf dem betroffenen Transponder aus der channels.conf gelöscht habe, wurden sie erwartungsgemäß natürlich wieder gefunden. Den Fehler mit den 0xFF bzw. "read incomplete section" habe ich also wieder. Nur auf der Frequenz 12552, d.h. https://www.satindex.de/frequenz/12552/


    frontend 4/0, also der sundtek hat Probleme mit SYFY HD, hier gibt es "lost lock" und unmittelbar darauf "regained lock". Ca. 5x pro Stunde.

    Die frontends 0/0 bis 3/0, also die vtuner meckern nachwievor timeouts beim tuning an, ziemlich häufig... Ich versuche das nochmal mit dem satip.log zusammenzubringen.

    So ein Beispiel-Log für die Timeouts wäre folgendes:

    Zeitlich passiert der Timeout lt. log (vtunerc2) 9s nach der ersten Meldung mit Signallevel 0. Die 9s oder 10s sind wohl ein timeout, da das immer gleich ist. Nach meinem Verständnis müsste der timer in 10:56:35 gecancelt werden? Die Zeile sieht "richtig" aus. Warum es überhaupt zum signallevel=0 kommt, ist dann nochmal was anderes.

    Auf den ersten Blick folgt auf die quality=0 Meldung 4-6 Sekunden später immer eine quality=15 Meldung.

    Code
    Jan 12 10:56:32 [13431 satip_rtp.c:146] debug: RTCP: update signallevel=0 quality=0
Jan 12 10:56:35 [13431 satip_rtp.c:146] debug: RTCP: update signallevel=193 quality=15
Jan 12 10:56:53 [13431 satip_config.c:212] debug: DVBS2 freq: 11052 mod: 8psk pol: h sym: 22000 fec: 23 roff: 0.35 pilot: on
Jan 12 10:56:53 [13431 satip_rtsp.c:466] debug: >>play:
PLAY rtsp://192.168.241.119/stream=8?src=1&freq=11052&pol=h&msys=dvbs2&mtype=8psk&sr=22000&fec=23&ro=0.35&plts=on&pids=0,16,17,18,19,20 RTSP/1.0
CSeq: 230
Session: 1313745668c4c2a


    jojo61 Ich habe aktuell keinen Zugriff drauf, versuche das aber später mal zu kontrollieren.

    Merkwürdig ist schonmal folgendes:

    Code
    Jan 12 11:56:53 server01 kernel: vtunerc0: MSG_PIDLIST (DTV_TUNE) 0s 16s 17s 18s 19s 20s

    Ein Kanal ohne DMX_TYPE_TS-Pids?


    Was ich auch komisch finde, das nirgendswo found pusi for pid 18 oder so erscheint.


    Signallevel und Quality sind in der aktuellsten GIT-Version irrelevant. Das wird nur noch als "femon"-Service gesetzt.


    Der LOCK-Status wird anhand des ersten DMX_TYPE_TS-Pakets gesetzt:

    Code
    if (!(ctx->status & FE_HAS_LOCK) && ctx->demux.feed[idx].type==DMX_TYPE_TS) {
                    dprintk(ctx, "set signal LOCK\n");
                    ctx->status = FE_HAS_SIGNAL | FE_HAS_CARRIER | FE_HAS_VITERBI | FE_HAS_SYNC | FE_HAS_LOCK; // no filler, ts stream -> we have a lock!
                }


    Du könntest mal probieren den Teil ctx->demux.feed[idx].type==DMX_TYPE_TS zu entfernen, dann würde schon ein LOCK beim Empfang irgendeines Pakets aus der PID-Liste gesetzt...

    Was natürlich auch sein kann, das überhaupt keine PIDs gesetzt werden sollen da ja keine DMX_TYPE_TS PID dabei ist. Bislang bin ich davon ausgegangen das es zu jedem Kanal DMX_TYPE_TS PIDs gibt. Dann hänge ich automatisch 0s 16s 17s 18s 19s 20s dazu. Eventuell darf ich das eben nur machen wenn es mindestens eine DMX_TYPE_TS PID gibt.

    Quote from Joe_D

    Was ich auch komisch finde, das nirgendswo found pusi for pid 18 oder so erscheint.

    Die hatte ich bis 9.1. im Log, seitdem nicht mehr. Aktuelle Version ist https://github.com/joed74/vtun…60e37aac03d960edb88bf81e3

    Entweder hat die ein Commit verschwinden lassen oder mir fehlt noch ein debug Schalter...


    Quote from Joe_D

    Du könntest mal probieren den Teil ctx->demux.feed[idx].type==DMX_TYPE_TS zu entfernen, dann würde schon ein LOCK beim Empfang irgendeines Pakets aus der PID-Liste gesetzt...

    Test kommt.

Participate now!

Don’t have an account yet? Register yourself now and be a part of our community!

Register Yourself Login