I have a SmartApp that runs twice a day. In the morning it runs one process and in the evening it runs a different process. The evening process is a little more involved, but not significantly. Over the last few weeks (especially the past week) I have noticed that the morning process has increased from around 4 seconds to over 20 seconds. The evening process has increased from around 8 seconds to over 20 seconds. The times do not coincide with sunrise or sunset (in the US).
With 20 seconds (or so) being the magic number for ST killing an app, this has become a major problem. The app was not changed so that cannot account for the increase in time. No new devices have been added either. My internet connection is fine - no issues. The issue is not just isolated to my app, but also seems to be affecting the ecobee app as well. It appears that anything that involves cloud-to-cloud or round-trip-to-cloud (i.e. my app checks the status of one device before making a change to another) is slowly increasing in execution time. Maybe this issue will go away with Hub v2 (and likely replaced with some other issue), although ecobee may still be an issue due to its cloud dependence (if I understand correctly how Hub v2 decides whether or not the app runs locally on the hub).
Once the times increase to the point of critical mass, the apps fail. I understand the need to limit execution time, but execution time is dependent on more than just the app. Has anyone else noticed this?
Iāve noticed that one of my Hello Home phrases has added a very noticeable 10 to 15 seconds to its execution time sometime in the last few weeks.
This is a gate notification. When the gate opens, it should ring a bell in the house.
We were getting the ring almost at the same moment that the gate opens. Now the person usually gets all the way to the front door and knocks before the bell rings. If itās my housemate coming in, he may have unlocked the door and come in before the bell.
This is a very obvious change, and makes the gate bell much less useful.
Except mine is a plain vanilla Hello Home Action based on a contact sensor opening. No schedule or unschedule involved that I know of. Gate opens, notification is sent. This is now consistently taking about 10-15 seconds longer than it did a month ago.
I believe the root cause is the same though. The message queues got clogged up. Time to call the plumber. For some bizarre reason it always happens on weekends.
Last night it hit 46 seconds (nearly a 500% increase in execution time). All the app did was check the status of a device, determine who was home, and turn another device on.
Maybe Hub v2 will solve this (it at least eliminates the cloud aspect for this app) and if so, not having a migration utility isnāt enough of a hindrance. This is a bigger issue for me than setting things up again.
@geko@keithcroshaw@tgauchat I was hoping that you might have some insight. So Iāve been watching my app fail today (I set it so it would trigger) and I noticed something that I did not expect. I thought it would fail on some line in the actual scheduled processing that was taking ātooā long. However, the line that it complains about taking too long is in the preferences.
section("Changes to 'away' mode...") {
Why would it fail here when it is executing a block of code from a scheduled event? What am I missing?
section("Changes to away mode...") {
input "modeAway", "mode",title:"When this mode becomes active:", required: true, multiple: true
input "modeAwayActivate", "enum", title: "Activate the alarm?", metadata: [values: ['Yes','No']], required: true
}
I made the change suggested by @keithcroshaw - I took out the single quotes. This was before I saw your response. The error message that I was receiving said that the āsectionā line above exceeded 20 app seconds. It made no sense to me since it shouldnāt be executing that line anyway.
So when I ran it the next time without the single quotes, I got a another strange error referencing a line stating that I canāt add ānull + nullā. Again this was before I saw your response.
The frustrating part for me is that the app worked perfectly for months. And it still works, sometimes, but when it fails the errors show up at weird locations and up until this last one, always stated that it exceeded 20 app seconds.
Since none of this made any sense (i.e. the ānull + nullā error message where nothing was being added or concatenated), I tried something different. I copied the code, deleted the app, and then re-added the app. Now the execution times are around 1 second. So far, no new errors, but itās too early to know for sure.
java.util.concurrent.TimeoutException: Execution time exceeded 20 app execution seconds: 461842538451231 @ line 63
java.util.concurrent.TimeoutException: Execution time exceeded 20 app execution seconds: 462758065996948 @ line 122
java.util.concurrent.TimeoutException: Execution time exceeded 20 app execution seconds: 462789754635758 @ line 17
java.util.concurrent.TimeoutException: Execution time exceeded 20 app execution seconds: 462820632591649 @ line 585
Line 17 is a comment.
Line 63 sets up a section in preferences.
Line 122 sets up a page in preferences.
Line 585 is a log.trace
Multiple apps are experiencing the problem. It does get horrendously worse around sunrise and sunset (even though the app I initially asked about shouldnāt be hindered by that issue).
@geko made a comment about the message queue getting clogged, and I would agree (especially with respect to line 585).
But Iām confused as to why it references lines that are comments or preferences as taking too long. I donāt understand why it is trying to process comments or preferences (since theyāre not needed during execution). Thanks for your help @geko@keithcroshaw.
Something smells fishy here. Obviously comments have no executable code, so they canāt ātake too longā to execute. And preference sections execute only when you open the app preferences. Are you sure the messages that you see have the correct app id?