Skip to content

ESP8266WebServerSecure BearSSL handshakes failing frequently #6247

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

Closed
5 of 6 tasks
thekurtovic opened this issue Jul 2, 2019 · 13 comments
Closed
5 of 6 tasks

ESP8266WebServerSecure BearSSL handshakes failing frequently #6247

thekurtovic opened this issue Jul 2, 2019 · 13 comments
Assignees
Labels
waiting for feedback Waiting on additional info. If it's not received, the issue may be closed.

Comments

@thekurtovic
Copy link

thekurtovic commented Jul 2, 2019

Basic Infos

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

Platform

  • Hardware: ESP-WROOM-02
  • Core Version: 2.5.2-47-g5a47cab7
  • Development Env: Arduino IDE
  • Operating System: Windows

Settings in IDE

  • Module: Generic ESP8266 Module
  • Flash Mode: dout
  • Flash Size: 2MB
  • lwip Variant: v2 Lower Memory
  • Reset Method: ck
  • Flash Frequency: 40Mhz
  • CPU Frequency: 80Mhz
  • Upload Using: SERIAL
  • Upload Speed: 115200

Problem Description

I am trying to migrate from ESP8266WebServer to ESP8266WebServerSecure, and have been able to successfully connect to a soft-AP created by the ESP via HTTPS. I expected the performance to be noticeably slower compared HTTP, but getting a webpage served up to my smartphone seems like it can take quite a while sometimes. I enabled debug messages to the Serial port, with debug level SSL, and noticed I was seeing this message below very often.
BSSL:_wait_for_handshake: failed
This message shows up somewhat regularly after I connect to the AP and request https://192.168.4.1 on my smartphone's browser. I've tried changing the CPU frequency to 160 MHz, and although it does result in pages being served more often, doesn't seem to impact the handshake process. I noticed this while on 2.5.2, but have installed the latest git version as outlined here.

In the MCVE, the page served by the web server contains javascript which refreshes the page to start another request. The "Served root (millis)" messages help roughly calculate how long it took to serve the page, when compared to the previous value.

Am I misunderstanding the context of the "BSSL:_wait_for_handshake: failed" messages? Based on the debug messages, it appears as if the ESP has occasional moments where the handshakes occur seamlessly.

MCVE Sketch

#include <ESP8266WiFi.h>
#include <ESP8266WebServerSecure.h>
#include <DNSServer.h>

ESP8266WebServerSecure server(443);
DNSServer dnsServer;
#define DNS_PORT    53
#define AP_NAME     "AP_HTTPS_TEST"
#define AP_PASS     ""
#define AP_IP       192,168,4,1
#define AP_SUBNET   255,255,255,0
#define AP_PAGE     "<script>setTimeout(function(){ location.reload();}, 1000);</script><h1>%u</h1>"

uint16_t count = 0;

static const char serverCert[] PROGMEM = R"EOF(
-----BEGIN CERTIFICATE-----
MIIDSzCCAjMCCQD2ahcfZAwXxDANBgkqhkiG9w0BAQsFADCBiTELMAkGA1UEBhMC
VVMxEzARBgNVBAgMCkNhbGlmb3JuaWExFjAUBgNVBAcMDU9yYW5nZSBDb3VudHkx
EDAOBgNVBAoMB1ByaXZhZG8xGjAYBgNVBAMMEXNlcnZlci56bGFiZWwuY29tMR8w
HQYJKoZIhvcNAQkBFhBlYXJsZUB6bGFiZWwuY29tMB4XDTE4MDMwNjA1NDg0NFoX
DTE5MDMwNjA1NDg0NFowRTELMAkGA1UEBhMCQVUxEzARBgNVBAgMClNvbWUtU3Rh
dGUxITAfBgNVBAoMGEludGVybmV0IFdpZGdpdHMgUHR5IEx0ZDCCASIwDQYJKoZI
hvcNAQEBBQADggEPADCCAQoCggEBAPVKBwbZ+KDSl40YCDkP6y8Sv4iNGvEOZg8Y
X7sGvf/xZH7UiCBWPFIRpNmDSaZ3yjsmFqm6sLiYSGSdrBCFqdt9NTp2r7hga6Sj
oASSZY4B9pf+GblDy5m10KDx90BFKXdPMCLT+o76Nx9PpCvw13A848wHNG3bpBgI
t+w/vJCX3bkRn8yEYAU6GdMbYe7v446hX3kY5UmgeJFr9xz1kq6AzYrMt/UHhNzO
S+QckJaY0OGWvmTNspY3xCbbFtIDkCdBS8CZAw+itnofvnWWKQEXlt6otPh5njwy
+O1t/Q+Z7OMDYQaH02IQx3188/kW3FzOY32knER1uzjmRO+jhA8CAwEAATANBgkq
hkiG9w0BAQsFAAOCAQEAnDrROGRETB0woIcI1+acY1yRq4yAcH2/hdq2MoM+DCyM
E8CJaOznGR9ND0ImWpTZqomHOUkOBpvu7u315blQZcLbL1LfHJGRTCHVhvVrcyEb
fWTnRtAQdlirUm/obwXIitoz64VSbIVzcqqfg9C6ZREB9JbEX98/9Wp2gVY+31oC
JfUvYadSYxh3nblvA4OL+iEZiW8NE3hbW6WPXxvS7Euge0uWMPc4uEcnsE0ZVG3m
+TGimzSdeWDvGBRWZHXczC2zD4aoE5vrl+GD2i++c6yjL/otHfYyUpzUfbI2hMAA
5tAF1D5vAAwA8nfPysumlLsIjohJZo4lgnhB++AlOg==
-----END CERTIFICATE-----
)EOF";

static const char serverKey[] PROGMEM =  R"EOF(
-----BEGIN RSA PRIVATE KEY-----
MIIEpQIBAAKCAQEA9UoHBtn4oNKXjRgIOQ/rLxK/iI0a8Q5mDxhfuwa9//FkftSI
IFY8UhGk2YNJpnfKOyYWqbqwuJhIZJ2sEIWp2301OnavuGBrpKOgBJJljgH2l/4Z
uUPLmbXQoPH3QEUpd08wItP6jvo3H0+kK/DXcDzjzAc0bdukGAi37D+8kJfduRGf
zIRgBToZ0xth7u/jjqFfeRjlSaB4kWv3HPWSroDNisy39QeE3M5L5ByQlpjQ4Za+
ZM2yljfEJtsW0gOQJ0FLwJkDD6K2eh++dZYpAReW3qi0+HmePDL47W39D5ns4wNh
BofTYhDHfXzz+RbcXM5jfaScRHW7OOZE76OEDwIDAQABAoIBAQDKov5NFbNFQNR8
djcM1O7Is6dRaqiwLeH4ZH1pZ3d9QnFwKanPdQ5eCj9yhfhJMrr5xEyCqT0nMn7T
yEIGYDXjontfsf8WxWkH2TjvrfWBrHOIOx4LJEvFzyLsYxiMmtZXvy6YByD+Dw2M
q2GH/24rRdI2klkozIOyazluTXU8yOsSGxHr/aOa9/sZISgLmaGOOuKI/3Zqjdhr
eHeSqoQFt3xXa8jw01YubQUDw/4cv9rk2ytTdAoQUimiKtgtjsggpP1LTq4xcuqN
d4jWhTcnorWpbD2cVLxrEbnSR3VuBCJEZv5axg5ZPxLEnlcId8vMtvTRb5nzzszn
geYUWDPhAoGBAPyKVNqqwQl44oIeiuRM2FYenMt4voVaz3ExJX2JysrG0jtCPv+Y
84R6Cv3nfITz3EZDWp5sW3OwoGr77lF7Tv9tD6BptEmgBeuca3SHIdhG2MR+tLyx
/tkIAarxQcTGsZaSqra3gXOJCMz9h2P5dxpdU+0yeMmOEnAqgQ8qtNBfAoGBAPim
RAtnrd0WSlCgqVGYFCvDh1kD5QTNbZc+1PcBHbVV45EmJ2fLXnlDeplIZJdYxmzu
DMOxZBYgfeLY9exje00eZJNSj/csjJQqiRftrbvYY7m5njX1kM5K8x4HlynQTDkg
rtKO0YZJxxmjRTbFGMegh1SLlFLRIMtehNhOgipRAoGBAPnEEpJGCS9GGLfaX0HW
YqwiEK8Il12q57mqgsq7ag7NPwWOymHesxHV5mMh/Dw+NyBi4xAGWRh9mtrUmeqK
iyICik773Gxo0RIqnPgd4jJWN3N3YWeynzulOIkJnSNx5BforOCTc3uCD2s2YB5X
jx1LKoNQxLeLRN8cmpIWicf/AoGBANjRSsZTKwV9WWIDJoHyxav/vPb+8WYFp8lZ
zaRxQbGM6nn4NiZI7OF62N3uhWB/1c7IqTK/bVHqFTuJCrCNcsgld3gLZ2QWYaMV
kCPgaj1BjHw4AmB0+EcajfKilcqtSroJ6MfMJ6IclVOizkjbByeTsE4lxDmPCDSt
/9MKanBxAoGAY9xo741Pn9WUxDyRplww606ccdNf/ksHWNc/Y2B5SPwxxSnIq8nO
j01SmsCUYVFAgZVOTiiycakjYLzxlc6p8BxSVqy6LlJqn95N8OXoQ+bkwUux/ekg
gz5JWYhbD6c38khSzJb0pNXCo3EuYAVa36kDM96k1BtWuhRS10Q1VXk=
-----END RSA PRIVATE KEY-----
)EOF";

void setup(void) {
    Serial.begin(115200);
    Serial.println("\n\nConfiguring AP");
    IPAddress ip(AP_IP);
    IPAddress subnet(AP_SUBNET);
    WiFi.softAP(AP_NAME, AP_PASS);
    WiFi.softAPConfig(ip, ip, subnet);

    dnsServer.setErrorReplyCode(DNSReplyCode::NoError);
    dnsServer.start(DNS_PORT, "*", ip); 
  
    server.setRSACert(new X509List(serverCert), new PrivateKey(serverKey));
    server.on("/", []() {
        char buf[256];
        sprintf(buf, AP_PAGE, ++count);
        server.send(200, "text/html", buf);
        Serial.printf("Served root (%lu)\n", millis());
    });
    server.begin();
    Serial.println("HTTPS server started");
}

void loop() {
    server.handleClient();
    dnsServer.processNextRequest();
}

Debug Messages

@80 MHz
Configuring AP
HTTPS server started
add 1
aid 1
station: 24:92:0e:2c:c6:aa join, AID = 1
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
Served root (44541)
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
Served root (54183)
Served root (60111)
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
Served root (94620)
Served root (99540)
Served root (102922)
Served root (106318)
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
Served root (129950)


@160 MHz
Configuring AP
HTTPS server started
add 1
aid 1
station: 24:92:0e:2c:c6:aa join, AID = 1
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
Served root (54877)
BSSL:_wait_for_handshake: failed
Served root (60116)
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
Served root (75023)
Served root (76767)
Served root (78498)
Served root (80312)
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
Served root (94369)
Served root (96113)
Served root (97853)
Served root (101338)
BSSL:_wait_for_handshake: failed
Served root (104597)
Served root (106353)
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
BSSL:_wait_for_handshake: failed
Served root (120473)
@earlephilhower
Copy link
Collaborator

Please enable full debug and post some output from the failing connects. This is not happening to most people, so without logs (which should give the reason for failure) there's not really anything to go on.

@earlephilhower earlephilhower added the waiting for feedback Waiting on additional info. If it's not received, the issue may be closed. label Jul 6, 2019
@thekurtovic
Copy link
Author

thekurtovic commented Jul 6, 2019

Sorry about that, I decided to change the debug level from full to SSL before opening the issue for brevity, though admittedly that was counterproductive.

Just as a minor update, I am now testing this with the core version below.
Core Version: 2.5.2-47-g3f0f2143

As soon as I updated the latest git version, and modified the MCVE accordingly, I noticed a huge difference. Looks like I can get pages served in about 2 seconds now! I did notice some of those BSSL:_wait_for_handshake: failed messages were still showing up however.

Debug Messages

station: 24:92:0e:2c:c6:aa join, AID = 1
wifi evt: 5
wifi evt: 9
:urn 47
:urch 71, 47
:urd 47, 47, 0
:urd 47, 47, 0
wifi evt: 7
wifi evt: 7
wifi evt: 7
wifi evt: 7
:urn 34
:urd 34, 34, 0
wifi evt: 7
:urn 39
:urd 39, 39, 0
:urn 39
:urd 39, 39, 0
WS:ac
:ref 1
:rn 172
:rd 5, 172, 0
:rdi 172, 5
:rd 167, 172, 5
:rdi 167, 167
:c0 167, 172
:urn 47
:urch 71, 47
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:ack 17
:rn 7
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
:close
WS:dis
:del
WS:av
:urd 47, 47, 0
:urd 47, 47, 0
:urn 32
:urd 32, 32, 0
:urn 36
:urd 36, 36, 0
:urn 39
:urd 39, 39, 0
WS:ac
:ref 1
:rn 172
:rd 5, 172, 0
:rdi 172, 5
:rd 167, 172, 5
:rdi 167, 167
:c0 167, 172
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:ack 17
:rn 7
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
:close
WS:dis
:del
WS:av
:urn 41
:urd 41, 41, 0
WS:ac
:ref 1
:rn 189
:rd 5, 189, 0
:rdi 189, 5
:rd 184, 189, 5
:rdi 184, 184
:c0 184, 189
:wr 517 0
:wrc 517 517 0
:wr 50 0
:wrc 50 50 0
:ack 517
:ack 50
:rn 7
:rd 5, 7, 0
:rdi 7, 5
:er -14 0x00000000
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
WS:dis
:del
WS:av
WS:ac
:ref 1
:rn 189
:rd 5, 189, 0
:rdi 189, 5
:rd 184, 189, 5
:rdi 184, 184
:c0 184, 189
:wr 517 0
:wrc 517 517 0
:wr 50 0
:wrc 50 50 0
:ack 517
:ack 50
:rn 7
:er -14 0x00000000
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
WS:dis
:del
WS:av
:urn 37
:urd 37, 37, 0
WS:ac
:ref 1
:rn 517
:rd 5, 517, 0
:rdi 517, 5
:rd 512, 517, 5
:rdi 512, 512
:c0 512, 517
:urn 48
:rcl
:abort
:urch 72, 37
BSSL:_wait_for_handshake: failed
:ur 1
WS:dis
:del
WS:av
:urd 48, 48, 0
:urd 37, 37, 0
WS:ac
:ref 1
:rn 517
:rd 5, 517, 0
:rdi 517, 5
:rd 512, 517, 5
:rdi 512, 512
:c0 512, 517
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:ack 17
:urn 41
:rn 7
:er -14 0x00000000
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
WS:dis
:del
WS:av
:urd 41, 41, 0
:urn 45
:urd 45, 45, 0
WS:ac
:ref 1
:rn 193
:rd 5, 193, 0
:rdi 193, 5
:rd 188, 193, 5
:rdi 188, 188
:c0 188, 193
WS:ac
:rn 517
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:ack 17
:rn 7
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
:close
WS:dis
:del
WS:av
:ref 1
:rd 5, 517, 0
:rdi 517, 5
:rd 512, 517, 5
:rdi 512, 512
:c0 512, 517
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:rn 7
:rcl
:abort
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
WS:dis
:del
WS:av
:urn 36
:urd 36, 36, 0
WS:ac
:ref 1
:rn 517
:rd 5, 517, 0
:rdi 517, 5
:rd 512, 517, 5
:rdi 512, 512
:c0 512, 517
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:ack 17
:rn 7
:er -14 0x00000000
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
WS:dis
:del
WS:av
wifi evt: 7
wifi evt: 7
WS:ac
:rn 517
:ref 1
:rd 5, 517, 0
:rdi 517, 5
:rd 512, 517, 5
:rdi 512, 512
:c0 512, 517
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:rn 7
:rcl
:abort
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
WS:dis
:del
WS:av
:urn 30
:urch 54, 33
:urch 111, 28
:urd 30, 30, 0
:urd 33, 33, 0
:urd 28, 28, 0
WS:ac
WS:ac
:ref 1
:rn 517
:rn 517
:rd 5, 517, 0
:rdi 517, 5
:rd 512, 517, 5
:rdi 512, 512
:c0 512, 517
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:ack 17
:rn 7
:er -14 0x00000000
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
WS:dis
:del
WS:av
:ref 1
:rd 5, 517, 0
:rdi 517, 5
:rd 512, 517, 5
:rdi 512, 512
:c0 512, 517
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:rn 7
:rcl
:abort
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
WS:dis
:del
WS:av
:urn 39
:urd 39, 39, 0
WS:ac
:ref 1
WS:ac
:rn 517
WS:ac
:rn 517
:rn 172
:rd 5, 172, 0
:rdi 172, 5
:rd 167, 172, 5
:rdi 167, 167
:c0 167, 172
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:ack 17
:rn 7
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
:close
WS:dis
:del
WS:av
:ref 1
:rd 5, 517, 0
:rdi 517, 5
:rd 512, 517, 5
:rdi 512, 512
:c0 512, 517
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:rn 7
:rcl
:abort
:rd 5, 7, 0
:rdi 7, 5
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
WS:dis
:del
WS:av
:ref 1
:rd 5, 517, 0
:rdi 517, 5
:rd 512, 517, 5
:rdi 512, 512
:c0 512, 517
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:rn 7
:rcl
:abort
:rd 5, 7, 0
:rdi 7, 5
WS:ac
:rn 517
:rd 2, 7, 5
:rdi 2, 2
:c0 2, 7
BSSL:_wait_for_handshake: failed
:ur 1
WS:dis
:del
WS:av
:ref 1
:rd 5, 517, 0
:rdi 517, 5
:rd 512, 517, 5
:rdi 512, 512
:c0 512, 517
:wr 517 0
:wrc 517 517 0
:wr 17 0
:wrc 17 17 0
:ack 517
:ack 17
:rn 85
:rd 5, 85, 0
:rdi 85, 5
:rd 37, 85, 5
:rdi 80, 37
:rd 5, 85, 42
:rdi 43, 5
:rd 1, 85, 47
:rdi 38, 1
:rd 5, 85, 48
:rdi 37, 5
:rd 32, 85, 53
:rdi 32, 32
:c0 32, 85
:wr 6 0
:wrc 6 6 0
:wr 37 0
:wrc 37 37 0
WS:av
:ref 2
:ur 2
:ref 2
:ur 2
New client
:ref 2
:ur 2
:ack 6
:ack 37
:rn 498
:rd 5, 498, 0
:rdi 498, 5
:rd 493, 498, 5
:rdi 493, 493
:c0 493, 498
request: GET / HTTP/1.1
method: GET url: / search: 
headerName: Host
headerValue: 192.168.4.1
headerName: Connection
headerValue: keep-alive
headerName: Cache-Control
headerValue: max-age=0
headerName: Upgrade-Insecure-Requests
headerValue: 1
headerName: User-Agent
headerValue: Mozilla/5.0 (Linux; Android 6.0.1; SM-J120W) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/75.0.3770.101 Mobile Safari/537.36
headerName: Accept
headerValue: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3
headerName: Accept-Encoding
headerValue: gzip, deflate, br
headerName: Accept-Language
headerValue: en-CA,en-GB;q=0.9,en-US;q=0.8,en;q=0.7
args: 
args count: 0
args: 
args count: 0
Request: /
Arguments: 
final list of key/value pairs:
:wr 104 0
:wrc 104 104 0
:ack 104
:wr 98 0
:wrc 98 98 0
:ack 98
:rcl
:abort
Served root (67373)

@earlephilhower
Copy link
Collaborator

Looks good to me on the latest logs. I'd also recommend making sure you're at 160MHz ad 80MHz is pretty marginal in terms of speed and some clients or servers will drop the connection because the handshake takes too long.

There have been some BearSSL updates as well, thanks to @s-hadinger , which sped things up, which might be the reason you're doing so well now.

I think we can close this for now, and can reopen it should something else pop up later.

@avrhack
Copy link

avrhack commented Jul 10, 2019

I have exactly this issue on a NodeMCU v2 and it's a killer. Saying we should go to 160MHz processor is not the answer; effectively you're saying that TLS is no longer possible on the 80MHz esp8266?

@earlephilhower
Copy link
Collaborator

The SSL server was always marginal at 80MHz. I should know, I wrote it back when axtls was the only game in town. :)

As always, try with Git head. @s-hadinger did some optimizations to BearSSL EC paths. Also you can reduce the ciphers to the faster but less secure ones, which makes BearSSL faster than axtls. 160MHz makes lots of things better and is not as large a power drain as you might think (the WiFi PA is probably more energy than this tiny core...)

@avrhack
Copy link

avrhack commented Jul 10, 2019

Yes tried the git head and made no difference - but that's because the problem was my own utter incompetence :)

Now that I found the fact the TLS fingerprinting mechanism changed and fixed the fingerprint all seems fine, even with an 80MHz part.

But thanks for coming back so quickly. Cheers.

@CyanoFresh
Copy link

Same problem :( I've used HelloServerBearSSL.ino example. Event tried removing mdns - result is the same:
2 errors of BSSL:_wait_for_handshake: failed but finally connects after 5 seconds of delay. Can it be faster?
160MHz, latest esp8266/Arduino

01:34:32.797 -> SDK:2.2.2-dev(38a443e)/Core:2.5.2-103-ga8873c23=20502103/lwIP:STABLE-2_1_2_RELEASE/glue:1.1-8-g2314329/BearSSL:89454af
01:34:32.872 -> scandone
01:34:32.872 -> 
01:34:32.872 -> wifi evt: 2
01:34:33.368 -> .....scandone
01:34:36.654 -> state: 0 -> 2 (b0)
01:34:36.654 -> .state: 2 -> 3 (0)
01:34:36.654 -> state: 3 -> 5 (10)
01:34:36.654 -> add 0
01:34:36.654 -> aid 7
01:34:36.654 -> cnt 
01:34:36.654 -> state: 5 -> 2 (1a0)
01:34:36.654 -> rm 0
01:34:36.654 -> wifi evt: 1
01:34:36.691 -> STA disconnect: 1
01:34:37.151 -> ..reconnect
01:34:37.687 -> state: 2 -> 0 (0)
01:34:37.799 -> scandone
01:34:37.799 -> state: 0 -> 2 (b0)
01:34:37.799 -> state: 2 -> 3 (0)
01:34:37.799 -> state: 3 -> 5 (10)
01:34:37.799 -> add 0
01:34:37.799 -> aid 7
01:34:37.799 -> cnt 
01:34:37.834 -> 
01:34:37.834 -> connected with HUAWEI-D190, channel 6
01:34:37.834 -> dhcp client start...
01:34:37.834 -> wifi evt: 0
01:34:38.150 -> ............ip:192.168.8.113,mask:255.255.255.0,gw:192.168.8.1
01:34:43.712 -> wifi evt: 3
01:34:44.171 -> .
01:34:44.171 -> Connected to HUAWEI-D190
01:34:44.171 -> IP address: 192.168.8.113
01:34:44.246 -> HTTPS server started
01:35:00.824 -> WS:ac
01:35:00.824 -> WS:ac
01:35:00.824 -> :ref 1
01:35:00.824 -> :rn 517
01:35:00.824 -> :rn 517
01:35:00.824 -> :rd 5, 517, 0
01:35:00.824 -> :rdi 517, 5
01:35:00.824 -> :rd 512, 517, 5
01:35:00.824 -> :rdi 512, 512
01:35:00.824 -> :c0 512, 517
01:35:00.857 -> :wr 517 0
01:35:00.857 -> :wrc 517 517 0
01:35:01.745 -> :ack 517
01:35:02.577 -> :wr 517 0
01:35:02.577 -> :wrc 517 517 0
01:35:02.577 -> :wr 223 0
01:35:02.577 -> :wrc 223 223 0
01:35:02.577 -> :ack 517
01:35:02.577 -> :rn 7
01:35:02.577 -> :rcl
01:35:02.577 -> :abort
01:35:02.577 -> :rd 5, 7, 0
01:35:02.577 -> :rdi 7, 5
01:35:02.577 -> :rd 2, 7, 5
01:35:02.612 -> :rdi 2, 2
01:35:02.612 -> :c0 2, 7
01:35:02.612 -> BSSL:_wait_for_handshake: failed
01:35:02.612 -> :ur 1
01:35:02.612 -> WS:dis
01:35:02.612 -> :del
01:35:02.612 -> WS:av
01:35:02.612 -> :ref 1
01:35:02.612 -> :rd 5, 517, 0
01:35:02.612 -> :rdi 517, 5
01:35:02.612 -> :rd 512, 517, 5
01:35:02.612 -> :rdi 512, 512
01:35:02.612 -> :c0 512, 517
01:35:02.647 -> :wr 517 0
01:35:02.647 -> :wrc 517 517 0
01:35:03.557 -> :ack 517
01:35:04.369 -> :wr 517 0
01:35:04.369 -> :wrc 517 517 0
01:35:04.369 -> :wr 223 0
01:35:04.369 -> :wrc 223 223 0
01:35:04.514 -> :ack 517
01:35:04.514 -> :rn 7
01:35:04.514 -> :rcl
01:35:04.514 -> :abort
01:35:04.514 -> :rd 5, 7, 0
01:35:04.514 -> :rdi 7, 5
01:35:04.514 -> :rd 2, 7, 5
01:35:04.514 -> :rdi 2, 2
01:35:04.514 -> :c0 2, 7
01:35:04.514 -> BSSL:_wait_for_handshake: failed
01:35:04.514 -> :ur 1
01:35:04.514 -> WS:dis
01:35:04.514 -> :del
01:35:04.514 -> WS:av
01:35:04.514 -> WS:ac
01:35:04.514 -> :rn 517
01:35:04.514 -> :ref 1
01:35:04.514 -> :rd 5, 517, 0
01:35:04.514 -> :rdi 517, 5
01:35:04.514 -> :rd 512, 517, 5
01:35:04.514 -> :rdi 512, 512
01:35:04.514 -> :c0 512, 517
01:35:04.548 -> :wr 517 0
01:35:04.548 -> :wrc 517 517 0
01:35:05.459 -> :ack 517
01:35:06.277 -> :wr 517 0
01:35:06.277 -> :wrc 517 517 0
01:35:06.277 -> :wr 223 0
01:35:06.277 -> :wrc 223 223 0
01:35:06.383 -> :ack 517
01:35:06.383 -> :ack 223
01:35:06.383 -> :rn 93
01:35:06.383 -> :rd 5, 93, 0
01:35:06.383 -> :rdi 93, 5
01:35:06.383 -> :rd 37, 93, 5
01:35:06.383 -> :rdi 88, 37
01:35:06.452 -> :rd 5, 93, 42
01:35:06.452 -> :rdi 51, 5
01:35:06.452 -> :rd 1, 93, 47
01:35:06.452 -> :rdi 46, 1
01:35:06.452 -> :rd 5, 93, 48
01:35:06.452 -> :rdi 45, 5
01:35:06.452 -> :rd 40, 93, 53
01:35:06.452 -> :rdi 40, 40
01:35:06.452 -> :c0 40, 93
01:35:06.490 -> :wr 6 0
01:35:06.490 -> :wrc 6 6 0
01:35:06.490 -> :wr 45 0
01:35:06.490 -> :wrc 45 45 0
01:35:06.490 -> WS:av
01:35:06.490 -> :ref 2
01:35:06.490 -> :ur 2
01:35:06.490 -> :ref 2
01:35:06.490 -> :ur 2
01:35:06.490 -> New client
01:35:06.490 -> :ref 2
01:35:06.490 -> :ur 2
01:35:06.529 -> :ack 6
01:35:06.529 -> :ack 45
01:35:06.529 -> :rn 495
01:35:06.529 -> :rd 5, 495, 0
01:35:06.529 -> :rdi 495, 5
01:35:06.529 -> :rd 490, 495, 5
01:35:06.529 -> :rdi 490, 490
01:35:06.563 -> :c0 490, 495
01:35:06.563 -> request: GET / HTTP/1.1
01:35:06.563 -> method: GET url: / search: 
01:35:06.563 -> headerName: Host
01:35:06.563 -> headerValue: 192.168.8.113
01:35:06.563 -> headerName: Connection
01:35:06.563 -> headerValue: keep-alive
01:35:06.563 -> headerName: Cache-Control
01:35:06.563 -> headerValue: max-age=0
01:35:06.563 -> headerName: Upgrade-Insecure-Requests
01:35:06.563 -> headerValue: 1
01:35:06.563 -> headerName: User-Agent
01:35:06.563 -> headerValue: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/75.0.3770.142 Safari/537.36
01:35:06.600 -> headerName: Accept
01:35:06.600 -> headerValue: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3
01:35:06.600 -> headerName: Accept-Encoding
01:35:06.600 -> headerValue: gzip, deflate, br
01:35:06.600 -> headerName: Accept-Language
01:35:06.600 -> headerValue: ru-RU,ru;q=0.9,en-US;q=0.8,en;q=0.7
01:35:06.600 -> args: 
01:35:06.600 -> args count: 0
01:35:06.600 -> args: 
01:35:06.600 -> args count: 0
01:35:06.600 -> Request: /
01:35:06.600 -> Arguments: 
01:35:06.633 -> final list of key/value pairs:
01:35:06.633 -> :wr 113 0
01:35:06.633 -> :wrc 113 113 0
01:35:06.673 -> :ack 113
01:35:06.673 -> :wr 59 0
01:35:06.673 -> :wrc 59 59 0
01:35:06.673 -> :ack 59
01:35:06.673 -> :rcl
01:35:06.673 -> :abort
01:35:06.673 -> :ur 1
01:35:06.673 -> WS:dis
01:35:06.673 -> :del

@earlephilhower
Copy link
Collaborator

Just to reiterate, please double-check you're running the latest GIT head. There are 10s of KB in tables in flash and, while the pgm_read_xxx routines were being optimized and changed to support misaligned access, you might have grabbed one a version that had a slower read macro. But that may not be the issue.

It could be a matter of the ciphers being negotiated between the BSSL server and your host. Some, like EC ones, are significantly slower than lower-security RSA codes. As a simple test, try using the IDE menus to select the Tools->SSL->Basic SSL, which removes everything but the simplest RSA codes and be less CPU intensive.

@CyanoFresh
Copy link

double checked, it's latest git head.
with basic ciphers selected:

03:32:18.782 -> WS:ac
03:32:18.782 -> :ref 1
03:32:18.782 -> :rn 517
03:32:18.782 -> WS:ac
03:32:18.782 -> :rn 517
03:32:18.782 -> :rd 5, 517, 0
03:32:18.782 -> :rdi 517, 5
03:32:18.782 -> :rd 512, 517, 5
03:32:18.818 -> :rdi 512, 512
03:32:18.818 -> :c0 512, 517
03:32:18.851 -> :wr 517 0
03:32:18.851 -> :wrc 517 517 0
03:32:18.851 -> :wr 435 0
03:32:18.851 -> :wrc 435 435 0
03:32:18.887 -> :ack 517
03:32:18.920 -> :ack 435
03:32:18.920 -> :rn 7
03:32:18.920 -> :rcl
03:32:18.920 -> :abort
03:32:18.920 -> :rd 5, 7, 0
03:32:18.920 -> :rdi 7, 5
03:32:18.920 -> :rd 2, 7, 5
03:32:18.920 -> :rdi 2, 2
03:32:18.920 -> :c0 2, 7
03:32:18.920 -> BSSL:_wait_for_handshake: failed
03:32:18.920 -> :ur 1
03:32:18.920 -> WS:dis
03:32:18.920 -> :del
03:32:18.920 -> WS:av
03:32:18.920 -> :ref 1
03:32:18.920 -> :rd 5, 517, 0
03:32:18.920 -> :rdi 517, 5
03:32:18.920 -> :rd 512, 517, 5
03:32:18.920 -> :rdi 512, 512
03:32:18.920 -> :c0 512, 517
03:32:18.955 -> :wr 517 0
03:32:18.955 -> :wrc 517 517 0
03:32:18.992 -> :wr 435 0
03:32:18.992 -> :wrc 435 435 0
03:32:19.027 -> :ack 517
03:32:19.027 -> :ack 435
03:32:19.027 -> :rn 7
03:32:19.027 -> :rcl
03:32:19.027 -> :abort
03:32:19.027 -> :rd 5, 7, 0
03:32:19.027 -> :rdi 7, 5
03:32:19.027 -> :rd 2, 7, 5
03:32:19.027 -> :rdi 2, 2
03:32:19.027 -> :c0 2, 7
03:32:19.027 -> WS:ac
03:32:19.027 -> :rn 517
03:32:19.027 -> BSSL:_wait_for_handshake: failed
03:32:19.060 -> :ur 1
03:32:19.060 -> WS:dis
03:32:19.060 -> :del
03:32:19.060 -> WS:av
03:32:19.060 -> :ref 1
03:32:19.060 -> :rd 5, 517, 0
03:32:19.060 -> :rdi 517, 5
03:32:19.060 -> :rd 512, 517, 5
03:32:19.060 -> :rdi 512, 512
03:32:19.060 -> :c0 512, 517
03:32:19.096 -> :wr 517 0
03:32:19.096 -> :wrc 517 517 0
03:32:19.096 -> :wr 435 0
03:32:19.096 -> :wrc 435 435 0
03:32:19.133 -> :ack 517
03:32:19.171 -> :ack 435
03:32:19.171 -> :rn 318
03:32:19.171 -> :rd 5, 318, 0
03:32:19.171 -> :rdi 318, 5
03:32:19.171 -> :rd 262, 318, 5
03:32:19.171 -> :rdi 313, 262
03:32:20.828 -> :rd 5, 318, 267
03:32:20.828 -> :rdi 51, 5
03:32:20.828 -> :rd 1, 318, 272
03:32:20.828 -> :rdi 46, 1
03:32:20.828 -> Fatal exception 28(LoadProhibitedCause):
03:32:20.828 -> epc1=0x402224fd, epc2=0x00000000, epc3=0x00000000, excvaddr=0x0000000c, depc=0x00000000
03:32:20.828 -> 
03:32:20.828 -> Exception (28):
03:32:20.828 -> epc1=0x402224fd epc2=0x00000000 epc3=0x00000000 excvaddr=0x0000000c depc=0x00000000
03:32:20.828 -> 
03:32:20.828 -> >>>stack>>>
03:32:20.828 -> 
03:32:20.828 -> ctx: bearssl
03:32:20.828 -> sp: 3fff108c end: 3fff145c offset: 01a0
03:32:20.867 -> 3fff122c:  1f6538a4 196b7707 830d5fa2 86c48289  
03:32:20.867 -> 3fff123c:  579689c2 d5b2fa1b bbb0a836 b9ab59ac  
03:32:20.867 -> 3fff124c:  e083876e 6a909a13 e4e19eee 3fff2fc0  
03:32:20.867 -> 3fff125c:  3fff306c 00000004 3fff30cc 4022233e  
03:32:20.867 -> 3fff126c:  3fff127c 40255810 3fff2c94 00000010  
03:32:20.867 -> 3fff127c:  3fff2e85 00000020 3fff2ea5 3fff2fc0  
03:32:20.867 -> 3fff128c:  3fff3064 3fff2fd0 3fff2fd0 40229968  
03:32:20.867 -> 3fff129c:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.867 -> 3fff12ac:  a7ebc001 aa5476f3 22101037 a3158dcd  
03:32:20.867 -> 3fff12bc:  0ee36b12 aa6885f7 26a62557 470ffc46  
03:32:20.906 -> 3fff12cc:  ea209c26 7441a945 716e64ac 9d248d32  
03:32:20.906 -> 3fff12dc:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.906 -> 3fff12ec:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.906 -> 3fff12fc:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.906 -> 3fff130c:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.906 -> 3fff131c:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.906 -> 3fff132c:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.906 -> 3fff133c:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.906 -> 3fff134c:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.945 -> 3fff135c:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.945 -> 3fff136c:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.945 -> 3fff137c:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.945 -> 3fff138c:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.945 -> 3fff139c:  deadbeef 00000100 deadbeef 40258bad  
03:32:20.945 -> 3fff13ac:  3fff27dc 3fff2fd8 000008f0 deadbeef  
03:32:20.945 -> 3fff13bc:  deadbeef deadbeef deadbeef deadbeef  
03:32:20.945 -> 3fff13cc:  deadbeef 00000000 deadbeef 3fff32c0  
03:32:20.945 -> 3fff13dc:  3fff2fd0 00000001 deadbeef deadbeef  
03:32:20.982 -> 3fff13ec:  deadbeef deadbeef 3fff27dc 3fff31dc  
03:32:20.982 -> 3fff13fc:  3fff32dc 00000000 3fff27dc 40221cd0  
03:32:20.982 -> 3fff140c:  3fff2fc0 00000001 deadbeef deadbeef  
03:32:20.982 -> 3fff141c:  00000340 00000005 deadbeef 3ffee9fc  
03:32:20.982 -> 3fff142c:  00000008 00000000 3fff27dc 402221b5  
03:32:20.982 -> 3fff143c:  000001b3 deadbeef deadbeef deadbeef  
03:32:20.982 -> 3fff144c:  deadbeef 00000000 3ffffde0 40203c18  
03:32:20.982 -> 
03:32:20.982 -> ctx: cont
03:32:20.982 -> sp: 3ffffce0 end: 3fffffc0 offset: 0000
03:32:21.015 -> 3ffffce0:  00000008 00000000 00000001 40207579  
03:32:21.015 -> 3ffffcf0:  00000001 00000000 0a7cd7c1 9796f2c2  
03:32:21.015 -> 3ffffd00:  00000340 00000005 a1a8c937 3ffffd40  
03:32:21.015 -> 3ffffd10:  40228994 40228940 3fff27dc 3ffffd40  
03:32:21.015 -> 3ffffd20:  4022126c 00000001 3ffffde0 402077a8  
03:32:21.015 -> 3ffffd30:  c09c009d 00000001 3ffffde0 40207c9f  
03:32:21.015 -> 3ffffd40:  402211d8 4025000a 3ffe8304 3fff16d4  
03:32:21.015 -> 3ffffd50:  00000000 00000000 00000000 4020ee3a  
03:32:21.052 -> 3ffffd60:  3fff16d4 00000000 3fff27dc 3fff1930  
03:32:21.052 -> 3ffffd70:  3fff168c 00000001 00000000 00000000  
03:32:21.052 -> 3ffffd80:  00004145 00000345 3ffffe5c 3fff16d4  
03:32:21.052 -> 3ffffd90:  3fff166c 3fff24f4 3ffffde0 40207e20  
03:32:21.052 -> 3ffffda0:  00004145 00000345 3ffffde0 4020743c  
03:32:21.052 -> 3ffffdb0:  00000000 00000000 3ffffec0 3ffeea44  
03:32:21.052 -> 3ffffdc0:  3fffdad0 3ffffec0 3ffee7d0 40208134  
03:32:21.052 -> 3ffffdd0:  00000000 3fffc6fc 00000064 3ffffec0  
03:32:21.052 -> 3ffffde0:  4020c560 00000000 00003a98 00000030  
03:32:21.087 -> 3ffffdf0:  3ffee81c 3fff24f4 00000000 00000000  
03:32:21.087 -> 3ffffe00:  3fff27dc 3fff23c4 3fff27dc 00000000  
03:32:21.087 -> 3ffffe10:  00000000 00000000 00000000 00000000  
03:32:21.087 -> 3ffffe20:  00000000 3fff6eec 3fff15cc 3fffb044  
03:32:21.087 -> 3ffffe30:  3fff15f4 00000000 00000000 401024d4  
03:32:21.087 -> 3ffffe40:  00004145 00000345 40100000 00000000  
03:32:21.087 -> 3ffffe50:  00000000 00000000 00000000 00000000  
03:32:21.087 -> 3ffffe60:  00000000 00000000 00000000 00040000  
03:32:21.123 -> 3ffffe70:  00002200 3fffc200 3fffff3c 400071fc  
03:32:21.123 -> 3ffffe80:  00000000 00000000 00000000 00000000  
03:32:21.123 -> 3ffffe90:  00000000 00000000 00000000 4020743c  
03:32:21.123 -> 3ffffea0:  00000000 00000000 3ffee7d0 4020bf8c  
03:32:21.123 -> 3ffffeb0:  3fffdad0 00000000 3ffee7d0 402038e9  
03:32:21.123 -> 3ffffec0:  4020c508 00000000 00003a98 ffffffff  
03:32:21.123 -> 3ffffed0:  00000000 00000000 00000000 00000000  
03:32:21.123 -> 3ffffee0:  00000000 00000000 00000000 00000000  
03:32:21.123 -> 3ffffef0:  00000000 00000000 00000000 00000000  
03:32:21.159 -> 3fffff00:  00000000 00000000 00000000 00000000  
03:32:21.159 -> 3fffff10:  00000000 00000000 00000000 401024d4  
03:32:21.159 -> 3fffff20:  00004145 00000255 3ffe0000 00000000  
03:32:21.159 -> 3fffff30:  00000000 00000000 00000000 00000000  
03:32:21.159 -> 3fffff40:  00000000 00000000 00000000 00040000  
03:32:21.159 -> 3fffff50:  00002200 3fffc200 3fffff3c 000071fc  
03:32:21.159 -> 3fffff60:  00000000 00000000 00000000 00000000  
03:32:21.159 -> 3fffff70:  40203600 00000000 00000000 4020743c  
03:32:21.200 -> 3fffff80:  00000000 00000000 3ffee7d0 3ffeea44  
03:32:21.200 -> 3fffff90:  3fffdad0 00000000 3ffeea14 402039fc  
03:32:21.200 -> 3fffffa0:  3fffdad0 00000000 3ffeea14 4020a314  
03:32:21.200 -> 3fffffb0:  feefeffe feefeffe 3ffe8510 40100d79  
03:32:21.200 -> <<<stack<<<
03:32:21.200 -> 
03:32:21.200 ->  ets Jan  8 2013,rst cause:2, boot mode:(3,6)
03:32:21.200 -> 
03:32:21.235 -> load 0x4010f000, len 1384, room 16 
03:32:21.235 -> tail 8
03:32:21.235 -> chksum 0x2d
03:32:21.235 -> csum 0x2d
03:32:21.235 -> va8873c23
03:32:21.235 -> ~ld

decoded:


Exception 28: LoadProhibited: A load referenced a page mapped with an attribute that does not permit loads
PC: 0x402224fd: br_ssl_engine_switch_gcm_in at src/ssl/ssl_engine.c line 1459
EXCVADDR: 0x0000000c

Decoding stack results
0x4022233e: br_ssl_engine_compute_master at src/ssl/ssl_engine.c line 1336
0x40229968: br_ssl_hs_server_run at src/ssl/ssl_hs_server.c line 1735
0x4022a506: sendpld_flush at src/ssl/ssl_engine.c line 851
0x40221bcc: sendpld_ack at src/ssl/ssl_engine.c line 878
0x4022a524: clear_encrypt at src/ssl/ssl_engine.c line 951
0x40221cd0: jump_handshake at src/ssl/ssl_engine.c line 1081
0x402221b5: br_ssl_engine_recvrec_ack at src/ssl/ssl_engine.c line 1206
0x40207579: BearSSL::WiFiClientSecure::_run_until(unsigned int, bool) (C:\Program Files at x86)\Arduino\hardware\esp8266com\esp8266\libraries\ESP8266WiFi\src\WiFiClientSecureBearSSL.cpp line 523
0x40228994: br_ssl_hs_server_run at src/ssl/ssl_hs_server.c line 943
0x40228940: br_ssl_hs_server_init_main at /home/earle/Arduino/hardware/esp8266com/esp8266/tools/xtensa-lx106-elf/xtensa-lx106-elf/include/sys/pgmspace.h line 77
0x4022126c: br_rsa_i15_private at src/rsa/rsa_i15_priv.c line 33
0x402077a8: BearSSL::WiFiClientSecure::_wait_for_handshake() (C:\Program Files at x86)\Arduino\hardware\esp8266com\esp8266\libraries\ESP8266WiFi\src\WiFiClientSecureBearSSL.cpp line 547
0x40207c9f: BearSSL::WiFiClientSecure::_connectSSLServerRSA(BearSSL::X509List const*, BearSSL::PrivateKey const*, BearSSL::X509List const*) (C:\Program Files at x86)\Arduino\hardware\esp8266com\esp8266\libraries\ESP8266WiFi\src\WiFiClientSecureBearSSL.cpp line 1194
0x402211d8: br_rsa_i15_pkcs1_sign at src/rsa/rsa_i15_pkcs1_sign.c line 32
0x4020ee3a: printf at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/printf.c line 61
0x40207e20: BearSSL::WiFiClientSecure::WiFiClientSecure(ClientContext*, BearSSL::X509List const*, BearSSL::PrivateKey const*, int, int, BearSSL::X509List const*) (C:\Program Files at x86)\Arduino\hardware\esp8266com\esp8266\libraries\ESP8266WiFi\src\WiFiClientSecureBearSSL.cpp line 142
0x4020743c: BearSSL::WiFiClientSecure::~WiFiClientSecure() (C:\Program Files at x86)\Arduino\hardware\esp8266com\esp8266\libraries\ESP8266WiFi\src\WiFiClientSecureBearSSL.cpp line 130
0x40208134: BearSSL::WiFiServerSecure::available(unsigned char*) (C:\Program Files at x86)\Arduino\hardware\esp8266com\esp8266\libraries\ESP8266WiFi\src\WiFiServerSecureBearSSL.cpp line 84
0x4020743c: BearSSL::WiFiClientSecure::~WiFiClientSecure() (C:\Program Files at x86)\Arduino\hardware\esp8266com\esp8266\libraries\ESP8266WiFi\src\WiFiClientSecureBearSSL.cpp line 130
0x4020bf8c: WiFiClient::operator bool() (C:\Program Files at x86)\Arduino\hardware\esp8266com\esp8266\libraries\ESP8266WiFi\src\WiFiClient.cpp line 350
0x402038e9: esp8266webserver::ESP8266WebServerTemplate ::handleClient() (C:\Program Files at x86)\Arduino\hardware\esp8266com\esp8266\libraries\ESP8266WebServer\src/ESP8266WebServer-impl.h line 306
0x40203600: esp8266webserver::ESP8266WebServerTemplate ::send(int, char const*, String const&) (C:\Program Files at x86)\Arduino\hardware\esp8266com\esp8266\libraries\ESP8266WebServer\src/ESP8266WebServer-impl.h line 437
0x4020743c: BearSSL::WiFiClientSecure::~WiFiClientSecure() (C:\Program Files at x86)\Arduino\hardware\esp8266com\esp8266\libraries\ESP8266WiFi\src\WiFiClientSecureBearSSL.cpp line 130
0x402039fc: loop() at C:\Users\Work\Documents\Arduino\HelloServerBearSSL_dev/HelloServerBearSSL_dev.ino line 142
0x4020a314: loop_wrapper() (C:\Program Files at x86)\Arduino\hardware\esp8266com\esp8266\cores\esp8266\core_esp8266_main.cpp line 140

@earlephilhower
Copy link
Collaborator

Put the crash info with MCVE In a new bug, it should work. Looking at the excvaddr it looked like an oom or null pointer will somewhere.

@CyanoFresh
Copy link

Updated to the latest core. 160MHz and basic ciphers.
Now delay is between 2 and 6 seconds... still long enough (
I am loading page from Chrome.

00:32:32.435 -> SDK:2.2.2-dev(38a443e)/Core:2.5.2-106-gadfc28d7=20502106/lwIP:STABLE-2_1_2_RELEASE/glue:1.1-8-g2314329/BearSSL:89454af
00:32:32.435 -> scandone
00:32:32.435 -> 
00:32:32.435 -> wifi evt: 2
00:32:32.539 -> scandone
00:32:32.539 -> state: 0 -> 2 (b0)
00:32:32.539 -> state: 2 -> 3 (0)
00:32:32.539 -> state: 3 -> 5 (10)
00:32:32.539 -> add 0
00:32:32.539 -> aid 10
00:32:32.539 -> cnt 
00:32:32.573 -> 
00:32:32.573 -> connected with Solomaha, channel 3
00:32:32.573 -> dhcp client start...
00:32:32.573 -> wifi evt: 0
00:32:32.573 -> ip:192.168.1.178,mask:255.255.255.0,gw:192.168.1.1
00:32:32.608 -> wifi evt: 3
00:32:32.920 -> .
00:32:32.920 -> Connected to Solomaha
00:32:32.920 -> IP address: 192.168.1.178
00:32:32.989 -> HTTPS server started
00:32:36.087 -> WS:ac
00:32:36.087 -> :rn 517
00:32:36.087 -> WS:ac
00:32:36.087 -> :rn 517
00:32:36.087 -> :ref 1
00:32:36.087 -> :rd 5, 517, 0
00:32:36.087 -> :rdi 517, 5
00:32:36.087 -> :rd 512, 517, 5
00:32:36.087 -> :rdi 512, 512
00:32:36.087 -> :c0 512, 517
00:32:36.155 -> :wr 517 0
00:32:36.155 -> :wrc 517 517 0
00:32:36.155 -> :wr 435 0
00:32:36.155 -> :wrc 435 435 0
00:32:36.189 -> :ack 517
00:32:36.224 -> :ack 435
00:32:36.224 -> :rn 7
00:32:36.224 -> :rcl
00:32:36.224 -> :abort
00:32:36.224 -> :rd 5, 7, 0
00:32:36.224 -> :rdi 7, 5
00:32:36.224 -> :rd 2, 7, 5
00:32:36.224 -> :rdi 2, 2
00:32:36.224 -> :c0 2, 7
00:32:36.224 -> BSSL:_wait_for_handshake: failed
00:32:36.224 -> :ur 1
00:32:36.224 -> WS:dis
00:32:36.224 -> :del
00:32:36.224 -> WS:av
00:32:36.224 -> :ref 1
00:32:36.224 -> :rd 5, 517, 0
00:32:36.224 -> :rdi 517, 5
00:32:36.224 -> :rd 512, 517, 5
00:32:36.224 -> :rdi 512, 512
00:32:36.224 -> :c0 512, 517
00:32:36.259 -> :wr 517 0
00:32:36.259 -> :wrc 517 517 0
00:32:36.294 -> :wr 435 0
00:32:36.294 -> :wrc 435 435 0
00:32:36.328 -> :ack 517
00:32:36.363 -> :ack 435
00:32:36.363 -> :rn 7
00:32:36.363 -> :rcl
00:32:36.363 -> :abort
00:32:36.363 -> :rd 5, 7, 0
00:32:36.363 -> :rdi 7, 5
00:32:36.363 -> :rd 2, 7, 5
00:32:36.363 -> :rdi 2, 2
00:32:36.363 -> :c0 2, 7
00:32:36.363 -> WS:ac
00:32:36.363 -> :rn 517
00:32:36.363 -> BSSL:_wait_for_handshake: failed
00:32:36.363 -> :ur 1
00:32:36.363 -> WS:dis
00:32:36.363 -> :del
00:32:36.363 -> WS:av
00:32:36.363 -> :ref 1
00:32:36.363 -> :rd 5, 517, 0
00:32:36.363 -> :rdi 517, 5
00:32:36.363 -> :rd 512, 517, 5
00:32:36.363 -> :rdi 512, 512
00:32:36.363 -> :c0 512, 517
00:32:36.431 -> :wr 517 0
00:32:36.431 -> :wrc 517 517 0
00:32:36.431 -> :wr 435 0
00:32:36.431 -> :wrc 435 435 0
00:32:36.466 -> :ack 517
00:32:36.501 -> :ack 435
00:32:36.501 -> :rn 342
00:32:36.501 -> :rd 5, 342, 0
00:32:36.501 -> :rdi 342, 5
00:32:36.501 -> :rd 262, 342, 5
00:32:36.501 -> :rdi 337, 262
00:32:38.162 -> :rd 5, 342, 267
00:32:38.162 -> :rdi 75, 5
00:32:38.162 -> :rd 1, 342, 272
00:32:38.162 -> :rdi 70, 1
00:32:38.162 -> :rd 5, 342, 273
00:32:38.162 -> :rdi 69, 5
00:32:38.162 -> :rd 64, 342, 278
00:32:38.162 -> :rdi 64, 64
00:32:38.162 -> :c0 64, 342
00:32:38.162 -> :wr 6 0
00:32:38.162 -> :wrc 6 6 0
00:32:38.162 -> :wr 69 0
00:32:38.162 -> :wrc 69 69 0
00:32:38.162 -> WS:av
00:32:38.162 -> :ref 2
00:32:38.162 -> :ur 2
00:32:38.162 -> :ref 2
00:32:38.162 -> :ur 2
00:32:38.162 -> New client
00:32:38.162 -> :ref 2
00:32:38.162 -> :ur 2
00:32:38.196 -> :ack 6
00:32:38.231 -> :ack 69
00:32:38.231 -> :rn 536
00:32:38.231 -> :rch 536, 45
00:32:38.231 -> :rd 5, 581, 0
00:32:38.231 -> :rdi 536, 5
00:32:38.231 -> :rd 576, 581, 5
00:32:38.231 -> :rdi 531, 531
00:32:38.231 -> :c 531, 536, 581
00:32:38.231 -> :rdi 45, 45
00:32:38.231 -> :c0 45, 45
00:32:38.231 -> request: GET / HTTP/1.1
00:32:38.231 -> method: GET url: / search: 
00:32:38.231 -> headerName: Host
00:32:38.231 -> headerValue: 192.168.1.178
00:32:38.231 -> headerName: Connection
00:32:38.231 -> headerValue: keep-alive
00:32:38.231 -> headerName: Cache-Control
00:32:38.231 -> headerValue: max-age=0
00:32:38.231 -> headerName: Upgrade-Insecure-Requests
00:32:38.266 -> headerValue: 1
00:32:38.266 -> headerName: User-Agent
00:32:38.266 -> headerValue: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/76.0.3809.100 Safari/537.36
00:32:38.266 -> headerName: Sec-Fetch-Mode
00:32:38.266 -> headerValue: navigate
00:32:38.266 -> headerName: Sec-Fetch-User
00:32:38.266 -> headerValue: ?1
00:32:38.266 -> headerName: Accept
00:32:38.266 -> headerValue: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3
00:32:38.301 -> headerName: Sec-Fetch-Site
00:32:38.301 -> headerValue: none
00:32:38.301 -> headerName: Accept-Encoding
00:32:38.301 -> headerValue: gzip, deflate, br
00:32:38.301 -> headerName: Accept-Language
00:32:38.301 -> headerValue: ru-RU,ru;q=0.9,en-US;q=0.8,en;q=0.7
00:32:38.301 -> args: 
00:32:38.301 -> args count: 0
00:32:38.301 -> args: 
00:32:38.301 -> args count: 0
00:32:38.301 -> Request: /
00:32:38.301 -> Arguments: 
00:32:38.301 -> final list of key/value pairs:
00:32:38.301 -> :wr 133 0
00:32:38.301 -> :wrc 133 133 0
00:32:38.369 -> :ack 133
00:32:38.369 -> :wr 85 0
00:32:38.369 -> :wrc 85 85 0
00:32:38.369 -> :ack 85
00:32:38.369 -> :rcl
00:32:38.369 -> :abort
00:32:38.369 -> :ur 1
00:32:38.369 -> WS:dis
00:32:38.369 -> :del

@earlephilhower
Copy link
Collaborator

That's within the realm of reason. It's 2-3 seconds for me, and I'm talking between a wired client and the ESP8266 server, with the 8266 only a couple meters from the AP. It's a slow, single-core machine, and since it's running everything from SPI flash if there's a cache miss it spends more time waiting for instructions than actually running them...

@CyanoFresh
Copy link

ah, ok. Thank you very much

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
waiting for feedback Waiting on additional info. If it's not received, the issue may be closed.
Projects
None yet
Development

No branches or pull requests

4 participants