Thema: (solved) sasc-ng mythfrontend hänger

[mailman]

Ersteinmal ein GROSSES Lob für sasc-ng!

Jetzt zu meinem etwas eigenartigen Problem:
Ich nutze das aktuelle sasc-ng zusammen mit camd3 und mythTV (0.21pre) - aber das sollte wohl keine so große Rolle spielen. Auf dem Server selbst läuft das ganze absolut stabil. Allerdings gibt es ein Problem, wenn ich mich mit einem Frontend von einem anderen Rechner aus verbinde und einen verschlüsselten Sender im LiveTV auswähle. Das mythTV-Frontend stürzt dann nach einigen Sekunden mit einem segfault ab. Bis zu diesem Zeitpunkt, wird der verschlüsselte Sender aber korrekt dekodiert und wiedergegeben. Die Zeit bis zum Absturtz variiert, in der Regel kommt der segfault aber nach ungefähr 1-5 Sekunde. Wenn ein unverschlüsselter Sender ausgewählt ist, gibt es hingegen keine Probleme.

Das gleiche Problem besteht bei der Wiedergabe aufgenommener Sendungen. Lokal kann das Frontend die Aufnahmen von verschlüsselten Sendungen wiedergeben, auf einem anderen Rechner stürtzt das Frontend i.d.R. sofort ab.

Aufnahmen, die ich vor der Umstellung auf sasc-ng mit sasc und entsp. mythTV patches gemacht habe, laufen dagegen problemos auch auf dem Remote-Frontend. Aufnahmen von unverschlüsselten Sendern (auch über das loopback device!) laufen auch problemlos.

Kann es sein, dass das Problem in dem entschlüsselten stream des loopback devices liegt?

Vielen Dank für jede Hilfe oder Hinweis!

[mailman]

Noch ein paar Infos zu dem Problem:

Hier die Ausgabe des Frontends und des Debuggers:
2007-07-27 18:39:02.811 AFD: Opened codec 0x848ab60, id(MPEG2VIDEO) type(Video)
2007-07-27 18:39:02.812 AFD: Opened codec 0x848c170, id(MP3) type(Audio)
2007-07-27 18:39:02.813 AFD: Opened codec 0x845e260, id(AC3) type(Audio)
2007-07-27 18:39:02.915 Opening OSS audio device '/dev/dsp'.
[New Thread -1469432944 (LWP 30769)]
2007-07-27 18:39:02.921 NVP: Enabling Audio
2007-07-27 18:39:03.015 NVP: Prebuffer wait timed out 10 times.
2007-07-27 18:39:04.036 NVP: prebuffering pause
2007-07-27 18:39:05.319 NVP: prebuffering pause
2007-07-27 18:39:07.014 NVP: Prebuffer wait timed out 10 times.
2007-07-27 18:39:07.751 NVP: prebuffering pause
2007-07-27 18:39:09.200 NVP: prebuffering pause
2007-07-27 18:39:10.649 NVP: prebuffering pause
2007-07-27 18:39:11.799 NVP: prebuffering pause
2007-07-27 18:39:13.365 NVP: prebuffering pause

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread -1366295664 (LWP 30764)]
0xb7492126 in ff_imdct_calc_sse () from /usr/lib/libmythavcodec-0.20.so.0
(gdb) backtrace
#0  0xb7492126 in ff_imdct_calc_sse () from /usr/lib/libmythavcodec-0.20.so.0
#1  0x04c804eb in ?? ()
#2  0xae8fe3c8 in ?? ()
#3  0x0000007f in ?? ()
#4  0xb7445d63 in ?? () from /usr/lib/libmythavcodec-0.20.so.0
#5  0x00000200 in ?? ()
#6  0x00000040 in ?? ()
#7  0x00000100 in ?? ()
#8  0xae9ff0f0 in ?? ()
#9  0xacb64430 in ?? ()
#10 0xacb64560 in ?? ()
#11 0x00000000 in ?? ()
(gdb)

[mtron]

poste mal den sasc-ng debug

[mailman]

Hier die Ausgabe von sasc-ng beim Start. Wie gesagt, zum entschlüsseln verwende ich den camd3 als cardserver:

Code: [Auswählen]

tv-server trunk # ./sasc-ng -j 0:2 --cam-budget -d 0xfffff
23:03:04.970371 : Version: 0.0.2-Unknown
23:03:04.971105 CSA: Setting state: NOT_ENCRYPTED
23:03:04.971490 CAM: initializing plugin: s*ftc*m (0.8.1): A software emulated CAM
Jul 27 23:03:04 [general.info] SC version 0.8.1 initializing
23:03:04.972495 CAM: starting plugin:
Jul 27 23:03:04 [general.info] SC version 0.8.1 starting
Jul 27 23:03:04 [core.load] ** Plugin config:
Jul 27 23:03:04 [core.load] ** Key updates (AU) are enabled (active CAIDs)
Jul 27 23:03:04 [core.load] ** Local systems DON'T take priority over cached remote
Jul 27 23:03:04 [core.load] ** Concurrent FF recordings are NOT allowed
Jul 27 23:03:04 [core.load] ** Force transfermode with digital auido
Jul 27 23:03:04 [core.load] ** ScCaps are 1 2 0 0 0 0 0 0 0 0
Jul 27 23:03:04 [core.load] ** Ignored CAIDs 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000
Jul 27 23:03:04 [general.error] Failed to open file './sc_files/s*ftc*m.Key': No such file or directory
Jul 27 23:03:04 [core.load] loaded 0 keys from ./sc_files/s*ftc*m.Key
Jul 27 23:03:04 [general.error] no keys loaded for s*ftc*m!
Jul 27 23:03:04 [core.load] ** registered systems:
Jul 27 23:03:04 [core.load] ** Cardclient        (pri -15)
Jul 27 23:03:04 [core.load] ** Conax             (pri -10)
Jul 27 23:03:04 [core.load] ** ConstCW           (pri -20)
Jul 27 23:03:04 [core.load] ** Cryptoworks       (pri -10)
Jul 27 23:03:04 [core.load] ** Irdeto            (pri -10)
Jul 27 23:03:04 [core.load] ** Nagra             (pri -10)
Jul 27 23:03:04 [core.load] ** Nagra2            (pri -10)
Jul 27 23:03:04 [core.load] ** SC-Conax          (pri  -5)
Jul 27 23:03:04 [core.load] ** SC-Cryptoworks    (pri  -5)
Jul 27 23:03:04 [core.load] ** SC-Irdeto         (pri  -5)
Jul 27 23:03:04 [core.load] ** SC-Nagra          (pri  -5)
Jul 27 23:03:04 [core.load] ** SC-Seca           (pri  -5)
Jul 27 23:03:04 [core.load] ** SC-Viaccess       (pri  -5)
Jul 27 23:03:04 [core.load] ** Seca              (pri -10)
Jul 27 23:03:04 [core.load] ** @SHL              (pri -10)
Jul 27 23:03:04 [core.load] ** Viaccess          (pri -10)
Jul 27 23:03:04 [general.info] loading cardclient config from ./sc_files/cardclient.conf
Jul 27 23:03:04 [cardclient.core] hostname=localhost port=20248 emm=1 emmCaids 0000/0000
Jul 27 23:03:04 [cardclient.core] Camd35: username=benutzer1 password=password2 ucrc=b20a17d1
Jul 27 23:03:04 [cardclient.core] client 'Camd35' ready
Jul 27 23:03:04 [cardclient.core] created 1 client(s)
Jul 27 23:03:04 [general.error] Failed to open file './sc_files/Ird-Beta.KID': No such file or directory
Jul 27 23:03:04 [core.load] loaded 0 Irdeto cards from ./sc_files/Ird-Beta.KID
Jul 27 23:03:04 [general.error] Failed to open file './sc_files/Seca.KID': No such file or directory
Jul 27 23:03:04 [core.load] loaded 0 Seca cards from ./sc_files/Seca.KID
Jul 27 23:03:04 [general.error] Failed to open file './sc_files/Viaccess.KID': No such file or directory
Jul 27 23:03:04 [core.load] loaded 0 Viaccess cards from ./sc_files/Viaccess.KID
Jul 27 23:03:04 [general.error] Failed to open file './sc_files/smartcard.conf': No such file or directory
Jul 27 23:03:04 [general.info] loading ca cache from ./sc_files/ca.cache
Jul 27 23:03:04 [general.warn] no smartcard interface defined!
23:03:05.995575 frontend: Starting thread on /dev/dvb/adapter2/frontend1
The thread scheduling parameters indicate:
policy = 0
priority = 0
23:03:05.995998 demux: Starting thread on /dev/dvb/adapter2/demux1
The thread scheduling parameters indicate:
policy = 0
priority = 0
23:03:06.015509 dvr: Starting thread on /dev/dvb/adapter2/dvr1
The thread scheduling parameters indicate:
policy = 1
priority = 99
23:03:06.015936 : Listening on port 5456

Sobald ich mythbackend starte kommt folgendes:
23:05:33.429995 frontend: Got custom command: 0
23:05:33.430271 frontend: Opened fd: 0=9 mode: 104002
23:05:33.430669 frontend: Got command 61 (size: 176)
23:05:34.749871 frontend: ioctl on (9) returned: 0
23:05:34.749942 : FE_GET_INFO(9): 'Philips TDA10021 DVB-C'
min:51000000 max:858000000 step:62500 tol:0 minsr:451875 maxsr:7230000 tolsr:0
23:05:34.750068 frontend: Got custom command: 1
23:05:34.750143 CAM: Got MSG_RESETSID
23:05:34.750171 CSA: Got command(2): I idx: 0 pid: 0
23:05:34.750193 CSA: Setting state: NOT_ENCRYPTED
23:05:34.750215 frontend: Closed fd: 9 ret: 0
23:05:34.750314 frontend: Got custom command: 0
23:05:34.750348 frontend: Opened fd: 0=9 mode: 104002
23:05:34.750386 frontend: Got command 61 (size: 176)
23:05:34.750410 frontend: ioctl on (9) returned: 0
23:05:34.750430 : FE_GET_INFO(9): 'Philips TDA10021 DVB-C'
min:51000000 max:858000000 step:62500 tol:0 minsr:451875 maxsr:7230000 tolsr:0
23:05:34.750474 frontend: Got custom command: 1
23:05:34.750512 CAM: Got MSG_RESETSID
23:05:34.750533 CSA: Got command(2): I idx: 0 pid: 0
23:05:34.750552 CSA: Setting state: NOT_ENCRYPTED
23:05:34.750573 frontend: Closed fd: 9 ret: 0
23:05:34.750665 frontend: Got custom command: 0
23:05:34.750697 frontend: Opened fd: 0=9 mode: 104002
23:05:34.750773 frontend: Got command 61 (size: 176)
23:05:34.750798 frontend: ioctl on (9) returned: 0
23:05:34.750818 : FE_GET_INFO(9): 'Philips TDA10021 DVB-C'
min:51000000 max:858000000 step:62500 tol:0 minsr:451875 maxsr:7230000 tolsr:0
23:05:34.831229 frontend: Got command 78 (size: 48)
23:05:34.831296 frontend: ioctl on (9) returned: -11
23:05:34.831318 : FE_GET_EVENT(9) returned -11
23:05:34.831357 frontend: Got command 76 (size: 44)
23:05:34.831969 frontend: ioctl on (9) returned: 0
23:05:34.831990 CHANNEL: Tuning frontend
23:05:34.832033 CAM: Got MSG_RESETSID
23:05:34.832058 CSA: Got command(2): I idx: 0 pid: 0
23:05:34.832079 CSA: Setting state: NOT_ENCRYPTED
23:05:34.832105 : FE_SET_FRONTEND(9): freq: 370000000 inv: AUTO
  QPSK: sr: 6900000 fec: 0
23:05:34.832206 frontend: Got custom command: 4
23:05:34.832231 frontend: Poll mode:3 ret:1 - sig: 0
23:05:34.832264 frontend: Got command 69 (size: 12)
23:05:35.110004 frontend: ioctl on (9) returned: 0
23:05:35.110090 : FE_READ_STATUS(9): SIGNAL CARRIER VITERBI SYNC LOCK                                                     

[mailman]

Während der Wiedergabe im Frontend vom Server kommt die folgende Ausgabe immer wieder:
23:15:57.772597 dvr: Read 10716 bytes (requested 10716 or 48128)
23:15:57.772762 dvr: Got custom command: 4
23:15:57.772794 dvr: Poll mode:0 ret:0 - sig: 1
23:15:57.785769 dvr: Got custom command: 4
23:15:57.785862 dvr: Poll mode:0 ret:0 - sig: 1
23:15:57.801100 dvr: Got custom command: 4
23:15:57.801196 dvr: Poll mode:0 ret:0 - sig: 1
23:15:57.801446 dvr: Got custom command: 4
23:15:57.801477 dvr: Poll mode:1 ret:1 - sig: 0
23:15:57.801658 dvr: Got custom command: 2

Jetzt das vielleicht interessante:
Das ist die Ausgabe, wenn ich das Frontend auf nem anderen Rechner starte und im LiveTV Modus einen verschlüsselten Sender sehe. In diesem Fall ist es direkt bei der Wiedergabe abgeschtürzt, ca. eine halbe Sekunde sah ich das Bild. Ich denke ich habe am Anfang noch ein Stück log von der Wiedergabe bis das Frontend dann weg war:
23:18:35.388295 dvr: Read 30832 bytes (requested 30832 or 48128)
23:18:35.388566 dvr: Got custom command: 4
23:18:35.388605 dvr: Poll mode:0 ret:0 - sig: 1
23:18:35.396647 dvr: Got custom command: 4
23:18:35.396747 dvr: Poll mode:0 ret:0 - sig: 1
23:18:35.411609 dvr: Got custom command: 4
23:18:35.411730 dvr: Poll mode:0 ret:0 - sig: 1
23:18:35.414198 dvr: Got custom command: 4
23:18:35.414272 dvr: Poll mode:1 ret:1 - sig: 0
23:18:35.414415 dvr: Got custom command: 2
23:18:35.414509 dvr: Read 23876 bytes (requested 23876 or 48128)
23:18:35.414708 dvr: Got custom command: 4
23:18:35.414743 dvr: Poll mode:0 ret:0 - sig: 1
23:18:35.423783 dvr: Got custom command: 4
23:18:35.423892 dvr: Poll mode:0 ret:0 - sig: 1
23:18:35.423951 CSA: decrypted packets max:37 now:37 of 63 avg:34.130000
23:18:35.437310 dvr: Got custom command: 4
23:18:35.437424 dvr: Poll mode:0 ret:0 - sig: 1
23:18:35.439845 dvr: Got custom command: 4
23:18:35.439879 dvr: Poll mode:1 ret:1 - sig: 0
23:18:35.440020 dvr: Got custom command: 2
23:18:35.440201 dvr: Read 22748 bytes (requested 22748 or 48128)
23:18:35.440779 dvr: Got custom command: 4
23:18:35.440825 dvr: Poll mode:0 ret:0 - sig: 1
23:18:35.451030 dvr: Got custom command: 4
23:18:35.451133 dvr: Poll mode:0 ret:0 - sig: 1
23:18:35.463599 dvr: Got custom command: 4
23:18:35.463695 dvr: Poll mode:0 ret:0 - sig: 1
23:18:35.465133 dvr: Got custom command: 4
23:18:35.465167 dvr: Poll mode:1 ret:1 - sig: 0
23:18:35.482727 demux: Got custom command: 1
23:18:35.483233 demux: Closed fd: 11 ret: 0
23:18:35.483448 demux: Got custom command: 1
23:18:35.483654 demux: Closed fd: 26 ret: 0
23:18:35.483847 demux: Got custom command: 1
23:18:35.484033 demux: Closed fd: 21 ret: 0
23:18:35.484185 demux: Got custom command: 1
23:18:35.484348 demux: Closed fd: 14 ret: 0
23:18:35.484497 demux: Got custom command: 1
23:18:35.484712 demux: Closed fd: 15 ret: 0
23:18:35.484921 demux: Got custom command: 1
23:18:35.485121 demux: Closed fd: 29 ret: 0
23:18:35.485308 demux: Got custom command: 1
23:18:35.485505 demux: Closed fd: 30 ret: 0
23:18:35.485691 demux: Got custom command: 1
23:18:35.485854 demux: Closed fd: 32 ret: 0
23:18:35.485982 demux: Got custom command: 1
23:18:35.486125 demux: Closed fd: 34 ret: 0
23:18:35.486252 demux: Got custom command: 1
23:18:35.486508 demux: Closed fd: 28 ret: 0
23:18:35.486645 demux: Got custom command: 1
23:18:35.486792 demux: Closed fd: 27 ret: 0
23:18:35.486918 demux: Got custom command: 1
23:18:35.487061 demux: Closed fd: 25 ret: 0
23:18:35.487187 demux: Got custom command: 1
23:18:35.487330 demux: Closed fd: 33 ret: 0
23:18:35.487456 demux: Got custom command: 1
23:18:35.487592 demux: Closed fd: 31 ret: 0
23:18:35.487717 demux: Got custom command: 1
23:18:35.487859 demux: Closed fd: 35 ret: 0
23:18:35.487984 demux: Got custom command: 1
23:18:35.488658 demux: Closed fd: 16 ret: 0
23:18:35.489064 demux: Got custom command: 1
23:18:35.489298 demux: Closed fd: 18 ret: 0
23:18:35.489491 demux: Got custom command: 1
23:18:35.489699 demux: Closed fd: 19 ret: 0
23:18:35.489889 demux: Got custom command: 1
23:18:35.490550 demux: Closed fd: 20 ret: 0
23:18:35.490970 demux: Got custom command: 1
23:18:35.491181 demux: Closed fd: 22 ret: 0
23:18:35.491544 demux: Got custom command: 1
23:18:35.491777 demux: Closed fd: 24 ret: 0
23:18:35.492013 dvr: Got custom command: 1
23:18:35.492325 dvr: Closed fd: 10 ret: 0
23:18:35.492366 CSA: Removing csa for rb: 2
23:18:35.492388 RINGBUF: Releasing ringbuffer: 2
23:18:35.492406 CSA: Setting state: ENCRYPTED_NOT_READY
23:18:35.492590 CAM: Got MSG_REMOVESID with sid: 11
23:18:35.492822 CAM: Mapped sid to 1795
23:18:35.493000 CAM: Mapped sid to 1793
23:18:35.493177 CAM: Mapped sid to 1792
23:18:35.493433 CAM: Mapped sid to 1791
23:18:35.493616 CAM: Mapped sid to 32
23:18:35.493795 CAM: Got MSG_REMOVESID with sid: 11
23:18:35.493974 CAM: Mapped sid to 1795
23:18:35.494152 CAM: Mapped sid to 1793
23:18:35.494312 CAM: Mapped sid to 1792
23:18:35.494471 CAM: Mapped sid to 1791
23:18:35.494631 CAM: Mapped sid to 32
23:18:35.494807 CAM: Got MSG_REMOVESID with sid: 11
23:18:35.494985 CAM: Mapped sid to 1795
23:18:35.495165 CAM: Mapped sid to 1793
23:18:35.495342 CAM: Mapped sid to 1792
23:18:35.495518 CAM: Mapped sid to 1791
23:18:35.495694 CAM: Mapped sid to 32
Called cSascDvbDevice::SetCaDescr
23:18:36.680206 CAM: Sending key(-1) O 0 939...9a
23:18:36.680236 CSA: Got command(2): O idx: 0 pid: 0 key: 0939...9a
23:18:36.680262 CSA: Processed Odd Key (idx=0): State = 1, ready = 3


Ich hoffe das hilft weiter. Wenn ich weiter behilflich sein kann, gerne! So wie ich das sehe, muss aber doch irgendetwas an dem von sasc-ng ausgegebenen video stream nicht stimmen: Schließlich funktioniert ja auch nicht die Wiedergabe bereits aufgenommener Sendungen. Und da ist sasc-ng und auch das loopback device dann gar nicht mehr dran beteiligt.

Meine Vermutung ist eher, dass der Videostream mythtv bei der Wiedergabe aus dem Tritt bringt, und erstaunlicherweise nur wernn dieses auf einem anderen Rechner läuft. Dafür würde ja auch evtl. die Ausgabe des Debuggers spreche, da scheint ja irgendwas bei der Dekodierung mit ffmpeg schief zu gehen. Trotzdem komisch, dass es manchmal für ein paar Sekunden funktioniert.

[mtron]

ja, da scheint was im trunk nicht zu passen. Mit 0.20 fixes kann ich es nicht reproduzieren. mein backend steht im keller und ich greife über mein frontend problemlos drauf zu.

funktioniert sasc-ng denn mit mplayer oder kaffeine im network stream über den virtuellen adapter?

Bezüglich myth hab ich gelesen dass es probleme seit dem der multirec patch mit sasc-ng gibt.  Vielleicht solltes NoOneImportant direkt mailen (findest ihm in happysat forum)

[mailman]

Hm.... Danke schonmal für die Mühe bisher. Wenn ich die Zeit finde, werde ich in den nächsten Tagen mal ein bisschen mit verschiedenen mythTV Versionen testen um das Problem einzugrenzen.

Nur zur Info: Momentan nutze ich mythTV in Version 13775 aus dem SVN mit den entsp. Gentoo patches aus Portage. Zudem habe ich einige eigene Patches dem ebuild hinzugefügt, um auch auf den Optionskanälen EPG-Daten zu bekommen. Eingige Änderungen waren aber bereits in änlicher Form in die SVN Sourcen eingeflossen. Jedoch hatte ich anfangs mit dem standard ebuild keinen Erfolg bzgl. der EPG Daten für diese Kanäle, sodass ich mir ein eigenes ebuild gebastelt habe. Damit funktioniert jetzt auch alles inklusive der EPG-Daten auf den Optionskanälen einwandfrei (habe aber auch einiges an der DB geändert, vielleicht war auch da das Probelm für die fehlenden EPG Daten für Direkt/Sport und das manuelle patchen war überflüssig). Und ich glaube nicht, dass das in diesem Thread beschriebene Problem mit diesen Patches zu tun hat.

Was mich aber wirklich wundert: Das Problem tritt ja nicht nur im LiveTV auf, sondern auch bei bereits abgeschlossenen Aufnahmen. Auf dem Server selbst kann ich diese Einwandfrei abspielen, über einen anderen Rechner aber nicht. Bei Aufnahmen von unverschlüsselten Sendern gibt es das Problem nicht. Aber so wie ich das verstehe, sollte der von Video-Stream doch von sasc-ng für mythTV völlig transparent entschlüsselt werden?!? Die fertige Aufnahme bzw. der Stream so aussehen, als wäre er nie verschlüsselt gewesen! Oder habe ich da was missverstanden?!

Ich hab mir bisher noch nicht die Mühe gemacht, tiefer in die mythTV Sourcen reinzusehen. Vielleicht kann mir ja jemand einen Hinweis geben, warum es dieses Problem nur auf dem remote frontend gibt. So viel anders sollte das doch eigentlich nicht laufen... Zudem ja auch nur bei "verschlüsselten" Kanälen (die Daten kommen doch schon unverschlüsselt bei mythTV an)...

Ich werde mich mal an NoOneImportant wenden und auch diesen Thread auf dem Laufenden halten. Bin natürlich immernoch über weitere Hinweise dankbar, insb. auch zu den gerade gestellten Fragen.

[mailman]

Es scheint doch ein reines Problem von mythTV zu sein. Ich habe für das remote frontend mal eine etwas ältere Version aus dem SVN genommen, und siehe da: Keine Probleme mehr.

Der Grund des Problem ist mir jedoch nicht klar geworden und warum die Hänger nur bei Aufnahmen von verschlüsselten Sendern auftreten. Ich habe auch mal versucht die ersten MBs einer Aufnahme eines verschlüssleten Senders manuell abzuschneiden (um die evtl. noch verschlüsselten Teile des Videostreams loszuwerden), aber auch das half nicht.

[mtron]

Gut dass es wieder funzt

Als warnung für andere: trunk ist immer mit Vorsicht zu geniessen. Wer eine stabile Version möchte / braucht sollte besser noch bei 0.20 fixes bleiben.

Obwohl mich der multirec patch schon sehr neugierig macht.  Aber wahrscheinlich wird die nächste release bald kommen...