Reconnect with back-off on every disconnect reason and log it
The session is opened again whatever AsyncMqttClient gives as the reason, after 1 s doubling to 60 s (AlexaReconnectBackoff, reset when a session opens), and only while Wi-Fi is up. 1.1.0 retried a lost TCP connection every 5 s and nothing else, silently: a refused password or a broker that was restarting left the board offline until a reset. Every disconnect prints its reason in words and the wait before the next attempt. The first connect waits for Wi-Fi; a connect without an answer after 30 s counts as failed, because the MQTT client reports nothing when no TCP connection was made. Keep-alive 30 s. basicLight: RAM 34,452 -> 34,476 B, flash 337,461 -> 338,281 B; host tests 41 -> 45. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
This commit is contained in:
parent
cb5c9876fe
commit
2ed52c8721
6 changed files with 194 additions and 23 deletions
106
src/Alex2ESP.cpp
106
src/Alex2ESP.cpp
|
|
@ -9,6 +9,11 @@
|
|||
*/
|
||||
#include "Alex2ESP.h"
|
||||
#include <time.h>
|
||||
#ifdef ESP8266
|
||||
#include <ESP8266WiFi.h>
|
||||
#else
|
||||
#include <WiFi.h>
|
||||
#endif
|
||||
|
||||
namespace
|
||||
{
|
||||
|
|
@ -17,6 +22,10 @@ namespace
|
|||
const char NTP_SERVER_1[] = "pool.ntp.org";
|
||||
const char NTP_SERVER_2[] = "time.nist.gov";
|
||||
|
||||
// The broker closes a session that was silent for one and a half times this long, and the board notices a
|
||||
// broker that is gone after the same time
|
||||
const uint16_t KEEP_ALIVE_S = 30;
|
||||
|
||||
const uint8_t SUBSCRIPTION_REFUSED = 0x80; // Return code of a SUBACK for a subscription the broker denies
|
||||
|
||||
// Room the MQTT client needs on top of topic and payload for the packet it builds (headers, its own object)
|
||||
|
|
@ -30,6 +39,30 @@ namespace
|
|||
return ESP.getMaxAllocHeap(); // ESP32: untested
|
||||
#endif
|
||||
}
|
||||
|
||||
// Why the session ended or was not opened, and what to check where the sketch can do something about it
|
||||
PGM_P disconnectReasonText(AsyncMqttClientDisconnectReason reason)
|
||||
{
|
||||
switch (reason)
|
||||
{
|
||||
case AsyncMqttClientDisconnectReason::TCP_DISCONNECTED:
|
||||
return PSTR("the broker cannot be reached or the connection was lost");
|
||||
case AsyncMqttClientDisconnectReason::MQTT_MALFORMED_CREDENTIALS:
|
||||
case AsyncMqttClientDisconnectReason::MQTT_NOT_AUTHORIZED:
|
||||
return PSTR("the broker refused the username or the password, check the two passed to begin()");
|
||||
case AsyncMqttClientDisconnectReason::MQTT_SERVER_UNAVAILABLE:
|
||||
return PSTR("the broker is not available");
|
||||
case AsyncMqttClientDisconnectReason::MQTT_IDENTIFIER_REJECTED:
|
||||
return PSTR("the broker refused the client id");
|
||||
case AsyncMqttClientDisconnectReason::MQTT_UNACCEPTABLE_PROTOCOL_VERSION:
|
||||
return PSTR("the broker does not accept MQTT 3.1.1");
|
||||
case AsyncMqttClientDisconnectReason::ESP8266_NOT_ENOUGH_SPACE:
|
||||
return PSTR("no memory for the connection");
|
||||
case AsyncMqttClientDisconnectReason::TLS_BAD_FINGERPRINT:
|
||||
return PSTR("the certificate of the broker has another fingerprint");
|
||||
}
|
||||
return PSTR("the MQTT client gave no reason");
|
||||
}
|
||||
}
|
||||
|
||||
Alex2ESP::Alex2ESP()
|
||||
|
|
@ -37,10 +70,11 @@ Alex2ESP::Alex2ESP()
|
|||
state(Alex2ESPState::UNINITIALIZED),
|
||||
disconnectReason(AsyncMqttClientDisconnectReason::TCP_DISCONNECTED),
|
||||
useSntp(true),
|
||||
beginTime(0),
|
||||
clockWaitStarted(0),
|
||||
linkWaitLogged(false),
|
||||
clockWarned(false),
|
||||
lastClockWarning(0),
|
||||
lastReconnectTime(0),
|
||||
waitingSince(0),
|
||||
discoverSubscription(0),
|
||||
directiveSubscription(0),
|
||||
subscriptionsPending(0),
|
||||
|
|
@ -88,9 +122,10 @@ void Alex2ESP::begin(const char *username, const char *password, const char *roo
|
|||
// Configure MQTT client
|
||||
mqttClient.setServer(MQTT_SERVER, MQTT_PORT);
|
||||
mqttClient.setCredentials(username, password);
|
||||
mqttClient.setKeepAlive(KEEP_ALIVE_S);
|
||||
|
||||
// loop() connects: see connectWhenClockIsSet()
|
||||
beginTime = millis();
|
||||
clockWaitStarted = millis();
|
||||
state = Alex2ESPState::INITIALIZED;
|
||||
}
|
||||
|
||||
|
|
@ -148,42 +183,70 @@ AlexaDevice *Alex2ESP::findDevice(const char *endpointId, size_t length)
|
|||
return nullptr;
|
||||
}
|
||||
|
||||
// The first connect waits until the clock is set, for CLOCK_WAIT_MS at most: a report sent before SNTP has answered
|
||||
// would carry a time of sample in 1970.
|
||||
// The first connect waits for Wi-Fi and then until the clock is set, for CLOCK_WAIT_MS at most: a report sent before
|
||||
// SNTP has answered would carry a time of sample in 1970.
|
||||
void Alex2ESP::connectWhenClockIsSet()
|
||||
{
|
||||
if (state != Alex2ESPState::INITIALIZED)
|
||||
{
|
||||
return;
|
||||
}
|
||||
if (WiFi.status() != WL_CONNECTED)
|
||||
{
|
||||
if (!linkWaitLogged)
|
||||
{
|
||||
linkWaitLogged = true;
|
||||
ALEX2ESP_LOGI("waiting for Wi-Fi: the sketch has to join a network with WiFi.begin()");
|
||||
}
|
||||
// SNTP cannot answer without a link, so the wait for the clock starts when the link is up
|
||||
clockWaitStarted = millis();
|
||||
return;
|
||||
}
|
||||
if (!AlexaBridgeLogic::clockIsSet(time(nullptr)))
|
||||
{
|
||||
if (millis() - beginTime < CLOCK_WAIT_MS)
|
||||
if (millis() - clockWaitStarted < CLOCK_WAIT_MS)
|
||||
{
|
||||
return;
|
||||
}
|
||||
warnAboutClock();
|
||||
}
|
||||
|
||||
connect();
|
||||
}
|
||||
|
||||
void Alex2ESP::connect()
|
||||
{
|
||||
state = Alex2ESPState::CONNECTING;
|
||||
lastReconnectTime = millis();
|
||||
waitingSince = millis();
|
||||
mqttClient.connect();
|
||||
}
|
||||
|
||||
// Opens the session again after it has ended or could not be opened, whatever the reason: a password that was
|
||||
// refused is accepted once the account has been repaired, and a broker that was restarting is back later.
|
||||
void Alex2ESP::handleMqttReconnection()
|
||||
{
|
||||
if (state == Alex2ESPState::UNINITIALIZED || state == Alex2ESPState::INITIALIZED)
|
||||
if (state == Alex2ESPState::CONNECTING && millis() - waitingSince >= CONNECT_TIMEOUT_MS)
|
||||
{
|
||||
// The MQTT client reports the end of an attempt only when it had a TCP connection to close. Without one
|
||||
// (the name of the broker did not resolve) it would stay in its connecting state and ignore every connect().
|
||||
mqttClient.disconnect(true);
|
||||
if (state == Alex2ESPState::CONNECTING)
|
||||
{
|
||||
onMqttDisconnect(AsyncMqttClientDisconnectReason::TCP_DISCONNECTED);
|
||||
}
|
||||
}
|
||||
|
||||
if (state != Alex2ESPState::DISCONNECTED || !backoff.due(millis(), waitingSince))
|
||||
{
|
||||
return;
|
||||
}
|
||||
if (!mqttClient.connected() && disconnectReason == AsyncMqttClientDisconnectReason::TCP_DISCONNECTED)
|
||||
if (WiFi.status() != WL_CONNECTED)
|
||||
{
|
||||
if (millis() - lastReconnectTime > RECONNECT_INTERVAL_MS)
|
||||
{
|
||||
lastReconnectTime = millis();
|
||||
mqttClient.connect();
|
||||
}
|
||||
// An attempt without a link fails at once and would only lengthen the wait
|
||||
return;
|
||||
}
|
||||
backoff.attempt();
|
||||
connect();
|
||||
}
|
||||
|
||||
void Alex2ESP::onMqttConnect(bool sessionPresent)
|
||||
|
|
@ -201,6 +264,7 @@ void Alex2ESP::onMqttConnect(bool sessionPresent)
|
|||
mqttClient.disconnect();
|
||||
return;
|
||||
}
|
||||
backoff.reset();
|
||||
ALEX2ESP_LOGI("connected to %s, subscribing", MQTT_SERVER);
|
||||
}
|
||||
|
||||
|
|
@ -230,8 +294,20 @@ void Alex2ESP::onMqttDisconnect(AsyncMqttClientDisconnectReason reason)
|
|||
{
|
||||
state = Alex2ESPState::DISCONNECTED;
|
||||
disconnectReason = reason;
|
||||
waitingSince = millis();
|
||||
directives.cancelArrival();
|
||||
ALEX2ESP_LOGI("disconnected (reason %u)", (unsigned)reason);
|
||||
|
||||
char words[96];
|
||||
strncpy_P(words, disconnectReasonText(reason), sizeof(words) - 1);
|
||||
words[sizeof(words) - 1] = '\0';
|
||||
if (WiFi.status() == WL_CONNECTED)
|
||||
{
|
||||
ALEX2ESP_LOGE("disconnected: %s; next attempt in %u s", words, (unsigned)(backoff.wait() / 1000));
|
||||
}
|
||||
else
|
||||
{
|
||||
ALEX2ESP_LOGE("disconnected: %s; next attempt when Wi-Fi is back", words);
|
||||
}
|
||||
}
|
||||
|
||||
// Runs in the network context, once per fragment of a message. It only takes notes: loop() answers a Discover and
|
||||
|
|
|
|||
|
|
@ -45,7 +45,9 @@ public:
|
|||
|
||||
// Begin function for initialization: MQTT username, MQTT password, root topic (the same order as alex2node).
|
||||
// The username and the password are not copied: they have to stay valid for as long as the client is used.
|
||||
// Starts SNTP; loop() opens the MQTT session once the clock is set, or after 5 s without an answer.
|
||||
// Starts SNTP; loop() opens the MQTT session once Wi-Fi is up and the clock is set, or after 5 s of Wi-Fi
|
||||
// without an answer. A session that ends or is refused is opened again after 1 s, then 2 s, 4 s ... up to once
|
||||
// a minute, while Wi-Fi is up; the reason is printed and returned by getDisconnectReason().
|
||||
void begin(const char *username, const char *password, const char *rootTopic);
|
||||
Alex2ESPState getState() const;
|
||||
|
||||
|
|
@ -74,7 +76,7 @@ public:
|
|||
private:
|
||||
static const unsigned long CLOCK_WAIT_MS = 5000; // How long the first connect waits for SNTP
|
||||
static const unsigned long CLOCK_WARNING_MS = 60000; // How often an unset clock is reported while it is used
|
||||
static const unsigned long RECONNECT_INTERVAL_MS = 5000;
|
||||
static const unsigned long CONNECT_TIMEOUT_MS = 30000; // How long a connect may stay without an answer
|
||||
static const unsigned long DISCOVERY_WINDOW_MS = 5000; // How long the backend keeps collecting a discovery answer
|
||||
static const unsigned long DISCOVERY_RETRY_MS = 20; // Pause before a refused discovery publish is tried again
|
||||
|
||||
|
|
@ -89,10 +91,12 @@ private:
|
|||
Alex2ESPState state;
|
||||
AsyncMqttClientDisconnectReason disconnectReason;
|
||||
bool useSntp;
|
||||
unsigned long beginTime; // millis() when begin() ran
|
||||
unsigned long clockWaitStarted; // millis() when begin() ran, or when Wi-Fi was last seen down before the first connect
|
||||
bool linkWaitLogged; // The wait for Wi-Fi before the first connect has been reported
|
||||
bool clockWarned; // The unset clock has been reported
|
||||
unsigned long lastClockWarning; // millis() of that report
|
||||
unsigned long lastReconnectTime;
|
||||
unsigned long waitingSince; // millis() of the connect while CONNECTING, of the disconnect while DISCONNECTED
|
||||
AlexaReconnectBackoff backoff; // The wait before the next connect
|
||||
uint16_t discoverSubscription; // Packet ids of the two SUBSCRIBEs, to match their acknowledgements
|
||||
uint16_t directiveSubscription;
|
||||
uint8_t subscriptionsPending;
|
||||
|
|
@ -116,6 +120,7 @@ private:
|
|||
|
||||
//loop processing function
|
||||
void connectWhenClockIsSet();
|
||||
void connect();
|
||||
void warnAboutClock();
|
||||
void handleMqttReconnection();
|
||||
void continueDiscovery();
|
||||
|
|
|
|||
|
|
@ -194,6 +194,11 @@ bool AlexaRecentIds::seenBefore(const char *id)
|
|||
return false;
|
||||
}
|
||||
|
||||
void AlexaReconnectBackoff::attempt()
|
||||
{
|
||||
waitMs = (waitMs >= LONGEST_WAIT_MS / 2) ? LONGEST_WAIT_MS : waitMs * 2;
|
||||
}
|
||||
|
||||
uint64_t AlexaBridgeLogic::hashBytes(const char *data, size_t length, uint64_t hash)
|
||||
{
|
||||
for (size_t i = 0; i < length; i++)
|
||||
|
|
|
|||
|
|
@ -1,6 +1,6 @@
|
|||
// The parts of the bridge that are plain logic: reassembling a directive from the fragments the MQTT client hands
|
||||
// over, queueing directives for loop(), telling a repeated directive from a new one, the limits on what is received
|
||||
// and sent, topics and time stamps. Nothing here touches the MQTT client, Wi-Fi or Serial, so the same code runs in
|
||||
// and sent, the wait between reconnects, topics and time stamps. Nothing here touches the MQTT client, Wi-Fi or Serial, so the same code runs in
|
||||
// the host tests (test/test_bridge_logic, pio test -e native) with the byte sequences a broker would deliver.
|
||||
#ifndef ALEXA_BRIDGE_LOGIC_H
|
||||
#define ALEXA_BRIDGE_LOGIC_H
|
||||
|
|
@ -157,6 +157,32 @@ private:
|
|||
AlexaRecentHashes recent;
|
||||
};
|
||||
|
||||
// How long the bridge waits before it tries to open the MQTT session again: 1 s after a session ended, twice as
|
||||
// long after every attempt that failed, a minute at most. A broker that is down or refuses the credentials is asked
|
||||
// once a minute, and a session that dropped is back within seconds.
|
||||
class AlexaReconnectBackoff
|
||||
{
|
||||
public:
|
||||
static const uint32_t FIRST_WAIT_MS = 1000;
|
||||
static const uint32_t LONGEST_WAIT_MS = 60000;
|
||||
|
||||
// The wait before the next attempt
|
||||
uint32_t wait() const { return waitMs; }
|
||||
|
||||
// True when that wait is over. now and since are values of millis(), since the one of the moment the session
|
||||
// ended or the attempt failed; the difference is right across the overflow of millis() after 49 days.
|
||||
bool due(uint32_t now, uint32_t since) const { return now - since >= waitMs; }
|
||||
|
||||
// An attempt is made: if it fails, the one after it waits twice as long
|
||||
void attempt();
|
||||
|
||||
// A session is open: the first attempt after it has ended waits FIRST_WAIT_MS again
|
||||
void reset() { waitMs = FIRST_WAIT_MS; }
|
||||
|
||||
private:
|
||||
uint32_t waitMs = FIRST_WAIT_MS;
|
||||
};
|
||||
|
||||
namespace AlexaBridgeLogic
|
||||
{
|
||||
// FNV-1a, 64 bit. Two different texts have the same hash with a probability of 2^-64.
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue