Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix ESP32 webquery response #20111

Merged
merged 4 commits into from
Nov 27, 2023

Conversation

barbudor
Copy link
Contributor

Description:

Related issue (if applicable): fixes #20102

Creating a copy of the response seems to solve the problem

Checklist:

  • The pull request is done against the latest development branch
  • Only relevant files were touched
  • Only one feature/fix was added per PR and the code change compiles without warnings
  • The code change is tested and works with Tasmota core ESP8266 V.2.7.4.9
  • The code change is tested and works with Tasmota core ESP32 V.2.0.14
  • I accept the CLA.

NOTE: The code change must pass CI tests. Your PR cannot be merged unless tests pass

@barbudor
Copy link
Contributor Author

barbudor commented Nov 26, 2023

Stil there is something wrong
My Rule2 doesn't get triggered while it was working in the past:

23:42:31.930 CMD: rule0
23:42:31.932 SRC: WebConsole from 0.0.0.0
23:42:31.934 CMD: Grp 0, Cmd 'RULE', Idx 0, Len 0, Pld -99, Data ''
23:42:31.942 MQT: stat/esp32dev3/RULE = {"Rule1":{"State":"ON","Once":"OFF","StopOnError":"OFF","Length":71,"Free":440,"Rules":"on tele-Time do webquery http://192.168.168.244/myip.php?json GET endon"}}
23:42:31.954 MQT: stat/esp32dev3/RULE = {"Rule2":{"State":"ON","Once":"OFF","StopOnError":"OFF","Length":34,"Free":477,"Rules":"on myip#data do var1 %value% endon"}}
23:42:31.965 MQT: stat/esp32dev3/RULE = {"Rule3":{"State":"OFF","Once":"OFF","StopOnError":"OFF","Length":0,"Free":511,"Rules":""}}
23:42:40.886 BRY: GC from 4236 to 3400 bytes, objects freed 4/30 (in 1 ms) - slots from 34/76 to 33/76
23:42:40.903 MQT: tele/esp32dev3/STATE = {"Time":"2023-11-26T23:42:40+01:00","Uptime":"0T00:14:06","UptimeSec":846,"Heap":164,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Berry":{"HeapUsed":3,"Objects":30},"Wifi":{"AP":1,"SSId":"BNETWLAN","BSSId":"88:C3:97:F2:25:EC","Channel":1,"Mode":"11n","RSSI":100,"Signal":-45,"LinkCount":1,"Downtime":"0T00:00:10"}}
23:42:40.917 RUL: TELE-TIME performs "webquery http://192.168.168.244/myip.php?json GET"
23:42:40.919 SRC: Rule
23:42:40.921 CMD: Grp 0, Cmd 'WEBQUERY', Idx 1, Len 40, Pld -99, Data 'http://192.168.168.244/myip.php?json GET'
23:42:40.959 MQT: stat/esp32dev3/WEBQUERY = {"WebQuery":{"myip":"192.168.168.196"}}
23:42:40.973 MQT: stat/esp32dev3/WEBQUERY = {"WebQuery":"Done"}
23:42:45.644 WIF: Checking connection...
23:42:50.902 BRY: GC from 3819 to 3400 bytes, objects freed 1/30 (in 1 ms) - slots from 34/76 to 33/76
23:42:50.913 MQT: tele/esp32dev3/STATE = {"Time":"2023-11-26T23:42:50+01:00","Uptime":"0T00:14:16","UptimeSec":856,"Heap":164,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Berry":{"HeapUsed":3,"Objects":30},"Wifi":{"AP":1,"SSId":"BNETWLAN","BSSId":"88:C3:97:F2:25:EC","Channel":1,"Mode":"11n","RSSI":100,"Signal":-43,"LinkCount":1,"Downtime":"0T00:00:10"}}
23:42:50.929 RUL: TELE-TIME performs "webquery http://192.168.168.244/myip.php?json GET"
23:42:50.931 SRC: Rule
23:42:50.933 CMD: Grp 0, Cmd 'WEBQUERY', Idx 1, Len 40, Pld -99, Data 'http://192.168.168.244/myip.php?json GET'
23:42:50.975 MQT: stat/esp32dev3/WEBQUERY = {"WebQuery":{"myip":"192.168.168.196"}}
23:42:50.988 MQT: stat/esp32dev3/WEBQUERY = {"WebQuery":"Done"}
23:43:00.911 BRY: GC from 3819 to 3400 bytes, objects freed 1/30 (in 1 ms) - slots from 34/76 to 33/76
23:43:00.921 MQT: tele/esp32dev3/STATE = {"Time":"2023-11-26T23:43:00+01:00","Uptime":"0T00:14:26","UptimeSec":866,"Heap":164,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Berry":{"HeapUsed":3,"Objects":30},"Wifi":{"AP":1,"SSId":"BNETWLAN","BSSId":"88:C3:97:F2:25:EC","Channel":1,"Mode":"11n","RSSI":100,"Signal":-42,"LinkCount":1,"Downtime":"0T00:00:10"}}

@barbudor
Copy link
Contributor Author

I need to check further because it seems that rules get impacted
rules on webquery# that were working on esp8266 doesn't work anymore

@barbudor barbudor marked this pull request as draft November 26, 2023 23:20
@arendst
Copy link
Owner

arendst commented Nov 27, 2023

I'll do some chks too using this on my server:

<?php
    $ip = getenv("REMOTE_ADDR");

    if (isset($_GET["json"])) {
        echo "{\"myip\":\"$ip\"}";
    } else {
        echo "myip = $ip";
    }
?>

It works on ESP8266 but fails on ESP32 and ESP32-C3.

UPDATE1: Your rule2 needs to be changed to: rule2 on webquery#myip do var1 %value% endon
UPDATE2: The rules works fine when executed manually but corrupt the "Done" result.

I'll remove the "Done" message when a valid result is received.

UPDATE3: Here is the result of a manual interrogation of the command. It responds as expected:

12:41:10.157-027 CMD: webquery http://192.168.2.24/myip.php?json GET
12:41:10.159-027 SRC: Serial
12:41:10.161-027 CMD: Grp 0, Cmd 'WEBQUERY', Idx 1, Len 37, Pld -99, Data 'http://192.168.2.24/myip.php?json GET'
12:41:10.190-024 MQT: stat/wemos4/RESULT = {"WebQuery":{"myip":"192.168.2.223"}}
12:41:10.192-024 RUL: ProcessEvent |{"WebQuery":{"myip":"192.168.2.223"}}|
12:41:10.193-024 RUL: Event |{"WEBQUERY":{"MYIP":"192.168.2.223"}}|
12:41:10.201-024 RUL-RP1: Event = {"WEBQUERY":{"MYIP":"192.168.2.223"}}, Rule = on Time#minute do webquery http://192.168.2.24/myip.php?json GET endon
12:41:10.213-023 RUL-RP2: Event |{"WEBQUERY":{"MYIP":"192.168.2.223"}}|, Rule |TIME#MINUTE|, Command(s) |webquery http://192.168.2.24/myip.php?json GET|
12:41:10.226-023 RUL-RM1: Teleperiod 0, Expr TIME#MINUTE, Name TIME#MINUTE, Param 
12:41:10.234-024 RUL-RP1: Event = {"WEBQUERY":{"MYIP":"192.168.2.223"}}, Rule = on webquery#myip do var1 %value% endon
12:41:10.244-024 RUL-RP2: Event |{"WEBQUERY":{"MYIP":"192.168.2.223"}}|, Rule |WEBQUERY#MYIP|, Command(s) |var1 %value%|
12:41:10.254-023 RUL-RM1: Teleperiod 0, Expr WEBQUERY#MYIP, Name WEBQUERY#MYIP, Param 
12:41:10.264-025 RUL-RM3: Name MYIP, Value ||, TrigCnt 0, TrigSt 0, Source {"WEBQUERY":{"MYIP":"192.168.2.223"}}, Json |192.168.2.223|
12:41:10.282-025 RUL: WEBQUERY#MYIP performs "var1 192.168.2.223"
12:41:10.284-025 SRC: Rule
12:41:10.285-025 CMD: Grp 0, Cmd 'VAR', Idx 1, Len 13, Pld 192, Data '192.168.2.223'
12:41:10.296-025 MQT: stat/wemos4/RESULT = {"Var1":"192.168.2.223"}
12:41:10.307-027 RUL: ProcessEvent |{"Var1":{"State":"192.168.2.223"}}|
12:41:10.308-027 RUL: Event |{"VAR1":{"STATE":"192.168.2.223"}}|
12:41:10.309-027 RUL-RP1: Event = {"VAR1":{"STATE":"192.168.2.223"}}, Rule = on Time#minute do webquery http://192.168.2.24/myip.php?json GET endon
12:41:10.322-027 RUL-RP2: Event |{"VAR1":{"STATE":"192.168.2.223"}}|, Rule |TIME#MINUTE|, Command(s) |webquery http://192.168.2.24/myip.php?json GET|
12:41:10.335-027 RUL-RM1: Teleperiod 0, Expr TIME#MINUTE, Name TIME#MINUTE, Param 
12:41:10.343-027 RUL-RP1: Event = {"VAR1":{"STATE":"192.168.2.223"}}, Rule = on webquery#myip do var1 %value% endon
12:41:10.353-027 RUL-RP2: Event |{"VAR1":{"STATE":"192.168.2.223"}}|, Rule |WEBQUERY#MYIP|, Command(s) |var1 %value%|
12:41:10.363-027 RUL-RM1: Teleperiod 0, Expr WEBQUERY#MYIP, Name WEBQUERY#MYIP, Param 

@arendst
Copy link
Owner

arendst commented Nov 27, 2023

Your PR fixes at least the missing/corrupted response so I'll merge this.

The issue with rules executing while another rule is busy (Rules.busy flag) is a different longstanding problem without a sinple solution.

@arendst arendst marked this pull request as ready for review November 27, 2023 11:38
@arendst arendst merged commit 3273aaa into arendst:development Nov 27, 2023
64 checks passed
@barbudor barbudor deleted the esp32_webquery_response branch November 27, 2023 12:12
@sfromis
Copy link
Contributor

sfromis commented Nov 27, 2023

Doing a simple WebQuery (3-character response) started to work now, on an ESP32-C3.

@sfromis
Copy link
Contributor

sfromis commented Nov 27, 2023

However, I'm still seeing WebQuery ESP32 badness with a file containing {"Level":"47%"}:

13:22:25.256 MQT: xxxxxxxx/stat/WEBQUERY = {"WebQuery":{"Level":"47xV���?�"}}
13:22:25.261 MQT: xxxxxxxx/stat/WEBQUERY = {"WebQuery":"Done"}

Looks like something is seeing usage of % as a call for action, but not getting to a good action.

@barbudor
Copy link
Contributor Author

strange because characters are copied 1 by 1 from the http response to the MQTT message
I will try to investigate tonight

@barbudor
Copy link
Contributor Author

UPDATE1: Your rule2 needs to be changed to: rule2 on webquery#myip do var1 %value% endon

That what I was first thinking but I found old notes from rules I was using more than a year ago that were apparently working like that. May be a change in Tasmota.
But webquery#myip makes much more sense

UPDATE2: The rules works fine when executed manually but corrupt the "Done" result.

So that seems to confirm that there is something broken in the kingdom of ext_vsnprinf_P ?

@arendst
Copy link
Owner

arendst commented Nov 27, 2023

So that seems to confirm that there is something broken in the kingdom of ext_vsnprinf_P ?

No, I don't think something is off with the long standing ext_vsnprintf_P. Something is off with releasing Strings. ANyway, I'll remove the unnneeded "Done" message resulting in a single response as expected.

However, I'm still seeing WebQuery ESP32 badness with a file containing {"Level":"47%"}:

Works fine on ESP8266 (but removes the %) and fails on any ESP32. Investigating too with focus on HttpClientLight.cpp not used by ESP8266....
EDIT1: I see it fails on ESP8266 too with random results. Back to WebQuery() again...

EDIT2: As expected see note:

int ResponseAppend_P(const char* format, ...)  // Content send snprintf_P char data
{
  // This uses char strings. Be aware of sending %% if % is needed

So we need to test for % and provide %%. Working on it.

@arendst
Copy link
Owner

arendst commented Nov 27, 2023

Should be fixed now.

@sfromis
Copy link
Contributor

sfromis commented Nov 27, 2023

Better now, {"WebQuery":{"Level":"47%"}} 👍

Trying with double %% did not help, nor other common escaping techniques. Could/can anything useful be done with % formatting around WebQuery or other "non-intuitive" places?

I'll remove the "Done" message when a valid result is received.

Good idea. Makes WebQuery more useful, but may be a little bit of a breaking change in case someone decided to use the Done for a rule trigger.

@arendst
Copy link
Owner

arendst commented Nov 27, 2023

Trying with double %% did not help

That's because every character is individually send to the snprintf code instead of sending the response as one text string. This was chosen to keep the memory footprint as low as possible.

Could/can anything useful be done with % formatting around WebQuery or other "non-intuitive" places?

Not anymore ;-) All formatting is now disabled in WebQuery response.

Using the Done for a rule trigger is useless as the previous webquery response is overwritten by the Done message.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

WebQuery get right answer on 8266 but erratic on ESP32
3 participants