The unit of sensor.wiser_lts [...] (°C) cannot be converted to the unit of previously compiled statistics (None).

[Chaoscontrol]

For a while now I've been getting these types of warnings in the HA log. Usually once every day or so.

The unit of sensor.wiser_lts_target_temperature_main_bedroom (°C) cannot be converted to the unit of previously compiled statistics (None). Generation of long term statistics will be suppressed unless the unit changes back to None or a compatible unit. Go to https://my.home-assistant.io/redirect/developer_statistics to fix this

I'm not sure if it's always the same sensor or it keeps changing. I usually just follow the instructions and apply the "fix" as instructed. But that only solves the issue temporarily, until the warning shows up again.
I'm pretty sure the unit keeps getting changed from None to C, and then back again. Which repeatedly triggers the warning even after it being fixed.

Which led me to believe there is an actual issue with the integration. It's been happening for weeks if not months, over updates as well.

Integration v3.4.2.
HA:

Core
2024.1.6
Supervisor
2023.12.1
Operating System
11.4
Frontend
20240104.0

HubR, with single channel, on a combi boiler without OpenTherm. Firm 3.14.0.

[msp1974]

Can you tell me if there are any automations or things that you do (such as turning off heating etc) in that room.

[Chaoscontrol]

It's just an example room, as I said, it's not always the same one.

There are no automations at all with any of the room devices. Only a single automation within the hub itself, to switch the away mode based on geolocation. I don't think this is related. This triggers about once a week as we work from home, and it just toggles the thing.

Here it is:

alias: Home Proximity
description: ""
trigger:
  - platform: numeric_state
    entity_id: proximity.home
    above: 3
    for:
      hours: 0
      minutes: 0
      seconds: 0
    id: away
  - platform: numeric_state
    entity_id: proximity.home
    for:
      hours: 0
      minutes: 0
      seconds: 0
    id: near-home
    below: 3
condition: []
action:
  - choose:
      - conditions:
          - condition: trigger
            id: away
        sequence:
          - type: turn_on
            device_id: 8f7b3c13e63e5fd07bcad676d0f76ca8
            entity_id: switch.wiser_away_mode
            domain: switch
          - service: light.turn_off
            data: {}
            target:
              entity_id: all
          - service: notify.mobile_app_xiaomi_12_lite_ax
            data:
              title: Everyone left home
              message: "Heating and lights switched off. "
      - conditions:
          - condition: trigger
            id: near-home
        sequence:
          - type: turn_off
            device_id: 8f7b3c13e63e5fd07bcad676d0f76ca8
            entity_id: switch.wiser_away_mode
            domain: switch
          - device_id: 255599bab4f8d77d4b7f2ff74dc494a1
            domain: mobile_app
            type: notify
            message: "Heating switched to schedule. "
            title: Someone is heading home.
mode: single

[Chaoscontrol]

Just adding that after update to 2024.2.0 it's still happening, and I believe it has happened at the same time of the day than last time, and same sensor too... Will leave a note here and keep monitoring.

Last logged: 8 February 2024 at 21:05:10

The unit of sensor.wiser_lts_target_temperature_main_bedroom (°C) cannot be converted to the unit of previously compiled statistics (None). Generation of long term statistics will be suppressed unless the unit changes back to None or a compatible unit. Go to https://my.home-assistant.io/redirect/developer_statistics to fix this

[msp1974]

Please do as not seeing anyone else report this, so not sure why there is a stat entry with a None uom. I will dig into the code more but any further info on what manual or schedule actions might happen on that room would be helpful.

[Chaoscontrol]

Bingo.

2024-02-09 21:05:10.185 WARNING (Recorder) [homeassistant.components.sensor.recorder] The unit of sensor.wiser_lts_target_temperature_main_bedroom (°C) cannot be converted to the unit of previously compiled statistics (None). Generation of long term statistics will be suppressed unless the unit changes back to None or a compatible unit. Go to https://my.home-assistant.io/redirect/developer_statistics to fix this

Seems to be daily, at exactly the same time. There have been restarts and updates in between too. And at least these last few days it has been the exact same sensor.

There are no automations handling this device as I mentioned, so I'm unsure what triggers this.

Also, have a look at the logbook in the screenshot. Notice how the sensor (this happens with all wiser sensors repeatedly) becomes unavailable over and over, for only a few seconds, but very often. This is another issue that has been happening for a LONG time. I didn't want to raise it as I heard it was due to connection issues with the hub, but at this point I'm not sure if that's how all the users live. Don't think it's related to the topic here though, but just in case.

[msp1974]

I suspect it is related and this shouldn't be happening. Can you post screenshot as think you missed it. Can you also look at your hub signal entity attributes and see how long your hub has been up?

Edit: sorry seen the link.

[Chaoscontrol]

Here: https://file.coffee/u/EJFxeDJkCOfjx7xfgQitV.webm
Forgive the mouse offset location, having issues with the recorder.
4h uptime atm. See the log and you can see that it gets unsavailable about 4 times per hour. Not equally spaced, and not equally long either. I've lived with it for a long while now.

Adding a few more errors from the log. Always assumed to be unrelated, and was planning to raise as issues at some point, but wanted to avoid overwhelming you...

[msp1974]

OK, I this is clearly your hub sending some erroneous data, which is the root cause of these issues. Need to think how we capture this to see what it is or whether I can check the data better and accommodate it. Give me a few days.

[msp1974]

I have just released v3.4.3 to fix an issue in passive mode. The update to the api included some better error handling for your issue. Can you upgrade and let me know if you still see these errors/different errors etc.

Thx

[Chaoscontrol]

Lovely! Just updated, can confirm the HVAC error is gone as that one appeared right off the bat.
On first reboot it showed a new error, but I just rebooted again and it's not showing up again so far. Will monitor through today and report back.

But seems promising! Many thanks!

[Chaoscontrol]

Yep, new warning is showing again.

This error originated from a custom integration.

Logger: custom_components.wiser.coordinator
Source: custom_components/wiser/coordinator.py:147
Integration: Drayton Wiser Integration for Home Assistant (documentation, issues)
First occurred: 10:10:24 (3 occurrences)
Last logged: 10:43:37

JSON decoding error from http://192.168.1.186:80/data/v2/domain/. Error is - Unterminated string starting at: line 1 column 4217 (char 4216). Data is - b'{"System":{"PairingStatus":"Paired","provisionTokenSucceedCount":1,"provisionTokenFailCount":2255,"provisionTokenRequestCount":2256,"TimeZoneOffset":0,"AutomaticDaylightSaving":false,"SystemMode":"Heat","FotaEnabled":true,"ValveProtectionEnabled":true,"EcoModeEnabled":false,"AwayModeAffectsHotWater":true,"AwayModeSetPointLimit":160,"BoilerSettings":{"ControlType":"HeatSourceType_RelayControlled","FuelType":"Gas","CycleRate":"CPH_6","OnOffHysteresis":5},"CoolingModeDefaultSetpoint":210,"CoolingAwayModeSetpointLimit":-200,"ComfortModeEnabled":false,"PreheatTimeLimit":10800,"DegradedModeSetpointThreshold":180,"GeoPosition":{"Latitude":53.3808,"Longitude":-2.16803},"UfhOrphanModeOutput":"On","isMigrated":false,"UnixTime":1709287800,"ActiveSystemVersion":"3.14.0-83886524ef","BrandName":"WiserHeat","CloudConnectionStatus":"Connected","ChipId":"0xa1120e00","LocalDateAndTime":{"Year":2024,"Month":"March","Date":1,"Day":"Friday","Time":1010},"HeatingButtonOverrideState":"Off","HotWaterButtonOverrideState":"Off","OpenThermConnectionStatus":"Disconnected","SunriseTimes":[709,706,704,702,700,657,655,653,650,648,646,643,641],"SunsetTimes":[1736,1738,1740,1742,1744,1746,1748,1750,1752,1754,1755,1757,1759],"isTrialist":false,"isProvisioned":true,"HardwareGeneration":1},"Cloud":{"DetailedPublishing":true,"EnableFullScheduleTelemetry":false,"BlockPublishing":{"RoomTimeSeries":false,"EcoMode":false,"BoilerOnOffEvent":true,"HotWaterOnOffEvent":true,"PercentageDemand":true,"FotaProgress":false,"SupportPackage":false,"PairingToken":false,"Notification":false,"Describe":false,"EntireDataModel":false,"ScheduleUpdate":false,"SmartPlugUpdate":false,"LightUpdate":false,"ShutterUpdate":false,"TemperatureChangeEvent":false,"EventSeriesDiagnostic":false},"WiserApiHost":"api-nl.wiserair.com","BootStrapApiHost":"bootstrap.gl.struxurewarecloud.com"},"HeatingChannel":[{"id":1,"Name":"Channel-1","RoomIds":[2,3,4,5],"PercentageDemand":100,"DemandOnOffOutput":"On","HeatingRelayState":"On","IsSmartValvePreventingDemand":false}],"Room":[{"id":2,"ManualSetPoint":-200,"ScheduleId":3,"ComfortModeScore":3898,"HeatingRate":2962,"RoomStatId":1,"SmartValveIds":[9,7,3],"Name":"Living room","Mode":"Auto","DemandType":"Modulating","WindowDetectionActive":true,"CalculatedTemperature":192,"CurrentSetPoint":210,"PercentageDemand":100,"ControlOutputState":"On","WindowState":"Closed","SetpointOrigin":"FromSchedule","DisplayedSetPoint":210,"ScheduledSetPoint":210,"RoundedAlexaTemperature":190,"EffectiveMode":"Auto","PercentageDemandForItrv":100,"ControlDirection":"Heat","HeatingType":"HydronicRadiator"},{"id":3,"ManualSetPoint":170,"ScheduleId":4,"ComfortModeScore":2920,"HeatingRate":1864,"SmartValveIds":[8],"Name":"Guest bedroom","Mode":"Auto","DemandType":"Modulating","WindowDetectionActive":true,"CalculatedTemperature":159,"CurrentSetPoint":160,"PercentageDemand":0,"ControlOutputState":"Off","WindowState":"Closed","SetpointOrigin":"FromSchedule","DisplayedSetPoint":160,"ScheduledSetPoint":160,"RoundedAlexaTemperature":160,"EffectiveMode":"Auto","PercentageDemandForItrv":0,"ControlDirection":"Heat","HeatingType":"HydronicRadiator"},{"id":4,"ManualSetPoint":-200,"ScheduleId":5,"ComfortModeScore":2995,"HeatingRate":1758,"SmartValveIds":[5],"Name":"Main bedroom","Mode":"Auto","DemandType":"Modulating","WindowDetectionActive":true,"CalculatedTemperature":146,"CurrentSetPoint":-200,"PercentageDemand":0,"ControlOutputState":"Off","WindowState":"Closed","SetpointOrigin":"FromSchedule","DisplayedSetPoint":-200,"ScheduledSetPoint":-200,"RoundedAlexaTemperature":145,"EffectiveMode":"Auto","PercentageDemandForItrv":0,"ControlDirection":"Heat","HeatingType":"HydronicRadiator"},{"id":5,"ManualSetPoint":210,"ScheduleId":4,"ComfortModeScore":344,"HeatingRate":636,"SmartValveIds":[6],"Name":"Kitchen","Mode":"Auto","DemandType":"Modulating","WindowDetectionActive":true,"CalculatedTemperature":164,"CurrentSetPoint":160,"PercentageDemand":0,"ControlOutputState":"Off","WindowState":"Closed","SetpointOrigin":"FromSchedule","DisplayedSetPoint":160,"ScheduledSetPoint":160,"RoundedAlexaTemperature":165,"EffectiveMode":"Auto","PercentageDemandForItrv":0,"ControlDirection":"Heat","HeatingType":"HydronicRadiator"}],"Dev'
JSON decoding error from http://192.168.1.186:80/data/v2/domain/. Error is - Expecting value: line 1 column 2789 (char 2788). Data is - b'{"System":{"PairingStatus":"Paired","provisionTokenSucceedCount":1,"provisionTokenFailCount":2255,"provisionTokenRequestCount":2256,"TimeZoneOffset":0,"AutomaticDaylightSaving":false,"SystemMode":"Heat","FotaEnabled":true,"ValveProtectionEnabled":true,"EcoModeEnabled":false,"AwayModeAffectsHotWater":true,"AwayModeSetPointLimit":160,"BoilerSettings":{"ControlType":"HeatSourceType_RelayControlled","FuelType":"Gas","CycleRate":"CPH_6","OnOffHysteresis":5},"CoolingModeDefaultSetpoint":210,"CoolingAwayModeSetpointLimit":-200,"ComfortModeEnabled":false,"PreheatTimeLimit":10800,"DegradedModeSetpointThreshold":180,"GeoPosition":{"Latitude":53.3808,"Longitude":-2.16803},"UfhOrphanModeOutput":"On","isMigrated":false,"UnixTime":1709288280,"ActiveSystemVersion":"3.14.0-83886524ef","BrandName":"WiserHeat","CloudConnectionStatus":"Connected","ChipId":"0xa1120e00","LocalDateAndTime":{"Year":2024,"Month":"March","Date":1,"Day":"Friday","Time":1018},"HeatingButtonOverrideState":"Off","HotWaterButtonOverrideState":"Off","OpenThermConnectionStatus":"Disconnected","SunriseTimes":[709,706,704,702,700,657,655,653,650,648,646,643,641],"SunsetTimes":[1736,1738,1740,1742,1744,1746,1748,1750,1752,1754,1755,1757,1759],"isTrialist":false,"isProvisioned":true,"HardwareGeneration":1},"Cloud":{"DetailedPublishing":true,"EnableFullScheduleTelemetry":false,"BlockPublishing":{"RoomTimeSeries":false,"EcoMode":false,"BoilerOnOffEvent":true,"HotWaterOnOffEvent":true,"PercentageDemand":true,"FotaProgress":false,"SupportPackage":false,"PairingToken":false,"Notification":false,"Describe":false,"EntireDataModel":false,"ScheduleUpdate":false,"SmartPlugUpdate":false,"LightUpdate":false,"ShutterUpdate":false,"TemperatureChangeEvent":false,"EventSeriesDiagnostic":false},"WiserApiHost":"api-nl.wiserair.com","BootStrapApiHost":"bootstrap.gl.struxurewarecloud.com"},"HeatingChannel":[{"id":1,"Name":"Channel-1","RoomIds":[2,3,4,5],"PercentageDemand":90,"DemandOnOffOutput":"On","HeatingRelayState":"On","IsSmartValvePreventingDemand":false}],"Room":[{"id":2,"ManualSetPoint":-200,"ScheduleId":3,"ComfortModeScore":3898,"HeatingRate":2962,"RoomStatId":1,"SmartValveIds":[9,7,3],"Name":"Living room","Mode":"Auto","DemandType":"Modulating","WindowDetectionActive":true,"CalculatedTemperature":194,"CurrentSetPoint":210,"PercentageDemand":90,"ControlOutputState":"On","WindowState":"Closed","SetpointOrigin":"FromSchedule","DisplayedSetPoint":210,"ScheduledSetPoint":210,"RoundedAlexaTemperature":195,"EffectiveMode":"Auto","PercentageDemandForItrv":90,"ControlDirection":"Heat","HeatingType":"HydronicRadiator"},{"id":3,"ManualSetPoint":170,"ScheduleId":4,"ComfortModeScore":2920,"HeatingRate":1864,"SmartValveIds":[8],"Name":"Guest bedroom","Mode":"Auto","DemandType":"Modulating","WindowDetectionActive":tr'
JSON decoding error from http://192.168.1.186:80/data/v2/domain/. Error is - Expecting value: line 1 column 2789 (char 2788). Data is - b'{"System":{"PairingStatus":"Paired","provisionTokenSucceedCount":1,"provisionTokenFailCount":2255,"provisionTokenRequestCount":2256,"TimeZoneOffset":0,"AutomaticDaylightSaving":false,"SystemMode":"Heat","FotaEnabled":true,"ValveProtectionEnabled":true,"EcoModeEnabled":false,"AwayModeAffectsHotWater":true,"AwayModeSetPointLimit":160,"BoilerSettings":{"ControlType":"HeatSourceType_RelayControlled","FuelType":"Gas","CycleRate":"CPH_6","OnOffHysteresis":5},"CoolingModeDefaultSetpoint":210,"CoolingAwayModeSetpointLimit":-200,"ComfortModeEnabled":false,"PreheatTimeLimit":10800,"DegradedModeSetpointThreshold":180,"GeoPosition":{"Latitude":53.3808,"Longitude":-2.16803},"UfhOrphanModeOutput":"On","isMigrated":false,"UnixTime":1709289780,"ActiveSystemVersion":"3.14.0-83886524ef","BrandName":"WiserHeat","CloudConnectionStatus":"Connected","ChipId":"0xa1120e00","LocalDateAndTime":{"Year":2024,"Month":"March","Date":1,"Day":"Friday","Time":1043},"HeatingButtonOverrideState":"Off","HotWaterButtonOverrideState":"Off","OpenThermConnectionStatus":"Disconnected","SunriseTimes":[709,706,704,702,700,657,655,653,650,648,646,643,641],"SunsetTimes":[1736,1738,1740,1742,1744,1746,1748,1750,1752,1754,1755,1757,1759],"isTrialist":false,"isProvisioned":true,"HardwareGeneration":1},"Cloud":{"DetailedPublishing":true,"EnableFullScheduleTelemetry":false,"BlockPublishing":{"RoomTimeSeries":false,"EcoMode":false,"BoilerOnOffEvent":true,"HotWaterOnOffEvent":true,"PercentageDemand":true,"FotaProgress":false,"SupportPackage":false,"PairingToken":false,"Notification":false,"Describe":false,"EntireDataModel":false,"ScheduleUpdate":false,"SmartPlugUpdate":false,"LightUpdate":false,"ShutterUpdate":false,"TemperatureChangeEvent":false,"EventSeriesDiagnostic":false},"WiserApiHost":"api-nl.wiserair.com","BootStrapApiHost":"bootstrap.gl.struxurewarecloud.com"},"HeatingChannel":[{"id":1,"Name":"Channel-1","RoomIds":[2,3,4,5],"PercentageDemand":90,"DemandOnOffOutput":"On","HeatingRelayState":"On","IsSmartValvePreventingDemand":false}],"Room":[{"id":2,"ManualSetPoint":-200,"ScheduleId":3,"ComfortModeScore":3898,"HeatingRate":2962,"RoomStatId":1,"SmartValveIds":[9,7,3],"Name":"Living room","Mode":"Auto","DemandType":"Modulating","WindowDetectionActive":true,"CalculatedTemperature":196,"CurrentSetPoint":210,"PercentageDemand":90,"ControlOutputState":"On","WindowState":"Closed","SetpointOrigin":"FromSchedule","DisplayedSetPoint":210,"ScheduledSetPoint":210,"RoundedAlexaTemperature":195,"EffectiveMode":"Auto","PercentageDemandForItrv":93,"ControlDirection":"Heat","HeatingType":"HydronicRadiator"},{"id":3,"ManualSetPoint":170,"ScheduleId":4,"ComfortModeScore":2920,"HeatingRate":1864,"SmartValveIds":[8],"Name":"Guest bedroom","Mode":"Auto","DemandType":"Modulating","WindowDetectionActive":tr'

[msp1974]

OK good (he says!) that's what I wanted to capture if it happened again. I'll look at this data and see what's wrong and if we can overcome it.

[msp1974]

Right, I think we have got to the bottom of the issue - whether we have got the fix is another question! :-)

So, it seems your and @dpgh947 issues are caused by your hubs sending the response chunked. Previous work to fix the issues with changes in aiohttp, forced use of http/1.0 which does not support chunked responses. As such, you only get a partial response which is not valid json (and also not enough to be of use anyway).

So the answer is to try and use http/1.1 (which supports chunking) and see if that fixes it out of the box or it needs something more to get all these chunks and put them together.

My hub is not doing this (seems only a very few are), so would appreciate if you can try something for me to test if we have fixed it or need to do more work.

In your config/custom_components/wiser directory you have a manifest.json file. In there, you will see a reference to aiowiserheatapi with a version of 1.5.7. Can you change this to 1.5.8, save the file and restart HA. Then tell me if you are still getting these errors or not.

If this fixes it, I will release this update to everybody as it may be affecting more people than are reporting it.

Thanks

[dpgh947]

Mine is currently 1.5.5 (I'm on 3.4.2)...... I just looked on hacs and an update 3.4.3 popped up so I will install that first. I don't get these errors very often.

[Chaoscontrol]

I did so, it seems it's showing this message now:

This error originated from a custom integration.

Logger: custom_components.wiser.coordinator
Source: custom_components/wiser/coordinator.py:147
Integration: Drayton Wiser Integration for Home Assistant (documentation, issues)
First occurred: 13:24:43 (14 occurrences)
Last logged: 14:40:09

Response error trying to communicate with Wiser Hub 192.168.1.186 for url http://192.168.1.186:80/data/v2/schedules/. Error is 400, message="Data after `Connection: close`:\n\n b'0'\n ^", url=URL('http://192.168.1.186:80/data/v2/schedules/')

[msp1974]

See I almost knew that would happen!!! So, as schedules are very long, I thought that may chunk too but maybe not. Give it about 10 mins and change the same entry in manifest.json to 1.5.9 and try again.

If you still get these errors (or back to previous error) then, think I'll have to rework some sort of retry routine as this is a very inconsistant issue (ie it works and then it doesnt and then it does and then it doesnt .. etc etc etc)

EDIT: Good news however is it has got beyond where it was erroring before!

[Chaoscontrol]

Looks promising! 25min and no error after reboot so far. Will keep an eye and report back tonight or after 24h.

[Chaoscontrol]

Nooooo. :( It showed up again.

This error originated from a custom integration.

Logger: custom_components.wiser.coordinator
Source: custom_components/wiser/coordinator.py:147
Integration: Drayton Wiser Integration for Home Assistant (documentation, issues)
First occurred: 16:15:00 (1 occurrences)
Last logged: 16:15:00

JSON decoding error from http://192.168.1.186:80/data/v2/network/. Error is - Unterminated string starting at: line 1 column 1345 (char 1344). Data is - b'{"AccessPoint":{"Enabled":false,"Channel":1,"SecurityMode":"Open","MacAddress":"FCFEC204B0AC","NetworkInterface":{"InterfaceName":"wlan1","HostName":"WiserHeat04B0AC","DhcpMode":"Server","IPv4HostAddress":"192.168.8.1","IPv4SubnetMask":"255.255.255.0","IPv4DefaultGateway":"0.0.0.0","IPv4PrimaryDNS":"192.168.8.1","IPv4SecondaryDNS":"0.0.0.0"}},"Station":{"Enabled":true,"SSID":"Ax","SecurityMode":"WPA_WPA2_PSK","ScanSlotTime":20,"ScanSlots":2,"NetworkInterface":{"InterfaceName":"wlan0","HostName":"WiserHeat04B0AC","DhcpMode":"Client"},"ConnectionStatus":"Connected","DhcpStatus":{"Status":"BOUND","LeaseStartTime":1743781766,"LeaseTime":43200,"IPv4Address":"192.168.1.186","IPv4SubnetMask":"255.255.255.0","IPv4DefaultGateway":"192.168.1.1","IPv4PrimaryDNS":"192.168.1.1","IPv4SecondaryDNS":"0.0.0.0"},"Scanning":false,"DetectedAccessPoints":[{"SSID":"Ax","Channel":1,"SecurityMode":"WPA_WPA2_PSK","RSSI":-58},{"SSID":"TALKTALK72BCB3","Channel":6,"SecurityMode":"WPA_WPA2_PSK","RSSI":-73},{"SSID":"SLZB-06_181072","Channel":1,"SecurityMode":"Open","RSSI":-81},{"SSID":"PLUSNET-9M6C-2.4G-extender","Channel":6,"SecurityMode":"WPA_WPA2_PSK","RSSI":-82}],"ConnectionFailures":0,"MdnsHostname":"WiserHeat04B0AC","MacAddress":"FCFEC204B0AC","RSSI":{"Current":-77,"Min":-81,"Max":-55},"Channel":1},"HealthCheckStats":{"IPv4AddressPing":"1.1.1.1","HealthCheckingE'

Also noticed the sensors going regularly unavailable is also still happening. This happens for all the room sensors, and all simultaneously. It doesn't match with the log warnings or anything though.

What I'm not seeing today are the living room sensor temp drops to 0.

Edit: also reporting the same error about the unit statistics keeps showing up at the same time every day for that specific sensor.

Logger: homeassistant.components.sensor.recorder
Source: components/sensor/recorder.py:245
Integration: Sensor (documentation, issues)
First occurred: 21:05:10 (1 occurrences)
Last logged: 21:05:10

The unit of sensor.wiser_lts_target_temperature_main_bedroom (°C) cannot be converted to the unit of previously compiled statistics (None). Generation of long term statistics will be suppressed unless the unit changes back to None or a compatible unit. Go to https://my.home-assistant.io/redirect/developer_statistics to fix this

[Chaoscontrol]

To add more info. After every HA reboot now I'm getting:

This error originated from a custom integration.

Logger: custom_components.wiser.coordinator
Source: custom_components/wiser/coordinator.py:147
Integration: Drayton Wiser Integration for Home Assistant (documentation, issues)
First occurred: 10:33:44 (1 occurrences)
Last logged: 10:33:44

Response error trying to communicate with Wiser Hub 192.168.1.186 for url http://192.168.1.186:80/data/v2/domain/. Error is 400, message="Data after `Connection: close`:\n\n b'0'\n ^", url=URL('http://192.168.1.186:80/data/v2/domain/')

[msp1974]

Ok, so this is a royal PITA but I have made some adjustments to handle these response errors and issue retries. It seems to work on mine but can you give it a go. Amend the api version to 1.5.10

[Chaoscontrol]

Updated. Will monitor for a few hours and report back if get any errors.

[msp1974]

Hows it looking?

[Chaoscontrol]

Actually... great! I was holding off to report good news just in case errors showed up later... but not a single error has shown up so far for this last 5h. Not after a couple reboots either.

I have noticed the issue of all sensors going unavailable regularly, which I mentioned here. But apart from that, nothing in the log. Looks very promising.

[msp1974]

Ok, thats great but dont understand why all your sensors are going unavailable. Would have understood as updates were failing but now they are not, that makes no sense. I'll release this update as it has a lot of other fixes too and lets see how we get on.

I have noticed on mine that the performance of some actions are slower now and this enhancement may need some more work to improve that but think we have the foundation to work with.
Thanks for testing.

[Chaoscontrol]

Oh. It just came up, the daily error ar 21:05h again.

Logger: homeassistant.components.sensor.recorder
Source: components/sensor/recorder.py:245
Integration: Sensor (documentation, issues)
First occurred: 21:05:10 (1 occurrences)
Last logged: 21:05:10

The unit of sensor.wiser_lts_target_temperature_main_bedroom (°C) cannot be converted to the unit of previously compiled statistics (None). Generation of long term statistics will be suppressed unless the unit changes back to None or a compatible unit. Go to https://my.home-assistant.io/redirect/developer_statistics to fix this

[msp1974]

Yes, the fix for this will be in the release but you probably need to clear the history on it after updating.

[Chaoscontrol]

Just updated and the unit conversion error popped instantly now. What do you mean with clearing the history? Never done that before, not sure how it's done.

Logger: homeassistant.components.sensor.recorder
Source: components/sensor/recorder.py:245
Integration: Sensor (documentation, issues)
First occurred: 22:10:10 (1 occurrences)
Last logged: 22:10:10

The unit of sensor.wiser_lts_target_temperature_main_bedroom (°C) cannot be converted to the unit of previously compiled statistics (None). Generation of long term statistics will be suppressed unless the unit changes back to None or a compatible unit. Go to https://my.home-assistant.io/redirect/developer_statistics to fix this

And also this new error has started appearing.

This error originated from a custom integration.

Logger: custom_components.wiser.coordinator
Source: helpers/update_coordinator.py:319
Integration: Drayton Wiser Integration for Home Assistant (documentation, issues)
First occurred: 22:21:15 (6 occurrences)
Last logged: 23:31:11

Timeout fetching wiser (wiser-WiserHeat04B0AC) data

[msp1974]

Removing the integration and reinstalling it won't help, right?

No, thats not the issue.

The unavailable times from the room sensors do not match the timeouts in the log at all.

Is it just your climate entities going unavailable or all of them? I don't think they shouldn't go unavailable even if the hub fails to update. I'll need to check that. You could turn debug logging on for the api by adding the following to configuration.yaml:

logger:
    logs:
        aioWiserHeatAPI: debug

and see if that shows anything. It will be quite a bit of logging to go through though.

[Chaoscontrol]

Is it just your climate entities going unavailable or all of them?

All of them. However for some reason the sensors don't show it on the history or logbook. Only the climate entity does.

Ok, added the debug logs. Here they are. Cross searching the unavailable times, I can see the timeout matched the unavailable sensor at 18:31, but then the next ones didn't, and not even the debug log shows anything weird.
(18:31 matches, 18:48 matches, 18:52 doesn't match, 19:10 matches, 19:13 matches).
home-assistant_2024-03-05T19-13-57.515Z.log

You will also notice the log has some of the JSON decoding errors. But they are in the Debug level and not a warning anymore. Not sure if they are the same as past ones either. And their times don't match with the other 2 issues.

[msp1974]

So, they all match to a timeout but 1, so i focussed on that. If you look carefully, it never finished the update but no error of any kind (no attempt to get status and no update successdul with time taken). It then took another 5s before it went unavailable. Thats very odd - its like it just gave up. I wonder if it did timeout but the logging doesnt show this. I'll have a look at that.

The question of why it times out so often but your wifi doesnt show it disconnected. Im wondering if it does disconnect for a short time and your wifi doesnt show if short. On your hub wifi signal sensor, what does your uptime look like?

The json decode errors are fine. I am initially querying the hub on http1.0, which when the hub is not honoring this request properly and sends you a partial chunk, you will see it retries on http1.1 and is successful. It wil do this up to 5 times before it fails and it never does, apart from just timeouts.

[Chaoscontrol]

24 days uptime atm. You can also see the signal varies from very good, to good, sometimes medium. But the unavailable sections don't correlate to the medium or poor bits.

[msp1974]

Ok. Hold off on resetting your hub for a bit. I have a theory about the timeouts not being a http timeout but the async job that runs the update being cancelled before update completes as it took too long and it is actually that timing out. With more robust retry method it could be exceeding some timeout.

[msp1974]

So, spent more time looking at this and I don't think it is that but a hub connection timeout.

I have included timeouts in the retry logic so if it does timeout, then it will try again 5 times. I have also increased the http timeout from 10s to 20s, so if your hub has dropped off wifi for a short time, it has 100s to come back on before it classes it as an update fail. I did notice with my mesh wifi though that after he hub has not been on wifi for 30s or so, it comes back within 3s with a connect fail (presuming dropped out of wifi device registry and gets a no route to host type error) and does not wait the full 20s. If yours does this then it may fail update much sooner.

I have also added some more debug logging in the api to see what is going on and how long each request is taking when successful.

And, I have updated the integration to stop entities going unavailable if the update fails. I'm not 100% sure about that as it seems to be standard HA functionality to do that if the update fails but I'm just too much of a crowd pleaser! It will still raise a warning in the logs as I think it should otherwise we are masking issues and it may not be easy to diagnose other symptoms.

This will all be in v3.4.6 which I will release later. And then that will be the last release for a couple of months, but let me know how you get on.

[Chaoscontrol]

Thank you SO much for the hard work on this one. Eager to test it out and see how it goes on.

[Chaoscontrol]

Don't want to say it too loud just yet but... I updated to 3.4.6 this morning, and it's been 4h now and 0 errors in the log. It's true it's been in "Away mode" all this time since we're out, but I don't think that is related. I checked and sensors are still going unavailable at the same rate. But I feel it's great progress.
Here's the log.
home-assistant_2024-03-08T14-06-07.398Z.log

[msp1974]

Ok, checked through the log and it didnt fail update once but i did see the same update routine just didnt finish but no error or explanaition why. I wonder if HA is cancelling the task for some reason. Can you send me the logbook screenshot of one of these entities so i can see the times it went unavailable to match this log.

This is bizzare!

[msp1974]

Rather than me release yet another version, can you also modify an integration file for me to see if we can capture something.

In custom_components/wiser is a file coordinator.py

At the very bottom of this file, you will see

        except Exception as ex:  # pylint: disable=broad-except
            raise UpdateFailed(ex) from ex

can you change it to

        except Exception as ex:  # pylint: disable=broad-except
            _LOGGER.error(
                "Unknown error fetching wiser (%s) data. %s.  Please report this error to the integration owner",
                f"{DOMAIN}-{self.config_entry.data.get(CONF_NAME)}",
                ex,
            )

Make sure to keep the right indentation.

I think this may stop them going unavailable but log an error in the logs as to what has happened. I think maybe somehow related to these updates that don't complete (either success or failure).

You will need to restart HA for the change to take effect.

[Chaoscontrol]

Here. Did some OCR and formatting for easier read.

chrome_RLiCHUqLAG
chrome_DWQT5EOmQf
chrome_iM8JTQtsR6

8 March 2024
Wiser Living room changed to Auto 13:54:56
Wiser Living room became unavailable 13:54:23
Wiser Living room changed to Auto 13:46:14
Wiser Living room became unavailable 13:45:05
Wiser Living room changed to Auto 13:17:06
Wiser Living room became unavailable 13:16:36
Wiser Living room changed to Auto 12:52:37
Wiser Living room became unavailable 12:52:05
Wiser Living room changed to Auto 12:47:31
Wiser Living room became unavailable 12:46:19
Wiser Living room changed to Auto 12:38:05
Wiser Living room became unavailable 12:37:32
Wiser Living room changed to Auto 12:25:03
Wiser Living room became unavailable 12:24:27
Wiser Living room changed to Auto 12:22:17
Wiser Living room became unavailable 12:21:46
Wiser Living room changed to Auto 12:16:18
Wiser Living room became unavailable 12:15:44
Wiser Living room changed to Auto 12:07:33
Wiser Living room became unavailable 12:07:03
Wiser Living room changed to Auto 11:55:50
Wiser Living room became unavailable 11:54:41
Wiser Living room changed to Auto 11:14:24
Wiser Living room became unavailable 11:13:46
Wiser Living room changed to Auto 11:00:12
Wiser Living room became unavailable 10:59:42
Wiser Living room changed to Auto 10:57:04
Wiser Living room became unavailable 10:56:30
Wiser Living room changed to Auto 10:39:22
Wiser Living room became unavailable 10:38:47

Just saw your new message. Will check that now but leave this here in the meantime.

[msp1974]

Recording here for safe keeping. These are the times in your log see the issue of not finishing update. I expect these to correlate to your entities going unavailable. And, yes I can see it is happening a lot!

10:38:41, 10:56:25, 10:59:35, 11:13:38, 11:54:36, 11:55:10, 12:06:58, 12:15:38, 12:21:41, 12:24:19, 12:37:25, 12:46:13, 12:46:55, 12:51:57, 13:16:30, 13:45:00, 13:45:39, 13:54:16, 14:02:35

[msp1974]

So yes they do correlate. If you can make the change above, I'm hoping we will see what it is in the log pretty quickly.

[Chaoscontrol]

Yeah, I did it 30min ago, but now the fucker hasn't gone unavailable yet. Will report back as soon as it does.

[msp1974]

I don't think it will but you should have some errors in your HA log

[Chaoscontrol]

Here it is, but I don't see any. At least not errors per se.
home-assistant_2024-03-08T18-08-07.125Z.log

[msp1974]

OK, I can see the issue happening in the log but, I can't see an error logged either. This makes no sense!

[Chaoscontrol]

This looks alright, right?

[msp1974]

Yes spot on.

[Chaoscontrol]

No clue why then. Still no error or anything going unavailable.

[Chaoscontrol]

The dreaded 21:05 error about the units keeps happening immovable though. Log here, but doesn't say much.
home-assistant_2024-03-08T22-27-28.982Z.log

[msp1974]

You would have to clear the statistics for this entity before this will go once the issue has been fixed. Go into dev tools -> statistics and fix in there.

[Chaoscontrol]

Yeah, that seems to have fixed that error. It hasn't showed up in 2 or 3 days now.

Regarding the unavailable sensors, idk what's happened with it but the logbooks show completely empty now for the sensors. I have been messing with my db and I'm currently migrating, so it might not have anything to do with this issue. Will monitor once I'm done with the migration.

[Chaoscontrol]

Hey @msp1974, check it out.

I don't have a clue what happened. I have now completed my db migration, but still, even before that, it's been 7 days now and not a single sensor going unavailable anymore (I find it even suspicious given I've rebooted HA several times and it doesn't show...). Also the issue about the units hasn't shown up either since I cleared the statistics one last time.

So... I guess we can close the issue? Should I maybe reverse the manual changes you asked me to do? This and the API version. And getting the log back to normal. Let me know how I should leave them.

[Chaoscontrol]

Bump @msp1974 to close the issue as had no issues ever since my last message. Just would like confirmation what to do about the manual changes requested along the line.

[msp1974]

You can leave the changes as is and I will include them in the next release. I am leaving the issue open until it is released.

[Chaoscontrol]

Not sure why or what caused it (I've done no changes aside of updating HA), but the Living Room sensor drops to 0 have returned a few days ago. Once or twice a day.

The logbook doesn't register any change in the sensor. First one happened the 9th of April. I updated to HA 2024.4.2 on 8th of April 15:28h. It could be related. Updated to 2024.4.3 yesterday too and still happening.

[msp1974]

Closing as now released changes in v3.4.7