search

bob1de / hass-apps

Some useful apps and snippets to empower Home Assistant and AppDaemon even more.
Apache License 2.0
86 stars 23 forks source link

[schedy] Overlays aren't applied when they won't change the scheduled value #40

Closed thundergreen closed 5 years ago

thundergreen commented 5 years ago

Hello.

As already mentioned, I seem having a corner case issue with my open door / window sensor. The goal is to stop the ac / save the last state and resume once the window has been closed again.

I tried already after start-up of shedy to change the temperature first to get a temperature value in shedy. Then I open the given window. It seems having detected those but won't change the operation_mode to OFF: Here the log part:

2019-11-10 15:28:34.067984 INFO bedroom_heating: --- [R:bedroom]     ������ => Mark(OFF, {'OVERLAY'})
2019-11-10 15:28:34.069730 INFO bedroom_heating: --- [R:bedroom] Final result: OFF
2019-11-10 15:28:34.071002 INFO bedroom_heating: --- [R:bedroom] Result markers: {'OVERLAY'}
2019-11-10 15:28:34.076204 INFO bedroom_heating: --- [R:bedroom] Result didn't change, not setting it again.

My config is:

bedroom_heating:
  module: hass_apps_loader
  class: SchedyApp

  actor_type: thermostat

  expression_environment: |
    def heating_mode():
        return state("input_select.heating_mode")
  schedule_prepend:
  - name: global schedule on/off switch
    x: "Abort() if is_off('input_boolean.automated_heating') else Next()"
  - name: per-room schedule on/off switch
    x: "Abort() if is_off('input_boolean.automated_heating_' + room_name) else Next()"
  - x: "Mark(OFF, Mark.OVERLAY) if not is_empty(filter_entities('binary_sensor', window_room=room_name, state='on')) else Next()"

  schedule_append:
  - v: "OFF"

  schedule_snippets:
    bedroom:
    - v: 21
      rules:
      # don't turn on when it's > 5 degrees in the bedroom
      - x: "Break() if float(state('sensor.temperature_bedroom') or 0) > 21 else Next()"
      - weekdays: 1-5
        rules:
        - rules:
          - x: "Next() if heating_mode() != 'All Home' else Break()"
          - { start: "06:00", end: "07:00" }
          - { start: "22:00", end: "23:59" }

      - weekdays: 6-7
        rules:
        - { start: "06:00", end: "07:00" }
        - { start: "22:30", end: "23:59" }

  watched_entities:
  - input_select.heating_mode
  - input_boolean.automated_heating
  - sensor.temperature_bedroom

  rooms:

    bedroom:
      rescheduling_delay: 15
      actors:
        climate.air_conditioner_bedroom:
      watched_entities:
      - sensor.temperature_bedroom
      - binary_sensor.window_bedroom
      - input_boolean.automated_heating_bedroom
      schedule:
      - x: "IncludeSchedule(schedule_snippets['bedroom'])"

  statistics:
    # Pick an arbitrary name for the parameter instance.
    bedroom_temp_delta:
      # The type of parameter as found in the actor'S documentation.
      type: temp_delta
      # More parameter-specific settings:
      rooms:
        bedroom:

The error log:

2019-11-10 15:24:22.003642 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Value for A:climate.air_conditioner_bedroom in R:bedroom is 0.0.
2019-11-10 15:24:22.005475 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Unchanged HA state: attributes={'min': 0.0, 'avg': 0.0, 'max': 0.0}
2019-11-10 15:25:43.929221 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'state' is 'heat'.
2019-11-10 15:25:43.932994 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'temperature' is 30.0.
2019-11-10 15:25:43.935268 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'current_temperature' is 22.8.
2019-11-10 15:25:43.937232 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Received value of 30.0��.
2019-11-10 15:25:43.939711 INFO bedroom_heating: --- [R:bedroom] Setting value to 30.0��.  [manual]
2019-11-10 15:25:43.949057 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Not sending value 30.0�� redundantly.
2019-11-10 15:25:43.951299 INFO bedroom_heating: --- [R:bedroom] Re-applying the schedule not before 15:40:43 (in 0:15:00).
2019-11-10 15:25:43.953091 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Going to update statistics in 3 seconds.
2019-11-10 15:25:43.971036 INFO bedroom_heating: <-- [R:bedroom] Sending state to HA: state='30.0', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': '30.0'}, 'scheduled_value': 'OFF', 'rescheduling_time': 1573396843.0, 'overlay_active': False}
2019-11-10 15:25:46.004839 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Value for A:climate.air_conditioner_bedroom in R:bedroom is 7.199999999999999.
2019-11-10 15:25:46.006213 INFO bedroom_heating: <-- [SP:bedroom_temp_delta] Sending state to HA: attributes={'min': 7.2, 'avg': 7.2, 'max': 7.2}
2019-11-10 15:28:33.852970 INFO bedroom_heating: --> Attribute 'state' of 'binary_sensor.window_bedroom' changed from 'off' to 'on', reevaluating <Room R:bedroom>.
2019-11-10 15:28:33.854094 INFO bedroom_heating: --- [R:bedroom] Doing schedule re-evaluation in 1 second [reset=False]
2019-11-10 15:28:34.038036 INFO bedroom_heating: --- [R:bedroom] Evaluating room's schedule (reset=False, force_resend=False).
2019-11-10 15:28:34.039271 INFO bedroom_heating: --- [R:bedroom] Assuming it to be 2019-11-10 15:28:34.
2019-11-10 15:28:34.040483 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/1:<Rule with sub <Schedule 'prepend'>>>
2019-11-10 15:28:34.041734 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/1:<Rule x='Mark(OFF, Mark.OVERLAY) if not is_empty('...>>
2019-11-10 15:28:34.043220 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: BasicHelper, order = 0
2019-11-10 15:28:34.044849 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: PatternHelper, order = 0
2019-11-10 15:28:34.046329 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ScheduleHelper, order = 0
2019-11-10 15:28:34.047775 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: StateHelper, order = 0
2019-11-10 15:28:34.049655 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ThermostatExpressionHelper, order = 0
2019-11-10 15:28:34.052220 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: CustomEnvironmentHelper, order = 1000
2019-11-10 15:28:34.054596 INFO bedroom_heating: --- [R:bedroom] Executing the expression_environment script.
2019-11-10 15:28:34.067984 INFO bedroom_heating: --- [R:bedroom]     ������ => Mark(OFF, {'OVERLAY'})
2019-11-10 15:28:34.069730 INFO bedroom_heating: --- [R:bedroom] Final result: OFF
2019-11-10 15:28:34.071002 INFO bedroom_heating: --- [R:bedroom] Result markers: {'OVERLAY'}
2019-11-10 15:28:34.076204 INFO bedroom_heating: --- [R:bedroom] Result didn't change, not setting it again.
2019-11-10 15:28:34.077493 INFO bedroom_heating: --- [R:bedroom] Unchanged HA state: state='30.0', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': '30.0'}, 'scheduled_value': 'OFF', 'rescheduling_time': 1573396843.0, 'overlay_active': False}
bob1de commented 5 years ago

Hi,

Thanks for reporting.

Could you please verify that this is fixed in the overlay-fix branch? You can simply use this URL in your requirements.txt/addon-config/whatever you use instead of hass-apps:

https://github.com/efficiosoft/hass-apps/archive/overlay-fix.zip

Best regards Robert

thundergreen commented 5 years ago

Hello Robert. That'S now working BUT:

If I turn on the climate outide the schedule and open the window it works like expected. But closing the window won't restore the last (maual set ) state of the climate. Is That intended? As Home Automation sometimes becomes too complaicated with all possible occurences we sometimes turn on the ac outside the schedule. Now if someone opens the window the ac get fine turned off but clsing the window will result in watching the schedule instead of the last state.

here the logs of the procedure:

2019-11-16 17:55:13.003862 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Value for A:climate.air_conditioner_bedroom in R:bedroom is 0.3999999999999986.
2019-11-16 17:55:13.005563 INFO bedroom_heating: <-- [SP:bedroom_temp_delta] Sending state to HA: attributes={'min': 0.4, 'avg': 0.4, 'max': 0.4}
2019-11-16 17:55:40.920798 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'state' is 'off'.
2019-11-16 17:55:41.059141 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'current_temperature' is 20.6.
2019-11-16 17:55:41.252090 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Received value of OFF.
2019-11-16 17:55:41.282340 INFO bedroom_heating: --- [R:bedroom] Setting value to OFF.  [scheduled]
2019-11-16 17:55:41.306402 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Not sending value OFF redundantly.
2019-11-16 17:55:41.425070 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Going to update statistics in 3 seconds.
2019-11-16 17:55:41.538224 INFO bedroom_heating: <-- [R:bedroom] Sending state to HA: state='OFF', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': 'OFF'}, 'scheduled_value': 'OFF', 'rescheduling_time': 1573924210.0, 'overlay_active': False}
2019-11-16 17:55:44.003240 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Value for A:climate.air_conditioner_bedroom in R:bedroom is 0.0.
2019-11-16 17:55:44.004676 INFO bedroom_heating: <-- [SP:bedroom_temp_delta] Sending state to HA: attributes={'min': 0.0, 'avg': 0.0, 'max': 0.0}
2019-11-16 17:56:30.943356 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'state' is 'heat'.
2019-11-16 17:56:31.067079 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'temperature' is 21.0.
2019-11-16 17:56:31.088086 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'current_temperature' is 20.6.
2019-11-16 17:56:31.089730 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Received value of 21.0��.
2019-11-16 17:56:31.091558 INFO bedroom_heating: --- [R:bedroom] Setting value to 21.0��.  [manual]
2019-11-16 17:56:31.112390 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Not sending value 21.0�� redundantly.
2019-11-16 17:56:31.114176 INFO bedroom_heating: --- [R:bedroom] Cancelled re-scheduling timer.
2019-11-16 17:56:31.165502 INFO bedroom_heating: --- [R:bedroom] Re-applying the schedule not before 18:11:31 (in 0:15:00).
2019-11-16 17:56:31.265933 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Going to update statistics in 3 seconds.
2019-11-16 17:56:31.428958 INFO bedroom_heating: <-- [R:bedroom] Sending state to HA: state='21.0', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': '21.0'}, 'scheduled_value': 'OFF', 'rescheduling_time': 1573924291.0, 'overlay_active': False}
2019-11-16 17:56:34.004790 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Value for A:climate.air_conditioner_bedroom in R:bedroom is 0.3999999999999986.
2019-11-16 17:56:34.006495 INFO bedroom_heating: <-- [SP:bedroom_temp_delta] Sending state to HA: attributes={'min': 0.4, 'avg': 0.4, 'max': 0.4}
2019-11-16 17:57:27.685107 INFO bedroom_heating: --> Attribute 'state' of 'binary_sensor.window_bedroom' changed from 'off' to 'on', reevaluating <Room R:bedroom>.
2019-11-16 17:57:27.687796 INFO bedroom_heating: --- [R:bedroom] Doing schedule re-evaluation in 1 second [reset=False]
2019-11-16 17:57:28.004770 INFO bedroom_heating: --- [R:bedroom] Evaluating room's schedule (reset=False, force_resend=False).
2019-11-16 17:57:28.006381 INFO bedroom_heating: --- [R:bedroom] Assuming it to be 2019-11-16 17:57:28.
2019-11-16 17:57:28.008301 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/1:<Rule with sub <Schedule 'prepend'>>>
2019-11-16 17:57:28.010078 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/1:<Rule x='Mark(OFF, Mark.OVERLAY) if not is_empty('...>>
2019-11-16 17:57:28.011623 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: BasicHelper, order = 0
2019-11-16 17:57:28.013095 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: PatternHelper, order = 0
2019-11-16 17:57:28.014822 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ScheduleHelper, order = 0
2019-11-16 17:57:28.016650 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: StateHelper, order = 0
2019-11-16 17:57:28.019301 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ThermostatExpressionHelper, order = 0
2019-11-16 17:57:28.021938 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: CustomEnvironmentHelper, order = 1000
2019-11-16 17:57:28.024235 INFO bedroom_heating: --- [R:bedroom] Executing the expression_environment script.
2019-11-16 17:57:28.030811 INFO bedroom_heating: --- [R:bedroom]     ������ => Mark(OFF, {'OVERLAY'})
2019-11-16 17:57:28.032471 INFO bedroom_heating: --- [R:bedroom] Final result: OFF
2019-11-16 17:57:28.033688 INFO bedroom_heating: --- [R:bedroom] Result markers: {'OVERLAY'}
2019-11-16 17:57:28.034777 INFO bedroom_heating: --- [R:bedroom] Storing value 21.0�� before overlaying.
2019-11-16 17:57:28.035940 INFO bedroom_heating: --- [R:bedroom] Cancelled re-scheduling timer.
2019-11-16 17:57:28.036972 INFO bedroom_heating: --- [R:bedroom] Setting value to OFF.  [scheduled]
2019-11-16 17:57:28.038346 INFO bedroom_heating: <-- [R:bedroom] [A:climate.air_conditioner_bedroom] Setting value OFF (left tries = 11).
2019-11-16 17:57:28.039787 INFO bedroom_heating: <-- [R:bedroom] [A:climate.air_conditioner_bedroom] Setting temperature = '<unset>', HVAC mode = 'off'.
2019-11-16 17:57:28.068686 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Re-sending in 30 seconds.
2019-11-16 17:57:28.071394 INFO bedroom_heating: <-- [R:bedroom] Value set to OFF.  [scheduled]
2019-11-16 17:57:28.073511 INFO bedroom_heating: <-- [R:bedroom] Sending state to HA: state='OFF', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': 'OFF'}, 'scheduled_value': 'OFF', 'rescheduling_time': None, 'overlay_active': True, 'overlaid_wanted_value': '21.0', 'overlaid_scheduled_value': 'OFF', 'overlaid_rescheduling_time': 1573924291.0}
2019-11-16 17:57:28.496400 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'state' is 'off'.
2019-11-16 17:57:28.515424 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'current_temperature' is 20.6.
2019-11-16 17:57:28.516803 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Cancelled re-sending timer.
2019-11-16 17:57:28.518091 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Received value of OFF.
2019-11-16 17:57:28.520331 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Going to update statistics in 3 seconds.
2019-11-16 17:57:28.521563 INFO bedroom_heating: --- [R:bedroom] Unchanged HA state: state='OFF', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': 'OFF'}, 'scheduled_value': 'OFF', 'rescheduling_time': None, 'overlay_active': True, 'overlaid_wanted_value': '21.0', 'overlaid_scheduled_value': 'OFF', 'overlaid_rescheduling_time': 1573924291.0}
2019-11-16 17:57:31.085452 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Value for A:climate.air_conditioner_bedroom in R:bedroom is 0.0.
2019-11-16 17:57:31.086699 INFO bedroom_heating: <-- [SP:bedroom_temp_delta] Sending state to HA: attributes={'min': 0.0, 'avg': 0.0, 'max': 0.0}
2019-11-16 17:57:47.697270 INFO bedroom_heating: --> Attribute 'state' of 'binary_sensor.window_bedroom' changed from 'on' to 'off', reevaluating <Room R:bedroom>.
2019-11-16 17:57:47.698529 INFO bedroom_heating: --- [R:bedroom] Doing schedule re-evaluation in 1 second [reset=False]
2019-11-16 17:57:48.005726 INFO bedroom_heating: --- [R:bedroom] Evaluating room's schedule (reset=False, force_resend=False).
2019-11-16 17:57:48.008731 INFO bedroom_heating: --- [R:bedroom] Assuming it to be 2019-11-16 17:57:48.
2019-11-16 17:57:48.010957 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/1:<Rule with sub <Schedule 'prepend'>>>
2019-11-16 17:57:48.012403 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/1:<Rule x='Mark(OFF, Mark.OVERLAY) if not is_empty('...>>
2019-11-16 17:57:48.013756 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: BasicHelper, order = 0
2019-11-16 17:57:48.015257 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: PatternHelper, order = 0
2019-11-16 17:57:48.016434 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ScheduleHelper, order = 0
2019-11-16 17:57:48.017649 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: StateHelper, order = 0
2019-11-16 17:57:48.019084 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ThermostatExpressionHelper, order = 0
2019-11-16 17:57:48.020521 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: CustomEnvironmentHelper, order = 1000
2019-11-16 17:57:48.021850 INFO bedroom_heating: --- [R:bedroom] Executing the expression_environment script.
2019-11-16 17:57:48.027388 INFO bedroom_heating: --- [R:bedroom]     ������ => Next()
2019-11-16 17:57:48.028655 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/2:<Rule x="Abort() if is_off('input_boolean.automat"...>>
2019-11-16 17:57:48.029907 INFO bedroom_heating: --- [R:bedroom]     ������ => Next()
2019-11-16 17:57:48.031368 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/3:<Rule x="Abort() if is_off('input_boolean.automat"...>>
2019-11-16 17:57:48.033618 INFO bedroom_heating: --- [R:bedroom]     ������ => Next()
2019-11-16 17:57:48.035821 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/2:<Rule with sub <Schedule 'room-individual'>>>
2019-11-16 17:57:48.037815 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/2/1:<Rule x="IncludeSchedule(schedule_snippets['bedro"...>>
2019-11-16 17:57:48.039890 INFO bedroom_heating: --- [R:bedroom]     ������ => IncludeSchedule(<Schedule 'bedroom'>)
2019-11-16 17:57:48.042045 INFO bedroom_heating: --- [R:bedroom]     ������ [SUB]  <<Schedule 'bedroom'>/2/?:<Rule with sub <Schedule 'bedroom'>>>
2019-11-16 17:57:48.044292 INFO bedroom_heating: --- [R:bedroom]         ������ [SUB]  <<Schedule 'bedroom'>/2/?/1:<Rule with sub <Schedule of 3 rules>, v=21>>
2019-11-16 17:57:48.046110 INFO bedroom_heating: --- [R:bedroom]             ������ [ACT]  <<Schedule 'bedroom'>/2/?/1/1:<Rule x="Break() if float(state('sensor.temperatu"...>>
2019-11-16 17:57:48.048118 INFO bedroom_heating: --- [R:bedroom]             ������ => Next()
2019-11-16 17:57:48.050000 INFO bedroom_heating: --- [R:bedroom]             ������ [SUB]  <<Schedule 'bedroom'>/2/?/1/2:<Rule with sub <Schedule of 1 rules>, weekdays={1-5}>>
2019-11-16 17:57:48.051871 INFO bedroom_heating: --- [R:bedroom]                 ������ [SUB]  <<Schedule 'bedroom'>/2/?/1/2/1:<Rule with sub <Schedule of 3 rules>>>
2019-11-16 17:57:48.053984 INFO bedroom_heating: --- [R:bedroom]                     ������ [INA]  <<Schedule 'bedroom'>/2/?/1/2/1/1:<Rule x="Next() if heating_mode() != 'All Home' e"...>>
2019-11-16 17:57:48.055746 INFO bedroom_heating: --- [R:bedroom]                     ������ [INA]  <<Schedule 'bedroom'>/2/?/1/2/1/2:<Rule from 06:00 to 07:00>>
2019-11-16 17:57:48.058171 INFO bedroom_heating: --- [R:bedroom]                     ������ [INA]  <<Schedule 'bedroom'>/2/?/1/2/1/3:<Rule from 22:00 to 23:59>>
2019-11-16 17:57:48.060680 INFO bedroom_heating: --- [R:bedroom]             ������ [SUB]  <<Schedule 'bedroom'>/2/?/1/3:<Rule with sub <Schedule of 2 rules>, weekdays={6-7}>>
2019-11-16 17:57:48.062309 INFO bedroom_heating: --- [R:bedroom]                 ������ [INA]  <<Schedule 'bedroom'>/2/?/1/3/1:<Rule from 06:00 to 07:00>>
2019-11-16 17:57:48.063598 INFO bedroom_heating: --- [R:bedroom]                 ������ [INA]  <<Schedule 'bedroom'>/2/?/1/3/2:<Rule from 22:30 to 23:59>>
2019-11-16 17:57:48.064720 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/3:<Rule with sub <Schedule 'append'>>>
2019-11-16 17:57:48.065836 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/3/1:<Rule v='OFF'>>
2019-11-16 17:57:48.066967 INFO bedroom_heating: --- [R:bedroom]     ������ => 'OFF'
2019-11-16 17:57:48.068053 INFO bedroom_heating: --- [R:bedroom] Final result: OFF
2019-11-16 17:57:48.069338 INFO bedroom_heating: --- [R:bedroom] Result didn't change, not setting it again.
2019-11-16 17:57:48.071231 INFO bedroom_heating: --- [R:bedroom] Unchanged HA state: state='OFF', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': 'OFF'}, 'scheduled_value': 'OFF', 'rescheduling_time': None, 'overlay_active': True, 'overlaid_wanted_value': '21.0', 'overlaid_scheduled_value': 'OFF', 'overlaid_rescheduling_time': 1573924291.0}
bob1de commented 5 years ago

You're right, I missed that route. Could you please retry and give such a great log again?

thundergreen commented 5 years ago

It seems working :) GREAT JOB! Awesome!!!

2019-11-16 18:44:19.705399 ERROR bedroom_heating: !!! [R:bedroom] [A:climate.air_conditioner_bedroom] Unknown HVAC mode 'cool', ignoring thermostat.
2019-11-16 18:44:19.707596 INFO bedroom_heating: --- [R:bedroom] Unchanged HA state: state='OFF', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': 'OFF'}, 'scheduled_value': 'OFF', 'rescheduling_time': 1573927122.0, 'overlay_active': False}
2019-11-16 18:44:20.708867 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'state' is 'heat'.
2019-11-16 18:44:20.714884 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'temperature' is 21.0.
2019-11-16 18:44:20.724106 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'current_temperature' is 20.8.
2019-11-16 18:44:20.735260 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Received value of 21.0��.
2019-11-16 18:44:20.737418 INFO bedroom_heating: --- [R:bedroom] Setting value to 21.0��.  [manual]
2019-11-16 18:44:20.740439 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Not sending value 21.0�� redundantly.
2019-11-16 18:44:20.742925 INFO bedroom_heating: --- [R:bedroom] Cancelled re-scheduling timer.
2019-11-16 18:44:20.746225 INFO bedroom_heating: --- [R:bedroom] Re-applying the schedule not before 18:59:20 (in 0:15:00).
2019-11-16 18:44:20.748515 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Going to update statistics in 3 seconds.
2019-11-16 18:44:20.750782 INFO bedroom_heating: <-- [R:bedroom] Sending state to HA: state='21.0', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': '21.0'}, 'scheduled_value': 'OFF', 'rescheduling_time': 1573927160.0, 'overlay_active': False}
2019-11-16 18:44:23.004049 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Value for A:climate.air_conditioner_bedroom in R:bedroom is 0.1999999999999993.
2019-11-16 18:44:23.006116 INFO bedroom_heating: <-- [SP:bedroom_temp_delta] Sending state to HA: attributes={'min': 0.2, 'avg': 0.2, 'max': 0.2}
2019-11-16 18:44:40.942017 INFO bedroom_heating: --> Attribute 'state' of 'binary_sensor.window_bedroom' changed from 'off' to 'on', reevaluating <Room R:bedroom>.
2019-11-16 18:44:40.944438 INFO bedroom_heating: --- [R:bedroom] Doing schedule re-evaluation in 1 second [reset=False]
2019-11-16 18:44:41.008801 INFO bedroom_heating: --- [R:bedroom] Evaluating room's schedule (reset=False, force_resend=False).
2019-11-16 18:44:41.012335 INFO bedroom_heating: --- [R:bedroom] Assuming it to be 2019-11-16 18:44:41.
2019-11-16 18:44:41.014996 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/1:<Rule with sub <Schedule 'prepend'>>>
2019-11-16 18:44:41.017916 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/1:<Rule x='Mark(OFF, Mark.OVERLAY) if not is_empty('...>>
2019-11-16 18:44:41.020483 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: BasicHelper, order = 0
2019-11-16 18:44:41.023049 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: PatternHelper, order = 0
2019-11-16 18:44:41.024402 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ScheduleHelper, order = 0
2019-11-16 18:44:41.026684 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: StateHelper, order = 0
2019-11-16 18:44:41.029499 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ThermostatExpressionHelper, order = 0
2019-11-16 18:44:41.032043 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: CustomEnvironmentHelper, order = 1000
2019-11-16 18:44:41.033328 INFO bedroom_heating: --- [R:bedroom] Executing the expression_environment script.
2019-11-16 18:44:41.037617 INFO bedroom_heating: --- [R:bedroom]     ������ => Mark(OFF, {'OVERLAY'})
2019-11-16 18:44:41.038729 INFO bedroom_heating: --- [R:bedroom] Final result: OFF
2019-11-16 18:44:41.039857 INFO bedroom_heating: --- [R:bedroom] Result markers: {'OVERLAY'}
2019-11-16 18:44:41.041944 INFO bedroom_heating: --- [R:bedroom] Storing value 21.0�� before overlaying.
2019-11-16 18:44:41.044523 INFO bedroom_heating: --- [R:bedroom] Cancelled re-scheduling timer.
2019-11-16 18:44:41.046244 INFO bedroom_heating: --- [R:bedroom] Setting value to OFF.  [scheduled]
2019-11-16 18:44:41.047778 INFO bedroom_heating: <-- [R:bedroom] [A:climate.air_conditioner_bedroom] Setting value OFF (left tries = 11).
2019-11-16 18:44:41.049273 INFO bedroom_heating: <-- [R:bedroom] [A:climate.air_conditioner_bedroom] Setting temperature = '<unset>', HVAC mode = 'off'.
2019-11-16 18:44:41.091265 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Re-sending in 30 seconds.
2019-11-16 18:44:41.094906 INFO bedroom_heating: <-- [R:bedroom] Value set to OFF.  [scheduled]
2019-11-16 18:44:41.096970 INFO bedroom_heating: <-- [R:bedroom] Sending state to HA: state='OFF', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': 'OFF'}, 'scheduled_value': 'OFF', 'rescheduling_time': None, 'overlay_active': True, 'overlaid_wanted_value': '21.0', 'overlaid_scheduled_value': 'OFF', 'overlaid_rescheduling_time': 1573927160.0}
2019-11-16 18:44:41.977568 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'state' is 'off'.
2019-11-16 18:44:41.979603 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'current_temperature' is 20.8.
2019-11-16 18:44:41.981388 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Cancelled re-sending timer.
2019-11-16 18:44:41.993969 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Received value of OFF.
2019-11-16 18:44:42.020525 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Going to update statistics in 3 seconds.
2019-11-16 18:44:42.073862 INFO bedroom_heating: --- [R:bedroom] Unchanged HA state: state='OFF', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': 'OFF'}, 'scheduled_value': 'OFF', 'rescheduling_time': None, 'overlay_active': True, 'overlaid_wanted_value': '21.0', 'overlaid_scheduled_value': 'OFF', 'overlaid_rescheduling_time': 1573927160.0}
2019-11-16 18:44:45.004537 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Value for A:climate.air_conditioner_bedroom in R:bedroom is 0.0.
2019-11-16 18:44:45.006219 INFO bedroom_heating: <-- [SP:bedroom_temp_delta] Sending state to HA: attributes={'min': 0.0, 'avg': 0.0, 'max': 0.0}
2019-11-16 18:45:02.366861 INFO bedroom_heating: --> Attribute 'state' of 'binary_sensor.window_bedroom' changed from 'on' to 'off', reevaluating <Room R:bedroom>.
2019-11-16 18:45:02.439069 INFO bedroom_heating: --- [R:bedroom] Doing schedule re-evaluation in 1 second [reset=False]
2019-11-16 18:45:03.004371 INFO bedroom_heating: --- [R:bedroom] Evaluating room's schedule (reset=False, force_resend=False).
2019-11-16 18:45:03.006832 INFO bedroom_heating: --- [R:bedroom] Assuming it to be 2019-11-16 18:45:03.
2019-11-16 18:45:03.008992 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/1:<Rule with sub <Schedule 'prepend'>>>
2019-11-16 18:45:03.010425 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/1:<Rule x='Mark(OFF, Mark.OVERLAY) if not is_empty('...>>
2019-11-16 18:45:03.012701 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: BasicHelper, order = 0
2019-11-16 18:45:03.014645 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: PatternHelper, order = 0
2019-11-16 18:45:03.016041 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ScheduleHelper, order = 0
2019-11-16 18:45:03.017507 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: StateHelper, order = 0
2019-11-16 18:45:03.024332 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ThermostatExpressionHelper, order = 0
2019-11-16 18:45:03.031280 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: CustomEnvironmentHelper, order = 1000
2019-11-16 18:45:03.033425 INFO bedroom_heating: --- [R:bedroom] Executing the expression_environment script.
2019-11-16 18:45:03.042885 INFO bedroom_heating: --- [R:bedroom]     ������ => Next()
2019-11-16 18:45:03.045098 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/2:<Rule x="Abort() if is_off('input_boolean.automat"...>>
2019-11-16 18:45:03.047349 INFO bedroom_heating: --- [R:bedroom]     ������ => Next()
2019-11-16 18:45:03.049407 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/3:<Rule x="Abort() if is_off('input_boolean.automat"...>>
2019-11-16 18:45:03.051471 INFO bedroom_heating: --- [R:bedroom]     ������ => Next()
2019-11-16 18:45:03.052825 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/2:<Rule with sub <Schedule 'room-individual'>>>
2019-11-16 18:45:03.054023 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/2/1:<Rule x="IncludeSchedule(schedule_snippets['bedro"...>>
2019-11-16 18:45:03.055354 INFO bedroom_heating: --- [R:bedroom]     ������ => IncludeSchedule(<Schedule 'bedroom'>)
2019-11-16 18:45:03.057740 INFO bedroom_heating: --- [R:bedroom]     ������ [SUB]  <<Schedule 'bedroom'>/2/?:<Rule with sub <Schedule 'bedroom'>>>
2019-11-16 18:45:03.060168 INFO bedroom_heating: --- [R:bedroom]         ������ [SUB]  <<Schedule 'bedroom'>/2/?/1:<Rule with sub <Schedule of 3 rules>, v=21>>
2019-11-16 18:45:03.062373 INFO bedroom_heating: --- [R:bedroom]             ������ [ACT]  <<Schedule 'bedroom'>/2/?/1/1:<Rule x="Break() if float(state('sensor.temperatu"...>>
2019-11-16 18:45:03.065942 INFO bedroom_heating: --- [R:bedroom]             ������ => Next()
2019-11-16 18:45:03.068255 INFO bedroom_heating: --- [R:bedroom]             ������ [SUB]  <<Schedule 'bedroom'>/2/?/1/2:<Rule with sub <Schedule of 1 rules>, weekdays={1-5}>>
2019-11-16 18:45:03.070308 INFO bedroom_heating: --- [R:bedroom]                 ������ [SUB]  <<Schedule 'bedroom'>/2/?/1/2/1:<Rule with sub <Schedule of 3 rules>>>
2019-11-16 18:45:03.072460 INFO bedroom_heating: --- [R:bedroom]                     ������ [INA]  <<Schedule 'bedroom'>/2/?/1/2/1/1:<Rule x="Next() if heating_mode() != 'All Home' e"...>>
2019-11-16 18:45:03.074301 INFO bedroom_heating: --- [R:bedroom]                     ������ [INA]  <<Schedule 'bedroom'>/2/?/1/2/1/2:<Rule from 06:00 to 07:00>>
2019-11-16 18:45:03.075582 INFO bedroom_heating: --- [R:bedroom]                     ������ [INA]  <<Schedule 'bedroom'>/2/?/1/2/1/3:<Rule from 22:00 to 23:59>>
2019-11-16 18:45:03.076894 INFO bedroom_heating: --- [R:bedroom]             ������ [SUB]  <<Schedule 'bedroom'>/2/?/1/3:<Rule with sub <Schedule of 2 rules>, weekdays={6-7}>>
2019-11-16 18:45:03.078714 INFO bedroom_heating: --- [R:bedroom]                 ������ [INA]  <<Schedule 'bedroom'>/2/?/1/3/1:<Rule from 06:00 to 07:00>>
2019-11-16 18:45:03.080419 INFO bedroom_heating: --- [R:bedroom]                 ������ [INA]  <<Schedule 'bedroom'>/2/?/1/3/2:<Rule from 22:30 to 23:59>>
2019-11-16 18:45:03.082043 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/3:<Rule with sub <Schedule 'append'>>>
2019-11-16 18:45:03.083406 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/3/1:<Rule v='OFF'>>
2019-11-16 18:45:03.084692 INFO bedroom_heating: --- [R:bedroom]     ������ => 'OFF'
2019-11-16 18:45:03.086029 INFO bedroom_heating: --- [R:bedroom] Final result: OFF
2019-11-16 18:45:03.087271 INFO bedroom_heating: --- [R:bedroom] Restoring overlaid value 21.0��.
2019-11-16 18:45:03.088733 INFO bedroom_heating: --- [R:bedroom] Setting value to 21.0��.  [manual]
2019-11-16 18:45:03.091362 INFO bedroom_heating: <-- [R:bedroom] [A:climate.air_conditioner_bedroom] Setting value 21.0�� (left tries = 11).
2019-11-16 18:45:03.093923 INFO bedroom_heating: <-- [R:bedroom] [A:climate.air_conditioner_bedroom] Setting temperature = 21.0��, HVAC mode = 'heat'.
2019-11-16 18:45:03.166345 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Re-sending in 30 seconds.
2019-11-16 18:45:03.170661 INFO bedroom_heating: <-- [R:bedroom] Value set to 21.0��.  [manual]
2019-11-16 18:45:03.172701 INFO bedroom_heating: --- [R:bedroom] Re-applying the schedule not before 18:59:20 (in 0:14:17).
2019-11-16 18:45:03.174994 INFO bedroom_heating: <-- [R:bedroom] Sending state to HA: state='21.0', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': '21.0'}, 'scheduled_value': 'OFF', 'rescheduling_time': 1573927160.0, 'overlay_active': False}
2019-11-16 18:45:03.653017 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'state' is 'heat'.
2019-11-16 18:45:03.655120 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'temperature' is 21.0.
2019-11-16 18:45:03.660059 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'current_temperature' is 20.8.
2019-11-16 18:45:03.667843 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Cancelled re-sending timer.
2019-11-16 18:45:03.673936 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Received value of 21.0��.
2019-11-16 18:45:03.675835 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Going to update statistics in 3 seconds.
2019-11-16 18:45:03.677729 INFO bedroom_heating: --- [R:bedroom] Unchanged HA state: state='21.0', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': '21.0'}, 'scheduled_value': 'OFF', 'rescheduling_time': 1573927160.0, 'overlay_active': False}
2019-11-16 18:45:06.005850 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Value for A:climate.air_conditioner_bedroom in R:bedroom is 0.1999999999999993.
2019-11-16 18:45:06.008189 INFO bedroom_heating: <-- [SP:bedroom_temp_delta] Sending state to HA: attributes={'min': 0.2, 'avg': 0.2, 'max': 0.2}
thundergreen commented 5 years ago

another try.. and it worked also

2019-11-16 18:45:03.093923 INFO bedroom_heating: <-- [R:bedroom] [A:climate.air_conditioner_bedroom] Setting temperature = 21.0��, HVAC mode = 'heat'.
2019-11-16 18:45:03.166345 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Re-sending in 30 seconds.
2019-11-16 18:45:03.170661 INFO bedroom_heating: <-- [R:bedroom] Value set to 21.0��.  [manual]
2019-11-16 18:45:03.172701 INFO bedroom_heating: --- [R:bedroom] Re-applying the schedule not before 18:59:20 (in 0:14:17).
2019-11-16 18:45:03.174994 INFO bedroom_heating: <-- [R:bedroom] Sending state to HA: state='21.0', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': '21.0'}, 'scheduled_value': 'OFF', 'rescheduling_time': 1573927160.0, 'overlay_active': False}
2019-11-16 18:45:03.653017 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'state' is 'heat'.
2019-11-16 18:45:03.655120 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'temperature' is 21.0.
2019-11-16 18:45:03.660059 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'current_temperature' is 20.8.
2019-11-16 18:45:03.667843 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Cancelled re-sending timer.
2019-11-16 18:45:03.673936 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Received value of 21.0��.
2019-11-16 18:45:03.675835 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Going to update statistics in 3 seconds.
2019-11-16 18:45:03.677729 INFO bedroom_heating: --- [R:bedroom] Unchanged HA state: state='21.0', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': '21.0'}, 'scheduled_value': 'OFF', 'rescheduling_time': 1573927160.0, 'overlay_active': False}
2019-11-16 18:45:06.005850 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Value for A:climate.air_conditioner_bedroom in R:bedroom is 0.1999999999999993.
2019-11-16 18:45:06.008189 INFO bedroom_heating: <-- [SP:bedroom_temp_delta] Sending state to HA: attributes={'min': 0.2, 'avg': 0.2, 'max': 0.2}
2019-11-16 18:46:11.558577 INFO bedroom_heating: --> Attribute 'state' of 'binary_sensor.window_bedroom' changed from 'off' to 'on', reevaluating <Room R:bedroom>.
2019-11-16 18:46:11.641547 INFO bedroom_heating: --- [R:bedroom] Doing schedule re-evaluation in 1 second [reset=False]
2019-11-16 18:46:12.092025 INFO bedroom_heating: --- [R:bedroom] Evaluating room's schedule (reset=False, force_resend=False).
2019-11-16 18:46:12.094197 INFO bedroom_heating: --- [R:bedroom] Assuming it to be 2019-11-16 18:46:12.
2019-11-16 18:46:12.096721 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/1:<Rule with sub <Schedule 'prepend'>>>
2019-11-16 18:46:12.099142 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/1:<Rule x='Mark(OFF, Mark.OVERLAY) if not is_empty('...>>
2019-11-16 18:46:12.101261 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: BasicHelper, order = 0
2019-11-16 18:46:12.107358 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: PatternHelper, order = 0
2019-11-16 18:46:12.108693 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ScheduleHelper, order = 0
2019-11-16 18:46:12.110299 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: StateHelper, order = 0
2019-11-16 18:46:12.112270 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ThermostatExpressionHelper, order = 0
2019-11-16 18:46:12.113717 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: CustomEnvironmentHelper, order = 1000
2019-11-16 18:46:12.115143 INFO bedroom_heating: --- [R:bedroom] Executing the expression_environment script.
2019-11-16 18:46:12.120506 INFO bedroom_heating: --- [R:bedroom]     ������ => Mark(OFF, {'OVERLAY'})
2019-11-16 18:46:12.121747 INFO bedroom_heating: --- [R:bedroom] Final result: OFF
2019-11-16 18:46:12.123439 INFO bedroom_heating: --- [R:bedroom] Result markers: {'OVERLAY'}
2019-11-16 18:46:12.124844 INFO bedroom_heating: --- [R:bedroom] Storing value 21.0�� before overlaying.
2019-11-16 18:46:12.126120 INFO bedroom_heating: --- [R:bedroom] Cancelled re-scheduling timer.
2019-11-16 18:46:12.127664 INFO bedroom_heating: --- [R:bedroom] Setting value to OFF.  [scheduled]
2019-11-16 18:46:12.129400 INFO bedroom_heating: <-- [R:bedroom] [A:climate.air_conditioner_bedroom] Setting value OFF (left tries = 11).
2019-11-16 18:46:12.131932 INFO bedroom_heating: <-- [R:bedroom] [A:climate.air_conditioner_bedroom] Setting temperature = '<unset>', HVAC mode = 'off'.
2019-11-16 18:46:12.454484 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Re-sending in 30 seconds.
2019-11-16 18:46:12.525882 INFO bedroom_heating: <-- [R:bedroom] Value set to OFF.  [scheduled]
2019-11-16 18:46:12.528260 INFO bedroom_heating: <-- [R:bedroom] Sending state to HA: state='OFF', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': 'OFF'}, 'scheduled_value': 'OFF', 'rescheduling_time': None, 'overlay_active': True, 'overlaid_wanted_value': '21.0', 'overlaid_scheduled_value': 'OFF', 'overlaid_rescheduling_time': 1573927160.0}
2019-11-16 18:46:13.289144 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'state' is 'off'.
2019-11-16 18:46:13.291958 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'current_temperature' is 20.8.
2019-11-16 18:46:13.313676 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Cancelled re-sending timer.
2019-11-16 18:46:13.315196 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Received value of OFF.
2019-11-16 18:46:13.316498 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Going to update statistics in 3 seconds.
2019-11-16 18:46:13.317710 INFO bedroom_heating: --- [R:bedroom] Unchanged HA state: state='OFF', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': 'OFF'}, 'scheduled_value': 'OFF', 'rescheduling_time': None, 'overlay_active': True, 'overlaid_wanted_value': '21.0', 'overlaid_scheduled_value': 'OFF', 'overlaid_rescheduling_time': 1573927160.0}
2019-11-16 18:46:16.003903 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Value for A:climate.air_conditioner_bedroom in R:bedroom is 0.0.
2019-11-16 18:46:16.005989 INFO bedroom_heating: <-- [SP:bedroom_temp_delta] Sending state to HA: attributes={'min': 0.0, 'avg': 0.0, 'max': 0.0}
2019-11-16 18:46:19.310917 INFO bedroom_heating: --> Attribute 'state' of 'binary_sensor.window_bedroom' changed from 'on' to 'off', reevaluating <Room R:bedroom>.
2019-11-16 18:46:19.312434 INFO bedroom_heating: --- [R:bedroom] Doing schedule re-evaluation in 1 second [reset=False]
2019-11-16 18:46:20.003641 INFO bedroom_heating: --- [R:bedroom] Evaluating room's schedule (reset=False, force_resend=False).
2019-11-16 18:46:20.006736 INFO bedroom_heating: --- [R:bedroom] Assuming it to be 2019-11-16 18:46:20.
2019-11-16 18:46:20.009581 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/1:<Rule with sub <Schedule 'prepend'>>>
2019-11-16 18:46:20.011308 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/1:<Rule x='Mark(OFF, Mark.OVERLAY) if not is_empty('...>>
2019-11-16 18:46:20.012620 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: BasicHelper, order = 0
2019-11-16 18:46:20.014082 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: PatternHelper, order = 0
2019-11-16 18:46:20.016031 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ScheduleHelper, order = 0
2019-11-16 18:46:20.017992 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: StateHelper, order = 0
2019-11-16 18:46:20.020219 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: ThermostatExpressionHelper, order = 0
2019-11-16 18:46:20.022723 INFO bedroom_heating: --- [R:bedroom] Initializing expression helper: CustomEnvironmentHelper, order = 1000
2019-11-16 18:46:20.024734 INFO bedroom_heating: --- [R:bedroom] Executing the expression_environment script.
2019-11-16 18:46:20.030993 INFO bedroom_heating: --- [R:bedroom]     ������ => Next()
2019-11-16 18:46:20.032237 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/2:<Rule x="Abort() if is_off('input_boolean.automat"...>>
2019-11-16 18:46:20.033523 INFO bedroom_heating: --- [R:bedroom]     ������ => Next()
2019-11-16 18:46:20.034724 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/3:<Rule x="Abort() if is_off('input_boolean.automat"...>>
2019-11-16 18:46:20.035993 INFO bedroom_heating: --- [R:bedroom]     ������ => Next()
2019-11-16 18:46:20.037140 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/2:<Rule with sub <Schedule 'room-individual'>>>
2019-11-16 18:46:20.038254 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/2/1:<Rule x="IncludeSchedule(schedule_snippets['bedro"...>>
2019-11-16 18:46:20.039435 INFO bedroom_heating: --- [R:bedroom]     ������ => IncludeSchedule(<Schedule 'bedroom'>)
2019-11-16 18:46:20.040804 INFO bedroom_heating: --- [R:bedroom]     ������ [SUB]  <<Schedule 'bedroom'>/2/?:<Rule with sub <Schedule 'bedroom'>>>
2019-11-16 18:46:20.041987 INFO bedroom_heating: --- [R:bedroom]         ������ [SUB]  <<Schedule 'bedroom'>/2/?/1:<Rule with sub <Schedule of 3 rules>, v=21>>
2019-11-16 18:46:20.043593 INFO bedroom_heating: --- [R:bedroom]             ������ [ACT]  <<Schedule 'bedroom'>/2/?/1/1:<Rule x="Break() if float(state('sensor.temperatu"...>>
2019-11-16 18:46:20.044863 INFO bedroom_heating: --- [R:bedroom]             ������ => Next()
2019-11-16 18:46:20.046028 INFO bedroom_heating: --- [R:bedroom]             ������ [SUB]  <<Schedule 'bedroom'>/2/?/1/2:<Rule with sub <Schedule of 1 rules>, weekdays={1-5}>>
2019-11-16 18:46:20.047179 INFO bedroom_heating: --- [R:bedroom]                 ������ [SUB]  <<Schedule 'bedroom'>/2/?/1/2/1:<Rule with sub <Schedule of 3 rules>>>
2019-11-16 18:46:20.048378 INFO bedroom_heating: --- [R:bedroom]                     ������ [INA]  <<Schedule 'bedroom'>/2/?/1/2/1/1:<Rule x="Next() if heating_mode() != 'All Home' e"...>>
2019-11-16 18:46:20.049573 INFO bedroom_heating: --- [R:bedroom]                     ������ [INA]  <<Schedule 'bedroom'>/2/?/1/2/1/2:<Rule from 06:00 to 07:00>>
2019-11-16 18:46:20.050789 INFO bedroom_heating: --- [R:bedroom]                     ������ [INA]  <<Schedule 'bedroom'>/2/?/1/2/1/3:<Rule from 22:00 to 23:59>>
2019-11-16 18:46:20.051969 INFO bedroom_heating: --- [R:bedroom]             ������ [SUB]  <<Schedule 'bedroom'>/2/?/1/3:<Rule with sub <Schedule of 2 rules>, weekdays={6-7}>>
2019-11-16 18:46:20.053159 INFO bedroom_heating: --- [R:bedroom]                 ������ [INA]  <<Schedule 'bedroom'>/2/?/1/3/1:<Rule from 06:00 to 07:00>>
2019-11-16 18:46:20.054350 INFO bedroom_heating: --- [R:bedroom]                 ������ [INA]  <<Schedule 'bedroom'>/2/?/1/3/2:<Rule from 22:30 to 23:59>>
2019-11-16 18:46:20.055481 INFO bedroom_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/3:<Rule with sub <Schedule 'append'>>>
2019-11-16 18:46:20.056594 INFO bedroom_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/3/1:<Rule v='OFF'>>
2019-11-16 18:46:20.057723 INFO bedroom_heating: --- [R:bedroom]     ������ => 'OFF'
2019-11-16 18:46:20.058780 INFO bedroom_heating: --- [R:bedroom] Final result: OFF
2019-11-16 18:46:20.059838 INFO bedroom_heating: --- [R:bedroom] Restoring overlaid value 21.0��.
2019-11-16 18:46:20.061008 INFO bedroom_heating: --- [R:bedroom] Setting value to 21.0��.  [manual]
2019-11-16 18:46:20.062508 INFO bedroom_heating: <-- [R:bedroom] [A:climate.air_conditioner_bedroom] Setting value 21.0�� (left tries = 11).
2019-11-16 18:46:20.064030 INFO bedroom_heating: <-- [R:bedroom] [A:climate.air_conditioner_bedroom] Setting temperature = 21.0��, HVAC mode = 'heat'.
2019-11-16 18:46:20.117007 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Re-sending in 30 seconds.
2019-11-16 18:46:20.118499 INFO bedroom_heating: <-- [R:bedroom] Value set to 21.0��.  [manual]
2019-11-16 18:46:20.120020 INFO bedroom_heating: --- [R:bedroom] Re-applying the schedule not before 18:59:20 (in 0:13:00).
2019-11-16 18:46:20.121705 INFO bedroom_heating: <-- [R:bedroom] Sending state to HA: state='21.0', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': '21.0'}, 'scheduled_value': 'OFF', 'rescheduling_time': 1573927160.0, 'overlay_active': False}
2019-11-16 18:46:20.805920 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'state' is 'heat'.
2019-11-16 18:46:20.823989 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'temperature' is 21.0.
2019-11-16 18:46:20.825977 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Attribute 'current_temperature' is 20.8.
2019-11-16 18:46:20.841787 INFO bedroom_heating: --- [R:bedroom] [A:climate.air_conditioner_bedroom] Cancelled re-sending timer.
2019-11-16 18:46:20.891142 INFO bedroom_heating: --> [R:bedroom] [A:climate.air_conditioner_bedroom] Received value of 21.0��.
2019-11-16 18:46:20.897080 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Going to update statistics in 3 seconds.
2019-11-16 18:46:20.914261 INFO bedroom_heating: --- [R:bedroom] Unchanged HA state: state='21.0', attributes={'actor_wanted_values': {'climate.air_conditioner_bedroom': '21.0'}, 'scheduled_value': 'OFF', 'rescheduling_time': 1573927160.0, 'overlay_active': False}
2019-11-16 18:46:23.009401 INFO bedroom_heating: --- [SP:bedroom_temp_delta] Value for A:climate.air_conditioner_bedroom in R:bedroom is 0.1999999999999993.
2019-11-16 18:46:23.024678 INFO bedroom_heating: <-- [SP:bedroom_temp_delta] Sending state to HA: attributes={'min': 0.2, 'avg': 0.2, 'max': 0.2}
bob1de commented 5 years ago

Great, then I'll merge the fix into master now and it'll be included in next release. If you want to use it beforehand, simply change the URL from overlay-fix.zip to master.zip.