[fmiweather] Exception on startup

[jlaur]

I have observed this exception in my logs during openHAB startup:

2024-10-28 20:45:30.497 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.IllegalStateException: Http client factory not available
	at org.openhab.core.io.net.http.HttpUtil.executeUrlAndGetReponse(HttpUtil.java:191) ~[?:?]
	at org.openhab.core.io.net.http.HttpUtil.executeUrl(HttpUtil.java:155) ~[?:?]
	at org.openhab.core.io.net.http.HttpUtil.executeUrl(HttpUtil.java:130) ~[?:?]
	at org.openhab.core.io.net.http.HttpUtil.executeUrl(HttpUtil.java:108) ~[?:?]
	at org.openhab.core.io.net.http.HttpUtil.executeUrl(HttpUtil.java:89) ~[?:?]
	at org.openhab.binding.fmiweather.internal.client.Client.queryWeatherStations(Client.java:161) ~[?:?]
	at org.openhab.binding.fmiweather.internal.discovery.FMIWeatherDiscoveryService.lambda$0(FMIWeatherDiscoveryService.java:74) ~[?:?]
	at org.openhab.core.cache.ExpiringCache.refreshValue(ExpiringCache.java:101) ~[?:?]
	at org.openhab.core.cache.ExpiringCache.getValue(ExpiringCache.java:72) ~[?:?]
	at org.openhab.binding.fmiweather.internal.discovery.FMIWeatherDiscoveryService.cachedStations(FMIWeatherDiscoveryService.java:193) ~[?:?]
	at org.openhab.binding.fmiweather.internal.discovery.FMIWeatherDiscoveryService.createObservationsForStations(FMIWeatherDiscoveryService.java:153) ~[?:?]
	at org.openhab.binding.fmiweather.internal.discovery.FMIWeatherDiscoveryService.createResults(FMIWeatherDiscoveryService.java:124) ~[?:?]
	at org.openhab.binding.fmiweather.internal.discovery.FMIWeatherDiscoveryService.lambda$1(FMIWeatherDiscoveryService.java:112) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
	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:833) [?:?]

Expected Behavior

Binding should not throw exception and discovery should work correctly.

Current Behavior

Bindings throws exception.

Possible Solution

As soon as the framework creates an instance of FMIWeatherDiscoveryService, a new Client is created:

openhab-addons/bundles/org.openhab.binding.fmiweather/src/main/java/org/openhab/binding/fmiweather/internal/discovery/FMIWeatherDiscoveryService.java

Lines 72 to 83 in 44fb3ad

	private ExpiringCache<Set<Location>> stationsCache = new ExpiringCache<>(STATIONS_CACHE_MILLIS, () -> {
	try {
	return new Client().queryWeatherStations(STATIONS_TIMEOUT_MILLIS);
	} catch (FMIUnexpectedResponseException e) {
	logger.warn("Unexpected error with the response, potentially API format has changed. Printing out details",
	e);
	} catch (FMIResponseException e) {
	logger.warn("Error when querying stations, {}: {}", e.getClass().getSimpleName(), e.getMessage());
	}
	// Return empty set on errors
	return Collections.emptySet();
	});

which is immediately queried:

openhab-addons/bundles/org.openhab.binding.fmiweather/src/main/java/org/openhab/binding/fmiweather/internal/client/Client.java

Lines 158 to 161 in 44fb3ad

	public Set<Location> queryWeatherStations(int timeoutMillis)
	throws FMIIOException, FMIUnexpectedResponseException, FMIExceptionReportException {
	try {
	String response = HttpUtil.executeUrl("GET", WEATHER_STATIONS_URL, timeoutMillis);

and core in return throws exception:

https://github.com/openhab/openhab-core/blob/728c7376b650c2c1cd271128f39d300cbacbf212/bundles/org.openhab.core.io.net/src/main/java/org/openhab/core/io/net/http/HttpUtil.java#L189-L192

The factory is set here:

https://github.com/openhab/openhab-core/blob/728c7376b650c2c1cd271128f39d300cbacbf212/bundles/org.openhab.core.io.net/src/main/java/org/openhab/core/io/net/http/HttpUtil.java#L539-L542

but apparently this has not yet happened during the startup.

Even though this might actually be a timing issue/bug in core, it could probably be mitigated in the binding by one of the following measures:

• Delaying initialization of stationsCache until a scan has been started.
• Using a more standard OSGi life cycle approach with HttpClient rather than the static HttpUtil class.

Steps to Reproduce

I'm not sure how easy it is to reproduce given that it's most likely a timing-related issue. However, I have seen it on multiple occasions during startup on my quite old development machine (running Windows).

Your Environment

• Version used: 4.3 latest snapshot as of today

[jlaur]

I'll have a look at this, since I'm currently able to reproduce it more or less consistently each day.