ksya / ha-nefiteasy

Nefit Easy connection for Home Assistant
74 stars 30 forks source link

Disconnect / connect error notifications #271

Closed AdeZwart closed 5 months ago

AdeZwart commented 9 months ago

I regularly have those notifications in the UI alerting me of connection errors: image

I see them so often that they really don't add any value anymore. Is there any way to turn those notifications off?

scotie commented 8 months ago

I have the same

bartkummel commented 6 months ago

I have the same. But rather than suppressing them, could it be possible to fix the underlying connection problem?

AdeZwart commented 6 months ago

@bartkummel yeah that would be best. But if I understood correctly this is caused by thr Bosch servers, making it out of their control.

RobBie1221 commented 6 months ago

I regularly have those notifications in the UI alerting me of connection errors: image

I see them so often that they really don't add any value anymore. Is there any way to turn those notifications off?

You are using an "old" version of the integration, but I see I set the newer one only on pre-release.

The old version used to give persistent errors when a sudden disconnect happens. This is however something that can happen and should be handled as normal as long as it can reconnect.

I added release 0.4.0. Please upgrade and test. That should make sure you get rid of all the persistent error messages.

AdeZwart commented 6 months ago

@RobBie1221 nice, I'll definitely check it out. Thanks!

AdeZwart commented 6 months ago

I haven't seen the persistent notifications since upgrading to v.0.4.0, Thanks @RobBie1221.

AdeZwart commented 6 months ago

I've been running this v0.4.0 release since it was released and at some point everything showed as "unavailabe", and according to the history it had been like that for 2 days. I dismissed it as an incident, and after reloading the integration everything worked as expected again.

However... today I found it in a similar state. All sensors offline and (coincidentally) it's been like that for 2 days again. So I started digging in the logs and I've found the following:

2023-12-16 18:28:17.413 ERROR (MainThread) [custom_components.nefiteasy] Timeout fetching nefiteasy data
[...]
2023-12-16 18:29:17.417 ERROR (MainThread) [custom_components.nefiteasy] Unexpected error fetching nefiteasy data: 
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 300, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/nefiteasy/__init__.py", line 262, in _async_update_data
    await self.connect()
  File "/config/custom_components/nefiteasy/__init__.py", line 148, in connect
    self.nefit.get("/gateway/brandID")
  File "/usr/local/lib/python3.11/site-packages/aionefit/__init__.py", line 107, in get
    self.xmppclient.send_message(mto=self._to, mbody=msg)
  File "/usr/local/lib/python3.11/site-packages/aionefit/provider/slixmpp_impl.py", line 93, in send_message
    message.stream.send_raw(str_data)
  File "/usr/local/lib/python3.11/site-packages/slixmpp/xmlstream/xmlstream.py", line 1354, in send_raw
    raise NotConnectedError()
slixmpp.xmlstream.xmlstream.NotConnectedError

At 18:28:17 it logs a timeout fetching data, followed by an uncaught exception a minute later. It looks like the connection is never restored afterwards, until I reload the integration.

Edit:

Inspected some older logs and the previous incident was at Dec 13th:

2023-12-13 14:09:29.048 ERROR (MainThread) [custom_components.nefiteasy] Unexpected error fetching nefiteasy data: 
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 300, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/nefiteasy/__init__.py", line 262, in _async_update_data
    await self.connect()
  File "/config/custom_components/nefiteasy/__init__.py", line 148, in connect
    self.nefit.get("/gateway/brandID")
  File "/usr/local/lib/python3.11/site-packages/aionefit/__init__.py", line 107, in get
    self.xmppclient.send_message(mto=self._to, mbody=msg)
  File "/usr/local/lib/python3.11/site-packages/aionefit/provider/slixmpp_impl.py", line 93, in send_message
    message.stream.send_raw(str_data)
  File "/usr/local/lib/python3.11/site-packages/slixmpp/xmlstream/xmlstream.py", line 1354, in send_raw
    raise NotConnectedError()
slixmpp.xmlstream.xmlstream.NotConnectedError

This exception wasn't preceded by a line containing Timeout fetching nefiteasy data, it just seemed to have happened out of the blue.

liquid-motion commented 6 months ago

I noticed exactly the same problem as @AdeZwart .

This also happened after upgrading to 0.4.0. Sometimes the plugin completely dies and everything becomes "unavailable".

RobBie1221 commented 6 months ago

I've been running this v0.4.0 release since it was released and at some point everything showed as "unavailabe", and according to the history it had been like that for 2 days. I dismissed it as an incident, and after reloading the integration everything worked as expected again.

However... today I found it in a similar state. All sensors offline and (coincidentally) it's been like that for 2 days again. So I started digging in the logs and I've found the following:

2023-12-16 18:28:17.413 ERROR (MainThread) [custom_components.nefiteasy] Timeout fetching nefiteasy data
[...]
2023-12-16 18:29:17.417 ERROR (MainThread) [custom_components.nefiteasy] Unexpected error fetching nefiteasy data: 
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 300, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/nefiteasy/__init__.py", line 262, in _async_update_data
    await self.connect()
  File "/config/custom_components/nefiteasy/__init__.py", line 148, in connect
    self.nefit.get("/gateway/brandID")
  File "/usr/local/lib/python3.11/site-packages/aionefit/__init__.py", line 107, in get
    self.xmppclient.send_message(mto=self._to, mbody=msg)
  File "/usr/local/lib/python3.11/site-packages/aionefit/provider/slixmpp_impl.py", line 93, in send_message
    message.stream.send_raw(str_data)
  File "/usr/local/lib/python3.11/site-packages/slixmpp/xmlstream/xmlstream.py", line 1354, in send_raw
    raise NotConnectedError()
slixmpp.xmlstream.xmlstream.NotConnectedError

At 18:28:17 it logs a timeout fetching data, followed by an uncaught exception a minute later. It looks like the connection is never restored afterwards, until I reload the integration.

Edit:

Inspected some older logs and the previous incident was at Dec 13th:

2023-12-13 14:09:29.048 ERROR (MainThread) [custom_components.nefiteasy] Unexpected error fetching nefiteasy data: 
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 300, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/nefiteasy/__init__.py", line 262, in _async_update_data
    await self.connect()
  File "/config/custom_components/nefiteasy/__init__.py", line 148, in connect
    self.nefit.get("/gateway/brandID")
  File "/usr/local/lib/python3.11/site-packages/aionefit/__init__.py", line 107, in get
    self.xmppclient.send_message(mto=self._to, mbody=msg)
  File "/usr/local/lib/python3.11/site-packages/aionefit/provider/slixmpp_impl.py", line 93, in send_message
    message.stream.send_raw(str_data)
  File "/usr/local/lib/python3.11/site-packages/slixmpp/xmlstream/xmlstream.py", line 1354, in send_raw
    raise NotConnectedError()
slixmpp.xmlstream.xmlstream.NotConnectedError

This exception wasn't preceded by a line containing Timeout fetching nefiteasy data, it just seemed to have happened out of the blue.

Thanks for the logging. Somehow directly after connect it hangs up and the next command to verify connection fails. It could be handled more gracefully by catching that error. I'll make some changes to the code.

jorgwonline commented 6 months ago

I've been running this v0.4.0 release since it was released and at some point everything showed as "unavailabe", and according to the history it had been like that for 2 days. I dismissed it as an incident, and after reloading the integration everything worked as expected again. However... today I found it in a similar state. All sensors offline and (coincidentally) it's been like that for 2 days again. So I started digging in the logs and I've found the following:

2023-12-16 18:28:17.413 ERROR (MainThread) [custom_components.nefiteasy] Timeout fetching nefiteasy data
[...]
2023-12-16 18:29:17.417 ERROR (MainThread) [custom_components.nefiteasy] Unexpected error fetching nefiteasy data: 
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 300, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/nefiteasy/__init__.py", line 262, in _async_update_data
    await self.connect()
  File "/config/custom_components/nefiteasy/__init__.py", line 148, in connect
    self.nefit.get("/gateway/brandID")
  File "/usr/local/lib/python3.11/site-packages/aionefit/__init__.py", line 107, in get
    self.xmppclient.send_message(mto=self._to, mbody=msg)
  File "/usr/local/lib/python3.11/site-packages/aionefit/provider/slixmpp_impl.py", line 93, in send_message
    message.stream.send_raw(str_data)
  File "/usr/local/lib/python3.11/site-packages/slixmpp/xmlstream/xmlstream.py", line 1354, in send_raw
    raise NotConnectedError()
slixmpp.xmlstream.xmlstream.NotConnectedError

At 18:28:17 it logs a timeout fetching data, followed by an uncaught exception a minute later. It looks like the connection is never restored afterwards, until I reload the integration. Edit: Inspected some older logs and the previous incident was at Dec 13th:

2023-12-13 14:09:29.048 ERROR (MainThread) [custom_components.nefiteasy] Unexpected error fetching nefiteasy data: 
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 300, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/nefiteasy/__init__.py", line 262, in _async_update_data
    await self.connect()
  File "/config/custom_components/nefiteasy/__init__.py", line 148, in connect
    self.nefit.get("/gateway/brandID")
  File "/usr/local/lib/python3.11/site-packages/aionefit/__init__.py", line 107, in get
    self.xmppclient.send_message(mto=self._to, mbody=msg)
  File "/usr/local/lib/python3.11/site-packages/aionefit/provider/slixmpp_impl.py", line 93, in send_message
    message.stream.send_raw(str_data)
  File "/usr/local/lib/python3.11/site-packages/slixmpp/xmlstream/xmlstream.py", line 1354, in send_raw
    raise NotConnectedError()
slixmpp.xmlstream.xmlstream.NotConnectedError

This exception wasn't preceded by a line containing Timeout fetching nefiteasy data, it just seemed to have happened out of the blue.

Thanks for the logging. Somehow directly after connect it hangs up and the next command to verify connection fails. It could be handled more gracefully by catching that error. I'll make some changes to the code.

Came to check for this, I have the same issue as @AdeZwart , after updating to 4.0. That would be great @RobBie1221 if you can fix it. Let me know if you would like me to test. Kind regards.

hwjr73 commented 6 months ago

Had the same, deactivated Integration for a while, and reactivated. Plugin started working again uninterrupted. Perhaps Nefit closes the connection with update frequency too high?

Regards

scotie commented 6 months ago

I ended up solving this with an automation that reloads the integration after it becomes unavailable for 30 seconds.

Added a notification to check if it is working, but disabled it later.

This has been working reliably for over a month now.


alias: Nefit auto reload
description: ""
trigger:
  - platform: state
    entity_id:
      - climate.nefit
    to: unavailable
    for:
      hours: 0
      minutes: 0
      seconds: 30
condition: []
action:
  - service: homeassistant.reload_config_entry
    target:
      device_id: your_device_id
    data: {}
  - service: notify.your_notification_entity
    data:
      message: Nefit thermostat became Unavailable. Reloading
    enabled: false
mode: single
jorgwonline commented 6 months ago

I ended up solving this with an automation that reloads the integration after it becomes unavailable for 30 seconds.

Added a notification to check if it is working, but disabled it later.

This has been working reliably for over a month now.


alias: Nefit auto reload
description: ""
trigger:
  - platform: state
    entity_id:
      - climate.nefit
    to: unavailable
    for:
      hours: 0
      minutes: 0
      seconds: 30
condition: []
action:
  - service: homeassistant.reload_config_entry
    target:
      device_id: your_device_id
    data: {}
  - service: notify.your_notification_entity
    data:
      message: Nefit thermostat became Unavailable. Reloading
    enabled: false
mode: single

Hi Scotie, although the root cause of the issue is not yet solved this helps keep the nefit integration running in the mean time. Thanks!

AdeZwart commented 5 months ago

I have enabled debug logging and I've captured the following:

2024-01-08 13:44:16.995 ERROR (MainThread) [custom_components.nefiteasy] Unexpected error fetching nefiteasy data: 
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 300, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/nefiteasy/__init__.py", line 262, in _async_update_data
    await self.connect()
  File "/config/custom_components/nefiteasy/__init__.py", line 148, in connect
    self.nefit.get("/gateway/brandID")
  File "/usr/local/lib/python3.11/site-packages/aionefit/__init__.py", line 107, in get
    self.xmppclient.send_message(mto=self._to, mbody=msg)
  File "/usr/local/lib/python3.11/site-packages/aionefit/provider/slixmpp_impl.py", line 93, in send_message
    message.stream.send_raw(str_data)
  File "/usr/local/lib/python3.11/site-packages/slixmpp/xmlstream/xmlstream.py", line 1354, in send_raw
    raise NotConnectedError()
slixmpp.xmlstream.xmlstream.NotConnectedError
2024-01-08 13:44:17.020 DEBUG (MainThread) [custom_components.nefiteasy] Finished fetching nefiteasy data in 0.032 seconds (success: False)
2024-01-08 13:44:18.301 DEBUG (MainThread) [aionefit.provider.slixmpp_impl] auth_success event: <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">[REDACTED]</success>
2024-01-08 13:45:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Starting reconnect procedure.
2024-01-08 13:45:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Start connecting.
2024-01-08 13:45:16.990 DEBUG (MainThread) [custom_components.nefiteasy] Connection procedure is already running.
2024-01-08 13:45:16.990 DEBUG (MainThread) [custom_components.nefiteasy] Finished fetching nefiteasy data in 0.002 seconds (success: False)
2024-01-08 13:46:16.988 DEBUG (MainThread) [custom_components.nefiteasy] Starting reconnect procedure.
2024-01-08 13:46:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Start connecting.
2024-01-08 13:46:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Connection procedure is already running.
2024-01-08 13:46:16.990 DEBUG (MainThread) [custom_components.nefiteasy] Finished fetching nefiteasy data in 0.002 seconds (success: False)
2024-01-08 13:47:16.993 DEBUG (MainThread) [custom_components.nefiteasy] Starting reconnect procedure.
2024-01-08 13:47:16.994 DEBUG (MainThread) [custom_components.nefiteasy] Start connecting.
2024-01-08 13:47:16.994 DEBUG (MainThread) [custom_components.nefiteasy] Connection procedure is already running.
2024-01-08 13:47:16.995 DEBUG (MainThread) [custom_components.nefiteasy] Finished fetching nefiteasy data in 0.002 seconds (success: False)
2024-01-08 13:48:16.988 DEBUG (MainThread) [custom_components.nefiteasy] Starting reconnect procedure.
2024-01-08 13:48:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Start connecting.
2024-01-08 13:48:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Connection procedure is already running.
2024-01-08 13:48:16.990 DEBUG (MainThread) [custom_components.nefiteasy] Finished fetching nefiteasy data in 0.002 seconds (success: False)
2024-01-08 13:49:16.988 DEBUG (MainThread) [custom_components.nefiteasy] Starting reconnect procedure.
2024-01-08 13:49:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Start connecting.
2024-01-08 13:49:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Connection procedure is already running.
2024-01-08 13:49:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Finished fetching nefiteasy data in 0.001 seconds (success: False)
2024-01-08 13:50:16.988 DEBUG (MainThread) [custom_components.nefiteasy] Starting reconnect procedure.
2024-01-08 13:50:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Start connecting.
2024-01-08 13:50:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Connection procedure is already running.
2024-01-08 13:50:16.990 DEBUG (MainThread) [custom_components.nefiteasy] Finished fetching nefiteasy data in 0.002 seconds (success: False)
2024-01-08 13:51:16.988 DEBUG (MainThread) [custom_components.nefiteasy] Starting reconnect procedure.
2024-01-08 13:51:16.988 DEBUG (MainThread) [custom_components.nefiteasy] Start connecting.
2024-01-08 13:51:16.988 DEBUG (MainThread) [custom_components.nefiteasy] Connection procedure is already running.
2024-01-08 13:51:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Finished fetching nefiteasy data in 0.001 seconds (success: False)
2024-01-08 13:52:16.988 DEBUG (MainThread) [custom_components.nefiteasy] Starting reconnect procedure.
2024-01-08 13:52:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Start connecting.
2024-01-08 13:52:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Connection procedure is already running.
2024-01-08 13:52:16.989 DEBUG (MainThread) [custom_components.nefiteasy] Finished fetching nefiteasy data in 0.001 seconds (success: False)

The logs about the reconnect procedure keep repeating until I reload the integration.

sanderlv commented 5 months ago

I have this issue lately (about 3-4-5 days)...

https://github.com/ksya/ha-nefiteasy/issues/289#issuecomment-1885472374

Is it related or something else?

RobBie1221 commented 5 months ago

Please try the newest version 0.4.1, this should be fixed. If not create a new issue with updated logs.