Get request no longer working

[Adam_Smith]

1) Give a description of the problem
My http get request no longer seems to be returning date

2) What is the expected behaviour?
Simple json data is pulled

3) What is happening/not happening?
$response seems blank

**4) Post a Green Snapshot of the piston!

5) Attach logs after turning logging level to Full
(PASTE YOUR LOGS HERE THEN HIGHLIGHT ALL OF THE LOGS AND CLICK ON THE </> ICON TO FORMAT THEM CORRECTLY) end execute;

Logs

3/26/2021, 2:10:12 PM +875ms
+0ms ╔Starting piston… (v0.3.113.20210203)
+5263ms ║╔Subscribing to devices…
+5332ms ║║Subscribing to PoolLC…
+5333ms ║╚Finished subscribing (78ms)
+5380ms ║Comparison (dynamic) is (integer) 1 = false (2ms)
+5385ms ║Comparison (dynamic) 0 is (integer) 0 = true (1ms)
+5394ms ║Comparison (dynamic) is (integer) 0 = false (1ms)
+5408ms ║Calculating (decimal) 0.0 - (decimal) 1.0 >> (decimal) -1.0
+5411ms ║Calculating (decimal) 1.885314982E9 * (decimal) -1.0 >> (decimal) -1.885314982E9
+5415ms ║Comparison (integer) 0 is_less_than_or_equal_to (decimal) -1.885314982E9 = false (1ms)
+5420ms ║Setting up scheduled job for Fri, Mar 26 2021 @ 2:15:18 PM MST (in 299s)
+5434ms ╚Piston successfully started (5434ms)
3/26/2021, 2:06:34 PM +53ms
+1ms ╔Received event [Home].time = 1616792794172 with a delay of -119ms
+10211ms ║RunTime Analysis CS > 24ms > PS > 10140ms > PE > 47ms > CE
+10212ms ║Piston waited at a semaphore for 10135ms
+10215ms ║Runtime (43761 bytes) successfully initialized in 10140ms (v0.3.113.20210203) (10212ms)
+10216ms ║╔Execution stage started
+10216ms ║╚Execution stage complete. (1ms)
+10218ms ║Setting up scheduled job for Fri, Mar 26 2021 @ 2:11:11 PM MST (in 266s)
+10227ms ╚Event processed successfully (10227ms)
3/26/2021, 2:06:34 PM +52ms
+1ms ╔Received event [Home].time = 1616792794172 with a delay of -120ms
+74ms ║RunTime Analysis CS > 20ms > PS > 5ms > PE > 48ms > CE
+76ms ║Runtime (43678 bytes) successfully initialized in 5ms (v0.3.113.20210203) (74ms)
+77ms ║╔Execution stage started
+87ms ║║Executed virtual command setVariable (0ms)
+96ms ║║Calculating (integer) 0 - (integer) 2 >> (integer) -2
+98ms ║║Executed virtual command setVariable (0ms)
+104ms ║║Executed virtual command setVariable (3ms)
+109ms ║║Executed virtual command setVariable (2ms)
+118ms ║║Calculating (integer) 0 - (integer) 2 >> (integer) -2
+123ms ║║Executed virtual command setVariable (2ms)
+125ms ║║Cancelling statement #8’s schedules…
+260ms ║║Executed physical command [PoolLC].changeTemperature([]) (131ms)
+261ms ║║Executed [PoolLC].changeTemperature (133ms)
+266ms ║║Comparison (dynamic) is (integer) 1 = false (1ms)
+268ms ║║Condition #13 evaluated false (4ms)
+269ms ║║Condition group #12 evaluated false (state did not change) (5ms)
+272ms ║║Comparison (dynamic) is (integer) 0 = false (1ms)
+274ms ║║Condition #19 evaluated false (4ms)
+275ms ║║Condition group #18 evaluated false (state did not change) (5ms)
+284ms ║║Calculating (decimal) 0.0 - (decimal) 1.0 >> (decimal) -1.0
+286ms ║║Calculating (decimal) 1.885091036E9 * (decimal) -1.0 >> (decimal) -1.885091036E9
+289ms ║║Comparison (integer) 0 is_less_than_or_equal_to (decimal) -1.885091036E9 = false (1ms)
+290ms ║║Condition #25 evaluated false (13ms)
+291ms ║║Condition group #24 evaluated false (state did not change) (14ms)
+300ms ║╚Execution stage complete. (223ms)
+301ms ║Setting up scheduled job for Fri, Mar 26 2021 @ 2:11:11 PM MST (in 276s)
+308ms ╚Event processed successfully (308ms)
3/26/2021, 2:06:13 PM +46ms
+1ms ╔Received event [Home].time = 1616792771172 with a delay of 1874ms
+65ms ║RunTime Analysis CS > 16ms > PS > 6ms > PE > 42ms > CE
+67ms ║Runtime (43678 bytes) successfully initialized in 6ms (v0.3.113.20210203) (65ms)
+68ms ║╔Execution stage started
+70ms ║╚Execution stage complete. (1ms)
+71ms ║Setting up scheduled job for Fri, Mar 26 2021 @ 2:06:34 PM MST (in 21s), with 1 more job pending
+77ms ╚Event processed successfully (77ms)
3/26/2021, 2:06:10 PM +267ms
+0ms ╔Received event [Home].wc_async_reply = httpRequest with a delay of 0ms
+64ms ║RunTime Analysis CS > 16ms > PS > 5ms > PE > 44ms > CE
+67ms ║Runtime (43683 bytes) successfully initialized in 5ms (v0.3.113.20210203) (66ms)
+68ms ║╔Execution stage started
+69ms ║╚Execution stage complete. (1ms)
+70ms ║Setting up scheduled job for Fri, Mar 26 2021 @ 2:06:11 PM MST (in 1s)
+79ms ╚Event processed successfully (79ms)
3/26/2021, 2:06:10 PM +52ms
+1ms ╔Received event [Home].time = 1616792771172 with a delay of -1120ms
+69ms ║RunTime Analysis CS > 23ms > PS > 6ms > PE > 39ms > CE
+72ms ║Runtime (43679 bytes) successfully initialized in 6ms (v0.3.113.20210203) (69ms)
+73ms ║╔Execution stage started
+82ms ║║Cancelling statement #7’s schedules…
+89ms ║║Sending external web request to: lacrossealertsmobile.com/laxservices/device_info.php?&limit=1&timezone=8&metric=0&deviceid=0001B17707252703
+118ms ║║Executed virtual command httpRequest (30ms)
+119ms ║║Requesting a wake up for Fri, Mar 26 2021 @ 2:06:34 PM MST (in 24.0s)
+124ms ║╚Execution stage complete. (52ms)
+126ms ║Setting up scheduled job for Fri, Mar 26 2021 @ 2:06:34 PM MST (in 23s), with 1 more job pending
+133ms ╚Event processed successfully (133ms<>

[orangebucket]

It seems like a very confused piston to me. It doesn’t seem to know what to do with the asynchronous HTTP reply when it gets it and later continues the piston after the HTTP timeout.

I don’t know if anyone has had much joy with http requests in timer blocks since webCoRE was switched to asynchronous HTTP, something I wish hadn’t happened.

[Adam_Smith]

I should clarify, the piston has worked fine for quite some time, basically gets the pool temp from a lacrosse sensor and shoves it into a tile for action tiles. Some of the additional items are to warn me when its low battery or stops responding, but its actually quite simple. Its only stopped working a few days ago.

[Adam_Smith]

So, if I understand, when it was synchronous it sent the GET, waited for a response then continued to parse the results.

Since the change, its almost like its sending the GET, but moving on to parsing the data before the response variable is filled? Is there a way to make it wait?

[orangebucket]

If it has worked until a few days ago that suggests it can work OK unless you’ve just updated webCoRE.

It just looks very confused.

• A timer fires a second early and a GET request is made with a timeout of 24 seconds.
• The response is received but ignored and the timer seemingly reset for a second’s time.
• That timer fires a second late but is ignored and the HTTP wake up scheduled again
• The wakeup happens and the piston continues but presumably doesn’t have the response data or something. The next five minute timer is scheduled.
• The wakeup happens again and hits a ten second wait before doing nothing. The timer is scheduled again.
• The piston is restarted before we discover if there are now two timers.

It is difficult to know what went wrong there.

[Adam_Smith]

Yes the log is confusing, it never used to be broken up like that.

What I did was put the GET request and setting of global variables from response into one piston, then the piston that runs every 5min and does the logic calls it. It seems to work that way.

[guxdude]

@Adam_Smith, I had this same problem recently. Seems the latest webcore release has a problem following redirects. See this post for interim fix:

Large web request responses error out if response is slow

Versions 0.3.111 through 0.3.113 will not follow redirects. Still working through a lot of surprises like that for the next release but for now you would need to use v0.3.110.20191009. You can grab the code for each of the four smart apps here just click “Raw” to get an easy-to-copy version of each file.

[Bluecarbon7]

I saw the same issue, with get requests to Weatherflow and some (but not all) other data sources failing after the upgrade. I’ve reverted to 3.110 and all is good again.
Thanks for the pointers on this thread !