_presence_state sensor not updating in all climate entities

[maia]

I'm having an issue with the presence state sensor not being updated properly in all my (currently three) vtherm climate devices. All three are using the same presence sensor entity id.

I'm wondering how to properly debug the issue. Do you have any suggestions on debugging/logging, so I could report again in a few days? Thanks.

[maia]

The issue is continuing. And weirdly without logbook entry:

[jmcollin78]

Hello @maia ,

To diagnose this, you could post here the configuration of one VTherm which is working properly and one which is not working to see if there is a difference.

When the presence is detected or not, you should see this logs:

<thermostat name> -  Presence changed. Event.new_state is xxx

and then:

xxx - Someone is back home. Restoring temperature to... or xxx - No one is at home. Apply temperature ... depending of the case.

Example:

2023-10-14 07:26:43.181 INFO (MainThread) [custom_components.versatile_thermostat.climate] VersatileThermostat-Thermostat switch 1 - Presence changed. Event.new_state is <state input_boolean.fake_presence_sensor1=off; editable=False, icon=mdi:home, friendly_name=Presence Sensor 1 @ 2023-10-14T09:26:43.179360+02:00>, _attr_preset_mode=none, activity=activity
2023-10-14 07:26:43.181 DEBUG (MainThread) [custom_components.versatile_thermostat.climate] VersatileThermostat-Thermostat switch 1 - Updating presence. New state is off
2023-10-14 07:26:43.181 DEBUG (MainThread) [custom_components.versatile_thermostat.climate] VersatileThermostat-Thermostat switch 1 - Checking new cycle. hvac_mode=heat, security_state=False, preset_mode=none
2023-10-14 07:26:43.181 DEBUG (MainThread) [custom_components.versatile_thermostat.climate] VersatileThermostat-Thermostat switch 1 - overpowering check: power=450.000, max_power=910.000 heater power=300.000
2023-10-14 07:26:43.181 DEBUG (MainThread) [custom_components.versatile_thermostat.climate] VersatileThermostat-Thermostat switch 1 - checking security delta_temp=1.6 delta_ext_temp=1.6 mod_cond=True temp_cond=False climate_cond=False switch_cond=True
2023-10-14 07:26:43.181 DEBUG (MainThread) [custom_components.versatile_thermostat.underlyings] VersatileThermostat-Thermostat switch 1-input_boolean.fake_heater_switch1 - Starting new cycle hvac_mode=heat on_time_sec=60 off_time_sec=0 force=True
2023-10-14 07:26:43.181 DEBUG (MainThread) [custom_components.versatile_thermostat.underlyings] VersatileThermostat-Thermostat switch 1-input_boolean.fake_heater_switch1 - we force a new cycle
2023-10-14 07:26:43.181 DEBUG (MainThread) [custom_components.versatile_thermostat.underlyings] VersatileThermostat-Thermostat switch 1-input_boolean.fake_heater_switch1 - Stopping cycle during calculation
2023-10-14 07:26:43.181 DEBUG (MainThread) [custom_components.versatile_thermostat.underlyings] VersatileThermostat-Thermostat switch 1-input_boolean.fake_heater_switch1 - _async_cancel_cycle=<bound method TimerHandle.cancel of <TimerHandle when=65075.290258272 _run_async_call_action(<HomeAssistant RUNNING>, <Job call_lat...fff41b9f590>>>) at /workspaces/core/homeassistant/helpers/event.py:1438 created at /workspaces/core/homeassistant/helpers/event.py:1479>>
2023-10-14 07:26:43.182 DEBUG (MainThread) [custom_components.versatile_thermostat.climate] VersatileThermostat-Thermostat switch 1 - Calling update_custom_attributes: {'hvac_mode': 'heat', 'preset_mode': 'none', 'type': 'thermostat_over_switch', 'eco_temp': 17.0, 'boost_temp': 20.0, 'comfort_temp': 19.0, 'eco_away_temp': 16.1, 'boost_away_temp': 16.2, 'comfort_away_temp': 16.3, 'power_temp': 13.0, 'target_temp': 20.0, 'current_temp': 18.3, 'ext_current_temperature': 6.2, 'current_power': 450.0, 'current_power_max': 910.0, 'saved_preset_mode': 'none', 'saved_target_temp': 20.0, 'saved_hvac_mode': None, 'window_state': 'off', 'motion_state': 'off', 'overpowering_state': False, 'presence_state': 'off', 'window_auto_state': False, 'security_delay_min': 2, 'security_min_on_percent': 0.5, 'security_default_on_percent': 0.1, 'last_temperature_datetime': '2023-10-14T09:25:04.451560+02:00', 'last_ext_temperature_datetime': '2023-10-14T09:25:04.451760+02:00', 'security_state': False, 'minimal_activation_delay_sec': 1, 'device_power': 300.0, 'mean_cycle_power': 300.0, 'total_energy': 5.0, 'last_update_datetime': '2023-10-14T09:26:43.182002+02:00', 'timezone': 'Europe/Paris', 'window_delay_sec': 20, 'window_auto_open_threshold': None, 'window_auto_close_threshold': None, 'window_auto_max_duration': None, 'underlying_switch_1': 'input_boolean.fake_heater_switch1', 'underlying_switch_2': None, 'underlying_switch_3': None, 'underlying_switch_4': None, 'on_percent': 1, 'on_time_sec': 60, 'off_time_sec': 0, 'cycle_min': 1, 'function': 'tpi', 'tpi_coef_int': 0.6, 'tpi_coef_ext': 0.01}
2023-10-14 07:26:43.182 INFO (MainThread) [custom_components.versatile_thermostat.climate] VersatileThermostat-Multi-switch - Presence changed. Event.new_state is <state input_boolean.fake_presence_sensor1=off; editable=False, icon=mdi:home, friendly_name=Presence Sensor 1 @ 2023-10-14T09:26:43.179360+02:00>, _attr_preset_mode=boost, activity=activity
2023-10-14 07:26:43.182 DEBUG (MainThread) [custom_components.versatile_thermostat.climate] VersatileThermostat-Multi-switch - Updating presence. New state is off
2023-10-14 07:26:43.182 INFO (MainThread) [custom_components.versatile_thermostat.climate] VersatileThermostat-Multi-switch - No one is at home. Apply temperature 16.20
2023-10-14 07:26:43.182 DEBUG (MainThread) [custom_components.versatile_thermostat.climate] VersatileThermostat-Multi-switch - presence change in temperature mode new_temp will be: 16.20
2

In the state of the VTherm (Development Tools / State), you should see presence_state: true

[jmcollin78]

When looking at the code, it is possible to ignore the presence state if one on this condition is present:

1. the VTherm is in security mode (no temperature update for a long time),
2. the VTherm is in power mode (the max power have been exceeded),
3. the VTherm is not configured for presence checking.

All of these condition can be checked in the Developemnt Tools / State.

[maia]

Thanks. How do you access the logs you're referring to? The logbook in the UI is less useful for copy&pasting (and filtering), I assume you access HA with SMB to some log folder I've not seen yet and use grep to filter for custom_components.versatile_thermostat.climate?

[jmcollin78]

Yes the logs are accessible in the config directory exposed by the SMB addon. It can also be accessed directly with the editor addon. Then you have access to the config/home-assistant.log file directly.

I use the VSCode editor addon.

[maia]

Also, it's not a single VTherm that's not working properly. They all switch to "Away" frequently even when the binary switch indicating presence does not change. E.g. all my currently three VTherm devices switched to "Away" between midnight and 1:00. Two of them switched back to "Home" 10 minutes ago. E If you look closely at the screenshot below, you'll see many grey lines, indicating short periods of "Away" in the past 12 hours. I was at home the entire time. (Oh, the VTherm is configured for presence checking, there's no power mode as it's controlling a TRV and the security mode was "safe" the entire time):

Edit: Unfortunately config/home-assistant.log is only 150 lines long and only contains a single mention of versatile thermostat, I think it got reset when HA rebooted:

2023-10-14 00:55:36.148 ERROR (MainThread) [custom_components.versatile_thermostat.underlyings] VersatileThermostat-Vorzimmer Heizung-climate.vorzimmer_eve_trv - Cannot find the underlying climate entity: climate.vorzimmer_eve_trv. Thermostat will not be operational
2023-10-14 00:55:36.163 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/config/custom_components/versatile_thermostat/climate.py", line 1416, in _async_temperature_changed
    await self._async_control_heating(force=False)
  File "/config/custom_components/versatile_thermostat/climate.py", line 2265, in _async_control_heating
    raise err
  File "/config/custom_components/versatile_thermostat/climate.py", line 2262, in _async_control_heating
    under.startup()
  File "/config/custom_components/versatile_thermostat/underlyings.py", line 430, in startup
    raise UnknownEntity(f"Underlying entity {self.entity_id} not found")
custom_components.versatile_thermostat.const.UnknownEntity: Underlying entity climate.vorzimmer_eve_trv not found

I guess whenever the underlying entity cannot be found for even a very short moment, the presence state is switched to "Away" and not turned back. I have no idea though why the underlying device disappears from time to time, but I imagine it's related to "sleepy" thread devices that stay in energy saving mode for a while to only wake up from time to time.

[jmcollin78]

Can you add the presence sensor state in the same screenshot ? The both graph should be strictly identical if no security mode or power mode is up.

Edit:

Unfortunately config/home-assistant.log is only 150 lines long and does not contain a single mention of versatile thermostat, I think it got reset when HA rebooted.

yes but have the old logs into the home-assistant.log.1 file after reboot.

custom_components.versatile_thermostat.const.UnknownEntity: Underlying entity climate.vorzimmer_eve_trv not found

It occurs at startup, you can just ignore it. It does not change anything on presence state.

[maia]

Here's the updated screenshot. As for the logs, I rebooted frequently last evening as I'm repairing all thread devices to a new thread network via Home Assistant SkyConnect dongle (completely removing Apple HomePod as border router).

[jmcollin78]

Are you sure that the presence sensor is "Someone at home" in the VTherm configuration ? It seems really weird what I see. Can you send me the page 1 of your VTherm configuration (like this):

and the page concerning the presence (like this):

[jmcollin78]

What is really strange is that you are the only one with such problems on presence feature. I never have a bug on this. So I suspect a configuration issue but I don't have any idea of what happens.

[maia]

Yes, it's strange. And I assume it might be caused by the TRVs bad connection, until last night I was using SkyConnect as second thread border router additionally to Apple HopePod (in a single, merged thread network), but I then realised that many devices didn't connect via thread but via bluetooth. Which is why I created a new thread network and started migrating the ~30 devices to the new network, ensuring they all connect via thread. So until yesterday, the bluetooth-connection might have caused the devices to disappear from time to time.

Here are the config screens:

[maia]

Is there any logging for the presence state, can I find out when exactly and why it switches to on/off? The weird thing is that the logbook does not show changes, but the state does change.

[jmcollin78]

Yes, it's strange. And I assume it might be caused by the TRVs bad connection, until last night I was using SkyConnect as second thread border router additionally to Apple HopePod (in a single, merged thread network), but I then realised that many devices didn't connect via thread but via bluetooth.

It seems good. I don't see anything weird.

Is there any logging for the presence state, can I find out when exactly and why it switches to on/off? The weird thing is that the logbook does not show changes, but the state does change.

For me I don't see how it is possible. The presence is managed by the change of the "Someone at home" sensor. There should be logs (in INFO level) in the home-assistant.log file. I see in another thread that you don't have the INFO log level ? You should something like that in your config/logger.yaml file:

...
default: warning
logs:
  custom_components.versatile_thermostat: info

[maia]

Meanwhile I figured out how to define log levels, see the other issue. I have exactly this setting now (only when you're asking for a debug log, I turn it on)

[jmcollin78]

Another idea, is to display more sensor or binary_sensor into the history graph to see if one is matching the changing state. It should give some clues maybe.

[maia]

Another idea, is to display more sensor or binary_sensor into the history graph to see if one is matching the changing state. It should give some clues maybe.

It seems to be related to the thread status. Whenever the underlying device disappears from the thread network, there's a chance that the VTherm device will switch to "Away". The first three lines are VTherm devices, then the binary presence toggle, then 3x the thread status:

[jmcollin78]

There is clearly correlation. What is strange is that you don't see this log:

_LOGGER.info(
            "%s - Presence changed. Event.new_state is %s, _attr_preset_mode=%s, activity=%s",
            self,
            new_state,
            self._attr_preset_mode,
            PRESET_ACTIVITY,
        )

I suppose if the sensor goes "unavailable" I should capture this new state.

If the state is "unavailable" I should not take it into account:

if new_state is None or new_state not in (
            STATE_OFF,
            STATE_ON,
            STATE_HOME,
            STATE_NOT_HOME,
        ):
            return

I continue to not understand because the state of "Someone at home" doesn't change when Thread is not working.

[maia]

I'm currently reloading yaml, rebooting HA etc. a lot, as I'm re-pairing about 50 devices (new setup of Zigbee2MQTT and Thread). So maybe it's related to that.

Is it possible that when the VTherm device loads and the presence sensor isn't available yet in that moment (during HA boot), the VTherm device is set to "Away"?

[jmcollin78]

Is it possible that when the VTherm device loads and the presence sensor isn't available yet in that moment (during HA boot), the VTherm device is set to "Away"?

No, it should not do that. Away is when presence is not detected, not at init or when presence is undefined.

[maia]

No, it should not do that. Away is when presence is not detected, not at init or when presence is undefined.

That's strange, here's a current example. I was editing the VTherm device a few times and it seems like every time I saved it, it became unavailable for a second, setting the presence state to "away". The two times it was set to "home" in this example was when I manually turned the presence state toggle I'm using in all VTherm devices off and on again.

[maia]

Here's a new chart of the last hour with a dozen vtherm devices and in the first row the binary presence sensor I'm using. I'm more and more convinced that it's an issue with reloading/editing vtherm devices, rebooting HA,… I'm currently forced to manually switch the binary presence sensor off and on again to force the vtherm devices to update properly.

[maia]

Yeah, when rebooting the thread network takes some time to make all underlying devices available, as first all thread routers need to reconnect to the HA border router, then the end devices can connect to the routers. This takes a minute or so. As you can see in the right part of the screenshot, four VTherm devices went back to "home" after the reboot at 13:13, 6 devices stayed at "away". All of these 6 underlying devices do not directly connect to the HA thread border router but to other thread routers, that need 20-30 seconds to go online.

[maia]

By the way, my HA log is full of the following error. I assume it shouldn't raise an error but only log something to the log, so there's something missing that can catch the exception and handle it properly.

2023-10-15 15:28:25.835 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/config/custom_components/versatile_thermostat/climate.py", line 1565, in try_motion_condition
    await self._async_control_heating(force=True)
  File "/config/custom_components/versatile_thermostat/climate.py", line 2304, in _async_control_heating
    raise err
  File "/config/custom_components/versatile_thermostat/climate.py", line 2301, in _async_control_heating
    under.startup()
  File "/config/custom_components/versatile_thermostat/underlyings.py", line 430, in startup
    raise UnknownEntity(f"Underlying entity {self.entity_id} not found")

[jmcollin78]

Yes this is a temporary error when the underlying is not yet available:

def startup(self):
        """Startup the Entity"""
        # Get the underlying climate
        self._underlying_climate = self.find_underlying_climate()
        if self._underlying_climate:
            _LOGGER.info(
                "%s - The underlying climate entity: %s have been succesfully found",
                self,
                self._underlying_climate,
            )
        else:
            _LOGGER.error(
                "%s - Cannot find the underlying climate entity: %s. Thermostat will not be operational",
                self,
                self.entity_id,
            )
            # #56 keep the over_climate and try periodically to find the underlying climate
            # self._is_over_climate = False
            raise UnknownEntity(f"Underlying entity {self.entity_id} not found")
        return

You should also see that error log: Cannot find the underlying climate entity: %s. Thermostat will not be operational

The caller (climate.py", line 2301, in _async_control_heating) catch the exception but rethrown it and nobody was catching this one. It will be fixed in next release.

Thanks for the report !

[jmcollin78]

Yeah, when rebooting the thread network takes some time to make all underlying devices available, as first all thread routers need to reconnect to the HA border router, then the end devices can connect to the routers. This takes a minute or so

Ok, i think I got the case. The presenceBinarySensor is listening to any change in the VTherm which is also listening to any change in the underlying.

If the underlying is not ready, I suppose I will get a undefined (or None) value. And the code says, I put it On (someone is present), if the presence_state is 'on'. That mean if present_state is undefined or unavailable or None or whatever, it will be set to 'Off' (No one is present).

I will change this logic and will not change the value if undefined. I think that will be more robust with that.

I will give you a beta release for testing if it is possible on your side.

[jmcollin78]

The release https://github.com/jmcollin78/versatile_thermostat/releases/tag/3.5.4beta1 is available for test. I will install it also on my self.

[maia]

Thanks, I'm currently testing it and until now it is working fine. I'll give you an update in a day or two, but I assume the issue is fixed.

[maia]

@jmcollin78 FYI: The issue seems to be fixed, it didn't occur to me since the new release.

[jmcollin78]

I do the release on sunday 3.5.4.