Piston to manage Blue Iris profiles stopped working yesterday


#1

1) Give a description of the problem
About a month ago I created a piston that changes the active profile in Blue Iris (BI) whenever a location mode change occurs. It was working perfectly until yesterday when I noticed that the profile didn’t change when I arrived home. I did some testing today and realize it no longer works. No recent changes were made to the piston or BI. If I format the command used to change the profile and execute it from a browser, it works. I’ve tried a number of things but cannot get this piston to work again. There is nothing in the log that indicates there is a problem. Or if there is, I’m not seeing it. I’m out of ideas as to how to troubleshoot this one.

2) What is the expected behavior?
A location changes intitiates a web request to BI to change the active profile.

3) What is happening/not happening?
This piston worked perfectly until yesterday. Now it issues the web request but Blue Iris does nothing. The same request issued from a browser works fine.

4) Post a Green Snapshot of the pistonimage

*5) Attach any logs (From ST IDE and by turning logging level to Full)

The logs below show a change from home to away and another change from away to home.

1/19/2018, 4:47:06 PM +372ms
+1ms ╔Received event [Home].time = 1516405627587 with a delay of -1215ms
+187ms ║RunTime Analysis CS > 34ms > PS > 58ms > PE > 94ms > CE
+190ms ║Runtime (52180 bytes) successfully initialized in 58ms (v0.2.102.20180116) (189ms)
+191ms ║╔Execution stage started
+233ms ║║Comparison (string) :fd6b2fd9366cdca291a786245b40fcf7: changes_to (string) :4f87089617dfb9cee9d4ec80da10baf8: = false (8ms)
+235ms ║║Condition #57 evaluated false (14ms)
+236ms ║║Condition group #53 evaluated false (state did not change) (15ms)
+238ms ║╚Execution stage complete. (48ms)
+239ms ╚Event processed successfully (239ms)
1/19/2018, 4:46:45 PM +333ms
+0ms ╔Received event [Home].time = 1516405606510 with a delay of -1178ms
+138ms ║RunTime Analysis CS > 16ms > PS > 40ms > PE > 82ms > CE
+141ms ║Runtime (52180 bytes) successfully initialized in 40ms (v0.2.102.20180116) (140ms)
+142ms ║╔Execution stage started
+176ms ║║Executed virtual command executePiston (6ms)
+179ms ║║Executed virtual command wait (1ms)
+180ms ║║Waiting for 2000ms
+2216ms ║║Calculating (string) 192.168.1.164 + (string) : >> (string) 192.168.1.164:
+2221ms ║║Calculating (string) 192.168.1.164: + (string) 50081 >> (string) 192.168.1.nn:nnnnn
+2226ms ║║Calculating (string) 192.168.1.nn:nnnnn + (string) /admin?profile= >> (string) 192.168.1.nn:nnnnn/admin?profile=
+2230ms ║║Calculating (string) 192.168.1.nn:nnnnn/admin?profile= + (string) 1 >> (string) 192.168.1.nn:nnnnn/admin?profile=1
+2234ms ║║Calculating (string) 192.168.1.nn:nnnnn/admin?profile=1 + (string) &user= >> (string) 192.168.1.nn:nnnnn/admin?profile=1&user=
+2237ms ║║Calculating (string) 192.168.1.nn:nnnnn/admin?profile=1&user= + (string) UserID >> (string) 192.168.1.nn:nnnnn/admin?profile=1&user=UserID
+2240ms ║║Calculating (string) 192.168.1.nn:nnnnn/admin?profile=1&user=UserID + (string) &pw= >> (string) 192.168.1.nn:nnnnn/admin?profile=1&user=UserID&pw=
+2243ms ║║Calculating (string) 192.168.1.nn:nnnnn/admin?profile=1&user=UserID&pw= + (string) Password >> (string) 192.168.1.nn:nnnnn/admin?profile=1&user=UserID&pw=Password
+2250ms ║║Sending internal web request to: 192.168.1.nn:nnnnn/admin?profile=1&user=UserID&pw=Password
+2252ms ║║Executed virtual command httpRequest (3ms)
+2253ms ║║Requesting a wake up for Fri, Jan 19 2018 @ 4:47:07 PM MST (in 20.0s)
+2258ms ║╚Execution stage complete. (2115ms)
+2259ms ║Setting up scheduled job for Fri, Jan 19 2018 @ 4:47:07 PM MST (in 19.995s)
+2301ms ╚Event processed successfully (2302ms)
1/19/2018, 4:45:16 PM +245ms
+0ms ╔Received event [Home].mode = Home with a delay of 131ms
+215ms ║RunTime Analysis CS > 35ms > PS > 60ms > PE > 120ms > CE
+219ms ║Runtime (52173 bytes) successfully initialized in 60ms (v0.2.102.20180116) (218ms)
+221ms ║╔Execution stage started
+234ms ║║Comparison (string) :fd6b2fd9366cdca291a786245b40fcf7: changes_to (string) :9984339f75f446f9c06978e611709967: = false (0ms)
+236ms ║║Cancelling condition #38’s schedules…
+237ms ║║Condition #38 evaluated false (8ms)
+239ms ║║Cancelling condition #19’s schedules…
+240ms ║║Condition group #19 evaluated false (state changed) (11ms)
+248ms ║║Comparison (string) :fd6b2fd9366cdca291a786245b40fcf7: changes_to (string) :fd6b2fd9366cdca291a786245b40fcf7: = true (1ms)
+250ms ║║Cancelling condition #49’s schedules…
+252ms ║║Condition #49 evaluated true (7ms)
+253ms ║║Cancelling condition #39’s schedules…
+254ms ║║Condition group #39 evaluated true (state changed) (10ms)
+258ms ║║Cancelling statement #50’s schedules…
+263ms ║║Executed virtual command wait (0ms)
+264ms ║║Requesting a wake up for Fri, Jan 19 2018 @ 4:46:46 PM MST (in 90.0s)
+271ms ║╚Execution stage complete. (51ms)
+273ms ║Setting up scheduled job for Fri, Jan 19 2018 @ 4:46:46 PM MST (in 89.993s)
+440ms ╚Event processed successfully (440ms)
1/19/2018, 4:44:19 PM +324ms
+1ms ╔Received event [Home].time = 1516405460785 with a delay of -1461ms
+173ms ║RunTime Analysis CS > 21ms > PS > 58ms > PE > 89ms > CE
+176ms ║Runtime (52180 bytes) successfully initialized in 58ms (v0.2.102.20180116) (175ms)
+177ms ║╔Execution stage started
+201ms ║║Comparison (string) :9984339f75f446f9c06978e611709967: changes_to (string) :fd6b2fd9366cdca291a786245b40fcf7: = false (4ms)
+203ms ║║Condition #49 evaluated false (8ms)
+204ms ║║Condition group #39 evaluated false (state did not change) (9ms)
+210ms ║║Comparison (string) :9984339f75f446f9c06978e611709967: changes_to (string) :4f87089617dfb9cee9d4ec80da10baf8: = false (1ms)
+212ms ║║Condition #57 evaluated false (4ms)
+213ms ║║Condition group #53 evaluated false (state did not change) (5ms)
+215ms ║╚Execution stage complete. (38ms)
+216ms ╚Event processed successfully (216ms)
1/19/2018, 4:43:58 PM +474ms
+0ms ╔Received event [Home].mode = Away with a delay of 130ms
+167ms ║RunTime Analysis CS > 33ms > PS > 53ms > PE > 82ms > CE
+171ms ║Runtime (52173 bytes) successfully initialized in 53ms (v0.2.102.20180116) (169ms)
+172ms ║╔Execution stage started
+181ms ║║Comparison (string) :9984339f75f446f9c06978e611709967: changes_to (string) :9984339f75f446f9c06978e611709967: = true (0ms)
+183ms ║║Cancelling condition #38’s schedules…
+184ms ║║Condition #38 evaluated true (6ms)
+185ms ║║Cancelling condition #19’s schedules…
+186ms ║║Condition group #19 evaluated true (state changed) (8ms)
+228ms ║║Comparison (time) 60238663 is_between (time) 1516371420000 … (time) 1516406640000 = true (10ms)
+229ms ║║Time restriction check passed
+231ms ║║Condition #37 evaluated true (43ms)
+232ms ║║Condition group #30 evaluated true (state did not change) (44ms)
+234ms ║║Cancelling statement #35’s schedules…
+247ms ║║Executed virtual command executePiston (7ms)
+251ms ║║Executed virtual command wait (1ms)
+252ms ║║Waiting for 2000ms
+2274ms ║║Calculating (string) 192.168.1.164 + (string) : >> (string) 192.168.1.164:
+2278ms ║║Calculating (string) 192.168.1.164: + (string) 50081 >> (string) 192.168.1.nn:nnnnn
+2282ms ║║Calculating (string) 192.168.1.nn:nnnnn + (string) /admin?profile= >> (string) 192.168.1.nn:nnnnn/admin?profile=
+2286ms ║║Calculating (string) 192.168.1.nn:nnnnn/admin?profile= + (string) 3 >> (string) 192.168.1.nn:nnnnn/admin?profile=3
+2291ms ║║Calculating (string) 192.168.1.nn:nnnnn/admin?profile=3 + (string) &user= >> (string) 192.168.1.nn:nnnnn/admin?profile=3&user=
+2294ms ║║Calculating (string) 192.168.1.nn:nnnnn/admin?profile=3&user= + (string) UserID >> (string) 192.168.1.nn:nnnnn/admin?profile=3&user=UserID
+2297ms ║║Calculating (string) 192.168.1.nn:nnnnn/admin?profile=3&user=UserID + (string) &pw= >> (string) 192.168.1.nn:nnnnn/admin?profile=3&user=UserID&pw=
+2300ms ║║Calculating (string) 192.168.1.nn:nnnnn/admin?profile=3&user=UserID&pw= + (string) Password >> (string) 192.168.1.nn:nnnnn/admin?profile=3&user=UserID&pw=Password
+2307ms ║║Sending internal web request to: 192.168.1.nn:nnnnn/admin?profile=3&user=UserID&pw=Password
+2309ms ║║Executed virtual command httpRequest (3ms)
+2310ms ║║Requesting a wake up for Fri, Jan 19 2018 @ 4:44:20 PM MST (in 20.0s)
+2316ms ║╚Execution stage complete. (2145ms)
+2318ms ║Setting up scheduled job for Fri, Jan 19 2018 @ 4:44:20 PM MST (in 19.994s)
+2329ms ╚Event processed successfully (2329ms)


#2

Check the URL is working by testing it in a web browser running on the same network.

If it doesent work in a browser, perhaps check to see if the local IP for your BI server has changed… rebooting a router can cause all your LAN IP addresses to get reassigned.

I use the WAN IP for BI but I see you are using the LAN IP… but that shouldn’t matter.


#3

Executing the command from a web browser works and the specified profile becomes active. And to add to the mystery, the command to change to a night profile failed last night so I manually made the change. But the command to change to a day profile was sent and successfully executed at sunset today. I suspect it’s not WebCoRE but something with BI but I have no idea what might have changed. I’m going to keep an eye on things and see if I can spot a pattern.


#4

There have been several posts relating to HTTP issues lately so maybe something bigger going on, including issues that I’m having taking snapshots with BI, but I can change BI modes OK…

Tagging @ipaterson @ady624