Pistons requiring two runs

#1

Just as the title says Pistons are requiring that I run them twice before they will work. Any idea what might be causing this?

Serious issues with Webcore. Commands disappearing into the ether
#2

Been all kinds of buggy the last couple weeks. I have most of my triggers based on virtual switches and they won’t trigger when they are changed programatically, but when I run them manually they usually do (which would correlate to your running twice scenario). I have no idea what’s causing it, but SUUUUUPER frustrated and so is the non-techy wife, patience is running out with me and the automations.

#3

It seems buggy just like that. I found an error in my harmony hub and logged out and back in in ST so hopefully that was the issue.

#4

Same here:))) if we have a divorce lawyers in this forum, they are about to become super rich LOL

#5

I’ve started looking into Hubitat after this most recent issue. It isn’t just my wife that is upset, but all our guests that finally started to understand automatic lights and fan are now all asking what’s going on (and leaving lights on, etc.).

Definitely an eye opening experience to see ST pretty much give us a “no problem here but we’ll look into it” response when so many of us have unusable systems.

#6

I don’t know about switching to hubitat because if my viper smart start isn’t compatible then I’m out of luck.

#7

Can you post an example of a piston that needed to run twice or is it all of them?

#8

download
download.png1178×1290 181 KB

This is one that is failing for me. I used to have both the on and off commands in the same piston but separated them thinking the piston may have been too complex. Since this started happening I had also switched the condition from “changes to” from “is” with alwaya subscribe. This just made it so I could run the piston manually without needing to flip the virtual switch to attempt to reinitiate. I changed it back to “changes to” for the screenshot.

With the log set to Full it doesn’t even show the Switch had changed to On, but flipping it off and on again would eventually make the trigger register.

#9

Unless it’s just a simple on/off switch all of mine are doing it.

#10

This error keeps coming up in the ST logs but there’s no error showing in the webcore logs.

c93b950d-7c41-4506-a755-d2e16864954b 1:24:44 PM: error org.springframework.jdbc.UncategorizedSQLException: Hibernate operation: could not execute query; uncategorized SQLException for SQL [select this_.id as id42_0_, this_.version as version42_0_, this_.date_created as date3_42_0_, this_.key as key4_42_0_, this_.type as type42_0_, this_.value as value42_0_ from server_config this_ where this_.key=?]; SQL state [null]; error code [0]; [SimpleAsyncTaskExecutor-847] Timeout: Pool empty. Unable to fetch a connection in 30 seconds, none available[size:50; busy:1; idle:0; lastwait:30000].; nested exception is org.apache.tomcat.jdbc.pool.PoolExhaustedException: [SimpleAsyncTaskExecutor-847] Timeout: Pool empty. Unable to fetch a connection in 30 seconds, none available[size:50; busy:1; idle:0; lastwait:30000]. @line 1149 (processSchedules)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: trace ║║ Requesting a wake up for Sat, Jan 4 2020 @ 1:25:14 PM EST (in 60.0s)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: trace ║║ Executed virtual command wait (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Condition #110 evaluated true (4ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Comparison (boolean) false is (boolean) false = true (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Cancelling condition #105’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Condition group #105 evaluated false (state changed) (26ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Condition #108 evaluated false (8ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Comparison (enum) not present is (string) present = false (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Comparison (enum) present is (string) not present = false (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Cancelling condition #107’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Comparison (boolean) false is (boolean) true = false (2ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Condition group #92 evaluated true (state changed) (8ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Cancelling condition #92’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Condition #93 evaluated true (5ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Comparison (enum) off is (string) off = true (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Cancelling condition #93’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Cancelling condition #3’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Condition group #3 evaluated false (state changed) (8ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Cancelling condition #4’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Condition #4 evaluated false (6ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: debug ║║ Comparison (enum) off is (string) on = false (2ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: trace ║╚ Execution stage started

c93b950d-7c41-4506-a755-d2e16864954b 1:24:14 PM: trace ║ Runtime (86530 bytes) successfully initialized in 28ms (v0.3.110.20191009) (128ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:12 PM: debug ║║ Fast executing schedules, waiting for 1995ms to sync up

c93b950d-7c41-4506-a755-d2e16864954b 1:24:12 PM: debug ║║ Cancelling statement #117’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:24:12 PM: info smartapp_pause called by smartAppName=webCoRE Piston, value=1995, smartAppVersionId=48aec84c-d588-4f50-b2e7-2227ef1e452a

c93b950d-7c41-4506-a755-d2e16864954b 1:24:12 PM: trace ║║ Requesting a wake up for Sat, Jan 4 2020 @ 1:24:14 PM EST (in 2.0s)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:12 PM: debug ║║ Cancelling statement #5’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:24:12 PM: debug ║║ Executed physical command [Living Room].setLevel([55]) (9ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:12 PM: trace ║ Runtime (86538 bytes) successfully initialized in 36ms (v0.3.110.20191009) (126ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:12 PM: debug ║ RunTime Analysis CS > 23ms > PS > 36ms > PE > 65ms > CE

c93b950d-7c41-4506-a755-d2e16864954b 1:24:12 PM: info ╚ Received event [Home].time = 1578162253048 with a delay of -869ms

c93b950d-7c41-4506-a755-d2e16864954b 1:24:07 PM: debug ║║ Executed physical command [Kids Room Fan].off() (10ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:07 PM: debug ║║ Cancelling statement #26’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:24:08 PM: trace ║╔ Execution stage complete. (148ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:08 PM: info ╔ Event processed successfully (327ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:08 PM: debug ║║ Condition #104 evaluated false (10ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:08 PM: debug ║║ Condition group #103 evaluated false (state did not change) (12ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:08 PM: trace ║║ Executed [Master Fan].off (45ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:07 PM: trace ║║ Executed virtual command setVariable (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:24:07 PM: debug ║ RunTime Analysis CS > 22ms > PS > 34ms > PE > 71ms > CE

c93b950d-7c41-4506-a755-d2e16864954b 1:24:07 PM: info ╚ Received event [Wendy].switch = on with a delay of 276ms

c93b950d-7c41-4506-a755-d2e16864954b 1:20:05 PM: error org.springframework.jdbc.UncategorizedSQLException: Hibernate operation: could not execute query; uncategorized SQLException for SQL [select this_.id as id52_0_, this_.version as version52_0_, this_.date_created as date3_52_0_, this_.key as key4_52_0_, this_.type as type52_0_, this_.value as value52_0_ from server_config this_ where this_.key=?]; SQL state [null]; error code [0]; [SimpleAsyncTaskExecutor-569] Timeout: Pool empty. Unable to fetch a connection in 30 seconds, none available[size:50; busy:1; idle:0; lastwait:30000].; nested exception is org.apache.tomcat.jdbc.pool.PoolExhaustedException: [SimpleAsyncTaskExecutor-569] Timeout: Pool empty. Unable to fetch a connection in 30 seconds, none available[size:50; busy:1; idle:0; lastwait:30000]. @line 1149 (processSchedules)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: info ║ Setting up scheduled job for Sat, Jan 4 2020 @ 1:20:35 PM EST (in 59.995s)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Cancelling condition #105’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Condition #107 evaluated false (9ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Condition group #109 evaluated true (state did not change) (6ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Cancelling statement #66’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Comparison (enum) not present is (string) present = false (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: trace ║║ Executed virtual command wait (0ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Condition #106 evaluated false (5ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Condition group #105 evaluated false (state changed) (26ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Comparison (enum) present is (string) not present = false (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Condition #108 evaluated false (8ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Cancelling condition #107’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Condition #110 evaluated true (5ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Condition #93 evaluated true (6ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Cancelling condition #92’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Comparison (boolean) false is (boolean) false = true (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Comparison (boolean) false is (boolean) true = false (2ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Cancelling condition #93’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Comparison (enum) off is (string) off = true (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Cancelling condition #3’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Condition group #92 evaluated true (state changed) (8ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Condition group #3 evaluated false (state changed) (8ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Condition #4 evaluated false (6ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Cancelling condition #4’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Comparison (enum) off is (string) on = false (2ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║ RunTime Analysis CS > 28ms > PS > 34ms > PE > 76ms > CE

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: trace ║╚ Execution stage started

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: trace ║ Runtime (86530 bytes) successfully initialized in 34ms (v0.3.110.20191009) (139ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: info ╚ Received event [Wendy].switch = off with a delay of 223ms

c93b950d-7c41-4506-a755-d2e16864954b 1:19:33 PM: trace ║║ Requesting a wake up for Sat, Jan 4 2020 @ 1:19:35 PM EST (in 2.0s)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: trace ║╔ Execution stage complete. (2149ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Cancelling condition #92’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:19:35 PM: debug ║║ Condition #93 evaluated false (9ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:33 PM: info smartapp_pause called by smartAppName=webCoRE Piston, value=1996, smartAppVersionId=48aec84c-d588-4f50-b2e7-2227ef1e452a

c93b950d-7c41-4506-a755-d2e16864954b 1:19:33 PM: trace ║║ Executed virtual command wait (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:33 PM: debug ║║ Cancelling statement #5’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:19:33 PM: trace ║╚ Execution stage started

c93b950d-7c41-4506-a755-d2e16864954b 1:19:33 PM: trace ║ Runtime (86537 bytes) successfully initialized in 38ms (v0.3.110.20191009) (132ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:33 PM: info ╚ Received event [Home].time = 1578161974610 with a delay of -1379ms

c93b950d-7c41-4506-a755-d2e16864954b 1:19:29 PM: debug ║║ Condition group #95 evaluated false (state changed) (26ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:29 PM: debug ║║ Comparison (enum) not present is (string) present = false (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:29 PM: debug ║║ Condition #96 evaluated false (5ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:29 PM: debug ║║ Comparison (boolean) false is (boolean) true = false (1ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:29 PM: debug ║║ Condition #4 evaluated true (5ms)

c93b950d-7c41-4506-a755-d2e16864954b 1:19:29 PM: debug ║║ Cancelling condition #3’s schedules…

c93b950d-7c41-4506-a755-d2e16864954b 1:19:29 PM: trace ║╚ Execution stage started

c93b950d-7c41-4506-a755-d2e16864954b 1:19:29 PM: info ╚ Received event [Wendy].switch = on with a delay of 237ms