SMHI Weather Binding

Thank you, I have now enable debug on smhi binding.
Do the log appear in a separate logfile?

No, itā€™s written to openhab.log

Thanks for pointing that out for me!
Look what I found i the logs earlier:

2021-06-10 01:08:13.073 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.ArithmeticException: / by zero
	at java.math.BigDecimal.divideAndRound(BigDecimal.java:4579) ~[?:?]
	at java.math.BigDecimal.divide(BigDecimal.java:5671) ~[?:?]
	at java.math.BigDecimal.divide(BigDecimal.java:1592) ~[?:?]
	at java.math.BigDecimal.divide(BigDecimal.java:1673) ~[?:?]
	at org.openhab.binding.smhi.internal.ForecastAggregator.total(ForecastAggregator.java:43) ~[?:?]
	at org.openhab.binding.smhi.internal.SmhiHandler.getAggregatedValue(SmhiHandler.java:483) ~[?:?]
	at org.openhab.binding.smhi.internal.SmhiHandler.lambda$3(SmhiHandler.java:177) ~[?:?]
	at java.util.ArrayList.forEach(ArrayList.java:1541) ~[?:?]
	at java.util.Collections$UnmodifiableCollection.forEach(Collections.java:1085) ~[?:?]
	at org.openhab.binding.smhi.internal.SmhiHandler.updateChannels(SmhiHandler.java:173) ~[?:?]
	at org.openhab.binding.smhi.internal.SmhiHandler.getUpdatedForecast(SmhiHandler.java:340) ~[?:?]
	at org.openhab.binding.smhi.internal.SmhiHandler.waitForForecast(SmhiHandler.java:272) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
	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:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]

I do not understand it but I can tell that something is wrong. :laughing:

Thatā€™s most likely the reason, Iā€™ll look into what might be causing it, thanks for the report!

1 Like

Thereā€™s not always any values for the last day, which caused a bug when calculating the total precipitation for that day. I will submit a fix that should set the channel to UNDEF when that happens. In the meantime, removing that day from the thing configuration should prevent it from occuring.

Ok, how do i remove ā€œdaysā€ from a thing?

From logs:

2021-06-12 01:09:39.867 [DEBUG] [.binding.smhi.internal.SmhiConnector] - Fetching reference time
2021-06-12 01:09:39.986 [DEBUG] [.binding.smhi.internal.SmhiConnector] - Received response with status 200 - OK
2021-06-12 01:09:39.987 [DEBUG] [.binding.smhi.internal.SmhiConnector] - Fetching new forecast
2021-06-12 01:09:40.007 [DEBUG] [.binding.smhi.internal.SmhiConnector] - Received response with status 200 - OK
2021-06-12 01:09:40.052 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.ArithmeticException: / by zero
	at java.math.BigDecimal.divideAndRound(BigDecimal.java:4579) ~[?:?]
	at java.math.BigDecimal.divide(BigDecimal.java:5671) ~[?:?]
	at java.math.BigDecimal.divide(BigDecimal.java:1592) ~[?:?]
	at java.math.BigDecimal.divide(BigDecimal.java:1673) ~[?:?]
	at org.openhab.binding.smhi.internal.ForecastAggregator.total(ForecastAggregator.java:43) ~[?:?]
	at org.openhab.binding.smhi.internal.SmhiHandler.getAggregatedValue(SmhiHandler.java:483) ~[?:?]
	at org.openhab.binding.smhi.internal.SmhiHandler.lambda$3(SmhiHandler.java:177) ~[?:?]
	at java.util.ArrayList.forEach(ArrayList.java:1541) ~[?:?]
	at java.util.Collections$UnmodifiableCollection.forEach(Collections.java:1085) ~[?:?]
	at org.openhab.binding.smhi.internal.SmhiHandler.updateChannels(SmhiHandler.java:173) ~[?:?]
	at org.openhab.binding.smhi.internal.SmhiHandler.getUpdatedForecast(SmhiHandler.java:340) ~[?:?]
	at org.openhab.binding.smhi.internal.SmhiHandler.waitForForecast(SmhiHandler.java:272) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
	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:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
2021-06-12 01:22:30.513 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Querying state active
2021-06-12 01:22:30.514 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Deactivating component
2021-06-12 01:22:30.515 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : registration change queue [unregistered]
2021-06-12 01:22:30.523 [DEBUG] [ab.binding.smhi.internal.SmhiHandler] - Cancelling polling
2021-06-12 01:22:30.532 [DEBUG] [ab.binding.smhi.internal.SmhiHandler] - Cancelling polling
2021-06-12 01:22:30.536 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Querying state active
2021-06-12 01:22:30.537 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : getting deactivate: deactivate
2021-06-12 01:22:30.537 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Locating method deactivate in class org.openhab.binding.smhi.internal.SmhiHandlerFactory
2021-06-12 01:22:30.538 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Declared Method org.openhab.binding.smhi.internal.SmhiHandlerFactory.deactivate([interface org.osgi.service.component.ComponentContext]) not found
2021-06-12 01:22:30.539 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Locating method deactivate in class org.openhab.core.thing.binding.BaseThingHandlerFactory
2021-06-12 01:22:30.539 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Found deactivate method: protected void org.openhab.core.thing.binding.BaseThingHandlerFactory.deactivate(org.osgi.service.component.ComponentContext)
2021-06-12 01:22:30.540 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : invoking deactivate: deactivate: parameters [org.apache.felix.scr.impl.manager.ComponentContextImpl]
2021-06-12 01:22:30.541 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : invoked deactivate: deactivate
2021-06-12 01:22:30.542 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : DependencyManager: $000 close component unbinding from org.apache.felix.scr.impl.manager.ComponentContextImpl@c1df76 at tracking count 1 refpairs: [[RefPair: ref: [{org.openhab.core.io.net.http.HttpClientFactory, org.openhab.core.io.net.http.WebSocketFactory}={service.id=282, service.bundleid=178, service.scope=bundle, component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=141}] service: [org.openhab.core.io.net.http.internal.WebClientFactoryImpl@151d34e]]]
2021-06-12 01:22:30.542 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Unset and deconfigured implementation object for component in deleteComponent for reason Unspecified
2021-06-12 01:22:30.543 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Changed state from active to satisfied
2021-06-12 01:22:30.544 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Deactivating dependency managers
2021-06-12 01:22:30.544 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Disabling dependency managers
2021-06-12 01:22:30.545 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : unregistering service listener for dependency $000
2021-06-12 01:22:30.546 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Querying state satisfied
2021-06-12 01:22:30.547 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Changed state from satisfied to disposed
2021-06-12 01:22:30.547 [DEBUG] [ing.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0.202105300405 (337)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(364)] : Disposing component (reason: 6)
2021-06-12 01:22:30.753 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Stopped HABPanel
2021-06-12 01:22:30.788 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2021-06-12 01:22:30.840 [INFO ] [io.openhabcloud.internal.CloudClient] - Shutting down openHAB Cloud service connection
2021-06-12 01:22:30.844 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = 9b6be914-da03-4e2e-a09c-d59398cb1424, base URL = http://localhost:8080)
2021-06-12 01:22:33.140 [INFO ] [org.openhab.ui.internal.UIService   ] - Stopped UI

Just untick the box for ā€œ9 days from nowā€ in the Thing config:


Personally I donā€™t use the daily forecasts at all, I only use hourly forecasts for automation purposes, which is why I missed this issue. So thanks again for bringing it to my attention!

1 Like

After examining some more I realized that it might actually be the forecast for ā€œTodayā€ that causes the issue. The reason for this is that in the response received just after midnight UTC (the timestamps in your logs led me to this suspicion), the timestamp of the forecast is e.g "referenceTime": "2021-06-13T23:00:00Z", but the first entry in the forecast is for 2021-06-14T00:00:00Z. This caused the binding to look for entries for 2021-06-13, which there were none, causing the calculation to error. I have updated the code to fix this, but unfortunately the only workaround is to remove the forecast for ā€œTodayā€, which I understand might not be an option.

Iā€™ve uploaded an updated version of the binding which can be downloaded from here and placed in your addons folder until the next OH update, which will hopefully have the fixes included.

1 Like

Thank you so much!

No problem! The updates have just been merged, so will be included when 3.1 gets released (and in any RCs released before that)

1 Like

Hi,
using this very usable binding for cooling the house, extending the awning etc. Very cool, big thanks!

But of course, since I am here, there is something that seems a bit odd. Suddenly the values change drastically and then hangs there for quite some hours (see below). I actually talked to SMHI because I thought maybe their api had a problem but they could not see anything wrong in their end.

This has happened a few times now with a few days in between, now it is the third time since the upgrade to 3.1 (on Windows 10).

Description of problem
Suddenly the day_0 values for SMHI Current Temperature, Wind Speed and Wind Gust Speed jumps quite a bit and then ā€œhangsā€ (possible also Wind Direction). In this latest instance this happened 1:08 AM in the middle of the night. Suddenly everything got cold in the house (since it was so hot outside) :slight_smile:

In this case the temperature jumped from 16.6 to 25.4 degrees (celsius) in the middle of the night which seems a bit unlikely.

Log from the events:

21-07-06 01:08:00.200 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'SMHIWeatherForecast_Temperature' changed from 14.9 Ā°C to 15.1 Ā°C
21-07-06 01:08:00.207 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'SMHIWeatherForecast_Temperature_Current' changed from 16.6 Ā°C to 25.4 Ā°C
21-07-06 01:08:00.208 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'SMHIWeatherForecast_WindDirection' changed from 252 Ā° to 162 Ā°
21-07-06 01:08:00.209 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'SMHIWeatherForecast_WindSpeed' changed from 3.7 m/s to 6.6 m/s
21-07-06 01:08:00.210 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'SMHIWeatherForecast_TotalCloudCover' changed from 50 % to 0 %
21-07-06 01:08:00.211 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'SMHIWeatherForecast_WindGustSpeed' changed from 6.4 m/s to 12.8 m/s
21-07-06 01:08:00.211 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'SMHIWeatherForecast_WeatherCondition' changed from 3 to 1
21-07-06 01:08:16.608 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'SunElevation' changed from -11.634931063372111 Ā° to -11.655956708465062 Ā°
21-07-06 01:08:43.144 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'SunroomTemperature' changed from 19.5 Ā°C to 19.6 Ā°C

21-07-06 07:08:15.119 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'SMHIWeatherForecast_Temperature_Current' changed from 25.4 Ā°C to 25.3 Ā°C

21-07-06 08:08:33.361 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'SMHIWeatherForecast_Temperature_Current' changed from 25.3 Ā°C to 25.5 Ā°C

This is how it looks on my dashboard in OH3.1 and there it is quite clear that somethings stops updating and also is giving a bit of questionable value:

Another detailed screenshot for Wind Speed as an axemple:

I have restarted the binding (since I am now in debug mode for it) but so far no change of the reported values.
`

The initial Debug log for the SMHI binding, I will add more if I see something strange or errors etc:

21-07-06 10:23:41.807 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory] : BundleComponentActivator : ComponentHolder created.
21-07-06 10:23:41.808 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory] : Dependency Manager created $000interface=org.openhab.core.io.net.http.HttpClientFactory, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=0
21-07-06 10:23:41.808 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory] : Component created: DS=DS14, implementation=org.openhab.binding.smhi.internal.SmhiHandlerFactory, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[binding.smhi]
21-07-06 10:23:41.808 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory] : Component Services: scope=singleton, services=[org.openhab.core.thing.binding.ThingHandlerFactory]
21-07-06 10:23:41.808 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory] : Component Properties: {}
21-07-06 10:23:41.808 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory] : Querying state disabled
21-07-06 10:23:41.809 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory] : Querying state disabled
21-07-06 10:23:41.809 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory] : Component can not be activated since it is in state disabled
21-07-06 10:23:41.809 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory] : Querying state disabled
21-07-06 10:23:41.809 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Updating target filters
21-07-06 10:23:41.809 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : No change in target property for dependency $000: currently registered: false
21-07-06 10:23:41.810 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] :  No existing service listener to unregister for dependency $000
21-07-06 10:23:41.810 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Setting target property for dependency $000 to null
21-07-06 10:23:41.810 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : New service tracker for $000, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.core.io.net.http.HttpClientFactory), initialReferenceFilter (objectClass=org.openhab.core.io.net.http.HttpClientFactory)
21-07-06 10:23:41.810 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : dm $000 tracker reset (closed)
21-07-06 10:23:41.811 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.io.net.http.HttpClientFactory, org.openhab.core.io.net.http.WebSocketFactory}={service.id=179, service.bundleid=177, service.scope=bundle, component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=70} (enter)
21-07-06 10:23:41.811 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : dm $000 tracking 1 SingleStatic active: false trackerOpened: false optional: false
21-07-06 10:23:41.812 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.io.net.http.HttpClientFactory, org.openhab.core.io.net.http.WebSocketFactory}={service.id=179, service.bundleid=177, service.scope=bundle, component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=70} (exit)
21-07-06 10:23:41.812 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : dm $000 tracker opened
21-07-06 10:23:41.812 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : registering service listener for dependency $000
21-07-06 10:23:41.812 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Changed state from disabled to unsatisfiedReference
21-07-06 10:23:41.812 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Component enabled
21-07-06 10:23:41.812 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : ActivateInternal
21-07-06 10:23:41.813 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Querying state unsatisfiedReference
21-07-06 10:23:41.813 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Querying state unsatisfiedReference
21-07-06 10:23:41.813 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Activating component from state unsatisfiedReference
21-07-06 10:23:41.813 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Querying state unsatisfiedReference
21-07-06 10:23:41.813 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Querying state unsatisfiedReference
21-07-06 10:23:41.814 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Changed state from unsatisfiedReference to satisfied
21-07-06 10:23:41.814 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : registration change queue [registered]
21-07-06 10:23:41.815 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Checking constructor public org.openhab.binding.smhi.internal.SmhiHandlerFactory(org.openhab.core.io.net.http.HttpClientFactory)
21-07-06 10:23:41.815 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : getReferenceClass: Looking for interface class org.openhab.core.io.net.http.HttpClientFactory through loader of org.openhab.binding.smhi.internal.SmhiHandlerFactory
21-07-06 10:23:41.815 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : getParameterClass: Found class org.openhab.core.io.net.http.HttpClientFactory
21-07-06 10:23:41.816 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Found constructor with 1 arguments : public org.openhab.binding.smhi.internal.SmhiHandlerFactory(org.openhab.core.io.net.http.HttpClientFactory)
21-07-06 10:23:41.816 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : This thread collected dependencies
21-07-06 10:23:41.816 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : getService (single component manager) dependencies collected.
21-07-06 10:23:41.816 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Querying state satisfied
21-07-06 10:23:41.817 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Querying state satisfied
21-07-06 10:23:41.817 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : For dependency $000, optional: false; to bind: [[RefPair: ref: [{org.openhab.core.io.net.http.HttpClientFactory, org.openhab.core.io.net.http.WebSocketFactory}={service.id=179, service.bundleid=177, service.scope=bundle, component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=70}] service: [null]]]
21-07-06 10:23:41.817 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : getting activate: activate
21-07-06 10:23:41.817 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Locating method activate in class org.openhab.binding.smhi.internal.SmhiHandlerFactory
21-07-06 10:23:41.818 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Declared Method org.openhab.binding.smhi.internal.SmhiHandlerFactory.activate([interface org.osgi.service.component.ComponentContext]) not found
21-07-06 10:23:41.818 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Locating method activate in class org.openhab.core.thing.binding.BaseThingHandlerFactory
21-07-06 10:23:41.818 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Found activate method: protected void org.openhab.core.thing.binding.BaseThingHandlerFactory.activate(org.osgi.service.component.ComponentContext)
21-07-06 10:23:41.818 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.manager.ComponentContextImpl]
21-07-06 10:23:41.818 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : invoked activate: activate
21-07-06 10:23:41.819 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Set implementation object for component
21-07-06 10:23:41.819 [DEBUG] [ding.smhi.internal.SmhiHandlerFactory] - bundle org.openhab.binding.smhi:3.1.0 (276)[org.openhab.binding.smhi.internal.SmhiHandlerFactory(342)] : Changed state from satisfied to active
21-07-06 10:23:41.847 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'smhi:forecast:2455b1fa20' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
21-07-06 10:23:41.850 [DEBUG] [hab.binding.smhi.internal.SmhiHandler] - Start polling
21-07-06 10:23:54.977 [DEBUG] [b.binding.smhi.internal.SmhiConnector] - Fetching new forecast
21-07-06 10:23:55.046 [DEBUG] [b.binding.smhi.internal.SmhiConnector] - Received response with status 200 - OK
21-07-06 10:23:55.050 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'smhi:forecast:2455b1fa20' changed from INITIALIZING to ONLINE

Is there anybody else experiencing this or have any idea on how to possibly fix the problem?

The values for the day_* channels are the value at noon (UTC) or, if itā€™s past noon the first value for the day (except for the min/max/total aggregated channels). If you want the current temperature etc you should use the hour_0 channels.

Oh man, totally missed that. Thank you very much!

First of, great binding! :slight_smile:
But I started getting this error message when I updated to OH 3.1.0
I get this a couple of times every minute and its flooding my logsā€¦


2021-07-24 00:12:28.386 [WARN ] [ab.binding.smhi.internal.SmhiHandler] - Unexpected exception occurred, please report to the developers: class java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 1

Any idea why? I didnā€™t change anything.

Thanks for reporting, not sure what would cause it, but might be something with the channel updating. I would need some more information to pinpoint it further:

  • Which hourly/daily forecasts have you activated?
  • Does the Items get updated successfully despite the error?

The logging of the error is new in 3.1, but should have been a fatal error which would have caused the binding to crash in earlier versions, so might be something that went wrong in the upgrade. Could you try to delete the Thing and recreate it? (As long as you name it the same as the old one all channels should be re-linked automatically)

Hi and thank you for responding :slight_smile:

I have hourly forecasts and also today, tomorrow, 2,3,4 days.
The item seems to be working fine despite the error.

Iā€™ve reinstalled the binding and havenā€™t had any error yet. The message comes and goes.
Iā€™ll get back if the message shows up again.

Sorry to report that it hasnā€™t helped. The error still appears.

2021-08-06 00:44:12.485 [WARN ] [ab.binding.smhi.internal.SmhiHandler] - Unexpected exception occurred, please report to the developers: class java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 1
2021-08-06 00:44:12.524 [WARN ] [ab.binding.smhi.internal.SmhiHandler] - Unexpected exception occurred, please report to the developers: class java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 1
2021-08-06 00:45:12.689 [WARN ] [ab.binding.smhi.internal.SmhiHandler] - Unexpected exception occurred, please report to the developers: class java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 1
2021-08-06 00:45:12.709 [WARN ] [ab.binding.smhi.internal.SmhiHandler] - Unexpected exception occurred, please report to the developers: class java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 1
2021-08-06 00:46:12.876 [WARN ] [ab.binding.smhi.internal.SmhiHandler] - Unexpected exception occurred, please report to the developers: class java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 1
2021-08-06 00:46:12.897 [WARN ] [ab.binding.smhi.internal.SmhiHandler] - Unexpected exception occurred, please report to the developers: class java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 1
2021-08-06 00:47:13.067 [WARN ] [ab.binding.smhi.internal.SmhiHandler] - Unexpected exception occurred, please report to the developers: class java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 1
2021-08-06 00:47:13.090 [WARN ] [ab.binding.smhi.internal.SmhiHandler] - Unexpected exception occurred, please report to the developers: class java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 1
2021-08-06 00:48:13.282 [WARN ] [ab.binding.smhi.internal.SmhiHandler] - Unexpected exception occurred, please report to the developers: class java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 1
2021-08-06 00:48:13.305 [WARN ] [ab.binding.smhi.internal.SmhiHandler] - Unexpected exception occurred, please report to the developers: class java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 1


Iā€™ll see if I can reproduce it to investigate. Could you post your thing configuration? Just copy it from the code tab in main UI (you can omit the coordinates if you feel itā€™s too sensitive).

UID: smhi:forecast:7435ea8222
label: SMHI Weather Forecast
thingTypeUID: smhi:forecast
configuration:
hourlyForecasts:
- 0
latitude: 57.XXXXXX
longitude: 11.XXXXXX
dailyForecasts:
- 0
- 1
- 2
- 3
- 4

(Replaced the coordinates last digits with XXXXXX :slight_smile: )

Thanks. Does the log line appear all the time, or just during a certain time of day?