Did you check the traces?
For the automation, yes. The issue is that it’s not even triggering at Midnight at the problem times. The timestamps I listed out in the main post are all the times when automation was triggered. It should be interleaved sunset/midnight/sunset/midnight/etc, but note the lack of midnights.
The issue seems to be that the automation isn’t even being triggered.
To be specific, this is the time when it worked:
Triggered by the time set in sensor.sun_next_midnight at May 24, 2024 at 1:29:33 AM
Which was… about a day and a half ago from when I’m making this post. It should have happened again about eight hours ago, but was never executed.
Is there some other trace I can look at to see perhaps when sensor.sun_next_midnight
is being updated and to what?
The sensor rolls over immediately after the time it shows as its state, so it should be fine using it in a time trigger the way you have. You can look at the entity History to see the times of the state changes.
Thank you. That’s good to know. And downloading the last week-ish of history shows what you say, and the midnight time is getting slightly later so it’s definitely not that.
entity_id,state,last_changed
sensor.sun_next_midnight,2024-05-18T05:29:06+00:00,2024-05-17T05:29:03.007Z
sensor.sun_next_midnight,2024-05-19T05:29:09+00:00,2024-05-18T05:29:06.008Z
sensor.sun_next_midnight,2024-05-20T05:29:13+00:00,2024-05-19T05:29:09.008Z
sensor.sun_next_midnight,2024-05-21T05:29:17+00:00,2024-05-20T05:29:13.009Z
sensor.sun_next_midnight,2024-05-22T05:29:22+00:00,2024-05-21T05:29:17.010Z
sensor.sun_next_midnight,2024-05-23T05:29:27+00:00,2024-05-22T05:29:22.013Z
sensor.sun_next_midnight,2024-05-24T05:29:33+00:00,2024-05-23T05:29:27.009Z
sensor.sun_next_midnight,2024-05-25T05:29:39+00:00,2024-05-24T05:29:33.016Z
sensor.sun_next_midnight,2024-05-26T05:29:46+00:00,2024-05-25T05:29:39.009Z
Do you know if there’s a way to see what happens at each… point… system-wide to see if events are scheduled to fire or whatnot? (I’m sure I have the terminology wrong here, but I’m thinking like… At X time do Y.)
The CPU load on this machine is low (currently saying around 4%) and I really don’t have it doing much other than basic HA stuff with Zigbee/Zwave/WiFi sensors/switches/lights and InfluxDB and Grafana to keep long term history. So I don’t think it’d be missing events because of system load?
And again, early this morning, the midnight task never even triggered.
Nothing appeared in the HA logs that appears relevant and my other timers (eg: sunset/sunrise for some other lights) works fine.
Are you having issues with any other time-based automations?
You said this was a RPi 4… How are you running HA?
You could try using a State trigger instead, since the sensors state changes at basically the same time, though you would want to limit the trigger to not fire on unavailable or unknown.
No issues at all. I’ve got only three other timer-based automation. One simply turns two Zwave switches on at dusk and off at dawn, and those have been bang-on reliable for months since I set them up. The other two only trigger if I’m home (lights on 20 minutes before sunset, and on at 6am) and those are reliable as well.
The only other stuff I have is two rarely-triggered motion sensors and maybe a dozen temperature/humidity sensors. All of this is very reliable as well.
Automated backups, to Google Drive, run at 4:23am so not anywhere near the time the midnight automation should.
HA is simply running the official distribution directly on a Pi4B 2GB that has a SanDisk USB SSD connected and which it boots directly from. I keep it as simple as possible to keep troubleshooting/replacement/etc simple. OS is installed to and everything boots and runs from the SSD. There is no microSD card installed.
I like your state trigger idea, I might also try simply setting it for a fixed time about then for the next few days and see what happens.
The automation worked last night. I hadn’t changed anything, it just happened to work this time.
I almost feel like this is going down the path of a bug, but it’ll take a bunch more digging before I can show that… I guess a good, simple test would be an automation that writes to the logbook. I’ll set something up to trigger on midday and midnight to write debug log entries and go from there, I guess.
To build on the last post, I set up two debug automations. It’ll be interesting to see what they gather. Here’s the midnight one, and I’ve also set up a noon one which is effectively the same:
alias: "DEBUG: Midnight"
description: ""
trigger:
- platform: time
at: sensor.sun_next_midnight
condition: []
action:
- service: logbook.log
metadata: {}
data:
entity_id: sensor.sun_next_midnight
name: DEBUG_MIDNIGHT
message: Midnight Event Triggered
mode: single
I guess I should note that my other (reliable) scheduled things, since they trigger on dusk and dawn, are using the sun
platform whereas the noon/midnight uses the time
platform:
alias: "Exterior Lights: Dusk-Dawn"
description: ""
trigger:
- platform: sun
event: sunrise
offset: 0
id: sunrise
- platform: sun
event: sunset
offset: 0
id: sunset
Hmm…
So now I’m even more confused… For the last two evenings my debug automation triggered at midnight, but only one of the light automations triggered (the night before last).
Here’s the trigger section for the one that seems to work reliably:
alias: "DEBUG: Midnight"
description: ""
trigger:
- platform: time
at: sensor.sun_next_midnight
And here’s for the one that intermittently doesn’t:
alias: "Interior Lights: On/Off at Sunset and Midnight (if Not Home)"
description: ""
trigger:
- platform: sun
event: sunset
offset: 0
id: lights_on
- platform: time
at: sensor.sun_next_midnight
id: lights_off
Any ideas how I can go deeper in troubleshooting this? Like some sort of debug level logging?
Just out of curiosity, would you mind trying another sun integration, to see, if it works with that?
I’m starting to get the feeling, that something’s off with the sun sensor from HA.
Please try this integration and see, if it triggers the automation correctly.
And here’s the support topic:
It’s available in HACS. EDIT: as a custom repository in HACS…
Personally, I’d not rely on using a sensor for a time trigger whose state changes at approximately the same time as the sensor’s value. Given all the stuff that goes on in the core to purposely prevent a slew of triggers firing at exactly the same time, chances are that is preventing the trigger from happening as you would expect. And I wouldn’t even necessarily say this is due to some sort of bug. It’s just you’re depending on this sensor to retain its value until after that time passes, and more than likely, sometimes it’s changing right before that time passes.
FWIW, the corresponding sensor from my Sun2 integration (e.g., sensor.home_sun_solar_midnight) always changes its value at 00:00:00 (+/- a few microseconds, due to the same core “feature” I mentioned above.) Still, as solar midnight changes from day to day, it can go from just before 00:00:00 to just after, or vice versa, and the same thing might happen (i.e., changing right before it would have triggered your automation.)
If you just want something that is “around midnight”, but not the same every day, it might be better to create an input datetime helper and have an automation, say every day around noon, change its value to midnight +/- some random amount of time. Then use that as the input to your automation.
That’s why I suggested your integration! It’s much more reliable than the default one from HA.
To prevent such a race condition, I’m working with the attribute from your sensor for tomorrow. As soon as the sensor changes, I update an input_datetime
helper with that value, and use the helper as trigger.
In an essence, I’m setting the time a day before it actually is used. Works great and I can’t say I had any issues with your integration. Yes, I’m a fanboy, and after years of usage I still know why!
EDIT: Btw. I have said it before, but thanks a lot for sun2
, I really love it!
Thank you for that.
Do you know how I could actually see this?
I’d really like to go deeper on this, but I’m having a very hard time finding info on how to enable debug-type logging. (But haven’t delved into reading code yet…)
Your sun sensor looks great, but to be honest, I’d really like to see why the issue is occurring before I try something different to solve it. I don’t really need this ‘midnight’ sensor, it just seems useful. Instead I can just do something else like you describe… Some other midnight-ish time. Or just a fixed time.
What (slightly) irks me is the option to use that time is there, but it doesn’t reliably work. So I’d like to understand why, and if it is a bug, file it. Or if it’s just a caveat, maybe help ensure it’s well documented.
To turn on debug mode for specific integrations you set the level in logger
.
See here:
I’m not trying to troubleshoot an integration, though… I’m trying to troubleshoot automations not triggering on an integration. So, I think, whatever the internal scheduler is, in conjunction with the timing of the sun integration?
Also, back to my debug automations, it appears those didn’t trigger either over the past couple days. So it seems to be some quirkyness triggering based on the sun_next_noon
and sun_next_midnight
entities.
You could enable logging for some core stuff. E.g., in configuration.yaml you could add:
logger:
default: info
logs:
homeassistant.components.automation: debug
homeassistant.core: debug
homeassitatnt.helpers.event: debug
homeassitatnt.helpers.script: debug
This will add a bunch of DEBUG messages to the log that might help shed some light. But honestly, to really “see” what’s happening, you might need to instrument the code some more.
FWIW, here is where the time trigger is implemented:
Basically, in your case, if the processing of sensor.sun_next_midnight changing state happens before the trigger processing, the previously set trigger “arming” will be removed and a new one (for the next midnight) will take its place, causing the previous one to be “missed.”
Based on the times you posted earlier from the database, there’s only about 8 milliseconds or so between when the trigger should fire and when the state of the sensor changes. I’m not saying it’s definitely happening, but I think it’s possible, especially if you’re running HA on a less powerful system, and you have it doing a lot, that the trigger callback is being delayed by other stuff, including the processing of the sensor’s state change, which will cause the trigger callback to be removed before it gets a chance to actually run.
Again, I doubt what you’re experiencing can be classified as a bug, although, of course, it might be. I really think that depending on a time trigger to fire at the time a sensor’s value indicates, when the sensor also changes at that same time, is not a robust design.
Thank you very much. This is really helpful.
And yeah, I think that’s likely what’s happening… If I get a bit of time in the next few days I’ll do a little digging to see if I can prove it out. (Balanced with is-it-really-worth-it…)
In the mean time I’ll change the actual automation to something… else… and leave the debugging one for troubleshooting.
I really appreciate it.
I wouldn’t say it’s more reliable, but I suppose it could be said, the way it works, is more useful in some situations. Which, after all, was kind of why I wrote it in the first place.
I see what you’re saying, but isn’t it really the same thing? I.e., the main state, as well as the yesterday, today & tomorrow attributes, all change at the same time, around 00:00:00. Then your automation would immediately change the input_datetime
helper. The only real difference is a bit more delay between 00:00:00 and when the trigger’s input changes (as opposed to using the sensor directly), right? Given your overall configuration and system performance, maybe that’s enough to make it work all the time. Or maybe the sensor you’re using (indirectly) sets a trigger time that’s nowhere near 00:00:00, and it wouldn’t matter if you used the sensor directly???
I made a blueprint a while back that essentially just adds the ability to use and offset to a Time trigger based on an entity like your sensor. Maybe, triggering a couple minutes before the sensor rolls over will solve the issue.
That’s kinda what I did. For now I’m simply using 7 hours before dawn for turning the lights off. The goal is a simple turn lights on and off at a not-exactly-specific time when we’re not home thing.
Initially ‘midnight’ sounded good because it’d vary, but since that’s not reliable… This should suffice.
I don’t want to get into any sort of occupancy simulation or anything that complicated, just some basic lights that are on when we aren’t home, which also get shut off at not-always-the-exact-same-time.
So, I think this’ll suffice.
(My HA setup heavily leans towards simple with as few additions to the base as possible.)