openhab/org.openhab.binding.zigbee

Sonoff zigbee 3.0 USB Dongle Plus -E remains in initializing status after restart

Opened this issue · 0 comments

Problem

The dongle will stay in initializing until you disable the thing delete or rename the xml file located in the subfolder of the ZigBee folder that matches the dongle.
reenable the dongle thing it then comes online and remains online until you either stop the service and restart it or reboot the box.
Then the dongle remains in the initializing state until you remove the xml file.
Note this issue does not occur if you run the Openhab manually not as a service.

openhab.log:

2024-01-17 10:24:58.075 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.NoClassDefFoundError: Could not initialize class com.thoughtworks.xstream.converters.collections.TreeSetConverter$Reflections
	at com.thoughtworks.xstream.converters.collections.TreeSetConverter.unmarshal(TreeSetConverter.java:62) ~[?:?]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:74) ~[?:?]
	at com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(AbstractReferenceUnmarshaller.java:72) ~[?:?]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:68) ~[?:?]
	at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshallField(AbstractReflectionConverter.java:499) ~[?:?]
	at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.doUnmarshal(AbstractReflectionConverter.java:425) ~[?:?]
	at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshal(AbstractReflectionConverter.java:277) ~[?:?]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:74) ~[?:?]
	at com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(AbstractReferenceUnmarshaller.java:72) ~[?:?]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:68) ~[?:?]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:52) ~[?:?]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:136) ~[?:?]
	at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:32) ~[?:?]
	at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1464) ~[?:?]
	at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1441) ~[?:?]
	at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1321) ~[?:?]
	at org.openhab.binding.zigbee.internal.ZigBeeDataStore.readNode(ZigBeeDataStore.java:134) ~[?:?]
	at com.zsmartsystems.zigbee.database.ZigBeeNetworkDatabaseManager.startup(ZigBeeNetworkDatabaseManager.java:193) ~[?:?]
	at com.zsmartsystems.zigbee.ZigBeeNetworkManager.initialize(ZigBeeNetworkManager.java:416) ~[?:?]
	at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.initialiseZigBee(ZigBeeCoordinatorHandler.java:431) ~[?:?]
	at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.lambda$2(ZigBeeCoordinatorHandler.java:557) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
	at java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: java.lang.ExceptionInInitializerError: Exception java.lang.reflect.InaccessibleObjectException: Unable to make field private transient java.util.NavigableMap java.util.TreeSet.m accessible: module java.base does not "opens java.util" to unnamed module @33264017 [in thread "OH-thingHandler-3"]
	at java.lang.reflect.AccessibleObject.checkCanSetAccessible(AccessibleObject.java:354) ~[?:?]
	at java.lang.reflect.AccessibleObject.checkCanSetAccessible(AccessibleObject.java:297) ~[?:?]
	at java.lang.reflect.Field.checkCanSetAccessible(Field.java:178) ~[?:?]
	at java.lang.reflect.Field.setAccessible(Field.java:172) ~[?:?]
	at com.thoughtworks.xstream.core.util.Fields.locate(Fields.java:40) ~[?:?]
	at com.thoughtworks.xstream.converters.collections.TreeSetConverter$Reflections.<clinit>(TreeSetConverter.java:135) ~[?:?]
	... 27 more
2024-01-17 10:24:57.050 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - bundle org.openhab.binding.zigbee:4.1.1 (305)[org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService(367)] : dm ZigBeeCoordinatorHandler tracking 10 MultipleDynamic added {org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler}={service.id=1084, service.bundleid=310, service.scope=singleton} (enter)
2024-01-17 10:24:57.050 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - bundle org.openhab.binding.zigbee:4.1.1 (305)[org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService(367)] : dm ZigBeeCoordinatorHandler tracking 10 MultipleDynamic already active, binding {org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler}={service.id=1084, service.bundleid=310, service.scope=singleton}
2024-01-17 10:24:57.051 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - bundle org.openhab.binding.zigbee:4.1.1 (305)[org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService(367)] : invoking bind: addZigBeeCoordinatorHandler: parameters [org.openhab.binding.zigbee.ember.handler.EmberHandler]
2024-01-17 10:24:57.051 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - bundle org.openhab.binding.zigbee:4.1.1 (305)[org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService(367)] : invoked bind: addZigBeeCoordinatorHandler
2024-01-17 10:24:57.051 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - bundle org.openhab.binding.zigbee:4.1.1 (305)[org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService(367)] : dm ZigBeeCoordinatorHandler tracking 10 MultipleDynamic added {org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler}={service.id=1084, service.bundleid=310, service.scope=singleton} (exit)
2024-01-17 10:24:57.057 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initializing ZigBee network [zigbee:coordinator_ember:ZigbeeDongle].
2024-01-17 10:24:57.057 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Channel 11
2024-01-17 10:24:57.057 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - PANID 2037
2024-01-17 10:24:57.057 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - EPANID 682844A80C922E8D
2024-01-17 10:24:57.057 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key 4EBE08FDA6442E662BC7D765EFA867FA
2024-01-17 10:24:57.057 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key 5A6967426565416C6C69616E63653039
2024-01-17 10:24:57.058 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Config: zigbee_initialise found, initializeNetwork=false
2024-01-17 10:24:57.058 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key String 4EBE08FDA6442E662BC7D765EFA867FA
2024-01-17 10:24:57.058 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network key final array 4EBE08FDA6442E662BC7D765EFA867FA
2024-01-17 10:24:57.058 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key String 5A6967426565416C6C69616E63653039
2024-01-17 10:24:57.058 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link key final array 5A6967426565416C6C69616E63653039
2024-01-17 10:24:57.058 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Initializing ZigBee Ember serial bridge handler.
2024-01-17 10:24:57.059 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - ZigBee Ember Coordinator opening Port:'COM4' PAN:7f5, EPAN:682844A80C922E8D, Channel:11
2024-01-17 10:24:57.059 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Ember end device poll timeout set to (169 * 2^9) = 86528 seconds
2024-01-17 10:24:57.059 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start
2024-01-17 10:24:58.061 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting
2024-01-17 10:24:58.061 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
2024-01-17 10:24:58.063 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING

Description

Discussion in Community:
https://community.openhab.org/t/sonoff-zigbee-dongle-modell-e-no-longer-available-after-restart/153097

Result of justaoldman's investigation:

"This appears to be related to Java 17.
even with openhab 3.4 and java 17 the issue immediately reoccurs. (Although java 17 was not the official version for 3.4 versions 3.4 would run on it and mostly function.)
Note this issue does not occur if you run the Openhab manually not as a service."

Add following Lines in openhab-wrapper.config solves the Problem:

set.default.PATH=%PATH_WITH_JAVA%
set.default.JDK_JAVA_OPTIONS=--add-reads=java.xml=java.logging --add-exports=java.base/org.apache.karaf.specs.locator=java.xml,ALL-UNNAMED --patch-module java.base=%KARAF_HOME%/lib/endorsed/org.apache.karaf.specs.locator-%KARAF_VERSION%.jar --patch-module java.xml=%KARAF_HOME%/lib/endorsed/org.apache.karaf.specs.java.xml-%KARAF_VERSION%.jar --add-opens java.base/java.security=ALL-UNNAMED --add-opens java.base/java.net=ALL-UNNAMED --add-opens java.base/java.lang=ALL-UNNAMED --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.naming/javax.naming.spi=ALL-UNNAMED --add-opens java.rmi/sun.rmi.transport.tcp=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.file=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.ftp=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.http=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.https=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.jar=ALL-UNNAMED --add-exports=java.base/sun.net.www.content.text=ALL-UNNAMED --add-exports=jdk.xml.dom/org.w3c.dom.html=ALL-UNNAMED --add-exports=jdk.naming.rmi/com.sun.jndi.url.rmi=ALL-UNNAMED --add-exports=java.rmi/sun.rmi.registry=ALL-UNNAMED --add-exports=java.naming/com.sun.jndi.ldap=ALL-UNNAMED

Configuration

Configuration Description
Coordinator used Sonoff zigbee 3.0 USB Dongle Plus -E used with firmware version 6.10.3.0
openHAB version 4.1.1; Problem reproducible from 3.4 upwards (with Java 17).
OS Windows 11 Home 22H2 64Bit
Memory 8GB
Java version ZULU JDK 17