Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

HA unresponsive after irrigation_unlimited is loaded #58

Closed
rmeekers opened this issue Apr 19, 2022 · 10 comments
Closed

HA unresponsive after irrigation_unlimited is loaded #58

rmeekers opened this issue Apr 19, 2022 · 10 comments

Comments

@rmeekers
Copy link
Contributor

Describe the bug
Since I've upgraded to 2022.3.0, I started to have issues with HA. It started three weeks ago on Sunday. HA was not accessible anymore via the web interface. I tried a lot, but couldn't pinpoint the problem. So I reinstalled HA and restored a backup. Everything went well that week... until it was Sunday again. Same as the week before. HA was unreachable via the web interface.

Long story short: when I disable irrigation_unlimited in configuration.yaml, HA works fine. If I enable it, it's unresponsive.

To Reproduce
For me it's reproducible by enabling irrigation_unlimited.

Additional context

Logs:

2022-04-19 08:45:25 INFO (MainThread) [custom_components.irrigation_unlimited] 
-------------------------------------------------------------------
Irrigation Unlimited
Version: 2022.3.0
If you have any issues with this you need to open an issue here:
https://github.com/rgc99/irrigation_unlimited/issues
-------------------------------------------------------------------

2022-04-19 08:45:25 DEBUG (MainThread) [custom_components.irrigation_unlimited] LOAD
2022-04-19 08:45:27 DEBUG (MainThread) [custom_components.irrigation_unlimited] REGISTER [2022-04-19 08:45:20] controller: 0, zone: 0, entity: irrigation_unlimited.coordinator
2022-04-19 08:45:27 DEBUG (MainThread) [custom_components.irrigation_unlimited] CALL [2022-04-19 08:45:20] service: adjust_time, controller: 1, zone: 0, data: {"actual": "2:54:10", "sequence_id": 1, "zones": [1]}
2022-04-19 08:45:27 DEBUG (MainThread) [custom_components.irrigation_unlimited] CALL [2022-04-19 08:45:20] service: adjust_time, controller: 1, zone: 0, data: {"actual": "1:15:20", "sequence_id": 1, "zones": [2]}
2022-04-19 08:45:27 DEBUG (MainThread) [custom_components.irrigation_unlimited] CALL [2022-04-19 08:45:20] service: adjust_time, controller: 1, zone: 0, data: {"actual": "6:04:00", "sequence_id": 2, "zones": [1]}
2022-04-19 08:45:28 DEBUG (MainThread) [custom_components.irrigation_unlimited] START
2022-04-19 08:45:28 DEBUG (MainThread) [custom_components.irrigation_unlimited] REGISTER [2022-04-19 08:45:20] controller: 1, zone: 0, entity: binary_sensor.irrigation_unlimited_c1_m
2022-04-19 08:45:28 DEBUG (MainThread) [custom_components.irrigation_unlimited] REGISTER [2022-04-19 08:45:20] controller: 1, zone: 1, entity: binary_sensor.irrigation_unlimited_c1_z1
2022-04-19 08:45:28 DEBUG (MainThread) [custom_components.irrigation_unlimited] REGISTER [2022-04-19 08:45:20] controller: 1, zone: 2, entity: binary_sensor.irrigation_unlimited_c1_z2
2022-04-19 08:45:28 DEBUG (MainThread) [custom_components.irrigation_unlimited] REGISTER [2022-04-19 08:45:20] controller: 1, zone: 3, entity: binary_sensor.irrigation_unlimited_c1_z3
2022-04-19 08:45:28 DEBUG (MainThread) [custom_components.irrigation_unlimited] REGISTER [2022-04-19 08:45:20] controller: 1, zone: 4, entity: binary_sensor.irrigation_unlimited_c1_z4
2022-04-19 08:45:28 DEBUG (MainThread) [custom_components.irrigation_unlimited] REGISTER [2022-04-19 08:45:20] controller: 1, zone: 5, entity: binary_sensor.irrigation_unlimited_c1_z5
2022-04-19 08:45:28 DEBUG (MainThread) [custom_components.irrigation_unlimited] REGISTER [2022-04-19 08:45:20] controller: 1, zone: 6, entity: binary_sensor.irrigation_unlimited_c1_z6
2022-04-19 08:45:37 DEBUG (MainThread) [custom_components.irrigation_unlimited] INITIALISED
2022-04-19 08:45:38 WARNING (MainThread) [homeassistant.helpers.frame] Detected integration that accesses the database without the database executor; Use homeassistant.components.recorder.get_instance(hass).async_add_executor_job() for faster database operations. Please report issue to the custom component author for irrigation_unlimited using this method at custom_components/irrigation_unlimited/history.py, line 142: data = history.get_significant_states(

My config:

granularity: 10
refresh_interval: 20
controllers:
  - name: 'Rain Bird'
    zones:
      # zone_id: 1
      - name: 'Lawn Front (zone 1)'
        entity_id: 'switch.rain_valve_1'
        maximum: '01:30'
      # zone_id: 2
      - name: 'Lawn Back (zone 2)'
        entity_id: 'switch.rain_valve_2'
        maximum: '06:00'
      # zone_id: 3
      - name: 'Lawn Side (zone 3)'
        entity_id: 'switch.rain_valve_3'
        maximum: '01:30'
      # zone_id: 4
      - name: 'Irrigation around house (zone 1)'
        entity_id: 'switch.irrigation_valve_1'
        maximum: '04:00'
      # zone_id: 5
      - name: 'Irrigation vegetable garden (zone 2)'
        entity_id: 'switch.irrigation_valve_2'
        maximum: '04:00'
      # zone_id: 6
      - name: 'Irrigation rhododendron (zone 3)'
        entity_id: 'switch.irrigation_valve_3'
        maximum: '04:00'
    sequences:
      - name: 'Lawn - Summer mornings zone 1 & 3'
        delay: '00:00:30'
        schedules:
          - time:
              sun: 'sunrise'
              before: '00:10'
            anchor: finish
            weekday: [mon]
            month: [mar, apr, may, jun, jul, aug, sep]
        zones:
          - zone_id: 1
            duration: '00:00'
          - zone_id: 3
            duration: '00:00'
      - name: 'Lawn - Summer mornings zone 2'
        delay: '00:00:30'
        schedules:
          - time:
              sun: 'sunrise'
              before: '01:10'
            anchor: finish
            weekday: [tue]
            month: [mar, apr, may, jun, jul, aug, sep]
        zones:
          - zone_id: 2
            duration: '00:00'
      - name: 'Borders - Summer mornings around house'
        delay: '00:00:20'
        schedules:
          - time:
              sun: 'sunrise'
              before: '00:10'
            anchor: finish
            weekday: [fri]
            month: [mar, apr, may, jun, jul, aug, sep]
        zones:
          - zone_id: 4
            duration: '04:00'
      - name: 'Vegetable garden - Summer mornings'
        delay: '00:00:20'
        schedules:
          - time:
              sun: 'sunrise'
              before: '00:10'
            anchor: finish
            weekday: [wed,sun]
            month: [may, jun, jul, aug, sep]
        zones:
          - zone_id: 5
            duration: '01:00'
      - name: 'Borders - Summer mornings rhododendron'
        delay: '00:00:20'
        schedules:
          - time:
              sun: 'sunrise'
              before: '00:10'
            anchor: finish
            weekday: [thu]
            month: [mar, apr, may, jun, jul, aug, sep]
        zones:
          - zone_id: 6
            duration: '04:00'
@rmeekers
Copy link
Contributor Author

PS: downgrading to 2022.2.0 doesn't solve the issue.

@rgc99
Copy link
Owner

rgc99 commented Apr 20, 2022

It's a bug. When using the finish anchor it happens if the start time is in the previous day (before midnight). Probably started a few weeks ago because in your neck of the woods the sun is rising earlier or the run time is longer due to it getting warmer or probably both. Sequence 2, zone 1 is the killer here, over 6 hour run time and the sun is probably rising before 6 am.

I will have it sorted shortly but need to test etc. In the mean time just make sure the run starts after midnight.
Back to you soon.

@rgc99
Copy link
Owner

rgc99 commented Apr 20, 2022

The update is now in the repository. Are you ok to do a manual install until I get the release organised?

@rmeekers
Copy link
Contributor Author

rmeekers commented Apr 20, 2022 •
edited

@rgc99 thanks. A manual install would be ok, do I need to uninstall it via HACS? Or can I just overwrite the files manually?
EDIT: I've copied over the changes from your commit and now it seems to be working 😅

And did you see from my logs where the issue was located? (I've lost quite some hours finding out which integration was causing this and I like to learn for the future ;-) )

@rgc99
Copy link
Owner

rgc99 commented Apr 20, 2022

Just overwrite the files manually. When it's officially released HACS will let you know.

I have a kind of test jig where I can setup a config and simulate running it for a period. All went well until I made the adjustment service calls and then it sat there spinning its wheels. From there it was a process of zeroing in on the problem. The information you supplied was perfect to get to the bottom of it quickly.

Thanks for your understanding.

@rmeekers
Copy link
Contributor Author

Glad you could fix it so quickly. Thanks for that.
What about this warning? Is it related?

2022-04-19 08:45:38 WARNING (MainThread) [homeassistant.helpers.frame] Detected integration that accesses the database without the database executor; Use homeassistant.components.recorder.get_instance(hass).async_add_executor_job() for faster database operations. Please report issue to the custom component author for irrigation_unlimited using this method at custom_components/irrigation_unlimited/history.py, line 142: data = history.get_significant_states(

@rgc99
Copy link
Owner

rgc99 commented Apr 20, 2022

No but it is something I need to look at. I think the HA developers have made some optimisations and they want us to use it. The shifting sands of development.

@rmeekers
Copy link
Contributor Author

I get another error in the logs now:

Logger: homeassistant
Source: custom_components/irrigation_unlimited/irrigation_unlimited.py:538
Integration: Irrigation Unlimited ([documentation](https://github.com/rgc99/irrigation_unlimited), [issues](https://github.com/rgc99/irrigation_unlimited/issues))
First occurred: 09:16:06 (140 occurrences)
Last logged: 09:38:03

Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/config/custom_components/irrigation_unlimited/irrigation_unlimited.py", line 3846, in _async_timer
    self.timer(atime)
  File "/config/custom_components/irrigation_unlimited/irrigation_unlimited.py", line 3842, in timer
    self.poll_main(atime)
  File "/config/custom_components/irrigation_unlimited/irrigation_unlimited.py", line 3830, in poll_main
    self.poll(atime, force)
  File "/config/custom_components/irrigation_unlimited/irrigation_unlimited.py", line 3818, in poll
    if self.muster(wtime, force) != 0:
  File "/config/custom_components/irrigation_unlimited/irrigation_unlimited.py", line 3779, in muster
    status |= controller.muster(stime, force)
  File "/config/custom_components/irrigation_unlimited/irrigation_unlimited.py", line 2736, in muster
    sequence_status = self.muster_sequence(
  File "/config/custom_components/irrigation_unlimited/irrigation_unlimited.py", line 2677, in muster_sequence
    next_run = init_run_time(stime, schedule, zone, total_time)
  File "/config/custom_components/irrigation_unlimited/irrigation_unlimited.py", line 2636, in init_run_time
    next_run = schedule.get_next_run(
  File "/config/custom_components/irrigation_unlimited/irrigation_unlimited.py", line 538, in get_next_run
    if next_run > final_time:
UnboundLocalError: local variable 'next_run' referenced before assignment

@rgc99
Copy link
Owner

rgc99 commented Apr 20, 2022

Doesn't add up. That statement is on line 540 not 538. Please make sure you copied all the files correctly. If you are copying the contents make sure it is raw.

@rmeekers
Copy link
Contributor Author

Hmm my bad. I had only copied the 3 changes from today, now I've copied everything and its fine. thanks again

@rgc99 rgc99 closed this as completed Sep 22, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@rmeekers @rgc99