Too many calls to calculate_regulated_temperature

[jmcollin78]

With currently 10 VTherm services using the regulated algo I can see 388 log entries within exactly 1 hour, so in average every service calls calculate_regulated_temperature in average every 1.5 minutes, even when using a 5 minutes cycle. Something is off, it should be called exactly once per cycle.

_Originally posted by @maia in https://github.com/jmcollin78/versatile_thermostat/discussions/154#discussioncomment-7480989_

[jmcollin78]

pi_alog.calculate_regulated_temperature() is called 3 times:

1. when target temperature is changed -> this allow to calculate a new regulated temperature. This should be called maybe 6 times a day depending of your preset changes by Scheduler or automation or if motion is configured at each motion/presence state change,
2. at each cycle -> this allows adjusting the regulation,
3. when the service which change the regulation mode (Slow, Light, ...) is called.

So for me it's sounds good and I can't do less. Your calls rate seems very strange for me.

What I have done is to add a specific log each time it is called:

_LOGGER.info(
            "%s - Calling ThermostatClimate._send_regulated_temperature force=%s",
            self,
            force,
        )

So you will the VTherm which is responsible of the call and you look just above this call you will see the reason. Example:

_LOGGER.info("%s - Set target temp: %s", self, temperature)
...
_LOGGER.info("%s - Set preset_mode: %s force=%s", self, preset_mode, force)
...
 _LOGGER.info(
            "%s - Motion changed. Event.new_state is %s, _attr_preset_mode=%s, activity=%s",
            self,
            new_state,
            self._attr_preset_mode,
            PRESET_ACTIVITY,
        )
...
_LOGGER.info("%s - Updating presence. New state is %s", self, new_state)

It will perhaps help us to understand if it is normal (and I think so).

[maia]

Thanks. If it's always 3x that would sound right, as I'm seeing calls every ~1,5 minute on a 5 minute cycle. Is it always 3 times or sometimes less? And is there a way to tell which reason it was called for and/or if it's the first call in a cycle? Because any calculation that's based on a fixed duration, e.g. 1 day = 288 times 5 minutes, shouldn't be run more frequently.

As for the logging, could you add the id of the entity to the log? If a dozen entities all log all calls, it's hard to tell more. Actually, for all LOGGER.info calls it would be good to add the id or user friendly name or so to the log.

[jmcollin78]

Is it always 3 times or sometimes less?

It should be less (I suppose you are not changing preset every 5 minutes).

And is there a way to tell which reason it was called for and/or if it's the first call in a cycle?

Yes it is the log just before. See my previous post.

As for the logging, could you add the id of the entity to the log?

This is done. I think you didn't read my previous post.

[maia]

And is there a way to tell which reason it was called for and/or if it's the first call in a cycle?

Yes it is the log just before. See my previous post.

This question wasn't about the log but about inside the code. I'm still trying to write a good algorithm, but this requires to be able to tell inside the code if the last call was 0 seconds ago or 5 minutes.

As for the logging, could you add the id of the entity to the log?

This is done. I think you didn't read my previous post.

Oh, so %s is the id? I wasn't aware of that, thanks.

[jmcollin78]

This question wasn't about the log but about inside the code. I'm still trying to write a good algorithm, but this requires to be able to tell inside the code if the last call was 0 seconds ago or 5 minutes.

Not out of the box. You have to add it if you need this.

Oh, so %s is the id? I wasn't aware of that, thanks.

%s is mapped on self which is translated by the method:

def __str__(self):
        return f"VersatileThermostat-{self.name}"

of BaseThermostat.

[maia]

I'm working myself through the logs for the 15 minutes after a reboot, without doing anything myself (no changes in presets, no motion, no open windows,…).

There's already one thing I noticed: with the default setting of window detection based on slope (decrease of 0.05) I'm seeing false positives in the log. And each time the hvac mode is switched to off and briefly afterwards back to on.

Please take a look at the following part (just grepping for one specific room). Is it possible that each time an open window is detected, this adds another 5 minute timer, which is added instead of replacing the previous timer? E.g.:

20:00 normal cycle call 20:05 normal cycle call 20:10 normal cycle call 20:12 open window detected, create another 5min cycle 20:10 normal cycle call 20:12 additional cycle call 20:15 normal cycle call 20:17 additional cycle call

In that case we'd have more and more cycles running parallel, all calling the regulation methods.

Also, should "underlying event is received less than 10 sec after command. Forget it to avoid loop" happen, when nothing is changed manually?

Here's the log:

21:26:34.941 INFO … [….underlyings] VersatileThermostat-Schlafzimmer Heizung-climate.schlafzimmer_eve_trv - The underlying climate entity: <entity climate.schlafzimmer_eve_trv=heat> have been succesfully found
21:26:34.942 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:26:59.429 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - Underlying climate changed. Event.new_hvac_mode is heat, current_hvac_mode=heat, new_hvac_action=heating, old_hvac_action=heating
21:28:08.684 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:30:15.907 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:30:15.907 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - Regulated temp have changed to 23.5. Resend it to underlyings
21:30:18.127 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - Underlying climate changed. Event.new_hvac_mode is heat, current_hvac_mode=heat, new_hvac_action=heating, old_hvac_action=heating
21:30:44.207 WARNING … [….base_thermostat] VersatileThermostat-Schlafzimmer Heizung - Start auto detection of open window slope=-0.099
21:30:44.208 INFO … [….base_thermostat] VersatileThermostat-Schlafzimmer Heizung - Sending event EventType.WINDOW_AUTO_EVENT with data: {'type': 'start', 'cause': 'slope alert', 'curve_slope': -0.09885498551175792}
21:30:44.209 INFO … [….base_thermostat] VersatileThermostat-Schlafzimmer Heizung - Set hvac mode: off
21:30:44.210 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:30:44.211 INFO … [….base_thermostat] VersatileThermostat-Schlafzimmer Heizung - Sending event EventType.HVAC_MODE_EVENT with data: {'hvac_mode': <HVACMode.OFF: 'off'>}
21:30:44.213 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:30:48.423 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - Underlying climate changed. Event.new_hvac_mode is off, current_hvac_mode=off, new_hvac_action=idle, old_hvac_action=heating
21:30:48.423 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - underlying just switch OFF at 2023-11-11T21:30:48.392295+01:00. delta_h=0.070 h
21:30:48.423 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - underlying event is received less than 10 sec after command. Forget it to avoid loop
21:30:48.424 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:33:09.082 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:38:09.511 INFO … [….thermostat_climate] VersatileThermostat-Schlafzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False

[maia]

This is for another room. Too many calls within 20 minutes (at a 5 minutes cycle):

21:24:48.627 INFO … [….underlyings] VersatileThermostat-Wohnzimmer Heizung-climate.wohnzimmer_eve_trv - The underlying climate entity: <entity climate.wohnzimmer_eve_trv=heat> have been succesfully found
21:24:48.628 INFO … [….thermostat_climate] VersatileThermostat-Wohnzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:25:15.540 INFO … [….thermostat_climate] VersatileThermostat-Wohnzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:28:08.490 INFO … [….thermostat_climate] VersatileThermostat-Wohnzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:28:08.491 INFO … [….thermostat_climate] VersatileThermostat-Wohnzimmer Heizung - Regulated temp have changed to 23.0. Resend it to underlyings
21:33:08.089 INFO … [….thermostat_climate] VersatileThermostat-Wohnzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:38:08.148 INFO … [….thermostat_climate] VersatileThermostat-Wohnzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:41:58.930 INFO … [….thermostat_climate] VersatileThermostat-Wohnzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
21:43:08.152 INFO … [….thermostat_climate] VersatileThermostat-Wohnzimmer Heizung - Calling ThermostatClimate._send_regulated_temperature force=False

[maia]

Oh, usually there's nothing "above" the line in the log, because there are no changes in preset, motion or target temperature. Here's the log for the entire component with INFO as log level (I skipped the first few minutes after the reboot, because that's when all the TRVs and room temperature sensors are not available yet): vtherm log regulated temp.txt I'm seeing frequent "Underlying climate changed. Event.new_hvac_mode is heat" in there, even though the climate didn't change and was "heat" previously too.

I just counted: 89 calls to _send_regulated_temperature in 20 minutes for 10 entities = 8.90 calls per entity in 20 minutes = average cycle length of 2.24 minutes.

(I'm using the latest version, the one you released today)

[jmcollin78]

I will try to reproduce what you have found. It sounds very strange to me. Regarding the code, it seems not possible to have multiple cycle in // on the same VTherm. Nevertheless, i will try. The most strange think is that you does nothing special. Maybe a side effect of the regulation which is relatively new.

[jmcollin78]

In my dev environment, all seems normal: after a window auto-detection there is only one cycle running which is every two minutes (my configuration).

2023-11-11 23:35:24.471 DEBUG (MainThread) [custom_components.versatile_thermostat.base_thermostat] VersatileThermostat-Thermostat climate 2 - Checking new cycle. hvac_mode=off, security_state=False, preset_mode=none
...
2023-11-11 23:37:24.470 DEBUG (MainThread) [custom_components.versatile_thermostat.base_thermostat] VersatileThermostat-Thermostat climate 2 - Checking new cycle. hvac_mode=off, security_state=False, preset_mode=none
...
2023-11-11 23:39:24.475 DEBUG (MainThread) [custom_components.versatile_thermostat.base_thermostat] VersatileThermostat-Thermostat climate 2 - Checking new cycle. hvac_mode=off, security_state=False, preset_mode=none

So the truth is elsewhere.

What you can do, if you don't want to upgrade to 4.x release is to change a few log level directly in the code, so that we will be able to see who is calling the _send_regulated_temperature:

1. baseThermostat.py line 2032 (maybe not exactly the same line for you), the first log of the method:

async def async_control_heating(self, force=False, _=None):
        """The main function used to run the calculation at each cycle"""

        _LOGGER.debug(          <------ change to INFO
            "%s - Checking new cycle. hvac_mode=%s, security_state=%s, preset_mode=%s",
            self,
            self._hvac_mode,
            self._security_state,
            self._attr_preset_mode,
        )

2. baseThermostat lien 2068: ``` _LOGGER.debug("%s - End of cycle (HVAC_MODE_OFF)", self) ```` This log should appears when open window is detected.

---

With those log you should see:

Checking new cycle before each call to _send_regulated_temperature or another log saying that preset or target temperature have change.

[maia]

Thanks. I was using 4.0.2 for these checks, but now changed the two LOGGER.debug to LOGGER.info and will make some more tests today.

[maia]

Does this here help? The log starts about 10 minutes after rebooting, it's grepping for versatile. As you can see, at different times different rooms have multiple rows of calling _send_regulated_temperature with <2 minutes inbetween. All services are set to 5 minute cycles. vtherm log regulated temp.txt

[jmcollin78]

Yes it helps. It shows clearly what you suspect: the cycle is totally in chaos. The 5 min cycle is not respected at all without any others sollicitations.

You didn't filter the logs right ? All logs are here ?

[maia]

That's all logs when searching for versatile. And I've just checked the logs again, from 9:00:00 to 9:04:59. So each service should only appear once. But one service has 4 cycles in these 5 minutes (check for "Hinterzimmer"), two services have 3 cycles in these 5 minutes (check for "Küche links" and "Küche rechts") and the others only have one cycle: vtherm log regulated temp 2.txt

[jmcollin78]

I have an idea. Maybe another cycle is started each time you reconfigure a VTherm. And because you are trying to tune the algorithm, you reconfigure and then it starts new cycle.

Can you please check that:

1. after a full HA restart, cycles are normal,
2. when you reconfigure a VTherm a double cycle is started.

Maybe I will be able to reproduce this in my dev environment but I'm not sure of that.

[maia]

This morning what I did was:

1. change the code to replace LOGGER.debug with LOGGER.info as requested
2. reboot HA
3. edit the config for two rooms ("Schlafzimmer" and "Kinderzimmer") by increasing the temperatures for eco/comfort/boost
4. eat breakfast
5. check the logs

I didn't touch any other service and I didn't touch the TRVs. So the three services with too many cycles at the moment were not reconfigured since the reboot.

[jmcollin78]

I try to reconfigure and all is fine. I try also in my production env (my house).

---

I think I've got something interesting (on my production env):

2023-11-12 09:27:36.011 DEBUG (MainThread) [custom_components.versatile_thermostat.base_thermostat] VersatileThermostat-Thermostat chambre - Temperature changed. Event.new_state is <state sensor.temperature_chambre=18.7; state_class=measurement, unit_of_measurement=°C, device_class=temperature, friendly_name=Température chambre @ 2023-11-12T09:27:36.007985+01:00>
2023-11-12 09:27:36.012 DEBUG (MainThread) [custom_components.versatile_thermostat.base_thermostat] VersatileThermostat-Thermostat chambre - After setting _last_temperature_mesure 2023-11-12 09:27:36.007985+01:00 , state.last_changed.replace=2023-11-12 09:27:36.007985+01:00
2023-11-12 09:27:36.012 DEBUG (MainThread) [custom_components.versatile_thermostat.open_window_algorithm] We are already initialized slope=None last_temp=18.90
2023-11-12 09:27:36.012 DEBUG (MainThread) [custom_components.versatile_thermostat.open_window_algorithm] delta_t=9.475 delta_temp=-0.200 new_slope=-0.021 last_slope=None slope=-0.021
2023-11-12 09:27:36.013 DEBUG (MainThread) [custom_components.versatile_thermostat.base_thermostat] VersatileThermostat-Thermostat chambre - Window auto is on, check the alert. last slope is -0.021
2023-11-12 09:27:36.013 DEBUG (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Thermostat chambre - recalculate all
2023-11-12 09:27:36.014 DEBUG (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Thermostat chambre - Calling update_custom_attributes: {'is_on': True, 'hvac_action': None, 'hvac_mode': 'heat', 'preset_mode': 'eco', 'type': None, 'eco_temp': 17.0, 'boost_temp': 21.0, 'comfort_temp': 19.0, 'eco_away_temp': 17.0, 'boost_away_temp': 17.0, 'comfort_away_temp': 17.0, 'power_temp': 13.0, 'ext_current_temperature': 6.6, 'ac_mode': True, 'current_power': 1.78, 'current_power_max': 8.0, 'saved_preset_mode': 'eco', 'saved_target_temp': 17.0, 'saved_hvac_mode': None, 'window_state': 'off', 'motion_state': None, 'overpowering_state': False, 'presence_state': 'on', 'window_auto_state': 'off', 'window_bypass_state': False, 'security_delay_min': 120, 'security_min_on_percent': 0.5, 'security_default_on_percent': 0.1, 'last_temperature_datetime': '2023-11-12T09:27:36.007985+01:00', 'last_ext_temperature_datetime': '2023-11-12T09:17:26.710736+01:00', 'security_state': False, 'minimal_activation_delay_sec': 10, 'device_power': 1.0, 'mean_cycle_power': None, 'total_energy': 0, 'last_update_datetime': '2023-11-12T09:27:36.013718+01:00', 'timezone': 'Europe/Paris', 'window_sensor_entity_id': 'binary_sensor.ouverture_chambre', 'window_delay_sec': 30, 'window_auto_open_threshold': None, 'window_auto_close_threshold': None, 'window_auto_max_duration': None, 'motion_sensor_entity_id': None, 'presence_sensor_entity_id': 'binary_sensor.maison_occupee', 'power_sensor_entity_id': 'sensor.total_puissance_consommee_net_instantanee', 'max_power_sensor_entity_id': 'input_number.chauffage_puissance_delestage', 'temperature_unit': '°C', 'is_device_active': True, 'is_over_climate': True, 'start_hvac_action_date': None, 'underlying_climate_0': 'climate.clim_chambre_localtuya', 'underlying_climate_1': None, 'underlying_climate_2': None, 'underlying_climate_3': None, 'is_regulated': True, 'regulated_target_temperature': 17.0, 'auto_regulation_mode': 'auto_regulation_light', 'regulation_accumulated_error': -5.699999999999996}
2023-11-12 09:27:36.015 DEBUG (MainThread) [custom_components.versatile_thermostat.base_thermostat] VersatileThermostat-Thermostat chambre - Checking new cycle. hvac_mode=heat, security_state=False, preset_mode=eco

That means the main cycle method have been called after an update of the temperature of the room (and also after the change of the external temperature).

If you have time to check, you are in the same case, you can add a INFO log level to the following event (in base_thermostat.py line 1261):

@callback
    async def _async_temperature_changed(self, event: Event):
        """Handle temperature of the temperature sensor changes."""
        new_state: State = event.data.get("new_state")
        _LOGGER.debug(                                                                           <----- put .INFO here 
            "%s - Temperature changed. Event.new_state is %s",
            self,
            new_state,
        )
        if new_state is None or new_state.state in (STATE_UNAVAILABLE, STATE_UNKNOWN):
            return

        await self._async_update_temp(new_state)
        self.recalculate()
        await self.async_control_heating(force=False)

Ok that's it. The async_control_heating (the main cycle method) is called after each temperature change and for over_climate, that is calling the send_regulated_temperature each time.

This is not optimal because it calls the regulation calculation each time which increments the error_accumulation. I have to think something different.

Many, many thanks for all your help finding this bug.

[jmcollin78]

ok so what do I do is to apply the temporal filter (based on the regulation_period_min parameter) BEFORE calculated the new regulated temp, so that if call is too frequent it will just be ignored.

I put also the log for regulation into INFO log level. We will see when calls are ignored. I push a maintenance release in few minutes. Let me test it before you can test it.

[jmcollin78]

https://github.com/jmcollin78/versatile_thermostat/releases/tag/4.0.3

[jmcollin78]

I install the fix. Now I can see that:

A calculation have been done:

VersatileThermostat-Thermostat chambre - Updating presence. New state is on
VersatileThermostat-Thermostat chambre - Calling ThermostatClimate._send_regulated_temperature force=True
VersatileThermostat-Thermostat chambre - regulation calculation will be done
VersatileThermostat-Thermostat chambre - Regulated temp have changed to 17.0. Resend it to underlyings

and after a short delay:

VersatileThermostat-Thermostat chambre - Window is closed. Restoring hvac_mode 'None'
VersatileThermostat-Thermostat chambre - Set hvac mode: None
VersatileThermostat-Thermostat chambre - Calling ThermostatClimate._send_regulated_temperature force=False
VersatileThermostat-Thermostat chambre - period (0.5) min is < 5 min -> forget the regulation send

This call to _send_regulated_temperature have been ignored.

The real log to check now is regulation calculation will be done and only this one.

[jmcollin78]

There is now 5 min between all regulation changes:

2023-11-12 10:28:47.534 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Thermostat chambre - regulation calculation will be done
...
2023-11-12 10:37:32.062 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Thermostat chambre - regulation calculation will be done

So the fix works as expected.

If you agree with me I will close this issue.

[maia]

Thanks for your work on that issue. It might be better now (unsure about that), but I'm still seeing way too many calls. In this case I installed 4.0.3, rebooted, waited 10 minutes, not doing anything with HA or the TRVs.

Here's the log for 13:40:00-13:59:00 (20 minutes). In this log you can see that some services have more calls to "regulation calculation will be done" than other. Correct would be 4 calls in exactly 20 minutes.

Some services have up to 12 calls ("Küche links", "Küche rechts"), but also 7x "Badezimmer unten", 6x "Badezimmer oben", 6x "Vorzimmer", 6x "WC", 3 rooms with 5 calls and only 2 rooms with the 4 calls (which would be correct).

So unfortunately the issue isn't fixed yet. Sigh, this seems to be complicated to track down. Let me know what I can do. vtherm log regulated temp 3.txt

[jmcollin78]

What is the value of your regulation_period_min ? Are you sure it is 5 (minutes) ? I think you talk about the cycle period which is NOT the regulation_period_min. Those are two different values.

[maia]

Both are 5 minutes:

Regulation minimal period: 5
Cycle duration: 5

[jmcollin78]

So unfortunately the issue isn't fixed yet. Sigh, this seems to be complicated to track down. Let me know what I can do. vtherm log regulated temp 3.txt

When I look room by room here what I see (the most significant is Küche Links):

2023-11-12 13:43:56.316 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
2023-11-12 13:43:56.316 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - regulation calculation will be done
2023-11-12 13:43:56.316 WARNING (MainThread) [custom_components.versatile_thermostat.pi_algorithm] Temporarily skipping the self-regulation algorithm while the configured sensor for outdoor temperature is unavailable
2023-11-12 13:43:56.317 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - dtemp (0.0) is < 0.5 -> forget the regulation send
...
2023-11-12 13:48:56.317 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
2023-11-12 13:48:56.317 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - regulation calculation will be done
2023-11-12 13:48:56.318 WARNING (MainThread) [custom_components.versatile_thermostat.pi_algorithm] Temporarily skipping the self-regulation algorithm while the configured sensor for outdoor temperature is unavailable
2023-11-12 13:48:56.318 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - dtemp (0.0) is < 0.5 -> forget the regulation send
...
2023-11-12 13:53:28.078 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
2023-11-12 13:53:28.078 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - regulation calculation will be done
2023-11-12 13:53:28.079 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - dtemp (0.0) is < 0.5 -> forget the regulation send
...
2023-11-12 13:53:56.395 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
2023-11-12 13:53:56.395 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - regulation calculation will be done
2023-11-12 13:53:56.395 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - dtemp (0.0) is < 0.5 -> forget the regulation send
...
2023-11-12 13:54:10.692 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
2023-11-12 13:54:10.692 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - regulation calculation will be done
2023-11-12 13:54:10.692 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - dtemp (0.0) is < 0.5 -> forget the regulation send
...
2023-11-12 13:54:27.182 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
2023-11-12 13:54:27.182 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - regulation calculation will be done
2023-11-12 13:54:27.182 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - dtemp (0.0) is < 0.5 -> forget the regulation send
...
2023-11-12 13:55:56.741 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
2023-11-12 13:55:56.741 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - regulation calculation will be done
2023-11-12 13:55:56.741 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - dtemp (0.0) is < 0.5 -> forget the regulation send
...
2023-11-12 13:57:08.117 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
2023-11-12 13:57:08.124 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - regulation calculation will be done
2023-11-12 13:57:08.124 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - dtemp (0.0) is < 0.5 -> forget the regulation send
...
2023-11-12 13:57:40.805 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
2023-11-12 13:57:40.806 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - regulation calculation will be done
2023-11-12 13:57:40.806 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - dtemp (0.0) is < 0.5 -> forget the regulation send
...
2023-11-12 13:58:19.649 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
2023-11-12 13:58:19.649 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - regulation calculation will be done
2023-11-12 13:58:19.650 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - dtemp (0.0) is < 0.5 -> forget the regulation send
...
2023-11-12 13:58:35.835 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
2023-11-12 13:58:35.835 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - regulation calculation will be done
2023-11-12 13:58:35.835 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - dtemp (0.0) is < 0.5 -> forget the regulation send
...
2023-11-12 13:58:56.598 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - Calling ThermostatClimate._send_regulated_temperature force=False
2023-11-12 13:58:56.598 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - regulation calculation will be done
2023-11-12 13:58:56.599 INFO (MainThread) [custom_components.versatile_thermostat.thermostat_climate] VersatileThermostat-Küche links Heizung - dtemp (0.0) is < 0.5 -> forget the regulation send

You can see that the regulation never occurs. There is always the message "forget the regulation send" because dtemp is too low. What is misleading, is that you have a message saying 'regulation calculation will be done' but finally the regulation is not done, only the calculation... I know i should do better.

I will change something: i will store the last date of regulation not when regulations is done but when calculation is done (which means the accumulated_error have been updated). So it will be less misleading.

[jmcollin78]

https://github.com/jmcollin78/versatile_thermostat/releases/tag/4.0.4

• window temporal filter to 30 sec.

[maia]

I've just installed 4.0.4. Hopefully it'll help. But please let me ask this: will the change only prevent a regulating in less than 5 minutes or also prevent calls to calculate_regulated_temperature in less than 5 minutes? Any algorithm should be able to rely on a fixed cycle, because calculations (updating accumulated_error in the case of PI) will be off if they are updated more often than the cycle.

[jmcollin78]

calculate_regulated_temperature in less than 5 minutes

It prevents the calculation every 5 min maximum. Before your cycle is also 5 min, you will have a calculation (and maybe a regulation) every 5 min exactly (except preset change, in that I force the calculation)

[maia]

Using 4.0.4 I'm seeing way less "regulation calculation will be done" messages. You seem to have found the solution. On the other hand it appears that it's not guaranteed that the cycle length is 5 minutes, it's just a minimum of 5 minutes? Because for a timeframe of exactly 19:59 minutes and a 5 minutes cycle I'm seeing:

• 7 services have each 3 occurrences of "regulation calculation will be done", which is correct for 19:59 minutes
• 4 services have each only 2 occurrences

Probably that's less of an issue when looking at longer timeframes of many hours and with a 5min cycle we'll see 280-288 cycles per day? I will recheck later.

[maia]

Update: the analysis of 59 minutes and 59 seconds with 5 minute cycles shows:

• 4 services regulated 11 times (that's how it should be)
• 4 services regulated 10 times
• 2 services regulated 9 times
• 1 service regulated 8 times

This is much better than previously. And if there is any chance to ensure a fixed 5 minutes cycle, that would be great.

[jmcollin78]

Hello @maia ,

Is it good for you. May I close this ?

[jmcollin78]

In release 4.1.0