After much trouble, I’ve figured out that my timing issues are due to some sort of mismatch in time zone in HassOS and Home Assistant. I’d love for anyone who understands and can explain (or link to explanations, code, diagrams, anything helpful really) to give an overview of how timezones are expected to work with Hass.io.
Below are the details of my problems and how I noticed them:
After some debugging in another thread[1] I setup this alert:
alert_test:
name: Alert Test fired
done_message: Alert test closed
entity_id: input_boolean.alert_test
state: 'on'
repeat:
- 2
can_acknowledge: false
skip_first: false
notifiers:
- notify_log
then I turned on input_boolean.alert_test
and left it on for over a day (which should have spammed me with notifications every 2 minutes for a day.). Here’s the log result:
➜ /config cat cmd/file_notify.txt | grep "Alert Test"
2019-05-30T04:01:59.710176+00:00 Alert Test fired
2019-05-30T05:06:05.752723+00:00 Alert Test fired
2019-05-30T12:08:06.024880+00:00 Alert Test fired
2019-05-30T19:10:07.025693+00:00 Alert Test fired
2019-05-31T02:12:08.032596+00:00 Alert Test fired
2019-05-31T09:14:09.029256+00:00 Alert Test fired
2019-05-31T16:16:10.027057+00:00 Alert Test fired
2019-05-31T17:30:15.733670+00:00 Alert Test fired
Ignoring some outliers (likely caused by my restarting the system for config changes, etc) I noticed that the alert was actually firing once every 7 hours and 2 minutes. Here are just the relevant timestamps from above:
05:06:05
12:08:06
19:10:07
02:12:08
09:14:09
16:16:10
So I did some searching about time zones, and came across a thread [2] recommending to run this in the Template Editor:
{{ now() }}
{{ now().astimezone() }}
{{ utcnow().astimezone() }}
{{ now().now() }}
{{ now().today() }}
{{ now().utcnow() }}
{{ utcnow() }}
{{ now().tzinfo }}
{{ now().astimezone().tzinfo }}
{{ utcnow().tzinfo }}
My output was:
2019-05-31 11:26:19.773069-07:00
2019-05-31 18:26:19.773223+00:00
2019-05-31 18:26:19.775135+00:00
2019-05-31 18:26:19.775495
2019-05-31 18:26:19.775705
2019-05-31 18:26:19.775898
2019-05-31 18:26:19.775936+00:00
America/Los_Angeles
UTC
UTC
The expected output from a working system was something like:
2019-02-02 21:52:43.591028-06:00
2019-02-02 21:52:43.591370-06:00
2019-02-02 21:52:43.592234-06:00
2019-02-02 21:52:43.593221
2019-02-02 21:52:43.593807
2019-02-03 03:52:43.594381
2019-02-03 03:52:43.594514+00:00
America/Chicago
CST
UTC
I’m fairly experienced with Python, but my Time foo is lacking. My best guess from this output is that somehow the timezone that is being used by the python environment is UTC despite the local time on the system and the time set in Home assistant being PT. Unfortunately, I don’t know where to go from here.
As a temporary workaround, I have set the time zone in my configuration.yaml to UTC and everything seems to be working as expected now (except that it all shows UTC time stamps)
[1] Alerts don't alert after first time
[2] "Internal" time wrong