Skip to content
This repository has been archived by the owner on May 7, 2020. It is now read-only.

Tradfri binding does not reestablish connection to gateway after connection loss #6065

Open
roben opened this issue Aug 16, 2018 · 83 comments
Open

Comments

@roben
Copy link

roben commented Aug 16, 2018

Short version:
If the gateway gets physically dis- and reconnected the binding does not automatically reconnect to it. To reestablish the connection manually, the IP can be changed to something else and back to the correct value again.

Long version with screenshots and logs:
https://community.openhab.org/t/tradfri-binding-loses-connection-after-power-failure-gateway-reboot/47833

@lukicsl
Copy link

lukicsl commented Aug 16, 2018

Have you tried to set the Security Code only?

@roben
Copy link
Author

roben commented Aug 16, 2018

No, because I never had an issue with the code. Maybe you setting the code again also only caused a reconnect. It is intended to not being set after the first connection.

@lukicsl
Copy link

lukicsl commented Aug 16, 2018

Do I read it correct: you go to Configuration > Things > Edit >TRÅDFRI Gateway and just change/change back the ip address.
Question: Do you have anything visible indication (*******) that Security Code has value. I have always a blank field there.

@roben
Copy link
Author

roben commented Aug 16, 2018

you go to Configuration > Things > Edit >TRÅDFRI Gateway and just change/change back the ip address.

Yes.

Question: Do you have anything visible indication (*******) that Security Code has value. I have always a blank field there.

No. It's empty after it has been processed. The real security credentials are shown when setting tools > show advanced settings (or something like this, it's in German for me).

@roben
Copy link
Author

roben commented Aug 16, 2018

But let's stick to the connection issue here. If you have further questions, we can continue in the OH forums.

@cweitkamp
Copy link
Contributor

The Bridge handler overwrites the "Security Code" with null after successfully establishing a connection to the gateway. Why? I will remove that line of code and do some tests.

https://github.com/eclipse/smarthome/blob/b39fe45be22b7290269f1959803e49fda91cdb6a/extensions/binding/org.eclipse.smarthome.binding.tradfri/src/main/java/org/eclipse/smarthome/binding/tradfri/handler/TradfriGatewayHandler.java#L220-L224

@kaikreuzer
Copy link
Contributor

@cweitkamp This is by design as @roben referenced here already. Afair, the Tradfri developer docs stated that systems must not persist the security code, only the PSK.

@cweitkamp
Copy link
Contributor

I got it. Did not read carefully enough. Nonetheless I did some more research. After restarting the bundle we ran into some timeout errors which seem to stop the handler from coming ONLINE again:

2018-08-19 14:18:33.803 [DEBUG] [tradfri.internal.TradfriCoapEndpoint] - Destroying CoAP endpoint.
java.lang.RuntimeException: Endpoint destroyed
        at org.eclipse.smarthome.binding.tradfri.internal.TradfriCoapEndpoint.destroy(TradfriCoapEndpoint.java:39) [234:org.eclipse.smarthome.binding.tradfri:0.10.0.201808191135]
        at org.eclipse.smarthome.binding.tradfri.handler.TradfriGatewayHandler.dispose(TradfriGatewayHandler.java:263) [234:org.eclipse.smarthome.binding.tradfri:0.10.0.201808191135]
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.thingUpdated(BaseThingHandler.java:206) [101:org.eclipse.smarthome.core.thing:0.10.0.201808011124]
        at org.eclipse.smarthome.binding.tradfri.handler.TradfriGatewayHandler.thingUpdated(TradfriGatewayHandler.java:371) [234:org.eclipse.smarthome.binding.tradfri:0.10.0.201808191135]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [94:org.eclipse.smarthome.core:0.10.0.201808011124]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [94:org.eclipse.smarthome.core:0.10.0.201808011124]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        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) [?:?]
2018-08-19 14:18:33.822 [INFO ] [radfri.handler.TradfriGatewayHandler] - Bridge configuration updated. Updating paired things (if any).
2018-08-19 14:18:37.842 [DEBUG] [.tradfri.internal.TradfriCoapHandler] - CoAP onError
2018-08-19 14:18:47.484 [DEBUG] [.tradfri.internal.TradfriCoapHandler] - CoAP onError
2018-08-19 14:18:50.242 [DEBUG] [.tradfri.internal.TradfriCoapHandler] - CoAP onError

I changed the order of destroying the endpoint before shutting down the client in #6079. This maybe is a fix for our issue, but I am not sure. We need some more testing.

@cweitkamp
Copy link
Contributor

@roben @lukicsl

New ESH 291 and OH2 1340 snapshots have been release. May I ask you to do some more tests with the new version? I am curios if it works...

@roben
Copy link
Author

roben commented Aug 25, 2018

Thanks! Can I use just the new binding jar with the current OH stable? Or is there even a way to tell OH to install the snapshot version of the binding?

@cweitkamp
Copy link
Contributor

Both options are possible. Lets continue our discussion in the community forum.

@roben
Copy link
Author

roben commented Aug 25, 2018

Sady it did not seem to help. I am running
234 │ Active │ 80 │ 0.10.0.201808242044 │ org.eclipse.smarthome.binding.tradfri
but still had to do the manual IP change workaround to get the gateway back online.

Even more it seems that OH is now taking much longer to detect the gateway being offline. It logged 12:09:24.240 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'tradfri:gateway:gwdcefcaba8d2b' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR) some minutes after I unplugged it and reconnected it.

@roben
Copy link
Author

roben commented Aug 25, 2018

I'll leave it in this state for now and see if it just takes some time to come back online automatically.

@roben
Copy link
Author

roben commented Aug 25, 2018

Oh and I tried to access the binding while it was already gone but still marked as online:
12:08:55.340 [INFO ] [smarthome.event.ItemCommandEvent ] - Item 'Tradfri_Bulb_WZ_Stehlampe_gr' received command 39
12:08:55.342 [INFO ] [smarthome.event.ItemStateChangedEvent] - Tradfri_Bulb_WZ_Stehlampe_gr changed from 76 to 39

@roben
Copy link
Author

roben commented Aug 25, 2018

15 Minutes later and still no luck. So it seems still broken to me, sorry.

@cweitkamp
Copy link
Contributor

My I ask you to enable DEBUG or TRACE logging while testing?

@roben
Copy link
Author

roben commented Aug 25, 2018

Of course. For which logging facility? Only org.eclipse.smarthome.binding.tradfri?

@cweitkamp
Copy link
Contributor

Yes.

@roben
Copy link
Author

roben commented Aug 25, 2018

First thing I noticed: 12:54:01.703 [DEBUG] [nal.discovery.TradfriDiscoveryService] - Adding device tradfri:0100:gwdcefcaba8d2b:65543 to inbox, even though it is already configured and currently online:
image

Update: Maybe not that important. Those are just the devices, not the gateway.

@roben
Copy link
Author

roben commented Aug 25, 2018

Unplugged the gateway - no update.

Switched lamp with unplugged gateway:

13:00:42.024 [DEBUG] [g.tradfri.handler.TradfriThingHandler] - Sending payload: {"3311":[{"5850":0}],"3":{}}
13:00:42.025 [DEBUG] [ng.tradfri.internal.TradfriCoapClient] - Proccessing payload: {"3311":[{"5850":0}],"3":{}}
13:00:43.946 [DEBUG] [g.tradfri.handler.TradfriThingHandler] - Sending payload: {"3311":[{"5850":1}],"3":{}}
13:00:43.947 [DEBUG] [ng.tradfri.internal.TradfriCoapClient] - Proccessing payload: {"3311":[{"5850":1}],"3":{}}

Two minutes later, gateway is marked offline in Habmin:

13:01:55.902 [DEBUG] [g.tradfri.internal.TradfriCoapHandler] - CoAP onError
13:02:05.967 [DEBUG] [g.tradfri.internal.TradfriCoapHandler] - CoAP onError
13:02:16.392 [DEBUG] [g.tradfri.internal.TradfriCoapHandler] - CoAP onError
[...]

Plugged gateway back in, gateway is discovered but still marked offline:

13:03:24.018 [DEBUG] [discovery.TradfriDiscoveryParticipant] - Discovered Tradfri gateway: [ServiceInfoImpl@321876347 name: 'gw-dcefcaba8d2b._coap._udp.local.' address: '/10.0.1.167:5684 ' status: 'DNS: JmDNS-IP-1 [/10.0.1.2] state: probing 1 task: null' is persistent, has data
	version: 1.4.15]
13:03:27.617 [DEBUG] [discovery.TradfriDiscoveryParticipant] - Discovered Tradfri gateway: [ServiceInfoImpl@321876347 name: 'gw-dcefcaba8d2b._coap._udp.local.' address: '/10.0.1.167:5684 /fe80:0:0:0:deef:caff:feba:8d2b:5684 ' status: 'DNS: JmDNS-IP-1 [/10.0.1.2] state: probing 1 task: null' is persistent, has data
	version: 1.4.15]
13:03:33.991 [DEBUG] [g.tradfri.internal.TradfriCoapHandler] - CoAP onError

Setting wrong IP:

java.lang.RuntimeException: Endpoint destroyed
	at org.eclipse.smarthome.binding.tradfri.internal.TradfriCoapEndpoint.destroy(TradfriCoapEndpoint.java:39) [234:org.eclipse.smarthome.binding.tradfri:0.10.0.201808242044]
	at org.eclipse.smarthome.binding.tradfri.handler.TradfriGatewayHandler.dispose(TradfriGatewayHandler.java:259) [234:org.eclipse.smarthome.binding.tradfri:0.10.0.201808242044]
	at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.handleConfigurationUpdate(BaseThingHandler.java:196) [108:org.eclipse.smarthome.core.thing:0.10.0.oh230]
	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.updateConfiguration(ThingRegistryImpl.java:92) [108:org.eclipse.smarthome.core.thing:0.10.0.oh230]
	at org.eclipse.smarthome.io.rest.core.internal.thing.ThingResource.updateConfiguration(ThingResource.java:425) [118:org.eclipse.smarthome.io.rest.core:0.10.0.oh230]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [15:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:848) [85:org.eclipse.jetty.servlet:9.3.21.v20170918]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:584) [85:org.eclipse.jetty.servlet:9.3.21.v20170918]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [183:org.ops4j.pax.web.pax-web-jetty:6.0.9]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [82:org.eclipse.jetty.security:9.3.21.v20170918]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:284) [183:org.ops4j.pax.web.pax-web-jetty:6.0.9]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [85:org.eclipse.jetty.servlet:9.3.21.v20170918]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [183:org.ops4j.pax.web.pax-web-jetty:6.0.9]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.server.Server.handle(Server.java:534) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:333) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283) [76:org.eclipse.jetty.io:9.3.21.v20170918]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108) [76:org.eclipse.jetty.io:9.3.21.v20170918]
	at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [76:org.eclipse.jetty.io:9.3.21.v20170918]
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [87:org.eclipse.jetty.util:9.3.21.v20170918]
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [87:org.eclipse.jetty.util:9.3.21.v20170918]
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [87:org.eclipse.jetty.util:9.3.21.v20170918]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [87:org.eclipse.jetty.util:9.3.21.v20170918]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [87:org.eclipse.jetty.util:9.3.21.v20170918]
	at java.lang.Thread.run(Thread.java:748) [?:?]
13:04:41.695 [DEBUG] [.tradfri.internal.TradfriCoapEndpoint] - Destroying CoAP endpoint.
java.lang.RuntimeException: Endpoint destroyed
	at org.eclipse.smarthome.binding.tradfri.internal.TradfriCoapEndpoint.destroy(TradfriCoapEndpoint.java:39) [234:org.eclipse.smarthome.binding.tradfri:0.10.0.201808242044]
	at org.eclipse.smarthome.binding.tradfri.handler.TradfriGatewayHandler.dispose(TradfriGatewayHandler.java:259) [234:org.eclipse.smarthome.binding.tradfri:0.10.0.201808242044]
	at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.handleConfigurationUpdate(BaseThingHandler.java:196) [108:org.eclipse.smarthome.core.thing:0.10.0.oh230]
	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.updateConfiguration(ThingRegistryImpl.java:92) [108:org.eclipse.smarthome.core.thing:0.10.0.oh230]
	at org.eclipse.smarthome.io.rest.core.internal.thing.ThingResource.updateConfiguration(ThingResource.java:425) [118:org.eclipse.smarthome.io.rest.core:0.10.0.oh230]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [15:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:848) [85:org.eclipse.jetty.servlet:9.3.21.v20170918]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:584) [85:org.eclipse.jetty.servlet:9.3.21.v20170918]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [183:org.ops4j.pax.web.pax-web-jetty:6.0.9]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [82:org.eclipse.jetty.security:9.3.21.v20170918]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:284) [183:org.ops4j.pax.web.pax-web-jetty:6.0.9]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [85:org.eclipse.jetty.servlet:9.3.21.v20170918]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [183:org.ops4j.pax.web.pax-web-jetty:6.0.9]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.server.Server.handle(Server.java:534) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:333) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [84:org.eclipse.jetty.server:9.3.21.v20170918]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283) [76:org.eclipse.jetty.io:9.3.21.v20170918]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108) [76:org.eclipse.jetty.io:9.3.21.v20170918]
	at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [76:org.eclipse.jetty.io:9.3.21.v20170918]
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [87:org.eclipse.jetty.util:9.3.21.v20170918]
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [87:org.eclipse.jetty.util:9.3.21.v20170918]
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [87:org.eclipse.jetty.util:9.3.21.v20170918]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [87:org.eclipse.jetty.util:9.3.21.v20170918]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [87:org.eclipse.jetty.util:9.3.21.v20170918]
	at java.lang.Thread.run(Thread.java:748) [?:?]

Setting correct IP:

13:04:43.784 [DEBUG] [g.tradfri.internal.TradfriCoapHandler] - CoAP response
options: {"Content-Format":"application/json", "Max-Age":604800}
payload: {"9023":"1.tradfri.pool.ntp.org","9029":"1.4.15","9059":1535195083,"9060":"2018-08-25T11:04:43.041104Z","9062":0,"9061":0,"9081":"7e191d52044000e8","9082":true,"9093":0,"9083":"862-73-258","9054":0,"9073":13,"9055":0,"9200":"537e7ce9-e42e-4eb4-80eb-93319c1c8f30","9066":5,"9069":1530532122,"9107":1,"9106":0,"9077":28,"9071":1,"9072":8,"9074":17,"9080":60,"9075":28,"9076":10,"9078":1,"9079":0,"9092":0,"9105":0}
13:04:44.229 [DEBUG] [g.tradfri.internal.TradfriCoapHandler] - CoAP response
options: {"Content-Format":"application/json", "Max-Age":604800}
payload: [65541,65536,65542,65540,65538,65537,65544,65543]
13:04:44.232 [DEBUG] [tradfri.handler.TradfriGatewayHandler] - onUpdate response: [65541,65536,65542,65540,65538,65537,65544,65543]
13:04:44.237 [DEBUG] [g.tradfri.internal.TradfriCoapHandler] - CoAP response
options: {"Content-Format":"application/json", "Max-Age":604800}
payload: {"15009":[{"9003":0}],"9001":"TRADFRI remote control 2","9002":1511897934,"9020":1534305112,"9003":65541,"5750":0,"9054":0,"9019":1,"3":{"3":"1.2.214","0":"IKEA of Sweden","1":"TRADFRI remote control","2":"","6":3,"9":60}}
13:04:44.239 [DEBUG] [tradfri.handler.TradfriGatewayHandler] - requestDeviceDetails response: {"15009":[{"9003":0}],"9001":"TRADFRI remote control 2","9002":1511897934,"9020":1534305112,"9003":65541,"5750":0,"9054":0,"9019":1,"3":{"3":"1.2.214","0":"IKEA of Sweden","1":"TRADFRI remote control","2":"","6":3,"9":60}}
13:04:44.240 [DEBUG] [nal.discovery.TradfriDiscoveryService] - Adding device tradfri:0830:gwdcefcaba8d2b:65541 to inbox
13:04:44.242 [DEBUG] [g.tradfri.internal.TradfriCoapHandler] - CoAP response

GW is back online.

@chriscolden
Copy link

Just to add, I have the same issue. Gateway is set to a fixed ip via dhcp reservation. I use the DNS fqdn in the binding. If i change the fqdn to something else in the binding and revert back to the proper fqdn of the gateway it comes back online.

@lukicsl
Copy link

lukicsl commented Sep 12, 2018

I was also just rebooting the openhab server serveral times yesterday and had to set/reset the ip address of gateway in order to get connected. The gateway was not touched at all (power all time on).

@chriscolden
Copy link

I think this needs to be reopened. I'm still having this issue. The address has been updated for the ip when I was using the fqdn which I assume is due to this commit, but its still loosing connection a staying lost until i manually change the address, save, edit the up back a save. Thanks.

@kaikreuzer
Copy link
Contributor

@chriscolden Are you sure that you have used the latest code that includes the fix?
In case you are using an openHAB snapshot, please note that this fix is only contained in it since build 1370.

@chriscolden
Copy link

Thanks @kaikreuzer. Im on snapshot but one behind that. I'll updated an see how I get on.

@boaks
Copy link

boaks commented Jan 14, 2019

Cool, I will start with the californium 1.0.7 release process on monday :-).

After the "next issue" above, I would prefer to have it tested some more. So wait a couple of days, what show up next?

@boaks
Copy link

boaks commented Jan 15, 2019

@hreichert

Did you use java 9 or newer?
Could you retest the latest fix for the covariants?
Does it work now?

@hreichert
Copy link
Contributor

@boaks It was Java8. I will try it with your new californium snapshot.

@kvoit
Copy link

kvoit commented Jan 16, 2019

My Tradfri is connected via VPN and I run into the same issue.
Let me add that I do not need to change the IP. For me it is enough to open the Thing config of the gateway in PaperUI and hit the tick sympol to get the binding online again.

@boaks
Copy link

boaks commented Jan 17, 2019

It was Java8

The good part of that is, I run it also mainly with that, so it should work quite well. The other part is, then I don't know, why java.lang.NoSuchMethodError: java.nio.CharBuffer.flip()Ljava/nio/CharBuffer
is reported :-). May be java9 (or newer) was used to build it.

I will try it with your new californium snapshot.

Thanks!

@boaks
Copy link

boaks commented Jan 17, 2019

My Tradfri is connected via VPN and I run into the same issue.

The same as this github issue? Or with the fix and update into java.lang.NoSuchMethodError: java.nio.CharBuffer.flip()Ljava/nio/CharBuffer;?

@boaks
Copy link

boaks commented Jan 17, 2019

Let me add that I do not need to change the IP. For me it is enough to open the Thing config of the gateway in PaperUI and hit the tick sympol to get the binding online again.

That fits to my analysis #6065 (comment)
May be you can also check the fix.

@kvoit
Copy link

kvoit commented Jan 17, 2019

My Tradfri is connected via VPN and I run into the same issue.

The same as this github issue?

Yes, same as this issue. At least when the connection is down for a while, Tradfri will no go online again and I have to open and save the Thing config of the gateway (without altering anything) to get it back working.

I will try to find time for testing the fix. Thanks!

@boaks
Copy link

boaks commented Jan 17, 2019

@hreichert

I retested to compile with openjdk-11 and execute with openjdk-8 and got the java.lang.NoSuchMethodError: java.nio.CharBuffer.flip()Ljava/nio/CharBuffer .
The java 11 compiler reports also "warning: [options] bootstrap class path not set in conjunction with -source 8 1 warning"

Now I'm not sure, did you build it it on your own? Or did you download it from the eclipse maven repo?
In the download case, I guess, I need to adjust the build on the eclipse jenkins to prevent other errors.

@hreichert
Copy link
Contributor

@boaks Ah well you're right, I've built it myself with Java 11 and let it run on Java 8 on a different machine.
I tested again with 1.0.7-20190119.070624-584 from the eclipse maven repository, and for me it's working well!

@boaks
Copy link

boaks commented Jan 19, 2019

Great! If no other issue is raised at this weekend, I start the "release process" on Monday.

@boaks
Copy link

boaks commented Jan 24, 2019

Californium released the 1.0.7 today including the fix for empty session ids mentioned above.
Please retest and maybe close this issue.
I'm looking forward to the next issues :-).

@hreichert
Copy link
Contributor

Thank you @boaks
FTR: There are additional changes needed in the Tradfri binding. PR following.

@kaikreuzer
Copy link
Contributor

@cweitkamp
Copy link
Contributor

A PR for the new californium release has been created and merged in openhab/openhab-core#475. Currently we will skip ESH.

@boaks Thank you very much for your work.

@Tobster77
Copy link

@boaks, @hreichert, @cweitkamp Thanks a lot for caring :-)

hreichert added a commit to hreichert/openhab2-addons that referenced this issue Jan 30, 2019
As discussed in eclipse-archived/smarthome#6065 the tradfri gateway does not support a session resumption after a gateway reboot or other communcation errors.
Californium 1.0.7 is able to force a full handshake instead.
This change calls "forceResumeSessionFor" after a communication error, so that a full handshake is done.

Signed-off-by: Holger Reichert <mail@h0lger.de>
hreichert added a commit to hreichert/openhab2-addons that referenced this issue Jan 31, 2019
As discussed in eclipse-archived/smarthome#6065 the tradfri gateway does not support a session resumption after a gateway reboot or other communcation errors.
Californium 1.0.7 is able to force a full handshake instead.
This change calls "forceResumeSessionFor" after a communication error, so that a full handshake is done.

Signed-off-by: Holger Reichert <mail@h0lger.de>
cweitkamp pushed a commit to openhab/openhab-addons that referenced this issue Feb 1, 2019
As discussed in eclipse-archived/smarthome#6065 the tradfri gateway does not support a session resumption after a gateway reboot or other communcation errors.
Californium 1.0.7 is able to force a full handshake instead.
This change calls "forceResumeSessionFor" after a communication error, so that a full handshake is done.

Signed-off-by: Holger Reichert <mail@h0lger.de>
Pshatsillo pushed a commit to Pshatsillo/openhab-addons that referenced this issue Jun 19, 2019
As discussed in eclipse-archived/smarthome#6065 the tradfri gateway does not support a session resumption after a gateway reboot or other communcation errors.
Californium 1.0.7 is able to force a full handshake instead.
This change calls "forceResumeSessionFor" after a communication error, so that a full handshake is done.

Signed-off-by: Holger Reichert <mail@h0lger.de>
Signed-off-by: Pshatsillo <pshatsillo@gmail.com>
ne0h pushed a commit to ne0h/openhab-addons that referenced this issue Sep 15, 2019
As discussed in eclipse-archived/smarthome#6065 the tradfri gateway does not support a session resumption after a gateway reboot or other communcation errors.
Californium 1.0.7 is able to force a full handshake instead.
This change calls "forceResumeSessionFor" after a communication error, so that a full handshake is done.

Signed-off-by: Holger Reichert <mail@h0lger.de>
Signed-off-by: Maximilian Hess <mail@ne0h.de>
@Tobster77
Copy link

A PR for the new californium release has been created and merged in openhab/openhab-core#475. Currently we will skip ESH.

@boaks Thank you very much for your work.

This did not improve the decribed issue. Is there any recommendation?

@5iver
Copy link
Contributor

5iver commented Mar 12, 2020

@Tobster77, seeing as this repo is dead (see #6883) and development has moved to openHAB, it would be best to create a new issue for the Tradfri binding. Of course, that is assuming you are using OH!

@boaks
Copy link

boaks commented Mar 12, 2020

@Tobster77

This and many other issues around tradfri and californium seems to be a mix of several different things. And the fix in californium only addresses to reconnect without restart.

If you create a new issue in openHab, maybe you can add the issue number here as well. Then a can follow up your issue.

In the meantime openHab uses Californium 2.0 and at least I got some info, that this improved the stability.

@Tobster77
Copy link

Tobster77 commented Mar 19, 2020 via email

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests