One Last Hail Mary


#1

All my pistons that use “when time happens daily at…” are failing. They fire about 1-2 minutes late and the “time happens daily” condition evaluates false.

Things I’ve noticed:

  1. When my pistons were working, my log files used to show [Home].time when they executed based on “time happens daily”.
  2. Now, when they fire late, they are triggered by [Home].execute
  3. This is always followed by {Home].time/recovery within 15-20 seconds. The [Home].time/recovery trigger still evaluates false for my “time happens daily” condition so my pistons don’t execute the appropriate code.

I have some other issues to sort out, like lights turning on despite webCoRE not showing commands sent - but the above seems to be the tip of the iceberg. If I can get some help sorting this out, I’d really appreciate it.

For now I’m using the Smart Lighting app in place of webCoRE but it leaves a lot to be desired.

@ipaterson @bangali @Robin really hoping one of you guys can help me sort this out. I have cleared memory/cache, updated Apps… everything I can think of from the front end.


Long delays in piston execution
Mode change at specific time
Help with thermostat piston
#2

Long shot, but have you made or pasted any code changes in the smart apps? I had that experience while testing some changes attempting to fix early time triggers but I don’t think I shared any sample code for that… The way I tried to reschedule the time triggers would always time out and so the piston eventually woke from the recovery step.


#3

Unfortunately, I haven’t. These pistons were working just fine for nearly 1 year… then they all fell apart. Every single one of them that uses “time happens daily” or Sunrise/Sunset triggers went from fine one day to not working the next. And I haven’t been able to get any of them to work correctly since (it has been 6 or 7 weeks now).


#4

ok how about this,
just delete a piston and re-write the same exact way and test.
i have heard that sometimes this works. (don’t know why above my pay check:)))))


#5

Are there any pistons for which you can share an anonymized green snapshot? I’m curious whether others would be able to experience the same late triggering with your pistons. Which shard are you on (i.e. what is the url after you log in at account.smartthings.com)?


#6

Good thinking! And I already tried and it didn’t work… but what is it they say about great minds?! :slight_smile:

Here is a brand-new piston, and the log from its last two executions (both of which failed as described above). I’ve added emphasis in the logs where teh questionable behavior is happening.

I’m running on the na04-useast2 shard.

And last but certainly not least, thank you for trying to help! This failure mode has completely ruined home automation for me and I’d like to get it back. Bonus points if we can figure out how/why it’s doing this… I can’t tell anything from the logs.

11/21/2018, 7:30:35 AM +493ms
+0ms ╔Received event [Home].time/recovery = 1542803435492 with a delay of 0ms
+599ms ║RunTime Analysis CS > 250ms > PS > 307ms > PE > 43ms > CE
+602ms ║Runtime (42859 bytes) successfully initialized in 307ms (v0.3.108.20180906) (601ms)
+603ms ║╔Execution stage started
+605ms ║╚Execution stage complete. (2ms)
+607ms ║Setting up scheduled job for Thu, Nov 22 2018 @ 7:30:00 AM EST (in 86363.901s)
+617ms ╚Event processed successfully (617ms)
11/21/2018, 7:30:35 AM +207ms
+0ms ╔Received event [Home].execute = recovery with a delay of 129ms
+148ms ║RunTime Analysis CS > 21ms > PS > 65ms > PE > 63ms > CE
+151ms ║Runtime (42844 bytes) successfully initialized in 65ms (v0.3.108.20180906) (149ms)
+152ms ║╔Execution stage started
+162ms ║║Comparison (time) 27035366 happens_daily_at (time) 27000000 = false (1ms)
+164ms ║║Condition #31 evaluated false (5ms)
+166ms ║║Cancelling statement #31’s schedules…
+170ms ║║Requesting time schedule wake up at Thu, Nov 22 2018 @ 7:30:00 AM EST
+174ms ║║Condition group #30 evaluated false (state did not change) (15ms)
+177ms ║╚Execution stage complete. (25ms)
+179ms ║Setting up scheduled job for Thu, Nov 22 2018 @ 7:30:00 AM EST (in 86364.615s)
+187ms ╚Event processed successfully (187ms)

As I mentioned above, the logs for events on SmartThings and webCoRE don’t align. Not a single one of them. Clearly above the time condition failed, therefore no commands were sent to lights. However, one light was left on this morning. Three lights met the condition of the piston at 7:30am (level below 99% and switch off)… yet only one was turned on. And it was never turned off; at least not by the piston, it was manually switched off by my (way out of patience) wife at 7:45am.