Piston is firing.... but not, Help needed :)

#1

Hi everyone! Hoping you can help me track down this issue. I have two really simple pistons that are to turn on my lights and change my thermostat when my presence sensor changes to present. It works randomly, as in it will be fine for a day or two and than just stops (It did work find the day after the hub update). So i went into webcore to check the piston and it says that it was last executed at the correct time. I next went to my devices and checked the lights and they do show that they seem to get the command to turn them on and set the level but that is not what is happening. The next log event is that lights are off. as you can see from the log below.

Date Source Type Name Value User Displayed Text
2017-11-19 1:02:52.661 PM PST
10 minutes ago DEVICE switch off Front light switch is off
2017-11-19 1:02:40.546 PM PST
10 minutes ago APP_COMMAND setLevel Come home lights sent setLevel command to Front light
2017-11-19 1:02:40.501 PM PST
10 minutes ago APP_COMMAND on Come home lights sent on command to Front light
2017-11-19 1:02:40.024 PM PST
10 minutes ago DEVICE switch on Front light switch is on
2017-11-18 9:47:15.814 PM PST
15 hours ago DEVICE switch off Front light switch is off

Anyone have any idea what I can do to try and fix this issue? I get the same thing for my thermostat as well (says it is doing what the piston state but actually doesn’t). Really appreciate it everyone!

#2

Can I suggest you post a screenshot of your piston here.
Without it, it is difficult tom advise.

#3

No problem, im not too sure it has anything to do with the piston but maybe the ST hub?

light
light.png1178×512 52.2 KB

#4

I’d be surprised if it is the hub.
But anyway.
Are you sure you don’t have another piston interacting with this as it looks reasonable to me.
Turn logging on to full and then post the logs. It will give a better idea as to what the piston is doing.

#5

What if you temporarily take out the line about adjust to100%?

#6

Good point @rudyinDana
Maybe just have …
Set Level to 100%
This will turn the light on to 100%.
With dimmers if you have turn on, it will turn it on to the last known level. I you use just Set Level 80% it will turn it on to 80%.

#7

ok here is the logs…
+1ms ╔Received event [Chris’s iPhone].presence = present with a delay of 102ms
+93ms ║RunTime Analysis CS > 20ms > PS > 50ms > PE > 24ms > CE
+102ms ║Runtime (37661 bytes) successfully initialized in 50ms (v0.2.0fe.20171109) (100ms)
+103ms ║╔Execution stage started
+175ms ║║Comparison (enum) not present is_not (string) present = true (1ms)
+176ms ║║Condition #6 evaluated true (67ms)
+177ms ║║Cancelling condition #1’s schedules…
+177ms ║║Condition group #1 evaluated true (state changed) (68ms)
+184ms ║║Comparison (enum) present changes_to (string) present = true (0ms)
+185ms ║║Cancelling condition #4’s schedules…
+186ms ║║Condition #4 evaluated true (7ms)
+187ms ║║Condition group #1 evaluated true (state did not change) (8ms)
+189ms ║║Cancelling statement #2’s schedules…
+195ms ║║Skipped execution of physical command [Back light].on([]) because it would make no change to the device. (2ms)
+196ms ║║Executed [Back light].on (4ms)
+209ms ║║Executed physical command [Front light].on() (11ms)
+210ms ║║Executed [Front light].on (12ms)
+215ms ║║Skipped execution of physical command [Kitchen 1].on([]) because it would make no change to the device. (2ms)
+216ms ║║Executed [Kitchen 1].on (4ms)
+221ms ║║Skipped execution of physical command [Kitchen 2].on([]) because it would make no change to the device. (3ms)
+222ms ║║Executed [Kitchen 2].on (4ms)
+228ms ║║Skipped execution of physical command [Kitchen 3].on([]) because it would make no change to the device. (3ms)
+228ms ║║Executed [Kitchen 3].on (4ms)
+233ms ║║Skipped execution of physical command [Kitchen 4].on([]) because it would make no change to the device. (2ms)
+234ms ║║Executed [Kitchen 4].on (3ms)
+245ms ║║Skipped execution of physical command [Back light].setLevel([100]) because it would make no change to the device. (5ms)
+246ms ║║Executed virtual command [Back light].adjustLevel (10ms)
+259ms ║║Executed physical command [Front light].setLevel([100]) (9ms)
+260ms ║║Executed virtual command [Front light].adjustLevel (13ms)
+268ms ║║Skipped execution of physical command [Kitchen 1].setLevel([100]) because it would make no change to the device. (5ms)
+269ms ║║Executed virtual command [Kitchen 1].adjustLevel (8ms)
+278ms ║║Skipped execution of physical command [Kitchen 2].setLevel([100]) because it would make no change to the device. (4ms)
+279ms ║║Executed virtual command [Kitchen 2].adjustLevel (9ms)
+288ms ║║Skipped execution of physical command [Kitchen 3].setLevel([100]) because it would make no change to the device. (5ms)
+289ms ║║Executed virtual command [Kitchen 3].adjustLevel (10ms)
+300ms ║║Skipped execution of physical command [Kitchen 4].setLevel([100]) because it would make no change to the device. (7ms)
+301ms ║║Executed virtual command [Kitchen 4].adjustLevel (11ms)
+303ms ║╚Execution stage complete. (200ms)
+311ms ╚Event processed successfully (312ms)
11/19/2017, 2:45:29 PM +274ms
+1ms ╔Received event [Chris’s iPhone].presence = not present with a delay of 68ms
+60ms ║RunTime Analysis CS > 11ms > PS > 32ms > PE > 18ms > CE
+67ms ║Runtime (37655 bytes) successfully initialized in 32ms (v0.2.0fe.20171109) (66ms)
+68ms ║╔Execution stage started
+79ms ║║Comparison (enum) not present is_not (string) present = true (1ms)
+80ms ║║Condition #6 evaluated true (7ms)
+81ms ║║Condition group #1 evaluated true (state did not change) (9ms)
+85ms ║║Comparison (enum) not present changes_to (string) present = false (1ms)
+86ms ║║Cancelling condition #4’s schedules…
+87ms ║║Condition #4 evaluated false (5ms)
+88ms ║║Cancelling condition #1’s schedules…
+88ms ║║Condition group #1 evaluated false (state changed) (6ms)
+90ms ║╚Execution stage complete. (22ms)
+96ms ╚Event processed successfully (96ms)

#8

ill give that a try and see if that fixes the issue, thanks!

#9

Looking at your logs, there is nothing in there turning the lights off.
I’m assuming your lights were already on from the logs because it says ‘Skipped execution set level 100 because it will make no difference’.
Were they already on?

#10

no, they are off, thats why I’m confused. I took out turn on and will go test them right now (take the pup for a walk real quick) and I will report back.

#11

OK. To force the commands to run you can turn off command optimisation.
When you have the piston in edit mode, click on the piston title at the very top.
Now click on the settings cog.
Now turn off command optimisation.
This will mean that all commands will now run. It will not check the state of a device before sending a command to it, It will always send it regardless of the device state,

Piston did work
#12

New logs, kitchen lights worked fine, back light turned on but to maybe 30% and the front light did not turn on at all… I will try your most recent suggestion, also, the thermostat turned on however instead of setting 74 it went to 73… so confused haha,

11/19/2017, 3:09:20 PM +949ms
+2ms ╔Received event [Chris’s iPhone].presence = present with a delay of 77ms
+81ms ║RunTime Analysis CS > 14ms > PS > 44ms > PE > 22ms > CE
+89ms ║Runtime (37641 bytes) successfully initialized in 44ms (v0.2.0fe.20171109) (87ms)
+90ms ║╔Execution stage started
+103ms ║║Comparison (enum) not present is_not (string) present = true (2ms)
+104ms ║║Condition #6 evaluated true (8ms)
+105ms ║║Cancelling condition #1’s schedules…
+106ms ║║Condition group #1 evaluated true (state changed) (11ms)
+112ms ║║Comparison (enum) present changes_to (string) present = true (1ms)
+113ms ║║Cancelling condition #4’s schedules…
+114ms ║║Condition #4 evaluated true (7ms)
+115ms ║║Condition group #1 evaluated true (state did not change) (8ms)
+117ms ║║Cancelling statement #2’s schedules…
+147ms ║║Executed physical command [Back light].setLevel([100]) (23ms)
+148ms ║║Executed virtual command [Back light].adjustLevel (26ms)
+167ms ║║Executed physical command [Front light].setLevel([100]) (14ms)
+168ms ║║Executed virtual command [Front light].adjustLevel (18ms)
+184ms ║║Executed physical command [Kitchen 1].setLevel([100]) (11ms)
+185ms ║║Executed virtual command [Kitchen 1].adjustLevel (15ms)
+203ms ║║Executed physical command [Kitchen 2].setLevel([100]) (12ms)
+203ms ║║Executed virtual command [Kitchen 2].adjustLevel (16ms)
+219ms ║║Executed physical command [Kitchen 3].setLevel([100]) (11ms)
+220ms ║║Executed virtual command [Kitchen 3].adjustLevel (15ms)
+237ms ║║Executed physical command [Kitchen 4].setLevel([100]) (11ms)
+237ms ║║Executed virtual command [Kitchen 4].adjustLevel (15ms)
+240ms ║╚Execution stage complete. (150ms)
+247ms ╚Event processed successfully (247ms)
11/19/2017, 3:07:01 PM +59ms
+1ms ╔Received event [Chris’s iPhone].presence = not present with a delay of 67ms
+80ms ║RunTime Analysis CS > 10ms > PS > 35ms > PE > 35ms > CE
+88ms ║Runtime (37638 bytes) successfully initialized in 35ms (v0.2.0fe.20171109) (85ms)
+88ms ║╔Execution stage started
+99ms ║║Comparison (enum) not present is_not (string) present = true (1ms)
+101ms ║║Condition #6 evaluated true (7ms)
+101ms ║║Cancelling condition #1’s schedules…
+102ms ║║Condition group #1 evaluated true (state changed) (9ms)
+106ms ║║Comparison (enum) not present changes_to (string) present = false (0ms)
+107ms ║║Condition #4 evaluated false (4ms)
+108ms ║║Cancelling condition #1’s schedules…
+109ms ║║Condition group #1 evaluated false (state changed) (6ms)
+111ms ║╚Execution stage complete. (23ms)
+117ms ╚Event processed successfully (117ms)

#14

this time all the lights worked out perfect! all on and set to 100%. All the lights are all hue bulbs. So I think that might be fixed, however the thermostat, really confuses me. I have it set to 74, and it says it setting it to 74… but its only going to 73… really weird. I have another piston that sets to 70 when I leave and that works perfect every time, but setting to 74 only gets me to 73 (I dont have any conflicting pistons)
logs:

11/19/2017, 3:29:14 PM +843ms
+1ms ╔Received event [Chris’s iPhone].presence = present with a delay of 85ms
+101ms ║RunTime Analysis CS > 22ms > PS > 56ms > PE > 23ms > CE
+231ms ║Runtime (37279 bytes) successfully initialized in 56ms (v0.2.0fe.20171109) (229ms)
+232ms ║╔Execution stage started
+248ms ║║Comparison (enum) not present is_not (string) present = true (2ms)
+249ms ║║Condition #9 evaluated true (10ms)
+251ms ║║Cancelling condition #1’s schedules…
+251ms ║║Condition group #1 evaluated true (state changed) (12ms)
+258ms ║║Comparison (enum) present changes_to (string) present = true (1ms)
+260ms ║║Cancelling condition #8’s schedules…
+261ms ║║Condition #8 evaluated true (8ms)
+262ms ║║Condition group #1 evaluated true (state did not change) (9ms)
+264ms ║║Cancelling statement #5’s schedules…
+295ms ║║Executed physical command [Thermostat].setHeatingSetpoint([74.0]) (26ms)
+296ms ║║Executed [Thermostat].setHeatingSetpoint (28ms)
+405ms ║║Executed physical command [Thermostat].setCoolingSetpoint([76.0]) (106ms)
+406ms ║║Executed [Thermostat].setCoolingSetpoint (108ms)
+409ms ║╚Execution stage complete. (177ms)
+417ms ╚Event processed successfully (418ms)

btw thank you everyone appreciate all the help!

#15

Lazy me would say, tell the thermostat to go to 75 and if it goes to 74, tell everyone how you outsmarted the stupid thermostat. That’s just me of course.

Seriously though, and this will seem silly, is to set the thermostat after a 1 second (or more) wait.

Couldn’t hurt.

#16

haha right! thats what I was thinking. Im not sure if this has anything to do with it, but I had it set to 73 but that was too low, so I edited the value saved it and now I only get 73, so for this one I am not sure if there is something funky going on. Ill try to set to 75 and see if I still get 73 or 74 :grinning:

#17

So, after two days of working fine, now its not working again!

download
download.png1178×563 55.4 KB

I have full trace on and here is the log:
11/21/2017, 1:18:11 PM +471ms
+2ms ╔Received event [Chris’s iPhone].presence = present with a delay of 104ms
+89ms ║RunTime Analysis CS > 20ms > PS > 43ms > PE > 25ms > CE
+97ms ║Runtime (37631 bytes) successfully initialized in 43ms (v0.2.0fe.20171109) (95ms)
+97ms ║╔Execution stage started
+110ms ║║Comparison (enum) not present is_not (string) present = true (1ms)
+111ms ║║Cancelling condition #6’s schedules…
+112ms ║║Condition #6 evaluated true (10ms)
+113ms ║║Cancelling condition #1’s schedules…
+113ms ║║Condition group #1 evaluated true (state changed) (11ms)
+118ms ║║Comparison (enum) present changes_to (string) present = false (0ms)
+119ms ║║Cancelling condition #4’s schedules…
+120ms ║║Condition #4 evaluated false (6ms)
+120ms ║║Cancelling condition #1’s schedules…
+121ms ║║Condition group #1 evaluated false (state changed) (7ms)
+123ms ║╚Execution stage complete. (25ms)
+205ms ╚Event processed successfully (205ms)

I have not changed the system in any way… Any ideas?

#18

I have no idea if it will help but I would insert a wait before the with command.

Bear in mind real programmers laugh and/or throw things at my amateurish methods.

#19

well I have no idea what I am doing so I guess I think like you. I cloned my piston, paused the original, renamed the new one and know it is working (both for my lights and for my thermostat), there must be some disconnect happening between ST and webcore after x amount of time…