openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.86k stars 3.57k forks source link

[groheondus] No automatic refresh #10612

Closed PottiMc closed 1 year ago

PottiMc commented 3 years ago

Expected Behavior

The Grohe Ondus Binding should refresh every 15 minutes (900s) as polling interval.

Current Behavior

The binding is only refreshing when disabled and enabled again. Values are different from Grohe Sense Android App.

I tried uninsalling and reinstalling the binding, did not help. Refresh token is set and account credentials are given.

All I can see in the log files is the following. The java error messages only show up at the first starting, after that, everything looks fine, bridge is online and SenseGuard too.

==> /var/log/openhab/openhab.log <==

2021-04-29 08:20:01.706 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘groheondus:account:8a040c38be’ changed from UNINITIALIZED (DISABLED) to INITIALIZING

2021-04-29 08:20:01.727 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘groheondus:account:8a040c38be’ changed from INITIALIZING to UNKNOWN

==> /var/log/openhab/openhab.log <==

2021-04-29 08:20:03.072 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:

java.lang.NullPointerException: null

at org.openhab.binding.groheondus.internal.handler.GroheOndusBaseHandler.getRoom(GroheOndusBaseHandler.java:135) ~[?:?]

at org.openhab.binding.groheondus.internal.handler.GroheOndusBaseHandler.getAppliance(GroheOndusBaseHandler.java:144) ~[?:?]

at org.openhab.binding.groheondus.internal.handler.GroheOndusBaseHandler.updateChannels(GroheOndusBaseHandler.java:102) ~[?:?]

at org.openhab.binding.groheondus.internal.handler.GroheOndusAccountHandler.lambda$2(GroheOndusAccountHandler.java:154) ~[?:?]

at java.util.ArrayList.forEach(ArrayList.java:1541) ~[?:?]

at java.util.Collections$UnmodifiableCollection.forEach(Collections.java:1085) ~[?:?]

at org.openhab.binding.groheondus.internal.handler.GroheOndusAccountHandler.lambda$1(GroheOndusAccountHandler.java:151) ~[?:?]

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]

at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]

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:834) [?:?] ==> /var/log/openhab/events.log <==

2021-04-29 08:20:03.072 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘groheondus:account:8a040c38be’ changed from UNKNOWN to ONLINE

==> /var/log/openhab/openhab.log <==

2021-04-29 08:30:12.307 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler GroheOndusSenseGuardHandler of thing groheondus:senseguard:8a040c38be:e95c8f14-e75c-4aaa-bec5-a0767544612b tried accessing its bridge although the handler was already disposed.

2021-04-29 08:30:12.309 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler GroheOndusSenseGuardHandler tried updating the thing status although the handler was already disposed.

Steps to Reproduce (for Bugs)

  1. Fresh install of binding
  2. Enter account data
  3. Add SenseGuard device

Your Environment

OpenHab 3.0.2 (Issue was in former 3 versions too, didn't test on OH2) RaspberryPi4B

ssvenn commented 3 years ago

I am having the same problem with a freshly installed Grohe Sense Guard on openHAB 3.1.0.M5, the devices show up as online in the list of things but are not refreshing. The binding suddenly managed to poll the API once in the middle of the night but stopped updating again afterwards.

Screenshot 2021-06-11 at 08 12 30
PottiMc commented 2 years ago

Is anybody able to offer support for this binding?

lolodomo commented 2 years ago

@FlorianSW is the author/maintainer of this bindings.

FlorianSW commented 2 years ago

I'll check that. However, I'm out a bit since quite some time, let's see how long it takes to get up to speed again :)

FlorianSW commented 2 years ago

I am having the same problem with a freshly installed Grohe Sense Guard on openHAB 3.1.0.M5, the devices show up as online in the list of things but are not refreshing. The binding suddenly managed to poll the API once in the middle of the night but stopped updating again afterwards.

Screenshot 2021-06-11 at 08 12 30

Do you have the same error message like the creator of this issue? I can't reproduce the issue for now tbh :/ However, I also have trouble using the latest snapshot with OH. @lolodomo was there any change on how to include maven dependencies in the build artifact? I just made a mvn install for the binding, added the resulting jar to the addons/ directory of my local OH installation and it errored the installation with that apache commons-text could not be found:

22:35:03.774 [WARN ] [org.apache.felix.fileinstall         ] - Error while starting bundle: file:/D:/Entwicklung/openhab/core/addons/org.openhab.binding.groheondus-3.2.0-SNAPSHOT.jar
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.groheondus [242]
  Unresolved requirement: Import-Package: org.apache.commons.text; version="[1.6.0,2.0.0)"

The resulting jar also just contains the grohe ondus api, but not the comons-text one. I've the feeling, I miss something.

PottiMc commented 2 years ago

Thank you for your help! If I can support in any way just let me know.

For your information: bug is still present in 3.1.0.

seime commented 2 years ago

Can confirm this problem on my side on 3.1.0 as well

PottiMc commented 2 years ago

@FlorianSW did you find any problems?

PottiMc commented 2 years ago

Unfortunately still no change on Version 3.2.0

I can see requests going out to Grohe, so it's definitely some kind of OH related problem. Red is my OH, Yellow my Phone

image

seime commented 2 years ago

I started digging into the internals of this binding and have found several issues, will provide a PR when confirmed working well over time.

PottiMc commented 2 years ago

Thank you very much! If you need help with testing or debugging just let me know. I have a Sense Guard in my home.

seime commented 2 years ago

@PottiMc Here is a build you can try: https://github.com/seime/openhab2-addons/releases/tag/grohe_refresh_etc

PS: You should probably restart openhab after installing it as the old version did have some lifecycle issues that might cause problems

PottiMc commented 2 years ago

@seime Sorry for the delay. Would you mind creating a new build as I can not run this one because of the dependencies.

grafik

seime commented 2 years ago

Yes, did not notice it as I had the previous version deployed alongside

Try this one: https://github.com/seime/openhab2-addons/releases/tag/groheondus_refresh_2

PottiMc commented 2 years ago

Just installed the binding and it worked flawless. No errors, no (non-debug) logs at all. Did pull the data for 45 minutes now. Valve switching is working properly, too.

Like mentioned in the pull request, I had to make a state description for the "waterconsumption since midnight" channel to get it to liters.

Will keep you updated about data pulling behaviour in the next days. Thank you for your work.

PottiMc commented 2 years ago

Short notice: The binding worked well for some days but now it is starting to crash on 1 am. The account still stays online, but my SenseGuard has a Comm error "Could net retrieve data from API". After disabling and enabling the SenseGuard thing it works fine for one more day.

And one thing on the side "Water consumption since midnight" is resetting at 1 am since I installed the binding.

seime commented 2 years ago

New release with some more fixes https://github.com/seime/openhab2-addons/releases/tag/groheondus_refresh_3

PottiMc commented 2 years ago

Thank you very much again.

Installation worked flawless again and right away pulled the data from the API. I will check if my water consumption since midnight is working as intended now.

I actually think I found my mistake why the data could not be pulled from the API anymore in your last build after a several amount of time. My polling interval was set to 15 instead of 900. I tried it with 900 now for two days and it worked fine again. Maybe it would be best to define a minimum somehow or change the description underneath (the value needs to be filled in in seconds, but it is talked about minutes in the description).

PottiMc commented 2 years ago

@seime

Unfortunately got the same error in the night for my SenseGuard appliance.

grafik

Here is the log:

openhab.log

2022-01-26 23:49:39.912 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.NullPointerException: null
    at org.openhab.binding.groheondus.internal.handler.GroheOndusSenseGuardHandler.getLastMeasurement(GroheOndusSenseGuardHandler.java:146) ~[?:?]
    at org.openhab.binding.groheondus.internal.handler.GroheOndusSenseGuardHandler.updateChannel(GroheOndusSenseGuardHandler.java:91) ~[?:?]
    at org.openhab.binding.groheondus.internal.handler.GroheOndusSenseGuardHandler.updateChannel(GroheOndusSenseGuardHandler.java:1) ~[?:?]
    at org.openhab.binding.groheondus.internal.handler.GroheOndusBaseHandler.lambda$1(GroheOndusBaseHandler.java:117) ~[?:?]
    at java.util.ArrayList.forEach(ArrayList.java:1541) ~[?:?]
    at java.util.Collections$UnmodifiableCollection.forEach(Collections.java:1085) ~[?:?]
    at org.openhab.binding.groheondus.internal.handler.GroheOndusBaseHandler.updateChannels(GroheOndusBaseHandler.java:117) ~[?:?]
    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) [?:?]

events.log:

2022-01-26 23:49:39.910 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'groheondus:senseguard:73bca11de6:e2ca6eb2f1' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Failed to find appliance data
2022-01-26 23:49:39.914 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'groheondus:senseguard:73bca11de6:e2ca6eb2f1' changed from OFFLINE (COMMUNICATION_ERROR): Failed to find appliance data to OFFLINE (COMMUNICATION_ERROR): Could not load data from API.
seime commented 2 years ago

Sense guard and not Sense (sensor). Using the version I posted last night?

Could you check if the Grohe app has values for the same device? I have noticed that a few of my sensors sometimes do not connect and report data. The binding queries for values in a timespan, and I think when there is no data the API reports this.

Unfortunately the API SDK wrapper in front hides a lot of the details here, so it is difficult to see what it is unless I put a breakpoint in the code and sit and wait for something to go wrong. Which I do not do in the middle of the night ;)

I might have to ditch the lib.

Regards

On Thu, Jan 27, 2022 at 8:05 AM PottiMc @.***> wrote:

Unfortunately got the same error in the night for my SenseGuard appliance.

[image: grafik] https://user-images.githubusercontent.com/39881308/151308410-aca46e2f-e0b9-4b9a-885a-89dfdfbd2d24.png

— Reply to this email directly, view it on GitHub https://github.com/openhab/openhab-addons/issues/10612#issuecomment-1022907826, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAL6DZANVLOBH5SF2ZHLVELUYDVE7ANCNFSM43ZGOJ3A . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you were mentioned.Message ID: @.***>

-- MVH Arne Seime ph +47 99574896 - @.***

PottiMc commented 2 years ago

Sense guard and not Sense (sensor). Using the version I posted last night? Yes to both.

Could you check if the Grohe app has values for the same device? I have noticed that a few of my sensors sometimes do not connect and report data. The binding queries for values in a timespan, and I think when there is no data the API reports this. Yes, values are visible in the app. I also checked my internet connection, no discontinuation in my router visible. There was a Wifi-band change with a disconnect of the SenseGuard, but at 1:30 am and only for 3 seconds. Screenshot_20220127-095241

Maybe, and just maybe, it is because I changed the Poll interval sometime in the morning and I ran into some API limit in the evening, do you know if something like this exists?

As soon as I disable the SenseGuard thing and enable it again data is polled fine by the way.

PottiMc commented 2 years ago

Update: No disconnects or problems this night. Will let you know if I get some troubles again.

openhab-bot commented 2 years ago

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/grohe-ondus-no-automatic-refresh/121567/4

PottiMc commented 2 years ago

Today I received a firmware update notification. Does it influence the binding in any way? Did somebody already try?

Screenshot_20220203-140209.jpg

Besides that I just had only one disconnection in the last days but it managed to pull the data later on by itself.

PottiMc commented 2 years ago

I tried the update, no unexpected behavior.

PottiMc commented 2 years ago

Hi @seime . As I think you did a really great job! This issue is resolved in the snapshot version you published as I think. Should I leave it open until the pull request is finished or can I close it?

seime commented 2 years ago

Hi @PottiMc , I noticed there is still a problem with token refresh error handling that must be fixed. So unfortunately not yet fixed :(

PottiMc commented 2 years ago

Okay. Really good to know you're still digging for errors! Let me know if you need some testing again.

seime commented 2 years ago

Hi @PottiMc, I've been away for a few weeks, so a bit of silence from me.

I did not get prompted for any firmware updates, and I see that I've still got the one your're updating from.

I've attaced a new binary that you could test. Let me know if the account goes offline.

https://github.com/seime/openhab2-addons/releases/tag/groheondus_refresh_4

PottiMc commented 2 years ago

Installation worked without any problems. Pulling data now. I will let you know if there happens anything unexpected.

seime commented 2 years ago

I see there is still a problem with the token refresh that must be fixed :(

On Mon, Feb 21, 2022 at 7:48 AM PottiMc @.***> wrote:

Installation worked without any problems. Pulling data now. I will let you know if there happens anything unexpected.

— Reply to this email directly, view it on GitHub https://github.com/openhab/openhab-addons/issues/10612#issuecomment-1046525901, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAL6DZHREU6WOOMBJXTQMWTU4HN2HANCNFSM43ZGOJ3A . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you were mentioned.Message ID: @.***>

-- MVH Arne Seime ph +47 99574896 - @.***

PottiMc commented 2 years ago

Yes, I had a pulling error yesterday at 23:12 o'clock and the binding didn't retry to connect or pull until disabled and enabled again this morning.

seime commented 2 years ago

Added a new jar; it has survived on my end the last 21 hours at least ;)

https://github.com/seime/openhab2-addons/releases/tag/groheondus_refresh_5

PottiMc commented 2 years ago

Unfortunately now I have the second night in a row where the SenseGuard thing gets an error and does not reconnect again. The account stays online.

Version 3 was more reliable in this.

seime commented 2 years ago

Could you provide the debug logs so I can see what's going wrong? Make sure you mask sensitive details.

PottiMc commented 2 years ago

Unfurtonately I can not provide a debug log for this night since I don't have debug mode enabled by default and I didn't have any disconnects since then.

seime commented 2 years ago

I probably will stop trying to fix the binding as it is now, and instead focus on a complete rewrite later on.

PottiMc commented 2 years ago

I really appreciate your help fixing the existing binding! It works way better than before and even if there are errors sometimes the binding is useful now, it was not before. If you need help testing again please let me know.

PottiMc commented 2 years ago

Hi @seime , I need to revive this topic. Since the time change here in Germany I have problems with the binding. Crashing every day or second. This time it's not the Sense Guard like all the time, the account is crashing and with "Error: No Comm". Do you experience the same?

seime commented 2 years ago

Hi @potticmc; I did not see a problem on my side other than the usual token problems (random problems on refreshing token, hidden responses). If you think this is something different I do need the logs in order to debug.

Regards

On Thu, Mar 31, 2022 at 9:15 PM PottiMc @.***> wrote:

Hi @seime https://github.com/seime , I need to revive this topic. Since the time change here in Germany I have problems with the binding. Crashing every day or second. This time it's not the Sense Guard like all the time, the account is crashing and with "Error: No Comm". Do you experience the same?

— Reply to this email directly, view it on GitHub https://github.com/openhab/openhab-addons/issues/10612#issuecomment-1085004312, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAL6DZESN65RK7GQVEHWPU3VCX2WVANCNFSM43ZGOJ3A . You are receiving this because you were mentioned.Message ID: @.***>

-- MVH Arne Seime ph +47 99574896 - @.***

PottiMc commented 2 years ago

@seime

There you go, here are some logs. If you can find any sensible data please let me know. The "returned null" part in the end is staying in place until I disable and start the Grohe account thing again.

I can see a problem with time zone since the token refresh is always expiring 1 hour before the actual system time. But I don't know if that is the problem.

2022-04-05 03:06:50.977 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Refreshing token 2022-04-05 03:06:51.234 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Refreshed token, token expires at 2022-04-05T02:06:51.233799Z 2022-04-05 03:06:51.236 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Trying to login using refresh token 2022-04-05 03:06:51.359 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Scheduled token refresh at 2022-04-05T02:01:51.359318Z 2022-04-05 03:13:09.276 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 03:13:09.557 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T01:13:09.557513Z to 2022-04-06T01:13:09.557519Z 2022-04-05 03:28:10.028 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 03:28:10.297 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T01:28:10.296806Z to 2022-04-06T01:28:10.296811Z 2022-04-05 03:43:11.036 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 03:43:11.325 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T01:43:11.325194Z to 2022-04-06T01:43:11.325198Z 2022-04-05 03:58:11.835 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 03:58:12.133 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T01:58:12.133294Z to 2022-04-06T01:58:12.133300Z 2022-04-05 04:01:50.359 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Refreshing token 2022-04-05 04:01:50.599 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Could not refresh token for GROHE ONDUS account, removing refresh token javax.security.auth.login.LoginException: 401 - Unauthorized at io.github.floriansw.ondus.api.actions.RefreshTokenAction.refresh(RefreshTokenAction.java:24) ~[?:?] at io.github.floriansw.ondus.api.OndusService.refreshAuthorization(OndusService.java:105) ~[?:?] at org.openhab.binding.groheondus.internal.handler.GroheOndusAccountHandler.lambda$0(GroheOndusAccountHandler.java:118) ~[?:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?] at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?] 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) [?:?] 2022-04-05 04:01:50.607 [DEBUG] [nal.handler.GroheOndusAccountHandler] - No refresh token found, trying to log in using username and password 2022-04-05 04:01:51.572 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Scheduled token refresh at 2022-04-05T02:56:51.570821Z 2022-04-05 04:13:12.897 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 04:13:13.245 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T02:13:13.245114Z to 2022-04-06T02:13:13.245122Z 2022-04-05 04:22:03.905 [WARN ] [ternal.handler.HomematicThingHandler] - Channel not found for datapoint '000A5BE992D565:1#ERROR_DEGRADED_CHAMBER' 2022-04-05 04:28:13.982 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 04:28:14.275 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T02:28:14.275361Z to 2022-04-06T02:28:14.275365Z 2022-04-05 04:43:15.166 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 04:43:15.475 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T02:43:15.475487Z to 2022-04-06T02:43:15.475493Z 2022-04-05 04:56:50.572 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Refreshing token 2022-04-05 04:56:50.841 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Refreshed token, token expires at 2022-04-05T03:56:50.840341Z 2022-04-05 04:56:50.842 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Trying to login using refresh token 2022-04-05 04:56:50.996 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Scheduled token refresh at 2022-04-05T03:51:50.995483Z 2022-04-05 04:58:16.160 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 04:58:16.403 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T02:58:16.402772Z to 2022-04-06T02:58:16.402778Z 2022-04-05 05:13:17.058 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 05:13:17.485 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T03:13:17.485143Z to 2022-04-06T03:13:17.485149Z 2022-04-05 05:28:18.158 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 05:28:18.482 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T03:28:18.482528Z to 2022-04-06T03:28:18.482534Z 2022-04-05 05:43:19.033 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 05:43:19.333 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T03:43:19.333324Z to 2022-04-06T03:43:19.333329Z 2022-04-05 05:51:49.996 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Refreshing token 2022-04-05 05:51:50.247 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Refreshed token, token expires at 2022-04-05T04:51:50.246685Z 2022-04-05 05:51:50.248 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Trying to login using refresh token 2022-04-05 05:51:50.374 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Scheduled token refresh at 2022-04-05T04:46:50.373436Z 2022-04-05 05:58:20.156 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 05:58:20.448 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T03:58:20.447877Z to 2022-04-06T03:58:20.447882Z

2022-04-05 09:31:47.514 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Refreshing token 2022-04-05 09:31:47.761 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Refreshed token, token expires at 2022-04-05T08:31:47.760967Z 2022-04-05 09:31:47.763 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Trying to login using refresh token 2022-04-05 09:31:47.854 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Refresh token invalid, try again with username and password 2022-04-05 09:31:48.534 [DEBUG] [nal.handler.GroheOndusAccountHandler] - Grohe api login failed javax.security.auth.login.LoginException: 401 - Unauthorized at io.github.floriansw.ondus.api.actions.RefreshTokenAction.refresh(RefreshTokenAction.java:24) ~[?:?] at io.github.floriansw.ondus.api.OndusService.login(OndusService.java:69) ~[?:?] at io.github.floriansw.ondus.api.OndusService.login(OndusService.java:39) ~[?:?] at io.github.floriansw.ondus.api.OndusService.loginWebform(OndusService.java:61) ~[?:?] at org.openhab.binding.groheondus.internal.handler.GroheOndusAccountHandler.login(GroheOndusAccountHandler.java:97) ~[?:?] at org.openhab.binding.groheondus.internal.handler.GroheOndusAccountHandler.lambda$0(GroheOndusAccountHandler.java:124) ~[?:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?] at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?] 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) [?:?] 2022-04-05 09:43:34.122 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 09:43:34.446 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T07:43:34.446527Z to 2022-04-06T07:43:34.446532Z 2022-04-05 09:58:35.464 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 09:58:35.847 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T07:58:35.847297Z to 2022-04-06T07:58:35.847301Z 2022-04-05 10:13:36.353 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 10:13:36.671 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T08:13:36.671551Z to 2022-04-06T08:13:36.671556Z 2022-04-05 10:28:37.380 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 10:28:37.681 [DEBUG] [.handler.GroheOndusSenseGuardHandler] - Fetching data for groheondus:senseguard:73bca11de6:e2ca6eb2f1 from 2022-04-04T08:28:37.680770Z to 2022-04-06T08:28:37.680774Z 2022-04-05 10:43:38.460 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 10:43:38.676 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - getAppliance for thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 returned null 2022-04-05 10:43:38.685 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels failed since appliance is null, thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 10:58:38.686 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 10:58:38.870 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - getAppliance for thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 returned null 2022-04-05 10:58:38.876 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels failed since appliance is null, thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 11:13:38.878 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 11:13:39.076 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - getAppliance for thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 returned null 2022-04-05 11:13:39.082 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels failed since appliance is null, thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 11:28:39.085 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 11:28:39.279 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - getAppliance for thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 returned null 2022-04-05 11:28:39.287 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels failed since appliance is null, thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 11:43:39.289 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 11:43:39.488 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - getAppliance for thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 returned null 2022-04-05 11:43:39.499 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels failed since appliance is null, thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 11:58:39.501 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 11:58:39.695 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - getAppliance for thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 returned null 2022-04-05 11:58:39.701 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels failed since appliance is null, thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 12:13:39.703 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - Updating channels for appliance groheondus:senseguard:73bca11de6:e2ca6eb2f1 2022-04-05 12:13:39.874 [DEBUG] [ternal.handler.GroheOndusBaseHandler] - getAppliance for thing groheondus:senseguard:73bca11de6:e2ca6eb2f1 returned null

seime commented 2 years ago

Thanks, yes there is a problem with the token refresh handling.

I think I'll stick to my original plan and rewrite the whole binding at some point in time

PottiMc commented 2 years ago

That's to bad. It was working pretty well since your last release in February. Didn't even have a single crash since then.

seime commented 2 years ago

I have a rule that detects the bridge or valve goes offline that alerts me. I am pretty sure you could do a REST call from the rule to restart the bridge when this happens.

It is a temporary workaround though.

Care to test?

PottiMc commented 2 years ago

Of course. Thank you.

I tried making rules with HTTP and REST calls before you optimized the binding. But my attempts didn't work much better than the original binding 😃

PottiMc commented 2 years ago

@seime Would you mind sending me your script please?

seime commented 2 years ago

@PottiMc I think this could work: It detects that the valve goes offline and restarts the account thing by disabling and then after a minute enabling it.

Make sure you add your own thing identifiers both in the rule trigger and in the url

rule "Restart Grohe ondus when valve offline"
when 
   Thing "groheondus:senseguard:account:hoveddel_stoppekran" changed from ONLINE to OFFLINE
then
sendHttpPutRequest("http://OPENHAB_REST_USERNAME:OPENHAB_REST_PWD@OPENHAB_HOST:OPENHAB_PORT/rest/things/groheondus%3Aaccount%3Aaccount/enable","text/plain",'false',5000)
   createTimer(now.plusMinutes(1),  [|
sendHttpPutRequest("http://OPENHAB_REST_USERNAME:OPENHAB_REST_PWD@OPENHAB_HOST:OPENHAB_PORT/rest/things/groheondus%3Aaccount%3Aaccount/enable","text/plain",'true',5000)
   ] )
end
PottiMc commented 2 years ago

Thanks. I gave it a try. Did a good job so far and restarted 5 or 6 times already. I get a notfication when it happens. Can't see any pattern at all. Sometimes it's 3 times in an hour, last week it was online for over 6 days. That's a good workaround for now.

seime commented 2 years ago

@PottiMc even after a re-enabling of the thing, you might still get an error. So I updated my rule to simply check every 5 minutes;

rule "Restart Grohe ondus when valve offline"
when 
   Time cron "0 0/5 * 1/1 * ? *"
then
    var thingStatusInfo = getThingStatusInfo("groheondus:account:account")

    if ((thingStatusInfo !== null) && (thingStatusInfo.getStatus().toString() == "OFFLINE")) {
         logInfo("FILE", "Grohe offline")
         sendHttpPutRequest("http://USER:PWD@127.0.0.1:8080/rest/things/groheondus%3Aaccount%3Aaccount/enable","text/plain",'false',5000)

         createTimer(now.plusMinutes(1),  [|
            sendHttpPutRequest("http://USER:PWD@127.0.0.1:8080/rest/things/groheondus%3Aaccount%3Aaccount/enable","text/plain",'true',5000)
            logInfo("FILE", "Grohe re-enabled")
         ] )
    }
end
sirupflex commented 2 years ago

Fantastic, in the past days I tried the binding V3.3 beta and your script and basically it works, but sometimes runs into a timeout when it tries to re-enable it. Just wanted to check back for suggestions and hey, there it is already. Will try immediately. Thanks so much for all you work, it is highly appreciated!!