smarthome icon indicating copy to clipboard operation
smarthome copied to clipboard

ExtensibleTrustManager - circular reference

Open martinvw opened this issue 6 years ago • 27 comments

I and others noted that when injecting / implementing the TlsTrustManagerProvider warning sometimes pop up. Eg.

!ENTRY org.apache.felix.scr 4 0 2018-12-07 06:55:13.806
!MESSAGE Circular reference detected trying to get service {org.eclipse.smarthome.io.net.http.TlsTrustManagerProvider}={service.id=62, service.bundleid=4, service.scope=bundle, component.name=org.openhab.binding.unifi.internal.ssl.UniFiTrustManagerProvider, component.id=26}
 stack of references: ServiceReference: {org.eclipse.smarthome.io.net.http.TlsTrustManagerProvider}={service.id=62, service.bundleid=4, service.scope=bundle, component.name=org.openhab.binding.unifi.internal.ssl.UniFiTrustManagerProvider, component.id=26}
ServiceReference: {org.eclipse.smarthome.io.net.http.internal.ExtensibleTrustManager}={service.id=69, service.bundleid=107, service.scope=bundle, component.name=org.eclipse.smarthome.io.net.http.internal.ExtensibleTrustManager, component.id=29}

And the (I suppose, correct) conclusions by Mathew

What I think is happening:

UniFiThingHandlerFactory depends on a reference to HttpClientFactory HttpClientFactory depends on ExtensibleTrustManager ExtensibleTrustManager depends on TlsTrustManagerProvider (provided by unifi) <-- circular reference

Regardless of this error, it seems that it eventually loads everything and the binding functions as expected.

See also: https://community.openhab.org/t/ubiquiti-unifi-binding-feature-discussion/14520/630

Is there way we could suppress the warning and/or work around this by playing around with 'Delayed Components'? Or some other solutions? Thanks!

martinvw avatar Dec 07 '18 12:12 martinvw

And the (I suppose, correct) conclusions by Mathew

I've dug deeper and even if I remove the reference to HttpClientFactory (and just instantiate HttpClient myself), I still get the circular reference.

!ENTRY org.apache.felix.scr 4 0 2018-12-07 14:59:48.274
!MESSAGE Circular reference detected trying to get service {org.eclipse.smarthome.io.net.http.TlsTrustManagerProvider}={service.id=62, service.bundleid=4, service.scope=bundle, component.name=org.openhab.binding.unifi.internal.ssl.UniFiTrustManagerProvider, component.id=26}
 stack of references: ServiceReference: {org.eclipse.smarthome.io.net.http.TlsTrustManagerProvider}={service.id=62, service.bundleid=4, service.scope=bundle, component.name=org.openhab.binding.unifi.internal.ssl.UniFiTrustManagerProvider, component.id=26}
ServiceReference: {org.eclipse.smarthome.io.net.http.internal.ExtensibleTrustManager}={service.id=70, service.bundleid=107, service.scope=bundle, component.name=org.eclipse.smarthome.io.net.http.internal.ExtensibleTrustManager, component.id=29}

Also my assumptions about the binding eventually loading and functioning properly isn't 100% accurate - at least not consistently :(

mgbowman avatar Dec 07 '18 13:12 mgbowman

Also my assumptions about the binding eventually loading and functioning properly isn't 100% accurate - at least not consistently :(

I spotted that in the community topic as well.

Maybe an @Component(immediate = false) on the UniFiTrustManagerProvider will make or break it. I have to pickup the kids now, but will try later as well.

martinvw avatar Dec 07 '18 13:12 martinvw

If TrustManagerProvider is deprecated (I'm assuming in favor of ExtensibleTrustManager), why are the reference calls to setExtensibleTrustManager / unsetExtensibleTrustManager marked as @Deprecated (instead of the calls to setTrustmanagerProvider / unsetTrustmanagerProvider)?

TrustManagerProvider is deprecated

https://github.com/eclipse/smarthome/blob/cb0463b2e37ce2bb1ea195865de6c7aecc13cfb2/bundles/io/org.eclipse.smarthome.io.net/src/main/java/org/eclipse/smarthome/io/net/http/TrustManagerProvider.java#L27-L28

And the reference calls for ExtensibleTrustManager are deprecated

https://github.com/eclipse/smarthome/blob/cb0463b2e37ce2bb1ea195865de6c7aecc13cfb2/bundles/io/org.eclipse.smarthome.io.net/src/main/java/org/eclipse/smarthome/io/net/http/internal/WebClientFactoryImpl.java#L393-L404

However the reference calls for TrustManagerProvider are not...

https://github.com/eclipse/smarthome/blob/cb0463b2e37ce2bb1ea195865de6c7aecc13cfb2/bundles/io/org.eclipse.smarthome.io.net/src/main/java/org/eclipse/smarthome/io/net/http/internal/WebClientFactoryImpl.java#L406-L415

mgbowman avatar Dec 07 '18 13:12 mgbowman

I updated those annotations already, you are not looking at the master branch:

https://github.com/eclipse/smarthome/pull/6520

martinvw avatar Dec 07 '18 14:12 martinvw

Sorry 🤦‍♂️

mgbowman avatar Dec 07 '18 14:12 mgbowman

No problem, it was indeed wrong before my PR follow up :-)

martinvw avatar Dec 07 '18 14:12 martinvw

I'm testing now with immediate = false for the icloud binding

martinvw avatar Dec 07 '18 14:12 martinvw

I'm testing now with immediate = false for the icloud binding

No that does not work 😞

@maggu2810 your ideas would be greatly appreciated.

martinvw avatar Dec 07 '18 14:12 martinvw

I assume having a separate OSGi bundle to provide the tls provider would solve this, but I’m not sure whether this direction is preferable.

martinvw avatar Dec 07 '18 15:12 martinvw

Separate bundles won't help anything - the circular dependency is between components (i.e. class instances), not between bundles. I still have to wrap my head around WHAT the actual circle is in that case...

kaikreuzer avatar Dec 07 '18 15:12 kaikreuzer

Bundles would explain it for me but classes do not compute for me. TlsCertificateProvider for iCloud fails similar for me sometimes but most of the times I recycle my Docker container so it did not really standout

martinvw avatar Dec 07 '18 15:12 martinvw

I've dug deeper and even if I remove the reference to HttpClientFactory (and just instantiate HttpClient myself), I still get the circular reference.

This sounds all pretty weird indeed. The UniFiTrustManagerProvider does not have ANY dependency, so how can it possibly be circular...? No clue. Will try to reproduce myself a bit later.

Nonetheless, this warning is usually just a warning that can be ignored and SCR still manages to bring all components up. So do you have a link to what actually goes wrong in your situations? Or are we just talking about the log message as cosmetics here?

kaikreuzer avatar Dec 07 '18 15:12 kaikreuzer

Nonetheless, this warning is usually just a warning that can be ignored and SCR still manages to bring all components up.

There's one user reporting that the binding stops working (others report it's fine). I've had mixed results running a clean 2.4.0-SNAPSHOT instance.

Edit: Everything works fine in the IDE 🤔

mgbowman avatar Dec 07 '18 15:12 mgbowman

Nonetheless, this warning is usually just a warning that can be ignored and SCR still manages to bring all components up. So do you have a link to what actually goes wrong in your situations? Or are we just talking about the log message as cosmetics here?

2018-12-07 13:58:37.458 [ERROR] [org.apache.felix.scr                ] - bundle org.apache.felix.scr:2.1.2 (44)Circular reference detected trying to get service {org.eclipse.smarthome.io.net.http.TlsCertificateProvider}={service.id=169, service.bundleid=274, service.scope=bundle, component.name=org.openhab.binding.icloud.internal.ICloudTlsCertificateProvider, component.id=74}
 stack of references: ServiceReference: {org.eclipse.smarthome.io.net.http.TlsCertificateProvider}={service.id=169, service.bundleid=274, service.scope=bundle, component.name=org.openhab.binding.icloud.internal.ICloudTlsCertificateProvider, component.id=74}
ServiceReference: {org.eclipse.smarthome.io.net.http.internal.ExtensibleTrustManager}={service.id=209, service.bundleid=122, service.scope=bundle, component.name=org.eclipse.smarthome.io.net.http.internal.ExtensibleTrustManager, component.id=128}

java.lang.Exception: stack trace
        at org.apache.felix.scr.impl.ComponentRegistry.enterCreate(ComponentRegistry.java:481) [44:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.BundleComponentActivator.enterCreate(BundleComponentActivator.java:735) [44:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:845) [44: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) [44:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47) [44:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:662) [44:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2304) [44:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.prebind(DependencyManager.java:419) [44:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1576) [44:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1014) [44:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:899) [44:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) [44: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) [?:?]
...
2018-12-07 13:58:37.475 [WARN ] [org.openhab.binding.icloud          ] - FrameworkEvent WARNING - org.openhab.binding.icloud
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) ~[?:?]
...
2018-12-07 13:58:37.518 [DEBUG] [org.openhab.binding.icloud          ] - BundleEvent STARTING - org.openhab.binding.icloud
2018-12-07 13:58:37.519 [DEBUG] [org.openhab.binding.icloud          ] - BundleEvent STARTED - org.openhab.binding.icloud

I have nu clue whether those are related, but it seems fishy. Note that they are immediately adjacent

The account is online after this warning but the devices not, maybe this is existing

martinvw avatar Dec 07 '18 15:12 martinvw

Just another data point... if I run OH2 with org.eclipse.smarthome.io.net from within my workspace (vs. the target platform), the circular dependency warning goes away.

mgbowman avatar Dec 07 '18 16:12 mgbowman

I am failing to reproduce this warning.

There's one user reporting that the binding stops working

I doubt that it is related to that message. If it stops working, something else is probably wrong there and some suitable logging should be made available.

I've had mixed results running a clean 2.4.0-SNAPSHOT instance.

Which means you saw that message? Did you see any other issue or did the trust manager work as expected?

kaikreuzer avatar Dec 07 '18 17:12 kaikreuzer

@kaikreuzer / @mgbowman with the fixes as in https://github.com/openhab/openhab2-addons/pull/4329

The iCloud binding always reports online on the devices that should be online, so I cannot reproduce the problem (anymore).

martinvw avatar Dec 07 '18 19:12 martinvw

It would be great if we could reproduce the cycle by e.g. a small change to the magic bundle that adds one or multiple components that cause such a cycle message. If it is working most of the time but a warning is only shown some times and not reproducible it is hard to comment...

maggu2810 avatar Dec 10 '18 08:12 maggu2810

@maggu2810 the main reason i did a shout out to you, is because I did not understand how this would really break something and / or how to split and divide to work around it.

But as it seems now other bugs caused the non-functioning. So luckily it is more like a warning which is solved by the framework in the end.

Given it’s a warning only would it still make sense to add it to the magic bundle? Or was that more for reproduction and debugging the actual problems.

Thanks!!!

martinvw avatar Dec 10 '18 09:12 martinvw

Or was that more for reproduction and debugging the actual problems.

Only for reproduction and debugging, so we can dig into the problem using the Eclipse SmartHome IDE setup.

maggu2810 avatar Dec 10 '18 09:12 maggu2810

I need to get a proper ESH dev env setup but I could reproduce it consistently like this...

FooThingHanderFactory.java

@Component(service = ThingHandlerFactory.class, configurationPid = "binding.foo")
public class FooThingHandlerFactory extends BaseThingHandlerFactory {

    ...

    @Reference
    public void setHttpClientFactory(HttpClientFactory httpClientFactory) {
        this.httpClientFactory = httpClientFactory;
    }

    public void unsetHttpClientFactory(HttpClientFactory httpClientFactory) {
        if (this.httpClientFactory == httpClientFactory) {
            this.httpClientFactory = null;
        }
    }

}

FooTlsTrustManagerProvider.java

@Component
public class FooTlsTrustManagerProvider implements TlsTrustManagerProvider {

    // TlsTrustManagerProvider implementation

}

If I moved both services into FooThingHandlerFactory, the warning went away:

@Component(service = { ThingHandlerFactory.class, TlsTrustManagerProvider.class }, configurationPid = "binding.foo")
public class FooThingHandlerFactory extends BaseThingHandlerFactory implements TlsTrustManagerProvider {

    ...

}

mgbowman avatar Dec 10 '18 09:12 mgbowman

@mgbowman I tried to modify the magic bundle but cannot reproduce the error using the Eclipse SmartHome default launch configuration that is part of that repo:

Do I miss some code?

diff --git a/bundles/test/org.eclipse.smarthome.magic/src/main/java/org/eclipse/smarthome/magic/binding/foo/FooThingHandlerFactory.java b/bundles/test/org.eclipse.smarthome.magic/src/main/java/org/eclipse/smarthome/magic/binding/foo/FooThingHandlerFactory.java
new file mode 100644
index 0000000000..1346be206a
--- /dev/null
+++ b/bundles/test/org.eclipse.smarthome.magic/src/main/java/org/eclipse/smarthome/magic/binding/foo/FooThingHandlerFactory.java
@@ -0,0 +1,39 @@
+package org.eclipse.smarthome.magic.binding.foo;
+
+import org.eclipse.jdt.annotation.Nullable;
+import org.eclipse.smarthome.core.thing.Thing;
+import org.eclipse.smarthome.core.thing.ThingTypeUID;
+import org.eclipse.smarthome.core.thing.binding.BaseThingHandlerFactory;
+import org.eclipse.smarthome.core.thing.binding.ThingHandler;
+import org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory;
+import org.eclipse.smarthome.io.net.http.HttpClientFactory;
+import org.osgi.service.component.annotations.Component;
+import org.osgi.service.component.annotations.Reference;
+
+@Component(service = ThingHandlerFactory.class, configurationPid = "binding.foo")
+public class FooThingHandlerFactory extends BaseThingHandlerFactory {
+
+    private HttpClientFactory httpClientFactory;
+
+    @Reference
+    public void setHttpClientFactory(HttpClientFactory httpClientFactory) {
+        this.httpClientFactory = httpClientFactory;
+    }
+
+    public void unsetHttpClientFactory(HttpClientFactory httpClientFactory) {
+        if (this.httpClientFactory == httpClientFactory) {
+            this.httpClientFactory = null;
+        }
+    }
+
+    @Override
+    public boolean supportsThingType(ThingTypeUID thingTypeUID) {
+        return false;
+    }
+
+    @Override
+    protected @Nullable ThingHandler createHandler(Thing thing) {
+        return null;
+    }
+
+}
diff --git a/bundles/test/org.eclipse.smarthome.magic/src/main/java/org/eclipse/smarthome/magic/binding/foo/FooTlsTrustManagerProvider.java b/bundles/test/org.eclipse.smarthome.magic/src/main/java/org/eclipse/smarthome/magic/binding/foo/FooTlsTrustManagerProvider.java
new file mode 100644
index 0000000000..77e83d7ab1
--- /dev/null
+++ b/bundles/test/org.eclipse.smarthome.magic/src/main/java/org/eclipse/smarthome/magic/binding/foo/FooTlsTrustManagerProvider.java
@@ -0,0 +1,60 @@
+package org.eclipse.smarthome.magic.binding.foo;
+
+import java.net.Socket;
+import java.security.cert.CertificateException;
+import java.security.cert.X509Certificate;
+
+import javax.net.ssl.SSLEngine;
+import javax.net.ssl.X509ExtendedTrustManager;
+
+import org.eclipse.smarthome.io.net.http.TlsTrustManagerProvider;
+import org.osgi.service.component.annotations.Component;
+
+@Component
+public class FooTlsTrustManagerProvider implements TlsTrustManagerProvider {
+
+    @Override
+    public String getHostName() {
+        return "foo.bar";
+    }
+
+    @Override
+    public X509ExtendedTrustManager getTrustManager() {
+        return new X509ExtendedTrustManager() {
+
+            @Override
+            public X509Certificate[] getAcceptedIssuers() {
+                return new X509Certificate[] {};
+            }
+
+            @Override
+            public void checkServerTrusted(X509Certificate[] arg0, String arg1) throws CertificateException {
+            }
+
+            @Override
+            public void checkClientTrusted(X509Certificate[] arg0, String arg1) throws CertificateException {
+            }
+
+            @Override
+            public void checkServerTrusted(X509Certificate[] chain, String authType, SSLEngine engine)
+                    throws CertificateException {
+            }
+
+            @Override
+            public void checkServerTrusted(X509Certificate[] chain, String authType, Socket socket)
+                    throws CertificateException {
+            }
+
+            @Override
+            public void checkClientTrusted(X509Certificate[] chain, String authType, SSLEngine engine)
+                    throws CertificateException {
+            }
+
+            @Override
+            public void checkClientTrusted(X509Certificate[] chain, String authType, Socket socket)
+                    throws CertificateException {
+            }
+        };
+    }
+
+}

maggu2810 avatar Dec 12 '18 08:12 maggu2810

@maggu2810 I'm not exactly sure (the code looks good to me), but note what I said before:

Just another data point... if I run OH2 with org.eclipse.smarthome.io.net from within my workspace (vs. the target platform), the circular dependency warning goes away.

On another note, what exactly is the "magic" bundle? 🤔

mgbowman avatar Dec 12 '18 08:12 mgbowman

A bundle to test and demonstrate stuff (it is part of the ESH repo).

maggu2810 avatar Dec 12 '18 10:12 maggu2810

I still get the error with 2.5.0.M1. Any updates on this since Dec 18?

codefalk avatar May 04 '19 09:05 codefalk

And does it impact some functionality?

martinvw avatar May 04 '19 10:05 martinvw

i can't point to a specific problem that I have. But I do have problems since OH 2.4 stable with OH missing to trigger events / recognize state changes of items connected by bindings. This appears after some days/weeks of operation and does affect multiple bindings. Therefore I am trying to get error messages resolved in my installation to exclude possible root causes.

codefalk avatar May 04 '19 10:05 codefalk