Description
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-12
-
Core Version: SDK:2.2.2-dev(38a443e)/Core:2.7.4=20704000/lwIP:STABLE-2_1_2_RELEASE/glue:1.2-30-g92add50/BearSSL:5c771be and with straight from master.
-
Development Env: Arduino IDE
-
Operating System: Ubuntu & MacOS
Settings in IDE
- Module: Nodemcu
- Flash Mode: qio
- Flash Size: 4MB
- lwip Variant: v2 Lower Memory
- Reset Method: nodemcu
- Flash Frequency: ?
- CPU Frequency: 160MHz
- Upload Using: SERIAL
- Upload Speed: 115200
Problem Description
Attempting to connect to AWS IoT. MQTT client sometime is rarely successful most of the times it errors out in BearSSL. I know the AWS IoT setup works as the credentials used on other platforms and as I said it sometimes works. Same setup used on ESP8266 with sometime success. When success works as expected. When it fails the wifi connects, the SNTP gets the time, the MQTT client gets an IP addess from AWS, then attempts to connect and fails which causes and exception. The exception is either a 28 or a 9 depending on the configuration but is always associated with the same line of code ( br_ssl_hs_client_run at src/ssl/ssl_hs_client.c line 1871).
This version uses the MQTT client but the PubSubClient has the same behavior so i don't think it has to do with these libraries.
I have built this on both my MAC Powerbook and Ubuntu 18.04 to the same effect.
I have attempted to use GDB with some success but tracing this problem usually results in a segfault on target and then GDB exits abruptly. This eliminates the ability to do a backtrace.
I have looked at the max stack usage and this doesn't look like the problem. One interesting thing is that when it fails the max has like three different levels. When successful it is always the same value.
When it fails it looks like this:
Max stack 4580, 4532, 4564, 4548 or something else.
When successful it is always:
Max stack 4596
When successful the code will print out messages sent via the AWS IOT Core test client as would be expected.
What i show is with 2.7.4 but i have pulled master and it has very similar behavior but doesn't print out the exception stack so i didn't include that.
MCVE Sketch
#include <ESP8266WiFi.h>
#include <WiFiClientSecure.h>
#include <MQTT.h>
#include <ArduinoJson.h>
#include <time.h>
#include <StackThunk.h>
#define emptyString String()
#include "secrets.h"
const int MQTT_PORT = 8883;
const char MQTT_SUB_TOPIC[] = "robo/cmds";
const char MQTT_PUB_TOPIC[] = "$aws/things/" THINGNAME "/shadow/update";
#ifdef USE_SUMMER_TIME_DST
uint8_t DST = 1;
#else
uint8_t DST = 0;
#endif
WiFiClientSecure net;
BearSSL::X509List cert(cacert);
BearSSL::X509List client_crt(client_cert);
BearSSL::PrivateKey key(privkey);
MQTTClient client;
unsigned long lastMillis = 0;
time_t now;
time_t nowish = 1510592825;
void NTPConnect(void)
{
Serial.print("Setting time using SNTP");
configTime(TIME_ZONE * 3600, DST * 3600, "pool.ntp.org", "time.nist.gov");
now = time(nullptr);
while (now < nowish)
{
delay(500);
Serial.print(".");
now = time(nullptr);
}
Serial.println("done!");
struct tm timeinfo;
gmtime_r(&now, &timeinfo);
Serial.print("Current time: ");
Serial.print(asctime(&timeinfo));
}
void messageReceived(String &topic, String &payload)
{
Serial.println("Received [" + topic + "]: " + payload);
}
void lwMQTTErr(lwmqtt_err_t reason)
{
if (reason == lwmqtt_err_t::LWMQTT_SUCCESS)
Serial.print("Success");
else if (reason == lwmqtt_err_t::LWMQTT_BUFFER_TOO_SHORT)
Serial.print("Buffer too short");
else if (reason == lwmqtt_err_t::LWMQTT_VARNUM_OVERFLOW)
Serial.print("Varnum overflow");
else if (reason == lwmqtt_err_t::LWMQTT_NETWORK_FAILED_CONNECT)
Serial.print("Network failed connect");
else if (reason == lwmqtt_err_t::LWMQTT_NETWORK_TIMEOUT)
Serial.print("Network timeout");
else if (reason == lwmqtt_err_t::LWMQTT_NETWORK_FAILED_READ)
Serial.print("Network failed read");
else if (reason == lwmqtt_err_t::LWMQTT_NETWORK_FAILED_WRITE)
Serial.print("Network failed write");
else if (reason == lwmqtt_err_t::LWMQTT_REMAINING_LENGTH_OVERFLOW)
Serial.print("Remaining length overflow");
else if (reason == lwmqtt_err_t::LWMQTT_REMAINING_LENGTH_MISMATCH)
Serial.print("Remaining length mismatch");
else if (reason == lwmqtt_err_t::LWMQTT_MISSING_OR_WRONG_PACKET)
Serial.print("Missing or wrong packet");
else if (reason == lwmqtt_err_t::LWMQTT_CONNECTION_DENIED)
Serial.print("Connection denied");
else if (reason == lwmqtt_err_t::LWMQTT_FAILED_SUBSCRIPTION)
Serial.print("Failed subscription");
else if (reason == lwmqtt_err_t::LWMQTT_SUBACK_ARRAY_OVERFLOW)
Serial.print("Suback array overflow");
else if (reason == lwmqtt_err_t::LWMQTT_PONG_TIMEOUT)
Serial.print("Pong timeout");
}
void lwMQTTErrConnection(lwmqtt_return_code_t reason)
{
if (reason == lwmqtt_return_code_t::LWMQTT_CONNECTION_ACCEPTED)
Serial.print("Connection Accepted");
else if (reason == lwmqtt_return_code_t::LWMQTT_UNACCEPTABLE_PROTOCOL)
Serial.print("Unacceptable Protocol");
else if (reason == lwmqtt_return_code_t::LWMQTT_IDENTIFIER_REJECTED)
Serial.print("Identifier Rejected");
else if (reason == lwmqtt_return_code_t::LWMQTT_SERVER_UNAVAILABLE)
Serial.print("Server Unavailable");
else if (reason == lwmqtt_return_code_t::LWMQTT_BAD_USERNAME_OR_PASSWORD)
Serial.print("Bad UserName/Password");
else if (reason == lwmqtt_return_code_t::LWMQTT_NOT_AUTHORIZED)
Serial.print("Not Authorized");
else if (reason == lwmqtt_return_code_t::LWMQTT_UNKNOWN_RETURN_CODE)
Serial.print("Unknown Return Code");
}
void connectToMqtt(bool nonBlocking = false)
{
Serial.print("MQTT connecting ");
while (!client.connected())
{
if (client.connect(THINGNAME))
{
Serial.println("connected!");
if (!client.subscribe(MQTT_SUB_TOPIC))
lwMQTTErr(client.lastError());
}
else
{
Serial.print("SSL Error Code: ");
Serial.println(net.getLastSSLError());
Serial.print("failed, reason -> ");
lwMQTTErrConnection(client.returnCode());
if (!nonBlocking)
{
Serial.println(" < try again in 5 seconds");
delay(5000);
}
else
{
Serial.println(" <");
}
}
Serial.printf("Max stack %d.", stack_thunk_get_max_usage());
if (nonBlocking)
break;
}
}
void connectToWiFi(String init_str)
{
if (init_str != emptyString)
Serial.print(init_str);
while (WiFi.status() != WL_CONNECTED)
{
Serial.print(".");
delay(1000);
}
if (init_str != emptyString)
Serial.println("ok!");
}
void checkWiFiThenMQTT(void)
{
connectToWiFi("Checking WiFi");
connectToMqtt();
}
unsigned long previousMillis = 0;
const long interval = 5000;
void checkWiFiThenMQTTNonBlocking(void)
{
connectToWiFi(emptyString);
if (millis() - previousMillis >= interval && !client.connected()) {
previousMillis = millis();
connectToMqtt(true);
}
}
void checkWiFiThenReboot(void)
{
connectToWiFi("Checking WiFi");
Serial.print("Rebooting");
ESP.restart();
}
void sendData(void)
{
DynamicJsonDocument jsonBuffer(JSON_OBJECT_SIZE(3) + 100);
JsonObject root = jsonBuffer.to<JsonObject>();
JsonObject state = root.createNestedObject("state");
JsonObject state_reported = state.createNestedObject("reported");
state_reported["value"] = random(100);
Serial.printf("Sending [%s]: ", MQTT_PUB_TOPIC);
serializeJson(root, Serial);
Serial.println();
char shadow[measureJson(root) + 1];
serializeJson(root, shadow, sizeof(shadow));
if (!client.publish(MQTT_PUB_TOPIC, shadow, false, 0))
lwMQTTErr(client.lastError());
}
void setup()
{
Serial.begin(115200);
//gdbstub_init();
delay(5000);
Serial.println();
Serial.println();
WiFi.hostname(THINGNAME);
WiFi.mode(WIFI_STA);
WiFi.begin(ssid, pass);
connectToWiFi(String("Attempting to connect to SSID: ") + String(ssid));
NTPConnect();
net.setTrustAnchors(&cert);
net.setClientRSACert(&client_crt, &key);
client.begin(MQTT_HOST, MQTT_PORT, net);
client.onMessage(messageReceived);
connectToMqtt();
}
void loop()
{
//now = time(nullptr);
if (!client.connected())
{
Serial.print("Not Connected");
checkWiFiThenMQTT();
//checkWiFiThenMQTTNonBlocking();
//checkWiFiThenReboot();
}
else
{
client.loop();
if (millis() - lastMillis > 5000)
{
lastMillis = millis();
sendData();
}
}
}
Debug Messages
SDK:2.2.2-dev(38a443e)/Core:2.7.4=20704000/lwIP:STABLE-2_1_2_RELEASE/glue:1.2-30-g92add50/BearSSL:5c771be
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 0 (4)
reconnect
scandone
Attempting to connect to SSID: ARSnet...scandone
state: 0 -> 2 (b0)
.state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 15
cnt
connected with ARSnet, channel 6
dhcp client start...
ip:192.168.2.122,mask:255.255.255.0,gw:192.168.2.1
ok!
Setting time using SNTP..................pm open,type:2 0
...........done!
Current time: Thu Dec 31 00:24:09 2020
MQTT connecting BSSL:_connectSSL: start connection
BSSL:_run_until: Timeout
BSSL:_wait_for_handshake: failed
BSSL:Couldn't connect. Error = 'Unknown error code.'
SSL Error Code: 0
failed, reason -> Connection Accepted < try again in 5 seconds
Max stack 4580.Fatal exception 28(LoadProhibitedCause):
epc1=0x4022451e, epc2=0x00000000, epc3=0x00000000, excvaddr=0x0000000c, depc=0x00000000
Decoded Exception
Exception 28: LoadProhibited: A load referenced a page mapped with an attribute that does not permit loads
PC: 0x4022309a: br_ssl_hs_client_run at src/ssl/ssl_hs_client.c line 1871
EXCVADDR: 0x0000000c
Decoding stack results
0x402229e5: br_ssl_hs_client_run at src/ssl/ssl_hs_client.c line 1528
0x40221120: jump_handshake at src/ssl/ssl_engine.c line 1081
0x40221605: br_ssl_engine_recvrec_ack at src/ssl/ssl_engine.c line 1206
0x402060de: BearSSL::WiFiClientSecure::_run_until(unsigned int, bool) at /home/ccdocker/Arduino/hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/WiFiClientSecureBearSSL.cpp line 540
0x40206f08: HardwareSerial::write(unsigned char const*, unsigned int) at /home/ccdocker/Arduino/hardware/esp8266com/esp8266/cores/esp8266/HardwareSerial.h line 165
0x402072a1: Print::write(char const*) at /home/ccdocker/Arduino/hardware/esp8266com/esp8266/cores/esp8266/Print.h line 62
0x4020628d: BearSSL::WiFiClientSecure::available() at /home/ccdocker/Arduino/hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/WiFiClientSecureBearSSL.cpp line 386
0x402053aa: BearSSL::WiFiClientSecure::connected() at /home/ccdocker/Arduino/hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/WiFiClientSecureBearSSL.cpp line 260
0x40208b2d: __delay(unsigned long) at /home/ccdocker/Arduino/hardware/esp8266com/esp8266/cores/esp8266/core_esp8266_wiring.cpp line 57
0x4020a65d: MQTTClient::connected() at /home/ccdocker/Arduino/libraries/MQTT/src/MQTTClient.cpp line 398
0x40202330: connectToMqtt(bool) at /home/ccdocker/projects/2020/robot_iot_3/robot_iot_3.ino line 139
0x4020d7de: strdup at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/string/strdup.c line 11
0x402024d1: setup() at /home/ccdocker/projects/2020/robot_iot_3/robot_iot_3.ino line 259
0x402085dc: loop_wrapper() at /home/ccdocker/Arduino/hardware/esp8266com/esp8266/cores/esp8266/core_esp8266_main.cpp line 194