Added MQTT Logs, and improved OTA and NTP to Async

This commit is contained in:
2025-12-28 18:39:13 +02:00
parent 8d397c6dd5
commit 0f0b67cab9
18 changed files with 568 additions and 123 deletions

View File

@@ -13,6 +13,7 @@
#include "../../Telemetry/Telemetry.hpp"
#include "../../Logging/Logging.hpp"
#include "../ResponseBuilder/ResponseBuilder.hpp"
#include "../CommunicationRouter/CommunicationRouter.hpp"
CommandHandler::CommandHandler(ConfigManager& configManager, OTAManager& otaManager)
: _configManager(configManager)
@@ -23,6 +24,7 @@ CommandHandler::CommandHandler(ConfigManager& configManager, OTAManager& otaMana
, _firmwareValidator(nullptr)
, _clientManager(nullptr)
, _telemetry(nullptr)
, _communicationRouter(nullptr)
, _responseCallback(nullptr) {}
CommandHandler::~CommandHandler() {}
@@ -51,6 +53,10 @@ void CommandHandler::setTelemetryReference(Telemetry* telemetry) {
_telemetry = telemetry;
}
void CommandHandler::setCommunicationRouterReference(CommunicationRouter* comm) {
_communicationRouter = comm;
}
void CommandHandler::setResponseCallback(ResponseCallback callback) {
_responseCallback = callback;
}
@@ -1025,6 +1031,10 @@ void CommandHandler::handleSystemCommand(JsonVariant contents, const MessageCont
handleSetSerialLogLevelCommand(contents, context);
} else if (action == "set_sd_log_level") {
handleSetSdLogLevelCommand(contents, context);
} else if (action == "set_mqtt_log_level") {
handleSetMqttLogLevelCommand(contents, context);
} else if (action == "set_mqtt_enabled") {
handleSetMqttEnabledCommand(contents, context);
} else {
LOG_WARNING("Unknown system action: %s", action.c_str());
sendErrorResponse("system", "Unknown action: " + action, context);
@@ -1089,8 +1099,76 @@ void CommandHandler::handleSetSdLogLevelCommand(JsonVariant contents, const Mess
LOG_ERROR("Failed to save SD log level to SD card");
}
} else {
sendErrorResponse("set_sd_log_level",
sendErrorResponse("set_sd_log_level",
"Invalid log level (must be 0-5)", context);
}
}
void CommandHandler::handleSetMqttLogLevelCommand(JsonVariant contents, const MessageContext& context) {
if (!contents.containsKey("level")) {
sendErrorResponse("set_mqtt_log_level", "Missing level parameter", context);
return;
}
uint8_t level = contents["level"].as<uint8_t>();
// Set the level in ConfigManager
if (_configManager.setMqttLogLevel(level)) {
// Apply the level to Logging immediately
Logging::setMqttLogLevel((Logging::LogLevel)level);
// Save to SD card
bool saved = _configManager.saveGeneralConfig();
if (saved) {
sendSuccessResponse("set_mqtt_log_level",
"MQTT log level set to " + String(level) + " and saved", context);
LOG_INFO("MQTT log level updated to %d", level);
} else {
sendErrorResponse("set_mqtt_log_level",
"Log level set but failed to save to SD card", context);
LOG_ERROR("Failed to save MQTT log level to SD card");
}
} else {
sendErrorResponse("set_mqtt_log_level",
"Invalid log level (must be 0-5)", context);
}
}
void CommandHandler::handleSetMqttEnabledCommand(JsonVariant contents, const MessageContext& context) {
if (!contents.containsKey("enabled")) {
sendErrorResponse("set_mqtt_enabled", "Missing enabled parameter", context);
return;
}
bool enabled = contents["enabled"].as<bool>();
// Set MQTT enabled state in ConfigManager
_configManager.setMqttEnabled(enabled);
// Save to SD card
bool saved = _configManager.saveGeneralConfig();
if (saved) {
sendSuccessResponse("set_mqtt_enabled",
String("MQTT ") + (enabled ? "enabled" : "disabled") + " and saved", context);
LOG_INFO("MQTT %s by user command", enabled ? "enabled" : "disabled");
// If disabling, disconnect MQTT immediately
// If enabling, trigger connection attempt
if (_communicationRouter) {
if (!enabled) {
_communicationRouter->getMQTTClient().disconnect();
} else {
_communicationRouter->getMQTTClient().connect();
}
} else {
LOG_WARNING("CommunicationRouter reference not set - cannot control MQTT");
}
} else {
sendErrorResponse("set_mqtt_enabled",
"MQTT state changed but failed to save to SD card", context);
LOG_ERROR("Failed to save MQTT enabled state to SD card");
}
}

View File

@@ -34,6 +34,7 @@ class Timekeeper;
class FirmwareValidator;
class ClientManager;
class Telemetry;
class CommunicationRouter;
class CommandHandler {
public:
@@ -67,6 +68,7 @@ public:
void setFirmwareValidatorReference(FirmwareValidator* fv);
void setClientManagerReference(ClientManager* cm);
void setTelemetryReference(Telemetry* telemetry);
void setCommunicationRouterReference(CommunicationRouter* comm);
/**
* @brief Set response callback for sending responses back
@@ -90,6 +92,7 @@ private:
FirmwareValidator* _firmwareValidator;
ClientManager* _clientManager;
Telemetry* _telemetry;
CommunicationRouter* _communicationRouter;
ResponseCallback _responseCallback;
// Response helpers
@@ -146,4 +149,8 @@ private:
// Log Level Commands
void handleSetSerialLogLevelCommand(JsonVariant contents, const MessageContext& context);
void handleSetSdLogLevelCommand(JsonVariant contents, const MessageContext& context);
void handleSetMqttLogLevelCommand(JsonVariant contents, const MessageContext& context);
// MQTT Control Commands
void handleSetMqttEnabledCommand(JsonVariant contents, const MessageContext& context);
};

View File

@@ -60,6 +60,21 @@ void CommunicationRouter::begin() {
_mqttClient.setCallback([this](const String& topic, const String& payload) {
onMqttMessage(topic, payload);
});
// Setup MQTT logging callback
String logTopic = "vesper/" + _configManager.getDeviceUID() + "/logs";
Logging::setMqttPublishCallback(
[this](const String& topic, const String& payload, int qos) {
_mqttClient.publish(topic, payload, qos, false);
},
logTopic
);
// Apply MQTT log level from config
uint8_t mqttLogLevel = _configManager.getMqttLogLevel();
Logging::setMqttLogLevel((Logging::LogLevel)mqttLogLevel);
LOG_INFO("MQTT logging enabled with level %d on topic: %s", mqttLogLevel, logTopic.c_str());
LOG_INFO("✅ MQTT client initialized");
} catch (...) {
LOG_ERROR("❌ MQTT initialization failed, but WebSocket is still available");
@@ -68,12 +83,16 @@ void CommunicationRouter::begin() {
// 🔥 CRITICAL FIX: Connect ClientManager to CommandHandler
_commandHandler.setClientManagerReference(&_clientManager);
LOG_INFO("ClientManager reference set for CommandHandler");
// 🔥 Set CommunicationRouter reference for MQTT control commands
_commandHandler.setCommunicationRouterReference(this);
LOG_INFO("CommunicationRouter reference set for CommandHandler");
// Setup command handler response callback
_commandHandler.setResponseCallback([this](const String& response, const CommandHandler::MessageContext& context) {
sendResponse(response, context);
});
LOG_INFO("Communication Router initialized with modular architecture");
}
@@ -121,7 +140,7 @@ void CommunicationRouter::setupUdpDiscovery() {
StaticJsonDocument<128> req;
DeserializationError err = deserializeJson(req, msg);
if (!err) {
shouldReply = (req["op"] == "discover" && req["svc"] == "vesper");
shouldReply = (req["op"] == "discover");
}
}
@@ -136,7 +155,7 @@ void CommunicationRouter::setupUdpDiscovery() {
doc["id"] = _configManager.getDeviceUID();
doc["ip"] = _networking.getLocalIP();
char wsUrl[64];
snprintf(wsUrl, sizeof(wsUrl), "ws://%s/ws", _networking.getLocalIP().c_str());
snprintf(wsUrl, sizeof(wsUrl), "ws://%s:80/ws", _networking.getLocalIP().c_str());
doc["ws"] = wsUrl;
doc["port"] = 80;
doc["fw"] = "2.0";

View File

@@ -73,7 +73,10 @@ public:
bool hasActiveWebSocketClients() const;
size_t getWebSocketClientCount() const;
bool isHealthy() const;
// Component accessors
MQTTAsyncClient& getMQTTClient() { return _mqttClient; }
// Broadcast methods
void broadcastStatus(const String& statusMessage);
void broadcastStatus(const JsonDocument& statusJson);

View File

@@ -12,21 +12,33 @@ MQTTAsyncClient* MQTTAsyncClient::_instance = nullptr;
MQTTAsyncClient::MQTTAsyncClient(ConfigManager& configManager, Networking& networking)
: _configManager(configManager)
, _networking(networking)
, _messageCallback(nullptr)
, _messageCallback(nullptr)
, _mqttReconnectTimer(nullptr)
, _heartbeatTimer(nullptr) {
, _networkStabilizationTimer(nullptr)
, _heartbeatTimer(nullptr)
, _reconnectAttempts(0)
, _lastConnectionAttempt(0) {
_instance = this; // Set static instance pointer
// Create reconnection timer
// Create reconnection timer (initial delay will be calculated dynamically)
_mqttReconnectTimer = xTimerCreate(
"mqttReconnect", // Timer name (for debugging)
pdMS_TO_TICKS(MQTT_RECONNECT_DELAY), // Period: 5000ms = 5 seconds
pdMS_TO_TICKS(MQTT_RECONNECT_BASE_DELAY), // Initial period: 5000ms = 5 seconds
pdFALSE, // One-shot (false) or Auto-reload (true)
(void*)0, // Timer ID (can store data)
mqttReconnectTimerCallback // Callback function when timer expires
);
// Create network stabilization timer (one-shot, 2 seconds)
_networkStabilizationTimer = xTimerCreate(
"mqttNetStable", // Timer name
pdMS_TO_TICKS(NETWORK_STABILIZATION_DELAY), // Period: 2000ms = 2 seconds
pdFALSE, // One-shot timer
(void*)0, // Timer ID
networkStabilizationTimerCallback // Callback function
);
// Create heartbeat timer (auto-reload every 30 seconds)
_heartbeatTimer = xTimerCreate(
"mqttHeartbeat", // Timer name
@@ -42,6 +54,10 @@ MQTTAsyncClient::~MQTTAsyncClient() {
if (_mqttReconnectTimer) {
xTimerDelete(_mqttReconnectTimer, portMAX_DELAY);
}
if (_networkStabilizationTimer) {
xTimerStop(_networkStabilizationTimer, 0);
xTimerDelete(_networkStabilizationTimer, portMAX_DELAY);
}
if (_heartbeatTimer) {
xTimerStop(_heartbeatTimer, 0);
xTimerDelete(_heartbeatTimer, portMAX_DELAY);
@@ -98,17 +114,26 @@ void MQTTAsyncClient::begin() {
}
void MQTTAsyncClient::connect() {
auto& mqttConfig = _configManager.getMqttConfig();
// 🔥 Check if MQTT is enabled
if (!mqttConfig.enabled) {
LOG_DEBUG("MQTT is disabled in configuration - skipping connection");
return;
}
if (_mqttClient.connected()) {
LOG_DEBUG("Already connected to MQTT");
return;
}
auto& mqttConfig = _configManager.getMqttConfig();
// Track connection attempt
_lastConnectionAttempt = millis();
LOG_INFO("Free heap BEFORE MQTT connect: %d bytes", ESP.getFreeHeap());
_mqttClient.connect();
LOG_INFO("MQTT connect() called - waiting for async connection...");
}
@@ -118,17 +143,22 @@ void MQTTAsyncClient::disconnect() {
}
uint16_t MQTTAsyncClient::publish(const String& topic, const String& payload, int qos, bool retain) {
// Check if connected before attempting to publish
if (!_mqttClient.connected()) {
// Don't log error here - would cause infinite loop with MQTT logging
return 0;
}
// Build full topic (if relative)
String fullTopic = topic.startsWith("vesper/") ? topic : _dataTopic;
uint16_t packetId = _mqttClient.publish(fullTopic.c_str(), qos, retain, payload.c_str());
if (packetId > 0) {
LOG_DEBUG("Published to %s: %s (packetId=%d)", fullTopic.c_str(), payload.c_str(), packetId);
} else {
LOG_ERROR("Failed to publish to %s", fullTopic.c_str());
}
// REMOVED: Error logging here to prevent infinite recursion with MQTT logs
return packetId;
}
@@ -141,13 +171,28 @@ bool MQTTAsyncClient::isConnected() const {
}
void MQTTAsyncClient::onNetworkConnected() {
LOG_DEBUG("Network connected - waiting 2 seconds for network stack to stabilize...");
// Small delay to ensure network stack is fully ready
delay(2000);
LOG_DEBUG("Network stable - connecting to MQTT");
connect();
auto& mqttConfig = _configManager.getMqttConfig();
// 🔥 Only attempt connection if MQTT is enabled
if (!mqttConfig.enabled) {
LOG_DEBUG("Network connected but MQTT is disabled - skipping MQTT connection");
return;
}
LOG_DEBUG("Network connected - scheduling MQTT connection after 2s stabilization (non-blocking)");
// Reset reconnect attempts on fresh network connection
_reconnectAttempts = 0;
// 🔥 CRITICAL FIX: Use non-blocking timer instead of delay()
// This prevents blocking UDP discovery, WebSocket connections, and async operations
if (_networkStabilizationTimer) {
xTimerStart(_networkStabilizationTimer, 0);
} else {
LOG_ERROR("Network stabilization timer not initialized!");
// Fallback to immediate connection (better than blocking)
connect();
}
}
void MQTTAsyncClient::onNetworkDisconnected() {
@@ -166,15 +211,20 @@ void MQTTAsyncClient::subscribe() {
void MQTTAsyncClient::onMqttConnect(bool sessionPresent) {
LOG_INFO("✅ Connected to MQTT broker (session present: %s)", sessionPresent ? "yes" : "no");
LOG_INFO("🔍 Free heap AFTER MQTT connect: %d bytes", ESP.getFreeHeap());
// Reset reconnection attempts on successful connection
_reconnectAttempts = 0;
// Subscribe to control topic
subscribe();
// 🔥 Start heartbeat timer
startHeartbeat();
}
void MQTTAsyncClient::onMqttDisconnect(AsyncMqttClientDisconnectReason reason) {
auto& mqttConfig = _configManager.getMqttConfig();
const char* reasonStr;
switch(reason) {
case AsyncMqttClientDisconnectReason::TCP_DISCONNECTED:
@@ -199,14 +249,30 @@ void MQTTAsyncClient::onMqttDisconnect(AsyncMqttClientDisconnectReason reason) {
reasonStr = "Unknown";
break;
}
LOG_ERROR("❌ Disconnected from MQTT broker - Reason: %s (%d)", reasonStr, static_cast<int>(reason));
// Stop heartbeat timer when disconnected
stopHeartbeat();
if (_networking.isConnected()) {
LOG_INFO("Network still connected - scheduling MQTT reconnection in %d seconds", MQTT_RECONNECT_DELAY / 1000);
// 🔥 Don't attempt reconnection if MQTT is disabled
if (!mqttConfig.enabled) {
LOG_INFO("MQTT is disabled - not attempting reconnection");
return;
}
if (_networking.isConnected()) {
// Increment reconnection attempts
_reconnectAttempts++;
// Calculate backoff delay
unsigned long reconnectDelay = getReconnectDelay();
LOG_INFO("Network still connected - scheduling MQTT reconnection #%d in %lu seconds (backoff active)",
_reconnectAttempts, reconnectDelay / 1000);
// Update timer period with new delay
xTimerChangePeriod(_mqttReconnectTimer, pdMS_TO_TICKS(reconnectDelay), 0);
xTimerStart(_mqttReconnectTimer, 0);
} else {
LOG_INFO("Network is down - waiting for network to reconnect");
@@ -342,4 +408,43 @@ void MQTTAsyncClient::heartbeatTimerCallback(TimerHandle_t xTimer) {
if (MQTTAsyncClient::_instance) {
MQTTAsyncClient::_instance->publishHeartbeat();
}
}
// ═══════════════════════════════════════════════════════════════════════════════════
// NETWORK STABILIZATION - NON-BLOCKING TIMER APPROACH
// ═══════════════════════════════════════════════════════════════════════════════════
void MQTTAsyncClient::connectAfterStabilization() {
LOG_DEBUG("Network stabilization complete - connecting to MQTT");
connect();
}
void MQTTAsyncClient::networkStabilizationTimerCallback(TimerHandle_t xTimer) {
if (MQTTAsyncClient::_instance) {
MQTTAsyncClient::_instance->connectAfterStabilization();
}
}
// ═══════════════════════════════════════════════════════════════════════════════════
// EXPONENTIAL BACKOFF CALCULATION
// ═══════════════════════════════════════════════════════════════════════════════════
unsigned long MQTTAsyncClient::getReconnectDelay() {
// First 3 attempts: Quick retries (5 seconds each)
if (_reconnectAttempts <= MQTT_MAX_QUICK_RETRIES) {
return MQTT_RECONNECT_BASE_DELAY;
}
// After quick retries: Exponential backoff
// Formula: base_delay * 2^(attempts - quick_retries)
// Examples: 10s, 20s, 40s, 80s, 160s, 300s (capped at 5 minutes)
uint8_t backoffPower = _reconnectAttempts - MQTT_MAX_QUICK_RETRIES;
unsigned long delay = MQTT_RECONNECT_BASE_DELAY * (1 << backoffPower); // 2^backoffPower
// Cap at maximum delay (5 minutes)
if (delay > MQTT_RECONNECT_MAX_DELAY) {
delay = MQTT_RECONNECT_MAX_DELAY;
}
return delay;
}

View File

@@ -108,11 +108,22 @@ private:
void onMqttMessage(char* topic, char* payload, AsyncMqttClientMessageProperties properties, size_t len, size_t index, size_t total);
void onMqttPublish(uint16_t packetId);
// Reconnection Timer
// Reconnection Timer with Exponential Backoff
TimerHandle_t _mqttReconnectTimer;
static const unsigned long MQTT_RECONNECT_DELAY = 5000; // 5 seconds
static const unsigned long MQTT_RECONNECT_BASE_DELAY = 5000; // 5 seconds base
static const unsigned long MQTT_RECONNECT_MAX_DELAY = 300000; // 5 minutes max
static const uint8_t MQTT_MAX_QUICK_RETRIES = 3; // Try 3 times quickly
uint8_t _reconnectAttempts; // Track failed attempts
unsigned long _lastConnectionAttempt; // Track last attempt time
void attemptReconnection();
static void mqttReconnectTimerCallback(TimerHandle_t xTimer);
unsigned long getReconnectDelay(); // Calculate backoff delay
// Network Stabilization Timer (non-blocking replacement for delay)
TimerHandle_t _networkStabilizationTimer;
static const unsigned long NETWORK_STABILIZATION_DELAY = 2000; // 2 seconds
void connectAfterStabilization();
static void networkStabilizationTimerCallback(TimerHandle_t xTimer);
// Heartbeat Timer (30 seconds)
TimerHandle_t _heartbeatTimer;

View File

@@ -1163,6 +1163,16 @@ bool ConfigManager::setSdLogLevel(uint8_t level) {
return true;
}
bool ConfigManager::setMqttLogLevel(uint8_t level) {
if (level > 5) { // Max level is VERBOSE (5)
LOG_WARNING("ConfigManager - ⚠️ Invalid MQTT log level %d, valid range is 0-5", level);
return false;
}
generalConfig.mqttLogLevel = level;
LOG_DEBUG("ConfigManager - MQTT log level set to %d", level);
return true;
}
bool ConfigManager::loadGeneralConfig() {
if (!ensureSDCard()) return false;
@@ -1187,28 +1197,38 @@ bool ConfigManager::loadGeneralConfig() {
if (doc.containsKey("sdLogLevel")) {
generalConfig.sdLogLevel = doc["sdLogLevel"].as<uint8_t>();
}
LOG_DEBUG("ConfigManager - General config loaded - Serial log level: %d, SD log level: %d",
generalConfig.serialLogLevel, generalConfig.sdLogLevel);
if (doc.containsKey("mqttLogLevel")) {
generalConfig.mqttLogLevel = doc["mqttLogLevel"].as<uint8_t>();
}
if (doc.containsKey("mqttEnabled")) {
generalConfig.mqttEnabled = doc["mqttEnabled"].as<bool>();
mqttConfig.enabled = generalConfig.mqttEnabled; // Sync with mqttConfig
}
LOG_DEBUG("ConfigManager - General config loaded - Serial log level: %d, SD log level: %d, MQTT log level: %d, MQTT enabled: %s",
generalConfig.serialLogLevel, generalConfig.sdLogLevel, generalConfig.mqttLogLevel,
generalConfig.mqttEnabled ? "true" : "false");
return true;
}
bool ConfigManager::saveGeneralConfig() {
if (!ensureSDCard()) return false;
StaticJsonDocument<256> doc;
doc["serialLogLevel"] = generalConfig.serialLogLevel;
doc["sdLogLevel"] = generalConfig.sdLogLevel;
doc["mqttLogLevel"] = generalConfig.mqttLogLevel;
doc["mqttEnabled"] = generalConfig.mqttEnabled;
char buffer[256];
size_t len = serializeJson(doc, buffer, sizeof(buffer));
if (len == 0 || len >= sizeof(buffer)) {
LOG_ERROR("ConfigManager - ❌ Failed to serialize general config JSON");
return false;
}
saveFileToSD("/settings", "generalConfig.json", buffer);
LOG_DEBUG("ConfigManager - General config saved");
LOG_DEBUG("ConfigManager - General config saved (MQTT enabled: %s)", generalConfig.mqttEnabled ? "true" : "false");
return true;
}

View File

@@ -79,11 +79,12 @@ public:
* Username defaults to deviceUID for unique identification.
*/
struct MqttConfig {
IPAddress host = IPAddress(72,61,191,197); // 📡 Local Mosquitto broker
IPAddress host = IPAddress(72,61,191,197); // 📡 MQTT broker (default cloud broker)
int port = 1883; // 🔌 Standard MQTT port (non-SSL)
String user; // 👤 Auto-set to deviceUID
String password = "vesper"; // 🔑 Default password
bool useSSL = false; // 🔒 SSL disabled for local broker
bool enabled = true; // 🔘 MQTT enabled by default (can be toggled via command)
};
/**
@@ -212,7 +213,9 @@ public:
*/
struct GeneralConfig {
uint8_t serialLogLevel = 5;
uint8_t sdLogLevel = 0;
uint8_t sdLogLevel = 0;
uint8_t mqttLogLevel = 0;
bool mqttEnabled = true; // MQTT enabled by default
};
private:
@@ -396,8 +399,12 @@ public:
void setNighttimeSilenceOffTime(const String& time) { clockConfig.nighttimeSilenceOffTime = time; }
// General Config methods
bool setSerialLogLevel(uint8_t level);
bool setSerialLogLevel(uint8_t level);
bool setSdLogLevel(uint8_t level);
bool setMqttLogLevel(uint8_t level);
uint8_t getMqttLogLevel() const { return generalConfig.mqttLogLevel; }
void setMqttEnabled(bool enabled) { generalConfig.mqttEnabled = enabled; mqttConfig.enabled = enabled; }
bool getMqttEnabled() const { return generalConfig.mqttEnabled; }
bool loadGeneralConfig();
bool saveGeneralConfig();

View File

@@ -58,12 +58,30 @@ bool FileManager::ensureDirectoryExists(const String& dirPath) {
bool FileManager::downloadFile(const String& url, const String& directory, const String& filename) {
LOG_INFO("Starting download from: %s", url.c_str());
// Check if URL is HTTPS
bool isHttps = url.startsWith("https://");
HTTPClient http;
http.begin(url);
// Configure HTTP client based on protocol
if (isHttps) {
WiFiClientSecure* secureClient = new WiFiClientSecure();
secureClient->setInsecure(); // Skip certificate validation for Firebase
http.begin(*secureClient, url);
LOG_DEBUG("Using HTTPS with secure client");
} else {
http.begin(url);
LOG_DEBUG("Using HTTP");
}
http.setTimeout(30000); // 30 second timeout for large files
http.setFollowRedirects(HTTPC_FORCE_FOLLOW_REDIRECTS); // Follow redirects automatically
LOG_DEBUG("Sending HTTP GET request...");
int httpCode = http.GET();
if (httpCode != HTTP_CODE_OK) {
LOG_ERROR("HTTP GET failed, error: %s", http.errorToString(httpCode).c_str());
if (httpCode != HTTP_CODE_OK && httpCode != HTTP_CODE_MOVED_PERMANENTLY && httpCode != HTTP_CODE_FOUND) {
LOG_ERROR("HTTP GET failed, code: %d, error: %s", httpCode, http.errorToString(httpCode).c_str());
http.end();
return false;
}
@@ -92,17 +110,59 @@ bool FileManager::downloadFile(const String& url, const String& directory, const
return false;
}
// Get stream and file size
WiFiClient* stream = http.getStreamPtr();
uint8_t buffer[1024];
int bytesRead;
int contentLength = http.getSize();
LOG_DEBUG("Content length: %d bytes", contentLength);
while (http.connected() && (bytesRead = stream->readBytes(buffer, sizeof(buffer))) > 0) {
file.write(buffer, bytesRead);
uint8_t buffer[512]; // Smaller buffer for better responsiveness
size_t totalBytes = 0;
unsigned long lastYield = millis();
unsigned long lastLog = millis();
// Download with aggressive watchdog feeding
while (http.connected() && (contentLength <= 0 || totalBytes < contentLength)) {
// Check available data
size_t availableSize = stream->available();
if (availableSize) {
// Read available data (up to buffer size)
size_t readSize = availableSize > sizeof(buffer) ? sizeof(buffer) : availableSize;
int bytesRead = stream->readBytes(buffer, readSize);
if (bytesRead > 0) {
file.write(buffer, bytesRead);
totalBytes += bytesRead;
// Log progress every 5KB
if (millis() - lastLog > 5000) {
LOG_DEBUG("Download progress: %u bytes", totalBytes);
lastLog = millis();
}
}
}
// Aggressive task yielding every 100ms to prevent watchdog timeout
if (millis() - lastYield > 100) {
yield();
vTaskDelay(1 / portTICK_PERIOD_MS); // Let other tasks run
lastYield = millis();
}
// Exit if no data and connection closed
if (!availableSize && !http.connected()) {
break;
}
// Small delay if no data available yet
if (!availableSize) {
delay(10);
}
}
file.close();
http.end();
LOG_INFO("Download complete, file saved to: %s", fullPath.c_str());
LOG_INFO("Download complete, file saved to: %s (%u bytes)", fullPath.c_str(), totalBytes);
return true;
}

View File

@@ -22,6 +22,7 @@
#include <SD.h>
#include <HTTPClient.h>
#include <WiFiClient.h>
#include <WiFiClientSecure.h>
#include <ArduinoJson.h>
#include "../Logging/Logging.hpp"
#include "../ConfigManager/ConfigManager.hpp"

View File

@@ -1,7 +1,10 @@
#include "Logging.hpp"
// Initialize static member
Logging::LogLevel Logging::currentLevel = Logging::VERBOSE; // Default to DEBUG
// Initialize static members
Logging::LogLevel Logging::currentLevel = Logging::VERBOSE; // Default to VERBOSE
Logging::LogLevel Logging::mqttLogLevel = Logging::NONE; // Default MQTT logs OFF
Logging::MqttPublishCallback Logging::mqttPublishCallback = nullptr;
String Logging::mqttLogTopic = "";
void Logging::setLevel(LogLevel level) {
currentLevel = level;
@@ -12,6 +15,21 @@ Logging::LogLevel Logging::getLevel() {
return currentLevel;
}
void Logging::setMqttLogLevel(LogLevel level) {
mqttLogLevel = level;
Serial.printf("[LOGGING] MQTT log level set to %d\n", level);
}
Logging::LogLevel Logging::getMqttLogLevel() {
return mqttLogLevel;
}
void Logging::setMqttPublishCallback(MqttPublishCallback callback, const String& logTopic) {
mqttPublishCallback = callback;
mqttLogTopic = logTopic;
Serial.printf("[LOGGING] MQTT publish callback registered for topic: %s\n", logTopic.c_str());
}
bool Logging::isLevelEnabled(LogLevel level) {
return currentLevel >= level;
}
@@ -62,11 +80,59 @@ void Logging::verbose(const char* format, ...) {
}
void Logging::log(LogLevel level, const char* levelStr, const char* format, va_list args) {
Serial.printf("[%s] ", levelStr);
// Print the formatted message
char buffer[512];
vsnprintf(buffer, sizeof(buffer), format, args);
// Serial output
Serial.printf("[%s] ", levelStr);
Serial.print(buffer);
Serial.println();
// MQTT output (if enabled and callback is set)
if (mqttLogLevel >= level && mqttPublishCallback) {
publishToMqtt(level, levelStr, buffer);
}
}
void Logging::publishToMqtt(LogLevel level, const char* levelStr, const char* message) {
if (!mqttPublishCallback || mqttLogTopic.isEmpty()) {
return;
}
// CRITICAL: Prevent infinite recursion if MQTT publish fails
// Temporarily disable MQTT logging during publish to avoid cascading errors
static bool isPublishing = false;
if (isPublishing) {
return; // Already publishing, don't create recursive log loop
}
isPublishing = true;
// Build JSON manually to minimize stack usage (no StaticJsonDocument)
// Format: {"level":"🟢 INFO","message":"text","timestamp":12345}
String payload;
payload.reserve(600); // Pre-allocate to avoid fragmentation
payload = "{\"level\":\"";
payload += levelStr;
payload += "\",\"message\":\"";
// Escape special JSON characters in message
String escapedMsg = message;
escapedMsg.replace("\\", "\\\\");
escapedMsg.replace("\"", "\\\"");
escapedMsg.replace("\n", "\\n");
escapedMsg.replace("\r", "\\r");
payload += escapedMsg;
payload += "\",\"timestamp\":";
payload += millis();
payload += "}";
// Publish with QoS 1 (guaranteed delivery)
// Note: If this fails, it won't trigger another MQTT log due to isPublishing flag
mqttPublishCallback(mqttLogTopic, payload, 1);
isPublishing = false;
}

View File

@@ -19,6 +19,9 @@
#include <Arduino.h>
// Forward declaration
class MQTTAsyncClient;
class Logging {
public:
// Log Levels
@@ -28,31 +31,47 @@ public:
WARNING = 2, // Warnings and errors
INFO = 3, // Info, warnings, and errors
DEBUG = 4, // Debug logs. Really high level (full debugging)
VERBOSE = 5 // Nearly every command gets printed
VERBOSE = 5 // Nearly every command gets printed
};
// MQTT Log Publishing Callback
using MqttPublishCallback = std::function<void(const String& topic, const String& payload, int qos)>;
private:
static LogLevel currentLevel;
static LogLevel mqttLogLevel;
static MqttPublishCallback mqttPublishCallback;
static String mqttLogTopic;
public:
// Set the active log level
static void setLevel(LogLevel level);
// Get current log level
static LogLevel getLevel();
// Set MQTT log level (independent from serial logging)
static void setMqttLogLevel(LogLevel level);
// Get MQTT log level
static LogLevel getMqttLogLevel();
// Set MQTT callback for publishing logs
static void setMqttPublishCallback(MqttPublishCallback callback, const String& logTopic);
// Logging functions
static void error(const char* format, ...);
static void warning(const char* format, ...);
static void info(const char* format, ...);
static void debug(const char* format, ...);
static void verbose(const char* format, ...);
// Check if level is enabled (for conditional logging)
static bool isLevelEnabled(LogLevel level);
private:
static void log(LogLevel level, const char* levelStr, const char* format, va_list args);
static void publishToMqtt(LogLevel level, const char* levelStr, const char* message);
};
// Convenience macros for easier use

View File

@@ -5,7 +5,7 @@
#include <nvs_flash.h>
#include <nvs.h>
OTAManager::OTAManager(ConfigManager& configManager)
OTAManager::OTAManager(ConfigManager& configManager)
: _configManager(configManager)
, _fileManager(nullptr)
, _player(nullptr)
@@ -21,7 +21,8 @@ OTAManager::OTAManager(ConfigManager& configManager)
, _isEmergency(false)
, _progressCallback(nullptr)
, _statusCallback(nullptr)
, _scheduledCheckTimer(NULL) {
, _scheduledCheckTimer(NULL)
, _initialCheckTimer(NULL) {
}
OTAManager::~OTAManager() {
@@ -30,12 +31,17 @@ OTAManager::~OTAManager() {
xTimerDelete(_scheduledCheckTimer, portMAX_DELAY);
_scheduledCheckTimer = NULL;
}
if (_initialCheckTimer != NULL) {
xTimerStop(_initialCheckTimer, 0);
xTimerDelete(_initialCheckTimer, portMAX_DELAY);
_initialCheckTimer = NULL;
}
}
void OTAManager::begin() {
LOG_INFO("OTA Manager initialized");
setStatus(Status::IDLE);
// Create timer for scheduled checks (checks every minute if it's 3:00 AM)
_scheduledCheckTimer = xTimerCreate(
"OTA_Schedule",
@@ -44,13 +50,30 @@ void OTAManager::begin() {
this, // Timer ID (pass OTAManager instance)
scheduledCheckCallback
);
if (_scheduledCheckTimer != NULL) {
xTimerStart(_scheduledCheckTimer, 0);
LOG_INFO("OTA scheduled check timer started (will check at 3:00 AM)");
} else {
LOG_ERROR("Failed to create OTA scheduled check timer!");
}
// 🔥 NEW: Create one-shot timer for initial boot check (5 seconds after boot)
// This prevents blocking during critical connection phase
_initialCheckTimer = xTimerCreate(
"OTA_InitCheck",
pdMS_TO_TICKS(5000), // 5 seconds delay
pdFALSE, // One-shot timer
this, // Timer ID (pass OTAManager instance)
initialCheckCallback
);
if (_initialCheckTimer != NULL) {
xTimerStart(_initialCheckTimer, 0);
LOG_INFO("OTA initial check scheduled for 5 seconds after boot (non-blocking)");
} else {
LOG_ERROR("Failed to create OTA initial check timer!");
}
}
void OTAManager::setFileManager(FileManager* fm) {
@@ -61,18 +84,33 @@ void OTAManager::setPlayer(Player* player) {
_player = player;
}
// ✅ NEW: Static timer callback for initial boot check
void OTAManager::initialCheckCallback(TimerHandle_t xTimer) {
OTAManager* ota = static_cast<OTAManager*>(pvTimerGetTimerID(xTimer));
if (ota) {
LOG_INFO("🚀 Running initial OTA check (non-blocking, async)");
ota->performInitialCheck();
}
}
// ✅ NEW: Perform initial OTA check (async, non-blocking)
void OTAManager::performInitialCheck() {
// This runs asynchronously, won't block WebSocket/UDP/MQTT
checkForUpdates();
}
// ✅ NEW: Static timer callback for scheduled checks
void OTAManager::scheduledCheckCallback(TimerHandle_t xTimer) {
OTAManager* ota = static_cast<OTAManager*>(pvTimerGetTimerID(xTimer));
// Get current time
time_t now = time(nullptr);
struct tm* timeinfo = localtime(&now);
// Only proceed if it's exactly 3:00 AM
if (timeinfo->tm_hour == 3 && timeinfo->tm_min == 0) {
LOG_INFO("🕒 3:00 AM - Running scheduled OTA check");
// Check if player is idle before proceeding
if (!ota->isPlayerActive()) {
LOG_INFO("✅ Player is idle - checking for emergency updates");

View File

@@ -121,6 +121,11 @@ private:
// NEW: Scheduled check timer
TimerHandle_t _scheduledCheckTimer;
static void scheduledCheckCallback(TimerHandle_t xTimer);
// Initial boot check timer (non-blocking delayed check)
TimerHandle_t _initialCheckTimer;
static void initialCheckCallback(TimerHandle_t xTimer);
void performInitialCheck(); // Async initial check after boot
void setStatus(Status status, ErrorCode error = ErrorCode::NONE);
void notifyProgress(size_t current, size_t total);

View File

@@ -6,7 +6,7 @@ void Telemetry::begin() {
for (uint8_t i = 0; i < 16; i++) {
strikeCounters[i] = 0;
bellLoad[i] = 0;
bellMaxLoad[i] = 60; // Default max load
bellMaxLoad[i] = 200; // Default max load
}
coolingActive = false;

View File

@@ -135,47 +135,40 @@ unsigned long Timekeeper::getTime() {
void Timekeeper::syncTimeWithNTP() {
// Check if we have network connection and required dependencies
if (!_networking || !_configManager) {
LOG_ERROR("Cannot sync time: Networking or ConfigManager not set");
LOG_WARNING("Cannot sync time: Networking or ConfigManager not set - using RTC time");
return;
}
if (!_networking->isConnected()) {
LOG_WARNING("Cannot sync time: No network connection");
LOG_INFO("No network connection - skipping NTP sync, using RTC time");
return;
}
LOG_INFO("Syncing time with NTP server...");
LOG_INFO("⏰ Starting non-blocking NTP sync...");
// Get config from ConfigManager
auto& timeConfig = _configManager->getTimeConfig();
// Configure NTP with settings from config
configTime(timeConfig.gmtOffsetSec, timeConfig.daylightOffsetSec, timeConfig.ntpServer.c_str());
// Wait for time sync with timeout
// 🔥 NON-BLOCKING: Try to get time immediately without waiting
struct tm timeInfo;
int attempts = 0;
while (!getLocalTime(&timeInfo) && attempts < 10) {
LOG_DEBUG("Waiting for NTP sync... attempt %d", attempts + 1);
delay(1000);
attempts++;
}
if (attempts >= 10) {
LOG_ERROR("Failed to obtain time from NTP server after 10 attempts");
return;
}
if (getLocalTime(&timeInfo, 100)) { // 100ms timeout instead of blocking
// Success! Update RTC with synchronized time
rtc.adjust(DateTime(timeInfo.tm_year + 1900, timeInfo.tm_mon + 1, timeInfo.tm_mday,
timeInfo.tm_hour, timeInfo.tm_min, timeInfo.tm_sec));
// Update RTC with synchronized time
rtc.adjust(DateTime(timeInfo.tm_year + 1900, timeInfo.tm_mon + 1, timeInfo.tm_mday,
timeInfo.tm_hour, timeInfo.tm_min, timeInfo.tm_sec));
LOG_INFO("✅ NTP sync successful: %04d-%02d-%02d %02d:%02d:%02d",
timeInfo.tm_year + 1900, timeInfo.tm_mon + 1, timeInfo.tm_mday,
timeInfo.tm_hour, timeInfo.tm_min, timeInfo.tm_sec);
LOG_INFO("Time synced successfully: %04d-%02d-%02d %02d:%02d:%02d",
timeInfo.tm_year + 1900, timeInfo.tm_mon + 1, timeInfo.tm_mday,
timeInfo.tm_hour, timeInfo.tm_min, timeInfo.tm_sec);
// Reload today's events since the time might have changed significantly
loadTodaysEvents();
// Reload today's events since the time might have changed significantly
loadTodaysEvents();
} else {
// No internet or NTP server unreachable - this is NORMAL for local networks
LOG_INFO("⚠️ NTP sync skipped (no internet) - using RTC time. This is normal for local networks.");
}
}
// ════════════════════════════════════════════════════════════════════════════

View File

@@ -62,7 +62,7 @@
* 👨‍💻 AUTHOR: BellSystems bonamin
*/
#define FW_VERSION "131"
#define FW_VERSION "137"
/*
@@ -72,6 +72,7 @@
* v0.1 (100) - Vesper Launch Beta
* v1.2 (120) - Added Log Level Configuration via App/MQTT
* v1.3 (130) - Added Telemetry Reports to App, Various Playback Fixes
* v137 - Made OTA and MQTT delays Async
* ═══════════════════════════════════════════════════════════════════════════════
* NOTE: Versions are now stored as integers (v1.3 = 130)
* ═══════════════════════════════════════════════════════════════════════════════
@@ -196,7 +197,8 @@ void setup()
{
// Initialize Serial Communications (for debugging) & I2C Bus (for Hardware Control)
Serial.begin(115200);
Serial.println("Hello, VESPER System Initialized! - PontikoTest");
Serial.print("VESPER System Booting UP! - Version ");
Serial.println(FW_VERSION);
Wire.begin(4,15);
auto& hwConfig = configManager.getHardwareConfig();
SPI.begin(hwConfig.ethSpiSck, hwConfig.ethSpiMiso, hwConfig.ethSpiMosi);
@@ -340,53 +342,55 @@ void setup()
// 🔔 CONNECT BELLENGINE TO COMMUNICATION FOR DING NOTIFICATIONS!
bellEngine.setCommunicationManager(&communication);
// Track if AsyncWebServer has been started to prevent duplicates
static bool webServerStarted = false;
// Set up network callbacks
networking.setNetworkCallbacks(
[]() {
[&webServerStarted]() {
communication.onNetworkConnected();
// Sync time with NTP server when network becomes available
LOG_INFO("⏰ Syncing time with NTP server...");
// Non-blocking NTP sync (graceful without internet)
timekeeper.syncTimeWithNTP();
// Start AsyncWebServer when network becomes available
if (networking.getState() != NetworkState::WIFI_PORTAL_MODE) {
// Start AsyncWebServer when network becomes available (only once!)
if (!webServerStarted && networking.getState() != NetworkState::WIFI_PORTAL_MODE) {
LOG_INFO("🚀 Starting AsyncWebServer on port 80...");
server.begin();
LOG_INFO("✅ AsyncWebServer started on http://%s", networking.getLocalIP().c_str());
webServerStarted = true;
}
}, // onConnected
[]() { communication.onNetworkDisconnected(); } // onDisconnected
);
// If already connected, trigger MQTT connection manually
// If already connected, trigger MQTT connection and setup manually
if (networking.isConnected()) {
LOG_INFO("Network already connected - triggering MQTT connection");
LOG_INFO("Network already connected - initializing services");
communication.onNetworkConnected();
// Sync time with NTP server if network is already connected
LOG_INFO("⏰ Syncing time with NTP server...");
// Non-blocking NTP sync (graceful without internet)
timekeeper.syncTimeWithNTP();
// 🔥 CRITICAL: Start AsyncWebServer ONLY when network is ready
// Do NOT start if WiFiManager portal is active (port 80 conflict!)
LOG_INFO("🚀 Starting AsyncWebServer on port 80...");
server.begin();
LOG_INFO("✅ AsyncWebServer started and listening on http://%s", networking.getLocalIP().c_str());
if (!webServerStarted && networking.getState() != NetworkState::WIFI_PORTAL_MODE) {
LOG_INFO("🚀 Starting AsyncWebServer on port 80...");
server.begin();
LOG_INFO("✅ AsyncWebServer started on http://%s", networking.getLocalIP().c_str());
webServerStarted = true;
}
} else {
LOG_WARNING("⚠️ Network not ready - AsyncWebServer will start after connection");
LOG_WARNING("⚠️ Network not ready - services will start after connection");
}
delay(500);
// Initialize OTA Manager and check for updates
// Initialize OTA Manager
otaManager.begin();
otaManager.setFileManager(&fileManager);
otaManager.setPlayer(&player); // Set player reference for idle check
// 🔥 CRITICAL: Delay OTA check to avoid UDP socket race with MQTT
// Both MQTT and OTA HTTP use UDP sockets, must sequence them!
delay(2000);
LOG_INFO("Starting OTA update check after network stabilization...");
otaManager.checkForUpdates();
// 🔥 FIX: OTA check will happen asynchronously via scheduled timer (no blocking delay)
// UDP discovery setup can happen immediately without conflicts
communication.setupUdpDiscovery();
// Register OTA Manager with health monitor
@@ -457,6 +461,14 @@ void loop()
}
}
// 🔥 CRITICAL: Clean up dead WebSocket connections every 2 seconds
// This prevents ghost connections from blocking new clients
static unsigned long lastWsCleanup = 0;
if (millis() - lastWsCleanup > 2000) {
ws.cleanupClients();
lastWsCleanup = millis();
}
// 🔥 DEBUG: Log every 10 seconds to verify we're still running
static unsigned long lastLog = 0;
if (millis() - lastLog > 10000) {