HTTPClient mystery crash after http.end(), why?

[aldoaldoaldo]

Basic Infos

• [x ] This issue complies with the issue POLICY doc.
• [x ] I have read the documentation at readthedocs and the issue is not addressed there.
• [x ] I have tested that the issue is present in current master branch (aka latest git).
• [x ] I have searched the issue tracker for a similar issue.
• [x ] If there is a stack dump, I have decoded it.
• [x ] I have filled out all fields below.

Platform

• Hardware: [ESP-12S|
• Core Version: [2.7.4]
• Development Env: [Arduino IDE]
• Operating System: [Windows]

Settings in IDE

• Module: [Nodemcu]
• Flash Mode: [qio|dio|other]
• Flash Size: [4MB]
• lwip Variant: [v1.4 Higher Bandwidth]
• Reset Method: [ck|nodemcu]
• Flash Frequency: [40Mhz]
• CPU Frequency: [80Mhz]
• Upload Using: [OTA|SERIAL]
• Upload Speed: [115200|other] (serial upload only)

Problem Description

This is within a biggest project were I am running the standard sync webserver.
To exclude cross-errors, anyway, I wrote this simple test procedure that is called at a certain time from loop()
The ESP is 192.168.1.11 and it's connected to my wifi router, while 192.168.1.12 is another ESP connected to the same wifi.
The GET call is a success (I see it OK on the receiver), but as you see the "logg" after http.end is not called and instead there is a restart (this implies a crash...).
Heap space is good and >40K you see is logged; logg() is a my years old log procedure.
I see no reasons for crash ???!???!?!???!

NOTICE:1: The mother of that procedure used to work (months ago while I used 2.4.2 or so on all my projects) - so this may be caused by the web response of the other ESP (maybe at tcp level this is changed from 2.4.2 to 2.7.4) but in any case a http client proc is expected to NOT crash depending on server reply.

NOTICE2: With surl="http://termoeasy.com/1.txt" no crashes, this would prove true NOTICE1.

NOTICE3: I have another similar proc that uses a Stream instead a string, and I noticed it is SLOWED DOWN terribly when I download a series of (very short) files from web, after I upgraded to 2.7.2 (today 2.7.4 and recompiled before doing this report).

MCVE Sketch

void testsend()
{
      HTTPClient http;
      String surl="http://192.168.1.12/x?&id=1046&n=TS46&w=1&b=26&dm=15&pw=pippo&r=CE6400&t=-12700&h=0";
      logg(surl+"<< TEST");
      http.begin(surl);
      logg("after begin");
      int httpcode= http.GET();
      logg("after GET");
      String s=http.getString();
      logg(s+"<< s - after getString");
      http.end();
      logg(String(httpcode)+"; (after end) s="+s);
}

loop()
{
  deledc(50);  //somewhat like delay but calls dns/web service
  ....
  switch (azione)
  {
    case AZ_TESTSEND:
      {
        deledc(2000);
        testsend();
        azione=AZ_DO_NOTHING;
        break;
      }
    //AZ_DO_NOTHING;
    default:
  }

}

Debug Messages

this is the log:
[2020-09-26 22:22.02] G 18az >42608
http://192.168.1.12/x?&id=1046&n=TS46&w=1&b=26&dm=15&pw=pippo&r=CE6400&t=-12700&h=0<< TEST
[2020-09-26 22:22.02] G 18az >42672
after begin
[2020-09-26 22:22.02] G 18az >42360
after GET
[2020-09-26 22:22.02] G 18az >42200
RXOK<< s - after getString
[1970-00-00 00:00.00] G 99az >44824
(setup)WiFi.scanNetworks started
[1970-00-00 00:00.00] G 99az >44840
##############################

  START START START START
##############################
[2020-09-26 22:22.07] G -1az >43736
(wifiEndScanAction)

[aldoaldoaldo]

HTTP/1.1 200 OK
Content-Type: text/html; charset=iso-8859-1
Content-Length: 4
Connection: close

RXOK

(from Firefox debugger, this is what is returned from
http://192.168.1.12/x?&id=1046&n=TS46&w=1&b=26&dm=15&pw=pippo&r=CE6400&t=-12700&h=0

[earlephilhower]

@aldoaldoaldo you need to post a complete, compile-able and runnable MCVE. Your snippet isn't useful as it's not complete. You also did not post any decoded (or undecoded) ESP crash dumps. W/o these two bits, we can't do anything here.

[aldoaldoaldo]

I guessed so, but my total code is too big AND that is a very basic procedure that MUST work (I am doing just a GET). Also (sorry) I updated my first post before seeing your reply, but basically see below, now I additionally know that I can ask any URL on Web, but when I ask a URL that is on the other ESP on http://192.168.1.12/ it crashes.

[2020-09-27 01:49.00] G -1az >42128
2020-09-27 01:49.00<< Set time >>2020-09-27 01:49.00
[2020-09-27 01:49.02] G 19az >42736
http://termoeasy.com/1.txt<< TEST
[2020-09-27 01:49.02] G 19az >42792
after begin
[2020-09-27 01:49.02] G 19az >42456
after GET
[2020-09-27 01:49.02] G 19az >42256
(this is a test)
<< s - after getString
[2020-09-27 01:49.02] G 19az >42328
200; (after end) s=(this is a test)

[2020-09-27 01:49.09] G 19az >42528
http://termoeasy.com/1.txt<< TEST
[2020-09-27 01:49.09] G 19az >42584
after begin
[2020-09-27 01:49.09] G 19az >42272
after GET
[2020-09-27 01:49.09] G 19az >42072
(this is a test)
<< s - after getString
[2020-09-27 01:49.09] G 19az >42144
200; (after end) s=(this is a test)

[2020-09-27 01:49.18] G 20az >42376
http://192.168.1.12/<< TEST
[2020-09-27 01:49.18] G 20az >42400
after begin
[2020-09-27 01:49.19] G 20az >42112
after GET
[2020-09-27 01:49.19] G 20az >22864
<html><head><meta name='Content-Type' content='text/html; charset=iso-8859-1'>
[...omissis...]
<br>&copy; 2020 VisualVision - All rights reserved</font></div></body></html>
<< s - after getString
[1970-00-00 00:00.00] G 99az >44792
(setup)WiFi.scanNetworks started
[1970-00-00 00:00.00] G 99az >44808
##############################

  START START START START
##############################
[2020-09-27 01:49.24] G -1az >43704

(wifiEndScanAction)

Now I am writing a new simple sketch on a new ESP........

[aldoaldoaldo]

#include <ESP8266WiFi.h>
#include <ESP8266HTTPClient.h>

void setup() {
  // put your setup code here, to run once:
  pinMode(2,OUTPUT);
  digitalWrite(2,HIGH); //led off

  WiFi.begin("Vodafone-123","............");

  int i=350,j=0;
  while (i>0) {
    j=wifi_station_get_connect_status();
    switch(j) {
      case STATION_CONNECT_FAIL:
        i=0;
        break;
      case STATION_WRONG_PASSWORD:
        i=-1;
        break;
      case STATION_NO_AP_FOUND:
        i=-2;
        break;
      case STATION_GOT_IP:
        i=-3;
        break;
    }
    delay(100);
    if (i>0) i--;
  }
  Serial.begin(115200);
  Serial.println();
  Serial.println("Setup; Wifi status="+String(i));
}

bool done=false,led=false;

void testsend()
{
      HTTPClient http;
      //
      //this URL (on the Web) works
      ////String surl="http://termoeasy.com/1.txt";    

      //now other URLs supplied by the web server of another ESP, same wifi, on 192.168.1.12
      //It correctly works and supplies pages with Firefox

      //if this works
      //with w=1 will be received (and logged) as "channel 1" of the ESP at 192.168.1.12
      //(*** at present that ESP receives, so the GET works; but http.end() crashes )
      String surl="http://192.168.1.12/x?&id=1046&n=TS46&w=1&b=26&dm=15&pw=pippo&r=CE6400&t=-12700&h=0";

      //or that url will just show http://192.168.1.12/ homepage
      //String surl="http://192.168.1.12/";
      //(*** at present GET works but http.end() create a crash also with this URL)
      //
      http.begin(surl);
      Serial.println(surl);
      int httpcode= http.GET();
      String s=http.getString();
      Serial.println(s);
      Serial.println("BEFORE http END");
      http.end();

//****** with the urls with IP = GET webpage/script from external ESP in the same wifi network, it never arrives here *********

      Serial.println("AFTER http END");
      //
      //if it arrives here, led should blink
      led=true;
      //
      //with w=2 will be received (and logged) as "channel 2" of the ESP at 192.168.1.12
      surl="http://192.168.1.12/x?&id=1046&n=TS46&w=2&b=26&dm=15&pw=pippo&r=CE6400&t=-12700&h=0";
      http.begin(surl);
      Serial.println(surl);
      httpcode= http.GET();
      s=http.getString();
      http.end();
      Serial.println(s);
}

void loop() {
  // put your main code here, to run repeatedly:
  delay(100);
  if (!done)
  if (millis()>2000) 
  {
    testsend();
    done=true;
  }
  bool a=!(digitalRead(2));
  if (led) digitalWrite(2,a);
}

[aldoaldoaldo]

Setup; Wifi status=-3
http://192.168.1.12/x?&id=1046&n=TS46&w=1&b=26&dm=15&pw=pippo&r=CE6400&t=-12700&h=0
RXOK
BEFORE http END

--------------- CUT HERE FOR EXCEPTION DECODER ---------------

Exception (9):
epc1=0x40206dfc epc2=0x00000000 epc3=0x00000000 excvaddr=0x0000023d depc=0x00000000

>>>stack>>>

ctx: cont
sp: 3ffffd10 end: 3fffffc0 offset: 0190
3ffffea0:  40203b64 3ffee3f0 3ffe870a 40203e45  
3ffffeb0:  3fffdad0 0000000f 3ffffee0 402029b0  
3ffffec0:  3fffdad0 00000000 3ffffee0 40203754  
3ffffed0:  3fffdad0 00000000 3ffee3f0 4020116f  
3ffffee0:  00000000 00000000 3ffefbec 3ffefcd4  
3ffffef0:  000c000f 00000020 3f010050 3f001388  
3fffff00:  3ffefcec 0040004f 000d0020 70747468  
3fffff10:  00000c00 8400018c 3ffefe4c 0000001f  
3fffff20:  00fef971 3ffef95c 0011001f 00fee46c  
3fffff30:  00000000 4bc6a7f0 80b851eb 00000000  
3fffff40:  00000000 000000c8 00000004 00000000  
3fffff50:  00000000 0020000a 40100200 00001a99  
3fffff60:  80000000 00000000 3ffefd94 3ffefb00  
3fffff70:  0053005f 80fee4c8 4b4f5852 40205000  
3fffff80:  84205701 3ffefb84 0053005f 00fee46c  
3fffff90:  3fffdad0 00000000 3ffee3b9 4020122f  
3fffffa0:  feefeffe 00000000 3ffee42c 40205214  
3fffffb0:  feefeffe feefeffe 3ffe84e8 40100c55  
<<<stack<<<

--------------- CUT HERE FOR EXCEPTION DECODER ---------------

 ets Jan  8 2013,rst cause:1, boot mode:(3,6)

load 0x4010f000, len 3584, room 16 
tail 0
chksum 0xb0
csum 0xb0
v2843a5ac
~ld

[aldoaldoaldo]

by the way it does the GET (it is received by the other ESP, that responds "RXOK", and the response is correctly received); and as said, I was using 2.4.2 and never had this problem before. But 2.4.2 had heap problems if I put the ESP on the net on a dyndns, so I moved to 2.7.1 (now 2.7.4). That's all that I know. Now I think I should go sleeping!!! :)

[earlephilhower]

You need to decode the stack dump with the EspExceptionDecoder for it to be use. There is an Arduino plugin used to do so. It's described in the readme.

[Tech-TX]

https://github.com/me-no-dev/EspExceptionDecoder

Copy and paste EVERYTHING between the two 'CUT HERE' points and drop it in the Exception Decoder. This has to be done on your CURRENT COMPILE. If you recompile, then that stack trace above is even more meaningless than the raw dump you posted. The Exception Decoder gets it's code references from your latest *.elf file, and that changes each time you make a tweak and recompile.

[aldoaldoaldo]

Thank you, to be sure I recompiled and got a new dump (that seems identical to previous)

Exception (9):
epc1=0x40206dfc epc2=0x00000000 epc3=0x00000000 excvaddr=0x0000023d depc=0x00000000

>>>stack>>>

ctx: cont
sp: 3ffffd10 end: 3fffffc0 offset: 0190
3ffffea0:  40203b64 3ffee3f0 3ffe870a 40203e45  
3ffffeb0:  3fffdad0 0000000f 3ffffee0 402029b0  
3ffffec0:  3fffdad0 00000000 3ffffee0 40203754  
3ffffed0:  3fffdad0 00000000 3ffee3f0 4020116f  
3ffffee0:  00000000 00000000 3ffefbec 3ffefcd4  
3ffffef0:  000c000f 00000020 3f010050 3f001388  
3fffff00:  3ffefcec 0040004f 000d0020 70747468  
3fffff10:  00000c00 8400018c 3ffefe4c 0000001f  
3fffff20:  00fef971 3ffef95c 0011001f 00fee46c  
3fffff30:  00000000 4bc6a7f0 80f3b645 00000000  
3fffff40:  00000000 000000c8 00000004 00000000  
3fffff50:  00000000 001b000a 40100200 0000168c  
3fffff60:  80000000 00000000 3ffefd94 3ffefb00  
3fffff70:  0053005f 80fee4c8 4b4f5852 40205000  
3fffff80:  84205701 3ffefb84 0053005f 00fee46c  
3fffff90:  3fffdad0 00000000 3ffee3b9 4020122f  
3fffffa0:  feefeffe 00000000 3ffee42c 40205214  
3fffffb0:  feefeffe feefeffe 3ffe84e8 40100c55  
<<<stack<<<

but there's no way to copy and paste the decoded results

[aldoaldoaldo]

a ok no, now the text can be selected. Here we are:

Exception 9: LoadStoreAlignmentCause: Load or store to an unaligned address
PC: 0x40206dfc: HTTPClient::connected() at C:\Users\User\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.7.4\libraries\ESP8266HTTPClient\src\ESP8266HTTPClient.cpp line 475
EXCVADDR: 0x0000023d

Decoding stack results
0x40203b64: HardwareSerial::write(unsigned char const*, unsigned int) at C:\Users\User\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.7.4\cores\esp8266/HardwareSerial.h line 164
0x40203e45: Print::write(char const*) at C:\Users\User\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.7.4\cores\esp8266/Print.h line 62
0x402029b0: HTTPClient::disconnect(bool) at C:\Users\User\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.7.4\libraries\ESP8266HTTPClient\src\ESP8266HTTPClient.cpp line 434
0x40203754: HTTPClient::end() at C:\Users\User\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.7.4\libraries\ESP8266HTTPClient\src\ESP8266HTTPClient.cpp line 425
0x4020116f: testsend() at C:\Users\User\Documents\Arduino\test_httpclient/test_httpclient.ino line 64
0x40100200: millis() at C:\Users\User\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.7.4\cores\esp8266\core_esp8266_wiring.cpp line 188
0x40205000: base64::encode(unsigned char const*, unsigned int, bool) at C:\Users\User\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.7.4\cores\esp8266\base64.cpp line 67
0x4020122f: loop() at C:\Users\User\Documents\Arduino\test_httpclient/test_httpclient.ino line 86
0x40205214: loop_wrapper() at C:\Users\User\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.7.4\cores\esp8266\core_esp8266_main.cpp line 197

[aldoaldoaldo]

(ANOTHER STRANGE BEHAVIOR: DELAY IN MULTIPLE SUBSEQUENT FILE DOWNLOAD / BY STREAM)
While I am here, in 2.7 (& 1.4 H.B.) I've seen also a non explicable slow down when I download multiple very small files on web. This with the usual stream procedure (below) that I copied from a example.
This huge delay was not present when I used 2.4.2 (and additionally I was not compiling in 1.4 High Bandwidth but in default mode).

    http.begin(url);   
    int httpCode = http.GET();
    if (httpCode > 0) {
      {
        File ff = SPIFFS.open(destination, "w");
        if (ff) {
          int len = http.getSize();
          uint8_t buff[512] = { 0 };
          WiFiClient * stream = http.getStreamPtr();
          while(http.connected() && (len > 0 || len == -1)) {
             size_t size = stream->available();
             if (size) {
                int c = stream->readBytes(buff, ((size > sizeof(buff)) ? sizeof(buff) : size));
                ff.write(buff, c);
             }
          }
          ff.close();
        }        
      }
      http.end();

No crashes here, but around 11-12 seconds to download a small text file (!!).
I have a proc that downloads a list.txt then download the listed items with a while that calls the above proc.
Here the log:

update files
[2020-09-27 13:51.26] G 96az >42160
200 - download OK, URL:DEST http://wfeasy.com/xxxx/list.txt:/list
[2020-09-27 13:51.37] G 96az >41800
200 - download OK, URL:DEST http://wfeasy.com/xxxx/m/td.htm:/td.htm
[2020-09-27 13:51.48] G 96az >42008
404 - download OK, URL:DEST http://wfeasy.com/xxxx/m/ps.htm:/ps.htm
[2020-09-27 13:52.00] G 96az >42064
200 - download OK, URL:DEST http://wfeasy.com/xxxx/m/pl.htm:/pl.htm

[earlephilhower]

We can't run your MCVE because it needs your local server app, but given the decoded crash signature I am pretty sure that you're running out of memory.

Please enable full debug (Tools->Debug Port->Serial, Tools->Debug Level->(all, the longest one)) and rerun.

You may be GETting an object that's simply too big for RAM.

[aldoaldoaldo]

No, it's 100 bytes and RAM is almost all available.
Please read all that I posted.
The GET reponse (obtained with Firefox and copied above) is around 100 bytes including headers.
From the log, in the big original software where I've first seen the bug the heap was 40K so plenty of RAM; in the small example posted above it is obviously more, maybe 50K.
How can it hang for 100 bytes?
Also the GET response is correctly received and printed to Serial without any RAM problem.
It HANGS only WHEN CLOSING, while executing http.end() - or if I remove http.end() it hangs at the end of the proc, I guess when the compiler destroys/frees the object "http" as I do not explicitly destroy it.
The bug happens only when calling that server on same wifi / router, by IP (it seems also by DNS if I run a DNS on the other ESP), so it may be connected to timings or... who knows.
To run the MCVE and to test it you just need another ESP with a web server turned on within the same network and that serves any page. While I copy below the first page where I found the bug, I can say it happens also for 2 other pages so it seems definitely unrelated on the page. Maybe it will happen also with any other webserver on the same local net.

HTTP/1.1 200 OK
Content-Type: text/html; charset=iso-8859-1
Content-Length: 4
Connection: close

RXOK

(this is the page served as reply (with standard sync webserver) - it just confirms data have been received from the other ESP.)
P.s. when at home I will give a try with the debug on...

[aldoaldoaldo]

The handler on the ESP server is (basically)

void xdata()
{
String testo="RXOK";
//..... does some checks on server.arg......
server.send(200, "text/html; charset=iso-8859-1", testo);
}