irrigation_unlimited icon indicating copy to clipboard operation
irrigation_unlimited copied to clipboard

zones with adjusted time doesn't work in a sequence

Open bulburDE opened this issue 1 year ago • 3 comments

I have a sequence with multiple zones. If I adjust the time of the a zone, that zone is ignored. The other zone is executed as planned.

configuration:

irrigation_unlimited:
  granularity: 1
  history_span: 30
  controllers:
    all_zones_config:
      show:
        timeline: true   
    zones:
      # I did leave out some irrelevant zones.
      # This is binary_sensor.irrigation_unlimited_c1_z7
      - entity_id: input_boolean.irrigation_test_entity
        zone_id: test
        name: test zone
        maximum: "01:30"     
      # This is binary_sensor.irrigation_unlimited_c1_z8
      - entity_id: input_boolean.irrigation_test_entity_2
        zone_id: test2
        name: test zone2
        maximum: "01:30"         
    sequences:
      - name: Test2
        schedules:
          - time: "01:17"
            weekday: ["mon", "tue", "wed", "thu", "fri", "sat", "sun"]
            month: ["may", "jun", "jul", "aug"]          
        zones:
          - zone_id: [test]
            duration: "00:00:30"
          - zone_id: [test2]
            duration: "00:00:30"

Service call to adjust time

service: irrigation_unlimited.adjust_time
data:
  entity_id: binary_sensor.irrigation_unlimited_c1_z7
  actual: "00:01:00"

debug log:

2023-06-02 01:15:28.358 DEBUG (MainThread) [custom_components.irrigation_unlimited] LOAD
2023-06-02 01:15:28.358 DEBUG (MainThread) [custom_components.irrigation_unlimited] STOP
2023-06-02 01:15:28.359 DEBUG (MainThread) [custom_components.irrigation_unlimited] START
2023-06-02 01:17:30.003 INFO (MainThread) [custom_components.irrigation_unlimited] EVENT [2023-06-02 01:17:30] controller: 1, zone: 0, state: 1
2023-06-02 01:17:30.004 INFO (MainThread) [custom_components.irrigation_unlimited] EVENT [2023-06-02 01:17:30] controller: 1, zone: 8, state: 1, data: 8.1.1.2.1
2023-06-02 01:18:00.008 INFO (MainThread) [custom_components.irrigation_unlimited] EVENT [2023-06-02 01:18:00] controller: 1, zone: 8, state: 0
2023-06-02 01:18:00.009 INFO (MainThread) [custom_components.irrigation_unlimited] EVENT [2023-06-02 01:18:00] controller: 1, zone: 0, state: 0

I observed that the start and end times in the schedules in the timeline are also not adjusted. Here the start time for the sequence was 01:37. I don't know why the zone test2 has so many schedules with status scheduled in the timeline.

zone_id: test
index: 6
enabled: true
status: off
schedule_count: 0
schedules: 
adjustment: =0:01:00
current_schedule: null
percent_complete: 0
next_schedule: 1
today_total: 8.7
timeline: 
- start: '2023-06-03T23:37:00+00:00'
  end: '2023-06-03T23:38:00+00:00'
  schedule_name: Schedule 1
  adjustment: '=0:01:00'
  status: next
- start: '2023-06-01T23:13:30+00:00'
  end: '2023-06-01T23:14:00+00:00'
  schedule_name: Schedule 1
  adjustment: ''
  status: history
... [redacted]
zone_id: test2
index: 7
enabled: true
status: off
schedule_count: 0
schedules: 
adjustment: 
current_schedule: null
percent_complete: 0
next_adjustment: 
next_schedule: 1
next_name: Schedule 1
next_start: 2023-06-02T01:37:30+02:00
next_duration: 0:00:30
today_total: 11.5
timeline: 
- start: '2023-06-03T23:38:00+00:00'
  end: '2023-06-03T23:38:30+00:00'
  schedule_name: Schedule 1
  adjustment: ''
  status: scheduled
- start: '2023-06-03T23:37:30+00:00'
  end: '2023-06-03T23:38:00+00:00'
  schedule_name: Schedule 1
  adjustment: ''
  status: scheduled
- start: '2023-06-02T23:37:30+00:00'
  end: '2023-06-02T23:38:00+00:00'
  schedule_name: Schedule 1
  adjustment: ''
  status: scheduled
- start: '2023-06-01T23:37:30+00:00'
  end: '2023-06-01T23:38:00+00:00'
  schedule_name: Schedule 1
  adjustment: ''
  status: next
- start: '2023-06-01T23:33:30+00:00'
  end: '2023-06-01T23:34:00+00:00'
  schedule_name: Schedule 1
  adjustment: ''
  status: history
... [redacted]

I have also tested to adjust the time by a lower value than the scheduled, e.g. "00:00:25", but it had the same result.

bulburDE avatar Jun 02 '23 00:06 bulburDE

Please post the service call logs. These are important to fully understand the current state. They look like the following example:

2023-05-31 23:47:55.569 INFO (MainThread) [custom_components.irrigation_unlimited] CALL [2023-06-01 09:47:55] service: adjust_time, controller: 1, zone: 7, data: {"actual": "00:01:00", "entity_id": ["binary_sensor.irrigation_unlimited_c1_z7"]}

Adjustments are persistent so they will survive HA restarts. This means you must clear an adjustment as a restart won't do it - this is by design.

With the above in mind I see a number of inconsistencies. It is zone 6 not 7 that has the adjustment yet the service call shows z7. From the log only zone 8 ran.

The history_span (deprecated but still ok) is set to 30. Please note this the number of days. There is also a corresponding future_span which defaults to 3 (days). This shows the scheduled runs into the future which is why you see three status: scheduled in the timeline.

Looking at the time line it appears correct. Zone 6 comes on at 1:37 for 1 minute. It was scheduled for 30 seconds but there was an adjustment for 1 minute. Zone 7 comes on immediately after at 1:38 for the scheduled 30 seconds. Interleaving the next schedules from the timeline it looks like the following.

zone_id: test (index: 6)
- start: '2023-06-03T23:37:00+00:00'
  end: '2023-06-03T23:38:00+00:00'
  schedule_name: Schedule 1
  adjustment: '=0:01:00'
  status: next
zone_id: test2 (index: 7)
- start: '2023-06-01T23:37:30+00:00'
  end: '2023-06-01T23:38:00+00:00'
  schedule_name: Schedule 1
  adjustment: ''
  status: next

rgc99 avatar Jun 02 '23 03:06 rgc99

Sorry, I forgot the log to the adjust call. My log is just too messed up so I didn't want to paste everything :D Now all relevant entries should be in there. The disable and enable calls are to get the reload working. I had seen this in the community thread and can confirm that the schedules aren't updating when just calling reload.

2023-06-02 01:15:28.358 DEBUG (MainThread) [custom_components.irrigation_unlimited] LOAD
2023-06-02 01:15:28.358 DEBUG (MainThread) [custom_components.irrigation_unlimited] STOP
2023-06-02 01:15:28.359 DEBUG (MainThread) [custom_components.irrigation_unlimited] START
2023-06-02 01:15:28.947 INFO (MainThread) [custom_components.irrigation_unlimited] CALL [2023-06-02 01:15:28] service: disable, controller: 1, zone: 0, data: {"entity_id": ["binary_sensor.irrigation_unlimited_c1_m"]}
2023-06-02 01:15:33.962 INFO (MainThread) [custom_components.irrigation_unlimited] CALL [2023-06-02 01:15:33] service: enable, controller: 1, zone: 0, data: {"entity_id": ["binary_sensor.irrigation_unlimited_c1_m"]}
2023-06-02 01:15:41.052 INFO (MainThread) [custom_components.irrigation_unlimited] CALL [2023-06-02 01:15:41] service: adjust_time, controller: 1, zone: 7, data: {"entity_id": "binary_sensor.irrigation_unlimited_c1_z7", "actual": "0:01:00"}
2023-06-02 01:17:30.003 INFO (MainThread) [custom_components.irrigation_unlimited] EVENT [2023-06-02 01:17:30] controller: 1, zone: 0, state: 1
2023-06-02 01:17:30.004 INFO (MainThread) [custom_components.irrigation_unlimited] EVENT [2023-06-02 01:17:30] controller: 1, zone: 8, state: 1, data: 8.1.1.2.1
2023-06-02 01:18:00.008 INFO (MainThread) [custom_components.irrigation_unlimited] EVENT [2023-06-02 01:18:00] controller: 1, zone: 8, state: 0
2023-06-02 01:18:00.009 INFO (MainThread) [custom_components.irrigation_unlimited] EVENT [2023-06-02 01:18:00] controller: 1, zone: 0, state: 0

zone test has the entity_id binary_sensor.irrigation_unlimited_c1_z7 but the index 6 in the attributes. zone test2 has the entity_id binary_sensor.irrigation_unlimited_c1_z7 but the index 6 in the attributes. I was a bit confused by that, but thought that one started at 0 and the other at 1. Should the numbers match? image

I installed the integration a long time (and versions) ago. Maybe I should reinstall and clean everything.

Regarding the timeline: For test it looks like I expected it. The end time has changed due to the adjustment. But test2 should now start directly after at 23:38:00, but the start and end times haven´t changed. Even though it did correctly start at 23:38:00. I had expected this:

zone_id: test (index: 6)
- start: '2023-06-03T23:37:00+00:00'
  end: '2023-06-03T23:38:00+00:00'
  schedule_name: Schedule 1
  adjustment: '=0:01:00'
  status: next
zone_id: test2 (index: 7)
- start: '2023-06-01T23:38:00+00:00'
  end: '2023-06-01T23:38:30+00:00'
  schedule_name: Schedule 1
  adjustment: ''
  status: next

Regarding time_span: I just don't get why there is a difference between the two zones. test2 shows the schedules for 3 days in the future, but test only has the next even though they have the same schedule.

bulburDE avatar Jun 02 '23 06:06 bulburDE

I see you are using the reload service. There are currently some known issues with reload service. Could you retest without using reload. Better yet if you would like to get the latest updates from the repository and test them out it would be helpful. That is assuming you are ok with a manual install.

rgc99 avatar Jun 19 '23 08:06 rgc99