improve statistics

lib/log/GWLog.cpp

@@ -21,13 +21,16 @@ void GwLog::logString(const char *fmt,...){
     va_list args;
     va_start(args,fmt);
     xSemaphoreTake(locker, portMAX_DELAY);
-    vsnprintf(buffer,99,fmt,args);
+    vsnprintf(buffer,bufferSize-1,fmt,args);
-    buffer[99]=0;
+    buffer[bufferSize-1]=0;
     if (! writer) {
         xSemaphoreGive(locker);
         return;
     }
     writer->write(prefix.c_str());
+    char buf[20];
+    snprintf(buf,20,"%lu:",millis());
+    writer->write(buf);
     writer->write(buffer);
     writer->write("\n");
     xSemaphoreGive(locker);
@@ -37,8 +40,8 @@ void GwLog::logDebug(int level,const char *fmt,...){
     va_list args;
     va_start(args,fmt);
     xSemaphoreTake(locker, portMAX_DELAY);
-    vsnprintf(buffer,99,fmt,args);
+    vsnprintf(buffer,bufferSize-1,fmt,args);
-    buffer[99]=0;
+    buffer[bufferSize-1]=0;
     if (! writer) {
         xSemaphoreGive(locker);
         return;

lib/log/GwLog.h

@@ -10,7 +10,8 @@ class GwLogWriter{
 };
 class GwLog{
     private:
-        char buffer[100];
+        static const size_t bufferSize=200;
+        char buffer[bufferSize];
         int logLevel=1;
         GwLogWriter *writer;
         SemaphoreHandle_t locker;

lib/statistics/GwStatistics.h

@@ -0,0 +1,105 @@
+#pragma once
+#include <Arduino.h>
+class TimeAverage{
+  double factor=0.3;
+  double current=0;
+  unsigned long count=0;
+  unsigned long max=0;
+  bool init=false;
+  public:
+    TimeAverage(double factor){
+      this->factor=factor;
+    }
+    void add(unsigned long diff){
+      if (diff > max) max=diff;  
+      count++;
+      if (! init){
+          current=(double)diff;
+          init=true;
+      }
+      else{
+          double add=((double)diff - current)*factor;
+          current+=add;
+      }
+    }
+    double getCurrent(){
+      return current;
+    }
+
+    unsigned long getCount(){
+      return count;
+    }
+    void resetMax(){
+        max=0;
+    }
+    unsigned long getMax(){
+        return max;
+    }
+
+};
+class TimeMonitor{
+  public:
+    TimeAverage **times=NULL;
+    unsigned long start=0;
+    unsigned long lastLog=0;
+    unsigned long lastLogCount=0;
+    unsigned long count=0;
+    size_t len;
+    TimeMonitor(size_t len,double factor=0.3){
+      this->len=len;
+      times=new TimeAverage*[len];
+      for (size_t i=0;i<len;i++){
+          times[i]=new TimeAverage(factor);
+      }
+      reset();
+      count=0;
+    }
+    void reset(){
+      start=millis();
+      count++;
+      
+    }
+    double getMax(){
+        double rt=0;
+        for (size_t i=0;i<len;i++){
+            if (times[i]->getCurrent() == 0) continue;
+            if (times[i]->getCurrent() > rt) rt=times[i]->getCurrent();
+        }
+        return rt;
+    }
+    String getLog(){
+      unsigned long now=millis();
+      String log;  
+      if (lastLog != 0){
+          unsigned long num=count-lastLogCount;
+          unsigned long tdif=now-lastLog;
+          if (tdif > 0){
+            log+=String((double)(num*1000)/(double)tdif);
+            log+="/s,";
+            log+=String(getMax());
+            log+="ms#";
+          }
+      }
+      lastLog=now;
+      lastLogCount=count; 
+      for (size_t i=1;i<len;i++){
+        if (times[i]->getCount()){
+          log+=String(i);
+          log+=":";
+          log+=String(times[i]->getCurrent());
+          log+="[";
+          log+=String(times[i]->getMax());
+          log+="],";
+        }
+      }
+      for (size_t i=0;i<len;i++){
+          times[i]->resetMax();
+      }
+      return log;
+    }
+    void setTime(size_t index){
+      if (index < 1 || index >= len) return;
+      unsigned long current=millis()-start;
+      times[index-1]->add(current);
+    }
+};

src/main.cpp

@@ -72,6 +72,7 @@ const unsigned long HEAP_REPORT_TIME=2000; //set to 0 to disable heap reporting
 #include "GwXDRMappings.h"
 #include "GwSynchronized.h"
 #include "GwUserCode.h"
+#include "GwStatistics.h"
 
 
 //NMEA message channels
@@ -845,90 +846,8 @@ class NMEAMessageReceiver : public GwMessageFetcher{
       return true;
     }
 };
-class TimeMonitor{
-  public:
-    unsigned long *times=NULL;
-    size_t len;
-    TimeMonitor(size_t len){
-      this->len=len;
-      times=new unsigned long[len];
-      reset();
-    }
-    void reset(){
-      if (len>0) times[0]=millis();
-      for (size_t i=1;i<len;i++){
-        times[i]=0;
-      }
-    }
-    unsigned long getMax(){
-      unsigned long maxTime=0;
-      for (size_t i=1;i< len;i++){
-        if (times[i] != 0){
-          if (times[i] > maxTime) maxTime=times[i];
-        }
-      }
-      if (maxTime > 0) return maxTime-times[0];
-      return 0;
-    }
-    void writeLog(unsigned long minTime){
-      unsigned long maxTime=getMax();
-      if (maxTime == 0 || maxTime < minTime) return;
-      String log;
-      for (size_t i=1;i<len;i++){
-        if (times[i] != 0){
-          log+=String(i);
-          log+=":";
-          log+=String((times[i]-times[0]));
-          log+=",";
-        }
-      }
-      logger.logDebug(GwLog::LOG,"times: %s",log.c_str());
-    }
-    void setTime(size_t index){
-      if (index < 1 || index >= len) return;
-      times[index]=millis();
-    }
-};
-class TimeAverage{
-  size_t len;
-  size_t wp=0;
-  size_t filled=0;
-  unsigned long *diffs=NULL;
-  unsigned long count=0;
-  unsigned long sum=0;
-  public:
-    TimeAverage(size_t len){
-      this->len=len;
-      wp=0;
-      filled=0;
-      diffs=new unsigned long[len];
-    }
-    void add(unsigned long diff){
-      count++;
-      sum+=diff;
-      diffs[wp]=diff;
-      wp++;
-      if (filled < len){
-        filled++;
-      }
-      else{
-        if (wp >= len) wp=0;
-        sum-=diffs[wp];
-      }
-    }
-    unsigned long current(){
-      if (filled == 0) return 0;
-      return sum*1000/filled;
-    }
 
-    unsigned long getCount(){
+TimeMonitor monitor(20,0.2);
-      return count;
-    }
-
-};
-TimeMonitor monitor(20);
-TimeAverage average(50);
-unsigned long lastReportCount=0;
 NMEAMessageReceiver receiver;
 unsigned long lastHeapReport=0;
 void loop() {
@@ -946,11 +865,7 @@ void loop() {
           (long)xPortGetFreeHeapSize(),
           (long)xPortGetMinimumEverFreeHeapSize()
       );
-      logger.logDebug(GwLog::DEBUG,"Main loop count=%d, average=%dus",
+      logger.logDebug(GwLog::DEBUG,"Main loop %s",monitor.getLog().c_str());
-        (int)(average.getCount()-lastReportCount),
-        (int)average.current()
-        );
-      lastReportCount=average.getCount();  
     }
   }
   monitor.setTime(3);
@@ -999,8 +914,4 @@ void loop() {
     msg->unref();
   }
   monitor.setTime(15);
-  average.add(monitor.getMax());
-  if (logger.isActive(GwLog::LOG)){
-    monitor.writeLog(6);
-  }
 }