Ja, das "synchronized" von getCacheEntryBlocking ist der Grund, warum der "handle tv data added" angehalten bzw. blockiert wird. Ich kann zwar nicht sagen, warum das so ist, weil ich die Multithreading-Mechanismen vom TVBrowser nicht so ganz verstehe. Aber der Debugger von Eclipse behauptet, der Thread "TV data update" sei der Grund.
Um zumindest das ursächliche Szenario weiter einzugrenzen, habe ich mal ein abgespecktes Plugin (s.Anhang) geschrieben, das dem Titel und der Beschreibung jeder Sendung ein "*" voransetzt, damit man nicht behaupten kann, es liege am allzu sehr ausgeuferten Plugin selbst.
Code: Alles auswählen
public void handleTvDataAdded(MutableChannelDayProgram newProg) {
long in = System.currentTimeMillis();
String sNewProg = newProg.getChannel() + " " + newProg.getDate();
System.out.println("==> handleTvDataAdded: " + sNewProg);
System.out.println("... handleTvDataAdded: " + sNewProg);
Iterator<Program> it = newProg.getPrograms();
while ((it != null) && (it.hasNext())) {
MutableProgram program = (MutableProgram)it.next();
if (program == null) {
continue;
}
String sTitle = program.getTitle();
program.setTitle("*" + sTitle);
String sDescription = program.getDescription();
program.setDescription("*" + sDescription);
}
long out = System.currentTimeMillis();
System.out.println("<== handleTvDataAdded (" + (out - in) + "ms): " + sNewProg);
}
Über die System.out.println-Aufrufe kann man in der Konsole sehen, dass die Callback-Methode aufgerufen wurde und dass sie wieder verlassen wurde. Beim Verlassen wird noch die Verweildauer in handleTvDataAdded ausgegeben. Werte um bzw. größer 10000ms bedeuten abgebrochene Threads (t.join(10000)), die bei getCacheEntryBlocking hängengeblieben waren. Wenn ich meinen Beobachtungen trauen kann, tritt das Blockade-Problem dann ein, wenn ein Tag ganz neu heruntergeladen wird und der vormals letzte Tag (also der Vortag des neuen Tages) ebenfalls die Sendungen nach 24Uhr aktualisieren muss.
Mit anderen Worten: TVBrowser hat z.B. Daten fürs ZDF bis zum 22.8.. Bei der Datenaktualisierung kommt der 23.8. dazu. handleTvDataAdded wird während der Ausführung für die Sendungen des 22.8. nach 24 Uhr blockiert.
Interessanterweise passiert dies nicht immer, aber sehr, sehr oft. Hier mal die Log-Ausgabe einer solchen Blockade, die durch einfaches Löschen des ZDF-tvdata vom 23.8. mit anschließender Datenaktualisierung reproduziert werden konnte:
Code: Alles auswählen
==> handleTvDataAdded: ZDF Fr, 23. Aug
... handleTvDataAdded: ZDF Fr, 23. Aug
<== handleTvDataAdded (0ms): ZDF Fr, 23. Aug
==> handleTvDataAdded: ZDF Do, 22. Aug
... handleTvDataAdded: ZDF Do, 22. Aug
<== handleTvDataAdded (10001ms): ZDF Do, 22. Aug
Das sollte ich sich vielleicht noch mal jemand anderes als ich anschauen, der einfach mehr Ahnung mit den Zusammenhängen der TVBrowser-Innereien hat. In meinen Augen erscheint ja selbst das Spawnen eines neuen Threads pro handleTvDataAdded-Aufruf unnötig bzw. overkill, zumal ja bereits aus einem Thread heraus gespawnt wird, der nicht der Haupt-UI-Thread ist. Es ist also eigentlich gar kein Grund bzw. Nutzen dieser Multithreading-Orgie erkennbar. Naja, ein einziger Nutzen vielleicht schon: man kann durch den Timeout in join eventuelle Deadlock-Knoten zerschlagen. Allerdings ist dieser Deadlock TVBrowser-hausgemacht und sollte an der Wurzel und nicht durch Abwürgen des Plugins gelöst werden.
Mit der (Er-)Kenntnis, dass der spawnende Thread ("TV data update") den gespawnten Thread ("handle tv data added") im beschriebenen Szenario blockiert, und dass der spawnende Thread im Normalfall sowieso 10 Sekunden auf die Beendigung des gespawnten Threads wartet, also Multithreading hier ad absurdum geführt wird, würde ich eher dafür plädieren, dass "TV data update" handleTvDataAdded direkt und ohne Thread-Gedöns aufruft. Das behebt auf jeden Fall schon mal das Blockade-Problem.
Jetzt wird man zwar bestimmt wieder sagen: "Was ist mit den Plugins, die möglicherweise schlecht programmiert sind und den TVBrowser lahmlegen? Die muss der TVBrowser doch nach 10 Sekunden abwürgen können." Ich bin eher der Meinung, dass man das dem Benutzer überlassen sollte, dass also der TVBrowser anzeigt, welches Plugin gerade wie lange schon läuft, so dass sich der Benutzer sein eigenes Urteil bilden kann und die lahmen Krücken unter den Plugins dann abschaltet. Oder auch nicht...
Ja, das "synchronized" von getCacheEntryBlocking ist der Grund, warum der "handle tv data added" angehalten bzw. blockiert wird. Ich kann zwar nicht sagen, warum das so ist, weil ich die Multithreading-Mechanismen vom TVBrowser nicht so ganz verstehe. Aber der Debugger von Eclipse behauptet, der Thread "TV data update" sei der Grund.
Um zumindest das ursächliche Szenario weiter einzugrenzen, habe ich mal ein abgespecktes Plugin (s.Anhang) geschrieben, das dem Titel und der Beschreibung jeder Sendung ein "*" voransetzt, damit man nicht behaupten kann, es liege am allzu sehr ausgeuferten Plugin selbst. :wink:
[code]
public void handleTvDataAdded(MutableChannelDayProgram newProg) {
long in = System.currentTimeMillis();
String sNewProg = newProg.getChannel() + " " + newProg.getDate();
System.out.println("==> handleTvDataAdded: " + sNewProg);
System.out.println("... handleTvDataAdded: " + sNewProg);
Iterator<Program> it = newProg.getPrograms();
while ((it != null) && (it.hasNext())) {
MutableProgram program = (MutableProgram)it.next();
if (program == null) {
continue;
}
String sTitle = program.getTitle();
program.setTitle("*" + sTitle);
String sDescription = program.getDescription();
program.setDescription("*" + sDescription);
}
long out = System.currentTimeMillis();
System.out.println("<== handleTvDataAdded (" + (out - in) + "ms): " + sNewProg);
}
[/code]
Über die System.out.println-Aufrufe kann man in der Konsole sehen, dass die Callback-Methode aufgerufen wurde und dass sie wieder verlassen wurde. Beim Verlassen wird noch die Verweildauer in handleTvDataAdded ausgegeben. Werte um bzw. größer 10000ms bedeuten abgebrochene Threads (t.join(10000)), die bei getCacheEntryBlocking hängengeblieben waren. Wenn ich meinen Beobachtungen trauen kann, tritt das Blockade-Problem dann ein, wenn ein Tag ganz neu heruntergeladen wird und der vormals letzte Tag (also der Vortag des neuen Tages) ebenfalls die Sendungen nach 24Uhr aktualisieren muss.
Mit anderen Worten: TVBrowser hat z.B. Daten fürs ZDF bis zum 22.8.. Bei der Datenaktualisierung kommt der 23.8. dazu. handleTvDataAdded wird während der Ausführung für die Sendungen des 22.8. nach 24 Uhr blockiert.
Interessanterweise passiert dies nicht immer, aber sehr, sehr oft. Hier mal die Log-Ausgabe einer solchen Blockade, die durch einfaches Löschen des ZDF-tvdata vom 23.8. mit anschließender Datenaktualisierung reproduziert werden konnte:
[code]
==> handleTvDataAdded: ZDF Fr, 23. Aug
... handleTvDataAdded: ZDF Fr, 23. Aug
<== handleTvDataAdded (0ms): ZDF Fr, 23. Aug
==> handleTvDataAdded: ZDF Do, 22. Aug
... handleTvDataAdded: ZDF Do, 22. Aug
<== handleTvDataAdded (10001ms): ZDF Do, 22. Aug
[/code]
Das sollte ich sich vielleicht noch mal jemand anderes als ich anschauen, der einfach mehr Ahnung mit den Zusammenhängen der TVBrowser-Innereien hat. In meinen Augen erscheint ja selbst das Spawnen eines neuen Threads pro handleTvDataAdded-Aufruf unnötig bzw. overkill, zumal ja bereits aus einem Thread heraus gespawnt wird, der nicht der Haupt-UI-Thread ist. Es ist also eigentlich gar kein Grund bzw. Nutzen dieser Multithreading-Orgie erkennbar. Naja, ein einziger Nutzen vielleicht schon: man kann durch den Timeout in join eventuelle Deadlock-Knoten zerschlagen. Allerdings ist dieser Deadlock TVBrowser-hausgemacht und sollte an der Wurzel und nicht durch Abwürgen des Plugins gelöst werden.
Mit der (Er-)Kenntnis, dass der spawnende Thread ("TV data update") den gespawnten Thread ("handle tv data added") im beschriebenen Szenario blockiert, und dass der spawnende Thread im Normalfall sowieso 10 Sekunden auf die Beendigung des gespawnten Threads wartet, also Multithreading hier ad absurdum geführt wird, würde ich eher dafür plädieren, dass "TV data update" handleTvDataAdded direkt und ohne Thread-Gedöns aufruft. Das behebt auf jeden Fall schon mal das Blockade-Problem.
Jetzt wird man zwar bestimmt wieder sagen: "Was ist mit den Plugins, die möglicherweise schlecht programmiert sind und den TVBrowser lahmlegen? Die muss der TVBrowser doch nach 10 Sekunden abwürgen können." Ich bin eher der Meinung, dass man das dem Benutzer überlassen sollte, dass also der TVBrowser anzeigt, welches Plugin gerade wie lange schon läuft, so dass sich der Benutzer sein eigenes Urteil bilden kann und die lahmen Krücken unter den Plugins dann abschaltet. Oder auch nicht... :)