Hello guys,
after running very satisfying for months and passing some minor updates from OpenHab2 without issues, my Hue devices start to react very slowly to any command triggered or initiated threw Openhab (HabPanel or PaperUI or rules) since update to 2.5.8-1
The time between the click on the Item in HabPanel and the reaction of the bulb/switch is at least 1 minute, equal if ON or OFF.
Logs (openhab.log and events.log ) do not show up any problem.
The events.log shows no delay between command an execution:
2020-08-27 12:05:23.673 [ome.event.ItemCommandEvent] - Item 'hue_0010_ecb5fa0a86c8_2_switch' received command ON
2020-08-27 12:05:23.683 [nt.ItemStatePredictedEvent] - hue_0010_ecb5fa0a86c8_2_switch predicted to become ON
2020-08-27 12:05:23.693 [vent.ItemStateChangedEvent] - hue_0010_ecb5fa0a86c8_2_switch changed from OFF to ON
Platform information:
Raspberry PI 4B 4GB RAM
OS: Raspbian Kernel 5.4.51-v7l+ #1333 SMP
Java Runtime Environment: openjdk version “1.8.0_265”
openHAB version: openHAB 2.5.8-1
HUE Bridge and OpenHab are connected by wired LAN and both are in the same network 192.168.0.0/24
Reboot of HUE Bridge and/or OpenHab had no effect.
Commands direct via the HUE App are fast as expected.
Any idea or help is highly appreciated.
Thanks a lot in advance
Michael
PS: For the experts I attach an example for an HUE switch action logged in DEBUG Mode:
[13:34:30] openhabian@mbc-smarthome:~$ tail -f /var/log/openhab2/openhab.log | grep hue_0010_ecb5fa0a86c8_2
2020-08-28 13:36:43.053 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - REQUEST for //mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch on HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=IDLE,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=0}
POST //mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch HTTP/1.1
2020-08-28 13:36:43.055 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@1a98b64::SocketChannelEndPoint@564d76{/192.168.0.98:36728<->/192.168.0.43:8080,OPEN,fill=-,flush=-,to=45/30000}{io=0/0,kio=0,kro=1}->HttpConnection@1a98b64[p=HttpParser{s=CONTENT,0 of 3},g=HttpGenerator@1ac5e9a{s=START}]=>HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=IDLE,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=1} parsed true HttpParser{s=CONTENT,0 of 3}
2020-08-28 13:36:43.056 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=IDLE,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=2} handle //mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch
2020-08-28 13:36:43.057 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=DISPATCHED,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=4} action DISPATCH
2020-08-28 13:36:43.058 [DEBUG] [org.eclipse.jetty.server.Server ] - REQUEST POST /rest/items/hue_0010_ecb5fa0a86c8_2_switch on HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=DISPATCHED,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=5}
2020-08-28 13:36:43.059 [DEBUG] [ax.web.service.spi.model.ServerModel] - Matching [/rest/items/hue_0010_ecb5fa0a86c8_2_switch]...
2020-08-28 13:36:43.060 [DEBUG] [ax.web.service.spi.model.ServerModel] - Path [/rest/items/hue_0010_ecb5fa0a86c8_2_switch] matched to {pattern=/rest/.*,model=ServletModel{id=org.ops4j.pax.web.service.spi.model.ServletModel-5,name=org.ops4j.pax.web.service.spi.model.ServletModel-5,urlPatterns=[/rest/*],alias=/rest,servlet=com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge@5c1e8f,initParams={},context=ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-4,name=,httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [19], contextID=default],contextParams={},virtualHosts={},connectors={}}}}
2020-08-28 13:36:43.061 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items/hue_0010_ecb5fa0a86c8_2_switch @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [19], contextID=default]}
2020-08-28 13:36:43.062 [DEBUG] [.jetty.server.handler.ContextHandler] - context=||/rest/items/hue_0010_ecb5fa0a86c8_2_switch @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [19], contextID=default]}
2020-08-28 13:36:43.065 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - servlet |/rest|/items/hue_0010_ecb5fa0a86c8_2_switch -> org.ops4j.pax.web.service.spi.model.ServletModel-5@378be0fd==com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge,jsp=null,order=-1,inst=true,async=true
2020-08-28 13:36:43.066 [DEBUG] [ce.jetty.internal.HttpServiceContext] - Handling request for [/rest/items/hue_0010_ecb5fa0a86c8_2_switch] using http context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [19], contextID=default]]
2020-08-28 13:36:43.075 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@1a98b64::SocketChannelEndPoint@564d76{/192.168.0.98:36728<->/192.168.0.43:8080,OPEN,fill=-,flush=-,to=66/30000}{io=0/0,kio=0,kro=1}->HttpConnection@1a98b64[p=HttpParser{s=CONTENT,0 of 3},g=HttpGenerator@1ac5e9a{s=START}]=>HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=DISPATCHED,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=22} parse HeapByteBuffer@1c5e876[p=562,l=565,c=8192,r=3]={POST /rest/items/... keep-alive\r\n\r\n<<<OFF>>>\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} {}
2020-08-28 13:36:43.079 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=DISPATCHED,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=26} onContent Content@8b63a5{HeapByteBufferR@d8ad63[p=562,l=565,c=8192,r=3]={POST /rest/items/... keep-alive\r\n\r\n<<<OFF>>>\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}}
2020-08-28 13:36:43.084 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=DISPATCHED,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=31} onContentComplete
2020-08-28 13:36:43.086 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=DISPATCHED,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=33} onRequestComplete
2020-08-28 13:36:43.090 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@1a98b64::SocketChannelEndPoint@564d76{/192.168.0.98:36728<->/192.168.0.43:8080,OPEN,fill=-,flush=-,to=80/30000}{io=0/0,kio=0,kro=1}->HttpConnection@1a98b64[p=HttpParser{s=END,3 of 3},g=HttpGenerator@1ac5e9a{s=START}]=>HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=DISPATCHED,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=37} parsed false HttpParser{s=END,3 of 3}
2020-08-28 13:36:43.094 [DEBUG] [.eclipse.jetty.server.HttpConnection] - releaseRequestBuffer HttpConnection@1a98b64::SocketChannelEndPoint@564d76{/192.168.0.98:36728<->/192.168.0.43:8080,OPEN,fill=-,flush=-,to=85/30000}{io=0/0,kio=0,kro=1}->HttpConnection@1a98b64[p=HttpParser{s=END,3 of 3},g=HttpGenerator@1ac5e9a{s=START}]=>HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=DISPATCHED,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=41}
2020-08-28 13:36:43.110 [DEBUG] [org.eclipse.jetty.server.Server ] - handled=true async=false committed=false on HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=DISPATCHED,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=57}
2020-08-28 13:36:43.112 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1b274e8{r=1,c=false,c=false/false,a=COMPLETING,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=59} action COMPLETE
2020-08-28 13:36:43.125 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - COMMIT for /rest/items/hue_0010_ecb5fa0a86c8_2_switch on HttpChannelOverHttp@1b274e8{r=1,c=true,c=false/false,a=COMPLETING,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=72}
2020-08-28 13:36:43.137 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 97 SocketChannelEndPoint@564d76{/192.168.0.98:36728<->/192.168.0.43:8080,OPEN,fill=-,flush=W,to=122/30000}{io=0/0,kio=0,kro=1}->HttpConnection@1a98b64[p=HttpParser{s=END,3 of 3},g=HttpGenerator@1ac5e9a{s=COMPLETING}]=>HttpChannelOverHttp@1b274e8{r=1,c=true,c=false/false,a=COMPLETING,uri=//mbc-smarthome:8080/rest/items/hue_0010_ecb5fa0a86c8_2_switch,age=78}
2020-08-28 13:36:43.151 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - COMPLETE for /rest/items/hue_0010_ecb5fa0a86c8_2_switch written=0
