To Be Physical, Or Not To Be


#1

1) Give a description of the problem
My piston isn’t deciphering physical from digital/programmatic changes.

2) What is the expected behavior?
Lights should stay on if a physical switch interaction is detected after they were turned on my a motion sensor. If no physical interaction, they’ll turn off after a period of time without motion.

In the example below there were two event. The first is the motion sensor turning on the lights. The second, I’m not sure why that is happening. It almost seems like a response from the switch that’s being processed as a new action rather than a response from the piston turning it on.

3) What is happening/not happening?
The piston is turning the light on, which is almost immediately followed by a light switch event re-triggering the piston. This light switch event is deemed physical by webCoRE but appears digital in the ST logs.

Appreciate any help here. I’ve been WAY over my head tinkering with DTH stuff to get this to work. I thought once I had the switch interactions reporting as digital rather than physical, I’d be home free.

4) Post a Green Snapshot of the pistonimage

5) Attach any logs (From ST IDE and by turning logging level to Full)
` 11:12:38 PM: debug ║║ Condition #33 evaluated false (4ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Cancelling condition #30’s schedules…
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Comparison (integer) 2 rises = false (1ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Cancelling condition #33’s schedules…
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Comparison (boolean) false is (boolean) true = false (1ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Calculating (integer) -92 < (integer) 15 >> (boolean) true
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Condition #32 evaluated true (4ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Cancelling condition #6’s schedules…
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Calculating (decimal) 1.1558376E7 / (decimal) 60000.0 >> (decimal) 192.6396
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Condition #26 evaluated false (5ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Comparison (enum) inactive is (string) active = false (1ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Calculating (datetime) 1512187958376 - (datetime) 1512176400000 >> (datetime) 11558376
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Condition group #17 evaluated false (state did not change) (4ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Cancelling condition #12’s schedules…
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: info ╚ Received event [Z-Wave Motion Sensor].motion = inactive with a delay of 180ms
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: trace ║║ Executed virtual command setVariable (3ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Calculating (integer) -92 > (integer) 100 >> (boolean) false
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Calculating (decimal) 100.0 - (decimal) -966.63945 >> (decimal) 1066.6394500000001
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Calculating (datetime) 1512129960000 - (datetime) 1512187958367 >> (datetime) -57998367
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: debug ║║ Calculating (datetime) 1512187958361 < (datetime) 1512129960000 >> (boolean) false
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: trace ║╚ Execution stage started
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:12:38 PM: trace ║ Runtime (49083 bytes) successfully initialized in 68ms (v0.2.0ff.20171129) (240ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:28 PM: info ╔ Event processed successfully (390ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:28 PM: debug ║║ Cancelling statement #13’s schedules…
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:28 PM: debug ║║ Condition group #12 evaluated true (state changed) (9ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:28 PM: debug ║║ Comparison (enum) on changes_to (string) on = true (1ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:28 PM: trace ║╔ Execution stage complete. (136ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:28 PM: debug ║║ Comparison (integer) 2 rises = false (1ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:28 PM: debug ║║ Calculating (integer) -90 > (integer) 100 >> (boolean) false
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:28 PM: debug ║║ Calculating (integer) -90 < (integer) 15 >> (boolean) true
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:28 PM: debug ║║ Calculating (decimal) 1.1427995E7 / (decimal) 60000.0 >> (decimal) 190.46658333333335
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:27 PM: debug ║║ Calculating (datetime) 1512187827980 < (datetime) 1512129960000 >> (boolean) false
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:27 PM: debug ║║ Cancelling statement #43’s schedules…
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:27 PM: trace ║ Runtime (49074 bytes) successfully initialized in 65ms (v0.2.0ff.20171129) (223ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:27 PM: debug ║ RunTime Analysis CS > 28ms > PS > 65ms > PE > 123ms > CE
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Condition #26 evaluated true (4ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Cancelling condition #26’s schedules…
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Condition group #6 evaluated true (state changed) (5ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Condition #20 evaluated false (3ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:25 PM: info ╔ Event processed successfully (1127ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Condition #69 evaluated false (7ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:25 PM: trace ║╔ Execution stage complete. (901ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Condition group #72 evaluated true (state changed) (9ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Condition #28 evaluated true (6ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Calculating (integer) -90 > (integer) 100 >> (boolean) false
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: trace ║║ Executed virtual command setVariable (2ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Cancelling statement #70’s schedules…
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Calculating (decimal) 100.0 - (decimal) 190.41418333333334 >> (decimal) -90.41418333333334
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Comparison (enum) active is (string) active = true (1ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Calculating (datetime) 1512129960000 - (datetime) 1512187824842 >> (datetime) -57864842
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Cancelling condition #6’s schedules…
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Comparison (integer) 2 is_greater_than (integer) 0 = true (1ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Condition group #17 evaluated false (state did not change) (4ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: trace ║ Runtime (49090 bytes) successfully initialized in 56ms (v0.2.0ff.20171129) (216ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Comparison (integer) 2 changes_to (integer) 0 = false (1ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║ RunTime Analysis CS > 26ms > PS > 56ms > PE > 127ms > CE
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Condition group #12 evaluated false (state did not change) (17ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: info ╚ Received event [Z-Wave Motion Sensor].motion = active with a delay of 168ms
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Condition #47 evaluated false (9ms)
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Calculating (integer) -90 < (integer) 15 >> (boolean) true
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Calculating (decimal) 1.1424851E7 / (decimal) 60000.0 >> (decimal) 190.41418333333334
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Calculating (datetime) 1512187824851 - (datetime) 1512176400000 >> (datetime) 11424851
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Calculating (decimal) 100.0 - (decimal) -964.4140333333334 >> (decimal) 1064.4140333333335
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Calculating (decimal) -5.7864842E7 / (decimal) 60000.0 >> (decimal) -964.4140333333334
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: debug ║║ Cancelling statement #43’s schedules…
1bc25c86-0b46-4bca-8e8a-092028d27f5a 11:10:24 PM: trace ║╚ Execution stage started

11:14:24 PM: debug Parsed SwitchMultilevelReport(value: 15) to [[‘name’:‘switch’, ‘value’:‘on’, ‘type’:‘digital’, ‘isStateChange’:false, ‘displayed’:false, ‘linkText’:‘Kitchen Lights’, ‘descriptionText’:Kitchen Lights switch is on], [‘name’:‘level’, ‘value’:15, ‘unit’:’%’, ‘type’:‘digital’, ‘isStateChange’:false, ‘displayed’:false, ‘linkText’:‘Kitchen Lights’, ‘descriptionText’:Kitchen Lights level is 15%]]
dc1e509f-f9fd-4e33-94b3-bc474ef991aa 11:14:24 PM: debug description: zw device: 07, command: 2603, payload: 0F
dc1e509f-f9fd-4e33-94b3-bc474ef991aa 11:10:26 PM: debug Parsed SwitchMultilevelReport(value: 15) to [[‘name’:‘switch’, ‘value’:‘on’, ‘type’:‘digital’, ‘isStateChange’:true, ‘displayed’:true, ‘linkText’:‘Kitchen Lights’, ‘descriptionText’:Kitchen Lights switch is on], [‘name’:‘level’, ‘value’:15, ‘unit’:’%’, ‘type’:‘digital’, ‘isStateChange’:false, ‘displayed’:false, ‘linkText’:‘Kitchen Lights’, ‘descriptionText’:Kitchen Lights level is 15%]]
dc1e509f-f9fd-4e33-94b3-bc474ef991aa 11:10:26 PM: debug description: zw device: 07, command: 2603, payload: 0F`

And the same events from webCoRE:

12/1/2017, 11:10:27 PM +706ms
+1ms ╔Received event [Kitchen Lights].switch = on with a delay of 1814ms
+215ms ║RunTime Analysis CS > 28ms > PS > 65ms > PE > 123ms > CE
+225ms ║Runtime (49074 bytes) successfully initialized in 65ms (v0.2.0ff.20171129) (223ms)
+226ms ║╔Execution stage started
+230ms ║║Cancelling statement #43’s schedules…
+277ms ║║Calculating (datetime) 1512187827980 < (datetime) 1512129960000 >> (boolean) false
+282ms ║║Calculating (datetime) 1512129960000 - (datetime) 1512187827986 >> (datetime) -57867986
+285ms ║║Calculating (decimal) -5.7867986E7 / (decimal) 60000.0 >> (decimal) -964.4664333333334
+287ms ║║Calculating (decimal) 100.0 - (decimal) -964.4664333333334 >> (decimal) 1064.4664333333335
+294ms ║║Calculating (datetime) 1512187827995 - (datetime) 1512176400000 >> (datetime) 11427995
+297ms ║║Calculating (decimal) 1.1427995E7 / (decimal) 60000.0 >> (decimal) 190.46658333333335
+299ms ║║Calculating (decimal) 100.0 - (decimal) 190.46658333333335 >> (decimal) -90.46658333333335
+305ms ║║Executed virtual command setVariable (3ms)
+312ms ║║Calculating (integer) -90 < (integer) 15 >> (boolean) true
+315ms ║║Calculating (integer) -90 > (integer) 100 >> (boolean) false
+319ms ║║Executed virtual command setVariable (2ms)
+323ms ║║Comparison (integer) 2 rises = false (1ms)
+324ms ║║Condition #47 evaluated false (3ms)
+327ms ║║Comparison (enum) on changes_to (string) on = true (1ms)
+328ms ║║Cancelling condition #69’s schedules…
+329ms ║║Condition #69 evaluated true (4ms)
+329ms ║║Cancelling condition #12’s schedules…
+330ms ║║Condition group #12 evaluated true (state changed) (9ms)
+332ms ║║Cancelling statement #13’s schedules…
+340ms ║║Skipped execution of physical command [Kitchen Lights].setLevel([15]) because it would make no change to the device. (4ms)
+340ms ║║Executed [Kitchen Lights].setLevel (4ms)
+346ms ║║Executed virtual command [Kitchen Lights].setVariable (4ms)
+350ms ║║Comparison (integer) 2 changes_to (integer) 0 = false (0ms)
+351ms ║║Condition #20 evaluated false (3ms)
+352ms ║║Condition group #17 evaluated false (state did not change) (4ms)
+360ms ║║Condition #39 evaluated false (3ms)
+360ms ║║Condition group #36 evaluated false (state did not change) (4ms)
+362ms ║╚Execution stage complete. (136ms)
+390ms ╚Event processed successfully (390ms)
12/1/2017, 11:10:24 PM +570ms
+1ms ╔Received event [Z-Wave Motion Sensor].motion = active with a delay of 168ms
+208ms ║RunTime Analysis CS > 26ms > PS > 56ms > PE > 127ms > CE
+218ms ║Runtime (49090 bytes) successfully initialized in 56ms (v0.2.0ff.20171129) (216ms)
+218ms ║╔Execution stage started
+222ms ║║Cancelling statement #43’s schedules…
+269ms ║║Calculating (datetime) 1512187824837 < (datetime) 1512129960000 >> (boolean) false
+274ms ║║Calculating (datetime) 1512129960000 - (datetime) 1512187824842 >> (datetime) -57864842
+277ms ║║Calculating (decimal) -5.7864842E7 / (decimal) 60000.0 >> (decimal) -964.4140333333334
+279ms ║║Calculating (decimal) 100.0 - (decimal) -964.4140333333334 >> (decimal) 1064.4140333333335
+285ms ║║Calculating (datetime) 1512187824851 - (datetime) 1512176400000 >> (datetime) 11424851
+288ms ║║Calculating (decimal) 1.1424851E7 / (decimal) 60000.0 >> (decimal) 190.41418333333334
+290ms ║║Calculating (decimal) 100.0 - (decimal) 190.41418333333334 >> (decimal) -90.41418333333334
+296ms ║║Executed virtual command setVariable (3ms)
+302ms ║║Calculating (integer) -90 < (integer) 15 >> (boolean) true
+305ms ║║Calculating (integer) -90 > (integer) 100 >> (boolean) false
+310ms ║║Executed virtual command setVariable (3ms)
+320ms ║║Comparison (integer) 2 rises = false (7ms)
+321ms ║║Condition #47 evaluated false (9ms)
+328ms ║║Condition #69 evaluated false (7ms)
+329ms ║║Condition group #12 evaluated false (state did not change) (17ms)
+333ms ║║Comparison (integer) 2 changes_to (integer) 0 = false (1ms)
+334ms ║║Condition #20 evaluated false (3ms)
+335ms ║║Condition group #17 evaluated false (state did not change) (4ms)
+340ms ║║Comparison (integer) 2 is_greater_than (integer) 0 = true (1ms)
+342ms ║║Condition #55 evaluated true (3ms)
+342ms ║║Cancelling condition #6’s schedules…
+343ms ║║Condition group #6 evaluated true (state changed) (5ms)
+347ms ║║Comparison (enum) active is (string) active = true (1ms)
+348ms ║║Cancelling condition #26’s schedules…
+348ms ║║Condition #26 evaluated true (4ms)
+349ms ║║Condition group #6 evaluated true (state did not change) (5ms)
+351ms ║║Cancelling statement #70’s schedules…
+356ms ║║Executed virtual command setVariable (2ms)
+363ms ║║Comparison (enum) off is (string) off = true (1ms)
+364ms ║║Cancelling condition #28’s schedules…
+364ms ║║Condition #28 evaluated true (6ms)
+365ms ║║Cancelling condition #72’s schedules…
+366ms ║║Condition group #72 evaluated true (state changed) (9ms)
+368ms ║║Cancelling statement #7’s schedules…
+1109ms ║║Executed physical command [Kitchen Lights].setLevel([15]) (739ms)
+1110ms ║║Executed [Kitchen Lights].setLevel (739ms)
+1116ms ║║Condition #39 evaluated false (3ms)
+1117ms ║║Condition group #36 evaluated false (state did not change) (5ms)
+1119ms ║╚Execution stage complete. (901ms)
+1128ms ╚Event processed successfully (1127ms)
.


#2

Is physical / not physical depends on the device / handler, unfortunately most devices / handlers do not report the required info.

Despite numerous attempts at tweaking code, I’ve never got it working on any of my devices.


#3

There is a bug in webcore in regards to this also that should be fixed soon.