ruebox / openhab2-addons

Add-ons for openHAB 2.x
Eclipse Public License 1.0
16 stars 6 forks source link

FreeAtHome: Timeout while waiting on advertised authentication mechanisms #57

Open Cybso opened 4 years ago

Cybso commented 4 years ago

I'm failing to use the FreeAtHome addon with OpenHAB 2.5.5. I've tested on a clean default installation on Raspberry Pi.

The log says:

15:30:33.126 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'freeathome:bridge:e144bd48' changed from UNINITIALIZED to INITIALIZING
15:30:33.473 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - SysAP Info:2.5.1
15:30:33.931 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Login: user      with the current jid: 031bf211-7a3f-4c84-93dd-e67c3d1f5d90@busch-jaeger.de
15:30:33.939 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Login: installer      with the current jid: installer@busch-jaeger.de
15:30:33.947 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Login: admin      with the current jid: e33b42b5-8cad-48b8-a2fb-da0fc230f230@busch-jaeger.de
15:30:33.953 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Login: openhab      with the current jid: d3890891-439f-4954-bdeb-ed8ee2ce8012@busch-jaeger.de
15:30:33.960 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Matching jid for login(openhab)      d3890891-439f-4954-bdeb-ed8ee2ce8012@busch-jaeger.de
15:30:38.198 [WARN ] [.core.thing.internal.ThingManagerImpl] - Initializing handler for thing 'freeathome:bridge:e144bd48' takes more than 5000ms.
15:30:40.005 [WARN ] [thome.handler.FreeAtHomeBridgeHandler] - rocks.xmpp.core.session.NoResponseException: Timeout while waiting on advertised authentication mechanisms.
15:30:40.008 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'freeathome:bridge:e144bd48' changed from INITIALIZING to OFFLINE (COMMUNICATION_ERROR): Can not connect to SysAP with address: 10.11.12.54
15:31:11.057 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'freeathome:bridge:e144bd48' changed from OFFLINE (COMMUNICATION_ERROR): Can not connect to SysAP with address: 10.11.12.54 to REMOVING
15:31:11.070 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'freeathome:bridge:e144bd48' changed from REMOVING to REMOVED
15:31:11.208 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'freeathome:bridge:e144bd48' changed from REMOVED to UNINITIALIZED
15:31:11.261 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'freeathome:bridge:e144bd48' changed from UNINITIALIZED to OFFLINE (CONFIGURATION_ERROR): Bridge removed
15:31:11.272 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'freeathome:bridge:e144bd48' changed from OFFLINE (CONFIGURATION_ERROR): Bridge removed to OFFLINE (BRIDGE_OFFLINE): Connection closed
15:31:11.282 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'freeathome:bridge:e144bd48' changed from OFFLINE (BRIDGE_OFFLINE): Connection closed to UNINITIALIZED (HANDLER_MISSING_ERROR)

Same with OpenHAB 2.4.0-1 after purge and clean install:

15:49:18.917 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'freeathome:bridge:2da26227' changed from UNINITIALIZED to INITIALIZING
15:49:19.195 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - SysAP Info:2.5.1
15:49:23.941 [WARN ] [.core.thing.internal.ThingManagerImpl] - Initializing handler for thing 'freeathome:bridge:2da26227' takes more than 5000ms.
15:49:25.086 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Login: user      with the current jid: 031bf211-7a3f-4c84-93dd-e67c3d1f5d90@busch-jaeger.de
15:49:25.095 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Login: installer      with the current jid: installer@busch-jaeger.de
15:49:25.103 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Login: admin      with the current jid: e33b42b5-8cad-48b8-a2fb-da0fc230f230@busch-jaeger.de
15:49:25.111 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Login: openhab      with the current jid: d3890891-439f-4954-bdeb-ed8ee2ce8012@busch-jaeger.de
15:49:25.119 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Matching jid for login(openhab)      d3890891-439f-4954-bdeb-ed8ee2ce8012@busch-jaeger.de
15:49:26.289 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Login: user      with the current jid: 031bf211-7a3f-4c84-93dd-e67c3d1f5d90@busch-jaeger.de
15:49:26.294 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Login: installer      with the current jid: installer@busch-jaeger.de
15:49:26.302 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Login: admin      with the current jid: e33b42b5-8cad-48b8-a2fb-da0fc230f230@busch-jaeger.de
15:49:26.310 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Login: openhab      with the current jid: d3890891-439f-4954-bdeb-ed8ee2ce8012@busch-jaeger.de
15:49:26.319 [INFO ] [thome.handler.FreeAtHomeBridgeHandler] - Matching jid for login(openhab)      d3890891-439f-4954-bdeb-ed8ee2ce8012@busch-jaeger.de
15:49:26.962 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'freeathome:bridge:2da26227' changed from INITIALIZING to ONLINE

I've also tried the 2.5.0 version by @kjoglum:

16:00:21.161 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'freeathome:bridge:196df2f5' changed from UNINITIALIZED to INITIALIZING
16:00:21.994 [INFO ] [ernal.handler.FreeAtHomeBridgeHandler] - Login: user      with the current jid: 031bf211-7a3f-4c84-93dd-e67c3d1f5d90@busch-jaeger.de
16:00:21.996 [INFO ] [ernal.handler.FreeAtHomeBridgeHandler] - Login: installer      with the current jid: installer@busch-jaeger.de
16:00:21.998 [INFO ] [ernal.handler.FreeAtHomeBridgeHandler] - Login: admin      with the current jid: e33b42b5-8cad-48b8-a2fb-da0fc230f230@busch-jaeger.de
16:00:22.000 [INFO ] [ernal.handler.FreeAtHomeBridgeHandler] - Login: openhab      with the current jid: d3890891-439f-4954-bdeb-ed8ee2ce8012@busch-jaeger.de
16:00:22.003 [INFO ] [ernal.handler.FreeAtHomeBridgeHandler] - Matching jid for login(openhab)      d3890891-439f-4954-bdeb-ed8ee2ce8012@busch-jaeger.de
16:00:22.795 [WARN ] [rocks.xmpp.core.session.XmppSession  ] - <?xml version='1.0' encoding='UTF-8'?><stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" from="d3890891-439f-4954-bdeb-ed8ee2ce8012@busch-jaeger.de" to="busch-jaeger.de" version="1.0" xml:lang="de-DE">
16:00:22.798 [WARN ] [mpp.websocket.net.WebSocketConnection] - Websocketconnection open being sent
16:00:26.218 [WARN ] [.core.thing.internal.ThingManagerImpl] - Initializing handler for thing 'freeathome:bridge:196df2f5' takes more than 5000ms.
16:00:28.057 [WARN ] [ernal.handler.FreeAtHomeBridgeHandler] - rocks.xmpp.core.session.NoResponseException: Timeout while waiting on advertised authentication mechanisms.
16:00:28.060 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'freeathome:bridge:196df2f5' changed from INITIALIZING to OFFLINE (COMMUNICATION_ERROR): Can not connect to SysAP with address: 10.11.12.54

It seems that some change in OpenHAB triggers a timeout in rocks.xmpp.

Cybso commented 4 years ago

Update: the version from https://community.openhab.org/t/busch-jaeger-free-home/31043/224 (Feb 2nd) seems to work.

kjoglum commented 4 years ago

Update: the version from https://community.openhab.org/t/busch-jaeger-free-home/31043/224 (Feb 2nd) seems to work.

You could even try https://community.openhab.org/t/busch-jaeger-free-home/31043/313 to ensure you get all the updates/features.

Cybso commented 4 years ago

Thanks, great! Now it even finds my window sensors :-)