TLS reconnect not performed cleanly

[capedra]

Hello, I've been trying to use the sketch from the following URL on Wemos D1 Mini Pro: (https://github.com/electronicsguy/ESP8266/blob/master/HTTPSRedirect/GoogleDocs.ino)

It happens that this same sketch works well on SDK 2.3.0 but, on the other hand, on SDK 2.4.0-rc1 the SSL handshake doesn't work for the host script.googleusercontent.com when it's redirecting, because SSL.h is returning -1 when the function ssl_handshake_status is called on _connectSSL method.

Would like to know why, @igrr . Thanks.

[igrr]

Can you set "debug level" to "Core + SSL", add Serial.setDebugOutput(true);, and post the resulting serial log?

[electronicsguy]

@capedra also, please post the sketch that you're using, in case you've made changes.

[capedra]

@electronicsguy It's the same sketch from there. I didn't make any changes.

[capedra]

@igrr Sure, here's the output:

Free heap before: 34880
unmodified stack   = 3888

Connecting to wifi: APJ15
sta config unchangedscandone
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 4
cnt 
.
connected with APJ15, channel 11
dhcp client start...
..............ip:192.168.254.76,mask:255.255.255.0,gw:192.168.254.254
.
WiFi connected
IP address: 
192.168.254.76
Connecting to script.google.com
:ref 1
please start sntp first !
State:	sending Client Hello (1)
:wr 104 104 0
:wrc 104 104 0
:sent 104
:rn 1452
:rd 5, 1452, 0
:rdi 1452, 5
:rd 74, 1452, 5
:rdi 1447, 74
State:	receiving Server Hello (2)
:rd 5, 1452, 79
:rdi 1373, 5
:rch 1452, 596
:rch 2048, 1452
:rch 3500, 596
:rch 4096, 80

:rd 4083, 4176, 84
:rdi 1368, 1368
:c 1368, 1452, 4176
:rdi 596, 596
:c 596, 596, 2724
:rdi 1452, 1452
:c 1452, 1452, 2128
:rdi 596, 596
:c 596, 596, 676
:rdi 80, 71
State:	receiving Certificate (11)
:rd 5, 80, 71
:rdi 9, 5
:rd 4, 80, 76
:rdi 4, 4
:c0 4, 80
State:	receiving Server Hello Done (14)
State:	sending Client Key Exchange (16)
:wr 267 267 0
:wrc 256 267 0
:wrc 11 11 0
:wr 6 6 0
:wrc 6 6 0
State:	sending Finished (16)
:wr 69 69 0
:wrc 69 69 0
:sent 267
:sent 75
:rn 75
:rd 5, 75, 0
:rdi 75, 5
:rd 1, 75, 5
:rdi 70, 1
:rd 5, 75, 6
:rdi 69, 5
:rd 64, 75, 11
:rdi 64, 64
:c0 64, 75
State:	receiving Finished (16)
domain name: 'script.google.com'
Certificate match.
:wr 357 357 0
:wrc 256 357 0
:wrc 101 101 0
:sent 357
:rn 1452
:rd 5, 1452, 0
:rdi 1452, 5
:rd 1447, 1452, 5
:rdi 1447, 1447
:c0 1447, 1452
:rn 596
:rch 596, 106
:rd 121, 702, 0
:rdi 596, 121
:wcs ra 1516
:ur 1
:close
:del
:ref 1
:wr 53 53 0
:wrc 53 53 0
Alert: close notify
please start sntp first !
State:	sending Client Hello (1)
:wr 115 115 0
:wrc 115 115 0
:sent 53
:rn 7
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
Alert: decode error
Error: SSL error 50
:wr 7 7 0
:wrc 7 7 0
Alert::rcl
:abort
 unexpected message
Alert: close notify
Connection to re-directed URL failed!
Error! Not connected to host.

GET: Write into cell 'A1'
=========================
Error! Not connected to host.
Error! Not connected to host.

GET: Fetch Google Calendar Data:
================================
Error! Not connected to host.
Error! Not connected to host.

Series of GET and POST requests
===============================
Free heap: 32984
unmodified stack   = 2032
:ur 1
:del
:ref 1
please start sntp first !
State:	sending Client Hello (1)
:wr 104 104 0
:wrc 104 104 0
:sent 104
:rn 1452
:rd 5, 1452, 0
:rdi 1452, 5
:rd 74, 1452, 5
:rdi 1447, 74
State:	receiving Server Hello (2)
:rd 5, 1452, 79
:rdi 1373, 5
:rch 1452, 596
:rch 2048, 1452
:rch 3500, 596

:rd 4012, 4096, 84
:rdi:rch 4096, 80
 1368, 1368
:c 1368, 1452, 4176
:rdi 596, 596
:c 596, 596, 2724
:rdi 1452, 1452
:c 1452, 1452, 2128
:rdi 596, 596
:c 596, 596, 676
:rd 71, 80, 0
:rdi 80, 71
State:	receiving Certificate (11)
:rd 5, 80, 71
:rdi 9, 5
:rd 4, 80, 76
:rdi 4, 4
:c0 4, 80
State:	receiving Server Hello Done (14)
State:	sending Client Key Exchange (16)
:wr 267 267 0
:wrc 256 267 0
:wrc 11 11 0
:wr 6 6 0
:wrc 6 6 0
State:	sending Finished (16)
:wr 69 69 0
:wrc 69 69 0
:sent 267
:sent 75
:rn 75
:rd 5, 75, 0
:rdi 75, 5
:rd 1, 75, 5
:rdi 70, 1
:rd 5, 75, 6
:rdi 69, 5
:rd 64, 75, 11
:rdi 64, 64
:c0 64, 75
State:	receiving Finished (16)
:wr 357 357 0
:wrc 256 357 0
:wrc 101 101 0
:sent 357
:rn 1452
:rd 5, 1452, 0
:rdi 1452, 5
:rd 1447, 1452, 5
:rdi 1447, 1447
:c0 1447, 1452
:rn 121
:rch 121, 581
:rd 121, 702, 0
:rdi 121, 121
:c 121, 121, 702
:wcs ra 1516
:ur 1
:close
:del
:ref 1
:wr 53 53 0
:wrc 53 53 0
Alert: close notify
please start sntp first !
State:	sending Client Hello (1)
:wr 115 115 0
:wrc 115 115 0
:sent 53
:rn 7
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
Alert: decode error
Error: SSL error 50
:wr 7 7 0
:wrc 7 7 0
Alert: un:rcl
:abort
expected message
Alert: close notify
Connection to re-directed URL failed!
GET Data from cell 'A1':
Error! Not connected to host.
POST append memory data to spreadsheet:
Error! Not connected to host.
:ur 1
:del
:ref 1
please start sntp first !
State:	sending Client Hello (1)
:wr 104 104 0
:wrc 104 104 0
:sent 104
:rn 1452
:rd 5, 1452, 0
:rdi 1452, 5
:rd 74, 1452, 5
:rdi 1447, 74
State:	receiving Server Hello (2)
:rd 5, 1452, 79
:rdi 1373, 5
:rch 1452, 596
:rch 2048, 1452
:rch 3500, 596
:rch 4096, 80

:rd 4083, 4176, 84
:rdi 1368, 1368
:c 1368, 1452, 4176
:rdi 596, 596
:c 596, 596, 2724
:rdi 1452, 1452
:c 1452, 1452, 2128
:rdi 596, 596
:c 596, 596, 676
:rdi 80, 71
State:	receiving Certificate (11)
:rd 5, 80, 71
:rdi 9, 5
:rd 4, 80, 76
:rdi 4, 4
:c0 4, 80
State:	receiving Server Hello Done (14)
State:	sending Client Key Exchange (16)
:wr 267 267 0
:wrc 256 267 0
:wrc 11 11 0
:wr 6 6 0
:wrc 6 6 0
State:	sending Finished (16)
:wr 69 69 0
:wrc 69 69 0
:sent 267
:sent 75
:rn 75
:rd 5, 75, 0
:rdi 75, 5
:rd 1, 75, 5
:rdi 70, 1
:rd 5, 75, 6
:rdi 69, 5
:rd 64, 75, 11
:rdi 64, 64
:c0 64, 75
State:	receiving Finished (16)
:wr 357 357 0
:wrc 256 357 0
:wrc 101 101 0
:sent 357
:rn 1452
:rd 5, 1452, 0
:rdi 1452, 5
:rd 1447, 1452, 5
:rdi 1447, 1447
:c0 1447, 1452
:rn 121
:rch 121, 581
:rd 121, 702, 0
:rdi 121, 121
:c 121, 121, 702
:wcs ra 1516
:ur 1
:close
:del
:ref 1
:wr 53 53 0
:wrc 53 53 0
Alert: close notify
please start sntp first !
State:	sending Client Hello (1)
:wr 115 115 0
:wrc 115 115 0
:sent 53
:rn 7
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
Alert: decode error
Error: SSL error 50
:wr 7 7 0
:wrc 7 7 0
A:rcl
:abort
lert: unexpected message
Alert: close notify
Connection to re-directed URL failed!
GET Data from cell 'A1':
Error! Not connected to host.
POST append memory data to spreadsheet:
Error! Not connected to host.
Halting processor...
:ur 1
:del
Final free heap: 33536
Final unmodified stack   = 1776
state: 5 -> 0 (0)
rm 0
del if0
bcn 0
del if1
usl

[electronicsguy]

@capedra I have seen users get errors due to wifi/network configuration too, which is difficult to debug. Could you try using your setup with on a completely different network if possible, and report?

[capedra]

@electronicsguy I just tested with another wifi network from a completely different ISP but the same problem persists. Maybe @CameronRich could help us either.

I think this part describes the problem:

Alert: decode error
Error: SSL error 50
:wr 7 7 0
:wrc 7 7 0
Aler:rcl
:abort
t: unexpected message
Alert: close notify
Connection to re-directed URL failed!
Error! Not connected to host.

[igrr]

Thanks for the log, i think i understand what's going on now.

[igrr]

This should be fixed in 8c3bb69. I wasn't able to verify this using GoogleDocs script, probably because I have not set something up on Google Docs side correctly. Nevertheless, in the simulated case when i call WiFiClientSecure::connect twice in a row, the second call no longer results in the connection being immediately aborted.