I have an automation that is in charge of the sprinkler system and its pretty basic. It fires at a specific time, turns a valve on, waits, off, next, etc until it sends a push notification. Today I noticed that the push notification was sent tons of times to my phone so I digged into the logs and this is what I see:
2019-04-24 03:00:35 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-04-24 03:00:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Running script
2019-04-24 03:00:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:00:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:04:00
2019-04-24 02:50:00 INFO (SyncWorker_4) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-04-24 03:01:35 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-04-24 03:01:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:01:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:01:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:04:00
2019-04-24 02:51:00 INFO (SyncWorker_12) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-04-24 03:02:35 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-04-24 03:02:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:02:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:02:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:04:00
2019-04-24 02:52:00 INFO (SyncWorker_3) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-04-24 03:03:35 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-04-24 03:03:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:03:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:03:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:04:00
2019-04-24 02:53:00 INFO (SyncWorker_19) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-04-24 03:04:35 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-04-24 03:04:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:04:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 02:54:00 INFO (SyncWorker_3) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-04-24 02:54:00 INFO (SyncWorker_9) [homeassistant.components.pushbullet.notify] Sent notification to self
2019-04-24 03:05:35 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-04-24 03:05:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Running script
2019-04-24 03:05:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:05:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:04:00
2019-04-24 02:55:00 INFO (SyncWorker_7) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-04-24 03:06:35 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-04-24 03:06:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:06:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:06:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:04:00
2019-04-24 02:56:00 INFO (SyncWorker_8) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-04-24 03:07:35 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-04-24 03:07:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:07:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:07:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:04:00
2019-04-24 02:57:00 INFO (SyncWorker_19) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-04-24 03:08:35 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-04-24 03:08:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:08:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:08:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:04:00
2019-04-24 02:58:00 INFO (SyncWorker_9) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-04-24 03:09:35 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-04-24 03:09:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
It just went nuts and fired multiple times
- id: sprinkler_orchard_schedule_automation
alias: 'Orchard Schedule'
trigger:
platform: time
at: '19:00:00'
condition:
condition: and
conditions:
- condition: template
value_template: "{{ states('sensor.sprinklers_weather_should_fire') }}"
- condition: or
conditions:
- condition: template
value_template: '{{ (now().strftime("%a") == "Mon") and (states.input_boolean.sprinklers_orchard_monday.state=="on")}}'
- condition: template
value_template: '{{ (now().strftime("%a") == "Tue") and (states.input_boolean.sprinklers_orchard_tuesday.state=="on")}}'
- condition: template
value_template: '{{ (now().strftime("%a") == "Wed") and (states.input_boolean.sprinklers_orchard_wednesday.state=="on")}}'
- condition: template
value_template: '{{ (now().strftime("%a") == "Thu") and (states.input_boolean.sprinklers_orchard_thursday.state=="on")}}'
- condition: template
value_template: '{{ (now().strftime("%a") == "Fri") and (states.input_boolean.sprinklers_orchard_friday.state=="on")}}'
- condition: template
value_template: '{{ (now().strftime("%a") == "Sat") and (states.input_boolean.sprinklers_orchard_saturday.state=="on")}}'
- condition: template
value_template: '{{ (now().strftime("%a") == "Sun") and (states.input_boolean.sprinklers_orchard_sunday.state=="on")}}'
action:
#Valve5
- service: homeassistant.turn_on
data:
entity_id:
- switch.sprinkler_valve_orchard
- delay: '00:{{ states.input_number.valve5.state | int }}:00'
- service: homeassistant.turn_off
data:
entity_id:
- switch.sprinkler_valve_orchard
- service: notify.pushbullet
data:
message: Orchard done.
Any idea on why it is behaving like this?
Thanks
Your automation has the alias ‘Orchard Schedule’, but the log shows ‘Executing Sprinkler Schedule’
Are you sure there’s no other automation?
Sorry I have two and they are the same. Pasting the other automation here
- id: sprinkler_schedule_automation
alias: 'Sprinkler Schedule'
trigger:
platform: time
at: '20:00:00'
condition:
condition: and
conditions:
- condition: template
value_template: "{{ states('sensor.sprinklers_weather_should_fire') }}"
- condition: or
conditions:
- condition: template
value_template: '{{ (now().strftime("%a") == "Mon") and (states.input_boolean.sprinklers_monday.state=="on")}}'
- condition: template
value_template: '{{ (now().strftime("%a") == "Tue") and (states.input_boolean.sprinklers_tuesday.state=="on")}}'
- condition: template
value_template: '{{ (now().strftime("%a") == "Wed") and (states.input_boolean.sprinklers_wednesday.state=="on")}}'
- condition: template
value_template: '{{ (now().strftime("%a") == "Thu") and (states.input_boolean.sprinklers_thursday.state=="on")}}'
- condition: template
value_template: '{{ (now().strftime("%a") == "Fri") and (states.input_boolean.sprinklers_friday.state=="on")}}'
- condition: template
value_template: '{{ (now().strftime("%a") == "Sat") and (states.input_boolean.sprinklers_saturday.state=="on")}}'
- condition: template
value_template: '{{ (now().strftime("%a") == "Sun") and (states.input_boolean.sprinklers_sunday.state=="on")}}'
action:
#Valve1
- service: homeassistant.turn_on
data:
entity_id:
- switch.sprinkler_valve_front_1
- delay: '00:{{ states.sensor.sprinkler_calculated_duration_valve1.state | int }}:00'
- service: homeassistant.turn_off
data:
entity_id:
- switch.sprinkler_valve_front_1
#Valve2
- service: homeassistant.turn_on
data:
entity_id:
- switch.sprinkler_valve_front_2
- delay: '00:{{ states.sensor.sprinkler_calculated_duration_valve2.state | int }}:00'
- service: homeassistant.turn_off
data:
entity_id:
- switch.sprinkler_valve_front_2
#Valve3
- service: homeassistant.turn_on
data:
entity_id:
- switch.sprinkler_valve_back_hedge
- delay: '00:{{ states.sensor.sprinkler_calculated_duration_valve3.state | int }}:00'
- service: homeassistant.turn_off
data:
entity_id:
- switch.sprinkler_valve_back_hedge
#Valve4
- service: homeassistant.turn_on
data:
entity_id:
- switch.sprinkler_valve_back_grass
- delay: '00:{{ states.sensor.sprinkler_calculated_duration_valve4.state | int }}:00'
- service: homeassistant.turn_off
data:
entity_id:
- switch.sprinkler_valve_back_grass
- service: notify.pushbullet
data:
message: Sprinkler done.
Note how the history shows multiple short on / off of the valves
There is definitely strangeness in that log. First, you can see that some events are logged out of sequence. E.g.:
2019-04-24 03:00:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:04:00
2019-04-24 02:50:00 INFO (SyncWorker_4) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-04-24 03:01:35 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
That’s strangeness #1. For #2, you can see the delays are getting prematurely canceled after one minute (when they should have lasted four minutes):
2019-04-24 03:00:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-04-24 03:00:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:04:00
2019-04-24 02:50:00 INFO (SyncWorker_4) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-04-24 03:01:35 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-04-24 03:01:35 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
And oddly enough, this seems to coincide with those out of sequence Ecobee updates.
And for strangeness #3, the automation doesn’t seem to be triggering at the correct time. The second automation you posted is triggered at ‘20:00:00’, yet the log shows it triggering at ‘03:00:35’. If you have everything configured correctly (system clock and time zone settings), both of these times (i.e., the trigger and the log timestamps) should be in the local time zone.
Unless you haven’t faithfully shared what’s really in your log, or what other automations you might have that play into this, then it seems like there is something screwy with you system configuration.
Hi @pnbruckner I have shared the automations that matter on those events and I also do not have many more automations and definitely the others do not interact with this two. I had my server in UTC but I am in PST. Now I changed the server to PST and restarted home assistant. Hopefully I will be able to debug this further today. This same environment has been running for a while now without any issue.
Do you have any idea on what in the server may cause the ha clock / triggers to behave like this? Currently its running on a mac mini with ubuntu 18
Thanks
All I know is that the time zone setting in HA has to agree with the time zone setting in the environment in which HA is running (whether that’s the OS, a docker, or whatever.)
I came up with the following that can be used to check if the system clock and the time zone settings are all correct. Just paste it into the Template Editor:
{{ utcnow() }}
{{ now() }}
{{ utcnow().astimezone() }}
{{ now().astimezone() }}
{{ utcnow().tzinfo }}
{{ now().tzinfo }}
{{ now().astimezone().tzinfo }}
The first line should show the current time in UTC.
The next three lines should all show the current time in the local time zone.
The fifth line should say UTC.
And the six and seventh lines should show the local time zone, probably in different formats (but they should be equivalent.)
2 Likes
Thanks @pnbruckner I do see the output that you expect:
2019-04-25 02:16:50.530085+00:00
2019-04-24 19:16:50.530108-07:00
2019-04-24 19:16:50.530136-07:00
2019-04-24 19:16:50.530194-07:00
UTC
America/Los_Angeles
PDT
At least for now the sprinklers did fire correctly (updated my box from UTC to PST). I will write back as soon as I get more data. In the past I aways had my box in UTC without any trouble in HA. Always running the latest version using the official docker image
After a few days, the problem occurs again. The timestamps in the logs are all mangled
2019-05-02 19:48:17 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.ecobee is taking over 10 seconds
2019-05-02 20:00:56 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-05-02 20:00:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Running script
2019-05-02 20:00:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:00:56 WARNING (MainThread) [homeassistant.components.climate] Updating ecobee climate took longer than the scheduled update interval 0:01:00
2019-05-02 20:00:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:05:00
2019-05-02 19:50:18 WARNING (SyncWorker_9) [pyecobee] Error connecting to Ecobee. Possible connectivity outage.
2019-05-02 19:50:18 INFO (SyncWorker_9) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-05-02 20:01:56 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-05-02 20:01:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:01:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:01:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:05:00
2019-05-02 19:51:17 WARNING (MainThread) [homeassistant.helpers.entity] Update of weather.ecobee is taking over 10 seconds
2019-05-02 20:02:56 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-05-02 20:02:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:02:56 WARNING (MainThread) [homeassistant.components.weather] Updating ecobee weather took longer than the scheduled update interval 0:00:30
2019-05-02 20:02:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:02:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:05:00
2019-05-02 20:03:56 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-05-02 20:03:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:03:56 WARNING (MainThread) [homeassistant.components.weather] Updating ecobee weather took longer than the scheduled update interval 0:00:30
2019-05-02 20:03:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:03:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:05:00
2019-05-02 19:53:16 WARNING (SyncWorker_19) [pyecobee] Error connecting to Ecobee. Possible connectivity outage.
2019-05-02 19:53:16 INFO (SyncWorker_19) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-05-02 20:04:56 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-05-02 20:04:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:04:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 19:54:07 INFO (SyncWorker_6) [homeassistant.components.pushbullet.notify] Sent notification to self
2019-05-02 19:54:17 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.ecobee is taking over 10 seconds
2019-05-02 20:05:56 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-05-02 20:05:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Running script
2019-05-02 20:05:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:05:56 WARNING (MainThread) [homeassistant.components.climate] Updating ecobee climate took longer than the scheduled update interval 0:01:00
2019-05-02 20:05:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:05:00
2019-05-02 20:06:56 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-05-02 20:06:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:06:56 WARNING (MainThread) [homeassistant.components.climate] Updating ecobee climate took longer than the scheduled update interval 0:01:00
2019-05-02 20:06:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:06:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:05:00
2019-05-02 19:56:16 WARNING (SyncWorker_4) [pyecobee] Error connecting to Ecobee. Possible connectivity outage.
2019-05-02 19:56:16 INFO (SyncWorker_4) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-05-02 20:07:56 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-05-02 20:07:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:07:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:07:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:05:00
2019-05-02 19:57:17 WARNING (MainThread) [homeassistant.helpers.entity] Update of weather.ecobee is taking over 10 seconds
2019-05-02 20:08:56 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-05-02 20:08:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:08:56 WARNING (MainThread) [homeassistant.components.weather] Updating ecobee weather took longer than the scheduled update interval 0:00:30
2019-05-02 20:08:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:08:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:05:00
2019-05-02 20:09:56 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-05-02 20:09:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:09:56 WARNING (MainThread) [homeassistant.components.weather] Updating ecobee weather took longer than the scheduled update interval 0:00:30
2019-05-02 20:09:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 19:59:07 INFO (SyncWorker_19) [homeassistant.components.pushbullet.notify] Sent notification to self
2019-05-02 19:59:16 WARNING (SyncWorker_8) [pyecobee] Error connecting to Ecobee. Possible connectivity outage.
2019-05-02 19:59:16 INFO (SyncWorker_8) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-05-02 20:00:00 INFO (MainThread) [homeassistant.components.automation] Executing Sprinkler Schedule
2019-05-02 20:00:00 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Running script
2019-05-02 20:00:00 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:00:00 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:05:00
2019-05-02 20:10:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:10:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:10:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:05:00
2019-05-02 20:00:17 WARNING (MainThread) [homeassistant.helpers.entity] Update of weather.ecobee is taking over 10 seconds
2019-05-02 20:11:56 WARNING (MainThread) [homeassistant.components.weather] Updating ecobee weather took longer than the scheduled update interval 0:00:30
2019-05-02 20:12:56 WARNING (MainThread) [homeassistant.components.weather] Updating ecobee weather took longer than the scheduled update interval 0:00:30
2019-05-02 20:02:17 WARNING (SyncWorker_15) [pyecobee] Error connecting to Ecobee. Possible connectivity outage.
2019-05-02 20:02:17 INFO (SyncWorker_15) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-05-02 20:02:50 WARNING (Thread-4) [pychromecast.socket_client] [Kitchen speaker:8009] Heartbeat timeout, resetting connection
2019-05-02 20:02:53 ERROR (Thread-4) [pychromecast.socket_client] [Kitchen speaker:8009] Failed to connect to service Google-Home-Mini-ec1bb2e4433b962df6020a45c3469d59._googlecast._tcp.local., retrying in 5.0s
2019-05-02 20:03:17 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.ecobee is taking over 10 seconds
2019-05-02 20:14:57 WARNING (MainThread) [homeassistant.components.climate] Updating ecobee climate took longer than the scheduled update interval 0:01:00
2019-05-02 20:15:57 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:15:57 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:15:57 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:05:00
2019-05-02 20:05:17 WARNING (SyncWorker_14) [pyecobee] Error connecting to Ecobee. Possible connectivity outage.
2019-05-02 20:05:17 INFO (SyncWorker_14) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-05-02 20:06:17 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.ecobee is taking over 10 seconds
2019-05-02 20:17:56 WARNING (Thread-4) [pychromecast.socket_client] [Kitchen speaker:8009] Heartbeat timeout, resetting connection
2019-05-02 20:17:56 WARNING (MainThread) [homeassistant.components.climate] Updating ecobee climate took longer than the scheduled update interval 0:01:00
2019-05-02 20:18:57 WARNING (MainThread) [homeassistant.components.climate] Updating ecobee climate took longer than the scheduled update interval 0:01:00
2019-05-02 20:08:17 WARNING (SyncWorker_3) [pyecobee] Error connecting to Ecobee. Possible connectivity outage.
2019-05-02 20:08:17 INFO (SyncWorker_3) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-05-02 20:09:17 WARNING (MainThread) [homeassistant.helpers.entity] Update of weather.ecobee is taking over 10 seconds
2019-05-02 20:20:56 WARNING (MainThread) [homeassistant.components.weather] Updating ecobee weather took longer than the scheduled update interval 0:00:30
2019-05-02 20:21:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:21:56 WARNING (MainThread) [homeassistant.components.weather] Updating ecobee weather took longer than the scheduled update interval 0:00:30
2019-05-02 20:21:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step call service
2019-05-02 20:21:56 INFO (MainThread) [homeassistant.helpers.script] Script Sprinkler Schedule: Executing step delay 0:05:00
2019-05-02 20:11:17 WARNING (SyncWorker_2) [pyecobee] Error connecting to Ecobee. Possible connectivity outage.
2019-05-02 20:11:17 INFO (SyncWorker_2) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-05-02 20:12:17 WARNING (MainThread) [homeassistant.helpers.entity] Update of weather.ecobee is taking over 10 seconds
2019-05-02 20:23:56 WARNING (MainThread) [homeassistant.components.weather] Updating ecobee weather took longer than the scheduled update interval 0:00:30
2019-05-02 20:24:56 WARNING (MainThread) [homeassistant.components.weather] Updating ecobee weather took longer than the scheduled update interval 0:00:30
2019-05-02 20:14:17 WARNING (SyncWorker_5) [pyecobee] Error connecting to Ecobee. Possible connectivity outage.
2019-05-02 20:14:17 INFO (SyncWorker_5) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-05-02 20:15:17 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.ecobee is taking over 10 seconds
2019-05-02 20:17:18 WARNING (SyncWorker_11) [pyecobee] Error connecting to Ecobee. Possible connectivity outage.
2019-05-02 20:17:18 INFO (SyncWorker_11) [homeassistant.components.ecobee] Ecobee data updated successfully
2019-05-02 20:25:46 INFO (MainThread) [homeassistant.components.automation] Executing Toggle bedroom light
Any idea on why the time may change like that?
