openhab/org.openhab.binding.zigbee

InvocationTargetException: null when starting console bundle

kpanchen opened this issue · 7 comments

After 3.1.0-snapshot or 3.1.0 RC update zigbee binding logs error in the log file. Was Ok in original 3 released version.

Configuration

Coordinator used - Nortek Security & Control HUSBZB-1
openHAB version - 3.1.0 RC
Hardware - Intel
Memory - 16gb
Java version - Zulu 11
Devices - no devices

openhab.log

I can confirm this on a fresh and clean 3.1.RC1 installation.

@cdjackson I consider this a critical issue, could you please have a look?

FTR, here's the log details:

2021-06-26 10:25:03.396 [ERROR] [al.EmberZigBeeConsoleCommandProvider] - bundle org.openhab.binding.zigbee.console.ember:3.1.0.RC1 (252)[org.openhab.binding.zigbee.console.ember.internal.EmberZigBeeConsoleCommandProvider(307)] : Error during instantiation of the implementation object
java.lang.reflect.InvocationTargetException: null
	at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:?]
	at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[?:?]
	at jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:?]
	at java.lang.reflect.Constructor.newInstance(Constructor.java:490) ~[?:?]
	at org.apache.felix.scr.impl.inject.internal.ComponentConstructorImpl.newInstance(ComponentConstructorImpl.java:316) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:286) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:115) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:1000) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:973) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:918) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:216) ~[org.eclipse.osgi-3.16.200.jar:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:213) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:114) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:48) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:547) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:533) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:656) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:88) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:675) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2556) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:2075) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:2058) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:443) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:333) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:301) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1200) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1121) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:928) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:864) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1152) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:114) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:120) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:957) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:936) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:873) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:141) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:261) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:496) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:929) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:915) ~[?:?]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:984) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:752) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:674) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:437) ~[?:?]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:667) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:305) ~[?:?]
	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:554) ~[?:?]
	at org.apache.felix.scr.impl.Activator.access$200(Activator.java:70) ~[?:?]
	at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:421) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:488) ~[osgi.core-7.0.0.jar:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:420) ~[osgi.core-7.0.0.jar:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[osgi.core-7.0.0.jar:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:450) ~[osgi.core-7.0.0.jar:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:945) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:232) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:138) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:130) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:217) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:499) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.container.Module.start(Module.java:486) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:440) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:459) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.apache.karaf.features.internal.service.BundleInstallSupportImpl.startBundle(BundleInstallSupportImpl.java:165) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.startBundle(FeaturesServiceImpl.java:1160) ~[?:?]
	at org.apache.karaf.features.internal.service.Deployer.deploy(Deployer.java:1041) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.doProvision(FeaturesServiceImpl.java:1069) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.lambda$doProvisionInThread$13(FeaturesServiceImpl.java:1004) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:834) [?:?]
Caused by: java.lang.IllegalStateException: Duplicate key ncpscan (attempted merging values com.zsmartsystems.zigbee.console.ember.EmberConsoleNcpScanCommand@d597b9e and com.zsmartsystems.zigbee.console.ember.EmberConsoleNcpScanCommand@220d25af)
	at java.util.stream.Collectors.duplicateKeyException(Collectors.java:133) ~[?:?]
	at java.util.stream.Collectors.lambda$uniqKeysMapAccumulator$1(Collectors.java:180) ~[?:?]
	at java.util.stream.ReduceOps$3ReducingSink.accept(ReduceOps.java:169) ~[?:?]
	at java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:948) ~[?:?]
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484) ~[?:?]
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[?:?]
	at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913) ~[?:?]
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:578) ~[?:?]
	at org.openhab.binding.zigbee.console.ember.internal.EmberZigBeeConsoleCommandProvider.<init>(EmberZigBeeConsoleCommandProvider.java:63) ~[?:?]
	... 80 more
2021-06-26 10:25:03.424 [WARN ] [ternal.ZigBeeConsoleCommandExtension] - bundle org.openhab.binding.zigbee.console:3.1.0.RC1 (251)[org.openhab.binding.zigbee.console.internal.ZigBeeConsoleCommandExtension(306)] : Could not get service from ref {org.openhab.binding.zigbee.console.ZigBeeConsoleCommandProvider}={service.id=478, service.bundleid=252, service.scope=bundle, component.name=org.openhab.binding.zigbee.console.ember.internal.EmberZigBeeConsoleCommandProvider, component.id=307}
2021-06-26 10:25:03.424 [WARN ] [ternal.ZigBeeConsoleCommandExtension] - bundle org.openhab.binding.zigbee.console:3.1.0.RC1 (251)[org.openhab.binding.zigbee.console.internal.ZigBeeConsoleCommandExtension(306)] : DependencyManager : invokeBindMethod : Service not available from service registry for ServiceReference {org.openhab.binding.zigbee.console.ZigBeeConsoleCommandProvider}={service.id=478, service.bundleid=252, service.scope=bundle, component.name=org.openhab.binding.zigbee.console.ember.internal.EmberZigBeeConsoleCommandProvider, component.id=307} for reference CommandProvider
2021-06-26 10:25:03.425 [ERROR] [al.EmberZigBeeConsoleCommandProvider] - bundle org.openhab.binding.zigbee.console.ember:3.1.0.RC1 (252)[org.openhab.binding.zigbee.console.ember.internal.EmberZigBeeConsoleCommandProvider(307)] : Error during instantiation of the implementation object
java.lang.reflect.InvocationTargetException: null
	at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:?]
	at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[?:?]
	at jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:?]
	at java.lang.reflect.Constructor.newInstance(Constructor.java:490) ~[?:?]
	at org.apache.felix.scr.impl.inject.internal.ComponentConstructorImpl.newInstance(ComponentConstructorImpl.java:316) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:286) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:115) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:1000) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:973) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:776) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:674) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:437) ~[?:?]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:667) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:305) ~[?:?]
	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:554) ~[?:?]
	at org.apache.felix.scr.impl.Activator.access$200(Activator.java:70) ~[?:?]
	at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:421) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:488) ~[osgi.core-7.0.0.jar:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:420) ~[osgi.core-7.0.0.jar:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[osgi.core-7.0.0.jar:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:450) ~[osgi.core-7.0.0.jar:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:945) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:232) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:138) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:130) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:217) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:499) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.container.Module.start(Module.java:486) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:440) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:459) ~[org.eclipse.osgi-3.16.200.jar:?]
	at org.apache.karaf.features.internal.service.BundleInstallSupportImpl.startBundle(BundleInstallSupportImpl.java:165) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.startBundle(FeaturesServiceImpl.java:1160) ~[?:?]
	at org.apache.karaf.features.internal.service.Deployer.deploy(Deployer.java:1041) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.doProvision(FeaturesServiceImpl.java:1069) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.lambda$doProvisionInThread$13(FeaturesServiceImpl.java:1004) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:834) [?:?]
Caused by: java.lang.IllegalStateException: Duplicate key ncpscan (attempted merging values com.zsmartsystems.zigbee.console.ember.EmberConsoleNcpScanCommand@d597b9e and com.zsmartsystems.zigbee.console.ember.EmberConsoleNcpScanCommand@220d25af)
	at java.util.stream.Collectors.duplicateKeyException(Collectors.java:133) ~[?:?]
	at java.util.stream.Collectors.lambda$uniqKeysMapAccumulator$1(Collectors.java:180) ~[?:?]
	at java.util.stream.ReduceOps$3ReducingSink.accept(ReduceOps.java:169) ~[?:?]
	at java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:948) ~[?:?]
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484) ~[?:?]
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[?:?]
	at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913) ~[?:?]
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:578) ~[?:?]
	at org.openhab.binding.zigbee.console.ember.internal.EmberZigBeeConsoleCommandProvider.<init>(EmberZigBeeConsoleCommandProvider.java:63) ~[?:?]
	... 44 more

Thanks for the quick fix, @cdjackson. I have built a new snapshot and can confirm that the issue is fixed in that.

Thanks for testing Kai. I’m trying to start getting my new system installed over the weekend so now have M1 running (just!) but still got to install some devices...

On 26/06/2021, at 9:45 PM, Kai Kreuzer @.***> wrote: Thanks for the quick fix, @cdjackson https://github.com/cdjackson. I have built a new snapshot and can confirm that the issue is fixed in that. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#655 (comment)>, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAH6IQ73GNRC4AN5VLF7XFLTUWOSRANCNFSM47LC5YCQ.

Thanks Chris, I'll test it too. If needed debug log can be provided!