Zigbee binding

zigbee
beginners
Tags: #<Tag:0x00007fe05fbddc78> #<Tag:0x00007fe05fbdd7a0>

(Jared Frank) #1622

Since updating to M8 I’ve noticed difficulty with some bulbs and poor performance (very chatty zigbee network visible via debug) / If I add and remove a bulb it seems to revert back to the 0 is cool white 100 is warm. Does that update require me to remove/rejoin bulbs or are there any known performance issues. Everything does seem to ultimately work and I can try to get some logs later this weekend when i have a bit more time (for now i’ve reverted back to the 1.1.4 on m7)


(Chris Jackson) #1623

It should be the same as before.

Color temperature was swapped around to be consistent with ESH definition. Also, the color temperature channel was changed as this is now defined as a system channel by ESH.

No. You might want to delete the thing and add it back so that it uses the new color temp channel.

Please don’t - M8 will become 2.4 in a few days time, and using a different version really isn’t going to solve any issues if there are any. Please try and work out what problems you have and report them.


(Jared Frank) #1624

I agree thank you - I just reverted since I didn’t have time to work on it further and needed it stable. I’ll give a try this weekend with deleting things and rejoining them and let you know if I have any issues.


(stephan) #1625

A complete reinstallation of OH resolved my problems for some days - till yesterday: using XBee stick and ubuntu server 18.04.01 I cannot get this coordinator online anymore. Did another fresh install and here are the logs (trying different parameters)
Has anyone similar problems?

openhab> list |grep -i zig
200 │ Active │ 80 │ 1.1.6 │ com.zsmartsystems.zigbee
201 │ Active │ 80 │ 1.1.6 │ com.zsmartsystems.zigbee.dongl
202 │ Active │ 80 │ 1.1.6 │ com.zsmartsystems.zigbee.dongl
203 │ Active │ 80 │ 1.1.6 │ com.zsmartsystems.zigbee.dongl
204 │ Active │ 80 │ 1.1.6 │ com.zsmartsystems.zigbee.dongl
211 │ Active │ 80 │ 2.4.0.201812110506 │ ZigBee Binding
212 │ Active │ 80 │ 2.4.0.201812110506 │ ZigBee CC2531 Binding
213 │ Active │ 80 │ 2.4.0.201812110506 │ ZigBee Ember Binding
214 │ Active │ 80 │ 2.4.0.201812110506 │ ZigBee Telegesis Binding
215 │ Active │ 80 │ 2.4.0.201812110506 │ ZigBee XBee Binding
openhab> log:tail
17:57:32.767 [INFO ] [rthome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
17:57:33.187 [INFO ] [i.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.50.30:8080
17:57:33.188 [INFO ] [i.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.50.30:8443
17:57:44.244 [INFO ] [smarthome.event.ExtensionEvent ] - Extension ‘package-standard’ has been installed.
17:57:45.348 [INFO ] [mebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder
17:57:45.380 [INFO ] [bpanel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
17:57:45.513 [INFO ] [marthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
17:57:45.528 [INFO ] [smarthome.event.ExtensionEvent ] - Extension ‘ui-homebuilder’ has been installed.
17:57:45.532 [INFO ] [smarthome.event.ExtensionEvent ] - Extension ‘ui-basic’ has been installed.
17:57:45.533 [INFO ] [smarthome.event.ExtensionEvent ] - Extension ‘ui-habpanel’ has been installed.
17:57:45.533 [INFO ] [smarthome.event.ExtensionEvent ] - Extension ‘ui-paper’ has been installed.
17:58:09.255 [INFO ] [smarthome.event.ExtensionEvent ] - Extension ‘binding-zigbee’ has been installed.
17:59:04.902 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - ‘zigbee:coordinator_xbee:69e57f59’ changed from UNINITIALIZED to INITIALIZING
17:59:04.909 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_xbee:69e57f59’ has been updated.
17:59:04.913 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_xbee:69e57f59’ has been updated.
17:59:04.929 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_xbee:69e57f59’ has been updated.
17:59:04.929 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_xbee:69e57f59’ has been updated.
17:59:04.942 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - ‘zigbee:coordinator_xbee:69e57f59’ changed from INITIALIZING to UNKNOWN
17:59:11.038 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_xbee:69e57f59’ has been updated.
17:59:24.038 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_xbee:69e57f59’ has been updated.
17:59:24.078 [ERROR] [est.core.internal.thing.ThingResource] - Exception during HTTP PUT request for update config at ‘things/zigbee:coordinator_xbee:69e57f59/config’
java.lang.NullPointerException: null
at com.zsmartsystems.zigbee.app.discovery.ZigBeeDiscoveryExtension.extensionShutdown(ZigBeeDiscoveryExtension.java:96) ~[?:?]
at com.zsmartsystems.zigbee.ZigBeeNetworkManager.shutdown(ZigBeeNetworkManager.java:529) ~[?:?]
at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.dispose(ZigBeeCoordinatorHandler.java:303) ~[?:?]
at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.handleConfigurationUpdate(ZigBeeCoordinatorHandler.java:554) ~[?:?]
at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.updateConfiguration(ThingRegistryImpl.java:91) ~[?:?]
at org.eclipse.smarthome.io.rest.core.internal.thing.ThingResource.updateConfiguration(ThingResource.java:438) [120:org.eclipse.smarthome.io.rest.core:0.10.0.201812091851]
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) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [82:org.eclipse.jetty.security:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.Server.handle(Server.java:531) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [84:org.eclipse.jetty.server: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) [?:?]
17:59:53.361 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_xbee:69e57f59’ has been updated.
17:59:53.389 [ERROR] [est.core.internal.thing.ThingResource] - Exception during HTTP PUT request for update config at ‘things/zigbee:coordinator_xbee:69e57f59/config’
java.lang.NullPointerException: null
at com.zsmartsystems.zigbee.app.discovery.ZigBeeDiscoveryExtension.extensionShutdown(ZigBeeDiscoveryExtension.java:96) ~[?:?]
at com.zsmartsystems.zigbee.ZigBeeNetworkManager.shutdown(ZigBeeNetworkManager.java:529) ~[?:?]
at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.dispose(ZigBeeCoordinatorHandler.java:303) ~[?:?]
at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.handleConfigurationUpdate(ZigBeeCoordinatorHandler.java:554) ~[?:?]
at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.updateConfiguration(ThingRegistryImpl.java:91) ~[?:?]
at org.eclipse.smarthome.io.rest.core.internal.thing.ThingResource.updateConfiguration(ThingResource.java:438) [120:org.eclipse.smarthome.io.rest.core:0.10.0.201812091851]
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) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [82:org.eclipse.jetty.security:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.Server.handle(Server.java:531) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [84:org.eclipse.jetty.server: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) [?:?]
18:00:24.703 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_xbee:69e57f59’ has been updated.
18:00:24.717 [ERROR] [est.core.internal.thing.ThingResource] - Exception during HTTP PUT request for update config at ‘things/zigbee:coordinator_xbee:69e57f59/config’
java.lang.NullPointerException: null
at com.zsmartsystems.zigbee.app.discovery.ZigBeeDiscoveryExtension.extensionShutdown(ZigBeeDiscoveryExtension.java:96) ~[?:?]
at com.zsmartsystems.zigbee.ZigBeeNetworkManager.shutdown(ZigBeeNetworkManager.java:529) ~[?:?]
at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.dispose(ZigBeeCoordinatorHandler.java:303) ~[?:?]
at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.handleConfigurationUpdate(ZigBeeCoordinatorHandler.java:554) ~[?:?]
at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.updateConfiguration(ThingRegistryImpl.java:91) ~[?:?]
at org.eclipse.smarthome.io.rest.core.internal.thing.ThingResource.updateConfiguration(ThingResource.java:438) [120:org.eclipse.smarthome.io.rest.core:0.10.0.201812091851]
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) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [82:org.eclipse.jetty.security:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.Server.handle(Server.java:531) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352) [84:org.eclipse.jetty.server:9.4.11.v20180605]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [84:org.eclipse.jetty.server: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) [?:?]


(Chris Jackson) #1626

The error is caused when you are shutting down the system, so it doesn’t really help with your problem.

Please can you also format logs with the </> button so they are more easily readable.


(Scott Karns) #1627

(Jared Frank) #1628

Just letting you know - I ended up just going ahead with this at lunch today since it was daylight out and lights less important. Anyway … went back to m8 and am deleting / rejoining things that have the color temp channel and it seems everything is going smoother. Prior to deleting / readding I did notice a number of discovery failed messages so perhaps something with the channel change was clunking up one of my bulbs. Thanks for the info!


(Jared Frank) #1629

Hi Chris - are these failures normal? I see numerous discovery failed messages. I have been able to get everything re-added with the exception of one bulb that is being difficult. This final node (841826000007ad26) seems to never finish discovery. I"ve attached my log via this link as it was too big to post up here directly. Let me know if you have issues accessing it (its hosted locally by me).
Thanks!


(Chris Jackson) #1630

Just so we’re looking at the same messages, can you tell me what you’re actually looking at?


(Jared Frank) #1631

These messages below caught me. I managed to finally get it to join - I power cycled / force reset the bulb again and it started playing nice. Perhaps the bulb was just the issue.

2018-12-12 13:39:42.797 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=4427, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0,

(Chris Jackson) #1632

These aren’t “failures” - this is just a message that is reflected back from the library when a packet is sent. The DISCOVERY thing here in the options simply means that if the NCP doesn’t know the address, it should discovery it.


(stephan) #1633

sorry guys for asking again. I did a complete reset : installed ubuntu server 18.04.1, then zulu-8, openhab2 testing main, added openhab to dialout and tty, changed EXTRA_JAVA_OPTS, zigbee binding and added xbee thing
XBee coordinator stays to unknown; it reports ERROR: 500 - Internal Server Error
What can I do to get it working again???
logs are added as requested (sorry)

17:19:17.718 [INFO ] [bpanel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
17:19:17.896 [INFO ] [mebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder
17:19:22.131 [INFO ] [rthome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
17:19:22.650 [INFO ] [i.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.50.30:8080
17:19:22.651 [INFO ] [i.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.50.30:8443
17:19:22.861 [INFO ] [marthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
17:20:42.988 [INFO ] [smarthome.event.ExtensionEvent       ] - Extension 'binding-zigbee' has been installed.
17:21:07.678 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zigbee:coordinator_xbee:c16885ee' changed from UNINITIALIZED to INITIALIZING
17:21:07.695 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zigbee:coordinator_xbee:c16885ee' has been updated.
17:21:07.698 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zigbee:coordinator_xbee:c16885ee' has been updated.
17:21:07.701 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zigbee:coordinator_xbee:c16885ee' has been updated.
17:21:07.703 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zigbee:coordinator_xbee:c16885ee' has been updated.
17:21:07.725 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zigbee:coordinator_xbee:c16885ee' changed from INITIALIZING to UNKNOWN
17:21:13.831 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zigbee:coordinator_xbee:c16885ee' has been updated.
17:21:31.095 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zigbee:coordinator_xbee:c16885ee' has been updated.
17:21:31.124 [ERROR] [est.core.internal.thing.ThingResource] - Exception during HTTP PUT request for update config at 'things/zigbee:coordinator_xbee:c16885ee/config'
java.lang.NullPointerException: null
	at com.zsmartsystems.zigbee.app.discovery.ZigBeeDiscoveryExtension.extensionShutdown(ZigBeeDiscoveryExtension.java:96) ~[?:?]
	at com.zsmartsystems.zigbee.ZigBeeNetworkManager.shutdown(ZigBeeNetworkManager.java:529) ~[?:?]
	at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.dispose(ZigBeeCoordinatorHandler.java:303) ~[?:?]
	at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.handleConfigurationUpdate(ZigBeeCoordinatorHandler.java:554) ~[?:?]
	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.updateConfiguration(ThingRegistryImpl.java:91) ~[?:?]
	at org.eclipse.smarthome.io.rest.core.internal.thing.ThingResource.updateConfiguration(ThingResource.java:438) [120:org.eclipse.smarthome.io.rest.core:0.10.0.oh240M8]
	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) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [82:org.eclipse.jetty.security:9.4.11.v20180605]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.Server.handle(Server.java:531) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [84:org.eclipse.jetty.server: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) [?:?]

(Chris Jackson) #1634

What are you actually doing to cause this error? As I said previously, the error is caused during the shutdown of the binding, and it’s initiated when you did something via the UI.


(stephan) #1635

Thanks for your quick response!!!
It was just after installation.
I had not documented the preferences of the previous settings. As “Flow control” did not work with “Hardware”, I changed it to “Software”.
I did the same in previous installations till it worked.
Now every time I change this value I get the same error - but in contrast to earlier installations I never get it “online”.
I am a bit confused as I had NOT shut the binding down!
Bildschirmfoto%20von%202018-12-14%2020-56-12|690x388 ?


(Chris Jackson) #1636

If you change the configuration of the serial port, the binding will restart (well, more correctly the thing will be destroyed and reinstantiated).


(stephan) #1637

Thanks - I believe I understand that now.
But I don’t get the xbee coordinator online. I changed to debug. Do these logs deliver any explanation (at least to an expert:-))?

10:10:19.076 [INFO ] [marthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
10:11:00.323 [DEBUG] [org.openhab.binding.zigbee.xbee      ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler}={service.id=361, service.bundleid=211, service.scope=singleton} - org.openhab.binding.zigbee.xbee
10:11:00.338 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zigbee:coordinator_xbee:57b76b00' changed from UNINITIALIZED to INITIALIZING
10:11:00.343 [DEBUG] [nding.zigbee.xbee.handler.XBeeHandler] - Initializing ZigBee XBee serial bridge handler.
10:11:00.344 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Initializing ZigBee network [zigbee:coordinator_xbee:57b76b00].
10:11:00.346 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Channel 0
10:11:00.347 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - PANID 0
10:11:00.348 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - EPANID 0000000000000000
10:11:00.350 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Network Key 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
10:11:00.351 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Link Key null
10:11:00.352 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Config: zigbee_initialise found, initializeNetwork=false
10:11:00.353 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - ExtendedPanId or PanId not set: initializeNetwork=true
10:11:00.355 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Network Key String 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
10:11:00.356 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Network key initialised AB84DEBBA25FA9954290CA7B239C87D6
10:11:00.358 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Network key final array AB84DEBBA25FA9954290CA7B239C87D6
10:11:00.359 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Link Key String 
10:11:00.360 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Link Key String has invalid format. Revert to default key.
10:11:00.361 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Initialising network
10:11:00.362 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Channel set to 11.
10:11:00.371 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Created random ZigBee PAN ID [6252].
10:11:00.371 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zigbee:coordinator_xbee:57b76b00' has been updated.
10:11:00.374 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Created random ZigBee extended PAN ID [DF7DF769ECB55A1B].
10:11:00.374 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zigbee:coordinator_xbee:57b76b00' has been updated.
10:11:00.377 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zigbee:coordinator_xbee:57b76b00' has been updated.
10:11:00.379 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zigbee:coordinator_xbee:57b76b00' has been updated.
10:11:00.380 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Link key final array 5A6967426565416C6C69616E63653039
10:11:00.392 [DEBUG] [nding.zigbee.xbee.handler.XBeeHandler] - ZigBee XBee Coordinator opening Port:'/dev/ttyUSB0' PAN:6252, EPAN:DF7DF769ECB55A1B, Channel:11
10:11:00.395 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start
10:11:00.398 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zigbee:coordinator_xbee:57b76b00' changed from INITIALIZING to UNKNOWN
10:11:01.399 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting
10:11:01.403 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
10:11:01.415 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 1280
10:11:01.417 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode  ] - ClusterMatcher starting
10:11:01.443 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode  ] - ClusterMatcher adding cluster IAS_ZONE
10:11:01.445 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 25
10:11:01.446 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode  ] - ClusterMatcher adding cluster OTA_UPGRADE
10:11:01.448 [DEBUG] [rnal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: Start.
10:11:01.449 [DEBUG] [rnal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: File does not exist
10:11:01.450 [DEBUG] [s.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee dongle initialize.
10:11:01.451 [DEBUG] [nding.zigbee.handler.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB0] at 9600 baud, flow control FLOWCONTROL_OUT_XONOFF.
10:11:01.454 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to UNINITIALISED
10:11:01.458 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=UNINITIALISED
10:11:01.467 [DEBUG] [nding.zigbee.handler.ZigBeeSerialPort] - Serial port [/dev/ttyUSB0] is initialized.
10:11:01.470 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - XBeeFrameHandler clearing receive buffer.
10:11:01.571 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - XBeeFrameHandler cleared receive buffer.
10:11:01.578 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - XBeeFrameHandler thread started
10:11:01.579 [DEBUG] [s.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee dongle reset 1.
10:11:01.582 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeSetSoftwareResetCommand [frameId=1]
10:11:01.583 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeSetSoftwareResetCommand [frameId=1]
10:11:01.585 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 04 08 01 46 52 5E
10:11:01.713 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 05 88 01 46 52 00 DE
10:11:01.720 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeSoftwareResetResponse [frameId=1, commandStatus=OK]
10:11:04.004 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 02 8A 01 74
10:11:04.009 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeModemStatusEvent [status=WATCHDOG_TIMER_RESET]
10:11:04.011 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 02 8A 06 6F
10:11:04.011 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeSetApiEnableCommand [frameId=2, mode=2]
10:11:04.012 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeModemStatusEvent [status=COORDINATOR_STARTED]
10:11:04.013 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeSetApiEnableCommand [frameId=2, mode=2]
10:11:04.014 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 05 08 02 41 50 02 62
10:11:04.147 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 05 88 02 41 50 00 E4
10:11:04.150 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeApiEnableResponse [frameId=2, commandStatus=OK, mode=null]
10:11:04.153 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeSetApiModeCommand [frameId=3, mode=3]
10:11:04.156 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeSetApiModeCommand [frameId=3, mode=3]
10:11:04.159 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 05 08 03 41 4F 03 61
10:11:04.292 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 05 88 03 41 4F 00 E4
10:11:04.296 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeApiModeResponse [frameId=3, commandStatus=OK, mode=null]
10:11:04.301 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeGetHardwareVersionCommand [frameId=4]
10:11:04.304 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeGetHardwareVersionCommand [frameId=4]
10:11:04.310 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 04 08 04 48 56 55
10:11:04.436 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 88 04 48 56 00 19 4A 72
10:11:04.441 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeHardwareVersionResponse [frameId=4, commandStatus=OK, hardwareVersion=19 4A]
10:11:04.445 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeGetFirmwareVersionCommand [frameId=5]
10:11:04.448 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeGetFirmwareVersionCommand [frameId=5]
10:11:04.452 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 04 08 05 56 52 4A
10:11:04.580 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 88 05 56 52 00 21 A7 02
10:11:04.584 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeFirmwareVersionResponse [frameId=5, commandStatus=OK, firmwareVersion=21 A7]
10:11:04.588 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeGetDetailedVersionCommand [frameId=6]
10:11:04.591 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeGetDetailedVersionCommand [frameId=6]
10:11:04.595 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 04 08 06 56 4C 4F
10:11:04.725 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 05 88 06 56 4C 02 CD
10:11:04.729 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeDetailedVersionResponse [frameId=6, commandStatus=INVALID_COMMAND]
10:11:04.734 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeGetIeeeAddressHighCommand [frameId=7]
10:11:04.737 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeGetIeeeAddressHighCommand [frameId=7]
10:11:04.742 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 04 08 07 53 48 55
10:11:04.868 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 09 88 07 53 48 00 00 13 A2 00 20
10:11:04.873 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeIeeeAddressHighResponse [frameId=7, commandStatus=OK, ieeeAddress=00 13 A2 00]
10:11:04.880 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeGetIeeeAddressLowCommand [frameId=8]
10:11:04.883 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeGetIeeeAddressLowCommand [frameId=8]
10:11:04.888 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 04 08 08 53 4C 50
10:11:05.012 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 09 88 08 53 4C 00 41 8B 72 0F 83
10:11:05.016 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeIeeeAddressLowResponse [frameId=8, commandStatus=OK, ieeeAddress=41 8B 72 0F]
10:11:05.019 [DEBUG] [s.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee IeeeAddress=0013A200418B720F
10:11:05.025 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeSetZigbeeStackProfileCommand [frameId=9, stackProfile=2]
10:11:05.029 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeSetZigbeeStackProfileCommand [frameId=9, stackProfile=2]
10:11:05.034 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 05 08 09 5A 53 02 3F
10:11:05.156 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 05 88 09 5A 53 00 C1
10:11:05.159 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeZigbeeStackProfileResponse [frameId=9, commandStatus=OK, stackProfile=null]
10:11:05.163 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeSetEncryptionEnableCommand [frameId=10, enableEncryption=true]
10:11:05.166 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeSetEncryptionEnableCommand [frameId=10, enableEncryption=true]
10:11:05.169 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 05 08 0A 45 45 01 62
10:11:05.299 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 05 88 0A 45 45 00 E3
10:11:05.302 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeEncryptionEnableResponse [frameId=10, commandStatus=OK, enableEncryption=null]
10:11:05.308 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeSetEncryptionOptionsCommand [frameId=11, encryptionOptions=[ENABLE_TRUST_CENTRE]]
10:11:05.311 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeSetEncryptionOptionsCommand [frameId=11, encryptionOptions=[ENABLE_TRUST_CENTRE]]
10:11:05.314 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 05 08 0B 45 4F 02 56
10:11:05.443 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 05 88 0B 45 4F 00 D8
10:11:05.446 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeEncryptionOptionsResponse [frameId=11, commandStatus=OK]
10:11:05.451 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeSetCoordinatorEnableCommand [frameId=12, enable=true]
10:11:05.453 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeSetCoordinatorEnableCommand [frameId=12, enable=true]
10:11:05.457 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 05 08 0C 43 45 01 62
10:11:05.587 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 05 88 0C 43 45 02 E1
10:11:05.590 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeCoordinatorEnableResponse [frameId=12, commandStatus=INVALID_COMMAND]
10:11:05.594 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeSetNetworkKeyCommand [frameId=13, networkKey=00000000000000000000000000000000]
10:11:05.595 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeSetNetworkKeyCommand [frameId=13, networkKey=00000000000000000000000000000000]
10:11:05.596 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 14 08 0D 4E 4B 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 51
10:11:05.747 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 05 88 0D 4E 4B 00 D1
10:11:05.750 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeNetworkKeyResponse [frameId=13, commandStatus=OK]
10:11:05.752 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeSetLinkKeyCommand [frameId=14, linkKey=5A6967426565416C6C69616E63653039]
10:11:05.753 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeSetLinkKeyCommand [frameId=14, linkKey=5A6967426565416C6C69616E63653039]
10:11:05.754 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 14 08 0E 4B 59 5A 69 67 42 65 65 41 6C 6C 69 61 6E 63 65 30 39 8D
10:11:05.891 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 05 88 0E 4B 59 00 C5
10:11:05.895 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeLinkKeyResponse [frameId=14, commandStatus=OK]
10:11:05.900 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeSetSaveDataCommand [frameId=15]
10:11:05.903 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeSetSaveDataCommand [frameId=15]
10:11:05.906 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 04 08 0F 57 52 3F
10:11:06.035 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 05 88 0F 57 52 00 BF
10:11:06.038 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeSaveDataResponse [frameId=15, commandStatus=OK]
10:11:06.042 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeGetPanIdCommand [frameId=16]
10:11:06.045 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeGetPanIdCommand [frameId=16]
10:11:06.050 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 04 08 10 4F 49 4F
10:11:06.178 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 88 10 4F 49 00 BB 68 AC
10:11:06.181 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeePanIdResponse [frameId=16, commandStatus=OK, panId=47976]
10:11:06.185 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeGetExtendedPanIdCommand [frameId=17]
10:11:06.188 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeGetExtendedPanIdCommand [frameId=17]
10:11:06.192 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 04 08 11 4F 50 47
10:11:06.323 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 0D 88 11 4F 50 00 36 CE CF 7B CE 73 4D 1A D1
10:11:06.326 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeExtendedPanIdResponse [frameId=17, commandStatus=OK, extendedPanId=36CECF7BCE734D1A]
10:11:06.329 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to INITIALISING
10:11:06.331 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeGetOperatingChannelCommand [frameId=18]
10:11:06.333 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING
10:11:06.334 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeGetOperatingChannelCommand [frameId=18]
10:11:06.339 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 04 08 12 43 48 5A
10:11:06.466 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 06 88 12 43 48 00 0B CF
10:11:06.469 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeOperatingChannelResponse [frameId=18, commandStatus=OK, channel=11]
10:11:06.475 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - ZigBee Initialise: Previous device configuration was: channel=CHANNEL_11, PanID=47976, EPanId=36CECF7BCE734D1A
10:11:06.477 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Link key initialise 5A6967426565416C6C69616E63653039
10:11:06.480 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - Network key initialise AB84DEBBA25FA9954290CA7B239C87D6
10:11:06.484 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeSetScanChannelsCommand [frameId=19, channels=1]
10:11:06.487 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeSetScanChannelsCommand [frameId=19, channels=1]
10:11:06.493 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 06 08 13 53 43 00 01 4D
10:11:06.626 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 05 88 13 53 43 00 CE
10:11:06.629 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeScanChannelsResponse [frameId=19, commandStatus=OK, channels=null]
10:11:06.632 [DEBUG] [s.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee dongle startup.
10:11:06.634 [DEBUG] [s.zigbee.dongle.xbee.ZigBeeDongleXBee] - Reinitialising XBee dongle and forming network.
10:11:06.637 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to ONLINE
10:11:06.637 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeGetOperatingChannelCommand [frameId=20]
10:11:06.642 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeGetOperatingChannelCommand [frameId=20]
10:11:06.647 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 04 08 14 43 48 58
10:11:06.770 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 06 88 14 43 48 00 0B CD
10:11:06.773 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeOperatingChannelResponse [frameId=20, commandStatus=OK, channel=11]
10:11:06.775 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - ZigBee Initialise done. channel=CHANNEL_11, PanId=25170  EPanId=DF7DF769ECB55A1B
10:11:06.783 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 1280
10:11:06.786 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zigbee:coordinator_xbee:57b76b00' has been updated.
10:11:06.787 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode  ] - ClusterMatcher adding cluster IAS_ZONE
10:11:42.348 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 19 91 00 1F EE 00 00 00 22 BA FA 68 01 01 00 06 01 04 01 18 82 0A 00 00 10 00 61
10:11:42.352 [DEBUG] [dongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeReceivePacketExplicitEvent [ieeeAddress=001FEE00000022BA, networkAddress=64104, sourceEndpoint=1, destinationEndpoint=1, clusterId=6, profileId=260, receiveOptions=PACKET_ACKNOWLEDGED, data=18 82 0A 00 00 10 00]
10:11:42.354 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=64104/1, destinationAddress=0/1, profile=0104, cluster=6, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=18 82 0A 00 00 10 00]
10:11:42.364 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=130, commandId=10]
10:11:42.393 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [On/Off: 64104/1 -> 0/1, cluster=0006, TID=82, reports=[Attribute Report: attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=false]]

(Chris Jackson) #1638

Well, in this log it looks to be working fine.


(stephan) #1639

but it stays “unknown” and doesn’t go “online”?
so I can’t use it:-(


(Chris Jackson) #1640

In the log there are no problems that I can see - it seems to be working. Communications with the device is fine and it seems to be communicating with other devices. However the log is pretty short and I can’t tell what happens after this once the initialisation is complete.


(Chris Jackson) #1641

In the log you emailed me, I also don’t see anything wrong. The network is initialising fine, and devices seem to be connecting to the network and are being communicated with.

The only thing I can think of is that there is a missing call from the driver to say that it has completed initialisation and is online. I will take a look at this shortly but unfortunately this will not get in to 2.4.