Files
project-vesper/vesper/src/OTAManager/OTAManager.cpp

1239 lines
45 KiB
C++

#include "OTAManager.hpp"
#include "../ConfigManager/ConfigManager.hpp"
#include "../Logging/Logging.hpp"
#include "../Player/Player.hpp"
#include "../SDCardMutex/SDCardMutex.hpp"
#include <nvs_flash.h>
#include <nvs.h>
#include <esp_task_wdt.h>
OTAManager::OTAManager(ConfigManager& configManager)
: _configManager(configManager)
, _fileManager(nullptr)
, _player(nullptr)
, _timeKeeper(nullptr)
, _telemetry(nullptr)
, _status(Status::IDLE)
, _lastError(ErrorCode::NONE)
, _availableVersion(0.0f)
, _minVersion(0.0f)
, _expectedFileSize(0)
, _updateAvailable(false)
, _availableChecksum("")
, _updateChannel("stable")
, _isMandatory(false)
, _isEmergency(false)
, _progressCallback(nullptr)
, _statusCallback(nullptr)
, _scheduledCheckTimer(NULL)
, _initialCheckTimer(NULL)
, _otaWorkerTask(NULL)
, _otaWorkSignal(NULL)
, _pendingWork(OTAWorkType::NONE) {
}
OTAManager::~OTAManager() {
// Clean up worker task and semaphore
if (_otaWorkerTask != NULL) {
vTaskDelete(_otaWorkerTask);
_otaWorkerTask = NULL;
}
if (_otaWorkSignal != NULL) {
vSemaphoreDelete(_otaWorkSignal);
_otaWorkSignal = NULL;
}
if (_scheduledCheckTimer != NULL) {
xTimerStop(_scheduledCheckTimer, 0);
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 semaphore for worker task signaling
_otaWorkSignal = xSemaphoreCreateBinary();
if (_otaWorkSignal == NULL) {
LOG_ERROR("Failed to create OTA work semaphore!");
return;
}
// Create dedicated worker task with 8KB stack (prevents timer task overflow)
BaseType_t taskCreated = xTaskCreatePinnedToCore(
otaWorkerTaskFunction,
"OTA_Worker",
8192, // 8KB stack - plenty for HTTP and JSON operations
this, // Pass OTAManager instance
2, // Priority 2 (lower than critical tasks)
&_otaWorkerTask,
0 // Core 0
);
if (taskCreated != pdPASS) {
LOG_ERROR("Failed to create OTA worker task!");
vSemaphoreDelete(_otaWorkSignal);
_otaWorkSignal = NULL;
return;
}
LOG_INFO("OTA worker task created with 8KB stack on Core 0");
// Create timer for scheduled checks (checks every minute if it's 3:00 AM)
_scheduledCheckTimer = xTimerCreate(
"OTA_Schedule",
pdMS_TO_TICKS(60000), // Check every minute
pdTRUE, // Auto-reload (periodic)
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) {
_fileManager = fm;
}
void OTAManager::setPlayer(Player* player) {
_player = player;
}
void OTAManager::setTimeKeeper(Timekeeper* tk) {
_timeKeeper = tk;
}
void OTAManager::setTelemetry(Telemetry* telemetry) {
_telemetry = telemetry;
}
// ✅ NEW: Static timer callback for initial boot check
// CRITICAL: Timer callbacks run in Timer Service task with limited stack!
// We ONLY set a flag here - actual work is done by dedicated worker task
void OTAManager::initialCheckCallback(TimerHandle_t xTimer) {
OTAManager* ota = static_cast<OTAManager*>(pvTimerGetTimerID(xTimer));
if (ota && ota->_otaWorkSignal) {
// Signal worker task to perform initial check
ota->_pendingWork = OTAWorkType::INITIAL_CHECK;
xSemaphoreGive(ota->_otaWorkSignal);
}
}
// ✅ NEW: Perform initial OTA check (async, non-blocking)
void OTAManager::performInitialCheck() {
// This runs asynchronously in worker task, won't block WebSocket/UDP/MQTT
checkForUpdates();
}
// ✅ NEW: Static timer callback for scheduled checks
// CRITICAL: Timer callbacks run in Timer Service task with limited stack!
// We ONLY set a flag here - actual work is done by dedicated worker task
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) {
// Check if player is idle before signaling worker
if (!ota->isPlayerActive() && ota->_otaWorkSignal) {
// Signal worker task to perform scheduled check
ota->_pendingWork = OTAWorkType::SCHEDULED_CHECK;
xSemaphoreGive(ota->_otaWorkSignal);
} else if (ota->isPlayerActive()) {
LOG_WARNING("⚠️ Player is active - skipping scheduled update check");
}
}
}
// ✅ NEW: Check for emergency updates only (called by scheduled timer)
void OTAManager::checkForEmergencyUpdates() {
if (_status != Status::IDLE) {
LOG_WARNING("OTA check already in progress");
return;
}
LOG_INFO("Checking for EMERGENCY updates only...");
checkForUpdates("stable"); // Check stable channel
// Only proceed if emergency flag is set
if (_updateAvailable && _isEmergency) {
LOG_INFO("🚨 EMERGENCY update detected during scheduled check - updating immediately");
update("stable");
} else if (_updateAvailable && _isMandatory) {
LOG_INFO("⚠️ Mandatory update available, but will wait for next boot");
} else {
LOG_INFO("✅ No emergency updates available");
}
}
void OTAManager::checkForUpdates() {
// Boot-time check: only check stable channel for emergency/mandatory updates
checkForUpdates("stable");
}
void OTAManager::checkForUpdates(const String& channel) {
if (_status != Status::IDLE) {
LOG_WARNING("OTA check already in progress");
return;
}
// 🔥 CRITICAL: Check network connectivity before attempting HTTP requests
if (WiFi.status() != WL_CONNECTED && !ETH.linkUp()) {
LOG_WARNING("OTA check skipped - no network connectivity");
return;
}
setStatus(Status::CHECKING_VERSION);
LOG_INFO("Checking for firmware updates in %s channel for %s...",
channel.c_str(), _configManager.getHardwareVariant().c_str());
if (checkVersion(channel)) {
uint16_t currentVersion = getCurrentVersion();
LOG_INFO("Current version: %u, Available version: %u (Channel: %s)",
currentVersion, _availableVersion, channel.c_str());
if (_availableVersion > currentVersion) {
_updateAvailable = true;
LOG_INFO("New version available! Mandatory: %s, Emergency: %s",
_isMandatory ? "YES" : "NO", _isEmergency ? "YES" : "NO");
setStatus(Status::IDLE);
// Auto-update for emergency or mandatory updates during boot check
if (channel == "stable" && (_isEmergency || _isMandatory)) {
LOG_INFO("Emergency/Mandatory update detected - starting automatic update");
update(channel);
}
} else {
_updateAvailable = false;
LOG_INFO("No new version available");
setStatus(Status::IDLE);
}
} else {
_updateAvailable = false;
setStatus(Status::FAILED, _lastError);
}
}
void OTAManager::update() {
update("stable"); // Default to stable channel
}
void OTAManager::update(const String& channel) {
if (_status != Status::IDLE) {
LOG_WARNING("OTA update already in progress");
return;
}
if (!_updateAvailable) {
LOG_WARNING("No update available for channel: %s", channel.c_str());
return;
}
LOG_INFO("Starting OTA update from %s channel...", channel.c_str());
setStatus(Status::DOWNLOADING);
if (downloadAndInstall(channel)) {
setStatus(Status::SUCCESS);
LOG_INFO("Update successfully finished. Rebooting...");
delay(1000);
ESP.restart();
} else {
setStatus(Status::FAILED, _lastError);
}
}
uint16_t OTAManager::getCurrentVersion() const {
String fwVersionStr = _configManager.getFwVersion();
// Parse integer directly: "130" -> 130
return fwVersionStr.toInt();
}
void OTAManager::setStatus(Status status, ErrorCode error) {
_status = status;
_lastError = error;
if (_statusCallback) {
_statusCallback(status, error);
}
}
void OTAManager::notifyProgress(size_t current, size_t total) {
if (_progressCallback) {
_progressCallback(current, total);
}
}
// ✅ ENHANCED: Version checking with full validation
bool OTAManager::checkVersion(const String& channel) {
std::vector<String> servers = _configManager.getUpdateServers();
auto& updateConfig = _configManager.getUpdateConfig();
for (size_t serverIndex = 0; serverIndex < servers.size(); serverIndex++) {
String baseUrl = servers[serverIndex];
String metadataUrl = baseUrl + "/ota/" + _configManager.getHardwareVariant() + "/" + channel + "/metadata.json";
LOG_INFO("OTA: Trying server %d/%d: %s", serverIndex + 1, servers.size(), baseUrl.c_str());
HTTPClient http;
http.setTimeout(updateConfig.timeout);
http.begin(metadataUrl.c_str());
int retryCount = 0;
int httpCode = -1;
// Retry logic for current server
while (retryCount < updateConfig.retries && httpCode != HTTP_CODE_OK) {
if (retryCount > 0) {
LOG_INFO("OTA: Retry %d/%d for %s", retryCount + 1, updateConfig.retries, baseUrl.c_str());
delay(1000 * retryCount); // Exponential backoff
}
httpCode = http.GET();
retryCount++;
}
if (httpCode == HTTP_CODE_OK) {
String jsonStr = http.getString();
http.end();
// Parse JSON metadata
DynamicJsonDocument doc(1024);
DeserializationError error = deserializeJson(doc, jsonStr);
if (error) {
LOG_ERROR("OTA: Failed to parse metadata JSON from %s: %s",
baseUrl.c_str(), error.c_str());
continue; // Try next server
}
// Extract metadata - all integers now
_availableVersion = doc["version"].as<uint16_t>();
_availableChecksum = doc["checksum"].as<String>();
_updateChannel = doc["channel"].as<String>();
_isMandatory = doc["mandatory"].as<bool>();
_isEmergency = doc["emergency"].as<bool>();
_minVersion = doc["minVersion"].as<uint16_t>();
_expectedFileSize = doc["fileSize"].as<size_t>();
// ✅ NEW: Validate channel matches requested
if (_updateChannel != channel) {
LOG_ERROR("OTA: Channel mismatch! Requested: %s, Got: %s",
channel.c_str(), _updateChannel.c_str());
_lastError = ErrorCode::CHANNEL_MISMATCH;
continue; // Try next server
}
// Validate hardware variant matches
String hwVariant = doc["hardwareVariant"].as<String>();
String ourHardwareVariant = _configManager.getHardwareVariant();
if (!hwVariant.isEmpty() && hwVariant != ourHardwareVariant) {
LOG_ERROR("OTA: Hardware variant mismatch! Expected: %s, Got: %s",
ourHardwareVariant.c_str(), hwVariant.c_str());
continue; // Try next server
}
// ✅ NEW: Check minVersion compatibility
uint16_t currentVersion = getCurrentVersion();
if (_minVersion > 0 && currentVersion < _minVersion) {
LOG_ERROR("OTA: Current version %u is below minimum required %u",
currentVersion, _minVersion);
LOG_ERROR("OTA: Intermediate update required first - cannot proceed");
_lastError = ErrorCode::VERSION_TOO_LOW;
continue; // Try next server
}
if (_availableVersion == 0) {
LOG_ERROR("OTA: Invalid version in metadata from %s", baseUrl.c_str());
continue; // Try next server
}
if (_availableChecksum.length() != 64) { // SHA256 is 64 hex characters
LOG_ERROR("OTA: Invalid checksum in metadata from %s", baseUrl.c_str());
continue; // Try next server
}
LOG_INFO("OTA: Successfully got metadata from %s", baseUrl.c_str());
LOG_INFO("OTA: Expected file size: %u bytes, Min version: %u",
_expectedFileSize, _minVersion);
return true; // Success!
} else {
LOG_ERROR("OTA: Server %s failed after %d retries. HTTP error: %d",
baseUrl.c_str(), updateConfig.retries, httpCode);
http.end();
}
}
// All servers failed
LOG_ERROR("OTA: All %d servers failed to provide metadata", servers.size());
_lastError = ErrorCode::HTTP_ERROR;
return false;
}
// ✅ ENHANCED: Download and install with size validation
bool OTAManager::downloadAndInstall(const String& channel) {
std::vector<String> servers = _configManager.getUpdateServers();
for (size_t serverIndex = 0; serverIndex < servers.size(); serverIndex++) {
String baseUrl = servers[serverIndex];
String firmwareUrl = baseUrl + "/ota/" + _configManager.getHardwareVariant() + "/" + channel + "/firmware.bin";
LOG_INFO("OTA: Trying firmware download from server %d/%d: %s",
serverIndex + 1, servers.size(), baseUrl.c_str());
// 🔥 Download directly to flash (bypassing problematic SD card writes)
if (downloadDirectToFlash(firmwareUrl, _expectedFileSize)) {
LOG_INFO("✅ OTA update successful!");
return true;
} else {
LOG_WARNING("OTA: Firmware download failed from %s, trying next server", baseUrl.c_str());
}
}
// All servers failed
LOG_ERROR("OTA: All %d servers failed to provide firmware", servers.size());
return false;
}
// 🔥 NEW: Download directly to flash memory, bypassing SD card
bool OTAManager::downloadDirectToFlash(const String& url, size_t expectedSize) {
LOG_INFO("OTA: Starting direct-to-flash download (bypassing SD card)");
HTTPClient http;
http.begin(url.c_str());
http.setTimeout(30000); // 30 seconds
int httpCode = http.GET();
if (httpCode != HTTP_CODE_OK) {
LOG_ERROR("Download HTTP error code: %d", httpCode);
setStatus(Status::FAILED, ErrorCode::HTTP_ERROR);
http.end();
return false;
}
int contentLength = http.getSize();
LOG_INFO("OTA: HTTP Response Code: %d", httpCode);
LOG_INFO("OTA: Content-Length: %d bytes", contentLength);
if (contentLength <= 0) {
LOG_ERROR("Invalid content length");
setStatus(Status::FAILED, ErrorCode::DOWNLOAD_FAILED);
http.end();
return false;
}
// Validate file size
if (expectedSize > 0 && (size_t)contentLength != expectedSize) {
LOG_ERROR("OTA: File size mismatch! Expected: %u, Got: %d", expectedSize, contentLength);
setStatus(Status::FAILED, ErrorCode::SIZE_MISMATCH);
http.end();
return false;
}
// ═══════════════════════════════════════════════════════════════════════════
// ENTER OTA FREEZE MODE - Pause all non-critical systems
// ═══════════════════════════════════════════════════════════════════════════
LOG_INFO("OTA: Entering freeze mode - pausing TimeKeeper and Telemetry");
if (_timeKeeper) {
_timeKeeper->pauseClockUpdates();
}
if (_telemetry) {
_telemetry->pause();
}
// Begin OTA update to flash with MD5 validation enabled
if (!Update.begin(contentLength)) {
LOG_ERROR("Not enough space to begin OTA update");
setStatus(Status::FAILED, ErrorCode::INSUFFICIENT_SPACE);
http.end();
// Resume systems
if (_timeKeeper) _timeKeeper->resumeClockUpdates();
if (_telemetry) _telemetry->resume();
return false;
}
LOG_INFO("OTA: Update partition ready, starting stream write...");
LOG_INFO("OTA: Checksum validation will be performed by ESP32 bootloader");
setStatus(Status::INSTALLING);
// Stream directly to flash
WiFiClient* stream = http.getStreamPtr();
size_t written = Update.writeStream(*stream);
http.end();
// ═══════════════════════════════════════════════════════════════════════════
// EXIT OTA FREEZE MODE - Resume all paused systems
// ═══════════════════════════════════════════════════════════════════════════
LOG_INFO("OTA: Exiting freeze mode - resuming TimeKeeper and Telemetry");
if (_timeKeeper) {
_timeKeeper->resumeClockUpdates();
}
if (_telemetry) {
_telemetry->resume();
}
if (written == (size_t)contentLength) {
LOG_INFO("OTA: Successfully written %u bytes to flash", written);
} else {
LOG_ERROR("OTA: Written only %u/%d bytes", written, contentLength);
setStatus(Status::FAILED, ErrorCode::WRITE_FAILED);
return false;
}
if (Update.end(true)) { // true = set new boot partition
LOG_INFO("OTA: Update complete!");
if (Update.isFinished()) {
setStatus(Status::SUCCESS);
LOG_INFO("OTA: Firmware update successful. Rebooting...");
// Update version in config
_configManager.setFwVersion(String(_availableVersion));
_configManager.saveDeviceConfig();
delay(1000);
ESP.restart();
return true;
} else {
LOG_ERROR("OTA: Update not finished");
setStatus(Status::FAILED, ErrorCode::VERIFICATION_FAILED);
return false;
}
} else {
LOG_ERROR("OTA: Update error: %s", Update.errorString());
setStatus(Status::FAILED, ErrorCode::VERIFICATION_FAILED);
return false;
}
}
bool OTAManager::downloadToSD(const String& url, const String& expectedChecksum, size_t expectedSize) {
if (!_fileManager) {
LOG_ERROR("FileManager not set!");
setStatus(Status::FAILED, ErrorCode::DOWNLOAD_FAILED);
return false;
}
// Ensure firmware directory exists
_fileManager->createDirectory("/firmware");
// Download to temporary file
String tempPath = "/firmware/staged_update.bin";
HTTPClient http;
http.begin(url.c_str());
// Set timeout to prevent hanging
http.setTimeout(30000); // 30 seconds
int httpCode = http.GET();
if (httpCode != HTTP_CODE_OK) {
LOG_ERROR("Download HTTP error code: %d", httpCode);
setStatus(Status::FAILED, ErrorCode::HTTP_ERROR);
http.end();
return false;
}
int contentLength = http.getSize();
// Log HTTP response headers for debugging
LOG_INFO("OTA: HTTP Response Code: %d", httpCode);
LOG_INFO("OTA: Content-Length header: %d bytes", contentLength);
if (contentLength <= 0) {
LOG_ERROR("Invalid content length");
setStatus(Status::FAILED, ErrorCode::DOWNLOAD_FAILED);
http.end();
return false;
}
// ✅ NEW: Validate file size against metadata
if (expectedSize > 0 && (size_t)contentLength != expectedSize) {
LOG_ERROR("OTA: File size mismatch! Expected: %u, Got: %d", expectedSize, contentLength);
setStatus(Status::FAILED, ErrorCode::SIZE_MISMATCH);
http.end();
return false;
}
// ✅ NEW: Check available SD card space
if (!checkAvailableSpace(contentLength)) {
LOG_ERROR("OTA: Insufficient SD card space for update");
setStatus(Status::FAILED, ErrorCode::INSUFFICIENT_SPACE);
http.end();
return false;
}
LOG_INFO("OTA: Starting download of %d bytes...", contentLength);
// ═══════════════════════════════════════════════════════════════════════════
// ENTER OTA FREEZE MODE - Pause all non-critical systems to prevent SD contention
// ═══════════════════════════════════════════════════════════════════════════
LOG_INFO("OTA: Entering freeze mode - pausing TimeKeeper and Telemetry");
if (_timeKeeper) {
_timeKeeper->pauseClockUpdates();
}
if (_telemetry) {
_telemetry->pause();
}
// 🔒 ACQUIRE SD CARD MUTEX - Prevents concurrent SD access
LOG_INFO("OTA: Acquiring SD card mutex for safe file operations");
if (!SDCardMutex::getInstance().lock(10000)) { // 10 second timeout
LOG_ERROR("OTA: Failed to acquire SD card mutex!");
if (_timeKeeper) _timeKeeper->resumeClockUpdates();
if (_telemetry) _telemetry->resume();
setStatus(Status::FAILED, ErrorCode::DOWNLOAD_FAILED);
http.end();
return false;
}
// Delete file if it exists, before opening
if (SD.exists(tempPath.c_str())) {
LOG_INFO("OTA: Removing existing staged update file");
if (!SD.remove(tempPath.c_str())) {
LOG_ERROR("OTA: Failed to remove existing file!");
}
delay(200); // Give SD card time to complete deletion
}
// Open file for writing
File file = SD.open(tempPath.c_str(), FILE_WRITE);
if (!file) {
LOG_ERROR("Failed to create temporary update file");
// Release mutex and resume systems before returning
SDCardMutex::getInstance().unlock();
if (_timeKeeper) _timeKeeper->resumeClockUpdates();
if (_telemetry) _telemetry->resume();
setStatus(Status::FAILED, ErrorCode::DOWNLOAD_FAILED);
http.end();
return false;
}
LOG_INFO("OTA: File opened successfully for writing (mutex locked)");
WiFiClient* stream = http.getStreamPtr();
uint8_t buffer[4096]; // ✅ Increased to 4KB for better performance
size_t written = 0;
size_t lastLoggedPercent = 0;
unsigned long lastYield = millis();
int loopsWithoutData = 0;
while (http.connected() && written < (size_t)contentLength) {
size_t available = stream->available();
if (available) {
loopsWithoutData = 0; // Reset counter when we have data
size_t toRead = min(available, sizeof(buffer));
size_t bytesRead = stream->readBytes(buffer, toRead);
if (bytesRead > 0) {
// Write to SD card
size_t bytesWritten = file.write(buffer, bytesRead);
// Check if write succeeded
if (bytesWritten != bytesRead) {
LOG_ERROR("SD write failed at offset %u (%u/%u bytes written)", written, bytesWritten, bytesRead);
file.close();
SDCardMutex::getInstance().unlock();
http.end();
if (_timeKeeper) _timeKeeper->resumeClockUpdates();
if (_telemetry) _telemetry->resume();
setStatus(Status::FAILED, ErrorCode::WRITE_FAILED);
return false;
}
written += bytesWritten;
// Progress reporting
notifyProgress(written, contentLength);
// Log progress every 20%
size_t currentPercent = (written * 100) / contentLength;
if (currentPercent >= lastLoggedPercent + 20) {
LOG_INFO("OTA: Download progress: %u%% (%u/%u bytes)",
currentPercent, written, contentLength);
lastLoggedPercent = currentPercent;
}
}
} else {
// No data available - yield to prevent tight loop
loopsWithoutData++;
if (loopsWithoutData > 10) {
// If we've waited a while with no data, give longer yield
vTaskDelay(pdMS_TO_TICKS(1)); // 1ms delay
loopsWithoutData = 0;
}
}
// 🐕 Yield every 100ms to allow other tasks (including IDLE) to run
if (millis() - lastYield > 100) {
vTaskDelay(pdMS_TO_TICKS(1)); // Just 1ms is enough
lastYield = millis();
}
}
// 🔥 CRITICAL: Flush file buffer before closing to ensure all data is written
file.flush();
delay(100); // Brief delay to ensure SD card completes write
file.close();
// 🔓 RELEASE SD CARD MUTEX - Other tasks can now access SD
SDCardMutex::getInstance().unlock();
LOG_INFO("OTA: SD card mutex released");
http.end();
// ═══════════════════════════════════════════════════════════════════════════
// EXIT OTA FREEZE MODE - Resume all paused systems
// ═══════════════════════════════════════════════════════════════════════════
LOG_INFO("OTA: Exiting freeze mode - resuming TimeKeeper and Telemetry");
if (_timeKeeper) {
_timeKeeper->resumeClockUpdates();
}
if (_telemetry) {
_telemetry->resume();
}
if (written != (size_t)contentLength) {
LOG_ERROR("Download incomplete: %u/%d bytes", written, contentLength);
setStatus(Status::FAILED, ErrorCode::DOWNLOAD_FAILED);
return false;
}
LOG_INFO("Download complete (%u bytes)", written);
// 🔒 Acquire mutex for file verification operations
if (!SDCardMutex::getInstance().lock(5000)) {
LOG_ERROR("OTA: Failed to acquire SD mutex for verification");
setStatus(Status::FAILED, ErrorCode::DOWNLOAD_FAILED);
return false;
}
// 🔍 DEBUG: Check actual file size on SD card
size_t actualFileSize = _fileManager->getFileSize(tempPath);
LOG_INFO("OTA: File size on SD card: %u bytes (expected: %u)", actualFileSize, written);
if (actualFileSize != written) {
LOG_ERROR("OTA: FILE SIZE MISMATCH ON SD CARD! Expected %u, got %u", written, actualFileSize);
SDCardMutex::getInstance().unlock();
setStatus(Status::FAILED, ErrorCode::WRITE_FAILED);
return false;
}
// 🔍 DEBUG: Read first 32 bytes for inspection
File debugFile = SD.open(tempPath.c_str());
if (debugFile) {
uint8_t debugBuffer[32];
size_t debugRead = debugFile.readBytes((char*)debugBuffer, 32);
debugFile.close();
String hexDump = "OTA: First 32 bytes (hex): ";
for (size_t i = 0; i < debugRead && i < 32; i++) {
char hex[4];
sprintf(hex, "%02X ", debugBuffer[i]);
hexDump += hex;
}
LOG_INFO("%s", hexDump.c_str());
}
SDCardMutex::getInstance().unlock(); // Release before checksum (checksum will acquire its own)
// Verify checksum (verifyChecksum acquires its own mutex)
if (!verifyChecksum(tempPath, expectedChecksum)) {
LOG_ERROR("Checksum verification failed after download");
_fileManager->deleteFile(tempPath);
setStatus(Status::FAILED, ErrorCode::CHECKSUM_MISMATCH);
return false;
}
LOG_INFO("Download and checksum verification successful");
return true;
}
bool OTAManager::verifyChecksum(const String& filePath, const String& expectedChecksum) {
String calculatedChecksum = calculateSHA256(filePath);
if (calculatedChecksum.isEmpty()) {
LOG_ERROR("Failed to calculate checksum");
return false;
}
bool match = calculatedChecksum.equalsIgnoreCase(expectedChecksum);
if (match) {
LOG_INFO("Checksum verification passed");
} else {
LOG_ERROR("Checksum mismatch!");
LOG_ERROR("Expected: %s", expectedChecksum.c_str());
LOG_ERROR("Calculated: %s", calculatedChecksum.c_str());
}
return match;
}
String OTAManager::calculateSHA256(const String& filePath) {
// 🔒 Acquire SD mutex for file reading
if (!SDCardMutex::getInstance().lock(5000)) {
LOG_ERROR("Failed to acquire SD mutex for checksum calculation");
return "";
}
File file = SD.open(filePath.c_str());
if (!file) {
LOG_ERROR("Failed to open file for checksum calculation: %s", filePath.c_str());
SDCardMutex::getInstance().unlock();
return "";
}
mbedtls_md_context_t ctx;
mbedtls_md_type_t md_type = MBEDTLS_MD_SHA256;
mbedtls_md_init(&ctx);
mbedtls_md_setup(&ctx, mbedtls_md_info_from_type(md_type), 0);
mbedtls_md_starts(&ctx);
uint8_t buffer[1024];
size_t bytesRead;
while ((bytesRead = file.readBytes((char*)buffer, sizeof(buffer))) > 0) {
mbedtls_md_update(&ctx, buffer, bytesRead);
}
uint8_t hash[32];
mbedtls_md_finish(&ctx, hash);
mbedtls_md_free(&ctx);
file.close();
// 🔓 Release SD mutex
SDCardMutex::getInstance().unlock();
// Convert to hex string
String hashString = "";
for (int i = 0; i < 32; i++) {
String hex = String(hash[i], HEX);
if (hex.length() == 1) {
hex = "0" + hex;
}
hashString += hex;
}
return hashString;
}
bool OTAManager::installFromSD(const String& filePath) {
// 🔒 Acquire SD mutex for file size check
if (!SDCardMutex::getInstance().lock(5000)) {
LOG_ERROR("Failed to acquire SD mutex for installation");
setStatus(Status::FAILED, ErrorCode::DOWNLOAD_FAILED);
return false;
}
size_t updateSize = _fileManager->getFileSize(filePath);
SDCardMutex::getInstance().unlock(); // Release after size check
if (updateSize == 0) {
LOG_ERROR("Empty update file");
setStatus(Status::FAILED, ErrorCode::DOWNLOAD_FAILED);
return false;
}
LOG_INFO("Installing firmware from SD (%u bytes)...", updateSize);
setStatus(Status::INSTALLING);
if (!Update.begin(updateSize)) {
LOG_ERROR("Not enough space to begin update");
setStatus(Status::FAILED, ErrorCode::INSUFFICIENT_SPACE);
return false;
}
// 🔒 Acquire SD mutex for file reading during flash
if (!SDCardMutex::getInstance().lock(30000)) { // 30 second timeout for flash operation
LOG_ERROR("Failed to acquire SD mutex for firmware flash");
setStatus(Status::FAILED, ErrorCode::DOWNLOAD_FAILED);
return false;
}
File updateBin = SD.open(filePath.c_str());
if (!updateBin) {
LOG_ERROR("Failed to open update file: %s", filePath.c_str());
SDCardMutex::getInstance().unlock();
setStatus(Status::FAILED, ErrorCode::DOWNLOAD_FAILED);
return false;
}
size_t written = Update.writeStream(updateBin);
updateBin.close();
// 🔓 Release SD mutex after reading file
SDCardMutex::getInstance().unlock();
if (written == updateSize) {
LOG_INFO("Update written successfully (%u bytes)", written);
} else {
LOG_ERROR("Written only %u/%u bytes", written, updateSize);
setStatus(Status::FAILED, ErrorCode::WRITE_FAILED);
return false;
}
if (Update.end(true)) { // true = set new boot partition
LOG_INFO("Update finished!");
if (Update.isFinished()) {
setStatus(Status::SUCCESS);
LOG_INFO("Update complete. Cleaning up and rebooting...");
// Clean up the update files
_fileManager->deleteFile(filePath);
_fileManager->deleteFile("/firmware/staged_update.sha256");
_fileManager->deleteFile("/firmware/update.sha256");
// Clear firmware validation state to force validation of new firmware
nvs_handle_t nvsHandle;
esp_err_t err = nvs_open("fw_validator", NVS_READWRITE, &nvsHandle);
if (err == ESP_OK) {
nvs_erase_key(nvsHandle, "val_state");
nvs_erase_key(nvsHandle, "retry_count");
nvs_erase_key(nvsHandle, "fail_count");
nvs_commit(nvsHandle);
nvs_close(nvsHandle);
LOG_INFO("✅ OTA: Firmware validation state cleared - new firmware will be validated");
} else {
LOG_WARNING("⚠️ OTA: Failed to clear validation state: %s", esp_err_to_name(err));
}
delay(1000);
// Version is already an integer - just convert to string: 130 -> "130"
_configManager.setFwVersion(String(_availableVersion));
_configManager.saveDeviceConfig();
delay(500);
ESP.restart();
return true;
} else {
LOG_ERROR("Update not complete");
setStatus(Status::FAILED, ErrorCode::VERIFICATION_FAILED);
return false;
}
} else {
LOG_ERROR("Update error: %s", Update.errorString());
setStatus(Status::FAILED, ErrorCode::VERIFICATION_FAILED);
return false;
}
}
void OTAManager::checkFirmwareUpdateFromSD() {
if (!_fileManager) {
LOG_ERROR("FileManager not set!");
return;
}
if (!_fileManager->fileExists("/firmware/update.bin")) {
LOG_DEBUG("No update.bin found on SD card");
return;
}
// Check for checksum file
String checksumFile = "/firmware/update.sha256";
if (!_fileManager->fileExists(checksumFile)) {
LOG_WARNING("No checksum file found, proceeding without verification");
installFromSD("/firmware/update.bin");
return;
}
// Read expected checksum
File checksumFileHandle = SD.open(checksumFile.c_str());
if (!checksumFileHandle) {
LOG_ERROR("Failed to open checksum file");
return;
}
String expectedChecksum = checksumFileHandle.readString();
checksumFileHandle.close();
expectedChecksum.trim();
// Verify checksum
if (!verifyChecksum("/firmware/update.bin", expectedChecksum)) {
LOG_ERROR("Checksum verification failed, aborting update");
setStatus(Status::FAILED, ErrorCode::CHECKSUM_MISMATCH);
return;
}
LOG_INFO("Checksum verified, proceeding with update");
installFromSD("/firmware/update.bin");
}
bool OTAManager::performManualUpdate() {
return performManualUpdate("stable");
}
bool OTAManager::performManualUpdate(const String& channel) {
if (_status != Status::IDLE) {
LOG_WARNING("OTA update already in progress");
return false;
}
// Check for updates in the specified channel first
checkForUpdates(channel);
if (!_updateAvailable) {
LOG_WARNING("No update available in %s channel", channel.c_str());
return false;
}
LOG_INFO("Starting manual OTA update from %s channel (direct-to-flash)...", channel.c_str());
setStatus(Status::DOWNLOADING);
String firmwareUrl = buildFirmwareUrl(channel);
// Download directly to flash
return downloadDirectToFlash(firmwareUrl, _expectedFileSize);
}
// ════════════════════════════════════════════════════════════════════════════
// CUSTOM FIRMWARE UPDATE
// ════════════════════════════════════════════════════════════════════════════
bool OTAManager::performCustomUpdate(const String& firmwareUrl, const String& checksum, size_t fileSize) {
if (_status != Status::IDLE) {
LOG_WARNING("OTA update already in progress");
return false;
}
// Check if player is active
if (isPlayerActive()) {
LOG_ERROR("Cannot perform custom update: Player is active");
setStatus(Status::FAILED, ErrorCode::PLAYER_ACTIVE);
return false;
}
LOG_INFO("🔥 Starting CUSTOM firmware update (direct-to-flash)...");
LOG_INFO(" URL: %s", firmwareUrl.c_str());
LOG_INFO(" File Size: %u bytes", fileSize);
if (!checksum.isEmpty()) {
LOG_INFO(" Checksum: %s (NOTE: ESP32 will validate after flash)", checksum.c_str());
}
setStatus(Status::DOWNLOADING);
// Download directly to flash
bool result = downloadDirectToFlash(firmwareUrl, fileSize);
if (result) {
LOG_INFO("🚀 Custom firmware installed - device will reboot");
} else {
LOG_ERROR("❌ Custom firmware installation failed");
}
return result;
}
// Hardware variant management
String OTAManager::getHardwareVariant() const {
return _configManager.getHardwareVariant();
}
void OTAManager::setHardwareVariant(const String& variant) {
LOG_WARNING("OTAManager::setHardwareVariant is deprecated. Use ConfigManager::setHardwareVariant instead");
}
// URL builders for multi-channel architecture
String OTAManager::buildChannelUrl(const String& channel) const {
auto& updateConfig = _configManager.getUpdateConfig();
String baseUrl = updateConfig.fallbackServerUrl;
return baseUrl + "/" + _configManager.getHardwareVariant() + "/" + channel + "/";
}
String OTAManager::buildMetadataUrl(const String& channel) const {
return buildChannelUrl(channel) + "metadata.json";
}
String OTAManager::buildFirmwareUrl(const String& channel) const {
return buildChannelUrl(channel) + "firmware.bin";
}
// ✅ NEW: Check if player is currently active
bool OTAManager::isPlayerActive() const {
if (!_player) {
// If player reference not set, assume it's safe to update
return false;
}
// Player is active if it's playing or paused (not stopped)
return _player->isCurrentlyPlaying() || _player->isCurrentlyPaused();
}
// ✅ NEW: Check if SD card has enough free space
bool OTAManager::checkAvailableSpace(size_t requiredBytes) const {
if (!_fileManager) {
LOG_WARNING("OTA: FileManager not set, cannot check available space");
return true; // Assume it's okay if we can't check
}
// Add 10% safety margin
size_t requiredWithMargin = requiredBytes + (requiredBytes / 10);
// Get SD card info
uint64_t totalBytes = SD.totalBytes();
uint64_t usedBytes = SD.usedBytes();
uint64_t freeBytes = totalBytes - usedBytes;
LOG_INFO("OTA: SD card space - Total: %llu MB, Used: %llu MB, Free: %llu MB",
totalBytes / (1024 * 1024),
usedBytes / (1024 * 1024),
freeBytes / (1024 * 1024));
if (freeBytes < requiredWithMargin) {
LOG_ERROR("OTA: Insufficient space! Required: %u bytes (+10%% margin), Available: %llu bytes",
requiredWithMargin, freeBytes);
return false;
}
LOG_INFO("OTA: Sufficient space available for update");
return true;
}
// ════════════════════════════════════════════════════════════════════════════
// HEALTH CHECK IMPLEMENTATION
// ════════════════════════════════════════════════════════════════════════════
bool OTAManager::isHealthy() const {
// Check if FileManager dependency is set
if (!_fileManager) {
LOG_DEBUG("OTAManager: Unhealthy - FileManager not set");
return false;
}
// Check if we're not in a failed state
if (_status == Status::FAILED) {
LOG_DEBUG("OTAManager: Unhealthy - In failed state");
return false;
}
// Check if ConfigManager has valid configuration
String hwVariant = _configManager.getHardwareVariant();
if (hwVariant.isEmpty() || hwVariant == "BellSystems") {
LOG_DEBUG("OTAManager: Unhealthy - Invalid hardware variant: %s", hwVariant.c_str());
return false;
}
String fwVersion = _configManager.getFwVersion();
if (fwVersion.isEmpty() || fwVersion == "0") {
LOG_DEBUG("OTAManager: Unhealthy - Invalid firmware version: %s", fwVersion.c_str());
return false;
}
// Check if update servers are available
std::vector<String> servers = _configManager.getUpdateServers();
if (servers.empty()) {
LOG_DEBUG("OTAManager: Unhealthy - No update servers configured");
return false;
}
// Check if FileManager is healthy (can access SD card)
if (!_fileManager->isHealthy()) {
LOG_DEBUG("OTAManager: Unhealthy - FileManager is unhealthy");
return false;
}
// Check if scheduled timer is running
if (_scheduledCheckTimer == NULL || xTimerIsTimerActive(_scheduledCheckTimer) == pdFALSE) {
LOG_DEBUG("OTAManager: Unhealthy - Scheduled check timer not running");
return false;
}
return true;
}
// ════════════════════════════════════════════════════════════════════════════
// WORKER TASK IMPLEMENTATION
// ════════════════════════════════════════════════════════════════════════════
// Static entry point for worker task
void OTAManager::otaWorkerTaskFunction(void* parameter) {
OTAManager* ota = static_cast<OTAManager*>(parameter);
LOG_INFO("🔧 OTA Worker task started on Core %d with 8KB stack", xPortGetCoreID());
// Run the worker loop
ota->otaWorkerLoop();
// Should not reach here
LOG_ERROR("❌ OTA Worker task ended unexpectedly!");
vTaskDelete(NULL);
}
// Worker task loop - waits for signals and performs OTA operations
void OTAManager::otaWorkerLoop() {
while (true) {
// Wait for work signal (blocks until semaphore is given)
if (xSemaphoreTake(_otaWorkSignal, portMAX_DELAY) == pdTRUE) {
// Check what type of work to perform
switch (_pendingWork) {
case OTAWorkType::INITIAL_CHECK:
LOG_INFO("🚀 Worker: Performing initial OTA check");
performInitialCheck();
break;
case OTAWorkType::SCHEDULED_CHECK:
LOG_INFO("🕒 Worker: Performing scheduled emergency check");
checkForEmergencyUpdates();
break;
case OTAWorkType::NONE:
default:
LOG_WARNING("⚠️ Worker: Received signal but no work pending");
break;
}
// Clear pending work
_pendingWork = OTAWorkType::NONE;
}
}
}