From a4059039e589df7a99985b0d5b8ebf3c8443ac01 Mon Sep 17 00:00:00 2001 From: raphaelcoeffic <1050031+raphaelcoeffic@users.noreply.github.com> Date: Sat, 4 Jul 2026 07:13:18 +0200 Subject: [PATCH 1/3] fix(logs): open log files from the UI task (#7513) Log files were opened lazily from logsWrite(), which runs on the FreeRTOS timer daemon task (priority 2). Telemetry frame polling is dispatched to that same task via async_call_isr(). 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 (priority 1). logsWrite() 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 being created. Co-Authored-By: Claude Opus 4.8 (1M context) --- radio/src/logs.cpp | 114 ++++++++++++++++++++++++++------------------- radio/src/main.cpp | 5 +- radio/src/sdcard.h | 2 +- 3 files changed, 67 insertions(+), 54 deletions(-) diff --git a/radio/src/logs.cpp b/radio/src/logs.cpp index ef5c9ce2270..0092d32e61a 100644 --- a/radio/src/logs.cpp +++ b/radio/src/logs.cpp @@ -37,6 +37,24 @@ static tmr10ms_t lastLogTime = 0; static timer_handle_t loggingTimer = TIMER_INITIALIZER; +// 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); + } +} + static void loggingTimerCb(timer_handle_t* timer) { (void)timer; @@ -63,22 +81,41 @@ bool loggingTimerIsRunning() return timer_is_active(&loggingTimer); } -void initLoggingTimer() -{ // called cyclically by main.cpp:perMain() +void logsHandle() +{ // called cyclically by main.cpp:perMain(), i.e. from the UI task static uint8_t logDelay100msOld = 0; - if(!timer_is_active(&loggingTimer)) { // log Timer not running - if(isFunctionActive(FUNCTION_LOGS) && logDelay100ms > 0) { // if SF Logging is active and log rate is valid - loggingTimerStart(logDelay100ms * 100); // 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) { - timer_set_period(&loggingTimer, logDelay100ms * 100); - } + bool logsActive = sdMounted() && isFunctionActive(FUNCTION_LOGS) && + logDelay100ms > 0 && !usbPlugged(); + + if (!logsActive) { + if (timer_is_active(&loggingTimer)) { + loggingTimerStop(); + 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; doing it from the timer task + // (logsWrite) would starve telemetry polling, which runs on the same task, + // 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 the timer stopped until we have a valid file } } + + if (!timer_is_active(&loggingTimer)) { // log timer not running + logDelay100msOld = logDelay100ms; + loggingTimerStart(logDelay100ms * 100); // start log timer + } else if (logDelay100msOld != logDelay100ms) { // log rate changed + logDelay100msOld = logDelay100ms; // memorize new log rate + timer_set_period(&loggingTimer, logDelay100ms * 100); + } } void writeHeader(); @@ -225,15 +262,19 @@ uint32_t getLogicalSwitchesStates(uint8_t first) return result; } -void logsWrite() +static void logsWrite() { - static const char * error_displayed = nullptr; + // Called from the logging timer callback (timer task). The log file is + // opened and closed by logsHandle() in the UI task, so this function only + // ever appends to an already-open file and never blocks on f_open(). - if (!sdMounted()) { + // 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) { @@ -242,27 +283,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; } @@ -355,19 +379,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 cd29db6fffd..a0e8c68a974 100644 --- a/radio/src/main.cpp +++ b/radio/src/main.cpp @@ -474,9 +474,6 @@ void guiMain(event_t evt) } #endif -// from logs.cpp -void initLoggingTimer(); - void perMain() { DEBUG_TIMER_START(debugTimerPerMain1); @@ -485,7 +482,7 @@ void perMain() if (!usbPlugged() || (getSelectedUsbMode() == USB_UNSELECTED_MODE)) { checkStorageUpdate(); - initLoggingTimer(); // initialize software timer for logging + logsHandle(); // open/close log file and drive the logging timer } handleUsbConnection(); diff --git a/radio/src/sdcard.h b/radio/src/sdcard.h index 5c85005bf96..5141bb79969 100644 --- a/radio/src/sdcard.h +++ b/radio/src/sdcard.h @@ -119,7 +119,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 8fa75025e509cdca4e19961fe5777e3764574b42 Mon Sep 17 00:00:00 2001 From: raphaelcoeffic <1050031+raphaelcoeffic@users.noreply.github.com> Date: Sat, 4 Jul 2026 07:37:38 +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 timer tick, leaving the file open and 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, 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 | 12 +++++++++++- 1 file changed, 11 insertions(+), 1 deletion(-) diff --git a/radio/src/logs.cpp b/radio/src/logs.cpp index 0092d32e61a..f83017a784b 100644 --- a/radio/src/logs.cpp +++ b/radio/src/logs.cpp @@ -97,6 +97,15 @@ 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 (timer_is_active(&loggingTimer)) loggingTimerStop(); + 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; doing it from the timer task // (logsWrite) would starve telemetry polling, which runs on the same task, @@ -104,9 +113,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 the timer stopped until we have a valid file } + error_displayed = nullptr; // (re)opened successfully } if (!timer_is_active(&loggingTimer)) { // log timer not running From 9a61966091244f1e111db5f714b0e5c53c281e58 Mon Sep 17 00:00:00 2001 From: raphaelcoeffic <1050031+raphaelcoeffic@users.noreply.github.com> Date: Sat, 4 Jul 2026 07:45:15 +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 f83017a784b..b2690ff8d2b 100644 --- a/radio/src/logs.cpp +++ b/radio/src/logs.cpp @@ -97,13 +97,16 @@ 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 (timer_is_active(&loggingTimer)) loggingTimerStop(); 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