[harmonyhub] "Failed communicating with Harmony Hub" with firmware 4.15.206

wborn commented 5 years ago

As part of a "security related fix" Logitech has closed access to the undocumented XMPP API on port 5222 of their Hub with firmware 4.15.206:

Harmony Hub firmware (v4.15.206)

Logitech released a firmware update for Harmony hub-based remotes which addresses security vulnerabilities brought to our attention by a third-party cyber security firm. Logitech takes our customers’ security seriously, and we work diligently to fix these type of issues as they’re discovered. >We are aware that some customers using Harmony APIs which were never documented, nor supported Harmony features. While it is unfortunate that customers using these features are affected by this fix, the overall security of our products and all of our customers is our priority.

As a result the binding is no longer able to communicate with Hubs running the 4.15.206 firmware.

For example the following exception is logged due to this issue:

2018-12-17 14:43:46.248 [DEBUG] [b.internal.handler.HarmonyHubHandler] - Could not connect to HarmonyHub at 192.168.0.204
java.lang.RuntimeException: Failed communicating with Harmony Hub
    at net.whistlingfish.harmony.HarmonyClient.connect(HarmonyClient.java:193) ~[?:?]
    at net.whistlingfish.harmony.HarmonyClient.connect(HarmonyClient.java:118) ~[?:?]
    at org.openhab.binding.harmonyhub.internal.handler.HarmonyHubHandler.connect(HarmonyHubHandler.java:238) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
    at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: org.jivesoftware.smack.SmackException$ConnectionException: The following addresses failed: '192.168.0.204:5222' failed because: /192.168.0.204 exception: java.net.ConnectException: Connection refused (Connection refused)
    at org.jivesoftware.smack.SmackException$ConnectionException.from(SmackException.java:277) ~[?:?]
    at org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration(XMPPTCPConnection.java:617) ~[?:?]
    at org.jivesoftware.smack.tcp.XMPPTCPConnection.connectInternal(XMPPTCPConnection.java:888) ~[?:?]
    at org.jivesoftware.smack.AbstractXMPPConnection.connect(AbstractXMPPConnection.java:377) ~[?:?]
    at net.whistlingfish.harmony.HarmonyClient.connect(HarmonyClient.java:129) ~[?:?]
    ... 9 more

These are the known workarounds for keeping the XMPP API enabled:

Stay on the 4.15.201 firmware (and not sync to trigger updates)
After an upgrade to 4.15.206 restore the 4.15.193 firmware using the MyHarmony application
After an upgrade to 4.15.206 install the "developer" 4.15.210 firmware using the MyHarmony application

To remain on the 4.15.193, 4.15.201 versions internet access (or specific servers) has to be blocked to those Hubs). As a result some functionality of the Phone Apps will no longer work.

As a workaround we might be able to use another undocumented Websocket API.

See also:

Firmware release notes
Vulnerabilities found by Tenable fixed by Logitech
openHAB community thread
Logitech community
- Harmony Hub Firmware Update Fixes Vulnerabilities (includes "developer" 4.15.210 firmware instructions)
- Harmony Hub FW 4.15.206
Logitech MyHarmony software downloads (Windows/macOS only)

pytz commented 5 years ago

Logitech responded to the ongoing discussion and released a beta firmware which reenables the XMPP API. They plan to release a normal firmware update for all users in january. Until that you can install the beta using the MyHarmony app.

Disclaimer: I haven't tested the beta firmware as I already downgraded my hub.

Source

wborn commented 5 years ago

Very good! I've updated my first comment so it summarizes all the latest information.

giraf commented 5 years ago

I tested it and it works https://community.logitech.com/s/question/0D55A00008D4bZ4SAJ/harmony-hub-firmware-update-fixes-vulnerabilities

digitaldan commented 5 years ago

So what do we think? Do we want to stay with XMPP or switch to using a lighter weight websocket impl? I have something working (its crude , so don't judge :-) which would not be tough to swap out at this point. I only worry they shut down using websockets and we are back to XMPP.

https://github.com/digitaldan/harmony-client

wborn commented 5 years ago

Many thanks for working on this @digitaldan!

With the total U-turn Logitech made my mind says XMPP (support, already working well, no additional time to invest) whereas my heart says Websockets (maintainability, readability).

I'll have a look at your code anyhow. Do you think ultimately the Websockets would allow for the same features as the XMPP API?

It would be nice if Logitech retires the XMPP API within a few years (with heads up notice) and from then on only supports the Websockets API. AFAIK they currently use the Websockets with the iPhone App.

wborn commented 5 years ago

The code looks good!

Some other advantages of the Websocket approach are:

removes a lot of dependencies (Smack) so the bundle gets a lot smaller, most of the Jetty dependencies are probably already available in Karaf
debugging will be a lot easier compared to XMPP
probably fixes Exceptions and delays we currently have with the XMPP implementation

digitaldan commented 5 years ago

Thanks @wborn , its still a bit rough, but all the pieces are there. My use of Futures is a bit off, i need to clean that up and the error handling is not very robust, but over all its not in bad shape.

removes a lot of dependencies (Smack) so the bundle gets a lot smaller, most of the Jetty dependencies are probably already available in Karaf

Right, GSON and Jetty are the only two dependencies , so it's really light when used in openhab .

probably fixes Exceptions and delays we currently have with the XMPP implementation

This is maybe the most compelling part, the smack library is extremely complex and when something breaks, it's down somewhere deep in a complex web of code and threads that I honestly have a hard time understanding, much less debugging. Using a single websocket with jetty and GSON is very straight forward.

digitaldan commented 5 years ago

@wborn I could not leave it alone :-) I have our binding working against the new websocket library, changes were fairly limited,

https://github.com/digitaldan/openhab2-addons/commit/863c4b79b8fd948eacecd133b4d6a41e4e8a8cd1

The new websocket library needs some minor cleanup, logging and use of futures mostly, but is in good shape. I ported over the shell classes from the original library if people want to try out the command line version (see readme)

https://github.com/digitaldan/harmony-client/

I have a 2.5 snapshot jar I can post on my clone if anyone is interested

wborn commented 5 years ago

Thanks @digitaldan ! Looks like it now supports all features while the bundle got reduced from 2 MB to just 92 kB. :+1:

After testing it a bit I found the following minor issues compared to the existing implementation:

When restarting openHAB the currentActivity remains NULL, instead of it being updated to the current activity state. It does get properly updated when switching between activities while openHAB is running.
When sending button presses on the buttonPress channel, the button seems to be pressed twice. So if you mute the volume it is immediately unmuted again:

13:03:04.931 [INFO ] [smarthome.event.ItemCommandEvent     ] - Item 'harmonyhub_device_Hub_28914461_buttonPress' received command Mute
13:03:04.933 [DEBUG] [internal.handler.HarmonyDeviceHandler] - Pressing button 'Mute' on 28914461
13:03:04.939 [DEBUG] [com.digitaldan.harmony.HarmonyClient ] - Sending: {"hbus":{"cmd":"vnd.logitech.harmony/vnd.logitech.harmony.engine?holdAction","id":"3b5defea-a09e-4d86-b106-cd6ea76f1987","params":{"action":"{\"type\":\"IRCommand\",\"deviceId\":\"28914461\",\"command\":\"Mute\"}","status":"press","timestamp":487418}}}
13:03:04.947 [INFO ] [arthome.event.ItemStatePredictedEvent] - harmonyhub_device_Hub_28914461_buttonPress predicted to become Mute
13:03:04.949 [INFO ] [smarthome.event.ItemStateChangedEvent] - harmonyhub_device_Hub_28914461_buttonPress changed from NULL to Mute
13:03:05.152 [DEBUG] [com.digitaldan.harmony.HarmonyClient ] - Sending: {"hbus":{"cmd":"vnd.logitech.harmony/vnd.logitech.harmony.engine?holdAction","id":"f3569991-f120-4f7f-9c5f-f0def882ac06","params":{"action":"{\"type\":\"IRCommand\",\"deviceId\":\"28914461\",\"command\":\"Mute\"}","status":"press","timestamp":487630}}}
13:03:05.360 [INFO ] [smarthome.event.ItemStateChangedEvent] - harmonyhub_device_Hub_28914461_buttonPress changed from Mute to UNDEF

Other than that, it already seems to be a nice drop in replacement. :slightly_smiling_face:

digitaldan commented 5 years ago

When restarting openHAB the currentActivity remains NULL

Fixed.

When sending button presses on the buttonPress channel, the button seems to be pressed twice.

Yep, I was sending press twice instead of sending press then release, fixed.

NickWaterton commented 5 years ago

Can you post the .jar, so that we can try it out?

Thanks.

wborn commented 5 years ago

Thanks for fixing the issues @digitaldan! I've been using the websocket changes for several days without any other issues with the 4.15.206 FW.

Here's a org.openhab.binding.harmonyhub-2.5.0-SNAPSHOT.jar I just compiled with the latest bugfixes @NickWaterton .

NicoVermeir commented 5 years ago

I just tried the 2.5 snapshot version but it's not working for me. I'm running latest released openHAB, paperUI is showing that I'm running the 2.5.0 version of the binding My Hub is running 4.15.206

the binding detects the hub and can add is a thing in paperUI, but the status is always offline - communication error

the openHAB log is getting spammed with this:

2019-01-02 11:34:53.168 [ERROR] [com.digitaldan.harmony.HarmonyClient] - onWebSocketError
org.eclipse.jetty.websocket.api.MessageTooLargeException: Text message size [66417] exceeds maximum size [65536]
    at org.eclipse.jetty.websocket.api.WebSocketPolicy.assertValidTextMessageSize(WebSocketPolicy.java:140) ~[90:org.eclipse.jetty.websocket.api:9.4.11.v20180605]
    at org.eclipse.jetty.websocket.common.Parser.assertSanePayloadLength(Parser.java:127) ~[92:org.eclipse.jetty.websocket.common:9.4.11.v20180605]
    at org.eclipse.jetty.websocket.common.Parser.parseFrame(Parser.java:485) ~[92:org.eclipse.jetty.websocket.common:9.4.11.v20180605]
    at org.eclipse.jetty.websocket.common.Parser.parse(Parser.java:241) ~[92:org.eclipse.jetty.websocket.common:9.4.11.v20180605]
    at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.readParse(AbstractWebSocketConnection.java:560) [92:org.eclipse.jetty.websocket.common:9.4.11.v20180605]
    at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:391) [92:org.eclipse.jetty.websocket.common:9.4.11.v20180605]
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281) [75:org.eclipse.jetty.io:9.4.11.v20180605]
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) [75:org.eclipse.jetty.io:9.4.11.v20180605]
    at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) [75:org.eclipse.jetty.io:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) [87:org.eclipse.jetty.util:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) [87:org.eclipse.jetty.util:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) [87:org.eclipse.jetty.util:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) [87:org.eclipse.jetty.util:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) [87:org.eclipse.jetty.util:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762) [87:org.eclipse.jetty.util:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680) [87:org.eclipse.jetty.util:9.4.11.v20180605]
    at java.lang.Thread.run(Thread.java:748) [?:?]

digitaldan commented 5 years ago

here is my latest jar https://github.com/digitaldan/openhab2-addons/releases/download/harmony-websocket-1.0/org.openhab.binding.harmonyhub-2.5.0-SNAPSHOT.jar

the openHAB log is getting spammed with this:

Can you turn on debug logging for the harmony jar, like log:set DEBUG com.digitaldan

Also can you try using the test command line client: https://github.com/digitaldan/harmony-client/releases/download/0.0.1/harmony-client-1.0-SNAPSHOT-jar-with-dependencies.jar

and run it like java -Dorg.slf4j.simpleLogger.defaultLogLevel=DEBUG -cp target/harmony-client-1.0-SNAPSHOT-jar-with-dependencies.jar com.digitaldan.harmony.App 192.168.1.1

But of course with the IP of your HUB.

digitaldan commented 5 years ago

Also I will also look at increasing the buffer size if this is indeed the actual issue. @NicoVermeir does your Hub have a lot of devices? I'm wondering if the config coming back is really really big, or if its something else.

NicoVermeir commented 5 years ago

@digitaldan my hub has 6 devices I tried running your command line app but getting Error: Could not find or load main class com.digitaldan.harmony.App

tried both from an rpi and a Windows 10 pc

digitaldan commented 5 years ago

I tried running your command line app but getting Error: Could not find or load main class com.digitaldan.harmony.App

sorry, the command should be java -Dorg.slf4j.simpleLogger.defaultLogLevel=DEBUG -cp harmony-client-1.0-SNAPSHOT-jar-with-dependencies.jar com.digitaldan.harmony.App 192.168.1.1

I had a extra "target" in there

can you try https://github.com/digitaldan/openhab2-addons/releases/download/harmony-websocket-1.0/org.openhab.binding.harmonyhub-2.5.0-SNAPSHOT.jar? I just uploaded a new version which sets the buffer size to 1mb. Please download again if you had downloaded it earlier.

digitaldan commented 5 years ago

I had posted the wrong link above originally, it should be

https://github.com/digitaldan/openhab2-addons/releases/download/harmony-websocket-1.0/org.openhab.binding.harmonyhub-2.5.0-SNAPSHOT.jar

NicoVermeir commented 5 years ago

removed the previous 2.5 snapshot jar, downloaded the new one, restarted openhab2, getting the same message.

Celaeno1 commented 5 years ago

@digitaldan One question: Is it necessary to switch to firmware 4.15.206 for using the new "websocket" access? Or should it be possible also with 4.15.201?

vbier commented 5 years ago

Thanks for the jar. I tried the last jar you linked and get:

2019-01-07 19:55:22.328 [ERROR] [com.digitaldan.harmony.HarmonyClient] - onWebSocketError
org.eclipse.jetty.websocket.api.MessageTooLargeException: Text message size [79924] exceeds maximum size [65536]
    at org.eclipse.jetty.websocket.api.WebSocketPolicy.assertValidTextMessageSize(WebSocketPolicy.java:140) ~[93:org.eclipse.jetty.websocket.api:9.4.11.v20180605]
    at org.eclipse.jetty.websocket.common.Parser.assertSanePayloadLength(Parser.java:127) ~[95:org.eclipse.jetty.websocket.common:9.4.11.v20180605]
    at org.eclipse.jetty.websocket.common.Parser.parseFrame(Parser.java:485) ~[95:org.eclipse.jetty.websocket.common:9.4.11.v20180605]
    at org.eclipse.jetty.websocket.common.Parser.parse(Parser.java:241) ~[95:org.eclipse.jetty.websocket.common:9.4.11.v20180605]
    at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.readParse(AbstractWebSocketConnection.java:560) [95:org.eclipse.jetty.websocket.common:9.4.11.v20180605]
    at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:391) [95:org.eclipse.jetty.websocket.common:9.4.11.v20180605]
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281) [78:org.eclipse.jetty.io:9.4.11.v20180605]
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) [78:org.eclipse.jetty.io:9.4.11.v20180605]
    at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) [78:org.eclipse.jetty.io:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) [90:org.eclipse.jetty.util:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) [90:org.eclipse.jetty.util:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) [90:org.eclipse.jetty.util:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) [90:org.eclipse.jetty.util:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) [90:org.eclipse.jetty.util:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762) [90:org.eclipse.jetty.util:9.4.11.v20180605]
    at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680) [90:org.eclipse.jetty.util:9.4.11.v20180605]
    at java.lang.Thread.run(Thread.java:748) [?:?]

Is there any way to configure the message size maximum?

NickWaterton commented 5 years ago

I just tried it also, and got the same message (but with a value of 103724, not 79924).

NickWaterton commented 5 years ago

Just wondering if there were any updates on this? Would be nice to get a harmony websockets binding working. Still looks like a bigger buffer than the default 64k is needed if you have more than a few devices. I have downloaded my config (through python websockets), and it is over 100k in size. Thanks.

chluehr commented 5 years ago

Thanks, @digitaldan - the binding works for me!

vbier commented 5 years ago

@NickWaterton , @NicoVermeir , i have just compiled digitaldan's code with the fixes provided by wborn. The add-on binding jar file is in this zip. It works for me, maybe it also works for you. org.openhab.binding.harmonyhub-2.5.0-SNAPSHOT.zip

Ra72xx commented 5 years ago

I have to ask a stupid question: Where to put the *.jar, or will there be some official update some time?

vbier commented 5 years ago

It is always advisable to read docs or search before asking questions: https://www.openhab.org/docs/configuration/addons.html#through-manually-provided-add-ons

Celaeno1 commented 5 years ago

@vbier @NickWaterton @NicoVermeir I've installed org.openhab.binding.harmonyhub-2.5.0-SNAPSHOT.zip (on build 1486) and it is running without any problems, I'm also still on firmware v4.15.201.

NicoVermeir commented 5 years ago

I can confirm that the 2.5.0 version is working as well

digitaldan commented 5 years ago

Hi all, sorry i was on other things, but i'm back. @wborn I just merged you settings into my branch. I have been running this over the xmpp version without issues. I think we should go ahead and pursue this as a replacement. I will get it fired up today and start preparing it for a PR .

@wborn is there anything missing that you can see from it?

wborn commented 5 years ago

Thanks for merging my PR. The code is feature complete and works very well @digitaldan. :+1: I've been using the new websocket implementation ever since (default firmware) and haven't found any new issues. :smiley:

digitaldan commented 5 years ago

Awesome, see https://github.com/openhab/openhab2-addons/pull/4926/

mattstocum commented 5 years ago

I'm not able to connect to my hub using the new binding. When trying the command line test client, it seems like it's being disconnected with HTTP error 417

[HttpClient@1db1f78-12] DEBUG org.eclipse.jetty.client.HttpReceiver - Response headers HttpResponse[HTTP/1.1 417 null]@1ecbe57
Access-Control-Allow-Headers: origin, content-type, accept
Access-Control-Allow-Method: POST, OPTIONS
Access-Control-Allow-Origin: http//:localhost.nebula.myharmony.com
Content-Length: 16
[HttpClient@1db1f78-12] DEBUG org.eclipse.jetty.client.HttpReceiver - Response content HttpResponse[HTTP/1.1 417 null]@1ecbe57
DirectByteBufferR@1d10f5a[p=208,l=224,c=16384,r=16]={HTTP/1.1 417\r\nAcc...-Length: 16\r\n\r\n<<<{"code":"417"}\r\n>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}
[HttpClient@1db1f78-12] DEBUG org.eclipse.jetty.http.HttpParser - CONTENT --> END
[HttpClient@1db1f78-12] DEBUG org.eclipse.jetty.http.HttpParser - reset HttpParser{s=END,16 of 16}
[HttpClient@1db1f78-12] DEBUG org.eclipse.jetty.http.HttpParser - END --> START
[HttpClient@1db1f78-12] DEBUG org.eclipse.jetty.client.HttpReceiver - Response success HttpResponse[HTTP/1.1 417 null]@1ecbe57
[HttpClient@1db1f78-12] DEBUG org.eclipse.jetty.client.HttpExchange - Terminated response for HttpExchange@f9f445 req=TERMINATED/null@null res=TERMINATED/null@null, result: Result[HttpRequest[POST / HTTP/1.1]@be2bc2 > HttpResponse[HTTP/1.1 417 null]@1ecbe57] null
[HttpClient@1db1f78-12] DEBUG org.eclipse.jetty.client.HttpReceiver - Response complete HttpResponse[HTTP/1.1 417 null]@1ecbe57
[HttpClient@1db1f78-12] DEBUG org.eclipse.jetty.client.HttpChannel - HttpExchange@f9f445 req=TERMINATED/null@null res=TERMINATED/null@null disassociated true from HttpChannelOverHTTP@1baed1d(exchange=null)[send=HttpSenderOverHTTP@e4344d(req=QUEUED,snd=COMPLETED,failure=null)[HttpGenerator@1d059c5{s=START}],recv=HttpReceiverOverHTTP@14504bf(rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}]]
[HttpClient@1db1f78-12] DEBUG org.eclipse.jetty.client.HttpDestination - Released HttpConnectionOverHTTP@1f8f9b1(l:/192.168.1.7:55730 <-> r:/192.168.1.9:8088,closed=false)=>HttpChannelOverHTTP@1baed1d(exchange=null)[send=HttpSenderOverHTTP@e4344d(req=QUEUED,snd=COMPLETED,failure=null)[HttpGenerator@1d059c5{s=START}],recv=HttpReceiverOverHTTP@14504bf(rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}]]<-SocketChannelEndPoint@125a68f{/192.168.1.9:8088<->/192.168.1.7:55730,OPEN,fill=-,flush=-,to=32/0}{io=0/0,kio=0,kro=1}->HttpConnectionOverHTTP@1f8f9b1(l:/192.168.1.7:55730 <-> r:/192.168.1.9:8088,closed=false)=>HttpChannelOverHTTP@1baed1d(exchange=null)[send=HttpSenderOverHTTP@e4344d(req=QUEUED,snd=COMPLETED,failure=null)[HttpGenerator@1d059c5{s=START}],recv=HttpReceiverOverHTTP@14504bf(rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}]]
[HttpClient@1db1f78-12] DEBUG org.eclipse.jetty.client.AbstractConnectionPool - Connection idle HttpConnectionOverHTTP@1f8f9b1(l:/192.168.1.7:55730 <-> r:/192.168.1.9:8088,closed=false)=>HttpChannelOverHTTP@1baed1d(exchange=null)[send=HttpSenderOverHTTP@e4344d(req=QUEUED,snd=COMPLETED,failure=null)[HttpGenerator@1d059c5{s=START}],recv=HttpReceiverOverHTTP@14504bf(rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}]]<-SocketChannelEndPoint@125a68f{/192.168.1.9:8088<->/192.168.1.7:55730,OPEN,fill=-,flush=-,to=34/0}{io=0/0,kio=0,kro=1}->HttpConnectionOverHTTP@1f8f9b1(l:/192.168.1.7:55730 <-> r:/192.168.1.9:8088,closed=false)=>HttpChannelOverHTTP@1baed1d(exchange=null)[send=HttpSenderOverHTTP@e4344d(req=QUEUED,snd=COMPLETED,failure=null)[HttpGenerator@1d059c5{s=START}],recv=HttpReceiverOverHTTP@14504bf(rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}]]
[HttpClient@1db1f78-12] DEBUG org.eclipse.jetty.client.HttpReceiver - Request/Response succeeded: Result[HttpRequest[POST / HTTP/1.1]@be2bc2 > HttpResponse[HTTP/1.1 417 null]@1ecbe57] null
[main] TRACE com.digitaldan.harmony.HarmonyClient - Discovery response for hos 192.168.1.9 : {"code":"417"}

digitaldan commented 5 years ago

@mattstocum Logitech also change the signature of the websocket instance with the new firmware released in the last 48 hours :-( Fortunately I have a fix waiting for review https://github.com/openhab/openhab2-addons/pull/4938

vbier commented 5 years ago

I seem to have gotten the firmware update, too. The binding can no longer connect and does now make openHAB unresponsive after some time. The number of HTTPClient threads increases every minute until the process is blocked. After a while I have more than a thousand threads like these:

"HttpClient@14a8099-184" #184 prio=5 os_prio=0 tid=0x5a594400 nid=0x66ff runnable [0x59d6e000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)

locked <0x6b954050> (a sun.nio.ch.Util$3)

locked <0x6b954060> (a java.util.Collections$UnmodifiableSet)

locked <0x6b954010> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101) at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.select(ManagedSelector.java:396) at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:333) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produceTask(EatWhatYouKill.java:357) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:181) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:132) at org.eclipse.jetty.io.ManagedSelector$$Lambda$150/23044786.run(Unknown Source) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762) at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680) at java.lang.Thread.run(Thread.java:748)

Uninstalling the binding stops the thread count from increasing, so it seems to be caused by the binding. @digitaldan, is this something you know or can fix? Or is this fixed in the new version? Or shall I open a new issue?

digitaldan commented 5 years ago

@vbier did this get resolved for you with the new version?

mattstocum commented 5 years ago

Snapshot after #4938 fixed the issue I was seeing. Hub was discovered immediately and worked with zero config on my part, beyond installing the snapshot binding.

vbier commented 5 years ago

The thing is not if the next version connects to the hub (as it already has been reported to be working), but what happens if the next version can no longer connect to the hub because of new firmware or other reasons. Does it then still hang the complete application?

The hanging openHAB completely blocked my eBUS, resulting in my heating unit warming up my house to 27 degrees celsius over night. There most likely are even more serious problems that could arise from the hanging application.

@digitaldan, it would be nice if you could fake connection problems and see if you can reproduce and fix the problem.

digitaldan commented 5 years ago

@viber my latest open pr does address this issues

vbier commented 5 years ago

That's great. I will update in the coming days. Thanks for your work on this.

digitaldan commented 5 years ago

👍

openhab / openhab-addons

[harmonyhub] "Failed communicating with Harmony Hub" with firmware 4.15.206 #4411

Harmony Hub firmware (v4.15.206)