search

bob1de / hass-apps

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

[schedy] Race condition with OVERLAY and rescheduling_delay #35

Closed tristone-cz closed 4 years ago

tristone-cz commented 4 years ago

If temperature is set manually at thermostat (OVERLAY applies) and then window is opened behavior is correct, valve goes OFF.

Then two cases: a) If window is closed inside the resheduling interval thermostat returns fine to the manual value and once rescheduling expires it continues according to schedule. This is correct behavior. b) Problem occurs once the window is opened for longer time and the rescheduling expiration is missed. Then after window closure the value is returned to the manual one instead of scheduled one. And during each evaluation of the schedule later on it is left untouched.

I attached logs. They are filter just for one room, others were removed for easier reading. schedy.log

Following times are interesting: 15:40:43 - manual change on thermostat from 16 to 17 °C 15:42:25 - window opened 15:44:11 - first re-evalution after rescheduling delay expired (happening every minute) 15:44:45 - window closed, thermostat returned to 17 °C 15:45:11 - re-evaluation of the schedule, not returned to 16 °C even here

Relevant parts of the config during the tess:

  schedule_prepend:
  # Master switch
  - x: "OFF if is_off('input_boolean.heating_enabled') else Skip()"
  # Open windows / doors
  - x: "Mark(OFF, Mark.OVERLAY) if not is_empty(filter_entities('binary_sensor', state='on', window_room=room_name)) else Skip()"

  rooms:
    bedroom:
      rescheduling_delay: 3
      actors:
        climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat:

      schedule:
      <SKIPPED RULES>
      # At all other times, set temperature to low value
      - x: state("input_number.bedroom_low_temperature")

Regards, Jaroslav

bob1de commented 4 years ago

Hi Jaroslav,

Thanks for the great problem description and your donation.

I'll look into it and get back to you though it may take some time.

Best regards Robert

tristone-cz commented 4 years ago

Hi Robert,

You're welcome.

I finished big upgrade of HA in last weeks (move to RPI 4, Schedy, Lovelace interface ...) so now sending few bugs here and there to people who deserve that ;)

For the description I am trained from work. For our RND I have to also create perfect ticket otherwise it becomes neverending story. Simply kill them for the first shot :)

Regards, Jaroslav

------ Původní zpráva ------ Od: "Robert Schindler" notifications@github.com Komu: "efficiosoft/hass-apps" hass-apps@noreply.github.com Kopie: "tristone-cz" tristone@centrum.cz; "Author" author@noreply.github.com Odesláno: 07.08.2019 10:17:04 Předmět: Re: [efficiosoft/hass-apps] [schedy] Race condition with OVERLAY and rescheduling_delay (#35)

Hi Jaroslav,

Thanks for the great problem description and your donation.

I'll look into it and get back to you though it may take some time.

Best regards Robert

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/efficiosoft/hass-apps/issues/35?email_source=notifications&email_token=AJVKCGPFSZWMCETALNG6KM3QDKAIBA5CNFSM4IJW3UM2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD3XTIJA#issuecomment-518992932, or mute the thread https://github.com/notifications/unsubscribe-auth/AJVKCGMAHTRQEAJVTVP4N6TQDKAIBANCNFSM4IJW3UMQ.

bob1de commented 4 years ago

Hi @tristone-cz

Would you please try if it's fixed in the schedy-overlay-race branch?

Please use this URL in requirements.txt / add-on configuration / pip command:

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

Regards Robert

bob1de commented 4 years ago

Please note, I edited the URL again.

tristone-cz commented 4 years ago

Hi @efficiosoft

I made the tests again. Just with room.py changed.

Usecase a) remained OK.

Usecase b) is fixed based on the test. See the logs when window closed:

2019-09-07 22:07:27.714731 INFO schedy_heating: --> Attribute 'state' of 'binary_sensor.0x00158d0001f406fb_contact' changed from 'on' to 'off', reevaluating <Room R:bedroom>.
2019-09-07 22:07:27.716961 INFO schedy_heating: --- [R:bedroom] Doing schedule re-evaluation in 1 second [reset=False]
2019-09-07 22:07:28.003521 INFO schedy_heating: --- [R:bedroom] Evaluating room's schedule (reset=False, force_resend=False).
2019-09-07 22:07:28.005245 INFO schedy_heating: --- [R:bedroom] Assuming it to be 2019-09-07 22:07:28.
2019-09-07 22:07:28.006997 INFO schedy_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/1:<Rule with sub <Schedule 'prepend'>>>
2019-09-07 22:07:28.008779 INFO schedy_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/1:<Rule x="OFF if is_off('binary_sensor.heating_ena"...>>
2019-09-07 22:07:28.010625 INFO schedy_heating: --- [R:bedroom] Initializing expression helper: BasicHelper, order = 0
2019-09-07 22:07:28.012561 INFO schedy_heating: --- [R:bedroom] Initializing expression helper: PatternHelper, order = 0
2019-09-07 22:07:28.014302 INFO schedy_heating: --- [R:bedroom] Initializing expression helper: ScheduleHelper, order = 0
2019-09-07 22:07:28.016012 INFO schedy_heating: --- [R:bedroom] Initializing expression helper: StateHelper, order = 0
2019-09-07 22:07:28.017892 INFO schedy_heating: --- [R:bedroom] Initializing expression helper: ThermostatExpressionHelper, order = 0
2019-09-07 22:07:28.019752 INFO schedy_heating: --- [R:bedroom] Initializing expression helper: CustomEnvironmentHelper, order = 1000
2019-09-07 22:07:28.021618 INFO schedy_heating: --- [R:bedroom]     ������ => Skip()
2019-09-07 22:07:28.023397 INFO schedy_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/1/2:<Rule x='Mark(OFF, Mark.OVERLAY) if not is_empty('...>>
2019-09-07 22:07:28.027424 INFO schedy_heating: --- [R:bedroom]     ������ => Skip()
2019-09-07 22:07:28.029256 INFO schedy_heating: --- [R:bedroom] ������ [SUB]  <<Schedule 'bedroom'>/2:<Rule with sub <Schedule 'room-individual'>>>
2019-09-07 22:07:28.031029 INFO schedy_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/2/1:<Rule x='state("input_number.bedroom_high_tempera'...>>
2019-09-07 22:07:28.032971 INFO schedy_heating: --- [R:bedroom]     ������ => Skip()
2019-09-07 22:07:28.034749 INFO schedy_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/2/2:<Rule x='state("input_number.bedroom_high_tempera'...>>
2019-09-07 22:07:28.036694 INFO schedy_heating: --- [R:bedroom]     ������ => Skip()
2019-09-07 22:07:28.038442 INFO schedy_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/2/3:<Rule x='state("input_number.bedroom_high_tempera'...>>
2019-09-07 22:07:28.040506 INFO schedy_heating: --- [R:bedroom]     ������ => Skip()
2019-09-07 22:07:28.042240 INFO schedy_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/2/4:<Rule x='state("input_number.bedroom_high_tempera'...>>
2019-09-07 22:07:28.044394 INFO schedy_heating: --- [R:bedroom]     ������ => Skip()
2019-09-07 22:07:28.046178 INFO schedy_heating: --- [R:bedroom]     ������ [ACT]  <<Schedule 'bedroom'>/2/5:<Rule x='state("input_number.bedroom_low_temperat'...>>
2019-09-07 22:07:28.048034 INFO schedy_heating: --- [R:bedroom]     ������ => '16.0'
2019-09-07 22:07:28.050176 INFO schedy_heating: --- [R:bedroom] Final result: 16.0��
2019-09-07 22:07:28.051850 INFO schedy_heating: --- [R:bedroom] Setting value to 16.0��.  [scheduled]
2019-09-07 22:07:28.053937 INFO schedy_heating: <-- [R:bedroom] [A:climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat] Setting value 16.0�� (left tries = 9).
2019-09-07 22:07:28.056045 INFO schedy_heating: <-- [R:bedroom] [A:climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat] Setting temperature = 16.0��, HVAC mode = 'heat'.
2019-09-07 22:07:28.096594 INFO schedy_heating: --- [R:bedroom] [A:climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat] Re-sending in 30 seconds.
2019-09-07 22:07:28.098490 INFO schedy_heating: <-- [R:bedroom] Value set to 16.0��.  [scheduled]
2019-09-07 22:07:28.100362 INFO schedy_heating: <-- [R:bedroom] Sending state to HA: state='16.0', attributes={'actor_wanted_values': {'climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat': '16.0'}, 'scheduled_value': '16.0', 'rescheduling_time': None}
2019-09-07 22:07:29.921382 INFO schedy_heating: --> [R:bedroom] [A:climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat] Attribute 'state' is 'heat'.
2019-09-07 22:07:29.928660 INFO schedy_heating: --> [R:bedroom] [A:climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat] Attribute 'temperature' is 17.0.
2019-09-07 22:07:29.938348 INFO schedy_heating: --> [R:bedroom] [A:climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat] Attribute 'current_temperature' is 23.3.
2019-09-07 22:07:29.940134 INFO schedy_heating: --> [R:bedroom] [A:climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat] Received value of 17.0��.
2019-09-07 22:07:29.941942 INFO schedy_heating: --- [R:bedroom] Not respecting value change from a sending actor.
2019-09-07 22:07:29.943669 INFO schedy_heating: --- [R:bedroom] Unchanged HA state: state='16.0', attributes={'actor_wanted_values': {'climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat': '16.0'}, 'scheduled_value': '16.0', 'rescheduling_time': None}
2019-09-07 22:07:30.161920 INFO schedy_heating: --> [R:bedroom] [A:climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat] Attribute 'state' is 'heat'.
2019-09-07 22:07:30.163694 INFO schedy_heating: --> [R:bedroom] [A:climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat] Attribute 'temperature' is 16.0.
2019-09-07 22:07:30.165520 INFO schedy_heating: --> [R:bedroom] [A:climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat] Attribute 'current_temperature' is 23.3.
2019-09-07 22:07:30.167323 INFO schedy_heating: --- [R:bedroom] [A:climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat] Cancelled re-sending timer.
2019-09-07 22:07:30.168869 INFO schedy_heating: --> [R:bedroom] [A:climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat] Received value of 16.0��.
2019-09-07 22:07:30.170549 INFO schedy_heating: --- [R:bedroom] Unchanged HA state: state='16.0', attributes={'actor_wanted_values': {'climate.eurotronic_eur_spiritz_wall_radiator_thermostat_heat': '16.0'}, 'scheduled_value': '16.0', 'rescheduling_time': None}

Regards, Jaroslav

bob1de commented 4 years ago

Hi Jaroslav,

Great. The fix is now in the master branch. Please not just replace room.py, there were API changes involving other files that might break Schedy unexpectedly. Better use the whole thing from master.

Best regards Robert

bob1de commented 4 years ago

Hi Jaroslav,

May I kindly ask you to test the overlay-rework branch again?

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

I had to reimplement crucial parts of the overlay handling to make the code simpler. My tests revealed no issues so far, but as you're an expert on that topic, I'd feel more confident if you could have a look at it as well and maybe use it a day or two on a daily basis.

Thanks for taking the time.

Best regards Robert

tristone-cz commented 4 years ago

I upgraded it and it started fine.

Will make some tests today or tomorrow evening.

Use it on daily basis is a bit issue. It is still not cold enough so always windows are open, at least a bit.

tristone-cz commented 4 years ago

Hi.

I made the test with full package and according to my tests nothing is broken. Both usecases A and B are still fine.

Thanks for your great job 👍

Regards, Jaroslav

bob1de commented 4 years ago

Hi Jaroslav,

Thanks again for taking the time! Your tests helped me a lot.

I'm going to prepare a new release with all fixes in the next weeks.

Best regards Robert