(Re)Scheduled Smartapp Failing


#1

Sigh… I had hoped that ST finally fixed the scheduling problem. Obviously not. In the last 3 days/nights my (long-running) smartapp failed to reschedule once each day, hence, stops working. No specific time when it failed. Nothing in the log that indicated a problem.

When working properly the app should run once on the hour then schedule the next run 1 hour later. For unknown reasons, in past 3 days, this rescheduling has failed once each day.


(Bobby) #2

I am seeing major issues lately too. The platform is pooped out again!


(www.rboyapps.com - Make your home your butler!) #3

Which API are you using? Once time API’s like runIn/runOnce or schedule()?

Also I’ve noticed by looking at the SmartApp details sometimes the method is “called” by the scheduler but it just never executes. So if you’re daisy chaining it will fail to schedule the next run time as it never executes even though the history shows that the function was “called” (not).


#4
runOnce(date, logData)

This runs (or is supposed to) every hour on the hour, 24 hours/day 7 day/week. There is no pattern to when it fails. Could run for days and then… :tired_face:


(www.rboyapps.com - Make your home your butler!) #5

This is a Single execute run, it’s a once and done API.
http://docs.smartthings.com/en/latest/ref-docs/smartapp-ref.html#runonce

EDIT: Are you daisy chaining this API (calling it back over and over again from within the method logData)

You would want to use

schedule(cronExpression or dateTime, logData)

http://docs.smartthings.com/en/latest/ref-docs/smartapp-ref.html#schedule

If you want it to run every hour for 24/7 then use

runEvery1Hour(logData)


#6
def logData() {
.
.
.
.
.
.
// Call scheduledLog before SendHTTP in case there is a server error. 
    scheduledLog()
    sendHttp(tableString)
}

/* ------------------------------------------------------------------------------------------------- */
def scheduledLog() {
	def timeMs=now() + 3600000
	def date = new Date(timeMs)
	def m = date.format('m').toInteger() * 60
	def s = date.format('s').toInteger() 
	def onTheHour= timeMs - (m + s) * 1000    
	date = new Date(onTheHour)
	sendNotificationEvent( "Next runOnce() is scheduled for $date")
	runOnce(date, logData) 
}

(www.rboyapps.com - Make your home your butler!) #7

Right that’s what was I alluding to earlier, you’re daisy chaining the runOnce calls. The new Ticker is far from perfect when it comes to runOnce schedules, like I had mentioned, sometimes it will pretend to call the function but actually never call it so the net effect is that your timer chain is broken. ST also recommends that once doesn’t daisy chain timer, I guess they know about the dropped schedule issue.

A couple of things I’ve noticed, runIn works better than runOnce for short period of time. In your case I would call runEvery1Hour(logData) from the updated/initialize function of the smartApp and remove the scheduledLog() function entirely. When you’re done with the logData() function call unschedule(logData) and you’ve cleaned up.


(www.rboyapps.com - Make your home your butler!) #8

If you want to verify when it broke open your SmartApp details under My Location and see the execution history.


#9

Does this allow setting the actual time. The logdata must be executed on the hour to record my Home Energy Meter readings as these numbers are compared to actual meter readinfg by my utility company.


(www.rboyapps.com - Make your home your butler!) #10

No but schedule() does, use a cron expression

schedule("* 0 * * * *", logData)


#11

That does not work. In fact, even the example in the documentation fails

// execute handlerMethod3 every hour on the half hour
schedule("0 30 & & & ?", handlerMethod3)

error :invalid cron expression found ‘0 30 & & & ?’


(www.rboyapps.com - Make your home your butler!) #12

Try this:

schedule("* 0 * * * ?", logData) // On the hour every hour

or

schedule("* */60 * * * ?", logData) // every 60 minutes


(www.rboyapps.com - Make your home your butler!) #13

Use this for every 30 minutes

schedule("* */30 * * * ?", logData) // every 30 minutes

and this should be every 30 minutes on the hour

schedule("* 0/30 * * * ?", logData) // every 30 minutes on the hour


#14

Well :slight_smile: It didnt return any errors when I updated tghe app. Now to wait for 20 minutes to see if it actually runs :wink:


(www.rboyapps.com - Make your home your butler!) #15

You can see what’s scheduled. IDE -> My Location -> List SmartApps, -> Locate your SmartApp and click on it -> Scroll down to scheduled events. See what time it’s scheduled to run and what type of timer it is.


#16

DUH!!! :blush: Of course I can :grinning:


#17

Well, after several day of using this new method I can say it is a big improvement however… I still get the odd unexplained “failure”.

The run scheduled for 2PM shown in Job History shows the App ran as shown below for

However, based on the notifications, nothing actually happened during that run. At the start and end of the function called by schedule() I placed SendNotification to log what actually happened during the hourly run. Note that there was no entry for 2PM run.

The good news is that at least now the app continues to run and the data not recorded at the 2PM mark was not lost but added to the 3PM run.


#18

BOOOOH!!! Scheduled apps failing like there is no tomorrow. One app that runs every hour (at least its supposed to) failed for numerous hours last night.

Job History
Handler	Scheduled Time	Actual Time	Delay (msec)	Execution (msec)
logData	2016-07-15 8:00:25 AM EDT	2016-07-15 8:00:55.429 AM EDT	30429	13658
logData	2016-07-15 6:00:25 AM EDT	2016-07-15 6:00:50.304 AM EDT	25304	5978
logData	2016-07-15 5:00:25 AM EDT	2016-07-15 5:00:53.746 AM EDT	28746	11094
logData	2016-07-15 4:00:25 AM EDT	2016-07-15 4:00:56.611 AM EDT	31611	16616
logData	2016-07-15 3:00:25 AM EDT	2016-07-15 3:00:57.679 AM EDT	32679	12203
logData	2016-07-15 2:00:25 AM EDT	2016-07-15 2:01:00.968 AM EDT	35968	16131
logData	2016-07-15 1:00:25 AM EDT	2016-07-15 1:00:58.719 AM EDT	33719	10005
logData	2016-07-15 12:00:25 AM EDT	2016-07-15 12:00:54.505 AM EDT	29505	101825
logData	2016-07-14 9:00:25 PM EDT	2016-07-14 9:00:59.582 PM EDT	34582	9988
logData	2016-07-14 8:00:25 PM EDT	2016-07-14 8:00:55.425 PM EDT	30425	16136

(John) #19

Things have started failing at a higher rate over the last week. I have seen lots of scheduling issues too.