sebr / bhyve-home-assistant

Orbit BHyve custom component for Home Assistant
MIT License
252 stars 42 forks source link

Receiving warnings with later break once a week #57

Closed Pirol62 closed 3 years ago

Pirol62 commented 3 years ago

Describe the bug At least one a week I receive issues as warnings with later disconnect.

Expected behaviour

BHyve devices 1 device

Logs

Logger: custom_components.bhyve
Source: custom_components/bhyve/__init__.py:262
Integration: Orbit BHyve Integration (documentation)
First occurred: 11. April 2021, 15:32:14 (1 occurrences)
Last logged: 11. April 2021, 15:32:14

Failed to connect to BHyve servers. Error requesting data from https://api.orbitbhyve.com/v1/devices: 500, message='Internal Server Error', url=URL('https://api.orbitbhyve.com/v1/devices?t=1618147934.0864298')
Logger: custom_components.bhyve
Source: custom_components/bhyve/__init__.py:262
Integration: Orbit BHyve Integration (documentation)
First occurred: 11. April 2021, 15:32:14 (1 occurrences)
Last logged: 11. April 2021, 15:32:14

Failed to connect to BHyve servers. Error requesting data from https://api.orbitbhyve.com/v1/devices: 500, message='Internal Server Error', url=URL('https://api.orbitbhyve.com/v1/devices?t=1618147934.0864298')
Logger: homeassistant.helpers.entity
Source: custom_components/bhyve/pybhyve/client.py:78
First occurred: 11. April 2021, 13:21:13 (3 occurrences)
Last logged: 11. April 2021, 16:56:45

Update for sensor.zone_1_zone_history fails
Update for sensor.wasserhahn_garten_battery_level fails
Traceback (most recent call last):
  File "/config/custom_components/bhyve/pybhyve/client.py", line 75, in _request
    resp.raise_for_status()
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client_reqrep.py", line 1000, in raise_for_status
    raise ClientResponseError(
aiohttp.client_exceptions.ClientResponseError: 500, message='Internal Server Error', url=URL('https://api.orbitbhyve.com/v1/watering_events/5d41cce54f0c47ece9e6ab27?t=1618140073.1427734&page=1&per-page=10')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 277, in async_update_ha_state
    await self.async_device_update()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 473, in async_device_update
    raise exc
  File "/config/custom_components/bhyve/sensor.py", line 184, in async_update
    raise (err)
  File "/config/custom_components/bhyve/sensor.py", line 151, in async_update
    history = await self._fetch_device_history(force_update=force_update) or []
  File "/config/custom_components/bhyve/__init__.py", line 272, in _fetch_device_history
    raise (err)
  File "/config/custom_components/bhyve/__init__.py", line 268, in _fetch_device_history
    return await self._bhyve.get_device_history(self._device_id, force_update)
  File "/config/custom_components/bhyve/pybhyve/client.py", line 182, in get_device_history
    await self._refresh_device_history(device_id, force_update=force_update)
  File "/config/custom_components/bhyve/pybhyve/client.py", line 112, in _refresh_device_history
    device_history = await self._request(
  File "/config/custom_components/bhyve/pybhyve/client.py", line 78, in _request
    raise RequestError(f"Error requesting data from {url}: {err}")
custom_components.bhyve.pybhyve.errors.RequestError: Error requesting data from https://api.orbitbhyve.com/v1/watering_events/5d41cce54f0c47ece9e6ab27: 500, message='Internal Server Error', url=URL('https://api.orbitbhyve.com/v1/watering_events/5d41cce54f0c47ece9e6ab27?t=1618140073.1427734&page=1&per-page=10')
sebr commented 3 years ago

These are errors from the BHyve servers. What is the behaviour you expect?

Pirol62 commented 3 years ago

Hmm...It would be great, if the connect could be reestablished. So far, I always have to check, if the irrigation have started. That's not the basic idea :-). To be honest: half a year ago, the breaks came nearly every night. It's better now. Around once a week or even less.

Pirol62 commented 3 years ago

Hi, I still have these errors at least twice a week. One solution would be to enable a reload of the integration. Maybe the connect errors are not avoidable but it would help, to simply reload the component like it is possible with Met.no and others. Is it possible to create a service?

Pirol62 commented 3 years ago

@sebr I already restarted HA and found out, that the switch is working, battery level is available but the sensor for the zone is not available This was the message in the log:

Logger: homeassistant.components.sensor
Source: custom_components/bhyve/pybhyve/client.py:78
Integration: Sensor (documentation, issues)
First occurred: 13:12:17 (1 occurrences)
Last logged: 13:12:17

bhyve: Error on device update!
Traceback (most recent call last):
  File "/config/custom_components/bhyve/pybhyve/client.py", line 75, in _request
    resp.raise_for_status()
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client_reqrep.py", line 1000, in raise_for_status
    raise ClientResponseError(
aiohttp.client_exceptions.ClientResponseError: 500, message='Internal Server Error', url=URL('https://api.orbitbhyve.com/v1/watering_events/5d41cce54f0c47ece9e6ab27?t=1619781127.6896255&page=1&per-page=10')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 365, in _async_add_entity
    await entity.async_device_update(warning=False)
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 482, in async_device_update
    await task
  File "/config/custom_components/bhyve/sensor.py", line 184, in async_update
    raise (err)
  File "/config/custom_components/bhyve/sensor.py", line 151, in async_update
    history = await self._fetch_device_history(force_update=force_update) or []
  File "/config/custom_components/bhyve/__init__.py", line 272, in _fetch_device_history
    raise (err)
  File "/config/custom_components/bhyve/__init__.py", line 268, in _fetch_device_history
    return await self._bhyve.get_device_history(self._device_id, force_update)
  File "/config/custom_components/bhyve/pybhyve/client.py", line 182, in get_device_history
    await self._refresh_device_history(device_id, force_update=force_update)
  File "/config/custom_components/bhyve/pybhyve/client.py", line 112, in _refresh_device_history
    device_history = await self._request(
  File "/config/custom_components/bhyve/pybhyve/client.py", line 78, in _request
    raise RequestError(f"Error requesting data from {url}: {err}")
custom_components.bhyve.pybhyve.errors.RequestError: Error requesting data from https://api.orbitbhyve.com/v1/watering_events/5d41cce54f0c47ece9e6ab27: 500, message='Internal Server Error', url=URL('https://api.orbitbhyve.com/v1/watering_events/5d41cce54f0c47ece9e6ab27?t=1619781127.6896255&page=1&per-page=10')

the sensor is unavailable since 2 days.

Does something changed in the api?

twhug commented 3 years ago

I'll add that I'm seeing the same thing. Other than a full HA restart - is there any way to re-sync a device when the error occurs? Have 5 devices so if one of the API calls fail but the other 4 complete OK it's a bit of an annoyance having to restart the whole thing.

Appreciate that this is being caused by a bodgy bHyve API but yeah a graceful way of handling it would be brilliant.

Pirol62 commented 3 years ago

Hi, I'm close to delete this integration even I had so much work on it. Yesterday I restarted HA due to not working bHyve. 10 Minutes ago bHyve did not work again. So up to now it is useless asI have to check availability daily. The error logs:

Logger: custom_components.bhyve.pybhyve.websocket
Source: custom_components/bhyve/pybhyve/websocket.py:137
Integration: Orbit BHyve Integration (documentation)
First occurred: 12. Juni 2021, 12:41:39 (1 occurrences)
Last logged: 12. Juni 2021, 12:41:39

Client connection error; state: starting
Logger: homeassistant.helpers.entity
Source: custom_components/bhyve/pybhyve/client.py:78
Integration: Orbit BHyve Integration (documentation)
First occurred: 12. Juni 2021, 3:14:17 (3 occurrences)
Last logged: 12. Juni 2021, 15:54:23

Update for sensor.wasserhahn_garten_battery_level fails
Traceback (most recent call last):
  File "/config/custom_components/bhyve/pybhyve/client.py", line 75, in _request
    resp.raise_for_status()
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client_reqrep.py", line 1000, in raise_for_status
    raise ClientResponseError(
aiohttp.client_exceptions.ClientResponseError: 500, message='Internal Server Error', url=URL('https://api.orbitbhyve.com/v1/devices?t=1623460456.930042')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 316, in async_update_ha_state
    await self.async_device_update()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 524, in async_device_update
    raise exc
  File "/config/custom_components/bhyve/sensor.py", line 107, in async_update
    await self._refetch_device()
  File "/config/custom_components/bhyve/__init__.py", line 264, in _refetch_device
    raise (err)
  File "/config/custom_components/bhyve/__init__.py", line 253, in _refetch_device
    device = await self._bhyve.get_device(self._device_id, force_update)
  File "/config/custom_components/bhyve/pybhyve/client.py", line 174, in get_device
    await self._refresh_devices(force_update=force_update)
  File "/config/custom_components/bhyve/pybhyve/client.py", line 87, in _refresh_devices
    self._devices = await self._request(
  File "/config/custom_components/bhyve/pybhyve/client.py", line 78, in _request
    raise RequestError(f"Error requesting data from {url}: {err}")
custom_components.bhyve.pybhyve.errors.RequestError: Error requesting data from https://api.orbitbhyve.com/v1/devices: 500, message='Internal Server Error', url=URL('https://api.orbitbhyve.com/v1/devices?t=1623460456.930042')

There are nor errors regarding the history sensor because I deactivated this. It did never work for more then 2 to 5 hours.

I'ts summer time, so I need the irrigation urgently - What can I do in order to stabalize this integration?

Can you provide a service in order to restart the component in case of an error?

sebr commented 3 years ago

Sorry to hear that mate - unfortunately I am extremely busy and do not have time to dedicate to solve this for you right now. Perhaps you could do some debugging and submit a pull request? To make matters more complex, I have no issues with the integration at all (my 3 tap timers all work very reliably) so I can't reproduce this.

Pirol62 commented 3 years ago

Hi @sebr . I would debug, if I'd know how it works ;-). I'm a bloody beginner in python and GitHub and might haven't the workspace in order to do that. All what I can do is got through the code and look what happens on the mentioned line in the error. So I have to wait. It's clear that prio 1 is family, prio 2 job, prio 3 friends and then the rest of all ;-)

briodan commented 3 years ago

figured I would add that I'm seeing the same issue here. most often i get

Logger: custom_components.bhyve
Source: custom_components/bhyve/__init__.py:271
Integration: Orbit BHyve Integration (documentation)
First occurred: 8:44:15 PM (1 occurrences)
Last logged: 8:44:15 PM

Failed to connect to BHyve servers. Error requesting data from https://api.orbitbhyve.com/v1/watering_events/60a948054f0cc5e78a2ffcf4: 500, message='Internal Server Error', url=URL('https://api.orbitbhyve.com/v1/watering_events/60a948054f0cc5e78a2ffcf4?t=1624329855.0481064&page=1&per-page=10')

followed by

Logger: homeassistant.helpers.entity
Source: custom_components/bhyve/pybhyve/client.py:78
Integration: Orbit BHyve Integration (documentation)
First occurred: 8:44:15 PM (1 occurrences)
Last logged: 8:44:15 PM

Update for sensor.zone_history fails
Traceback (most recent call last):
  File "/config/custom_components/bhyve/pybhyve/client.py", line 75, in _request
    resp.raise_for_status()
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client_reqrep.py", line 1000, in raise_for_status
    raise ClientResponseError(
aiohttp.client_exceptions.ClientResponseError: 500, message='Internal Server Error', url=URL('https://api.orbitbhyve.com/v1/watering_events/60a948054f0cc5e78a2ffcf4?t=1624329855.0481064&page=1&per-page=10')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 350, in async_update_ha_state
    await self.async_device_update()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 558, in async_device_update
    raise exc
  File "/config/custom_components/bhyve/sensor.py", line 186, in async_update
    raise (err)
  File "/config/custom_components/bhyve/sensor.py", line 153, in async_update
    history = await self._fetch_device_history(force_update=force_update) or []
  File "/config/custom_components/bhyve/__init__.py", line 272, in _fetch_device_history
    raise (err)
  File "/config/custom_components/bhyve/__init__.py", line 268, in _fetch_device_history
    return await self._bhyve.get_device_history(self._device_id, force_update)
  File "/config/custom_components/bhyve/pybhyve/client.py", line 182, in get_device_history
    await self._refresh_device_history(device_id, force_update=force_update)
  File "/config/custom_components/bhyve/pybhyve/client.py", line 112, in _refresh_device_history
    device_history = await self._request(
  File "/config/custom_components/bhyve/pybhyve/client.py", line 78, in _request
    raise RequestError(f"Error requesting data from {url}: {err}")
custom_components.bhyve.pybhyve.errors.RequestError: Error requesting data from https://api.orbitbhyve.com/v1/watering_events/60a948054f0cc5e78a2ffcf4: 500, message='Internal Server Error', url=URL('https://api.orbitbhyve.com/v1/watering_events/60a948054f0cc5e78a2ffcf4?t=1624329855.0481064&page=1&per-page=10')

which is mostly fine as not being able to get history is not that important to me, but it will eventually fail run execute the watering cycle. I'm using this to start a watering cycle every 10 minutes for 2 minutes if humidity is too low in my greenhouse. The only thing that seems to fix it is a restart of HA, unfortunately I did not capture the error messages before restarting and the log got wiped. I'll keep an eye on and post logs if I see this again.

sebr commented 3 years ago

Hi everyone, I've made a few small tweaks to hopefully increase the resiliency of the integration when it encounters upstream errors with the BHyve API. You can install 2.0.8-beta1 manually or by enabling beta releases in HACS.

Let me know how you go with this?

briodan commented 3 years ago

installed it just now will keep an eye on to see how it goes.

sebr commented 3 years ago

Thanks. It will still log the errors but hopefully will not cause the integration to break.

twhug commented 3 years ago

Thanks sebr, also installed the beta and will keep an eye out 🙂

Pirol62 commented 3 years ago

Hi sebr. I'm on leave and will install the beta on Friday. Thanks for your support

Pirol62 commented 3 years ago

Hi Seb, just to inform you, that we have this still in mind. I updated to the beta on saturday. Since then, I had no log entry (Debug level activated) and the irrigation switch is stable. This is more as expected as you only handle the incoming issues in a different way as I understood. Before, I had at least one message a day that the battery sensor could'nt been updated with the later total integration break. Let's wait another week and then I hope we can close this issue

DaftHonk commented 3 years ago

Just installed the beta after seeing similar behavior in 2.0.7, will report my findings. Either way the integration is still more stable than b-hyve's firmware update...

Doxxter commented 3 years ago

I'm still having this issue and no amounts of restarts seem to fix it. I've reinstalled the integration a few times, using the beta version for the last few, but no luck regardless unfortunately. It used to work for the most part, would drop occasionally but a restart would fix it, but the last week+ it's been totally unavailable.

I wouldnt be surprised if its on Orbit's end but just adding info.

Logger: homeassistant.setup Source: custom_components/bhyve/pybhyve/client.py:140 Integration: bhyve (documentation) First occurred: 3:14:25 PM (1 occurrences) Last logged: 3:14:25 PM

Error during setup of component bhyve Traceback (most recent call last): File "/config/custom_components/bhyve/pybhyve/client.py", line 134, in login resp.raise_for_status() File "/usr/local/lib/python3.8/site-packages/aiohttp/client_reqrep.py", line 1000, in raise_for_status raise ClientResponseError( aiohttp.client_exceptions.ClientResponseError: 401, message='Unauthorized', url=URL('https://api.orbitbhyve.com/v1/session')

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/setup.py", line 248, in _async_setup_component result = await task File "/config/custom_components/bhyve/init.py", line 119, in async_setup await bhyve.login() File "/config/custom_components/bhyve/pybhyve/client.py", line 140, in login raise RequestError(f"Error requesting data from {url}: {err}") custom_components.bhyve.pybhyve.errors.RequestError: Error requesting data from https://api.orbitbhyve.com/v1/session: 401, message='Unauthorized', url=URL('https://api.orbitbhyve.com/v1/session')

twhug commented 3 years ago

I wouldnt be surprised if its on Orbit's end but just adding info.

aiohttp.client_exceptions.ClientResponseError: 401, message='Unauthorized', url=URL('https://api.orbitbhyve.com/v1/session')

You’re getting a 401 Unauthorized error so either there’s an issue with bHyve authenticating your account, or (more likely) your login details have changed and haven’t been updated in the relevant config file. That’s different to the issue most of us have been getting (and I think sebr’s fix may have specifically dealt with the “500 internal server error” that we get, not with 401s as well).

briodan commented 3 years ago

so far the integration has been stable for me over the last 2 weeks, no random hangs etc.

still getting some errors in the logs like:

Unable to retreive data for zone history: Error requesting data from https://api.orbitbhyve.com/v1/watering_events/xxxx: 500, message='Internal Server Error', or Updating bhyve sensor took longer than the scheduled update interval 0:00:30 or websocket connection closed

they seem to be random delays/fails on API update, probably a timeout etc. on the orbit server side. But most importantly nothing is bringing the integration down and my watering continues to run on schedule.

sebr commented 3 years ago

Okay great, thanks for the update @briodan. I'll resolve this issue and re-release as v 2.0.8 for everyone else who isn't on a beta release. Much appreciate all the debugging and investigations everyone!

briodan commented 3 years ago

@sebr after more then a month of solid running ran into this issue again, or different issue with same symptoms. My integration and had to restart HA to get it working again.

here are my logs

2021-08-02 14:19:18 ERROR (MainThread) [custom_components.bhyve.pybhyve.websocket] websocket connection closed
2021-08-02 14:19:18 WARNING (MainThread) [custom_components.bhyve.pybhyve.websocket] Websocket exception:
2021-08-02 14:19:23 ERROR (MainThread) [custom_components.bhyve.pybhyve.websocket] Unexpected error 502, message='Invalid response status', url=URL('wss://api.orbitbhyve.com/v1/events')
----
2021-08-02 14:30:00 WARNING (MainThread) [custom_components.bhyve.pybhyve.websocket] Tried to send message whilst websocket closed; state: starting
----
2021-08-02 14:45:00 WARNING (MainThread) [custom_components.bhyve.pybhyve.websocket] Tried to send message whilst websocket closed; state: starting
----
2021-08-02 14:45:00 WARNING (MainThread) [custom_components.bhyve.pybhyve.websocket] Tried to send message whilst websocket closed; state: starting
----
2021-08-02 15:00:00 WARNING (MainThread) [custom_components.bhyve.pybhyve.websocket] Tried to send message whilst websocket closed; state: starting
----
2021-08-02 15:15:00 WARNING (MainThread) [custom_components.bhyve.pybhyve.websocket] Tried to send message whilst websocket closed; state: starting
----

after this its repeats the same message every 15 minutes (then its supposed to run) until I restarted HA.