Closed petervargait closed 3 years ago
I have found the error in the log it only appears when I restart the bundle
19:25:46.440 [WARN ] [ommon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.NullPointerException: null
at org.openhab.binding.hydrawise.internal.HydrawiseCloudHandler.pollController(HydrawiseCloudHandler.java:130) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseHandler.pollControllerInternal(HydrawiseHandler.java:311) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_152]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_152]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_152]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_152]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_152]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_152]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_152]
It looks to me that customerdetails gives back the info but some items are not in the expected format might be status. Here is my response from API ( https://app.hydrawise.com/api/v1/customerdetails.php?api_key=myAPIKey&type=controllers) )
{"controller_id":111297,"customer_id":98556,"current_controller":"Hunter Hydreawise","controllers":[{"name":"Hunter Hydreawise","last_contact":1585666199,"serial_number":"05fbb717","controller_id":111297,"status":"All good!"}]}
Hi, thanks for the report and the sample response, that helps confirm the issue. I have noticed too, it looks like they slightly changed the api, i have a fix i have been testing locally, but totally forgot to get this committed. I'll do that soon.
Hi! 1) HydraWise binding is not working in 2.5.3(same error @petervargait )
2) They changed API(last year's API was better…) As i understand some information now is only available via GraphQL & OAuth2.0 and limited data via REST.
URL for new api - https://support.hydrawise.com/hc/en-us/articles/360008965753-Hydrawise-API-Information
3) Also they implement "refresh windows", now you cannot just update every 30 second. There is parameter in json (time for next request)
"Rate Limiting Access to this API is rate limited. The statusschedule.php request has a field called nextpoll that indicates when the next API query should be made. Queries over this rate may be rejected with an HTTP 429 status code."
I can confirm that this error persists.
21:08:45.665 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.NullPointerException: null
at org.openhab.binding.hydrawise.internal.HydrawiseCloudHandler.pollController(HydrawiseCloudHandler.java:127) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseHandler.pollControllerInternal(HydrawiseHandler.java:310) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_232]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_232]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_232]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_232]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]
I will no longer be using the API listed above, they ended up removing quite a bit of functionality.
I have a working version based on their GraphQL api, which is what the mobile and web clients use.
There will be some changes to how you long in, the API key will no longer be used, instead you will enter your user name and password, and the binding will retrieve a OAuth access and refresh token to log in with, it will then delete your password so we do not need to store that beyond the first login.
The other change will be the thing structure will now include an "account" bridge, so items will have a different structure which will include the bridge type , but channels will remain the same, so hopefully this will be a search and replace operation to migrate
Normally i would try to maintain backwards compatibility, but my guess is there are less than a dozen people using the binding, so i think now is the right time to make clean break and do this the right way.
Update: I have a version of this working against the new API, I just need to clean up a few things and update documentation. I'm hoping to have a test version today or tomorrow if anyone wants to help test it.
Hi Dan,
I can help to test
P.
On Tue, May 5, 2020 at 3:50 PM Dan Cunningham notifications@github.com wrote:
Update: I have a version of this working against the new API, I just need to clean up a few things and update documentation. I'm hoping to have a test version today or tomorrow if anyone wants to help test it.
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/openhab/openhab-addons/issues/7261#issuecomment-624067529, or unsubscribe https://github.com/notifications/unsubscribe-auth/AO74KIZTLCHHPUSRWDE3753RQAKS3ANCNFSM4LXLQ6JQ .
Hi Dan, if you need testing, drop me a line!
Chris
Hi!
I сan help to test!
Denys K.
5 мая 2020 г., в 16:50, Dan Cunningham notifications@github.com написал(а):
Update: I have a version of this working against the new API, I just need to clean up a few things and update documentation. I'm hoping to have a test version today or tomorrow if anyone wants to help test it.
— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/openhab/openhab-addons/issues/7261#issuecomment-624067529, or unsubscribe https://github.com/notifications/unsubscribe-auth/ANOHPX67AIMZJPSBUS5I5HDRQAKS3ANCNFSM4LXLQ6JQ.
HI @digitaldan, would also be happy to help testing!
Best, David
Hi guys, i have a new jar at https://github.com/digitaldan/openhab2-addons/releases/tag/2.5.x-hydrawise-1.0
I crudely updated the readme with the new "Account bridge" section, see
I still have a bunch of clean up work todo and testing, not to mention documentation, but the binding seems to be working and stable.
I'm listing detailed install instructions, but the short version is you will 1) Delete your existing Cloud thing 2) Remove the existing binding 3) Install the new binding 4) In the paperUI install the "account" thing and configure it with your user name and password 5) In the paperUI add the auto discovered controller thing from the inbox 6) Updated your items file by doing a single find and replace (if using a items file)
For this new binding you will want to delete your cloud controller thing FIRST, then uninstall the current binding. Then install this new Jar (drop into your addons folder, or use the karaf console to install)
Once installed, in the PaperUI under the "Things" section add a new thing:
Then select the Hydrawise binding:
Then select "Add Manually" and select "Account Thing"
In the next screen, name the account thing, in the readme i use "myaccount" , but name it anything you want:
also enter your account username and password. The password will only be retained while the binding attempts to connect, unless the option to save it is enabled. One a successful connection is made we store an oAuth token for future use.
Your Inbox should now have your controller listed, or multiple controllers if you have more then one on your account. Go ahead and add it. Take a look at its ID (also shown under its channels). You will need it to update your items file below.
To use existing items you have in a file , it's a simple find and replace job. For example:
{channel="hydrawise:cloud:home:forecast1#temperaturehigh}
becomes
{channel="hydrawise:controller:myaccount:123456:forecast1#temperaturehigh"}
where 123456 is the id of the controller (look in the paperUI) and "myaccount" is whatever you name your account thing. All i did was find hydrawise:cloud:home
and replaced with hydrawise:controller:myaccount:123456
Hi @digitaldan,
I've got two different systems; LIVE - Debian Buster, Zulu-8, openHAB latest stable, various bindings, other services TEST - Debian Buster, Zulu-8, openHAB latest stable, ONLY(!) Hydrawise binding
Edit 1 (TEST/LIVE): Task: testing your binding in both LIVE and TEST system. Result: unfortunately I got an error in both my live-system and test environment.
openhab.log of TEST:
2020-05-06 08:05:27.203 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.NullPointerException: null
at org.openhab.binding.hydrawise.internal.HydrawiseAccountHandler.authTokenUpdated(HydrawiseAccountHandler.java:164) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseAccountHandler.configure(HydrawiseAccountHandler.java:96) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_252]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_252]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_252]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
Edit 2 (TEST): Task: trying different passwords (varying in different lenghts, w/o symbols, ...) Result: got it working after removing a special char from the password "^"
Edit 3 (LIVE): Task: now trying to "migrate" to LIVE Result: unfortunately I got an error.
openhab.log of LIVE:
2020-05-06 08:34:28.016 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'hydrawise:account:8f633696': Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@5bd37477 rejected from org.eclipse.smarthome.core.internal.common.WrappedScheduledExecutorService@762f8bd7[Shutting down, pool size = 1, active threads = 0, queued tasks = 19, completed tasks = 39324]
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@5bd37477 rejected from org.eclipse.smarthome.core.internal.common.WrappedScheduledExecutorService@762f8bd7[Shutting down, pool size = 1, active threads = 0, queued tasks = 19, completed tasks = 39324]
at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063) ~[?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830) ~[?:1.8.0_252]
at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:326) ~[?:1.8.0_252]
at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:533) ~[?:1.8.0_252]
at org.openhab.binding.hydrawise.internal.HydrawiseAccountHandler.initialize(HydrawiseAccountHandler.java:57) ~[?:?]
at sun.reflect.GeneratedMethodAccessor76.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
Edit 4 (LIVE): Task: restarting openHAB2 on LIVE Result: After an openHAB service restart the Hydrawise binding is listed in the thing configuration, but there are no further options (account, cloud, local).
According to KARAF, the Hydrawise-binding is running;
290 │ Active │ 80 │ 2.5.4.202005060354 │ openHAB Add-ons :: Bundles :: Hydrawise Binding
Edit 5 (LIVE): Task: change owner of org.openhab.binding.hydrawise-2.5.4-SNAPSHOT.jar to obenhab / restarting binding out of KARAF afterwards Result: after a "bundle:restart 290" in KARAF, the manual thing configuration showed further options again (account, cloud, local).
Edit 6 (LIVE): Task: trying to add the Hydrawise Account thing and finish thing configuration Result: successfully added the account without any errors, but when adding the controller from the inbox there is a DateTimeParseException thrown;
First off, the inbox log;
2020-05-06 09:12:19.550 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'hydrawise:controller:4466de28:XXXXXX' to inbox.
After adding from inbox;
2020-05-06 09:13:18.913 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler@1a1f57a5': Text 'Wed, 06 May 20 00:00:00 +0200' could not be parsed at index 0
java.time.format.DateTimeParseException: Text 'Wed, 06 May 20 00:00:00 +0200' could not be parsed at index 0
at java.time.format.DateTimeFormatter.parseResolved0(DateTimeFormatter.java:1949) ~[?:1.8.0_252]
at java.time.format.DateTimeFormatter.parse(DateTimeFormatter.java:1851) ~[?:1.8.0_252]
at java.time.ZonedDateTime.parse(ZonedDateTime.java:597) ~[?:1.8.0_252]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.stringToDateTime(HydrawiseControllerHandler.java:360) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.updateForecast(HydrawiseControllerHandler.java:308) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.lambda$1(HydrawiseControllerHandler.java:226) ~[?:?]
at java.util.Optional.ifPresent(Optional.java:159) ~[?:1.8.0_252]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.onData(HydrawiseControllerHandler.java:219) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseAccountHandler.addControllerListeners(HydrawiseAccountHandler.java:70) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.initialize(HydrawiseControllerHandler.java:97) ~[?:?]
at sun.reflect.GeneratedMethodAccessor76.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
2020-05-06 09:13:18.931 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'hydrawise:controller:4466de28:XXXXXX': Text 'Wed, 06 May 20 00:00:00 +0200' could not be parsed at index 0
java.time.format.DateTimeParseException: Text 'Wed, 06 May 20 00:00:00 +0200' could not be parsed at index 0
at java.time.format.DateTimeFormatter.parseResolved0(DateTimeFormatter.java:1949) ~[?:1.8.0_252]
at java.time.format.DateTimeFormatter.parse(DateTimeFormatter.java:1851) ~[?:1.8.0_252]
at java.time.ZonedDateTime.parse(ZonedDateTime.java:597) ~[?:1.8.0_252]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.stringToDateTime(HydrawiseControllerHandler.java:360) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.updateForecast(HydrawiseControllerHandler.java:308) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.lambda$1(HydrawiseControllerHandler.java:226) ~[?:?]
at java.util.Optional.ifPresent(Optional.java:159) ~[?:1.8.0_252]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.onData(HydrawiseControllerHandler.java:219) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseAccountHandler.addControllerListeners(HydrawiseAccountHandler.java:70) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.initialize(HydrawiseControllerHandler.java:97) ~[?:?]
at sun.reflect.GeneratedMethodAccessor76.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
Thanks @giterest ! i'll take a look. Your last error is strange, its breaking on trying to parse the time string for the weather forecast, what is strange is that it works on my system, the only difference is that my offset is -7 where yours is +2 , I'll try and reproduce that today.
The other errors look like they stem from an issue with handling the passcode? possibly b/c a symbol in it ? Let me see if i need to be escaping that string before sending to the http client, although we should never be allowing a null pointer error, so that is also a bug.
Hi @digitaldan ! Thanks for sharing the snapshot. I installed it, restarted the openHAB service and then added account thing and also a controller (which was discovered automatically). I also checked to add an item to items file and the sitemap and was able to start and stop a "run" of zone1.
So initial feedback: works well!
Will start now to integrate it more into my home automation setup (all zones, ...) and let you know once I have additional feedback.
Once again, so thankful for you work!
David
First addition: Seems like the connection to the Hydrawise servers is shaky. The bridge is switching between online and offline quite a bit.
2020-05-06 16:25:22.445 [hingStatusInfoChangedEvent] - 'hydrawise:account:ff94af04' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@195fac0::DecryptedEndPoint@1a56a22{app.hydrawise.com/52.41.248.73:443<->/192.168.1.39:52810,OPEN,fill=-,flush=-,to=60216/0}
2020-05-06 16:25:22.448 [hingStatusInfoChangedEvent] - 'hydrawise:controller:ff94af04:307177' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2020-05-06 16:26:23.560 [hingStatusInfoChangedEvent] - 'hydrawise:account:ff94af04' changed from OFFLINE (COMMUNICATION_ERROR): java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@195fac0::DecryptedEndPoint@1a56a22{app.hydrawise.com/52.41.248.73:443<->/192.168.1.39:52810,OPEN,fill=-,flush=-,to=60216/0} to ONLINE
2020-05-06 16:26:23.564 [hingStatusInfoChangedEvent] - 'hydrawise:controller:ff94af04:307177' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2020-05-06 16:31:52.554 [.ItemChannelLinkAddedEvent] - Link 'Zone1_Summary-hydrawise:controller:ff94af04:307177:zone1#summary' has been added.
2020-05-06 16:34:26.432 [hingStatusInfoChangedEvent] - 'hydrawise:account:ff94af04' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@50a5bd::DecryptedEndPoint@1e3b0d{app.hydrawise.com/52.41.248.73:443<->/192.168.1.39:52926,OPEN,fill=-,flush=-,to=60245/0}
2020-05-06 16:34:26.439 [hingStatusInfoChangedEvent] - 'hydrawise:controller:ff94af04:307177' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2020-05-06 16:35:27.584 [hingStatusInfoChangedEvent] - 'hydrawise:account:ff94af04' changed from OFFLINE (COMMUNICATION_ERROR): java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@50a5bd::DecryptedEndPoint@1e3b0d{app.hydrawise.com/52.41.248.73:443<->/192.168.1.39:52926,OPEN,fill=-,flush=-,to=60245/0} to ONLINE
2020-05-06 16:35:27.586 [hingStatusInfoChangedEvent] - 'hydrawise:controller:ff94af04:307177' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2020-05-06 16:35:35.929 [.ItemChannelLinkAddedEvent] - Link 'Zone1_NextRun-hydrawise:controller:ff94af04:307177:zone1#nextruntime' has been added.
2020-05-06 16:36:27.719 [hingStatusInfoChangedEvent] - 'hydrawise:account:ff94af04' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@125cae0::DecryptedEndPoint@6b467{app.hydrawise.com/35.165.155.138:443<->/192.168.1.39:33456,OPEN,fill=-,flush=-,to=60144/0}
2020-05-06 16:36:27.724 [hingStatusInfoChangedEvent] - 'hydrawise:controller:ff94af04:307177' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2020-05-06 16:37:28.835 [hingStatusInfoChangedEvent] - 'hydrawise:account:ff94af04' changed from OFFLINE (COMMUNICATION_ERROR): java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@125cae0::DecryptedEndPoint@6b467{app.hydrawise.com/35.165.155.138:443<->/192.168.1.39:33456,OPEN,fill=-,flush=-,to=60144/0} to ONLINE
2020-05-06 16:37:28.837 [hingStatusInfoChangedEvent] - 'hydrawise:controller:ff94af04:307177' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2020-05-06 16:44:31.430 [hingStatusInfoChangedEvent] - 'hydrawise:account:ff94af04' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@1174b00::DecryptedEndPoint@fb4837{app.hydrawise.com/52.41.248.73:443<->/192.168.1.39:53164,OPEN,fill=-,flush=-,to=60237/0}
2020-05-06 16:44:31.432 [hingStatusInfoChangedEvent] - 'hydrawise:controller:ff94af04:307177' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2020-05-06 16:45:32.527 [hingStatusInfoChangedEvent] - 'hydrawise:account:ff94af04' changed from OFFLINE (COMMUNICATION_ERROR): java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@1174b00::DecryptedEndPoint@fb4837{app.hydrawise.com/52.41.248.73:443<->/192.168.1.39:53164,OPEN,fill=-,flush=-,to=60237/0} to ONLINE
2020-05-06 16:45:32.529 [hingStatusInfoChangedEvent] - 'hydrawise:controller:ff94af04:307177' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2020-05-06 16:45:36.395 [temChannelLinkRemovedEvent] - Link 'Zone1_Summary => hydrawise:controller:ff94af04:307177:zone1#summary' has been removed.
2020-05-06 16:48:33.437 [hingStatusInfoChangedEvent] - 'hydrawise:account:ff94af04' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@998ef::DecryptedEndPoint@1fbc082{app.hydrawise.com/52.41.248.73:443<->/192.168.1.39:53330,OPEN,fill=-,flush=-,to=60146/0}
2020-05-06 16:48:33.440 [hingStatusInfoChangedEvent] - 'hydrawise:controller:ff94af04:307177' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2020-05-06 16:49:34.586 [hingStatusInfoChangedEvent] - 'hydrawise:account:ff94af04' changed from OFFLINE (COMMUNICATION_ERROR): java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@998ef::DecryptedEndPoint@1fbc082{app.hydrawise.com/52.41.248.73:443<->/192.168.1.39:53330,OPEN,fill=-,flush=-,to=60146/0} to ONLINE
2020-05-06 16:49:34.589 [hingStatusInfoChangedEvent] - 'hydrawise:controller:ff94af04:307177' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2020-05-06 16:50:34.712 [hingStatusInfoChangedEvent] - 'hydrawise:account:ff94af04' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@7c0dcd::DecryptedEndPoint@11aa0fe{app.hydrawise.com/35.165.155.138:443<->/192.168.1.39:33754,OPEN,fill=-,flush=-,to=60136/0}
2020-05-06 16:50:34.713 [hingStatusInfoChangedEvent] - 'hydrawise:controller:ff94af04:307177' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
Further I tested some of the channels, e.g. Zone #summary and Zone #nextruntime and did not receive any feedback for "summary" and only got feedback once for nextruntime, but then the information was gone and did not reload.
@dgebhardt is the refresh time still 60 seconds or did you set it to a lower value ? I'm wondering if you are being rate limited by the service.
Nm, i can see its still 60 seconds
@digitaldan it's still 60s. But I am not sure, if it's contradicted by the fact, that I am adding new items/ sitemap entries and save that back to openHAB and then openHAB is trying to query the information from Hydrawise? (so probably more often than every 60s)?
maybe, although i have seen this as well, but far less frequently , doing a little googling shows there might be a bug in the Jetty client with certain SSL servers, i will investigate, let me know if the problem gets better, worse or stays the same.
Further I tested some of the channels, e.g. Zone #summary and Zone #nextruntime a
I'll take a look, i have not actually tested those yet :-)
@digitaldan Thanks!
Regarding the channels:
Tested and working: zoneX#run zoneX#name zoneX#nextruntime
Tested and not working: allzones#run system#online system#name system#summary zoneX#summary
I could not test sensor related stuff, as I don't have any.
maybe, although i have seen this as well, but far less frequently , doing a little googling shows there might be a bug in the Jetty client with certain SSL servers, i will investigate, let me know if the problem gets better, worse or stays the same.
Will stop working on items/ sitemaps for a while and monitor the logs for a bit and let you know.
@digitaldan in regards to the timezone - yes, realls strange as it shouldn't make any difference parsing these. the fault symbol was a "^" - independent on the password length, so yes - I guess if you're escaping any special chars it should work.
What I can't reproduce is what @dgebhardt is reporting - I've got a stable (account) thing connection with not a single status change since my initial comment on this issue.
Can't test any more stuff until I can get my controller working.
I gave it another try (because.. you never know) with adding the controller thing, but same error is popping up again;
2020-05-06 17:44:28.018 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'hydrawise:controller:4466de28:XXXXXX': Text 'Wed, 06 May 20 00:00:00 +0200' could not be parsed at index 0
java.time.format.DateTimeParseException: Text 'Wed, 06 May 20 00:00:00 +0200' could not be parsed at index 0
at java.time.format.DateTimeFormatter.parseResolved0(DateTimeFormatter.java:1949) ~[?:1.8.0_252]
at java.time.format.DateTimeFormatter.parse(DateTimeFormatter.java:1851) ~[?:1.8.0_252]
at java.time.ZonedDateTime.parse(ZonedDateTime.java:597) ~[?:1.8.0_252]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.stringToDateTime(HydrawiseControllerHandler.java:360) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.updateForecast(HydrawiseControllerHandler.java:308) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.lambda$1(HydrawiseControllerHandler.java:226) ~[?:?]
at java.util.Optional.ifPresent(Optional.java:159) ~[?:1.8.0_252]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.onData(HydrawiseControllerHandler.java:219) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseAccountHandler.addControllerListeners(HydrawiseAccountHandler.java:70) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.initialize(HydrawiseControllerHandler.java:97) ~[?:?]
at sun.reflect.GeneratedMethodAccessor76.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
@dgebhardt - do you have any other offset than +2 like me?
its strange, i just tried hardcoding your time stamp in the code and it parses it correctly:
hydrawise:controller:account:96158:forecast1#time 2020-05-06T00:00:00.000+0200
@giterest i just made a small change, can you download the jar again and try it out?
@giterest i just made a small change, can you download the jar again and try it out?
Of course, will give it a try after dinner! Keep you updated.
Thanks!
Hi!
I have 2 sensors : Sensor 1 - Flow Sensor (counts water usage), Sensor 2 - Rain Sensor.
In last years API i have 2 parameters from HydraWise Cloud Dashboard:
String HydraWise_sensors_flow_week "Last Week Flow" (HydraWise) String HydraWise_sensors_rain_active "Rain Sensor" (HydraWise)
Does new API support Last Week Flow?
6 мая 2020 г., в 19:13, Dan Cunningham notifications@github.com написал(а):
Thanks!
— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/openhab/openhab-addons/issues/7261#issuecomment-624743965, or unsubscribe https://github.com/notifications/unsubscribe-auth/ANOHPX3OACGQZMRYQJEJXQ3RQGED7ANCNFSM4LXLQ6JQ.
Thanks!
Testing on TEST environment:
212 │ Active │ 80 │ 2.5.4.202005061613 │ openHAB Add-ons :: Bundles :: Hydrawise Binding
Account thing - works
2020-05-06 19:47:03.016 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'hydrawise:controller:f5ac4a5a:XXXXXX' to inbox.
Controller thing - works
I'll leave it on TEST now for a bit to see if I can reproduce @dgebhardt connections issues. Will reply to this after i migrated to LIVE where I'm going to assign items to the channels. I plan to do this this evening, so I can provide log-data overnight (just in case).
But, as of now, both account and controller things look fine!
@dgebhardt - do you have any other offset than +2 like me?
@giterest I am in GMT+1 (Europe/ Berlin)
@digitaldan: I collected all the logs related to the hydrawise binding. See attached file. Seems like the error is logged every minute (refresh interval at 60s). When connecting the first time I had enabled "save password", don't know if this could be the source. Will remove the account thing and recreate it to test if that changes the behaviour.
I spotted in the logs that every hour this line appears:
Thing 'hydrawise:account:ff94af04' has been updated.
What is happing to the account thing in that case?
@digitaldan can already confirm that recreation w/o "save password" did not change the behaviour. :)
I spotted in the logs that every hour this line appears: Thing 'hydrawise:account:ff94af04' has been updated. What is happing to the account thing in that case?
The oAuth access token expires after an hour (server setting), we use the refresh token to request a new token pair and save it to the thing. Updating the thing should not be a problem, although i need to test what happens if the thing is defined in a file vs added through the API.
Hi guys, also have some updates... the connection is really a bit shaky, getting disconnect/connects on a regular base (please see log later on). Maybe there's more behind that "refresh-token" you were talking about.
Not working channels (I didn't test every channel available!): hydrawise:controller:f32b6a98:XXXXXX:system#name hydrawise:controller:f32b6a98:XXXXXX:system#summary hydrawise:controller:f32b6a98:XXXXXX:forecast1#wind hydrawise:controller:f32b6a98:XXXXXX:zone1#summary
Besides that it seems there's a malformed datetime hiding in hydrawise:controller:f32b6a98:XXXXXX:forecast1#time - this is what I get:
0020-05-05T23:05:21+01:05:21
I've also written a special log-appender for that testing - here we go;
06-Mai-2020 22:20:37.587 [INFO ] [org.eclipse.smarthome.model.script.HYDRATEST ] - <THINGSTATUS_CHECKS> Hydrawise-Gateway: [offline]. 06-Mai-2020 22:21:38.647 [INFO ] [org.eclipse.smarthome.model.script.HYDRATEST ] - <THINGSTATUS_CHECKS> Hydrawise-Gateway: [online]. 06-Mai-2020 22:24:39.553 [INFO ] [org.eclipse.smarthome.model.script.HYDRATEST ] - <THINGSTATUS_CHECKS> Hydrawise-Gateway: [offline]. 06-Mai-2020 22:25:40.694 [INFO ] [org.eclipse.smarthome.model.script.HYDRATEST ] - <THINGSTATUS_CHECKS> Hydrawise-Gateway: [online]. 06-Mai-2020 22:29:41.934 [INFO ] [org.eclipse.smarthome.model.script.HYDRATEST ] - <THINGSTATUS_CHECKS> Hydrawise-Gateway: [offline]. 06-Mai-2020 22:30:42.979 [INFO ] [org.eclipse.smarthome.model.script.HYDRATEST ] - <THINGSTATUS_CHECKS> Hydrawise-Gateway: [online].
Therefore I assume that 60sec poll-rate is to high.
Therefore I assume that 60sec poll-rate is to high.
Let's not jump to conclusions, i have the same poll rate and only see this occasionally, as i mentioned above there may be an issues with the http client library jetty that is to blame.
OK - I'll leave it now overnight /w poll-rate of 300secs. Will provide logs for you tomorrow!
I think its a concurrency issue with jetty, so more frequent polling will more likely trigger it, there own web client polls every 60 seconds, so unless we are hitting it milliseconds faster and triggering it, i doubt we are being rate limited, also the app shifts in to more frequent polling when you trigger events without issue. This is in a browser of course. You can do less frequent polling, and you might have less of these errors, but its not going to tell me anything since there are many other conditions in the library that it will be effecting .
I just updated the jar with a new build, this contains a fix/workaround for the online/offline issue. I can confirm this is not the cloud service limiting requests but something with our http library.
OK - I'll leave it now overnight /w poll-rate of 300secs. Will provide logs for you tomorrow!
Hi, uploading the log of last night to this comment. HYDRATest.log
I just updated the jar with a new build, this contains a fix/workaround for the online/offline issue. I can confirm this is not the cloud service limiting requests but something with our http library.
Started testing right now - will keep you updated! (Thing configuration for both account and controller is working fine)
Channel check;
@digitaldan Replaced the .jar and can confirm that the error in logs is gone for now (15min testing so far).
Let me know once you focus on the channels, I will then go ahead and also test them. Or are there any changes to that regard yet?
@dgebhardt / @digitaldan - 6,5hours as of now w/o any connection issues.
@digitaldan / @giterest
Tested system, weather and zone channels (at least 5 zones):
Does not work:
hydrawise:controller:ff94af04:XXXXXXX:system#name hydrawise:controller:ff94af04:XXXXXXX:zone1#time
Does work:
hydrawise:controller:ff94af04:XXXXXXX:forecast1#temperaturehigh hydrawise:controller:ff94af04:XXXXXXX:forecast1#temperaturelow hydrawise:controller:ff94af04:XXXXXXX:forecast1#conditions hydrawise:controller:ff94af04:XXXXXXX:forecast1#humidity hydrawise:controller:ff94af04:XXXXXXX:forecast1#wind
hydrawise:controller:ff94af04:XXXXXXX:forecast2#temperaturehigh hydrawise:controller:ff94af04:XXXXXXX:forecast2#temperaturelow hydrawise:controller:ff94af04:XXXXXXX:forecast2#conditions hydrawise:controller:ff94af04:XXXXXXX:forecast2#humidity hydrawise:controller:ff94af04:XXXXXXX:forecast2#wind
hydrawise:controller:ff94af04:XXXXXXX:forecast3#temperaturehigh hydrawise:controller:ff94af04:XXXXXXX:forecast3#temperaturelow hydrawise:controller:ff94af04:XXXXXXX:forecast3#conditions hydrawise:controller:ff94af04:XXXXXXX:forecast3#humidity hydrawise:controller:ff94af04:XXXXXXX:forecast3#wind
hydrawise:controller:ff94af04:XXXXXXX:system#summary hydrawise:controller:ff94af04:XXXXXXX:system#online
hydrawise:controller:ff94af04:XXXXXXX:system#summary hydrawise:controller:ff94af04:XXXXXXX:system#online hydrawise:controller:ff94af04:XXXXXXX:zone1#name hydrawise:controller:ff94af04:XXXXXXX:zone1#run hydrawise:controller:ff94af04:XXXXXXX:zone1#nextruntime hydrawise:controller:ff94af04:XXXXXXX:zone1#summary hydrawise:controller:ff94af04:XXXXXXX:zone1#icon
Various controller + zone channels;
Weather channels;
Nice sitemap layout!
hydrawise:controller:ff94af04:XXXXXXX:system#name
Fixed in new release
hydrawise:controller:ff94af04:XXXXXXX:zone1#time
I actually removed this channel as it does not exist, use:
hydrawise:controller:ff94af04:XXXXXXX:zone1#nextruntime
instead
I just posted a new build which i think addresses most of missing channels, @giterest i had to revert some of the date time parsing code, can you let me know if this new build breaks again trying to parse your forecast time?
Hi buddy, snapshot #4 again giving me;
2020-05-07 20:07:19.273 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler@18aeb109': Text 'Thu, 07 May 20 00:00:00 +0200' could not be parsed at index 0
java.time.format.DateTimeParseException: Text 'Thu, 07 May 20 00:00:00 +0200' could not be parsed at index 0
at java.time.format.DateTimeFormatter.parseResolved0(DateTimeFormatter.java:1949) ~[?:1.8.0_252]
at java.time.format.DateTimeFormatter.parse(DateTimeFormatter.java:1851) ~[?:1.8.0_252]
at java.time.ZonedDateTime.parse(ZonedDateTime.java:597) ~[?:1.8.0_252]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.forecastStringToDateTime(HydrawiseControllerHandler.java:389) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.updateForecast(HydrawiseControllerHandler.java:332) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.lambda$1(HydrawiseControllerHandler.java:232) ~[?:?]
at java.util.Optional.ifPresent(Optional.java:159) ~[?:1.8.0_252]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.onData(HydrawiseControllerHandler.java:224) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseAccountHandler.addControllerListeners(HydrawiseAccountHandler.java:70) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.initialize(HydrawiseControllerHandler.java:100) ~[?:?]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_252]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_252]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
2020-05-07 20:07:19.283 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'hydrawise:controller:f32b6a98:XXXXXX': Text 'Thu, 07 May 20 00:00:00 +0200' could not be parsed at index 0
java.time.format.DateTimeParseException: Text 'Thu, 07 May 20 00:00:00 +0200' could not be parsed at index 0
at java.time.format.DateTimeFormatter.parseResolved0(DateTimeFormatter.java:1949) ~[?:1.8.0_252]
at java.time.format.DateTimeFormatter.parse(DateTimeFormatter.java:1851) ~[?:1.8.0_252]
at java.time.ZonedDateTime.parse(ZonedDateTime.java:597) ~[?:1.8.0_252]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.forecastStringToDateTime(HydrawiseControllerHandler.java:389) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.updateForecast(HydrawiseControllerHandler.java:332) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.lambda$1(HydrawiseControllerHandler.java:232) ~[?:?]
at java.util.Optional.ifPresent(Optional.java:159) ~[?:1.8.0_252]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.onData(HydrawiseControllerHandler.java:224) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseAccountHandler.addControllerListeners(HydrawiseAccountHandler.java:70) ~[?:?]
at org.openhab.binding.hydrawise.internal.HydrawiseControllerHandler.initialize(HydrawiseControllerHandler.java:100) ~[?:?]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_252]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_252]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
uhg, this is probably whats happening, its a Java 8 bug, i'll see about a workaround
https://bugs.java.com/bugdatabase/view_bug.do?bug_id=8138676
Hi, hmmm okay. I can anytime change to other Java SDKs. May I ask which one you have running?
I'm running 9, but you don't have to change as this needs to work for 8 too, the bug shows a workaround which i'll throw in today.
HI, I have openHAB 2.5 on Raspbian, my hydrawise binding added successfully, however when I add a Thing HydraWise Cloud it stucks in Initializing status. I have checked the API key and it works, nothing shows up in the logs