[SSL] timeout on second connection

[vlastahajek]

Board

DOIT ESP32 DevKit V1

Device Description

DOIT ESP32 DevKit V1

Hardware Configuration

Not related

Version

v2.0.2

IDE Name

Arduino IDE

Operating System

Windows 10

Flash frequency

80MHz

PSRAM enabled

no

Upload speed

921600

Description

When set HTTPClient::setReuse(false), 2nd https connection fails.

This is a regression from 2.0.1, most probably caused by #5945 in ssl_client.cpp:339, where all fields of sslclient_context are cleared, including handshake_timeout. Second call of start_ssl_client then fails on handshake_timeout.

Sketch

/**
   BasicHTTPSClient.ino

    Created on: 14.10.2018

*/

#include <Arduino.h>

#include <WiFi.h>

#include <HTTPClient.h>

#include <WiFiClientSecure.h>

// This is GandiStandardSSLCA2.pem, the root Certificate Authority that signed 
// the server certifcate for the demo server https://jigsaw.w3.org in this
// example. This certificate is valid until Sep 11 23:59:59 2024 GMT
const char* rootCACertificate = \
"-----BEGIN CERTIFICATE-----\n" \
"MIIF6TCCA9GgAwIBAgIQBeTcO5Q4qzuFl8umoZhQ4zANBgkqhkiG9w0BAQwFADCB\n" \
"iDELMAkGA1UEBhMCVVMxEzARBgNVBAgTCk5ldyBKZXJzZXkxFDASBgNVBAcTC0pl\n" \
"cnNleSBDaXR5MR4wHAYDVQQKExVUaGUgVVNFUlRSVVNUIE5ldHdvcmsxLjAsBgNV\n" \
"BAMTJVVTRVJUcnVzdCBSU0EgQ2VydGlmaWNhdGlvbiBBdXRob3JpdHkwHhcNMTQw\n" \
"OTEyMDAwMDAwWhcNMjQwOTExMjM1OTU5WjBfMQswCQYDVQQGEwJGUjEOMAwGA1UE\n" \
"CBMFUGFyaXMxDjAMBgNVBAcTBVBhcmlzMQ4wDAYDVQQKEwVHYW5kaTEgMB4GA1UE\n" \
"AxMXR2FuZGkgU3RhbmRhcmQgU1NMIENBIDIwggEiMA0GCSqGSIb3DQEBAQUAA4IB\n" \
"DwAwggEKAoIBAQCUBC2meZV0/9UAPPWu2JSxKXzAjwsLibmCg5duNyj1ohrP0pIL\n" \
"m6jTh5RzhBCf3DXLwi2SrCG5yzv8QMHBgyHwv/j2nPqcghDA0I5O5Q1MsJFckLSk\n" \
"QFEW2uSEEi0FXKEfFxkkUap66uEHG4aNAXLy59SDIzme4OFMH2sio7QQZrDtgpbX\n" \
"bmq08j+1QvzdirWrui0dOnWbMdw+naxb00ENbLAb9Tr1eeohovj0M1JLJC0epJmx\n" \
"bUi8uBL+cnB89/sCdfSN3tbawKAyGlLfOGsuRTg/PwSWAP2h9KK71RfWJ3wbWFmV\n" \
"XooS/ZyrgT5SKEhRhWvzkbKGPym1bgNi7tYFAgMBAAGjggF1MIIBcTAfBgNVHSME\n" \
"GDAWgBRTeb9aqitKz1SA4dibwJ3ysgNmyzAdBgNVHQ4EFgQUs5Cn2MmvTs1hPJ98\n" \
"rV1/Qf1pMOowDgYDVR0PAQH/BAQDAgGGMBIGA1UdEwEB/wQIMAYBAf8CAQAwHQYD\n" \
"VR0lBBYwFAYIKwYBBQUHAwEGCCsGAQUFBwMCMCIGA1UdIAQbMBkwDQYLKwYBBAGy\n" \
"MQECAhowCAYGZ4EMAQIBMFAGA1UdHwRJMEcwRaBDoEGGP2h0dHA6Ly9jcmwudXNl\n" \
"cnRydXN0LmNvbS9VU0VSVHJ1c3RSU0FDZXJ0aWZpY2F0aW9uQXV0aG9yaXR5LmNy\n" \
"bDB2BggrBgEFBQcBAQRqMGgwPwYIKwYBBQUHMAKGM2h0dHA6Ly9jcnQudXNlcnRy\n" \
"dXN0LmNvbS9VU0VSVHJ1c3RSU0FBZGRUcnVzdENBLmNydDAlBggrBgEFBQcwAYYZ\n" \
"aHR0cDovL29jc3AudXNlcnRydXN0LmNvbTANBgkqhkiG9w0BAQwFAAOCAgEAWGf9\n" \
"crJq13xhlhl+2UNG0SZ9yFP6ZrBrLafTqlb3OojQO3LJUP33WbKqaPWMcwO7lWUX\n" \
"zi8c3ZgTopHJ7qFAbjyY1lzzsiI8Le4bpOHeICQW8owRc5E69vrOJAKHypPstLbI\n" \
"FhfFcvwnQPYT/pOmnVHvPCvYd1ebjGU6NSU2t7WKY28HJ5OxYI2A25bUeo8tqxyI\n" \
"yW5+1mUfr13KFj8oRtygNeX56eXVlogMT8a3d2dIhCe2H7Bo26y/d7CQuKLJHDJd\n" \
"ArolQ4FCR7vY4Y8MDEZf7kYzawMUgtN+zY+vkNaOJH1AQrRqahfGlZfh8jjNp+20\n" \
"J0CT33KpuMZmYzc4ZCIwojvxuch7yPspOqsactIGEk72gtQjbz7Dk+XYtsDe3CMW\n" \
"1hMwt6CaDixVBgBwAc/qOR2A24j3pSC4W/0xJmmPLQphgzpHphNULB7j7UTKvGof\n" \
"KA5R2d4On3XNDgOVyvnFqSot/kGkoUeuDcL5OWYzSlvhhChZbH2UF3bkRYKtcCD9\n" \
"0m9jqNf6oDP6N8v3smWe2lBvP+Sn845dWDKXcCMu5/3EFZucJ48y7RetWIExKREa\n" \
"m9T8bJUox04FB6b9HbwZ4ui3uRGKLXASUoWNjDNKD/yZkuBjcNqllEdjB+dYxzFf\n" \
"BT02Vf6Dsuimrdfp5gJ0iHRc2jTbkNJtUQoj1iM=\n" \
"-----END CERTIFICATE-----\n";

// Not sure if WiFiClientSecure checks the validity date of the certificate. 
// Setting clock just to be sure...
void setClock() {
  configTime(0, 0, "pool.ntp.org", "time.nist.gov");

  Serial.print(F("Waiting for NTP time sync: "));
  time_t nowSecs = time(nullptr);
  while (nowSecs < 8 * 3600 * 2) {
    delay(500);
    Serial.print(F("."));
    yield();
    nowSecs = time(nullptr);
  }

  Serial.println();
  struct tm timeinfo;
  gmtime_r(&nowSecs, &timeinfo);
  Serial.print(F("Current time: "));
  Serial.print(asctime(&timeinfo));
}



void setup() {

  Serial.begin(115200);
  Serial.setDebugOutput(true);

  Serial.println();

  WiFi.mode(WIFI_STA);
  WiFi.begin("WIFI", "PASSWORD");

  // wait for WiFi connection
  Serial.print("Waiting for WiFi to connect...");
  int i=0;
  while (WiFi.status() != WL_CONNECTED && i<30) {
    Serial.print(".");
    delay(500);
    i++;
  }
  if(WiFi.status() != WL_CONNECTED) {
    Serial.println("WiFi failed");
    ESP.restart();  
  }


  setClock();  
}

void loop() {
  WiFiClientSecure *client = new WiFiClientSecure;
  if(client) {
    client -> setCACert(rootCACertificate);
    {
      // Add a scoping block for HTTPClient https to make sure it is destroyed before WiFiClientSecure *client is 
      HTTPClient https;
      https.setReuse(false);

      for(int i=0;i<2;i++) {
        Serial.printf("[HTTPS] begin %d...\n", i+1);
        if (https.begin(*client, "https://jigsaw.w3.org/HTTP/connection.html")) {  // HTTPS
        
          Serial.print("[HTTPS] GET...\n");
          // start connection and send HTTP header
          int httpCode = https.GET();
    
          // httpCode will be negative on error
          if (httpCode > 0) {
            // HTTP header has been send and Server response header has been handled
            Serial.printf("[HTTPS] GET... code: %d\n", httpCode);
    
            // file found at server
            if (httpCode == HTTP_CODE_OK || httpCode == HTTP_CODE_MOVED_PERMANENTLY) {
             // String payload = https.getString();
              //Serial.println(payload);
            }
          } else {
            Serial.printf("[HTTPS] GET... failed, error: %s\n", https.errorToString(httpCode).c_str());
          }
    
          https.end();
        } else {
          Serial.printf("[HTTPS] Unable to connect\n");
        }

      }
      // End extra scoping block
    }
  
    delete client;
  } else {
    Serial.println("Unable to create client");
  }

  Serial.println();
  Serial.println("Waiting 10s before the next round...");
  delay(10000);
}

Debug Message

[HTTPS] begin 1...
[  7679][V][HTTPClient.cpp:247] beginInternal(): url: https://jigsaw.w3.org/HTTP/connection.html
[  7681][D][HTTPClient.cpp:298] beginInternal(): protocol: https, host: jigsaw.w3.org port: 443 url: /HTTP/connection.html
[HTTPS] GET...
[  7702][D][HTTPClient.cpp:595] sendRequest(): request type: 'GET' redirCount: 0

[  7702][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 264188
[  7708][V][ssl_client.cpp:67] start_ssl_client(): Starting socket
[  7874][V][ssl_client.cpp:143] start_ssl_client(): Seeding the random number generator
[  7876][V][ssl_client.cpp:152] start_ssl_client(): Setting up the SSL/TLS structure...
[  7880][V][ssl_client.cpp:175] start_ssl_client(): Loading CA cert
[  7956][V][ssl_client.cpp:244] start_ssl_client(): Setting hostname for TLS session...
[  7957][V][ssl_client.cpp:259] start_ssl_client(): Performing the SSL/TLS handshake...
[  9308][V][ssl_client.cpp:283] start_ssl_client(): Verifying peer X.509 certificate...
[  9308][V][ssl_client.cpp:291] start_ssl_client(): Certificate verified.
[  9311][V][ssl_client.cpp:306] start_ssl_client(): Free internal heap after TLS 220188
[  9319][D][HTTPClient.cpp:1141] connect():  connected to jigsaw.w3.org:443
[  9326][V][ssl_client.cpp:357] send_ssl_data(): Writing HTTP request with 158 bytes...
[  9518][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'HTTP/1.1 200'
[  9519][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'date: Thu, 20 Jan 2022 21:15:07 GMT'
[  9523][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'content-length: 550'
[  9530][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'content-type: text/html'
[  9538][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'etag: "1giilod:q0efehi8"'
[  9545][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'last-modified: Tue, 20 Jun 2000 13:33:22 GMT'
[  9555][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'server: Jigsaw/2.3.0-beta3'
[  9563][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'extensionheader: ExtensionValue'
[  9571][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'strict-transport-security: max-age=15552015; includeSubDomains; preload'
[  9584][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'public-key-pins: pin-sha256="cN0QSpPIkuwpT6iP2YjEo1bEwGpH/yiUn6yhdy+HNto="; pin-sha256="WGJkyYjx1QMdMe0UqlyOKXtydPDVrk7sl2fV+nNm1r4="; pin-sha256="LrKdTxZLRTvyHM4/atX2nquX9BeHRZMCxg3cf4rhc2I="; max-age=864000'
[  9607][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'x-frame-options: deny'
[  9614][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'x-xss-protection: 1; mode=block'
[  9622][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'x-request-id: 61e9d0dbf67544f5'
[  9631][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: 'connection: close'
[  9638][V][HTTPClient.cpp:1234] handleHeaderResponse(): RX: ''
[  9643][D][HTTPClient.cpp:1275] handleHeaderResponse(): code: 200
[  9649][D][HTTPClient.cpp:1278] handleHeaderResponse(): size: 550
[  9655][D][HTTPClient.cpp:619] sendRequest(): sendRequest code=200

[HTTPS] GET... code: 200
[  9672][D][HTTPClient.cpp:383] disconnect(): still data in buffer (550), clean up.

[  9677][V][ssl_client.cpp:314] stop_ssl_socket(): Cleaning SSL connection.
[  9678][D][HTTPClient.cpp:392] disconnect(): tcp stop
[  9682][V][ssl_client.cpp:314] stop_ssl_socket(): Cleaning SSL connection.
[HTTPS] begin 2...
[  9699][V][HTTPClient.cpp:247] beginInternal(): url: https://jigsaw.w3.org/HTTP/connection.html
[  9700][D][HTTPClient.cpp:298] beginInternal(): protocol: https, host: jigsaw.w3.org port: 443 url: /HTTP/connection.html
[HTTPS] GET...
[  9720][D][HTTPClient.cpp:595] sendRequest(): request type: 'GET' redirCount: 0

[  9720][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 263452
[  9726][V][ssl_client.cpp:67] start_ssl_client(): Starting socket
[  9845][V][ssl_client.cpp:143] start_ssl_client(): Seeding the random number generator
[  9847][V][ssl_client.cpp:152] start_ssl_client(): Setting up the SSL/TLS structure...
[  9850][V][ssl_client.cpp:175] start_ssl_client(): Loading CA cert
[  9927][V][ssl_client.cpp:244] start_ssl_client(): Setting hostname for TLS session...
[  9928][V][ssl_client.cpp:259] start_ssl_client(): Performing the SSL/TLS handshake...
[  9944][E][WiFiClientSecure.cpp:135] connect(): start_ssl_client: -1
[  9951][V][ssl_client.cpp:314] stop_ssl_socket(): Cleaning SSL connection.
[  9957][D][HTTPClient.cpp:1134] connect(): failed connect to jigsaw.w3.org:443
[  9964][W][HTTPClient.cpp:1437] returnError(): error(-1): connection refused
[HTTPS] GET... failed, error: connection refused
[  9982][D][HTTPClient.cpp:405] disconnect(): tcp is closed

[  9982][V][ssl_client.cpp:314] stop_ssl_socket(): Cleaning SSL connection.
[  9987][V][ssl_client.cpp:314] stop_ssl_socket(): Cleaning SSL connection.

Other Steps to Reproduce

No response

I have checked existing issues, online documentation and the Troubleshooting Guide

• I confirm I have checked existing issues, online documentation and Troubleshooting guide.

[VojtechBartoska]

@vlastahajek Thanks for the issue and PR! We will take a look on PR itself.

[hoberman]

Note that this problem can also happen even with HTTPClient::setReuse(true) which is the default setting. Repeated GETs will succeed as long as the server keeps the connection alive. If/when the server ends the connection - which could be several minutes later - subsequent GETs will fail at the same SSL/TLS handshake step.