sectionsd: Handbremse los...

[PauleFoul]

Bleibt nur zu hoffen das Nirvana mal Zeit findet sich der Sache anzunehmen...

Dann ist das bestimmt schnell behoben...


Gruß
____Paule

[Nico 77]

Ist ja halb so wild, es ist im CVS und geht somit nicht verloren zur Weiterentwicklung.
Privat kann man ja einen älteren Stand nehmen damit läuft ja alles.

[alex12555]

Hi,
nur der vollständigkeithalber ich habe hier http://www.jackthegrabber.de/viewtopic.php?t=10824auch schon darüber berichtet und auch gedacht das ich der einzige bin . Naja wie gesagt, ich hab auch das Problem...

Alex

[seife]

Privat kann man ja einen älteren Stand nehmen damit läuft ja alles. :)

Welcher Stand ist denn noch "known good"? Ich stolpere beim dreambox-debuggen über dasselbe Problem (Hänger bis sectionsd gekillt / neu gestartet wird) und würde gern eine Version verwenden, die sicher funktioniert.

[dbluelle]

In der sectionsd.cpp gibt es noch ein paar Fälle, in denen bestimmte Sperren nicht wieder freigegeben werden.
Ich habe da gerade einen Fix eingecheckt, damit habe ich auf der Dreambox keine Hänger mehr
Ich hoffe, das das Problem damit auch auf der DBox gelöst ist,

dbluelle

[seife]

Held!

Ich baue grad und teste es dann. Danke. Ich habe versucht, mich durch den sectionsd zu kämpfen, aber ich habe den Kampf verloren ;-)

[ingrid]

Genial. Danke!

Ich baue auch mal und teste. Werde mal morgen irgendwann 'n Feedback geben, wenn's 'ne Weile gelaufen ist. (dbox)

[seife]

Auf der dm500 ist es schon fast gut. Die einzigen kurzen Hänger, die ich bekomme ist dann, wenn beim Umschalten das "now" Event fehlt, aber das "next" schon da ist. Dann kann ich erst nach ca. 5 Sekunden weiterschalten. Totalhänger, die sich nur durch killen des sectionsd beseitigen lassen habe ich aber bisher keine mehr gehabt.

Edit:
Zu früh gefreut? CNN Int. auf Astra 19.2E, 11778MHz scheint problematisch zu sein. Das geht soweit, daß sogar neutrino segfaulted :-(

[alex12555]

@Seife

Der Snap vom 24.05. läuft bei mir übrigens perfekt

Alex

[ingrid]

Hier scheint's subjektiv besser geworden zu sein (kurzer Test hat nichts ungewöhnliches gezeigt - sectionsd läuft momentan scheinbar stabil & mit weniger Last).
Endgültig kann man's aber erst sagen, wenn die Box ein oder mehrere Tage läuft. Schauen wir mal...

(dbox)

[Nico 77]

Nirvana im aktuellen sectionsd scheint ein Thread zu langsam zu sein oder stürtzt komplett ab.
Ich bekomme hier manchmal auf Sendern die keinen EPG liefern folgende Meldung mit einen Abschuss der Box(außer man killt den sectionsd).

Code: Alles auswählen

[basicsocket] receive timed out. waiting process 122
[CBasicClient] receive failed: /tmp/sectionsd.sock
[basicsocket] receive timed out. waiting process 122
[CBasicClient] receive failed: /tmp/sectionsd.sock
[basicsocket] receive timed out. waiting process 122
[CBasicClient] receive failed: /tmp/sectionsd.sock

Auf der dm500 ist es schon fast gut. Die einzigen kurzen Hänger, die ich bekomme ist dann, wenn beim Umschalten das "now" Event fehlt, aber das "next" schon da ist. Dann kann ich erst nach ca. 5 Sekunden weiterschalten. Totalhänger, die sich nur durch killen des sectionsd beseitigen lassen habe ich aber bisher keine mehr gehabt.

Edit:
Zu früh gefreut? CNN Int. auf Astra 19.2E, 11778MHz scheint problematisch zu sein. Das geht soweit, daß sogar neutrino segfaulted

Ich habe den Fehler eingekreist, es liegt am Extended EPG, werfe den komplett raus und der sectionsd hängt nicht mehr bzw Neutrino stürtzt nicht mehr ab.
Ok, den seltenen Uhrzeitbug beim starten gibt es immernoch, hat aber nichts mit diesem Problem zu tun.

Ps: Wenn man zusätzlich die rw_lock Patches rausnimmt ist nach meinem empfinden die reine Funktion des sectionsd auch besser. Der sectionsd läuft dann wieder einheitlich flüssig und ist nicht mal schnell, mal langsam. Auch sind immer alle EPG Daten vorhanden. Nirvana ich hoffe du bist nicht sauer wegen diesem Satz.

Pps: Wer komlett zurückgeht, nur nicht vergessen das das drin bleibt: http://cvs.tuxbox-cvs.sourceforge.net/l ... 00025.html

[Nirvana]

@Nico
Warum sollte ich sauer sein?
Sorry, ich programmiere ja nicht für Dich oder sonstwen, sondern ausschließlich für mich. Ich stelle meine Version nur zur Verfügung. Davon kann jeder halten was er möchte.

Und nochmal: Ich habe es ausführlichst getestet in den letzten Wochen. Bei mir freezed nix, verliert keinen EPG (ja wahrscheinlich weil ich die Box nachts ausmache -> Möchtegernöko) und rennt wesentlich schneller als die Versionen vorher. Wenn es bei anderen anders sein sollte, bad luck!

Explizit habe ich auch Sender ohne EPG getestet. GoTV.
Oder DW-TV oder CNN Int. Alles i.O. Es müssen also noch andere Faktoren (Einstellungen, sonstiger Memory Verbrauch, usw.) eine Rolle spielen. Vielleicht kann ja jemand noch eine präzisere Anleitung zum Fehlverhalten liefern.

Am Feedback mit dem Extended Text bin ich trotzdem interessiert. Was genau meinst Du mit rauswerfen?

@dbluelle
Danke. Sieht sehr sinnvoll aus!

[ingrid]

In der sectionsd.cpp gibt es noch ein paar Fälle, in denen bestimmte Sperren nicht wieder freigegeben werden.
Ich habe da gerade einen Fix eingecheckt, damit habe ich auf der Dreambox keine Hänger mehr
Ich hoffe, das das Problem damit auch auf der DBox gelöst ist,

dbluelle

Jetzt ist's hier wieder passiert, also ist das Problem nicht gelöst. Leider keine Änderung gegenüber Nirvana's Version.

Der Sender war dieses Mal RTL Shop, beschrieben hatte ich die Probleme weiter oben schon.

(DVB-C / Sagem)

Ich versuche es noch einmal zu beschreiben: Der Next-Event war dieses Mal da, es fehlte der Now-Event. Das OSD blendet dabei extrem langsam ein, ausblenden ebenfalls quälend. Beim Weiterzappen war's dann extrem slow, das OSD blieb ebenfalls langsam.
Irgendwann war ich aus dem Bouquet "draussen", im nächsten. Dann wieder zurück zu RTL Shop, sofort war der fehlende Now-Event da und die Box verhielt sich wieder normal.

Hilft das ein wenig mehr?

Ich würde ja liebend gerne Logs posten, aber der sectionsd sagt da nix. Als wäre nichts gewesen. Wie gesagt, evtl. kann mal jemand ein paar Log writes hinzufügen um das Ganze einzugrenzen?

[Nirvana]

Probier doch bitte mal ein Log zu machen.

/bin/sectionsd -d

[ingrid]

Probier doch bitte mal ein Log zu machen.

/bin/sectionsd -d

Okay, läuft. Dauert nur ein wenig, bis das Problem auftritt. Ich beobachte mal und werde berichten bzw. das Log posten. Ist ja doch extrem gesprächig, der gute sectionsd. ;-)

[ingrid]

Erstes Log ist im Anhang.

Szenario: Box gestartet, sectionsd mit -d neugestartet, vom ersten Programm an alles (rückwärts) durchgezappt, bei "Sky News (engl)" fehlte dann der Now-Event (ca. Zeile 32082) , OSD & Box wurden langsam. Weitergezappt, alle weiteren Sender schienen okay.
Gewartet, ZDF angelassen, später dann wieder zu "Sky News (engl)", Now-Event fehlt immer noch (ca. Zeile 67050 oder früher).
Auf Zweitbox kontrolliert, dort ist der Now-Event vorhanden, die Daten wurden also scheinbar korrekt gesendet.

Ich beobachte weiter & poste ein Log, wenn ich weitere Unregelmässigkeiten feststelle.
'nen Extrem-Slowdown bis zum Freeze hatte ich allerdings noch nicht, ist also schon länger nicht mehr passiert. Ist halt schwierig, das Ganze zu provozieren, es geschieht scheinbar "einfach so" und "irgendwann". Blöde Beschreibung, ich weiss... Vielleicht folgt ja doch noch was Handfestes im Log. *daumendrück*

Edit: Irgendwie bin ich wohl zu blöd zum Anhängen hier, deshalb hier DER LINK ZUM LOG.

[ingrid]

Ich habe das Log geupdated (Link in dem Post über diesem, ist immer noch der Durchlauf, den ich gestern gestartet habe - läuft immer noch).

Keine Freezes oder Extrem-Slowdowns. Ist ja immer so, wenn man's direkt testen will.

Das einzige, was durchgängig zu sein scheint ist, dass manchmal der Now-Event einfach nicht kommt, bzw. das relativ lange dauert (um die 20 Sekunden) und sich bis dahin die Box zäh verhält. Ist mir gerade eben wieder auf "DW-TV (EUROPA)" aufgefallen. Als ich weitergezappt habe, war die Last der Box wieder normal. Zurück auf DW-TV - kein Now-Event - wurde die Box wieder langsam.

Wenn Interesse besteht, stochere & beobachte ich mal weiter, das Log läuft ja einfach vor sich hin.

Spärliche Informationen bis hierhin, aber evtl. kann Nirvana schon irgendwas in dem Log erkennen? *hoff*

Evtl könnte jemand mit den ähnlichen Problemen auch mal nachschauen, ob er nicht einen besseren Report auf die Reihe bekommt... Das erhöht die Chancen, dass Nirvana das Problem unkompliziert fixen kann. Bei ihm tritt ja leider nichts davon auf.

[ingrid]

Selbst auf die Gefahr hin, dass ich mit mir selbst rede... ;-)

Hier ist ein Ausschnitt aus dem Log, während die Box unendlich lange auf EPG bei "DW TV (EUROPA)" wartet.

Wohlgemerkt: DIE BOX IST SEIT GESTERN NICHT NEUGESTARTET WORDEN, also scheint sie den EPG, den sie heute bei DW-TV schon hatte, einfach vergessen zu haben. Seltsam... Naja, jetzt kommt gar kein EPG mehr auf DIESER Box für diesen Sender rein.

Code: Alles auswählen

Connection from UDS
version: 5, cmd: 30, numbytes: 1
data length: 2
commandSetPrivatePid
[sectionsd] version update from 0x1f to 0x01 for table 0x4e table_extension 0x6e2f section 0x01
Connection from UDS
version: 5, cmd: 20, numbytes: 1
data length: 8
commandComponentTagsUniqueKey
Request of ComponentTags for 0x43100016e2993d8
ComponentTags found.
components.size 2 
 16:9 
 stereo 
[sectionsd] version update from 0x03 to 0x06 for table 0x4e table_extension 0x6e32 section 0x00
Connection from UDS
version: 5, cmd: 25, numbytes: 1
data length: 16
commandserviceChanged
[sectionsd] commandserviceChanged: Service changed to      262f001025f
--> '[sectionsd] commandserviceChanged: before messaging lock' 889.036000
[sectionsd] commandserviceChanged: current service-descriptor not loaded yet!
--> '[sectionsd] commandserviceChanged: before wakeup' 1.199000
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 0.689000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.670000
changeDMX [12]-> current/next (0x4e)
--> 'after DMX_SET_FILTER' 11.444000
--> '[sectionsd] commandserviceChanged: after doWakeup' 0.800000
[sectionsd] version update from 0x1f to 0x0d for table 0x4e table_extension 0x6e2e section 0x01
[sectionsd] version update from 0x08 to 0x16 for table 0x4e table_extension 0x6e2d section 0x01
[sectionsd] version update from 0x1f to 0x01 for table 0x4e table_extension 0x6e2f section 0x00
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 25, numbytes: 1
data length: 16
commandserviceChanged
[sectionsd] commandserviceChanged: Service changed to      262f001025f
--> '[sectionsd] commandserviceChanged: before messaging lock' 195.855000
--> '[sectionsd] commandserviceChanged: before wakeup' 0.817000
[sectionsd] commandserviceChanged: ignoring wakeup request...
--> '[sectionsd] commandserviceChanged: after doWakeup' 1.004000
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 30, numbytes: 1
data length: 2
commandSetPrivatePid
dmx.read timeout - filter: 4e - timeout# 0
dmx.read timeout - filter: 4e - timeout# 1
dmx.read timeout - filter: 4e - timeout# 2
[eitThread] skipping to next filter(1) (> DMX_TIMEOUT_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 1496.060000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.726000
changeDMX [12]-> scheduled (0x50)
--> 'after DMX_SET_FILTER' 4.224000
[sectionsd] version update from 0x08 to 0x0b for table 0x50 table_extension 0x6e47 section 0x98
[sectionsd] version update from 0x02 to 0x05 for table 0x50 table_extension 0x6e29 section 0xc0
[sectionsd] version update from 0x0d to 0x0f for table 0x50 table_extension 0x6e2a section 0xb0
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
dmx.read timeout - filter: 50 - timeout# 0
dmx.read timeout - filter: 50 - timeout# 1
dmx.read timeout - filter: 50 - timeout# 2
[eitThread] skipping to next filter(2) (> DMX_TIMEOUT_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 1715.403000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.717000
changeDMX [12]-> scheduled (0x4e)
--> 'after DMX_SET_FILTER' 3.974000
dmx.read timeout - filter: 4e - timeout# 0
dmx.read timeout - filter: 4e - timeout# 1
dmx.read timeout - filter: 4e - timeout# 2
[eitThread] skipping to next filter(3) (> DMX_TIMEOUT_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 1525.462000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.727000
changeDMX [12]-> scheduled (0x50)
--> 'after DMX_SET_FILTER' 3.968000
dmx.read timeout - filter: 50 - timeout# 0
dmx.read timeout - filter: 50 - timeout# 1
dmx.read timeout - filter: 50 - timeout# 2
[eitThread] skipping to next filter(4) (> DMX_TIMEOUT_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 1525.667000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.726000
changeDMX [12]-> scheduled (0x60)
--> 'after DMX_SET_FILTER' 3.970000
dmx.read timeout - filter: 60 - timeout# 0
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 25, numbytes: 1
data length: 16
commandserviceChanged
[sectionsd] commandserviceChanged: Service changed to      262f001025f
--> '[sectionsd] commandserviceChanged: before messaging lock' 988.339000
[sectionsd] commandserviceChanged: current service-descriptor not loaded yet!
--> '[sectionsd] commandserviceChanged: before wakeup' 1.191000
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 0.688000
dmx.read timeout - filter: 60 - timeout# 1
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 24.390000
changeDMX [12]-> current/next (0x4e)
--> 'after DMX_SET_FILTER' 4.010000
--> '[sectionsd] commandserviceChanged: after doWakeup' 1.059000
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
dmx.read timeout - filter: 4e - timeout# 2
[eitThread] skipping to next filter(1) (> DMX_TIMEOUT_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 505.066000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.712000
changeDMX [12]-> scheduled (0x50)
--> 'after DMX_SET_FILTER' 4.074000
dmx.read timeout - filter: 50 - timeout# 0
dmx.read timeout - filter: 50 - timeout# 1
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
dmx.read timeout - filter: 50 - timeout# 2
[eitThread] skipping to next filter(2) (> DMX_TIMEOUT_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 1524.462000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.726000
changeDMX [12]-> scheduled (0x4e)
--> 'after DMX_SET_FILTER' 3.968000
dmx.read timeout - filter: 4e - timeout# 0
dmx.read timeout - filter: 4e - timeout# 1
dmx.read timeout - filter: 4e - timeout# 2
[eitThread] skipping to next filter(3) (> DMX_TIMEOUT_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 1526.038000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.717000
changeDMX [12]-> scheduled (0x50)
--> 'after DMX_SET_FILTER' 3.973000
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 25, numbytes: 1
data length: 16
commandserviceChanged
[sectionsd] commandserviceChanged: Service changed to      262f001025f
--> '[sectionsd] commandserviceChanged: before messaging lock' 277.256000
--> '[sectionsd] commandserviceChanged: before wakeup' 0.817000
[sectionsd] commandserviceChanged: ignoring wakeup request...
--> '[sectionsd] commandserviceChanged: after doWakeup' 1.003000
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
dmx.read timeout - filter: 50 - timeout# 0
dmx.read timeout - filter: 50 - timeout# 1
dmx.read timeout - filter: 50 - timeout# 2
[eitThread] skipping to next filter(4) (> DMX_TIMEOUT_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 1245.435000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.728000
changeDMX [12]-> scheduled (0x60)
--> 'after DMX_SET_FILTER' 3.970000
dmx.read timeout - filter: 60 - timeout# 0
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
dmx.read timeout - filter: 60 - timeout# 1
dmx.read timeout - filter: 60 - timeout# 2
dmxEIT: going to sleep...
eit_set_update_filter
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 25, numbytes: 1
data length: 16
commandserviceChanged
[sectionsd] commandserviceChanged: Service changed to      262f001025f
--> '[sectionsd] commandserviceChanged: before messaging lock' 2558.399000
--> '[sectionsd] commandserviceChanged: before wakeup' 0.914000
[sectionsd] commandserviceChanged: ignoring wakeup request...
--> '[sectionsd] commandserviceChanged: after doWakeup' 1.462000
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
dmxPPT: waking up again - looking for new events :)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 79675.788000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.720000
changeDMX [b11]-> current/next (0xa0)
--> 'after DMX_SET_FILTER' 3.662000
dmxPPT: no valid pid 0
[pptThread] going to sleep...
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
Connection from UDS
version: 5, cmd: 25, numbytes: 1
data length: 16
commandserviceChanged
[sectionsd] commandserviceChanged: Service changed to      262f001025f
--> '[sectionsd] commandserviceChanged: before messaging lock' 49777.551000
[sectionsd] commandserviceChanged: current service-descriptor not loaded yet!
--> '[sectionsd] commandserviceChanged: before wakeup' 1.201000
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 0.687000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.668000
eit_stop_update_filter
dmxEIT: waking up again - requested from .change()
--> '[sectionsd] commandserviceChanged: after doWakeup' 4.936000
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
dmx.read timeout - filter: 4e - timeout# 0
dmx.read timeout - filter: 4e - timeout# 1
dmx.read timeout - filter: 4e - timeout# 2
[eitThread] skipping to next filter(1) (> DMX_TIMEOUT_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 1529.299000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.727000
changeDMX [12]-> scheduled (0x50)
--> 'after DMX_SET_FILTER' 4.035000
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f
dmx.read timeout - filter: 50 - timeout# 0
dmx.read timeout - filter: 50 - timeout# 1
dmx.read timeout - filter: 50 - timeout# 2
[eitThread] skipping to next filter(2) (> DMX_TIMEOUT_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 1525.233000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.728000
changeDMX [12]-> scheduled (0x4e)
--> 'after DMX_SET_FILTER' 4.040000
dmx.read timeout - filter: 4e - timeout# 0
dmx.read timeout - filter: 4e - timeout# 1
dmx.read timeout - filter: 4e - timeout# 2
[eitThread] skipping to next filter(3) (> DMX_TIMEOUT_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 1527.112000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.720000
changeDMX [12]-> scheduled (0x50)
--> 'after DMX_SET_FILTER' 4.114000
dmx.read timeout - filter: 50 - timeout# 0
dmx.read timeout - filter: 50 - timeout# 1
dmx.read timeout - filter: 50 - timeout# 2
[eitThread] skipping to next filter(4) (> DMX_TIMEOUT_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 1523.602000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.815000
changeDMX [12]-> scheduled (0x60)
--> 'after DMX_SET_FILTER' 4.040000
dmx.read timeout - filter: 60 - timeout# 0
dmx.read timeout - filter: 60 - timeout# 1
dmx.read timeout - filter: 60 - timeout# 2
dmxEIT: going to sleep...
eit_set_update_filter
Connection from UDS
version: 5, cmd: 17, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for      262f001025f

Hier ist nochmal das vollständige Log: sectionsd.log.rar

[Nirvana]

Interessant finde ich diesen Teil:

Code: Alles auswählen

commandserviceChanged 
[sectionsd] commandserviceChanged: Service changed to      262f001025f 
--> '[sectionsd] commandserviceChanged: before messaging lock' 889.036000 
[sectionsd] commandserviceChanged: current service-descriptor not loaded yet! 
--> '[sectionsd] commandserviceChanged: before wakeup' 1.199000 
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 0.689000 
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.670000 
changeDMX [12]-> current/next (0x4e) 
--> 'after DMX_SET_FILTER' 11.444000 
--> '[sectionsd] commandserviceChanged: after doWakeup' 0.800000 
[sectionsd] version update from 0x1f to 0x0d for table 0x4e table_extension 0x6e2e section 0x01 
[sectionsd] version update from 0x08 to 0x16 for table 0x4e table_extension 0x6e2d section 0x01 
[sectionsd] version update from 0x1f to 0x01 for table 0x4e table_extension 0x6e2f section 0x00 
Connection from UDS 
version: 5, cmd: 17, numbytes: 1 
data length: 8 
commandCurrentNextInfoChannelID 
[sectionsd] Request of current/next information for      262f001025f 
Connection from UDS 
version: 5, cmd: 17, numbytes: 1 
data length: 8 
commandCurrentNextInfoChannelID 
[sectionsd] Request of current/next information for      262f001025f 
Connection from UDS 
version: 5, cmd: 25, numbytes: 1 
data length: 16 
commandserviceChanged 
[sectionsd] commandserviceChanged: Service changed to      262f001025f 
--> '[sectionsd] commandserviceChanged: before messaging lock' 195.855000 
--> '[sectionsd] commandserviceChanged: before wakeup' 0.817000 
[sectionsd] commandserviceChanged: ignoring wakeup request... 
--> '[sectionsd] commandserviceChanged: after doWakeup' 1.004000 
Connection from UDS 
version: 5, cmd: 17, numbytes: 1 
data length: 8 
commandCurrentNextInfoChannelID 
[sectionsd] Request of current/next information for      262f001025f 
Connection from UDS 
version: 5, cmd: 30, numbytes: 1 
data length: 2 
commandSetPrivatePid 
dmx.read timeout - filter: 4e - timeout# 0 
dmx.read timeout - filter: 4e - timeout# 1 
dmx.read timeout - filter: 4e - timeout# 2 

Da wird 2x hintereinander commandservicechanged aufgerufen. Das bringt offenbar den dmx durcheinander. Jedenfalls kommt dann der Timeout. Ein Workaround den ich schon lange vor hatte (auch weil sectionsd immer losrödelt bloß weil man ? drückt) wird sein, dass der dmx nur neu gestartet wird, wenn sich der Sender auch wirklich ändert.
Dass das 2x aufgerufen wird könnte am zunächst fehlenden Now Event liegen. Davon abgesehen schaue ich mir mal den Code zum Stoppen des DMX an.

[ingrid]

Super! Danke schön. ;-)

Soll ich's Logging noch laufen lassen oder reicht das so weit?

[Nirvana]

Vielleicht möchte einer der Betroffenen dieses Diff gegen das aktuelle CVS testen.

http://ulc.tuxbox-cvs.sourceforge.net// ... tory=Diffs&

[mb405]

mach ich doch glatt.
info kommt in 30minuten.

[mb405]

so
sectionsd macht nur das, wenn ich ? drücke

Code: Alles auswählen

Connection from UDS
version: 5, cmd: 16, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for       110085000e
[sectionsd] current EPG found.
[sectionsd] next EPG found.

wenn epgwechsel/sendungswechel erfolgt, dann kommt das.

Code: Alles auswählen

housekeeping.
before removeoldevents
after removeoldevents
total size of memory occupied by chunks handed out by malloc: 1793228
total bytes memory allocated with `sbrk' by malloc, in bytes: 1848940 (1805kb, 1.76MB)
Removed 1 old events.
before removewasteepg
dmxPPT: waking up again - looking for new events :)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 241096.137000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.733000
changeDMX [0]-> current/next (0xa0)
--> 'after DMX_SET_FILTER' 3.299000
dmxPPT: no valid pid 0
[pptThread] going to sleep...
going to search dvb-s provider Astra/Eurobird 28.2E
going to search dvb-s provider ASTRA 1D/3A 23.5E
going to search dvb-s provider Astra 19.2E
...
Wasted ONID:0085 TSID:0004 SID:0a82
Same ONID:0085 TSID:0004 SID:0a82
...
going to search dvb-s provider Astra/Eurobird 28.2E
going to search dvb-s provider ASTRA 1D/3A 23.5E
going to search dvb-s provider Astra 19.2E
Wasted ONID:0085 TSID:0006 SID:0081
Same ONID:0085 TSID:0006 SID:0081
Same ONID:0085 TSID:0006 SID:0081
Same ONID:0085 TSID:0006 SID:0081
...
Same ONID:0085 TSID:0006 SID:0081
going to search dvb-s provider Astra/Eurobird 28.2E
going to search dvb-s provider ASTRA 1D/3A 23.5E
going to search dvb-s provider Astra 19.2E
Wasted ONID:0085 TSID:0006 SID:0082
...
going to search dvb-s provider Astra/Eurobird 28.2E
going to search dvb-s provider ASTRA 1D/3A 23.5E
going to search dvb-s provider Astra 19.2E
Wasted ONID:0001 TSID:0441 SID:3397
Same ONID:0001 TSID:0441 SID:3397
Same ONID:0001 TSID:0441 SID:3397
...
Same ONID:0001 TSID:0441 SID:3397
after removewasteepg
total size of memory occupied by chunks handed out by malloc: 1793228
total bytes memory allocated with `sbrk' by malloc, in bytes: 1848940 (1805kb, 1.76MB)
Removed 187 waste events.
Number of sptr events (event-ID): 2635
Number of sptr events (service-id, start time, event-id): 2635
Number of sptr events (end time, service-id, event-id): 2635
Number of sptr nvod events (event-ID): 0
Number of cached meta-services: 0
Number of services: 0
Number of cached nvod-services: 0
total size of memory occupied by chunks handed out by malloc: 1685116
total bytes memory allocated with `sbrk' by malloc, in bytes: 2926188 (2857kb, 2.79MB)
Connection from UDS
version: 5, cmd: 16, numbytes: 1
data length: 8
commandCurrentNextInfoChannelID
[sectionsd] Request of current/next information for       110085000e
[sectionsd] current EPG found.
[sectionsd] next EPG found.
Connection from UDS
version: 5, cmd: 19, numbytes: 1
data length: 8
commandComponentTagsUniqueKey
Request of ComponentTags for 0x110085000e10c5
ComponentTags found.
components.size 2
 4:3
 Deutsch
Connection from UDS
version: 5, cmd: 14, numbytes: 1
data length: 54440
commandEventListTVids
Request of TV event list (IDs).

[sectionsd] sendEventList - response-size: 0x129b
eit_stop_update_filter
dmxEIT: waking up again - looking for new events :)
New Filterindex: 2 (ges. 5)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 88838.180000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.725000
changeDMX [12]-> scheduled (0x4e)
--> 'after DMX_SET_FILTER' 4.020000
[sectionsd] skipped duplicate section for table 0x4f table_extension 0x0307 section 0x00
[sectionsd] version update from 0x1c to 0x1f for table 0x4f table_extension 0x0014 section 0x01
[sectionsd] version update from 0x0e to 0x11 for table 0x4f table_extension 0x0081 section 0x01
...
[sectionsd] version update from 0x18 to 0x01 for table 0x4f table_extension 0x00a7 section 0x01
[sectionsd] skipped duplicate section for table 0x4f table_extension 0x0307 section 0x00
[sectionsd] skipped duplicate section for table 0x4f table_extension 0x0014 section 0x01
[sectionsd] skipped duplicate section for table 0x4f table_extension 0x0081 section 0x01
...
[sectionsd] skipped duplicate section for table 0x4f table_extension 0x0307 section 0x00
[eitThread] skipping to next filter(3) (> DMX_HAS_ALL_SECTIONS_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 2057.124000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.720000
changeDMX [12]-> scheduled (0x50)
--> 'after DMX_SET_FILTER' 6.384000
[sectionsd] skipped duplicate section for table 0x50 table_extension 0x0013 section 0x58
...
[sectionsd] skipped duplicate section for table 0x50 table_extension 0x0013 section 0x58
[eitThread] skipping to next filter(4) (> DMX_HAS_ALL_SECTIONS_SKIPPING)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 10043.603000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.717000
changeDMX [12]-> scheduled (0x60)
--> 'after DMX_SET_FILTER' 7.682000
[sectionsd] skipped duplicate section for table 0x60 table_extension 0x0305 section 0x18
...
[sectionsd] skipped duplicate section for table 0x60 table_extension 0x0305 section 0x18
dmxEIT: going to sleep...
eit_set_update_filter
dmxPPT: waking up again - looking for new events :)
--> 'changeDMX: before pthread_mutex_lock(&start_stop_mutex)' 200056.572000
--> 'changeDMX: after pthread_mutex_lock(&start_stop_mutex)' 0.732000
changeDMX [0]-> current/next (0xa0)
--> 'after DMX_SET_FILTER' 3.425000
dmxPPT: no valid pid 0
[pptThread] going to sleep...
housekeeping.
before removeoldevents
after removeoldevents
total size of memory occupied by chunks handed out by malloc: 1710780
total bytes memory allocated with `sbrk' by malloc, in bytes: 1947244 (1901kb, 1.86MB)
Removed 2 old events.
before removewasteepg
going to search dvb-s provider Astra/Eurobird 28.2E
going to search dvb-s provider ASTRA 1D/3A 23.5E
going to search dvb-s provider Astra 19.2E
...
going to search dvb-s provider Astra/Eurobird 28.2E
going to search dvb-s provider ASTRA 1D/3A 23.5E
going to search dvb-s provider Astra 19.2E
after removewasteepg
total size of memory occupied by chunks handed out by malloc: 1710780
total bytes memory allocated with `sbrk' by malloc, in bytes: 1947244 (1901kb, 1.86MB)
Removed 10 waste events.
Number of sptr events (event-ID): 2642
Number of sptr events (service-id, start time, event-id): 2642
Number of sptr events (end time, service-id, event-id): 2642
Number of sptr nvod events (event-ID): 0
Number of cached meta-services: 0
Number of services: 0
Number of cached nvod-services: 0
total size of memory occupied by chunks handed out by malloc: 1701332
total bytes memory allocated with `sbrk' by malloc, in bytes: 2754156 (2689kb, 2.63MB)

ich hoffe das hilft ?

[Nirvana]

Ich hatte nur gegen die Freezes gekämpft. Sonst keine Änderung.

[Nico 77]

@mb405
Kannste den gedifften sectionsd hochladen, würde auch gerne mal testen zum log posten?