core icon indicating copy to clipboard operation
core copied to clipboard

Nest Thermostat Automations not working

Open pdobrien3 opened this issue 2 years ago • 59 comments

The problem

Logger: homeassistant.components.automation.lower_heat_at_10_pm_main Source: helpers/script.py:1783 Integration: Automation (documentation, issues) First occurred: November 11, 2023 at 10:00:10 PM (1 occurrences) Last logged: November 11, 2023 at 10:00:10 PM

Lower Heat at 10 pm Main: Error executing script. Error for call_service at pos 3: Error setting climate.thermostat_2 temperature to {'temperature': 16.666666666666668, 'entity_id': ['climate.thermostat_2']}: Error from API: 400: INVALID_ARGUMENT: coolCelsius contains an invalid value.: Bad Request

What version of Home Assistant Core has the issue?

2023.11.2

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant Container

Integration causing the issue

Google Nest

Link to integration documentation on our website

https://www.home-assistant.io/integrations/nest/

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Lower Heat at 10 pm Second: Error executing script. Error for call_service at pos 3: Error setting climate.thermostat temperature to {'temperature': 16.666666666666668, 'entity_id': ['climate.thermostat']}: Error from API: 400: INVALID_ARGUMENT: coolCelsius contains an invalid value.: Bad Request

Additional information

No response

pdobrien3 avatar Nov 12 '23 13:11 pdobrien3

Hey there @home-assistant/core, mind taking a look at this issue as it has been labeled with an integration (automation) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of automation can trigger bot actions by commenting:

  • @home-assistant close Closes the issue.
  • @home-assistant rename Awesome new title Renames the issue.
  • @home-assistant reopen Reopen the issue.
  • @home-assistant unassign automation Removes the current integration label and assignees on the issue, add the integration domain after the command.

(message by CodeOwnersMention)


automation documentation automation source (message by IssueLinks)

home-assistant[bot] avatar Nov 12 '23 13:11 home-assistant[bot]

Hey there @allenporter, mind taking a look at this issue as it has been labeled with an integration (nest) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of nest can trigger bot actions by commenting:

  • @home-assistant close Closes the issue.
  • @home-assistant rename Awesome new title Renames the issue.
  • @home-assistant reopen Reopen the issue.
  • @home-assistant unassign nest Removes the current integration label and assignees on the issue, add the integration domain after the command.

(message by CodeOwnersMention)


nest documentation nest source (message by IssueLinks)

home-assistant[bot] avatar Nov 12 '23 13:11 home-assistant[bot]

  action:
    - service: input_boolean.turn_on
      data:
        entity_id: input_boolean.thermostats_auto
    - delay: 00:00:05        
    - service: climate.set_temperature
      entity_id: climate.thermostat_2
      data:
        temperature: '62'

pdobrien3 avatar Nov 12 '23 14:11 pdobrien3

~~I haven't been able to pull logs yet but I did want to comment that my Nest automations suddenly seem to have stopped working as well based on the cold house I woke up in this morning 🫠~~

Update automations seem to be working again this morning, so maybe it was an API blip? I updated to 2023.11.2 as well, but since the original report was on that version and I don't think this was touched in 11.2 (I was on 11.1 prior), I doubt that's related.

zwrose avatar Nov 12 '23 14:11 zwrose

Currently the nest integration doesn't really do anything with the value passed in by Home Assistant, and it just passes it straight through to the Nest API. Presumably the Nest API behavior has changed here. However, i'm not yet able to reproduce this myself.

The only thing I can think of is that it's passing too many decimal places and now expects the input to be rounded to fewer digits?

It could be helpful if you can enable debug logging for the integration and run this again and capture the debug data from the full log, then we can see what the exact request being sent to the Nest API.

allenporter avatar Nov 12 '23 16:11 allenporter

This looks to be related? https://developers.google.com/nest/device-access/api/thermostat#change_the_temperature_setpoints

pdobrien3 avatar Nov 13 '23 12:11 pdobrien3

Error while executing automation automation.lower_heat_at_10_pm_main: Error setting climate.thermostat_2 temperature to {'temperature': 16.666666666666668, 'entity_id': ['climate.thermostat_2']}: Error from API: 400: FAILED_PRECONDITION: sdm.devices.commands.ThermostatTemperatureSetpoint.SetHeat command not allowed in current thermostat mode.: Bad Request

same but different i guess. my thermostat automations have worked flawlessly for years until recently.

pdobrien3 avatar Nov 16 '23 10:11 pdobrien3

OK, so maybe what we need is all of this at once (1) integrations diagnostics to understand the current mode/state and (2) debug log messages to see recent events and recent commands

(I'm wondering if the API is rejecting the commands because its not in the right state, or because the decimal format is too long, etc. We can try rounding but you have an example above where it seemed to work fine)

allenporter avatar Nov 16 '23 16:11 allenporter

Just to clarify: I believe so far you have given an error message, but not the debug logs associated with that error message. I think we need both at the same time.

allenporter avatar Nov 16 '23 16:11 allenporter

The above is a perfect example of the randomness of the errors. The two automations are exactly the same for both the main floor and the second floor. They both attempt to lower the temp at 10:00 pm. In the above example, the second floor automation completed without an error and lowered the temp. The main floor automation errored and didn't.

pdobrien3 avatar Nov 18 '23 12:11 pdobrien3

OK, this is a different set of errors than before: SetHeat command not allowed in current thermostat mode This seems to be saying you can't set the heat temperature when not in heat mode. So you need to first turn on heat mode then set the temperature, but the logs show the reverse order. That seems plausible given the logs above.

(Beyond that, what would be helpful if we can is focus on a specific entity and service calls + diagnostics, reproducing it outside the automation. It's a bit hard to say for sure if multiple devices are being touched here.)

allenporter avatar Nov 18 '23 16:11 allenporter

I am not sure what you mean by the second part, give me an example and I will do it. As far as the first part, the heat is always on. I actually have a condition to check if the heat is on. I basically have similar automations for heat/AC, with conditions that determine which one runs. As a matter of fact, I change the temps throughout the day depending on presence and certain times. The heat is raised back up at 0400 and that automation never errors. Again, the automations are exactly the same. I need to check if at 0400 the temps is being raised to the setpoint already on the thermostat, but that really shouldn't matter.

Also, realize there are 2 thermostats in those logs

pdobrien3 avatar Nov 18 '23 21:11 pdobrien3

OK, so the API server says your device is not in heat mode but you are saying it is in heat mode. That's not really in my control if that is the case.

What i'm saying on the second half is getting into the details of your specific automations is difficult. What is easier is for me to help with is something like this:

  • here is the current state of the entity
  • here is the service call i sent
  • this is what i expect
  • this is what happened
  • here are the diagnostics at the start and end (https://www.home-assistant.io/integrations/diagnostics/)
  • here are the debug logs showing the api calls sent

If we get it that simple then its easier for me to understand what is happening to get to the bottom of this. (I can't get into the details of your automations since it involves other things i can't really reason about or see)

Happy to keep digging here.

allenporter avatar Nov 18 '23 22:11 allenporter

any chance you can tell me when this was implemented (https://github.com/home-assistant/core/issues/92927#issuecomment-1763044721). I may roll back and see if it fixes the problem.

pdobrien3 avatar Nov 20 '23 11:11 pdobrien3

This am I woke up to both my thermostats in the off mode. When I checked the history, they both say Turned off triggered by automation Raise Heat at 3 am weekdays Main triggered by time Here is that automation for one of the thermostats. They are exact replicas minus the entity_id.

- id: 'x4'
  alias: Raise Heat at 3 am weekdays Main
  trigger:
    platform: time
    at: '04:00:00'
  condition:
    - condition: state
      entity_id: climate.thermostat_2
      state: 'heat'
    - condition: state
      entity_id: input_boolean.vacations_mode
      state: 'off'
    - condition: time
      weekday:
        - mon
        - tue
        - wed
        - thu
        - fri
    - condition: template
      value_template: "{{ state_attr('climate.thermostat_2', 'preset_mode') != 'eco' }}"
  action:
    - service: input_boolean.turn_on
      data:
        entity_id: input_boolean.thermostats_auto
    - delay: 00:00:05        
    - service: climate.set_temperature
      entity_id: climate.thermostat_2
      data:
        temperature: 67

pdobrien3 avatar Nov 20 '23 11:11 pdobrien3

If I look in the app, click on each thermostat and select mode, they both say Heat

pdobrien3 avatar Nov 20 '23 12:11 pdobrien3

So presumably the server published an incorrect off message at some point given the thermostat didn't turn off. Capturing event debug messages will show if this is the case or now.

allenporter avatar Nov 20 '23 16:11 allenporter

Getting the same issues as described above. My automation/script works when I trigger at some times in the day, but others it gives this error. I also have 2 thermostats. Haven't had the issue until recently, running ha in docker 11.2

For each command, the script logs it as level info in my logger. Note below, bdayhpos4 (hallway thermostat), and bdaykpos4 (kitchen thermostat). When this was called, the kitchen thermostat got set just fine.

Super strange...

2023-11-20 17:00:00.481 INFO (MainThread) [climate.script] for schedule = bdayhpos4, thermostat climate.hallway will be set = 66 2023-11-20 17:00:07.425 ERROR (MainThread) [homeassistant.components.script.climate_upstairs] Thermostat Scheduler: If at step 1: Error executing script. Error for call_service at pos 3: Error setting climate.hallway temperature to {'temperature': 18.88888888888889, 'entity_id': ['climate.hallway']}: Error from API: 400: INVALID_ARGUMENT: coolCelsius contains an invalid value.: Bad Request 2023-11-20 17:00:07.426 ERROR (MainThread) [homeassistant.components.script.climate_upstairs] Thermostat Scheduler: Error executing script. Error for if at pos 1: Error setting climate.hallway temperature to {'temperature': 18.88888888888889, 'entity_id': ['climate.hallway']}: Error from API: 400: INVALID_ARGUMENT: coolCelsius contains an invalid value.: Bad Request 2023-11-20 17:00:07.427 ERROR (MainThread) [homeassistant.components.script.climate_wrapper_2] Thermostat Wrapper 2: Repeat at step 1: Error executing script. Error for call_service at pos 1: Error setting climate.hallway temperature to {'temperature': 18.88888888888889, 'entity_id': ['climate.hallway']}: Error from API: 400: INVALID_ARGUMENT: coolCelsius contains an invalid value.: Bad Request 2023-11-20 17:00:09.434 INFO (MainThread) [climate.script] for schedule = bdaykpos4, thermostat climate.kitchen will be set = 68

Mark612 avatar Nov 21 '23 00:11 Mark612

If I had to guess, it seems in some cases the thermostat/API thinks we are cooling, when it is set at heating. I pass the temperature as 66, and it returns 18.8888888....

Mark612 avatar Nov 21 '23 00:11 Mark612

@Mark612 thanks, can you give some steps to reproduce like the following:

  • state of the thermostat from home assistant developer tools
  • a service call that reproduces the problem
  • debugging enabled to capture requests, then some example requests that failed

(Understanding automations involved is harder since there are more variables to consider, unless you have more data about what is happening for each step for the automation)

Also, just to be clear, this is needed to report the issue to google if this is a server side API issue.

allenporter avatar Nov 21 '23 00:11 allenporter

heat

hvac_modes: heat, cool, heat_cool, off min_temp: 50 max_temp: 90 fan_modes: on, off preset_modes: none, eco current_temperature: 64 temperature: 66 target_temp_high: null target_temp_low: null fan_mode: off hvac_action: heating preset_mode: none friendly_name: Hallway supported_features: 27

I'm using a new method, automation that alls a script.

Script service call:

       - service: climate.set_temperature
         target:
            entity_id: '{{my_thermostat}}'
         data:
            temperature: '{{my_temperature}}'

I can work on turning on debugging when I can get back to my office. Another clue, it seems that it always fails for my hallway thermostat (a newer model), than my kitchen thermostat. I even tried to switch the calls, kitchen, then hallway. And also tried putting a delay between them of 3 to 10 seconds. Sometimes it works.

When I used the old automation way (no scripts), it always worked the last couple of years. I wonder if we are parsing the variable with extra symbols or \n or something when we convert {{variable}} to the actual temperature, then send it to google.

action: - service: climate.set_temperature target: entity_id: climate.hallway data: temperature: 63

Mark612 avatar Nov 21 '23 00:11 Mark612

i am sure you read all the posts but just to reiterate, i have two thermostats also and it is super inconsistent Until last night, it was only my 10 pm automation that showed errors. sometimes one thermostat, sometimes both, sometimes neither. i finally turned on debug logs full time instead of just trying to catch the 10 pm automation

pdobrien3 avatar Nov 21 '23 01:11 pdobrien3

There is nothing in the logs, related to the thermostats, between the 10 pm and 4 am time period.

The target temperature did in fact change for the main floor thermostat at 4am, but not at 10pm The target temperature didnt change for the second thermostat at 10 pm and was irrelevant at 4 am as the target temp for the 4am automation was 64 degrees and the thermostat was already set to 64 degrees.

reloading the integration, once again brought the main floor thermostat back to its correct state of heat.

pdobrien3 avatar Nov 21 '23 11:11 pdobrien3

It seems that there are two things:

  • nest API is rejecting the request to lower the heat. (Home assistant can't control that)
  • nest API is publishing commands that say the thermostat is off. reloading the integration loads the real state from the server

Can you find the debug messages where the server is publishing an off HVAC mode event incorrectly?

allenporter avatar Nov 21 '23 13:11 allenporter

Any idea what I can search the logs for? I honestly thing the hass UI is incorrectly reporting the state because I saw this in another custom component and I didn’t see any other events related to the thermostats. Happy to search though.

pdobrien3 avatar Nov 21 '23 13:11 pdobrien3

I don't think it's a home assistant UI bug.

Search "sdm" in the logs.

allenporter avatar Nov 21 '23 13:11 allenporter

In that last log, what happened to the requests from the original trace? For example the requests at 2023-11-20 22:00:05.193

allenporter avatar Nov 21 '23 21:11 allenporter

I already posted them so I didn't include them

pdobrien3 avatar Nov 21 '23 22:11 pdobrien3

did the logs produce anything beneficial? need anything else? next step?

pdobrien3 avatar Nov 22 '23 23:11 pdobrien3

@pdobrien3 no, I don't have any insights yet. It is a little hard without the full detail here: https://github.com/home-assistant/core/issues/103846#issuecomment-1817660634 (the piecemeal information and multiple devices is a little hard to put together)

allenporter avatar Nov 23 '23 05:11 allenporter