search

nielsfaber / scheduler-component

Custom component for HA that enables the creation of scheduler entities
GNU General Public License v3.0
655 stars 41 forks source link

Thermostat temperature not updating (similar to 96, 133 and 136 I think) #181

Closed jal142 closed 2 years ago

jal142 commented 2 years ago

Checklist

Expected behavior

Running a Honeywell T6 Zwave thermostat. Using a scheme with the "regulate" option that should be updating the set temperature range at 7:30am.

Actual behavior

The temperature range remains at the same points as it was overnight. However, if I trigger the scheme manually by editing the range and clicking "save", it updates successfully.

Steps to Reproduce

In the log, when the scheduler runs, I see this: Schedule #ad7b05 turned on 7:31:00 AM - 4 hours ago T6 Pro Z-Wave Programmable Thermostat changed to Heat/Cool 7:30:10 AM - 4 hours ago T6 Pro Z-Wave Programmable Thermostat changed to Cool by service climate.set_temperature 7:30:00 AM - 4 hours ago Schedule #ad7b05 changed to triggered

When I manually triggered the scheme by editing the range and clicking save, I see this: T6 Pro Z-Wave Programmable Thermostat changed to Heat/Cool by service climate.set_hvac_mode 10:33:14 AM - 1 hour ago T6 Pro Z-Wave Programmable Thermostat changed to Cool by service climate.set_temperature 10:33:09 AM - 1 hour ago

Again, the scheduler command sequence (at 7:30 am) did not update the temperature. The second set of commands at 10:33 am did update the range. for completeness, I'm trying to set the temperature range from 65-75F overnight to 68-79F during the day. When I checked the thermostat at 10 am this morning, it was still at the 65-75F setting.

I see two differences in the logs:

  1. The delay between the commands is 10 seconds when the scheduler sent them, but it is only 5 seconds when it was done manually.
  2. The scheduler message for the Heat/Cool change is missing the "by service climate.set_hvac_mode"

In reading the other issues (133 and 136), I got the impression that the delay was upped to 10 seconds to address this issue. That fix does not appear to work for my setup (T6 thermostat, Zoos ZST10 Z-Wave USB stick, nothing else on the Z-Wave network at this point).

I am confused by the messages in the log. Why is the code is sending a "Cool" command followed by a "Heat/Cool" command. Or is the first "Cool" command actually the command to set the cooling temperature? I assume the "Regulate" option is equivalent to the "Heat/Cool" command. Should I not be using this?

Kingo71 commented 2 years ago

Same here, sometime is working other not. Was working with custom component "simple thermostat", failing now with another custom component "better thermostat".

nielsfaber commented 2 years ago

The 'regulate' action does the following:

  1. Call service set_hvac_mode with hvac_mode=heat_cool
  2. Wait 5 seconds
  3. Call service set_temperature with target_temp_low=<first slider value> and target_temp_high=<second slider value> and hvac_mode=heat_cool

These services are described here. In some cases only step 3 would be sufficient, but a lot of integrations don't support setting the hvac_mode directly via the set_temperature service.

I am unable to reproduce your issue since I use different integration. Therefore it would be helpful if you can troubleshoot the issue yourself.

First off, you could enable debug logging for the scheduler integration, by adding this to the configuration.yaml (and reloading HA):

logger:
  default: warning
  logs:
    custom_components.scheduler: debug

This will result in additional loggings in the HA log. You can track exactly which service is called by scheduler and when (although not the exact parameters will be displayed).

Second, you could define a script to 'mimic' the sequence which scheduler performs. Example:

thermostat_test:
  sequence:
    - service: climate.set_hvac_mode
      data:
        entity_id: climate.my_climate  #replace by correct entity
        hvac_mode: heat_cool
    - delay: 5
    - service: climate.set_temperature
      data:
        entity_id: climate.my_climate #replace by correct entity
        target_temp_low: 68
        target_temp_high: 79
        hvac_mode: heat_cool

I would assume executing this script has the same behaviour as the action performed by scheduler. If the thermostat doesn't respond well to it either, the problem might be with the device itself.

Please let me know your findings.

jal142 commented 2 years ago

I have added the debug logging to my configuration. I'll update as soon as I have anything to report.

Oddly enough, the thermostat temperature presets have been successfully updating for several days now. I didn't change anything with the scheduler, although there was an update to the z-wave stack and home assistant itself recently. Prior to these past few days, it only worked sporadically.

jal142 commented 2 years ago

Here's the Debug log for my most recent scheduler run, which successfully changed the temperature settings:

2022-02-24 20:40:00 DEBUG (MainThread) [custom_components.scheduler.timer] Timer 99876c has reached slot 3 2022-02-24 20:40:00 DEBUG (MainThread) [custom_components.scheduler.switch] Schedule 99876c is triggered, proceed with actions 2022-02-24 20:40:00 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Executing service climate.set_temperature on entity climate.t6_pro_z_wave_programmable_thermostat 2022-02-24 20:40:00 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Postponing next action for 5 seconds 2022-02-24 20:40:05 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Executing service climate.set_hvac_mode on entity climate.t6_pro_z_wave_programmable_thermostat 2022-02-24 20:40:05 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Action has no effect, skipping 2022-02-24 20:40:05 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Executing service climate.set_temperature on entity climate.t6_pro_z_wave_programmable_thermostat 2022-02-24 20:40:05 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Action has no effect, skipping 2022-02-24 20:40:05 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Finished execution of actions 2022-02-24 20:41:00 DEBUG (MainThread) [custom_components.scheduler.timer] Timer of 99876c set for 2022-02-24 23:59:59-05:00

Here's the log from a previous scheduler action, which did not work: 2022-02-24 17:00:00 DEBUG (MainThread) [custom_components.scheduler.timer] Timer 99876c has reached slot 2 2022-02-24 17:00:00 DEBUG (MainThread) [custom_components.scheduler.switch] Schedule 99876c is triggered, proceed with actions 2022-02-24 17:00:00 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Executing service climate.set_temperature on entity climate.t6_pro_z_wave_programmable_thermostat 2022-02-24 17:00:00 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Postponing next action for 5 seconds 2022-02-24 17:00:05 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Executing service climate.set_hvac_mode on entity climate.t6_pro_z_wave_programmable_thermostat 2022-02-24 17:00:05 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Action has no effect, skipping 2022-02-24 17:00:05 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Executing service climate.set_temperature on entity climate.t6_pro_z_wave_programmable_thermostat 2022-02-24 17:00:05 DEBUG (MainThread) [custom_components.scheduler.actions] [99876c]: Finished execution of actions 2022-02-24 17:01:00 DEBUG (MainThread) [custom_components.scheduler.timer] Timer of 99876c set for 2022-02-24 20:40:00-05:00

nielsfaber commented 2 years ago

In summary.

Correct execution:

  1. Set temperature
  2. Wait 5 seconds
  3. Set mode - skipped since the climate is already set to the correct mode
  4. Set temperature - skipped because the climate is already set to the correct temperature

Wrong execution:

  1. Set temperature
  2. Wait 5 seconds
  3. Set mode - skipped since the climate is already set to the correct mode
  4. Set temperature

The result is very weird to me. Step 4 is only added for climate devices which have a 'preset' temperature which is set when the mode is changed. In case step 3 is skipped, step 4 should always be skipped. In the wrong execution, scheduler detected that the temperature setting which was sent 5 seconds earlier, was not correctly applied, therefor it was repeated. It seems to me like a problem with the climate device. Perhaps the timing is too tight, your climate device might be still busy processing the command after 5 seconds.

I made a modified version of the test script. It now includes the checks for skipping steps and reports in the logs similar to the scheduler:

ERROR (MainThread) [homeassistant.components.system_log.external] -- Start of script -- ERROR (MainThread) [homeassistant.components.system_log.external] Setting temperature to 22 - 25 ERROR (MainThread) [homeassistant.components.system_log.external] Waiting for 5 seconds ERROR (MainThread) [homeassistant.components.system_log.external] Mode is already heat_cool, skipping step ERROR (MainThread) [homeassistant.components.system_log.external] Temperature is already 22 - 25, skipping step ERROR (MainThread) [homeassistant.components.system_log.external] -- End of script --

I would like to ask if you could run this script and test if it works consistently. It should have identical functionality as the scheduler action. It's important to repeat the action multiple times before drawing conclusions. But because it includes checks for skipping, please the temperature settings need to be changed between iterations (perhaps also the mode of the climate device should be varied). The script can be run via Developer Tools -> Services. Here you can assign the parameters like this:

The delay should be kept to 5 to be the same as scheduler. If you see the script failing, please increase the delay and see if it improves stability.

Please report your findings.

thermostat_test_script.txt

jal142 commented 2 years ago

I installed the script and ran it a few times... I left the delay at 5. I set the range to 69-79, then 69-75, then 64-79, then 69-75. So far it has worked every time.

I will try some different combinations later when I have more time. Perhaps I should try some of the same temperature settings that are in the scheduler card to see if there is something about the particular ranges I'm trying to set...

System log: 2022-03-08 23:41:48 ERROR (MainThread) [homeassistant.components.system_log.external] -- Start of script -- 2022-03-08 23:41:48 ERROR (MainThread) [homeassistant.components.system_log.external] Setting temperature to 69 - 79 and mode to heat_cool 2022-03-08 23:41:49 ERROR (MainThread) [homeassistant.components.system_log.external] Waiting for 5 seconds 2022-03-08 23:41:54 ERROR (MainThread) [homeassistant.components.system_log.external] Mode is already heat_cool, skipping step 2022-03-08 23:41:54 ERROR (MainThread) [homeassistant.components.system_log.external] Setting temperature to 69 - 79 2022-03-08 23:41:54 ERROR (MainThread) [homeassistant.components.system_log.external] -- End of script -- 2022-03-08 23:42:20 ERROR (MainThread) [homeassistant.components.system_log.external] -- Start of script -- 2022-03-08 23:42:20 ERROR (MainThread) [homeassistant.components.system_log.external] Setting temperature to 69 - 75 and mode to heat_cool 2022-03-08 23:42:20 ERROR (MainThread) [homeassistant.components.system_log.external] Waiting for 5 seconds 2022-03-08 23:42:25 ERROR (MainThread) [homeassistant.components.system_log.external] Mode is already heat_cool, skipping step 2022-03-08 23:42:25 ERROR (MainThread) [homeassistant.components.system_log.external] Setting temperature to 69 - 75 2022-03-08 23:42:25 ERROR (MainThread) [homeassistant.components.system_log.external] -- End of script -- 2022-03-08 23:43:33 ERROR (MainThread) [homeassistant.components.system_log.external] -- Start of script -- 2022-03-08 23:43:33 ERROR (MainThread) [homeassistant.components.system_log.external] Setting temperature to 64 - 79 and mode to heat_cool 2022-03-08 23:43:33 ERROR (MainThread) [homeassistant.components.system_log.external] Waiting for 5 seconds 2022-03-08 23:43:38 ERROR (MainThread) [homeassistant.components.system_log.external] Mode is already heat_cool, skipping step 2022-03-08 23:43:38 ERROR (MainThread) [homeassistant.components.system_log.external] Setting temperature to 64 - 79 2022-03-08 23:43:39 ERROR (MainThread) [homeassistant.components.system_log.external] -- End of script -- 2022-03-08 23:44:07 ERROR (MainThread) [homeassistant.components.system_log.external] -- Start of script -- 2022-03-08 23:44:07 ERROR (MainThread) [homeassistant.components.system_log.external] Setting temperature to 69 - 75 and mode to heat_cool 2022-03-08 23:44:07 ERROR (MainThread) [homeassistant.components.system_log.external] Waiting for 5 seconds 2022-03-08 23:44:12 ERROR (MainThread) [homeassistant.components.system_log.external] Mode is already heat_cool, skipping step 2022-03-08 23:44:12 ERROR (MainThread) [homeassistant.components.system_log.external] Setting temperature to 69 - 75 2022-03-08 23:44:12 ERROR (MainThread) [homeassistant.components.system_log.external] -- End of script --

github-actions[bot] commented 2 years ago

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days