setTimeout() hasn't any effect

[miwied]

Describe the bug

If address is a normal address e.g.: http://exampleasynchttp.com/index.html, it gives immediately a "-4" code if not available (good).
But if the address is a ip address like http://192.168.0.44/index.html (this host is down) the timeout takes always about 18 seconds no matter how many seconds you set (not good).

Steps to Reproduce

Copy code from:
https://gist.github.com/miwied/f56aca82c4f976f448dde1a8da051650
Flash it to esp32 and run.

Expected behavior

The request should time out after 3 seconds.

Actual behavior

The request is always timing out after 18 seconds (no matter what you pass into the setTimeout() method).

Additional Information

The _onPoll(AsyncClient *client) method, where the timeout is queried, is never called.

[khoih-prog]

Hi @miwied

The new AsyncHTTPRequest_Generic releases v1.9.0 has just been published. Your contribution is noted in Contributions and Thanks

Best Regards,

---

Releases v1.9.0

1. Fix long timeout if using IPAddress. Check setTimeout() hasn't any effect #38
2. Optimize code
3. Display only successful responseText in examples
4. Improve debug messages by adding functions to display error messages instead of cryptic error number
5. Remove support to STM32 using LAN8720 due to problem with new STM32 core v2.3.0
6. Update Packages' Patches

---

Use the following code to test the new library version

Test Code

#include <Arduino.h>

#if (ESP8266)
  #include <ESP8266WiFi.h>
#elif (ESP32)
  #include <WiFi.h>
#endif

#define ASYNC_HTTP_DEBUG_PORT     Serial
#define _ASYNC_HTTP_LOGLEVEL_     1

// 300s = 5 minutes to not flooding
#define HTTP_REQUEST_INTERVAL     60  //300

#define USING_GENERIC         true
//#define USING_GENERIC         false


#if USING_GENERIC
  #include <AsyncHTTPRequest_Generic.h>     // https://github.com/khoih-prog/AsyncHTTPRequest_Generic
#else
  #include <asyncHTTPrequest.h> 
  #define AsyncHTTPRequest    asyncHTTPrequest

  #define readyStateUnsent    0
  #define readyStateDone      4
  
#endif

#include <Ticker.h>

const char *ssid = "your_ssid";
const char *password = "your_pass";

AsyncHTTPRequest request;
Ticker ticker;

void sendRequest()
{
  static bool requestOpenResult;

  if (request.readyState() == readyStateUnsent || request.readyState() == readyStateDone)
  {
    //requestOpenResult = request.open("GET", "http://192.168.178.62/cm?cmnd=Power");
    //requestOpenResult = request.open("GET", "http://exampleasynchttp.com/index.html");
    requestOpenResult = request.open("GET", "http://worldtimeapi.org/api/timezone/America/Toronto.txt");

    if (requestOpenResult)
    {
      // Only send() if open() returns true, or crash
      Serial.println(F("Send request"));
     
      request.send();
    }
    else
    {
      Serial.println(F("Can't send bad request"));
    }
  }
  else
  {
    Serial.println(F("Can't send request"));
  }
}

void requestCB(void *optParm, AsyncHTTPRequest *request, int readyState)
{
  (void) optParm;

  if (readyState == readyStateDone)
  {
    AHTTP_LOGERROR(F("**************************************"));
    AHTTP_LOGERROR1(F("Response Code = "), request->responseHTTPString());

    if (request->responseHTTPcode() == 200)
    {
      Serial.println(F("**************************************"));
      Serial.println(request->responseText());
      Serial.println(F("**************************************"));
    }
    else
    {
      AHTTP_LOGERROR(F("Response error"));
    }
  }
}

void setup()
{
  Serial.begin(115200);
  while (!Serial && millis() < 5000);

  Serial.print(F("\nStarting AsyncHTTPRequest_Test using ")); Serial.println(ARDUINO_BOARD);
  Serial.println(ASYNC_HTTP_REQUEST_GENERIC_VERSION);

  WiFi.mode(WIFI_STA);

  WiFi.begin(ssid, password);
  
  Serial.print(F("Connecting to WiFi SSID: ")); Serial.println(ssid);

  while (WiFi.status() != WL_CONNECTED)
  {
    delay(500);
    Serial.print(F("."));
  }

  Serial.print(F("\nAsyncHTTPRequest @ IP : "));
  Serial.println(WiFi.localIP());

  request.setDebug(true);
  
  request.onReadyStateChange(requestCB);
  ticker.attach(HTTP_REQUEST_INTERVAL, sendRequest);
 
  // Send first request now
  sendRequest();  
}

void loop()
{
}

Using correct hostname http://worldtimeapi.org => response OK

00:34:46.090 -> Starting AsyncHTTPRequest_Test using ESP32_DEV
00:34:46.090 -> AsyncHTTPRequest_Generic v1.9.0
00:34:46.223 -> Connecting to WiFi SSID: HueNet1
00:34:46.720 -> ...
00:34:47.747 -> AsyncHTTPRequest @ IP : 192.168.2.109
00:34:47.747 -> Send request
00:34:47.747 -> [AHTTP] **************************************
00:34:47.747 -> [AHTTP] Response Code =  NOT_CONNECTED
00:34:47.747 -> [AHTTP] Response error
00:34:47.780 -> [AHTTP] **************************************
00:34:47.780 -> [AHTTP] Response Code =  HTTP OK
00:34:47.780 -> **************************************
00:34:47.780 -> abbreviation: EDT
00:34:47.780 -> client_ip: aaa.bbb.ccc.ddd
00:34:47.780 -> datetime: 2022-08-31T00:34:47.720501-04:00
00:34:47.780 -> day_of_week: 3
00:34:47.780 -> day_of_year: 243
00:34:47.780 -> dst: true
00:34:47.780 -> dst_from: 2022-03-13T07:00:00+00:00
00:34:47.813 -> dst_offset: 3600
00:34:47.813 -> dst_until: 2022-11-06T06:00:00+00:00
00:34:47.813 -> raw_offset: -18000
00:34:47.813 -> timezone: America/Toronto
00:34:47.813 -> unixtime: 1661920487
00:34:47.813 -> utc_datetime: 2022-08-31T04:34:47.720501+00:00
00:34:47.813 -> utc_offset: -04:00
00:34:47.813 -> week_number: 35
00:34:47.813 -> **************************************
00:35:47.729 -> Send request
00:35:47.762 -> [AHTTP] **************************************
00:35:47.762 -> [AHTTP] Response Code =  HTTP OK
00:35:47.762 -> **************************************
00:35:47.762 -> abbreviation: EDT
00:35:47.762 -> client_ip: 45.72.215.229
00:35:47.762 -> datetime: 2022-08-31T00:35:47.704449-04:00
00:35:47.762 -> day_of_week: 3
00:35:47.762 -> day_of_year: 243
00:35:47.762 -> dst: true
00:35:47.762 -> dst_from: 2022-03-13T07:00:00+00:00
00:35:47.796 -> dst_offset: 3600
00:35:47.796 -> dst_until: 2022-11-06T06:00:00+00:00
00:35:47.796 -> raw_offset: -18000
00:35:47.796 -> timezone: America/Toronto
00:35:47.796 -> unixtime: 1661920547
00:35:47.796 -> utc_datetime: 2022-08-31T04:35:47.704449+00:00
00:35:47.796 -> utc_offset: -04:00
00:35:47.796 -> week_number: 35
00:35:47.796 -> **************************************

---

Using bad IPAddress http://192.168.178.62/cm?cmnd=Power

00:36:57.012 -> Starting AsyncHTTPRequest_Test using ESP32_DEV
00:36:57.012 -> AsyncHTTPRequest_Generic v1.9.0
00:36:57.112 -> Connecting to WiFi SSID: HueNet1
00:36:57.609 -> ...
00:36:58.636 -> AsyncHTTPRequest @ IP : 192.168.2.109
00:36:58.636 -> Send request
00:36:58.636 -> [AHTTP] **************************************
00:36:58.636 -> [AHTTP] Response Code =  NOT_CONNECTED
00:36:58.636 -> [AHTTP] Response error
00:37:16.878 -> [AHTTP] _onError handler error = Connection aborted    <==== Controlled by AsyncTCP library

This case, Response error right away. But Connection aborted is controlled by AsyncTCP library and delay by 18s

---

Using bad hostname http://exampleasynchttp.com/index.html => DNS error

00:38:33.359 -> Starting AsyncHTTPRequest_Test using ESP32_DEV
00:38:33.359 -> AsyncHTTPRequest_Generic v1.9.0
00:38:33.492 -> Connecting to WiFi SSID: HueNet1
00:38:33.989 -> ...
00:38:34.982 -> AsyncHTTPRequest @ IP : 192.168.2.109
00:38:34.982 -> Send request
00:38:34.982 -> [AHTTP] **************************************
00:38:34.982 -> [AHTTP] Response Code =  NOT_CONNECTED
00:38:34.982 -> [AHTTP] Response error
00:38:35.148 -> [AHTTP] _onError handler error = DNS failed

This case, Response error right away. DNS failed is also controlled by AsyncTCP library and activated immediately

[miwied]

Hi @khoih-prog, first of all I would like to thank you for addressing the problem so quickly and looking for a possible solution.

I now tested the new library for about one hour and unfortunately, I have to tell you that the results are different for me than for you and the problem still exists. 😕

---

Here is the code I used (your test code):

#include <Arduino.h>

#if (ESP8266)
#include <ESP8266WiFi.h>
#elif (ESP32)
#include <WiFi.h>
#endif

#define ASYNC_HTTP_DEBUG_PORT Serial
#define _ASYNC_HTTP_LOGLEVEL_ 4

// 300s = 5 minutes to not flooding
#define HTTP_REQUEST_INTERVAL 60 // 300

#define USING_GENERIC true
//#define USING_GENERIC         false

#if USING_GENERIC
#include <AsyncHTTPRequest_Generic.h> // https://github.com/khoih-prog/AsyncHTTPRequest_Generic
#else
#include <asyncHTTPrequest.h>
#define AsyncHTTPRequest asyncHTTPrequest

#define readyStateUnsent 0
#define readyStateDone 4

#endif

#include <Ticker.h>

const char *ssid = "###";
const char *password = "###";

AsyncHTTPRequest request;
Ticker ticker;

void sendRequest()
{
  static bool requestOpenResult;

  if (request.readyState() == readyStateUnsent || request.readyState() == readyStateDone)
  {
    requestOpenResult = request.open("GET", "http://192.168.178.62/cm?cmnd=Power");
    // requestOpenResult = request.open("GET", "http://exampleasynchttp.com/index.html");
    // requestOpenResult = request.open("GET", "http://worldtimeapi.org/api/timezone/America/Toronto.txt");

    if (requestOpenResult)
    {
      // Only send() if open() returns true, or crash
      Serial.println(F("Send request"));

      request.send();
    }
    else
    {
      Serial.println(F("Can't send bad request"));
    }
  }
  else
  {
    Serial.println(F("Can't send request"));
  }
}

void requestCB(void *optParm, AsyncHTTPRequest *request, int readyState)
{
  (void)optParm;

  if (readyState == readyStateDone)
  {
    AHTTP_LOGERROR(F("**************************************"));
    AHTTP_LOGERROR1(F("Response Code = "), request->responseHTTPString());

    if (request->responseHTTPcode() == 200)
    {
      Serial.println(F("**************************************"));
      Serial.println(request->responseText());
      Serial.println(F("**************************************"));
    }
    else
    {
      AHTTP_LOGERROR(F("Response error"));
    }
  }
}

void setup()
{
  Serial.begin(115200);
  while (!Serial && millis() < 5000)
    ;

  Serial.print(F("\nStarting AsyncHTTPRequest_Test using "));
  Serial.println(ARDUINO_BOARD);
  Serial.println(ASYNC_HTTP_REQUEST_GENERIC_VERSION);

  WiFi.mode(WIFI_STA);

  WiFi.begin(ssid, password);

  Serial.print(F("Connecting to WiFi"));

  while (WiFi.status() != WL_CONNECTED)
  {
    delay(500);
    Serial.print(F("."));
  }

  Serial.print(F("\nAsyncHTTPRequest @ IP : "));
  Serial.println(WiFi.localIP());

  request.setDebug(true);

  request.onReadyStateChange(requestCB);
  // ticker.attach(HTTP_REQUEST_INTERVAL, sendRequest);

  // Send first request now
  sendRequest();
}

void loop()
{
}

---

Here are the results:

1.) Using correct hostname http://worldtimeapi.org -> works fine (no need to attach log here)

2.) Using bad IP Address http://192.168.178.62/cm?cmnd=Power -> "not connected" response comes only after 18 seconds

09:44:38.256 > Starting AsyncHTTPRequest_Test using DOIT ESP32 DEVKIT V1
09:44:38.259 > AsyncHTTPRequest_Generic v1.9.0
09:44:38.385 > Connecting to WiFi.....
09:44:40.886 > AsyncHTTPRequest @ IP : 192.168.178.41
09:44:40.889 > [AHTTP] setDebug( on ) version AsyncHTTPRequest_Generic v1.9.0
09:44:40.895 > [AHTTP] open( GET , url = http://192.168.178.62/cm?cmnd=Power
09:44:40.900 > [AHTTP] _parseURL(): scheme+host HTTP:// 192.168.178.62
09:44:40.905 > [AHTTP] _parseURL(): port+path+query 80 /cm ?cmnd=Power
09:44:40.910 > [AHTTP] open: connecting to hostname = 192.168.178.62:80
09:44:40.915 > [AHTTP] _connect()
09:44:40.917 > [AHTTP] _client->connecting to 192.168.178.62 , 80
09:44:40.921 > [AHTTP] client.connect OK to 192.168.178.62 , 80
09:44:40.926 > [AHTTP] _connect() true
09:44:40.928 > Send request
09:44:40.929 > [AHTTP] send()
09:44:40.931 > [AHTTP] _buildRequest()
09:44:40.933 > [AHTTP] _HTTPmethod = 0
09:44:40.935 > [AHTTP] GET  /cm ?cmnd=Power HTTP/1.1
09:44:40.938 >
09:44:40.939 > [AHTTP] host : 192.168.178.62:80
09:44:40.942 >
09:44:40.942 > [AHTTP] _send(), _request->available = 55
09:44:40.945 > [AHTTP] !connected yet
09:44:59.173 > [AHTTP] _onError handler error = Connection aborted
09:44:59.178 > [AHTTP]
09:44:59.179 > _onDisconnect handler
09:44:59.181 > [AHTTP] HTTPCODE_NOT_CONNECTED
09:44:59.185 > [AHTTP] _onDisconnect: _HTTPcode = -4
09:44:59.187 > [AHTTP] _onDisconnect: _HTTPcode = NOT_CONNECTED
09:44:59.191 > [AHTTP] _setReadyState : 4
09:44:59.195 > [AHTTP] **************************************
09:44:59.198 > [AHTTP] Response Code =  NOT_CONNECTED
09:44:59.202 > [AHTTP] Response error

3.) Using bad hostname http://exampleasynchttp.com/index.html -> works fine too

09:47:27.798 > Starting AsyncHTTPRequest_Test using DOIT ESP32 DEVKIT V1
09:47:27.803 > AsyncHTTPRequest_Generic v1.9.0
09:47:27.929 > Connecting to WiFi.....
09:47:30.430 > AsyncHTTPRequest @ IP : 192.168.178.41
09:47:30.433 > [AHTTP] setDebug( on ) version AsyncHTTPRequest_Generic v1.9.0  
09:47:30.439 > [AHTTP] open( GET , url = http://exampleasynchttp.com/index.html
09:47:30.445 > [AHTTP] _parseURL(): scheme+host HTTP:// exampleasynchttp.com 
09:47:30.450 > [AHTTP] _parseURL(): port+path+query 80 /index.html
09:47:30.455 > [AHTTP] open: connecting to hostname = exampleasynchttp.com:80
09:47:30.460 > [AHTTP] _connect()
09:47:30.462 > [AHTTP] _client->connecting to exampleasynchttp.com , 80
09:47:30.467 > [AHTTP] client.connect OK to exampleasynchttp.com , 80  
09:47:30.472 > [AHTTP] _connect() true
09:47:30.474 > Send request
09:47:30.475 > [AHTTP] send()
09:47:30.477 > [AHTTP] _buildRequest()[AHTTP] 
09:47:30.480 > [AHTTP] _onError handler error =_HTTPmethod = DNS failed 0
09:47:30.485 > [AHTTP]
09:47:30.486 > [AHTTP] GET  /index.html
09:47:30.488 > _onDisconnect handler
09:47:30.490 > HTTP/1.1
09:47:30.491 >
09:47:30.491 > [AHTTP] host : exampleasynchttp.com:80
09:47:30.495 >
09:47:30.495 > [AHTTP] _send(), _request->available = 58
09:47:30.499 > [AHTTP] !connected yet
09:47:30.501 > [AHTTP] HTTPCODE_NOT_CONNECTED
09:47:30.504 > [AHTTP] _onDisconnect: _HTTPcode = -4
09:47:30.507 > [AHTTP] _onDisconnect: _HTTPcode = NOT_CONNECTED
09:47:30.511 > [AHTTP] _setReadyState : 4
09:47:30.514 > [AHTTP] **************************************
09:47:30.518 > [AHTTP] Response Code =  NOT_CONNECTED
09:47:30.521 > [AHTTP] Response error

---

Look closely on the timestamps in both logs. If requesting the bad ip address the lines

[AHTTP] Response Code =  NOT_CONNECTED
[AHTTP] Response error

are delayed by 18 seconds... this does not occur when requesting the bad hostname.

Do you have an idea why this is happening?

[khoih-prog]

Please read previous answer

Using bad IPAddress http://192.168.178.62/cm?cmnd=Power

00:36:57.012 -> Starting AsyncHTTPRequest_Test using ESP32_DEV
00:36:57.012 -> AsyncHTTPRequest_Generic v1.9.0
00:36:57.112 -> Connecting to WiFi SSID: HueNet1
00:36:57.609 -> ...
00:36:58.636 -> AsyncHTTPRequest @ IP : 192.168.2.109
00:36:58.636 -> Send request
00:36:58.636 -> [AHTTP] **************************************
00:36:58.636 -> [AHTTP] Response Code =  NOT_CONNECTED
00:36:58.636 -> [AHTTP] Response error
00:37:16.878 -> [AHTTP] _onError handler error = Connection aborted    <==== Controlled by AsyncTCP library

This case, Response error right away. But Connection aborted is controlled by AsyncTCP library and delay by 18s

---

Sorry I won't spend any more time on this special / not-popular use case.
I'm sure the original asyncHTTPrequest library has the same issue

As you're using ESP32, post the issue there if you're still interested.

[miwied]

@khoih-prog Ok. In my case the Response error unfortunately does not comes right away.. it is also delayed by 18 seconds. I thought you maybe know why. Thanks anyways ☹️