[SOLVED] HttpClientFactory

jannegpriv · October 5, 2018, 9:55pm

Hi!

I’m currently working on learning to implement a binding and in the binding that I’m currently trying to improve (Verisure) I’ve just switched to using the HttpClientFactory instead of instantiating and starting a binding specific HttpClient.

My binding specific VerisureHandlerFactory has now added the two methods:

    @Reference
    protected void setHttpClientFactory(HttpClientFactory httpClientFactory) {
        logger.debug("setHttpClientFactory this: " + this.toString());
        VerisureHandlerFactory.httpClient = httpClientFactory.getCommonHttpClient();
    }

    protected void unsetHttpClientFactory(HttpClientFactory httpClientFactory) {
        logger.debug("unsetHttpClientFactory this: " + this.toString());
        VerisureHandlerFactory.httpClient = null;
    }

When running I can see that the setHttpClientFactory gets called by the ESH framework:

2018-10-05 22:58:13.281 [DEBUG] [org.openhab.binding.verisure        ] - BundleEvent RESOLVED - org.openhab.binding.verisure
2018-10-05 22:58:13.299 [DEBUG] [org.openhab.binding.verisure        ] - BundleEvent STARTING - org.openhab.binding.verisure
2018-10-05 22:58:13.334 [DEBUG] [org.openhab.binding.verisure        ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=430, service.bundleid=237, ser
vice.scope=bundle, component.name=binding.verisure, component.id=268} - org.openhab.binding.verisure
2018-10-05 22:58:13.438 [DEBUG] [org.openhab.binding.verisure        ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=431, service.bundleid=237, ser
vice.scope=bundle, component.name=org.openhab.binding.verisure.internal.VerisureHandlerFactory, component.id=269} - org.openhab.binding.verisure
2018-10-05 22:58:13.444 [DEBUG] [sure.internal.VerisureHandlerFactory] - setHttpClientFactory this: org.openhab.binding.verisure.internal.VerisureHandlerFactory@1b677e7
2018-10-05 22:58:13.462 [DEBUG] [org.openhab.binding.verisure        ] - BundleEvent STARTED - org.openhab.binding.verisure
2018-10-05 22:58:13.659 [DEBUG] [sure.internal.VerisureHandlerFactory] - createHandler this: org.openhab.binding.verisure.internal.VerisureHandlerFactory@6bc8fa
2018-10-05 22:58:13.692 [DEBUG] [org.openhab.binding.verisure        ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=432, service.bundleid=237, service.
scope=singleton} - org.openhab.binding.verisure

It seems like my binding HandlerFactory gets called for 2 different objects/instances:

setHttpClientFactory this: org.openhab.binding.verisure.internal.VerisureHandlerFactory@1b677e7
createHandler this: org.openhab.binding.verisure.internal.VerisureHandlerFactory@6bc8fa

Hence. in the second call my private member httpClient is not initialised (null) so my binding BridgeHandler is created with a null argument for the HttpClient.

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

    private final static Set<ThingTypeUID> SUPPORTED_THING_TYPES = Sets
            .union(VerisureBridgeHandler.SUPPORTED_THING_TYPES, VerisureThingHandler.SUPPORTED_THING_TYPES);

    private Map<ThingUID, ServiceRegistration<?>> discoveryServiceRegs = new HashMap<>();
    private HttpClient httpClient;
    private Logger logger = LoggerFactory.getLogger(VerisureHandlerFactory.class);

    @Override
    public boolean supportsThingType(ThingTypeUID thingTypeUID) {
        return SUPPORTED_THING_TYPES.contains(thingTypeUID);
    }

    @Override
    protected ThingHandler createHandler(Thing thing) {
        logger.debug("createHandler this: " + this.toString());
        if (VerisureBridgeHandler.SUPPORTED_THING_TYPES.contains(thing.getThingTypeUID())) {
            VerisureBridgeHandler handler = new VerisureBridgeHandler((Bridge) thing, httpClient);
            registerObjectDiscoveryService(handler);
            return handler;

        } else if (VerisureThingHandler.SUPPORTED_THING_TYPES.contains(thing.getThingTypeUID())) {
            return new VerisureThingHandler(thing);
        }
        return null;

    }

Why is the binding HandlerFactory called for different objects/instances? Shouldn’t I only have one instance of my binding HandlerFactory instantiated by the ESH framework?

I get the same behaviour locally on my Eclipse environment (as on my openHAB 2.3.0 Release Build production environment).

I temporary worked around it making my private member static, but other bindings does not do that.
What have I missed?

BR,

/Janne

cweitkamp · October 6, 2018, 6:54am

Hi Janne,

At first glance I suspect the possible mistake in the service reference methods itself. Let’s try to replace the prefix VerisonHandlerFactory with this when accessing the httpClient property of your handler factory.

@Reference protected void setHttpClientFactory(HttpClientFactory httpClientFactory) { 
    logger.debug("setHttpClientFactory this: " + this.toString());
    this.httpClient = httpClientFactory.getCommonHttpClient(); } protected void unsetHttpClientFactory(HttpClientFactory httpClientFactory) { 
    logger.debug("unsetHttpClientFactory this: " + this.toString());
    this.httpClient = null;
}

As a side note: Please use parametrized logging instead of String concatenation.

jannegpriv · October 6, 2018, 8:45am

Hi!

Thank you for your answer, the code that I pasted was after my work-around with a static member, sorry about that.
The reference methods looks like this (after fixing parametrized logging ) :

    @Reference
    protected void setHttpClientFactory(HttpClientFactory httpClientFactory) {
        logger.debug("setHttpClientFactory this: {}", this);
        this.httpClient = httpClientFactory.getCommonHttpClient();
    }

    protected void unsetHttpClientFactory(HttpClientFactory httpClientFactory) {
        logger.debug("unsetHttpClientFactory this: {}", this);
        this.httpClient = null;
    }

The behaviour is still the same, this time I’ve added more log rows. It looks really strange.

2018-10-06 10:31:14.100 [DEBUG] [o.b.v.i.VerisureHandlerFactory:82   ] - setHttpClientFactory this: org.openhab.binding.verisure.internal.VerisureHandlerFactory@6385b72a
2018-10-06 10:31:14.101 [DEBUG] [.n.h.i.SecureHttpClientFactory:192  ] - creating httpClient for endpoint null
2018-10-06 10:31:14.128 [DEBUG] [.n.h.i.SecureHttpClientFactory:169  ] - jetty shared http client created
2018-10-06 10:31:14.128 [DEBUG] [.n.h.i.SecureHttpClientFactory:119  ] - shared httpClient requested
2018-10-06 10:31:15.171 [DEBUG] [o.b.v.i.VerisureHandlerFactory:87   ] - unsetHttpClientFactory this: org.openhab.binding.verisure.internal.VerisureHandlerFactory@6385b72a
...
2018-10-06 10:31:17.589 [DEBUG] [o.b.v.i.VerisureHandlerFactory:82   ] - setHttpClientFactory this: org.openhab.binding.verisure.internal.VerisureHandlerFactory@b04a33e
2018-10-06 10:31:17.590 [DEBUG] [.n.h.i.SecureHttpClientFactory:119  ] - shared httpClient requested
...
2018-10-06 10:31:18.580 [DEBUG] [.c.thing.internal.ThingManager:964  ] - Thing handler factory 'VerisureHandlerFactory' added
2018-10-06 10:31:18.581 [DEBUG] [.c.thing.internal.ThingManager:964  ] - Thing handler factory 'VerisureHandlerFactory' added
...
2018-10-06 10:31:18.592 [DEBUG] [.c.thing.internal.ThingManager:563  ] - Calling 'VerisureHandlerFactory.registerHandler()' for thing 'verisure:bridge:47f8246d'.
2018-10-06 10:31:18.592 [DEBUG] [o.b.v.i.VerisureHandlerFactory:60   ] - createHandler this: org.openhab.binding.verisure.internal.VerisureHandlerFactory@22b39c83

Something must be really wrong in my setup, why is VerisureHandlerFactory added twice?

Any hints of what might be wrong are extremely appreciated, I will continue to dig into this tonight.

BR,

/Janne

cweitkamp · October 6, 2018, 9:08am

Please double check if there are one or more .xml files in the OSGI-INF/ folder of the bindings sources. If so delete all of them. They will be created automatically during Maven build because there is a @Component annotation in the handler factory.

jannegpriv · October 6, 2018, 2:48pm

Fantastic, spot on :

$ ll OSGI-INF/
total 16
-rw-r--r--  1 jannegpriv  staff  706 Aug 30 21:21 VerisureHandlerFactory.xml
-rw-r--r--  1 jannegpriv  staff  662 Oct  5 22:57 org.openhab.binding.verisure.internal.VerisureHandlerFactory.xml

When I switched to using the HttpClientFactory I added the @Component annotation, since the other bindings using the HttpClientFactory also had that annotation. From that point on I must have had 2 xml-files in the OSGI-INF folder.

Now it works as expected.

Thank’s for the swift help!

BR,

/Janne

cweitkamp · October 6, 2018, 7:40pm

That is awesome. Keep on going with your work.