From c4bab7fdeb9b9cb5e41b369cbfa4c5bc8d5cc69d Mon Sep 17 00:00:00 2001 From: raphaelcoeffic <1050031+raphaelcoeffic@users.noreply.github.com> Date: Sat, 4 Jul 2026 07:20:43 +0200 Subject: [PATCH 1/3] fix(logs): open log files from the UI task (#7513) Log files were opened lazily from logsWrite(), which on firmware runs on the FreeRTOS timer daemon task. Telemetry frame polling is dispatched to that same task via xTimerPendFunctionCallFromISR(). When the LOGS directory is large (thousands of files), f_open() with FA_OPEN_ALWAYS has to scan the whole FAT directory and blocks the timer task long enough to starve telemetry polling, producing a brief "Telemetry lost" / "Telemetry recovered" at log start. Move the file open/close into the new logsHandle(), called cyclically from perMain() on the menus/UI task. On firmware the logging timer now only appends a line to an already-open file and never blocks on f_open(); because the timer/telemetry task is higher priority it preempts the directory scan running on the UI task, so telemetry keeps flowing while the log file is created. In the simulator logsHandle() opens the file and calls logsWrite() directly, as before (the open already happened on the UI thread there, so it was never affected). Co-Authored-By: Claude Opus 4.8 (1M context) --- radio/src/logs.cpp | 130 +++++++++++++++++++++++++++------------------ radio/src/main.cpp | 11 +--- radio/src/sdcard.h | 2 +- 3 files changed, 79 insertions(+), 64 deletions(-) diff --git a/radio/src/logs.cpp b/radio/src/logs.cpp index 7f0b0a24e12..3dc0c1f0f8b 100644 --- a/radio/src/logs.cpp +++ b/radio/src/logs.cpp @@ -32,6 +32,24 @@ FIL g_oLogFile __DMA; uint8_t logDelay100ms; static tmr10ms_t lastLogTime = 0; +// Last error reported to the user, used only to avoid repeating the popup. +// Written from both the UI task (logsHandle) and the higher-priority timer +// task (logsWrite); the two never run concurrently on the target (the UI task +// cannot preempt the timer task) and a pointer store is atomic, so no lock is +// needed. +static const char* error_displayed = nullptr; + +static void logsWrite(); +const char* logsOpen(); + +static void displayLogError(const char* err) +{ + if (err != error_displayed) { + error_displayed = err; + POPUP_WARNING_ON_UI_TASK(err, nullptr); + } +} + #if !defined(SIMU) #include #include @@ -76,26 +94,52 @@ void loggingTimerStop() } } -void initLoggingTimer() { // called cyclically by main.cpp:perMain() +#endif + +void logsHandle() +{ // called cyclically by main.cpp:perMain(), i.e. from the UI task static uint8_t logDelay100msOld = 0; - if(loggingTimer == nullptr) { // log Timer not running - if(isFunctionActive(FUNCTION_LOGS) && logDelay100ms > 0) { // if SF Logging is active and log rate is valid - loggingTimerStart(); // start log timer - } - } else { // log timer is already running - if(logDelay100msOld != logDelay100ms) { // if log rate was changed - logDelay100msOld = logDelay100ms; // memorize new log rate - - if(logDelay100ms > 0) { - if(xTimerChangePeriod( loggingTimer, logDelay100ms*100, 0 ) != pdPASS ) { // and restart timer with new log rate - /* The timer period could not be changed */ - } - } + bool logsActive = sdMounted() && isFunctionActive(FUNCTION_LOGS) && + logDelay100ms > 0 && !usbPlugged(); + + if (!logsActive) { +#if !defined(SIMU) + loggingTimerStop(); +#endif + logsClose(); + error_displayed = nullptr; + return; + } + + // Open the log file here, in the UI task. f_open() may have to scan a large + // LOGS directory and can block for a long time. On firmware logsWrite() runs + // on the timer daemon task, which is shared with telemetry frame polling, so + // opening there would starve telemetry and cause a brief "telemetry lost". + // See issue #7513. + if (!g_oLogFile.obj.fs) { + const char* result = sdIsFull() ? STR_SDCARD_FULL_EXT : logsOpen(); + if (result) { + displayLogError(result); + return; // keep logging stopped until we have a valid file } } -} + +#if !defined(SIMU) + if (loggingTimer == nullptr) { // log timer not running + logDelay100msOld = logDelay100ms; + loggingTimerStart(); // start log timer + } else if (logDelay100msOld != logDelay100ms) { // log rate changed + logDelay100msOld = logDelay100ms; // memorize new log rate + if (xTimerChangePeriod(loggingTimer, logDelay100ms * 100, 0) != pdPASS) { + /* The timer period could not be changed */ + } + } +#else + (void)logDelay100msOld; + logsWrite(); // SIMU: write directly from the UI task (self rate-limited) #endif +} void writeHeader(); @@ -241,15 +285,20 @@ uint32_t getLogicalSwitchesStates(uint8_t first) return result; } -void logsWrite() +static void logsWrite() { - static const char * error_displayed = nullptr; - - if (!sdMounted()) { + // Called from the logging timer callback (timer task) on firmware, and + // directly from logsHandle() (UI task) in the simulator. The log file is + // opened and closed by logsHandle(), so this function only ever appends to + // an already-open file and never blocks on f_open(). + + // stop writing once an error has been reported; logsHandle() clears + // error_displayed when logging is toggled off, which resumes logging. + if (!sdMounted() || !g_oLogFile.obj.fs || error_displayed) { return; } - if (isFunctionActive(FUNCTION_LOGS) && logDelay100ms > 0 && !usbPlugged()) { + { #if defined(SIMU) || !defined(RTCLOCK) tmr10ms_t tmr10ms = get_tmr10ms(); // tmr10ms works in 10ms increments if (lastLogTime == 0 || (tmr10ms_t)(tmr10ms - lastLogTime) >= (tmr10ms_t)(logDelay100ms*10)-1) { @@ -258,27 +307,10 @@ void logsWrite() { #endif - bool sdCardFull = sdIsFull(); - - // check if file needs to be opened - if (!g_oLogFile.obj.fs) { - const char *result = sdCardFull ? STR_SDCARD_FULL_EXT : logsOpen(); - - // SD card is full or file open failed - if (result) { - if (result != error_displayed) { - error_displayed = result; - POPUP_WARNING_ON_UI_TASK(result, nullptr); - } - return; - } - } - - // check at every write cycle - if (sdCardFull) { - logsClose(); // timer is still running and code above will try to - // open the file again but will fail with error - // which will trigger the warning popup + // SD card became full: report and stop writing. The file is left open + // and closed later by logsHandle() from the UI task. + if (sdIsFull()) { + displayLogError(STR_SDCARD_FULL_EXT); return; } @@ -371,19 +403,11 @@ void logsWrite() div_t qr = div(g_vbat100mV, 10); int result = f_printf(&g_oLogFile, "%d.%d\n", abs(qr.quot), abs(qr.rem)); - if (result<0 && !error_displayed) { - error_displayed = STR_SDCARD_ERROR; - POPUP_WARNING_ON_UI_TASK(STR_SDCARD_ERROR, nullptr); - logsClose(); + // Write error: report it and stop writing. The file is left open and + // closed later by logsHandle() from the UI task. + if (result < 0) { + displayLogError(STR_SDCARD_ERROR); } } } - else { - error_displayed = nullptr; - logsClose(); - - #if !defined(SIMU) - loggingTimerStop(); - #endif - } } diff --git a/radio/src/main.cpp b/radio/src/main.cpp index ed49381b980..f1fafacceab 100644 --- a/radio/src/main.cpp +++ b/radio/src/main.cpp @@ -464,10 +464,6 @@ void guiMain(event_t evt) } #endif -#if !defined(SIMU) -void initLoggingTimer(); -#endif - void perMain() { DEBUG_TIMER_START(debugTimerPerMain1); @@ -476,12 +472,7 @@ void perMain() if (!usbPlugged() || (getSelectedUsbMode() == USB_UNSELECTED_MODE)) { checkStorageUpdate(); - -#if !defined(SIMU) // use FreeRTOS software timer if radio firmware - initLoggingTimer(); // initialize software timer for logging -#else - logsWrite(); // call logsWrite the old way for simu -#endif + logsHandle(); // open/close log file and drive logging (UI task) } handleUsbConnection(); diff --git a/radio/src/sdcard.h b/radio/src/sdcard.h index a6c380abcb9..22e8ce2e578 100644 --- a/radio/src/sdcard.h +++ b/radio/src/sdcard.h @@ -120,7 +120,7 @@ const char YAMLFILE_CHECKSUM_TAG_NAME[] = "checksum"; extern uint8_t logDelay100ms; void logsInit(); void logsClose(); -void logsWrite(); +void logsHandle(); void sdInit(); void sdMount(); From 80e043c652dcbe634357dd56afb61195f609b443 Mon Sep 17 00:00:00 2001 From: raphaelcoeffic <1050031+raphaelcoeffic@users.noreply.github.com> Date: Sat, 4 Jul 2026 07:39:17 +0200 Subject: [PATCH 2/3] fix(logs): recover from log write errors without toggling logging After logsWrite() reported a read/write error it set error_displayed and then no-op'd on every tick, leaving the file open (and, on firmware, the timer firing empty callbacks) until the user toggled logging off and on. The open-error path in logsHandle() already retried automatically, so the two error paths were inconsistent. Handle a pending error in logsHandle() (UI task): stop the timer (on firmware), close the file, and retry a fresh open through the existing open path. A successful (re)open clears error_displayed and resumes logging; while the error persists the timer stays stopped and the file closed, and the popup remains deduplicated. Co-Authored-By: Claude Opus 4.8 (1M context) --- radio/src/logs.cpp | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-) diff --git a/radio/src/logs.cpp b/radio/src/logs.cpp index 3dc0c1f0f8b..2fdd876c404 100644 --- a/radio/src/logs.cpp +++ b/radio/src/logs.cpp @@ -112,6 +112,17 @@ void logsHandle() return; } + // After an error was reported (by logsWrite or a previous open), tear the + // logging down and retry a fresh open below. This releases the file and + // stops the no-op timer callbacks; a successful (re)open clears the error + // and resumes logging without the user having to toggle it off and on. + if (error_displayed) { +#if !defined(SIMU) + loggingTimerStop(); +#endif + logsClose(); + } + // Open the log file here, in the UI task. f_open() may have to scan a large // LOGS directory and can block for a long time. On firmware logsWrite() runs // on the timer daemon task, which is shared with telemetry frame polling, so @@ -120,9 +131,10 @@ void logsHandle() if (!g_oLogFile.obj.fs) { const char* result = sdIsFull() ? STR_SDCARD_FULL_EXT : logsOpen(); if (result) { - displayLogError(result); + displayLogError(result); // deduplicated: no repeated popup return; // keep logging stopped until we have a valid file } + error_displayed = nullptr; // (re)opened successfully } #if !defined(SIMU) From 1fd77d9c40bafa092e69415f1cec906119b5d21c Mon Sep 17 00:00:00 2001 From: raphaelcoeffic <1050031+raphaelcoeffic@users.noreply.github.com> Date: Sat, 4 Jul 2026 07:46:31 +0200 Subject: [PATCH 3/3] fix(logs): give up on fatal log errors instead of retrying forever The previous change retried the open on every perMain() cycle after any error. For a persistent hard error (bad card / corrupted FS) that means rescanning a potentially huge LOGS directory indefinitely, which is wasteful and cannot succeed. Only a full SD card is treated as recoverable: sdIsFull() is a cheap check (no directory scan) and the condition clears when the user frees space, so logging resumes automatically. Any other error now stops logging until the user re-enables it (which clears error_displayed). Co-Authored-By: Claude Opus 4.8 (1M context) --- radio/src/logs.cpp | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-) diff --git a/radio/src/logs.cpp b/radio/src/logs.cpp index 2fdd876c404..8d90f8bbcc6 100644 --- a/radio/src/logs.cpp +++ b/radio/src/logs.cpp @@ -112,15 +112,18 @@ void logsHandle() return; } - // After an error was reported (by logsWrite or a previous open), tear the - // logging down and retry a fresh open below. This releases the file and - // stops the no-op timer callbacks; a successful (re)open clears the error - // and resumes logging without the user having to toggle it off and on. + // An error was reported (by logsWrite or a previous open): release the file + // and stop the no-op timer. A full SD card is the one recoverable case - + // keep checking cheaply (sdIsFull() needs no directory scan) and resume once + // space is freed. Any other error is treated as fatal: give up until the + // user re-enables logging, rather than rescanning the LOGS directory on + // every cycle for an error that will not fix itself. if (error_displayed) { #if !defined(SIMU) loggingTimerStop(); #endif logsClose(); + if (error_displayed != STR_SDCARD_FULL_EXT) return; } // Open the log file here, in the UI task. f_open() may have to scan a large