[Aufruf] IKEA-Trådfri Adapter testen

[AlCalzone]

Wenn das Problem bei dir täglich auftritt, liegts vermutlich an was anderem. Bei mir ist folgende Situation, die mich zum regelmäßigen Neustart des Gateways zwingt:

• Telekom VDSL-Router an uralter Hausverkabelung mit viel zu dünnen Kabeln.

• Im Keller: Uralter Schaltkasten mit Steckverbindern. Telefon-Kabel laufen parallel mit Stromkabeln zu 10 anderen Wohnungen.

• Irgendwann sagt dann der Router: "Ne, is nich!" und startet neu.

Und dann stimmt irgendwas mit den DNS-Einstellungen im Netzwerk nicht mehr.

Entweder verbindet das Gateway nicht mehr mit dem Router. Oder es verbindet, aber der Pi findet es mit dem Hostnamen nicht mehr.

[pxstd]

Genau so sieht es dann aus:

Grundsätzlich gibt es bei mir keinerlei Netzwerkprobleme. Das Gateway ist ja auch weiterhin Pingbar und auch über die Tradfri App selbst ansprechbar.

Ist der Adapter da so pingelig? Und vor allem: Wieso funktioniert der neue Verbindungsaufbau nicht im Anschluss, sondern es bedarf eines Adapter neustarts?

Ist das nicht ggfs. irgendwie zu automatisieren? Ansonsten ist die Einbindung in eine Hausautomation ja relativ witzlos

Und ja - fast täglich.

[AlCalzone]

@pxstd:

Wieso funktioniert der neue Verbindungsaufbau nicht im Anschluss, sondern es bedarf eines Adapter neustarts? `
Das hatte ich in Version 0.3.x ne Zeitlang drin - mit dem Ergebnis, dass sich bei mehreren Leuten beim ein oder anderen Neustart ein Prozess aufgehängt hat und die CPU auf Anschlag geschoben hat.

Bei dir scheint es aber wirklich ein systematisches Problem zu sein. Eventuell ist da was anderes im Argen.

Du könntest mal bei Gelegenheit einen erweiterten Log erstellen und mir die Datei zukommen lassen:

cd /opt/iobroker/node_modules/iobroker.tradfri
DEBUG=node-*-client node main.js --force > tradfri_log.txt 2>&1 

[Homoran]

Kann es sein, dass es ein Tradfri Firmware update von ikea gegeben hatte?

Danach musste ich auch immer den Adapter neu starten.

Gruß Rainer

[pxstd]

@AlCalzone:

@pxstd:

Wieso funktioniert der neue Verbindungsaufbau nicht im Anschluss, sondern es bedarf eines Adapter neustarts? `
Das hatte ich in Version 0.3.x ne Zeitlang drin - mit dem Ergebnis, dass sich bei mehreren Leuten beim ein oder anderen Neustart ein Prozess aufgehängt hat und die CPU auf Anschlag geschoben hat.

Bei dir scheint es aber wirklich ein systematisches Problem zu sein. Eventuell ist da was anderes im Argen.

Du könntest mal bei Gelegenheit einen erweiterten Log erstellen und mir die Datei zukommen lassen:

cd /opt/iobroker/node_modules/iobroker.tradfri
DEBUG=node-*-client node main.js --force > tradfri_log.txt 2>&1 

```` `  

Sure - einfach laufen lassen und abwarten?

[pxstd]

Gemacht, aber da kommt nix.

Shell:

` > root@iobroker:~# cd /opt/iobroker/node_modules/iobroker.tradfri

root@iobroker:/opt/iobroker/node_modules/iobroker.tradfri# DEBUG=node-*-client node main.js –force > tradfri_log.txt 2>&1 `

root@iobroker:/opt/iobroker/node_modules/iobroker.tradfri# tail -f tradfri_log.txt
2017-12-14T15:06:59.542Z node-coap-client CoAP client version 0.4.8

iobroker Web-Log:

` > tradfri.0 2017-12-14 16:42:25.045 info Connection to gateway reestablished

tradfri.0 2017-12-14 16:42:20.031 warn Lost connection to gateway

tradfri.0 2017-12-14 16:38:14.951 info Connection to gateway reestablished

tradfri.0 2017-12-14 16:38:09.935 warn Lost connection to gateway

tradfri.0 2017-12-14 16:34:04.897 info Connection to gateway reestablished

tradfri.0 2017-12-14 16:33:49.860 warn Lost connection to gateway

tradfri.0 2017-12-14 16:32:04.826 info Connection to gateway reestablished

tradfri.0 2017-12-14 16:31:59.824 warn Lost connection to gateway

tradfri.0 2017-12-14 16:27:54.796 info Connection to gateway reestablished

tradfri.0 2017-12-14 16:27:49.729 warn Lost connection to gateway

tradfri.0 2017-12-14 16:19:44.567 info Connection to gateway reestablished

tradfri.0 2017-12-14 16:19:39.564 warn Lost connection to gateway

tradfri.0 2017-12-14 16:17:34.526 info Connection to gateway reestablished

tradfri.0 2017-12-14 16:17:29.523 warn Lost connection to gateway

tradfri.0 2017-12-14 16:11:24.405 info Connection to gateway reestablished

tradfri.0 2017-12-14 16:11:19.391 warn Lost connection to gateway `

[AlCalzone]

@pxstd:

Gemacht, aber da kommt nix. `

Hm!? Bei mir sieht es so aus (bzw. gleiches Ergebnis mit der Textdatei):

DEBUG=node-*-client node main.js --force
  node-coap-client CoAP client version 0.4.8 +0ms
  node-coap-client reset() +1s
  node-coap-client 0 pending requests remaining... +1ms
  node-coap-client 0 pending connections remaining... +1ms
  node-coap-client 0 active connections remaining... +0ms
  node-coap-client getConnection(coaps://gw-b072bf257a41:5684) => establishing new connection +4ms
  node-coap-client successfully created socket for origin coaps://gw-b072bf257a41:5684 +89ms
  node-coap-client getConnection(coaps://gw-b072bf257a41:5684) => found existing connection +25ms

@Homoran:

Kann es sein, dass es ein Tradfri Firmware update von ikea gegeben hatte? `
Nein, immer noch 1.2.42.

Übrigens, kaum bin ich daheim sieht es bei mir so aus:

Ich muss nochmal mit dem Reconnect spielen, mich nervt es nämlich auch langsam. Hier liegt es aber definitiv am Netzwerk. MiVacuum und Cloud verabschieden sich auch regelmäßig.

[Homoran]

Auch wenn es nicht (direkt ) hilft.

Bei mir ist alles grün.

Version 1.0.0

Allerdings hat eine Fernbedienung in letzter Zeit oft keine Lust mehr gehabt.

Gruß

Rainer

[pxstd]

@AlCalzone:

@pxstd:

Gemacht, aber da kommt nix. `

Hm!? Bei mir sieht es so aus (bzw. gleiches Ergebnis mit der Textdatei):

DEBUG=node-*-client node main.js --force
  node-coap-client CoAP client version 0.4.8 +0ms
  node-coap-client reset() +1s
  node-coap-client 0 pending requests remaining... +1ms
  node-coap-client 0 pending connections remaining... +1ms
  node-coap-client 0 active connections remaining... +0ms
  node-coap-client getConnection(coaps://gw-b072bf257a41:5684) => establishing new connection +4ms
  node-coap-client successfully created socket for origin coaps://gw-b072bf257a41:5684 +89ms
  node-coap-client getConnection(coaps://gw-b072bf257a41:5684) => found existing connection +25ms

@Homoran:

Kann es sein, dass es ein Tradfri Firmware update von ikea gegeben hatte? `
Nein, immer noch 1.2.42.

Übrigens, kaum bin ich daheim sieht es bei mir so aus:

Unbenannt.PNG

Ich muss nochmal mit dem Reconnect spielen, mich nervt es nämlich auch langsam. Hier liegt es aber definitiv am Netzwerk. MiVacuum und Cloud verabschieden sich auch regelmäßig. `

Witzig. Das habe ich nicht, obwohl bei mir auch Cloud und Vac am start sind.

Es ist exklusiv nur Tradfri. (Okay - und manchmal die CCU2)

[pxstd]

` > root@iobroker:/opt/iobroker/node_modules/iobroker.tradfri# DEBUG=node-*-client node main.js –force

node-coap-client CoAP client version 0.4.8 +0ms

root@iobroker:/opt/iobroker/node_modules/iobroker.tradfri# `

Ohne Umleitung springt er gleich wieder in die Shell.

[pxstd]

Folgendes rauschte allerdings gerade durchs Weblog:

` > tradfri.0 2017-12-14 17:44:07.466 info updating possible scenes for group 131081: ["196632","196633","196634"]

tradfri.0 2017-12-14 17:44:07.402 info updating possible scenes for group 131081: ["196632","196633","196634"]

tradfri.0 2017-12-14 17:44:07.338 info updating possible scenes for group 131081: ["196632","196633","196634"]

tradfri.0 2017-12-14 17:44:07.274 info updating possible scenes for group 131080: ["196629","196630","196631"]

tradfri.0 2017-12-14 17:44:07.234 info updating possible scenes for group 131080: ["196629","196630","196631"]

tradfri.0 2017-12-14 17:44:07.194 info updating possible scenes for group 131080: ["196629","196630","196631"]

tradfri.0 2017-12-14 17:44:07.153 info updating possible scenes for group 131077: ["196620","196621","196622"]

tradfri.0 2017-12-14 17:44:07.053 info updating possible scenes for group 131077: ["196620","196621","196622"]

tradfri.0 2017-12-14 17:44:06.954 info updating possible scenes for group 131077: ["196620","196621","196622"]

tradfri.0 2017-12-14 17:44:06.865 info updating possible scenes for group 131073: ["196608","196609","196610"]

tradfri.0 2017-12-14 17:44:06.797 info updating possible scenes for group 131073: ["196608","196609","196610"]

tradfri.0 2017-12-14 17:44:06.728 info updating possible scenes for group 131073: ["196608","196609","196610"]

tradfri.0 2017-12-14 17:44:06.661 info got all scenes in group 131081: [196632,196633,196634]

tradfri.0 2017-12-14 17:44:06.642 info got all scenes in group 131080: [196629,196630,196631]

tradfri.0 2017-12-14 17:44:06.623 info got all scenes in group 131077: [196620,196621,196622]

tradfri.0 2017-12-14 17:44:06.602 info got all scenes in group 131073: [196608,196609,196610]

tradfri.0 2017-12-14 17:44:06.355 info got all groups: [131077,131073,131080,131081]

tradfri.0 2017-12-14 17:44:06.344 info got all devices: [65536,65553,65537,65543,65548,65549,65541,65551,65552,65538,65545,65546,65544,65550]

tradfri.0 2017-12-14 17:44:06.338 info Connection to gateway reestablished

tradfri.0 2017-12-14 17:44:01.310 warn 3 consecutive pings failed, resetting connection (attempt #2)…

tradfri.0 2017-12-14 17:43:41.304 warn Lost connection to gatewaytradfri.0 2017-12-14 17:43:27.440 info updating possible scenes for group 131081: ["196632","196633","196634"]

tradfri.0 2017-12-14 17:43:27.376 info updating possible scenes for group 131081: ["196632","196633","196634"]

tradfri.0 2017-12-14 17:43:27.312 info updating possible scenes for group 131081: ["196632","196633","196634"]

tradfri.0 2017-12-14 17:43:27.249 info updating possible scenes for group 131080: ["196629","196630","196631"]

tradfri.0 2017-12-14 17:43:27.209 info updating possible scenes for group 131080: ["196629","196630","196631"]

tradfri.0 2017-12-14 17:43:27.159 info updating possible scenes for group 131080: ["196629","196630","196631"]

tradfri.0 2017-12-14 17:43:27.119 info updating possible scenes for group 131077: ["196620","196621","196622"]

tradfri.0 2017-12-14 17:43:27.033 info updating possible scenes for group 131077: ["196620","196621","196622"]

tradfri.0 2017-12-14 17:43:26.941 info updating possible scenes for group 131077: ["196620","196621","196622"]

tradfri.0 2017-12-14 17:43:26.853 info updating possible scenes for group 131073: ["196608","196609","196610"]

tradfri.0 2017-12-14 17:43:26.781 info updating possible scenes for group 131073: ["196608","196609","196610"]

tradfri.0 2017-12-14 17:43:26.713 info updating possible scenes for group 131073: ["196608","196609","196610"]

tradfri.0 2017-12-14 17:43:26.646 info got all scenes in group 131081: [196632,196633,196634]

tradfri.0 2017-12-14 17:43:26.625 info got all scenes in group 131080: [196629,196630,196631]

tradfri.0 2017-12-14 17:43:26.609 info got all scenes in group 131077: [196620,196621,196622]

tradfri.0 2017-12-14 17:43:26.591 info got all scenes in group 131073: [196608,196609,196610]

tradfri.0 2017-12-14 17:43:26.347 info got all groups: [131077,131073,131080,131081]

tradfri.0 2017-12-14 17:43:26.341 info got all devices: [65536,65553,65537,65543,65548,65549,65541,65551,65552,65538,65545,65546,65544,65550]

tradfri.0 2017-12-14 17:43:26.332 info Connection to gateway reestablished

tradfri.0 2017-12-14 17:43:21.303 error unhandled promise rejection: CoapClient was reset

tradfri.0 2017-12-14 17:43:21.303 error unhandled promise rejection: CoapClient was reset

tradfri.0 2017-12-14 17:43:21.303 error unhandled promise rejection: CoapClient was reset

tradfri.0 2017-12-14 17:43:21.303 error unhandled promise rejection: CoapClient was reset

tradfri.0 2017-12-14 17:43:21.303 warn 3 consecutive pings failed, resetting connection (attempt #1)…

tradfri.0 2017-12-14 17:43:09.292 error at Timer.listOnTimeout (timers.js:214:5)

tradfri.0 2017-12-14 17:43:09.292 error at tryOnTimeout (timers.js:250:5)

tradfri.0 2017-12-14 17:43:09.292 error at ontimeout (timers.js:386:11)

tradfri.0 2017-12-14 17:43:09.292 error at Timeout.action [as _onTimeout] (/opt/iobroker/node_modules/iobroker.tradfri/node_modules/node-tradfri-client/node_modules/node-coap-client/build/CoapClient.js:222:46)

tradfri.0 2017-12-14 17:43:09.292 error at Function.retransmit (/opt/iobroker/node_modules/iobroker.tradfri/node_modules/node-tradfri-client/node_modules/node-coap-client/build/CoapClient.js:324:40)

tradfri.0 2017-12-14 17:43:09.292 error > stack: Error: Retransmit counter exceeded

tradfri.0 2017-12-14 17:43:09.290 error unhandled promise rejection: Retransmit counter exceeded

tradfri.0 2017-12-14 17:43:01.300 warn Lost connection to gateway

web.0 2017-12-14 17:42:47.067 info 2017-12-14T16:42:47.067Z Connected system.user.admin

tradfri.0 2017-12-14 17:42:46.308 info Connection to gateway reestablished

tradfri.0 2017-12-14 17:42:31.302 warn Lost connection to gateway

web.0 2017-12-14 17:42:04.146 info 2017-12-14T16:42:04.146Z Connected system.user.admin

web.0 2017-12-14 17:42:03.259 info 2017-12-14T16:42:03.259Z Connected system.user.admin

web.0 2017-12-14 17:41:53.166 info 2017-12-14T16:41:53.166Z Connected system.user.admin

web.0 2017-12-14 17:41:48.244 info 2017-12-14T16:41:48.244Z Connected system.user.admin

tradfri.0 2017-12-14 17:37:56.212 info Connection to gateway reestablished

tradfri.0 2017-12-14 17:37:51.181 warn Lost connection to gateway

tradfri.0 2017-12-14 17:36:46.166 info Connection to gateway reestablished

tradfri.0 2017-12-14 17:36:31.157 warn Lost connection to gateway

tradfri.0 2017-12-14 17:33:46.097 info Connection to gateway reestablished

tradfri.0 2017-12-14 17:33:41.091 warn Lost connection to gateway

tradfri.0 2017-12-14 17:05:35.512 info Connection to gateway reestablished

tradfri.0 2017-12-14 17:05:20.491 warn Lost connection to gateway

tradfri.0 2017-12-14 17:04:55.495 info Connection to gateway reestablished `

[pxstd]

Es wäre toll wenn sich das Problem irgendwie analysieren ließe. Der WAF hat aktuell einen sehr wackeligen Standpunkt

` > tradfri.0 2017-12-15 23:41:49.083 error Please restart the adapter!

tradfri.0 2017-12-15 23:41:49.083 error Cannot send changes.

tradfri.0 2017-12-15 23:41:49.083 error The connection to the gateway is dead.

tradfri.0 2017-12-15 23:41:48.644 error Please restart the adapter!

tradfri.0 2017-12-15 23:41:48.644 error Cannot send changes.

tradfri.0 2017-12-15 23:41:48.644 error The connection to the gateway is dead.

tradfri.0 2017-12-15 23:41:47.644 error Please restart the adapter!

tradfri.0 2017-12-15 23:41:47.643 error Cannot send changes.

tradfri.0 2017-12-15 23:41:47.643 error The connection to the gateway is dead. `

@AlCalzone: Was kann ich tun? Lass mich deine Laborratte sein!

[AlCalzone]

@pxstd:

Es wäre toll wenn sich das Problem irgendwie analysieren ließe. Da haben wirs: > Retransmit counter exceeded `
Es geht ein Paket verloren (anscheinend mit regelmäßiger Häufigkeit), wir müssen nur rausfinden, warum.

Stoppst du den Adapter übers Webinterface, bevor du ihn versuchst mit Debug-Log über die Konsole zu starten? Wenn nein, tu das bitte.

[pxstd]

@AlCalzone:

@pxstd:

Es wäre toll wenn sich das Problem irgendwie analysieren ließe. Da haben wirs: > Retransmit counter exceeded `
Es geht ein Paket verloren (anscheinend mit regelmäßiger Häufigkeit), wir müssen nur rausfinden, warum.

Stoppst du den Adapter übers Webinterface, bevor du ihn versuchst mit Debug-Log über die Konsole zu starten? Wenn nein, tu das bitte. `

Nein, habe ich aber nun:

[AlCalzone]

Danke für den Log, sieht für mich gut aus.

Gab es im Log-Zeitraum einen Verbindungsabbruch?

Wenn nicht, brauche ich einen Log, während dem das Problem aufgetreten ist. Am besten noch mit der Option –logs, damit die ioBroker-Ausgaben ebenfalls darin auftauchen:

DEBUG=node-*-client node main.js --force --logs > tradfri_log.txt 2>&1

[pxstd]

Ich befürchte einen Vorführeffekt.

Ich lasse den Adapter nochmal im Debug laufen.

[pxstd]

Hey,

also seit letztem Posting laufen gelassen - jetzt gerade reagiert keine Lampe mehr, deshalb anbei der Export:

[AlCalzone]

Danke für den Log. Der relevante Part scheint dieser zu sein:

! ````
[...]
2017-12-18T13:13:31.611Z node-coap-client workOffSendQueue > queue empty
2017-12-18T13:13:40.618Z node-coap-client getConnection(coaps://10.1.15.102:5684) => found existing connection
2017-12-18T13:13:40.618Z node-coap-client remembering request: msgID=0x122, token=, url=coaps://10.1.15.102:5684
2017-12-18T13:13:40.618Z node-coap-client added message to send queue, new length = 1
2017-12-18T13:13:40.618Z node-coap-client workOffSendQueue > concurrency = 0 (MAX 1)
2017-12-18T13:13:40.618Z node-coap-client concurrency low enough, sending message 0x122
2017-12-18T13:13:40.618Z node-coap-client request 0x122: concurrency changed => 1
2017-12-18T13:13:40.626Z node-coap-client received message: ID=0x122
2017-12-18T13:13:40.626Z node-coap-client request 0x122: concurrency changed => 0
2017-12-18T13:13:40.627Z node-coap-client workOffSendQueue > queue empty
2017-12-18T13:13:40.627Z node-coap-client received response to ping with ID 0x122
2017-12-18T13:13:40.627Z node-coap-client forgetting request: token=; msgID=0x122
ping successful...
2017-12-18T13:13:41.620Z node-coap-client workOffSendQueue > queue empty
2017-12-18T13:13:50.625Z node-coap-client getConnection(coaps://10.1.15.102:5684) => found existing connection
2017-12-18T13:13:50.625Z node-coap-client remembering request: msgID=0x123, token=, url=coaps://10.1.15.102:5684
2017-12-18T13:13:50.625Z node-coap-client added message to send queue, new length = 1
2017-12-18T13:13:50.625Z node-coap-client workOffSendQueue > concurrency = 0 (MAX 1)
2017-12-18T13:13:50.625Z node-coap-client concurrency low enough, sending message 0x123
2017-12-18T13:13:50.625Z node-coap-client request 0x123: concurrency changed => 1
2017-12-18T13:13:51.627Z node-coap-client workOffSendQueue > queue empty
2017-12-18T13:13:55.627Z node-coap-client forgetting request: token=; msgID=0x123
2017-12-18T13:13:55.627Z node-coap-client request 0x123: concurrency changed => 0
2017-12-18T13:13:55.627Z node-coap-client workOffSendQueue > queue empty
ping unsuccessful...
[...]

In Summe nichts auffälliges, außer dass das Gateway auf den letzten Ping nicht antwortet und danach auch nicht mehr.

Auf vorherige Anfragen werden aber weiterhin Updates geschickt… Seltsam. Ich muss nochmal mit dem automatischen Restart spielen, schätze da führt kein Weg dran vorbei.

[pxstd]

Das wäre toll. Der Adapter ist genial und löst einige meiner Probleme - wenn er denn dann reagiert!

[Nanouk]

Hallo in die Runde,

nach langer Zeit hab ich mich auch mal wieder mit dem Tradfri Adapter beschäftigt.

Da iobroker bei mir auf einer Windows Kiste läuft und ich mehrfach alles zerschossen hatte beim Node update, habe ich gedacht ich teste den Adapter mal wieder, da jetzt Node auf der Windows Kiste auch auf v6 läuft.

Leider bekomme ich keine Verbindung zum Adapter. Ampel bleibt gelb.

tradfri.0	2017-12-22 10:04:10.760	error	at process._tickCallback (internal/process/next_tick.js:109:7)
tradfri.0	2017-12-22 10:04:10.760	error	at fulfilled (D:\ioBroker\node_modules\iobroker.tradfri\node_modules\node-tradfri-client\build\tradfri-client.js:4:58)
tradfri.0	2017-12-22 10:04:10.760	error	at next (native)
tradfri.0	2017-12-22 10:04:10.760	error	> stack: TypeError: Generator is already running
tradfri.0	2017-12-22 10:04:10.760	error	unhandled promise rejection: Generator is already running
tradfri.0	2017-12-22 10:04:10.744	info	startfile = D:\ioBroker\node_modules\iobroker.tradfri\main.js
tradfri.0	2017-12-22 10:04:10.604	info	starting. Version 1.0.0 in D:/ioBroker/node_modules/iobroker.tradfri, node: v6.12.0

Kann vielleicht jemand was mit den Fehlermeldungen anfangen?

Grüße,

Nanouk