Harmony Adapter: lost hub + Adapter neustart
-
Hi,
ab und zu verliert der Harmony Adapter die Verbindung zum Hub, danach tauchen Fehler im Log auf und der Adapter wird neu gestartet.
Weiss jemand ob das ein Fehler im Adapter oder ioBroker ist ob der Fehler wo anders liegt. Unten das Log, wenn weitere infos nötig sind stell ich die gern zur Verfügung.
scenes-0 2015-11-22 10:47:40 info restartAdapter harmony-0 2015-11-22 10:44:46 info synced hub config harmony-0 2015-11-22 10:44:46 info creating activities and devices harmony-0 2015-11-22 10:44:45 info connected to Wohnzimmer-Hub harmony-0 2015-11-22 10:44:44 info discovered Wohnzimmer-Hub harmony-0 2015-11-22 10:44:41 info discover start harmony-0 2015-11-22 10:44:41 info hub initialized harmony-0 2015-11-22 10:44:41 info starting. Version 0.5.4 in /opt/iobroker/node_modules/iobroker.harmony host-ioBroker 2015-11-22 10:44:35 info instance system.adapter.harmony.0 started with pid 3880 host-ioBroker 2015-11-22 10:44:05 info Restart adapter system.adapter.harmony.0 because enabled host-ioBroker 2015-11-22 10:44:05 error instance system.adapter.harmony.0 terminated with code 6 (uncaught exception) harmony-0 2015-11-22 10:44:05 info terminating Error: 2015-11-22 10:44:05 error at process._tickCallback (node.js:358:17) Error: 2015-11-22 10:44:05 error at doNTCallback3 (node.js:452:9) Error: 2015-11-22 10:44:05 error at dgram.js:213:18 Error: 2015-11-22 10:44:05 error at exports._exceptionWithHostPort (util.js:897:20) Error: 2015-11-22 10:44:05 error at Object.exports._errnoException (util.js:874:11) Error: 2015-11-22 10:44:05 error bind EADDRINUSE 0.0.0.0:5224 uncaught 2015-11-22 10:44:05 error exception: bind EADDRINUSE 0.0.0.0:5224 harmony-0 2015-11-22 10:44:04 warn lost Wohnzimmer-Hub harmony-0 2015-11-22 10:44:02 warn keep alive cannot get current Activity: Error: Timed out after 5000 ms -
Das Problem habe ich selber auch, konnte es bisher leider nicht identifizieren :x
-
Schon mal gut zu wissen das ich nicht der einzige bin und du davon weisst.
Weisst du warum er die Verbindung zum Hub verliert? Die Zeit scheint keine Rolle zu spielen, manchmal kommt das schon nach 5 Minuten und manchmal Stunden lang nicht.
Edit: Ab und zu bekomm ich auch die Meldung Hub busy. Da hilft dann nur ein neustart des Adapters. Soweit ich das bisher nach vollziehen konnte liegt das daran das ein Befehl nicht an den Hub gesendet werden kann. Der bleibt dann so lange in der Warteschleife bis der Adapter eine neue Verbindung aufbaut, dann wird der Befehl gesendet. Der Nachfolgende Befehl, für den die Meldung im Log auftaucht konnte ich noch nicht sicher feststellen ob der dann auch gesendet wird.
harmony.0 2015-11-22 13:40:16 info harmony.0 hub busy, stateChange delayed: harmony.0.Wohnzimmer-Hub.activities.PS3_BluRay=2 -
@Jey Cee:Schon mal gut zu wissen das ich nicht der einzige bin und du davon weisst.
Weisst du warum er die Verbindung zum Hub verliert? Die Zeit scheint keine Rolle zu spielen, manchmal kommt das schon nach 5 Minuten und manchmal Stunden lang nicht. `
Ich werde das Gefühl nicht los, dass es am Ende am Hub selber liegt, den habe ich auch schon dabei erwischt wie die LED auf einmal Rot wurde (kein Wlan) und kurz darauf wieder Grün. Hatte da leider den Adapter nicht laufen, kann den Zusammenhang also nicht sicher annehmen.
@Jey Cee:Edit: Ab und zu bekomm ich auch die Meldung Hub busy. Da hilft dann nur ein neustart des Adapters. Soweit ich das bisher nach vollziehen konnte liegt das daran das ein Befehl nicht an den Hub gesendet werden kann. Der bleibt dann so lange in der Warteschleife bis der Adapter eine neue Verbindung aufbaut, dann wird der Befehl gesendet. Der Nachfolgende Befehl, für den die Meldung im Log auftaucht konnte ich noch nicht sicher feststellen ob der dann auch gesendet wird.
harmony.0 2015-11-22 13:40:16 info harmony.0 hub busy, stateChange delayed: harmony.0.Wohnzimmer-Hub.activities.PS3_BluRay=2 ```` `Das könnte tatsächlich ein Bug sein, ich beschreibe mal wie der Adapter korrekt arbeiten sollte:
Wenn du an der Harmony Ultimate FB oder in der Harmony App eine Aktivität startest wird für die Zeit des Starts ein Popup angezeigt "starte…" und es können gar keine weiteren Befehle an den Hub gesendet werden. Dieser würde Befehle in der Zeit auch gar nicht ausführen.
Im ioBroker Adapter habe ich das so gelöst, dass der Adapter alle eingehenden Befehle in der Startzeit in eine Warteschlange legt und erst ausführt wenn die Aktivität gestartet ist.
Jetzt gilt im Hub das gleiche auch für alle andere Befehle, wie z. B. "TV lauter", dieser Befehl braucht ebenfalls eine gewisse Zeit zur Verarbeitung. Im Adapter wird standardmäßig für jeden Gerätebefehl 100ms angenommen, wird in der Zeit ein weiterer Befehl ausgeführt kommt er wieder in die Warteschlange. Wenn du beim Befehl "Tv lauter" 5000 eingibst wird dieser Befehl übrigens für 5 Sekunden ausgeführt, also so, als ob du auf der richtigen FB 5 Sekunden auf Lauter drückst.
Ob der Adapter aktuell "offen" ist oder ob die Befehle in die Warteschlange kommen siehst du übrigens an dem "hubBlocked" State.
Die Info im log bedeutet aber nur, dass der eingehende Befehl erstmal in die Warteschlange gekommen ist.
Sollte der Befehl nie ausgeführt werden kannst du gerne mal die Situation, in der der Fehler aufgetreten ist, genauer beschreiben.
-
> Ich werde das Gefühl nicht los, dass es am Ende am Hub selber liegt, den habe ich auch schon dabei erwischt wie die LED auf einmal Rot wurde (kein Wlan) und kurz darauf wieder Grün. Hatte da leider den Adapter nicht laufen, kann den Zusammenhang also nicht sicher annehmen.Ich hab den Adapter mal auf Debug im Log gestellt. Laut dem beendet der Hub die Verbindung. Bei mir konnte ich aber nicht beobachten das die LED rot wurde.
Hier das Log:
harmony-0 2015-11-22 14:19:16 debug discover started inMem 2015-11-22 14:19:15 debug message harmony.0.* harmony.0.Wohnzimmer-Hub.hubConnected val=false, ack=true, ts=1448198355, q=0, from=system.adapter.harmony.0, lc=1448198355 inMem 2015-11-22 14:19:15 debug message harmony.0.* harmony.0.Wohnzimmer-Hub.hubConnected val=false, ack=true, ts=1448198355, q=0, from=system.adapter.harmony.0, lc=1448198355 harmony-0 2015-11-22 14:19:15 debug client ended harmony-0 2015-11-22 14:19:15 debug discover ended harmony-0 2015-11-22 14:19:15 warn lost Wohnzimmer-Hub harmony-0 2015-11-22 14:19:13 warn keep alive cannot get current Activity: Error: Timed out after 5000 msDas andere werde ich nochmal Testen sobald der Fernseher nicht in Gebrauch ist. Sonst gibts ärger
-
Ich hab jetzt mal über ne Stunde lang versucht durch testen Informationen zu Gewinnen, wann genau die Befehle nicht mehr gesendet werden.
Aber es hat sich kein Muster finden lassen.
Deshalb hier mal ne Beschreibung der Funktion die ich Ausführe:
Ich hab 2 Szenen angelegt, beide Schalten zu erst eine Schaltsteckdose ein, dann wird mit 70 Sekunden Verzögerung eine Activity im Harmony Hub gestartet. Siehe Bild für details. Die 70 Sekunden Verzögerung habe ich eingebaut damit auch wirklich alle Geräte Einsatzbereit sind, der TV schaltet sich kurz ein und dann wieder aus bevor man ihn nutzen kann und der Harmony Hub braucht etwas Zeit zum Booten.
Hier mal ein Log als es mal nicht ging, es ist ein eine Timeout Warnung zu sehen die aber nicht jedesmal auftaucht. Was auffällt ist das sie erst nachdem senden des ersten Befehls auftaucht. Der erste Befehl wird auch noch ausgeführt.
! harmony.0 2015-11-23 12:32:10 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.hubBlocked
! harmony.0 2015-11-23 12:32:10 debug harmony.0 switching activity to: PS3_BluRay
! harmony.0 2015-11-23 12:32:10 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.activities.PS3_BluRay
! harmony.0 2015-11-23 12:29:48 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.hubBlocked
! harmony.0 2015-11-23 12:29:48 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.activities.PS3_BluRay
! harmony.0 2015-11-23 12:29:48 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.activities.Wiedergabe_PS3
! harmony.0 2015-11-23 12:29:48 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.activities.Musik_hören
! harmony.0 2015-11-23 12:29:48 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.activities.Fernsehen
! harmony.0 2015-11-23 12:29:48 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.activities.Tv_Schauen
! harmony.0 2015-11-23 12:29:48 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.activities.currentStatus
! harmony.0 2015-11-23 12:29:48 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.activities.currentActivity
! harmony.0 2015-11-23 12:29:48 debug harmony.0 current activity: Tv_Schauen
! harmony.0 2015-11-23 12:29:47 warn harmony.0 keep alive cannot get current Activity: Error: Timed out after 5000 ms
! harmony.0 2015-11-23 12:29:40 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.activities.Tv_Schauen
! harmony.0 2015-11-23 12:29:40 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.activities.currentStatus
! harmony.0 2015-11-23 12:29:40 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.activities.currentActivity
! harmony.0 2015-11-23 12:29:40 debug harmony.0 current activity: Tv_Schauen
! harmony.0 2015-11-23 12:29:40 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.hubBlocked
! harmony.0 2015-11-23 12:29:40 debug harmony.0 switching activity to: Tv_Schauen
! harmony.0 2015-11-23 12:29:40 debug inMem message harmony.0.* harmony.0.Wohnzimmer-Hub.activities.Tv_Schauen
! hm-rpc.0 2015-11-23 12:28:30 info hm-rpc.0 setValue ["LEQ0573981:1","STATE",true] BOOL
! hm-rpc.0 2015-11-23 12:28:30 info hm-rpc.0 setValue ["LEQ0573981:1","STATE",true] BOOLZum Testen hab ich die Lautstärke meines AV Recivers geändert, seit der Befehl einmal nicht gesendet wurde, steht der Entsprechende Datanpunkt auf "1" und wurde auch nach einem Adapter Neustart nicht zurück auf Null gesetzt.
282_szenen.png -
uncaught 2015-11-22 10:44:05 error exception: bind EADDRINUSE 0.0.0.0:5224Ich kann jetzt zumindest sagen das der Fehler auftritt weil der Port nicht wieder Freigegeben wird. Es ist nur die Frage ob HarmonyHubJS-discover (ping.js) nicht richtig beendet wird oder dort der Port nicht wieder frei gegeben wird wenn es beendet wird.
Vielleicht hilft dir das weiter.
2.
harmony-0 2015-11-22 14:19:13 warn keep alive cannot get current Activity: Error: Timed out after 5000 msIch hab mal Testhalber bei keepAlive() zu der Warnung die Ausgegeben wird noch den Funktionsaufruf connect(hub) eingefügt damit er neu verbindet.
Das hat auch Wunderbar funktioniert. Wäre es denkbar das fest in den Adapter ein zu bauen oder gibt es Probleme die ich noch nicht gesehen habe?
-
Also nochmal zum Verständnis: Irgendwie bricht die Verbindung zum Hub ab und was dann passiert löst einen Absturz und Neustart des Adapter aus? Du konntest das beheben indem du direkt wieder ein connect sendest, aber nicht dass die Verbindung überhaupt abbricht?
Wenn das zuverlässig klappt könnte ich das so in den Adapter einbauen, die Frage bleibt aber warum die Verbindung abbricht und was passiert bei deiner Lösung wenn der Hub wirklich weg ist und man nicht neu Verbinden kann?
-
> Irgendwie bricht die Verbindung zum Hub ab
Der Grund für den Abbruch der Verbindung ist bei mir der das ich ihn komplett abschalte.> was dann passiert löst einen Absturz und Neustart des Adapter aus?
Ja.> Du konntest das beheben indem du direkt wieder ein connect sendest, aber nicht dass die Verbindung überhaupt abbricht?
Nein. Das ist was anderes. Es kommt vor das keine Antwort mehr vom Hub kommt, obwohl er noch da ist und erreichbar, dann reicht ein neuer Connect zum Hub aus.> was passiert bei deiner Lösung wenn der Hub wirklich weg ist und man nicht neu Verbinden kann?
Gar nichts da KeepAlive nur ausgeführt wird wenn ein Hub verbunden ist.Ob der Hub noch da ist oder nicht prüft KeepAlive ja gar nicht, die verhindert nur das der Hub den Adapter(client) nicht wegen inaktivität abmeldet.
Ob der Hub noch da ist wird von Harmony Hub JS-Discover geprüft. Ist der Hub weg/die Verbindung Unterbrochen, wird Discover Neu gestartet. Beim Neustart wird Discover aber nicht richtig beendet und deswegen ist weiterhin der Port 5224 belegt, beim Neustart von Discover löst das den Fehler aus und der Harmony Adapter wird Neu gestartet.
-
@Jey Cee:Ob der Hub noch da ist oder nicht prüft KeepAlive ja gar nicht, die verhindert nur das der Hub den Adapter(client) nicht wegen inaktivität abmeldet.
Ob der Hub noch da ist wird von Harmony Hub JS-Discover geprüft. Ist der Hub weg/die Verbindung Unterbrochen, wird Discover Neu gestartet. Beim Neustart wird Discover aber nicht richtig beendet und deswegen ist weiterhin der Port 5224 belegt, beim Neustart von Discover löst das den Fehler aus und der Harmony Adapter wird Neu gestartet. `
Also wenn der Hub von keepAlive nicht mehr erreicht werden kann kommt nicht das hub lost von discover? Dann könnte man die beiden Situationen immerhin gut unterscheiden. Die gesamte Connect/Disconnect/Reconnect Geschichte müsste nochmal überarbeitet werden denke ich.
Dabei müsste dann folgendes berücksichtigt werden:
-Der Adapter wird hin und wieder die Verbindung zum Hub verlieren, das kann man mit der keepAlive Funktion prüfen und bei bedarf neu verbinden
-Ob der Hub wirklich verfügbar ist oder offline bzw. stromlos wird mit dem discover geprüft, ist er verfügbar wird er verbunden, ist er nicht mehr verfügbar wird der client zerstört.
-discover kann man nicht korrekt stoppen, da dabei der Port nicht frei wird. kann man discover einfach durchlaufen lassen? Wieso wird es aktuell überhaupt neugestartet (weiß ich nicht mehr :lol: )?
Ich kann leider erst in 7 Tagen wieder dran arbeiten, wenn du willst kannst du aber gerne den Adapter forken und gucken ob du was verbessern kannst
-
Fork… was? Bin kein programmierer und hab mit Mühe und not die Zusammenhänge im Adapter verstanden. Ich kann ein bisschen rum spielen und vielleicht find ich eine Lösung, zu der ich dir dann auch gerne den code gebe, aber mit github hab ich nix am Hut.
Gesendet von meinem Jolla mit Tapatalk
-
Kein Problem, ich werde das dann nächste Woche irgendwann mal angehen. Du hast auf jeden Fall schon gut geholfen
-
So ich hab den Fehler gefunden. Du hattest ihn aber wohl auch schon entdeckt, gleich am Anfang der harmony.js steht: fix discover stop.
Damit wolltest du wohl die Fehlerhafte Funktion in der ping.js von discover Überschreiben. Das scheint aber nicht funktioniert zu haben. Ich hab das direkt in der ping.js geändert und es klappt. Deshalb hab ich darum gebeten das im Original auf Github ein zu pflegen.
Wäre aber auch zu einfach wenn jetzt alles gut wäre. Dafür schmeißt er jetzt einen anderen Fehler aus und startet den Adapter neu.
Ich weiss zwar schon wie man mit dem Problem umgehen kann, aber ich weiss noch nicht wo das hin muss. Also weiter suchen :x
PS: Jetzt bin ich halt doch bei Github :lol:
-
hehe super. Ja ich erinnere mich dunkel daran, dass da was war mit dem stoppen beim discover.
Ich habe hier mal aus der Ferne was zusammen gewurstelt, da wird discover überhaupt nicht mehr gestoppt und läuft die ganze zeit weiter. Vielleicht kannst du diese Version ja mal testen wenn du Zeit hast.
422_harmony.js -
Hab grad ne email bekommen, dass der Fix in discover eingepflegt wurde.
Gesendet von meinem Jolla mit Tapatalk
-
Das ist schonmal gut, ich nehme dann in der nächsten Version den stop Fix komplett raus. Fände es aber noch besser wenn man den Discover durchlaufen lassen kann, ich glaube dass ich den gestoppt hatte war auch wegen einem Bug, da er nach einem Lost keine Hubs mehr gefunden hatte. Ich glaube das funktioniert jetzt korrekt.
-
Moin,
ich habe 2 Hubs. Küche und Wohnzimmer. Nur der Wohnzimmer zeigt ähnliche Symptome. Verbindung wird hergestellt, dann wieder verloren und Adapter wird neu gestartet. Fehlerlog kann ich heute Abend gern mal ranhängen, wenn ich zu Hause wieder darauf zugreifen kann.
Macht es Sinn die oben angehängte harmony.js auszutauschen und zu probieren?
Gruß, Markus
-
Das beste wäre du kopierst logs vom alten Adapter, tauschst dann mal aus und guckst ob es besser wird
Hast du beide Hubs eingebunden? Also laufen 2 Adapter gleichzeitig?
-
Das beste wäre du kopierst logs vom alten Adapter, tauschst dann mal aus und guckst ob es besser wird
`
Ok mach ich so. Macht ja Sinn. Dann hat man die Logs vorher/nachher zum Vergleich. Hätte vermutlich aber ohnehin die alten Logs erstmal rein instinktiv gepostet.
@Pman:Hast du beide Hubs eingebunden? Also laufen 2 Adapter gleichzeitig? `
Nein, es läuft aktuell nur ein Adapter (mit Wohnzimmer). Es werden aber aber beide Hubs gefunden/erkannt und der Wohnzimmer immer wieder verloren. Ich hatte einen 2. mit Küche versucht zu konfigurieren, aber da lief dann plötzlich gar nichts mehr und das Log strotzte vor Fehlern (Details habe ich nicht mehr im Kopf). Kann ich aber gern nochmal probieren und dann die Logs liefern, falls das hilft. -
Es werden aber aber beide Hubs gefunden/erkannt und der Wohnzimmer immer wieder verloren. Ich hatte einen 2. mit Küche versucht zu konfigurieren, aber da lief dann plötzlich gar nichts mehr und das Log strotzte vor Fehlern (Details habe ich nicht mehr im Kopf). Kann ich aber gern nochmal probieren und dann die Logs liefern, falls das hilft. `
Kannst du dir sparen, hätte mich nämlich gewundert wenn zwei Adapter gleichzeitig funktionieren würden. So wie der Adapter aktuell funktioniert, mit dem discover, kann nur ein Adapter gleichzeitig laufen, da der Adapter einen bestimmten Netzwerkport verwendet. Unterstützung für mehrere Hubs muss ich daher direkt in den Adapter einbauen. Vorher sollte aber erstmal ein Adapter alleine stabil laufen.
