masaccio/ha-kingspan-watchman-sensit

Integration - stops updating after a while

Closed this issue · 10 comments

Just installed this HA integration a few days ago. It's very good, many thanks for the time and effort.

I have the polling time set to 1 hr.

I am finding that the integration does not update after a while - see log below from 19/10 3am-10am. Seems to be some sort of error logging in?

When I restart HA everything starts working OK again.

023-10-19 03:43:50.850 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Found tank name 'MV'
2023-10-19 03:43:50.850 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Finished fetching kingspan_watchman_sensit data in 1.785 seconds (success: True)
2023-10-19 03:43:50.850 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Read oil level: 955 litres
2023-10-19 03:43:50.850 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Read oil level: 53.1 percent
2023-10-19 03:43:50.850 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Read tank capcity: 1800 litres
2023-10-19 03:43:50.851 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Tank last read 2023-10-18 03:05:58.723000+01:00
2023-10-19 03:43:50.851 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Current oil usage 4 days
2023-10-19 03:43:50.851 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Tank forecast empty 208 days
2023-10-19 04:43:51.064 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Fetching tank data with username=mike.eales@gmail.com
2023-10-19 04:43:52.168 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Tank data: level=955, capacity=1800, serial_number=20003530,last_read=2023-10-18 03:05:58.723000+01:00, usage_rate=4.6, forecast_empty=208
2023-10-19 04:43:52.168 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Found tank name 'MV'
2023-10-19 04:43:52.168 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Finished fetching kingspan_watchman_sensit data in 1.104 seconds (success: True)
2023-10-19 04:43:52.168 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Read oil level: 955 litres
2023-10-19 04:43:52.169 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Read oil level: 53.1 percent
2023-10-19 04:43:52.169 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Read tank capcity: 1800 litres
2023-10-19 04:43:52.169 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Tank last read 2023-10-18 03:05:58.723000+01:00
2023-10-19 04:43:52.169 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Current oil usage 4 days
2023-10-19 04:43:52.169 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Tank forecast empty 208 days
2023-10-19 05:43:52.065 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Fetching tank data with username=mike.eales@gmail.com
2023-10-19 05:43:52.780 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Tank data: level=955, capacity=1800, serial_number=20003530,last_read=2023-10-18 03:05:58.723000+01:00, usage_rate=4.6, forecast_empty=208
2023-10-19 05:43:52.780 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Found tank name 'MV'
2023-10-19 05:43:52.780 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Finished fetching kingspan_watchman_sensit data in 0.716 seconds (success: True)
2023-10-19 05:43:52.781 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Read oil level: 955 litres
2023-10-19 05:43:52.781 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Read oil level: 53.1 percent
2023-10-19 05:43:52.781 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Read tank capcity: 1800 litres
2023-10-19 05:43:52.781 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Tank last read 2023-10-18 03:05:58.723000+01:00
2023-10-19 05:43:52.781 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Current oil usage 4 days
2023-10-19 05:43:52.782 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Tank forecast empty 208 days
2023-10-19 06:43:53.065 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Fetching tank data with username=mike.eales@gmail.com
2023-10-19 06:43:53.535 ERROR (MainThread) [custom_components.kingspan_watchman_sensit] Unhandled error logging in as mike.eales@gmail.com:
2023-10-19 06:43:53.536 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Finished fetching kingspan_watchman_sensit data in 0.471 seconds (success: True)
File "/config/custom_components/kingspan_watchman_sensit/sensor.py", line 54, in native_value
2023-10-19 07:43:53.064 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Fetching tank data with username=mike.eales@gmail.com
2023-10-19 07:43:53.196 ERROR (MainThread) [custom_components.kingspan_watchman_sensit] Unhandled error logging in as mike.eales@gmail.com: [SSL: UNEXPECTED_EOF_WHILE_READING] EOF occurred in violation of protocol (_ssl.c:1006)
2023-10-19 07:43:53.200 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Finished fetching kingspan_watchman_sensit data in 0.136 seconds (success: True)
File "/config/custom_components/kingspan_watchman_sensit/sensor.py", line 54, in native_value
2023-10-19 08:43:53.064 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Fetching tank data with username=mike.eales@gmail.com
2023-10-19 08:43:53.194 ERROR (MainThread) [custom_components.kingspan_watchman_sensit] Unhandled error logging in as mike.eales@gmail.com: [SSL: UNEXPECTED_EOF_WHILE_READING] EOF occurred in violation of protocol (_ssl.c:1006)
2023-10-19 08:43:53.198 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Finished fetching kingspan_watchman_sensit data in 0.133 seconds (success: True)
File "/config/custom_components/kingspan_watchman_sensit/sensor.py", line 54, in native_value
File "/config/custom_components/kingspan_watchman_sensit/sensor.py", line 54, in native_value
2023-10-19 09:43:53.064 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Fetching tank data with username=mike.eales@gmail.com
2023-10-19 09:43:53.447 ERROR (MainThread) [custom_components.kingspan_watchman_sensit] Unhandled error logging in as mike.eales@gmail.com:
2023-10-19 09:43:53.448 DEBUG (MainThread) [custom_components.kingspan_watchman_sensit] Finished fetching kingspan_watchman_sensit data in 0.384 seconds (success: True)
File "/config/custom_components/kingspan_watchman_sensit/sensor.py", line 54, in native_value

Has it completely stopped updating? The errors are suggesting that the Kingspan server is closing the connection on you. I don't know whether that's because it's objecting to hourly updates, but that hardly seems an unreasonable refresh rate.

If it's an intermittent problem, then all I could do is handle the error and ignore it (which is what is happening).

I could add a debug switch to allow logging of the underlying transport between Kingspan and you though you'd need to be super-careful with that data as it would include your password.

OK let me add a switch to enable Zeep transport debug and they you can at least see what's happening between HA and Kingspan. Maybe there are some HTTP/SOAP errors that give some clues.

Yes it would need to be a new version. I don't know a way of injecting Python code into a running integration and that's what is needed to enable Zeep debug.

Updated in v1.6.0. The logs will get raw SOAP queries dumped into them. Hopefully you can spot some errors there. If you do end up sharing, PLEASE EDIT OUT PASSWORDS and you might want to zip too as it's very verbose. This is a public issue tracker.

Added better error handling in v1.6.1