#include "OTAManager.hpp" #include "../ConfigManager/ConfigManager.hpp" #include "../Logging/Logging.hpp" #include "../Player/Player.hpp" #include "../SDCardMutex/SDCardMutex.hpp" #include #include #include 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(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(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 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(); _availableChecksum = doc["checksum"].as(); _updateChannel = doc["channel"].as(); _isMandatory = doc["mandatory"].as(); _isEmergency = doc["emergency"].as(); _minVersion = doc["minVersion"].as(); _expectedFileSize = doc["fileSize"].as(); // ✅ 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 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 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 with periodic watchdog feeding WiFiClient* stream = http.getStreamPtr(); uint8_t buffer[4096]; // 4KB buffer for efficient transfer size_t written = 0; size_t lastLoggedPercent = 0; unsigned long lastWatchdogReset = millis(); while (http.connected() && written < (size_t)contentLength) { size_t available = stream->available(); if (available) { size_t toRead = min(available, sizeof(buffer)); size_t bytesRead = stream->readBytes(buffer, toRead); if (bytesRead > 0) { // Write to flash size_t bytesWritten = Update.write(buffer, bytesRead); if (bytesWritten != bytesRead) { LOG_ERROR("OTA: Flash write failed at offset %u (%u/%u bytes written)", written, bytesWritten, bytesRead); http.end(); // Resume systems if (_timeKeeper) _timeKeeper->resumeClockUpdates(); if (_telemetry) _telemetry->resume(); setStatus(Status::FAILED, ErrorCode::WRITE_FAILED); return false; } written += bytesWritten; // Log progress every 20% size_t currentPercent = (written * 100) / contentLength; if (currentPercent >= lastLoggedPercent + 20) { LOG_INFO("OTA: Flash write progress: %u%% (%u/%u bytes)", currentPercent, written, contentLength); lastLoggedPercent = currentPercent; } } } // Feed watchdog every 500ms to prevent timeout if (millis() - lastWatchdogReset > 500) { esp_task_wdt_reset(); lastWatchdogReset = millis(); } // Small yield to prevent tight loop yield(); } 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, uint16_t version) { 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()); } if (version > 0) { LOG_INFO(" Target Version: %u", version); } setStatus(Status::DOWNLOADING); // Download directly to flash bool result = downloadDirectToFlash(firmwareUrl, fileSize); if (result) { // Update version in config if provided if (version > 0) { _configManager.setFwVersion(String(version)); _configManager.saveDeviceConfig(); LOG_INFO("✅ Custom firmware version %u saved to NVS", version); } else { LOG_WARNING("⚠️ No version provided - NVS version unchanged"); } 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 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(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; } } }