Openhab-addons: [tankerkoenig] Thing repeatedly goes offline

Created on 27 Oct 2020  路  16Comments  路  Source: openhab/openhab-addons

Expected Behavior

It is expected that the binding stays online all (most) of the time.

My Bridge configuration:

Bridge tankerkoenig:webservice:Tankpreise "Tankpreise" [ apikey="<api key>", refresh=10, modeOpeningTime=true ]

The broken down monitoring part (it is a bit more complex, with delay triggers and notifications sent, but this code shows the relevant parts):

rule "Tankerkoenig Binding online (debug)"
when
    Thing "tankerkoenig:webservice:Tankpreise" changed from OFFLINE to ONLINE
then
    logInfo("Tankerkoenig Binding", "The binding is online")
end

rule "Tankerkoenig Binding offline (debug)"
when
    Thing "tankerkoenig:webservice:Tankpreise" changed from ONLINE to OFFLINE
then
    logInfo("Tankerkoenig Binding", "The binding is offline")
end

Current Behavior

I have monitoring in place for most of the Bindings, to see if they go offline, and if there is a problem. This Binding goes offline very often, comes online for a fraction of a second, and then goes offline again. However this does not happen all the time. This is yesterday:

2020-10-26 02:42:45.029 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 02:42:45.100 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 02:52:45.317 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 02:52:45.390 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 03:02:45.597 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 03:02:45.666 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 03:12:45.874 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 03:12:45.935 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 03:22:46.192 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 03:22:46.279 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 03:32:46.781 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 03:32:46.846 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 03:42:47.309 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 03:42:47.384 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 03:52:47.888 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 03:52:47.945 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 04:02:48.237 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 04:02:48.286 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 04:12:48.755 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 04:12:48.818 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 04:22:49.334 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 04:22:49.385 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 04:32:49.655 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 04:32:49.721 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 04:42:50.175 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 04:42:50.247 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 04:52:50.567 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 04:52:50.638 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 05:00:51.135 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 05:02:50.852 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 05:12:51.320 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 05:12:51.407 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 05:22:51.668 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 05:22:51.777 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 05:32:52.059 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 05:32:52.107 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 05:42:52.629 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 05:42:52.768 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 05:52:53.325 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 05:52:53.397 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 06:02:53.669 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 22:03:38.124 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 22:13:38.579 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 22:13:38.660 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 22:23:39.161 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 22:23:39.225 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 22:33:39.677 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 22:33:39.753 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 22:43:40.203 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 22:43:40.281 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 22:53:40.765 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 22:53:40.849 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 23:03:41.273 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 23:03:41.376 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 23:13:41.874 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 23:13:41.934 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 23:23:42.459 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 23:23:42.531 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 23:33:42.891 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 23:33:42.938 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 23:43:43.418 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 23:43:43.498 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline
2020-10-26 23:53:44.027 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is online
2020-10-26 23:53:44.086 [INFO ] [me.model.script.Tankerkoenig Binding] - The binding is offline

I would expect this Binding to stay online, except when there is a network or server-side problem.

Steps to Reproduce (for Bugs)

Install and configure the binding, use the above Rules code for monitoring the binding.

Context

Currently I can not reliable monitor this Binding, and most importantly I don't know if it is fetching accurate prices.

Your Environment

openHAB 2.5.9 (about to be updated to .10), the problem is not new in this version but exists since I started using the Binding.
The openHAB system runs on a Pi 4 with an up-to-date Raspbian system.

bug
Source
picture andreasscherbaum

Most helpful comment

I've cherry-picked it onto the 2.5.x branch (https://github.com/openhab/openhab-addons/commit/be0b3cf5b92a5347d00bcd9c34bf45a16268d6a7).

picture kaikreuzer on 4 Nov 2020
👍3 🚀1 ❤1

All 16 comments

I had never noticed such!
Please raise log level of org.openhab.binding.tankerkoenig to DEBUG and post the relevant lines after you observed such behaviour again.

Confirm you have only a single webservice installed.

Checking your posted log above I see timeperiods when the webservice is OFFLINE, during such a period could you check on PaperUI the posted reason for being OFFLINE? Since all posted OFFLINE times are outside "normal" working houres I do suspect a fuel station posting a not supported report which results in this OFFLINE message. The scheduled polling however isn't cancled, so the next poll creates the ONLINE again. But, present GUESS!

Used your rules on my system as well.

JueBag picture JueBag on 27 Oct 2020

I have only a single web service installed, which monitors a total of 10 stations. One local, a couple more in Berlin direction from where we live.

Here is the debug output from one "run":

2020-10-28 02:35:04.418 [DEBUG] [g.internal.handler.WebserviceHandler] - Try to refresh data
2020-10-28 02:35:04.420 [DEBUG] [g.internal.handler.WebserviceHandler] - Opening times are used
2020-10-28 02:35:04.422 [DEBUG] [g.internal.handler.WebserviceHandler] - Found a setting for WholeDay.
2020-10-28 02:35:04.424 [DEBUG] [g.internal.handler.WebserviceHandler] - Now is within opening times for today.
2020-10-28 02:35:04.426 [DEBUG] [g.internal.handler.WebserviceHandler] - o.length: 2
2020-10-28 02:35:04.428 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking opening time i: 0
2020-10-28 02:35:04.430 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking day: t盲glich
2020-10-28 02:35:04.432 [DEBUG] [g.internal.handler.WebserviceHandler] - Todays weekday: WEDNESDAY
2020-10-28 02:35:04.433 [DEBUG] [g.internal.handler.WebserviceHandler] - Found a setting for daily opening times.
2020-10-28 02:35:04.435 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking opening time i: 1
2020-10-28 02:35:04.437 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking day: t盲glich
2020-10-28 02:35:04.439 [DEBUG] [g.internal.handler.WebserviceHandler] - Todays weekday: WEDNESDAY
2020-10-28 02:35:04.441 [DEBUG] [g.internal.handler.WebserviceHandler] - Found a setting for daily opening times.
2020-10-28 02:35:04.443 [DEBUG] [g.internal.handler.WebserviceHandler] - Now is within opening times for today.
2020-10-28 02:35:04.445 [DEBUG] [g.internal.handler.WebserviceHandler] - Found a setting for WholeDay.
2020-10-28 02:35:04.447 [DEBUG] [g.internal.handler.WebserviceHandler] - Now is within opening times for today.
2020-10-28 02:35:04.449 [DEBUG] [g.internal.handler.WebserviceHandler] - o.length: 2
2020-10-28 02:35:04.450 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking opening time i: 0
2020-10-28 02:35:04.452 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking day: t盲glich ausser Sonn- und Feiertagen
2020-10-28 02:35:04.460 [DEBUG] [g.internal.handler.WebserviceHandler] - Todays weekday: WEDNESDAY
2020-10-28 02:35:04.461 [DEBUG] [g.internal.handler.WebserviceHandler] - Found a setting for daily opening times.
2020-10-28 02:35:04.467 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking opening time i: 1
2020-10-28 02:35:04.469 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking day: Sonntag, Feiertag
2020-10-28 02:35:04.472 [DEBUG] [g.internal.handler.WebserviceHandler] - Todays weekday: WEDNESDAY
2020-10-28 02:35:04.475 [DEBUG] [g.internal.handler.WebserviceHandler] - o.length: 3
2020-10-28 02:35:04.477 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking opening time i: 0
2020-10-28 02:35:04.480 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking day: Mo-Fr
2020-10-28 02:35:04.482 [DEBUG] [g.internal.handler.WebserviceHandler] - Todays weekday: WEDNESDAY
2020-10-28 02:35:04.485 [DEBUG] [g.internal.handler.WebserviceHandler] - Found a setting which is valid for today (Wednesday).
2020-10-28 02:35:04.488 [DEBUG] [g.internal.handler.WebserviceHandler] - o.length: 2
2020-10-28 02:35:04.491 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking opening time i: 0
2020-10-28 02:35:04.494 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking day: Mo-Fr
2020-10-28 02:35:04.496 [DEBUG] [g.internal.handler.WebserviceHandler] - Todays weekday: WEDNESDAY
2020-10-28 02:35:04.499 [DEBUG] [g.internal.handler.WebserviceHandler] - Found a setting which is valid for today (Wednesday).
2020-10-28 02:35:04.502 [DEBUG] [g.internal.handler.WebserviceHandler] - Found a setting for WholeDay.
2020-10-28 02:35:04.505 [DEBUG] [g.internal.handler.WebserviceHandler] - Now is within opening times for today.
2020-10-28 02:35:04.507 [DEBUG] [g.internal.handler.WebserviceHandler] - Found a setting for WholeDay.
2020-10-28 02:35:04.510 [DEBUG] [g.internal.handler.WebserviceHandler] - Now is within opening times for today.
2020-10-28 02:35:04.512 [DEBUG] [g.internal.handler.WebserviceHandler] - o.length: 1
2020-10-28 02:35:04.515 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking opening time i: 0
2020-10-28 02:35:04.517 [DEBUG] [g.internal.handler.WebserviceHandler] - Checking day: t盲glich
2020-10-28 02:35:04.519 [DEBUG] [g.internal.handler.WebserviceHandler] - Todays weekday: WEDNESDAY
2020-10-28 02:35:04.522 [DEBUG] [g.internal.handler.WebserviceHandler] - Found a setting for daily opening times.
2020-10-28 02:35:04.525 [DEBUG] [g.internal.handler.WebserviceHandler] - Now is within opening times for today.
2020-10-28 02:35:04.526 [DEBUG] [g.internal.handler.WebserviceHandler] - Found a setting for WholeDay.
2020-10-28 02:35:04.529 [DEBUG] [g.internal.handler.WebserviceHandler] - Now is within opening times for today.
2020-10-28 02:35:04.826 [DEBUG] [ig.internal.data.TankerkoenigService] - json-String: {"ok":true,"license":"CC BY 4.0 -  https:\/\/creativecommons.tankerkoenig.de","data":"MTS-K","prices":{"ce8685d4-7249-477e-8bb3-04eb69e6bb44":{"status":"open","e5":1.289,"e10":1.239,"diesel":1.129},"cc66653e-483c-46c0-a666-793478d9439f":{"status":"open","e5":false,"e10":false,"diesel":0.995},"aaedd081-4bcc-441f-8023-c42263f82e82":{"status":"open","e5":1.269,"e10":1.219,"diesel":1.099},"0ab14657-b01e-4827-a5d4-311ad444b887":{"status":"open","e5":1.269,"e10":1.219,"diesel":1.029},"005056ba-7cb6-1ed5-a7ce-94793a301eaf":{"status":"closed"},"7c6a13f6-12a8-4619-a7ab-2c3c9dbab28b":{"status":"open","e5":1.289,"e10":1.239,"diesel":1.129},"39ef08b9-3105-4122-beec-1c7809f3f404":{"status":"open","e5":1.269,"e10":1.219,"diesel":1.089}}}
2020-10-28 02:35:04.838 [INFO ] [l.script.Tankerkoenig Binding Status] - Tankerkoenig Binding is online
2020-10-28 02:35:04.845 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to ONLINE for device: tankerkoenig:station:Tankpreise:Station5
2020-10-28 02:35:04.848 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to ONLINE for device: tankerkoenig:station:Tankpreise:Station4
2020-10-28 02:35:04.848 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to ONLINE for device: tankerkoenig:station:Tankpreise:Station3
2020-10-28 02:35:04.850 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to ONLINE for device: tankerkoenig:station:Tankpreise:Station2
2020-10-28 02:35:04.852 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to ONLINE for device: tankerkoenig:station:Tankpreise:Station8
2020-10-28 02:35:04.855 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to ONLINE for device: tankerkoenig:station:Tankpreise:Station9
2020-10-28 02:35:04.855 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to ONLINE for device: tankerkoenig:station:Tankpreise:Station7
2020-10-28 02:35:04.857 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to ONLINE for device: tankerkoenig:station:Tankpreise:Station10
2020-10-28 02:35:04.857 [DEBUG] [g.internal.handler.WebserviceHandler] - UpdateStationData: tankstellenList.size 7
2020-10-28 02:35:04.857 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to ONLINE for device: tankerkoenig:station:Tankpreise:Station6
2020-10-28 02:35:04.857 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to ONLINE for device: tankerkoenig:station:Tankpreise:Station1
2020-10-28 02:35:04.860 [DEBUG] [g.internal.handler.WebserviceHandler] - UpdateStationThings: getThing().getThings().size 10
2020-10-28 02:35:04.861 [DEBUG] [enig.internal.handler.StationHandler] - Update Tankerkoenig data 'tankerkoenig:station:Tankpreise:Station5'
2020-10-28 02:35:04.868 [DEBUG] [enig.internal.handler.StationHandler] - Update Tankerkoenig data 'tankerkoenig:station:Tankpreise:Station4'
2020-10-28 02:35:04.874 [DEBUG] [enig.internal.handler.StationHandler] - Update Tankerkoenig data 'tankerkoenig:station:Tankpreise:Station3'
2020-10-28 02:35:04.880 [DEBUG] [g.internal.handler.WebserviceHandler] - Station with id e1a15081-2586-9107-e040-0b0a3dfe563c  is not updated!
2020-10-28 02:35:04.882 [DEBUG] [g.internal.handler.WebserviceHandler] - Station with id a2f96cc4-b858-463d-bd93-b3056e81fcaa  is not updated!
2020-10-28 02:35:04.884 [DEBUG] [g.internal.handler.WebserviceHandler] - Station with id 45936520-e830-4578-a3cb-188053b90765  is not updated!
2020-10-28 02:35:04.886 [DEBUG] [enig.internal.handler.StationHandler] - Update Tankerkoenig data 'tankerkoenig:station:Tankpreise:Station7'
2020-10-28 02:35:04.893 [DEBUG] [enig.internal.handler.StationHandler] - Update Tankerkoenig data 'tankerkoenig:station:Tankpreise:Station10'
2020-10-28 02:35:04.899 [DEBUG] [enig.internal.handler.StationHandler] - Update Tankerkoenig data 'tankerkoenig:station:Tankpreise:Station1'
2020-10-28 02:35:04.902 [DEBUG] [g.internal.handler.WebserviceHandler] - Caught exception in ScheduledExecutorService of BridgeHandler. RuntimeException: 
java.lang.NullPointerException: null
        at java.util.regex.Matcher.getTextLength(Matcher.java:1283) ~[?:1.8.0_265]
        at java.util.regex.Matcher.reset(Matcher.java:309) ~[?:1.8.0_265]
        at java.util.regex.Matcher.<init>(Matcher.java:229) ~[?:1.8.0_265]
        at java.util.regex.Pattern.matcher(Pattern.java:1093) ~[?:1.8.0_265]
        at org.openhab.binding.tankerkoenig.internal.handler.StationHandler.updateData(StationHandler.java:131) ~[?:?]
        at org.openhab.binding.tankerkoenig.internal.handler.WebserviceHandler.updateStationThings(WebserviceHandler.java:183) ~[?:?]
        at org.openhab.binding.tankerkoenig.internal.handler.WebserviceHandler.lambda$0(WebserviceHandler.java:100) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_265]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_265]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_265]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_265]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_265]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_265]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_265]
2020-10-28 02:35:04.913 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to OFFLINE for device: tankerkoenig:station:Tankpreise:Station5
2020-10-28 02:35:04.915 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to OFFLINE for device: tankerkoenig:station:Tankpreise:Station8
2020-10-28 02:35:04.916 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to OFFLINE for device: tankerkoenig:station:Tankpreise:Station2
2020-10-28 02:35:04.915 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to OFFLINE for device: tankerkoenig:station:Tankpreise:Station4
2020-10-28 02:35:04.918 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to OFFLINE for device: tankerkoenig:station:Tankpreise:Station7
2020-10-28 02:35:04.922 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to OFFLINE for device: tankerkoenig:station:Tankpreise:Station6
2020-10-28 02:35:04.919 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to OFFLINE for device: tankerkoenig:station:Tankpreise:Station3
2020-10-28 02:35:04.918 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to OFFLINE for device: tankerkoenig:station:Tankpreise:Station10
2020-10-28 02:35:04.918 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to OFFLINE for device: tankerkoenig:station:Tankpreise:Station9
2020-10-28 02:35:04.918 [DEBUG] [enig.internal.handler.StationHandler] - Bridge Status updated to OFFLINE for device: tankerkoenig:station:Tankpreise:Station1
2020-10-28 02:35:04.938 [INFO ] [l.script.Tankerkoenig Binding Status] - Tankerkoenig Binding offline

Station names are changed, everything else is as it came out of the log. The "WebserviceHandler" is not handling a null value properly.

andreasscherbaum picture andreasscherbaum on 28 Oct 2020

Thanks for the feedback.
Scanning the log I think this ERROR is caused by the station that reported closed. Since you are using the mode OpeningTimes that station shouldn't have been polled ( first problem). However, if that mode wouldn't have been used the same error would have occurred ( second problem).
Will do a code change proposal after some tests (I'm not @home, so that will take a couple of days).

JueBag picture JueBag on 28 Oct 2020
👍1

@andreasscherbaum
Reading the logs it is not clear to me from which station the error was produced. Could you send me a list with all used StationIDs in order to check their Detail messages.

JueBag picture JueBag on 28 Oct 2020

@JueBag You got a forum PM.

andreasscherbaum picture andreasscherbaum on 28 Oct 2020

i have in mind that the shortest poll intervall is 15 minutes. maybe that causes the problem.

TBail picture TBail on 28 Oct 2020

No, 10 minutes is OK,
as stated above a station that is actually closed got pulled.
A, this shouldn't have happened while using the OpeningTimes mode (I suspect a non-standard message from the station)
B The check for prices is done for a station that reports only closed and no prices, hence the error while checking a price. IMHO that is a real mistake! Obviously I always used the mode OpeningTimes!
The good news is, as planned for such irregular responses, the polling continues.

JueBag picture JueBag on 28 Oct 2020

Looking into it on my testing system revealed the issue is coming from different kind of messages when NOT reporting a price. The station causing it does report null in a detail-request and false in a price-request. The later is covered correctly.
So my understanding of the observed problem is:
The error occurs when intially creating this station and every 24 houres after that (iow when a detail-request is launched). IMHO all other errors observed when doing a standard price-request (every x minutes) are follow up errors.
Will let my test test system run for a while, if no more errors are observed I'll create a PR.

@andreasscherbaum:
The PR will be against against main, iow only for the 3.0 versions, any problems with that?

JueBag picture JueBag on 1 Nov 2020

@JueBag That will be fine, at some point I will upgrade to 3.0.
Thanks for fixing this!

andreasscherbaum picture andreasscherbaum on 1 Nov 2020

Really no chance to apply the fix on the 2.5.11?

Trashwarez picture Trashwarez on 4 Nov 2020

Really no chance to apply the fix on the 2.5.11?

The problem only appears at night when the station is closed, and normally it's not even visible without the kind of monitoring I have in place. I'm curious: do you have a case where this affects regular operations of the binding?

andreasscherbaum picture andreasscherbaum on 4 Nov 2020

Sure. I monitor 5 Stations. One of them closes at 6pm. From this time on I do not receive prices from the others anymore. And btw. the operation mode "modeOpeningTime=true" does not make sense anymore because you have to provide the holiday switch item (preferably at midnight from ephemeris). But this item does not switch as long as the binding is offline. :-(

Trashwarez picture Trashwarez on 4 Nov 2020

Ok, that's kind of early, I agree.

andreasscherbaum picture andreasscherbaum on 4 Nov 2020

I've cherry-picked it onto the 2.5.x branch (https://github.com/openhab/openhab-addons/commit/be0b3cf5b92a5347d00bcd9c34bf45a16268d6a7).

kaikreuzer picture kaikreuzer on 4 Nov 2020
👍3 🚀1 ❤1

Thanks for that quick reaction.

@Trashware
Why didn't you report such faulty behaviour earlier?

JueBag picture JueBag on 4 Nov 2020

@JueBag
I installed it few days ago and never was in touch with it before.

Trashwarez picture Trashwarez on 4 Nov 2020
👍1
Was this page helpful?
0 / 5 - 0 ratings

Related issues

J-N-K picture J-N-K  路  6Comments
trailblazer2006 picture trailblazer2006  路  6Comments
IOOOTAlan picture IOOOTAlan  路  3Comments
Nikos78 picture Nikos78  路  5Comments
UrsusS picture UrsusS  路  5Comments