improve logging MT robustness

lib/led/GwLeds.cpp

@@ -28,6 +28,7 @@ void handleLeds(void *param){
     GwLog *logger=api->getLogger();
     #ifndef GWLED_FASTLED
         LOG_DEBUG(GwLog::LOG,"currently only fastled handling");
+        delay(50);
         vTaskDelete(NULL);
         return;
     #else

lib/log/GWLog.cpp

@@ -34,7 +34,11 @@ void GwLog::logDebug(int level,const char *fmt,...){
     va_start(args,fmt);
     xSemaphoreTake(locker, portMAX_DELAY);
     vsnprintf(buffer,99,fmt,args);
-    if (! writer) return;
+    buffer[99]=0;
+    if (! writer) {
+        xSemaphoreGive(locker);
+        return;
+    }
     writer->write(prefix.c_str());
     writer->write(buffer);
     writer->write("\n");
@@ -46,3 +50,13 @@ void GwLog::setWriter(GwLogWriter *writer){
     this->writer=writer;
     xSemaphoreGive(locker);
 }
+
+void GwLog::flush(){
+    xSemaphoreTake(locker, portMAX_DELAY);
+    if (! this->writer) {
+        xSemaphoreGive(locker);
+        return;
+    }
+    this->writer->flush();
+    xSemaphoreGive(locker);
+}

lib/log/GwLog.h

@@ -6,6 +6,7 @@ class GwLogWriter{
     public:
         virtual ~GwLogWriter(){}
         virtual void write(const char *data)=0;
+        virtual void flush(){};
 };
 class GwLog{
     private:
@@ -25,6 +26,7 @@ class GwLog{
         void logString(const char *fmt,...);
         void logDebug(int level, const char *fmt,...);
         int isActive(int level){return level <= logLevel;};
+        void flush();
 };
 #define LOG_DEBUG(level,...){ if (logger != NULL && logger->isActive(level)) logger->logDebug(level,__VA_ARGS__);}
 

lib/serial/GwSerial.cpp

@@ -46,23 +46,24 @@ int GwSerial::setup(int baud, int rxpin, int txpin)
     return 0;
 }
 bool GwSerial::isInitialized() { return initialized; }
-size_t GwSerial::enqueue(const uint8_t *data, size_t len)
+size_t GwSerial::enqueue(const uint8_t *data, size_t len, bool partial)
 {
     if (! isInitialized()) return 0;
-    return buffer->addData(data, len);
+    return buffer->addData(data, len,partial);
 }
 GwBuffer::WriteStatus GwSerial::write(){
     if (! isInitialized()) return GwBuffer::ERROR;
     return buffer->fetchData(writer,-1,false);
 }
-void GwSerial::sendToClients(const char *buf,int sourceId){
+size_t GwSerial::sendToClients(const char *buf,int sourceId,bool partial){
-    if ( sourceId == id) return;
+    if ( sourceId == id) return 0;
     size_t len=strlen(buf);
-    size_t enqueued=enqueue((const uint8_t*)buf,len);
+    size_t enqueued=enqueue((const uint8_t*)buf,len,partial);
-    if (enqueued != len){
+    if (enqueued != len && ! partial){
         LOG_DEBUG(GwLog::DEBUG,"GwSerial overflow on channel %d",id);
         overflows++;
     }
+    return enqueued;
 }
 void GwSerial::loop(bool handleRead){
     write();

lib/serial/GwSerial.h

@@ -16,7 +16,7 @@ class GwSerial{
         GwBuffer::WriteStatus write();
         int id=-1;
         int overflows=0;
-        size_t enqueue(const uint8_t *data, size_t len);
+        size_t enqueue(const uint8_t *data, size_t len,bool partial=false);
         HardwareSerial *serial;
     public:
         static const int bufferSize=200;
@@ -24,7 +24,7 @@ class GwSerial{
         ~GwSerial();
         int setup(int baud,int rxpin,int txpin);
         bool isInitialized();
-        void sendToClients(const char *buf,int sourceId);
+        size_t sendToClients(const char *buf,int sourceId,bool partial=false);
         void loop(bool handleRead=true);
         bool readMessages(GwBufferWriter *writer);
         void flush();

src/main.cpp

@@ -171,10 +171,31 @@ GwSerial *serial1=NULL;
 
 
 class GwSerialLog : public GwLogWriter{
+  static const size_t bufferSize=4096;
+  char *logBuffer=NULL;
+  int wp=0;
   public:
+    GwSerialLog(){
+      logBuffer=new char[bufferSize];
+      wp=0;
+    }
     virtual ~GwSerialLog(){}
     virtual void write(const char *data){
-      usbSerial->sendToClients(data,-1); //ignore any errors
+      int len=strlen(data);
+      if ((wp+len) >= (bufferSize-1)) return;
+      strncpy(logBuffer+wp,data,len);
+      wp+=len;
+      logBuffer[wp]=0;
+    }
+    virtual void flush(){
+      size_t handled=0;
+      while (handled < wp){
+        usbSerial->flush();
+        size_t rt=usbSerial->sendToClients(logBuffer+handled,-1,true);
+        handled+=rt;
+        }
+      wp=0;
+      logBuffer[0]=0;
     }
 
 };
@@ -214,12 +235,14 @@ public:
   }
 };
 
-void delayedRestart(){
+bool delayedRestart(){
-  xTaskCreate([](void *p){
+  return xTaskCreate([](void *p){
+    GwLog *logRef=(GwLog *)p;
+    logRef->logDebug(GwLog::LOG,"delayed reset started");
     delay(500);
     ESP.restart();
     vTaskDelete(NULL);
-  },"reset",1000,NULL,0,NULL);
+  },"reset",1000,&logger,0,NULL) == pdPASS;
 }
 
 
@@ -243,7 +266,9 @@ protected:
   {
     logger.logDebug(GwLog::LOG, "Reset Button");
     result = JSON_OK;
-    delayedRestart();
+    if (!delayedRestart()){
+      logger.logDebug(GwLog::ERROR,"cannot initiate restart");
+    }
   }
 };
 
@@ -463,10 +488,10 @@ void setup() {
 
   // Start TCP server
   socketServer.begin();
-  usbSerial->flush();
+  logger.flush();
 
   logger.logDebug(GwLog::LOG,"usbRead: %s", usbReadFilter.toString().c_str());
-  usbSerial->flush();
+  logger.flush();
 
   webserver.registerMainHandler("/api/reset", [](AsyncWebServerRequest *request)->GwRequestMessage *{
     return new ResetRequest();
@@ -540,7 +565,7 @@ void setup() {
   preferences.end();
 
   logger.logDebug(GwLog::LOG,"NodeAddress=%d", NodeAddress);
-  usbSerial->flush();
+  logger.flush();
   NMEA2000.SetMode(tNMEA2000::N2km_ListenAndNode, NodeAddress);
   NMEA2000.SetForwardOwnMessages(false);
   // Set the information for other bus devices, which messages we support
@@ -549,7 +574,7 @@ void setup() {
     unsigned long *op=pgns;
     while (*op != 0){
       logger.logDebug(GwLog::DEBUG,"add transmit pgn %ld",(long)(*op));
-      usbSerial->flush();
+      logger.flush();
       op++;
     }
   }
@@ -666,6 +691,7 @@ class NMEAMessageReceiver : public GwBufferWriter{
 NMEAMessageReceiver receiver;
 unsigned long lastHeapReport=0;
 void loop() {
+  logger.flush();
   gwWifi.loop();
   unsigned long now=millis();
   if (HEAP_REPORT_TIME > 0 && now > (lastHeapReport+HEAP_REPORT_TIME)){