Any new results from your investigation, @jake9?
@gopher.ny - Victor - see anything in the engineering logs?
Engineering logs show sunrise/sunset calculating right after midnight, and values change day to day. Whatever this is, it's upstream.
2 Likes
I haven't had the issue for the last several days, so nothing to report unfortunately. I agree with the feeling that this will be 'upstream' but the logging I put into webcore will tell me when it happens.
2 Likes
Maybe it has something to do with my mode change times. I had Mode Dawn set to Sunrise -30. My Mode Day begins at 6:15. This is what the logs say. I took the -30 out yesterday and the modes changed properly now.
1 Like
Welp, I put in a bunch of debugging stuff, added two dedicated apps to test 5 minutes BEFORE sunrise and 5 minutes AFTER sunrise. And everything is working perfectly. So, never mind. 
And thanks for listening.
2 Likes
LOL...just think of us as your community teddy bear. 
1 Like
I finally had this happen again yesterday and think it is a WebCore bug. Since it had not happened I turned the nightly reboot back on (3:45AM) to see if that made a difference so I didn't have a chance to look at the state of the hub afterwards.
I believe there is a race condition with how webcore caches sunrise/sunset times. The cache (midnight, sunrise, sunset, etc.) is cleared and updated if the current day is after the calculated midnight in the cache map. The sunrise/sunset times come from HE APIs, however the midnight contained within the cache map is calculated within the app so there is never validation that the cached sunrise/sunset times are for the appropriate day. It seems that HE has not yet calculated the new sunrise/sunset times when they were requested so the old dates were cached and since the midnight validation was correct, won't be refreshed again.
Here is the update timing (it pulled app.getSunriseAndSunset() just after the second log entry).
[app:530]2022-04-20 00:00:00.210[info]Resetting sunrise/sunset
[app:530]2022-04-20 00:00:00.211[info]Updating sunrise/sunset
From the engineering logs previously (not for this date), the sunrise/sunset job had run at ~00:00.178, however depending on it to run and complete within 200ms of midnight clearly is not going to work consistently. The prior night, the webcore cache update started at 00:01.139, so the sunrise job likely had just enough time to run.
When I get some time, I'm going to look at fixing the WebCore logic. That said, I'm not sure if it will still schedule jobs for the wrong time if it initially gets an old value.
