Troubleshooting scheduled event failures


(Aaron) #1

I have a SmartApp I’m working on that is is suffering from some reliability issues with scheduled events. I am trying to troubleshoot. . . .when I look at the SmartApp status page, I see this evidence that an event that should have fired this morning at sunrise did not occur (not delayed, just did not occur). I also see this:

Everytime I pulled up this screen, the ‘next run time’ looks correct. However, the ‘prev run time’ is always garbage. That is, is says "1969-12. . . . " even when I know it ran, say, yesterday. I assume the ‘status’ of ‘waiting’ is appropriate and means the event is scheduled and waiting for the time to come for the event. I don’t know what I’m looking at in the last column labeled ‘schedule’.

On the ST platform status page, for a while, this has been posted:

However, what I am seeing is not a delay, just a failure altogether to fire. So, where do I go from here? I’ve considered adding some redundancy (schedule the same event once and then again for 5 minutes later, for example) but that seems like a band aide that may or may not work depending on the root cause of the problem. Any suggestions would be appreciated.


Dusk-to-Dawn Dimming Motion Light - RC1
Help with display of dates in log
(Ron S) #2

The incorrect Prev Run time issue has forever been there. Even when the scheduled events trigger correctly, it still shows the same 1969 year. Usually the last event datetime is always before we were born.


(Aaron) #3

I was afraid of that . … .

Maybe you. . . not me. I’m old :wink:

Thanks for linking the other thread. Besides some time travel/tardis jokes, I see @urman agreed to look into this but that was before the holidays and CES.


#4

Just adding to the discussion. I have simple on/off app from ST that I use to control my aquarium lights. I have 2 different banks that are staggered for burst lighting. Anyways, the first one that comes on at 5PM and turns off at around 930PM has stopped getting the OFF commands from my app. It’s been about 3 days now that I wake up and the lights are still on (algae farm!). The other bank of bulbs turn on and off as scheduled. I even tried adjusting the time to turn off just to see if it makes a difference but no go.

I emailed support this morning, still waiting for reply.


(Geko) #5

This is common Java programming error when converting Unix (epoch) time to Java Date object. The conversion requires explicit casting of epoch time to long data type which is often overlooked and results in incorrect Date. I believe this is just a UI issue though.

I don’t know what I’m looking at in the last column labeled ‘schedule’.

You’re looking at cron schedule.


Turn on at sunrise or sunset not working
(Ron S) #6

@geko it’s always nice learning from you guys! Why did they choose 1969? Woodstock?


(Geko) #7

Good try. :smile: Well… Unix epoch time is defined as number of seconds since Jan 1st, 1970. But when you apply time zone (UTC-06:00 for Chicago), you’ll get exactly what you see in the log: 6 PM, Dec. 31, 1969.


(Aaron) #8

@geko - helpful as always. Thanks. I found this link in the docs to a Quartz page that describes a cron implementation with a seconds field.

Can I fix this in my code or is this a problem in the code that generates the SmartApp status page?

I’m still feeling my way through a lot of this. I am using the getSunriseAndSunset() method and I really don’t fully understand what I’m getting back in the map. I have this issue that I haven’t solved where dates show up in my logs in a regular format and sometimes in a epoch format. I suspect that the dates I get back from the ST method are coming in in epoch and groovy is just somehow handling it for me in certain cases and masking the error.

If what I need to do is to bring the dates in from the map into variables explicitly cast as long and then do the conversion to java date object, I will see if I can figure out how to do that and see if that fixes the log issue and has any positive impact on anything else.


(Jody) #9

I have a security light set up with one simple rule; turn on when there is motion between the hours of 5:30 pm and 7:45 am or turn off if there is no motion for 15 minutes. Today my security light was still on at 8:45 am CST. It appears that scheduled events are not firing even during non-peak times.


#10

This is where I get frustrated with ST. The simplest apps that turn on/off at specific times (no other conditions) just stops working. The ON command gets sent but the OFF command does not.I emailed support but didn’t get much of a resolution so I just deleted the app and started over and tried to name it differently to see if it helps. It’s been working for 2 days without a glitch, crossing my fingers!


(Aaron) #11

FWIW, I’ve learned a lot about handling dates/time/schedules/etc. in ST from the community and through my experience writing my porch light app. The current version of the app seems to be stable and I have not noticed any scheduled event issues. I am still certainly no expert - far from it - but I would be willing to look at code to see if I notice any issues.


#12

The sad thing about mine is I’m using ST’s stock Once A Day app. :frowning:


(Jody) #13

Where is your porch light app? I am using the simple turn lights on motion trigger that is built in.


(Ron S) #14

Same here. Scheduled events are not firing. Opened ticket. Please open a ticket so that they know it is system wide.


(Aaron) #15

Look towards the end of the thread to find the latest posted code. I haven’t yet posted the version running without issue at my house but will soon. Stay tuned.


(Aaron) #16

Well, that’s a super simple app . . . no reason for it not to work other than some other system issue.


(Eric R) #17

Actually, that scheduled job has never run. Every day, you are creating a new sunrise and sunset time. When the app schedules the new job, it deletes the old job and creates a new job. If it has never run before, my guess is it returns a -1 unix time which is 1 second before Jan 1, 1970 UTC. I think if you look at a schedule that happened already and hasn’t been rescheduled, it would show the previous run time.


(Ron S) #18

Yeap! 1969. @geko explained in one of the threads why! :slight_smile: BTW, the sunset event triggered for me today. Yesterday was the only exception. For some reason it works most of the time for me. Things will definitely get better! Cheers!


(Aaron) #19

Yes! This explains it. Understood. Much appreciated, @baldeagle072 . 2 suggestions, @Ben, @Jim, to make this more clear: 1) add a column showing the date/time the schedule was initiated, and/or 2) trap for the null or 1 date and display “n/a” or something other than the day time began for Epoch.