Ubiquiti Unifi Binding Feature Discussion

Dim · December 7, 2018, 10:23am

strange. I have been monitoring the state of my Items using the console and doing items list "grep -i unifi and their state hasn’t updated since I used the newest version of the binding

do you get the Circular reference also or not?

Note: I may be wrong but I remember the following: The first time that I started it, it looked ok and I didn’t get any Circular reference logged. I stopped OH2 service, error appeared, started again… error again and since then: no updates

I will enable TRACE to see what is going on and report back

mhilbush · December 7, 2018, 10:29am

It’s perfectly ok for a bridge to have channels. Having said that, I agree it would be better to have separate Thing(s) for the site(s). As you said, there’s greater flexibility for defining multiple sites.

mgbowman · December 7, 2018, 10:32am

What’s funny is now that you mention it, going back up in the log, no I did not…

There’s something wonky going on here with the order the service components are getting registered.

I’m going to write a script to trash and redeploy the snapshot over and over to see if I can figure this out!

Dim · December 7, 2018, 10:35am

I just restarted OH2 service and got immediately (first 2 entries in openhab.log) the Circular reference error (1st) from org.apache.felix.scr and the ServiceException warning (2nd) from org.openhab.binding.unifi

So far: no updates from the binding to my Items (no worries: we are testing stuff out )

try to restart the OH2 service on your S1451 testbed system to see if they come up

mgbowman · December 7, 2018, 10:46am

Looks like you’re right, restart kills it.

I’m thinking it’s because fresh snapshot doesn’t have any circular references because unifi isn’t yet loaded.

Installing and starting the bundle works as expected (all the other components are already loaded).

Restart and poof

Digging deeper

Kim_Andersen · December 7, 2018, 12:03pm

Could it be related?:

Dim · December 7, 2018, 12:20pm

no, I think it’s more complex: The maintainers requested to re-use an existing ESH functionality (HttpClientFactory) and this impacts the way that Matthew had already implemented TLS within the binding so he has to figure out a new method

see here: https://github.com/openhab/openhab2-addons/pull/3387#discussion_r239528242

martinvw · December 7, 2018, 12:53pm

I think this is timing problem which is corrected by the runtime in the end.

And I opened an issue for it: ExtensibleTrustManager - circular reference · Issue #6641 · eclipse-archived/smarthome · GitHub

mgbowman · December 7, 2018, 1:12pm

What’s the difference here vs the iCloud binding?

iCloud uses TlsCertificateProvider where UniFi uses TlsTrustManagerProvider. I would think it would be functionally the same - it’s just different interface implementations.

Edit: I know iCloud uses the HttpRequestBuilder (which I could as well), but even if I remove the references to HttpClientFactory and use my own, it still throws throw the circular reference.

martinvw · December 7, 2018, 1:13pm

I fear that there is no difference and the iCloud binding also has this behaviour (some times ) after a restart.

roryd · December 7, 2018, 1:25pm

@mgbowman Okay, so I shutdown my cloud key and installed a controller on a windows machine (until I get to the bottom of the cert issue). Binding is working fine now

mgbowman · December 7, 2018, 1:30pm

@martinvw considering there are inconsistent results with using TlsTrustManagerProvider, would it not be ok to revert back to using my own HttpClient instance until we can manage to figure this out?

This way maybe there’s a chance we can still squeeze this into 2.4

Wanna · December 7, 2018, 3:11pm

Hey folks,

I’ve walked into this error today. Does anyone have an idea?

07-Dec-2018 16:01:01.366 [smarthome.event.ThingStatusInfoChangedEvent ] - ‘unifi:controller:home’ changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): java.io.EOFException: HttpConnectionOverHTTP@16a41ff(l:/192.168.1.60:48560 <-> r:/192.168.1.7:8443,closed=false)[HttpChannelOverHTTP@372aef(exchange=HttpExchange@4cf134 req=TERMINATED/null@null res=PENDING/null@null)[send=HttpSenderOverHTTP@1c24ae7(req=QUEUED,snd=COMPLETED,failure=null)[HttpGenerator@b88519{s=START}],recv=HttpReceiverOverHTTP@199a7f3(rsp=IDLE,failure=null)[HttpParser{s=CLOSED,0 of -1}]]]

Kind regards,
Alex

Dim · December 7, 2018, 5:07pm

Which version of the binding are you running, on which OH2 release?

this looks like a simple disconnection between the binding running on your OH2 host and the Unifi Controller Software running on the remote host. It could be due to several reasons …(Controller down, link down, etc)

Does it happen often? Does the Thing go back to Online after some time?

Kai · December 7, 2018, 5:58pm

Ok for me, let’s go the safe route - but please put the current solution back as soon as we are on 2.5.0-SNAPSHOT, so we can investigate further. Our TLS http client has to work reliably and this seems to be a good case to find out potential problems it might still have

mgbowman · December 8, 2018, 7:10am

@Dim can you try the latest version?

openhab> bundle:list | grep -i unifi
190 │ Active   │  80 │ 2.4.0.201812080707     │ UniFi Binding

I added some basic SSL exception handling and want to see if maybe you’re having an issue unrelated to the circular dependency warning (which I don’t think is causing your problems).

Edit: Fixed the version number (was using a local build vs. the jenkins build)

Dim · December 8, 2018, 7:21am

There you go Matthew (same status unfortunately)

OH 2.4.0.S1454
Unifi Controller: 5.6.40
binding.unifi: 2.4.0.201812080707

2018-12-08 09:18:17.136 [ERROR] [org.apache.felix.scr                ] - bundle org.apache.felix.scr:2.1.2 (39)Circular reference detected trying to get service {org.eclipse.smarthome.io.net.http.TlsTrustManagerProvider}={service.id=118, service.bundleid=191, service.scope=bundle, component.name=org.openhab.binding.unifi.internal.ssl.UniFiTrustManagerProvider, component.id=17}
 stack of references: ServiceReference: {org.eclipse.smarthome.io.net.http.TlsTrustManagerProvider}={service.id=118, service.bundleid=191, service.scope=bundle, component.name=org.openhab.binding.unifi.internal.ssl.UniFiTrustManagerProvider, component.id=17}
ServiceReference: {org.eclipse.smarthome.io.net.http.internal.ExtensibleTrustManager}={service.id=131, service.bundleid=118, service.scope=bundle, component.name=org.eclipse.smarthome.io.net.http.internal.ExtensibleTrustManager, component.id=35}

java.lang.Exception: stack trace
	at org.apache.felix.scr.impl.ComponentRegistry.enterCreate(ComponentRegistry.java:481) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.BundleComponentActivator.enterCreate(BundleComponentActivator.java:735) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:845) [39:org.apache.felix.scr:2.1.2]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) [?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) [?:?]
	at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:73) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:662) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2304) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.prebind(DependencyManager.java:419) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1576) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1014) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:899) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) [39:org.apache.felix.scr:2.1.2]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) [?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) [?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) [?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) [?:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) [?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) [?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) [?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:661) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:427) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:381) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:263) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) [39:org.apache.felix.scr:2.1.2]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) [?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) [?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) [?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) [?:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) [?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:467) [?:?]
	at org.eclipse.osgi.framework.util.SecureAction.start(SecureAction.java:468) [?:?]
	at org.eclipse.osgi.internal.hooks.EclipseLazyStarter.postFindLocalClass(EclipseLazyStarter.java:103) [?:?]
	at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findLocalClass(ClasspathManager.java:529) [?:?]
	at org.eclipse.osgi.internal.loader.ModuleClassLoader.findLocalClass(ModuleClassLoader.java:328) [?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(BundleLoader.java:368) [?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:446) [?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:395) [?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:387) [?:?]
	at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:150) [?:?]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:357) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.loadClass(EquinoxBundle.java:564) [?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.initDependencyManagers(AbstractComponentManager.java:984) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1011) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:899) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) [39:org.apache.felix.scr:2.1.2]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) [?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) [?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) [?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) [?:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) [?:?]
	at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183) [?:?]
	at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318) [?:?]
	at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261) [?:?]
	at com.eclipsesource.jaxrs.publisher.internal.Activator.openAllServiceTracker(Activator.java:91) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
	at com.eclipsesource.jaxrs.publisher.internal.Activator.start(Activator.java:55) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
	at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:779) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:1) [?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:772) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:729) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:933) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.startWorker(EquinoxBundle.java:309) [?:?]
	at org.eclipse.osgi.container.Module.doStart(Module.java:581) [?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:449) [?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1634) [?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1614) [?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1585) [?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1528) [?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340) [?:?]
2018-12-08 09:18:17.192 [WARN ] [org.openhab.binding.unifi           ] - FrameworkEvent WARNING - org.openhab.binding.unifi
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:232) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:73) ~[?:?]
	at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:662) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2304) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.prebind(DependencyManager.java:419) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1576) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1014) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:899) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) ~[?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) ~[?:?]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:661) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:427) ~[?:?]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339) ~[?:?]
	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:381) ~[?:?]
	at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) ~[?:?]
	at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:263) ~[?:?]
	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:482) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) ~[?:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) ~[?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:467) ~[?:?]
	at org.eclipse.osgi.framework.util.SecureAction.start(SecureAction.java:468) ~[?:?]
	at org.eclipse.osgi.internal.hooks.EclipseLazyStarter.postFindLocalClass(EclipseLazyStarter.java:103) ~[?:?]
	at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findLocalClass(ClasspathManager.java:529) ~[?:?]
	at org.eclipse.osgi.internal.loader.ModuleClassLoader.findLocalClass(ModuleClassLoader.java:328) ~[?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(BundleLoader.java:368) ~[?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:446) ~[?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:395) ~[?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:387) ~[?:?]
	at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:150) ~[?:?]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.loadClass(EquinoxBundle.java:564) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.initDependencyManagers(AbstractComponentManager.java:984) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1011) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:899) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) ~[?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261) ~[?:?]
	at com.eclipsesource.jaxrs.publisher.internal.Activator.openAllServiceTracker(Activator.java:91) ~[?:?]
	at com.eclipsesource.jaxrs.publisher.internal.Activator.start(Activator.java:55) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:779) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:1) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:772) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:729) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:933) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.startWorker(EquinoxBundle.java:309) ~[?:?]
	at org.eclipse.osgi.container.Module.doStart(Module.java:581) ~[?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:449) ~[?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1634) ~[?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1614) ~[?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1585) ~[?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1528) ~[?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340) [?:?]

mgbowman · December 8, 2018, 7:28am

@martinvw I think I might of discovered what’s going on here…

This is from a freshly unzipped 2.4.0-SNAPSHOT #1451 (no extra packages / no UIs installed - didn’t even open the web UI).

openhab> bundle:install https://jenkins.otr.mx/job/openhab2-unifi-binding/83/artifact/addons/binding/org.openhab.binding.unifi/target/org.openhab.binding.unifi-2.4.0-SNAPSHOT.jar
Bundle ID: 190
openhab> bundle:start 190

Here’s the error

2018-12-08 09:20:10.991 [DEBUG] [.handler.UniFiControllerThingHandler] - Initializing the UniFi Controller Handler with config = UniFiControllerConfig{host = unifi, port = 8443, username = [redacted], password = *****, refresh = 10}
2018-12-08 09:20:11.096 [ERROR] [.handler.UniFiControllerThingHandler] - Unknown error while configuring the UniFi Controller
org.openhab.binding.unifi.internal.api.UniFiException: java.lang.RuntimeException: Delegated task threw Exception/Error
	at org.openhab.binding.unifi.internal.api.UniFiControllerRequest.getContentResponse(UniFiControllerRequest.java:161) ~[190:org.openhab.binding.unifi:2.4.0.201812080707]
	at org.openhab.binding.unifi.internal.api.UniFiControllerRequest.getContent(UniFiControllerRequest.java:119) ~[190:org.openhab.binding.unifi:2.4.0.201812080707]
	at org.openhab.binding.unifi.internal.api.UniFiControllerRequest.execute(UniFiControllerRequest.java:104) ~[190:org.openhab.binding.unifi:2.4.0.201812080707]
	at org.openhab.binding.unifi.internal.api.UniFiController.executeRequest(UniFiController.java:113) ~[190:org.openhab.binding.unifi:2.4.0.201812080707]
	at org.openhab.binding.unifi.internal.api.UniFiController.login(UniFiController.java:70) ~[190:org.openhab.binding.unifi:2.4.0.201812080707]
	at org.openhab.binding.unifi.internal.api.UniFiController.start(UniFiController.java:56) ~[190:org.openhab.binding.unifi:2.4.0.201812080707]
	at org.openhab.binding.unifi.internal.handler.UniFiControllerThingHandler.initialize(UniFiControllerThingHandler.java:120) [190:org.openhab.binding.unifi:2.4.0.201812080707]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
	at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.201812032218]
	at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [101:org.eclipse.smarthome.core:0.10.0.201812032218]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.lang.RuntimeException: Delegated task threw Exception/Error
	at sun.security.ssl.Handshaker.checkThrown(Handshaker.java:1519) ~[?:?]
	at sun.security.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:528) ~[?:?]
	at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:802) ~[?:?]
	at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:766) ~[?:?]
	at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) ~[?:?]
	at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:681) ~[?:?]
	at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.process(HttpReceiverOverHTTP.java:128) ~[?:?]
	at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.receive(HttpReceiverOverHTTP.java:73) ~[?:?]
	at org.eclipse.jetty.client.http.HttpChannelOverHTTP.receive(HttpChannelOverHTTP.java:133) ~[?:?]
	at org.eclipse.jetty.client.http.HttpConnectionOverHTTP.onFillable(HttpConnectionOverHTTP.java:155) ~[?:?]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281) ~[?:?]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) ~[?:?]
	at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:291) ~[?:?]
	at org.eclipse.jetty.io.ssl.SslConnection$3.succeeded(SslConnection.java:151) ~[?:?]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) ~[?:?]
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) ~[?:?]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762) ~[?:?]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680) ~[?:?]
	... 1 more
Caused by: java.lang.NullPointerException
	at org.eclipse.smarthome.io.net.http.internal.ExtensibleTrustManager.getLinkedTrustMananger(ExtensibleTrustManager.java:135) ~[?:?]
	at org.eclipse.smarthome.io.net.http.internal.ExtensibleTrustManager.checkServerTrusted(ExtensibleTrustManager.java:112) ~[?:?]
	at sun.security.ssl.ClientHandshaker.serverCertificate(ClientHandshaker.java:1626) ~[?:?]
	at sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:223) ~[?:?]
	at sun.security.ssl.Handshaker.processLoop(Handshaker.java:1037) ~[?:?]
	at sun.security.ssl.Handshaker$1.run(Handshaker.java:970) ~[?:?]
	at sun.security.ssl.Handshaker$1.run(Handshaker.java:967) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1459) ~[?:?]
	at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:775) ~[?:?]
	at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.process(HttpReceiverOverHTTP.java:128) ~[?:?]
	at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.receive(HttpReceiverOverHTTP.java:73) ~[?:?]
	at org.eclipse.jetty.client.http.HttpChannelOverHTTP.receive(HttpChannelOverHTTP.java:133) ~[?:?]
	at org.eclipse.jetty.client.http.HttpConnectionOverHTTP.onFillable(HttpConnectionOverHTTP.java:155) ~[?:?]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281) ~[?:?]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) ~[?:?]
	at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:291) ~[?:?]
	at org.eclipse.jetty.io.ssl.SslConnection$3.succeeded(SslConnection.java:151) ~[?:?]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) ~[?:?]
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) ~[?:?]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762) ~[?:?]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680) ~[?:?]
	... 1 more
2018-12-08 09:20:11.112 [DEBUG] [rnal.handler.UniFiClientThingHandler] - Initializing the UniFi Client Handler with config = UniFiClientConfig{cid: '[redacted]', site: 'default', considerHome: 180}
2018-12-08 09:20:11.114 [DEBUG] [org.openhab.binding.unifi           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=313, service.bundleid=190, service.scope=bundle, component.name=org.openhab.binding.unifi.internal.UniFiThingHandlerFactory, component.id=176} - org.openhab.binding.unifi
2018-12-08 09:20:11.118 [DEBUG] [org.openhab.binding.unifi           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.net.http.TlsTrustManagerProvider}={service.id=314, service.bundleid=190, service.scope=bundle, component.name=org.openhab.binding.unifi.internal.ssl.UniFiTrustManagerProvider, component.id=177} - org.openhab.binding.unifi

It looks like the UniFiControllerThingHandler is getting started before the TlsTrustManagerProvider is being registered (notice the ServiceEvent REGISTERED lines at the end)

martinvw · December 8, 2018, 7:35am

But that does not have to be a problem, it should just retry the connection later, would you be able to implement that?

Or is the common client null when injecting?

mgbowman · December 8, 2018, 7:44am

It’s the ExtendedTrustManager throwing an NPE

github.com

eclipse/smarthome/blob/master/bundles/io/org.eclipse.smarthome.io.net/src/main/java/org/eclipse/smarthome/io/net/http/internal/ExtensibleTrustManager.java#L132-L135


logger.trace("Searching trustManager by Subject Alternative Names: {}",
        chain[0].getSubjectAlternativeNames());
// @formatter:off
return chain[0].getSubjectAlternativeNames().stream()

Same setup as above with TRACE enabled for org.eclipse.smarthome.io.net

...
2018-12-08 09:41:34.618 [TRACE] [http.internal.ExtensibleTrustManager] - Searching trustManager by Subject Alternative Names: null
...
Caused by: java.lang.NullPointerException
	at org.eclipse.smarthome.io.net.http.internal.ExtensibleTrustManager.getLinkedTrustMananger(ExtensibleTrustManager.java:135) ~[?:?]

...

You’re calling .stream() on NULL

Edit: looking through the ExtensibleTrustManager code again, I believe it confirms my suspicions of the TlsTrustManagerProvider being registered after because the branch a few lines above the NPE should of been taken:

github.com

eclipse/smarthome/blob/master/bundles/io/org.eclipse.smarthome.io.net/src/main/java/org/eclipse/smarthome/io/net/http/internal/ExtensibleTrustManager.java#L127-L130


if (trustManager != null) {
    logger.trace("Found trustManager by common name: {}", commonName);
    return trustManager;
}