From ce8cc0b540dc287c41d52e1c601b37e762e8c35c Mon Sep 17 00:00:00 2001
From: Michael <mha1@users.noreply.github.com>
Date: Mon, 27 Jun 2022 20:12:47 +0200
Subject: [PATCH] Fix missing log steps at 0.1s period (#1967)

fixed issued where log steps would be missed due to 10ms timer resolution
- simulator: allow for one get_tmr10ms() tick (10ms) deviation
- radio: switched to FreeRTOS software timer at user requested period

code cleanup
log.cpp: made variable lastLogTime static
log.cpp: deleted unused variable g_logError
functions.cpp, logs.cpp, sdcard.h: renamed variable logDelay to logDelay100ms to show it is scaled to 100ms increments
---
 radio/src/functions.cpp |  2 +-
 radio/src/logs.cpp      | 83 +++++++++++++++++++++++++++++++++++++----
 radio/src/main.cpp      | 11 +++++-
 radio/src/sdcard.h      |  2 +-
 4 files changed, 87 insertions(+), 11 deletions(-)

diff --git a/radio/src/functions.cpp b/radio/src/functions.cpp
index 16e1f9be5..8cb85149f 100644
--- a/radio/src/functions.cpp
+++ b/radio/src/functions.cpp
@@ -350,7 +350,7 @@ void evalFunctions(const CustomFunctionData * functions, CustomFunctionsContext
           case FUNC_LOGS:
             if (CFN_PARAM(cfn)) {
               newActiveFunctions |= (1u << FUNCTION_LOGS);
-              logDelay = CFN_PARAM(cfn);
+              logDelay100ms = CFN_PARAM(cfn);                   // logging period is 0..25.5s in 100ms increments
             }
             break;
 #endif
diff --git a/radio/src/logs.cpp b/radio/src/logs.cpp
index 9036bfa23..f715b0038 100644
--- a/radio/src/logs.cpp
+++ b/radio/src/logs.cpp
@@ -27,8 +27,71 @@
 #endif
 
 FIL g_oLogFile __DMA;
-const char * g_logError = nullptr;
-uint8_t logDelay;
+uint8_t logDelay100ms;
+static tmr10ms_t lastLogTime = 0;
+
+#if !defined(SIMU)
+#include <FreeRTOS/include/FreeRTOS.h>
+#include <FreeRTOS/include/timers.h>
+
+static TimerHandle_t loggingTimer = nullptr;
+static StaticTimer_t loggingTimerBuffer;
+
+static void loggingTimerCb(TimerHandle_t xTimer)
+{
+  (void)xTimer;
+  if (!s_pulses_paused) {
+    DEBUG_TIMER_START(debugTimerLoggingWakeup);
+    logsWrite();
+    DEBUG_TIMER_STOP(debugTimerLoggingWakeup);
+  }
+}
+
+void loggingTimerStart()
+{
+  if (!loggingTimer) {
+    loggingTimer =
+        xTimerCreateStatic("Logging", logDelay100ms*100 / RTOS_MS_PER_TICK, pdTRUE, (void*)0,
+                           loggingTimerCb, &loggingTimerBuffer);
+  }
+
+  if (loggingTimer) {
+    if( xTimerStart( loggingTimer, 0 ) != pdPASS ) {
+      /* The timer could not be set into the Active state. */
+    }
+  }
+}
+
+void loggingTimerStop()
+{
+  if (loggingTimer) {
+    if( xTimerStop( loggingTimer, 120 / RTOS_MS_PER_TICK ) != pdPASS ) {
+      /* The timer could not be stopped. */
+    }
+    loggingTimer = nullptr;
+  }
+}
+
+void initLoggingTimer() {                                       // called cyclically by main.cpp:perMain()
+  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 */
+        }
+      }
+    }
+  }
+}
+#endif
 
 void writeHeader();
 
@@ -117,8 +180,6 @@ const char * logsOpen()
   return nullptr;
 }
 
-tmr10ms_t lastLogTime = 0;
-
 void logsClose()
 {
   if (sdMounted()) {
@@ -128,9 +189,11 @@ void logsClose()
     }
     lastLogTime = 0;
   }
+  #if !defined(SIMU)
+  loggingTimerStop();
+  #endif
 }
 
-
 void writeHeader()
 {
 #if defined(RTCLOCK)
@@ -207,10 +270,14 @@ void logsWrite()
     return;
   }
 
-  if (isFunctionActive(FUNCTION_LOGS) && logDelay > 0) {
-    tmr10ms_t tmr10ms = get_tmr10ms();
-    if (lastLogTime == 0 || (tmr10ms_t)(tmr10ms - lastLogTime) >= (tmr10ms_t)logDelay*10) {
+  if (isFunctionActive(FUNCTION_LOGS) && logDelay100ms > 0) {
+    #if defined(SIMU)
+    tmr10ms_t tmr10ms = get_tmr10ms();                                        // tmr10ms works in 10ms increments
+    if (lastLogTime == 0 || (tmr10ms_t)(tmr10ms - lastLogTime) >= (tmr10ms_t)(logDelay100ms*10)-1) {
       lastLogTime = tmr10ms;
+    #else
+    {
+    #endif
 
       if (!g_oLogFile.obj.fs) {
         const char * result = logsOpen();
diff --git a/radio/src/main.cpp b/radio/src/main.cpp
index 1a88bd53a..7aec159b8 100644
--- a/radio/src/main.cpp
+++ b/radio/src/main.cpp
@@ -473,6 +473,10 @@ void guiMain(event_t evt)
 }
 #endif
 
+#if !defined(SIMU)
+  void initLoggingTimer();
+#endif
+
 void perMain()
 {
   DEBUG_TIMER_START(debugTimerPerMain1);
@@ -481,7 +485,12 @@ void perMain()
 
   if (!usbPlugged() || (getSelectedUsbMode() == USB_UNSELECTED_MODE)) {
     checkEeprom();
-    logsWrite();
+    
+    #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
   }
 
   handleUsbConnection();
diff --git a/radio/src/sdcard.h b/radio/src/sdcard.h
index 2b5a5b711..90f505a32 100644
--- a/radio/src/sdcard.h
+++ b/radio/src/sdcard.h
@@ -110,7 +110,7 @@ const char RADIO_SETTINGS_YAML_PATH[] = RADIO_PATH PATH_SEPARATOR "radio.yml";
   filename[sizeof(path)+sizeof(var)] = '\0'; \
   strcat(&filename[sizeof(path)], ext)
 
-extern uint8_t logDelay;
+extern uint8_t logDelay100ms;
 void logsInit();
 void logsClose();
 void logsWrite();