Profiler rework

src/main.cpp

@@ -86,8 +86,15 @@ int main() {
 
     Serial.begin(115200); // the serial monitor is actually always active (for debug use Serial.println & tycmd)
     debug.begin(SerialUSB1);
-    
+
     print_logo();
+
+    for(uint_32t i = 0; i < 5100; i++) {
+	prof.begin("tester");
+	delayMicroseconds(random(150, 250));
+	prof.end("tester");
+    }
+    prof.print("tester");
 
     // check to see if there is a crash report, and if so, print it repeatedly over Serial
     // in the future, we'll send this directly over comms
@@ -452,4 +459,4 @@ int main() {
     }
 
     return 0;
-}
+}

src/utils/profiler.cpp

@@ -1,53 +1,48 @@
 #include "profiler.hpp"
+#include <cstring>
 
-/// @brief Array of profiling sections.
 #ifdef PROFILE
-static DMAMEM Profiler::profiler_section_t sections[PROF_MAX_SECTIONS] = { 0 };
+static DMAMEM Profiler::profiler_section_t sections[PROF_MAX_SECTIONS] = {0};
 #endif
 
-
 void Profiler::clear() {
 #ifdef PROFILE
-    for (auto& sec : sections) {
-        // initialize each section so the sections arent filled with DMAMEM junk
+    for (auto &sec : sections)
         sec = profiler_section_t();
-    }
 #endif
 }
 
-void Profiler::begin(const char* name) {
+void Profiler::begin(const char *name) {
 #ifdef PROFILE
-    // search for a section by name or an empty slot
-    for (uint32_t i = 0; i < PROF_MAX_SECTIONS; i++) {
-        if (strncmp(sections[i].name, name, PROF_MAX_NAME) == 0 || (sections[i].count == 0 && sections[i].overflow == 0)) {
-            // start this section
-            strncpy(sections[i].name, name, PROF_MAX_NAME);
-            sections[i].name[PROF_MAX_NAME] = '\0';  // ensure null termination
-            if (sections[i].count < PROF_MAX_TIMES) {
-                sections[i].start_times[sections[i].count] = micros();
-                sections[i].started = 1;    // set this section as "started"
-            }
+    //find section by name or first empty slot
+    for(uint32_t i = 0; i < PROF_MAX_SECTIONS; i++) {
+        if(strcmp(sections[i].name, name) == 0 || (sections[i].count == 0 && sections[i].overflowed == 0)) {
+            //start section
+            strncpy(sections[i].name, name, PROF_MAX_NAME-1);
+            sections[i].start_time = micros();
+            sections[i].started = 1;//label section as started
             return;
         }
     }
 #endif
 }
 
-void Profiler::end(const char* name) {
+void Profiler::end(const char *name) {
 #ifdef PROFILE
-    // find the section by name and add an end time
-    for (uint32_t i = 0; i < PROF_MAX_SECTIONS; i++) {
-        if (strncmp(sections[i].name, name, PROF_MAX_NAME) == 0) {
-            uint32_t count = sections[i].count;
-            if (count < PROF_MAX_TIMES) {
-                sections[i].end_times[count] = micros();
+    //find section by name
+    for(uint32_t i = 0; i < PROF_MAX_SECTIONS; i++) {
+        if(strcmp(sections[i].name, name) == 0) {
+            //end section
+            if(sections[i].count < PROF_MAX_TIMES) {
+                sections[i].time_lengths[sections[i].count] = micros() - sections[i].start_time;
                 sections[i].count++;
-                sections[i].started = 0;    // set this section as "finished"
-                // if this value just overflowed, or it has reached the max time count, 
-                // mark it as overflowed and reset to 0
-                if (sections[i].count == 0 || sections[i].count == PROF_MAX_TIMES) {
-                    sections[i].overflow = 1;
+                sections[i].started = 0;//label section as finished
+
+                //if count is now at limit, reset count and label as overflowed
+                if(sections[i].count == PROF_MAX_TIMES)
+                {
                     sections[i].count = 0;
+                    sections[i].overflowed = 1;
                 }
             }
             return;
@@ -56,30 +51,35 @@ void Profiler::end(const char* name) {
 #endif
 }
 
-void Profiler::print(const char* name) {
+void Profiler::print(const char *name) {
 #ifdef PROFILE
+    uint32_t sum = 0;
     uint32_t min = UINT32_MAX;
     uint32_t max = 0;
-    uint32_t sum = 0;
-
+
+    // find section by name
     for (uint32_t i = 0; i < PROF_MAX_SECTIONS; i++) {
-        if (strncmp(sections[i].name, name, PROF_MAX_NAME) != 0) continue;
-        // find actual count since this value can overflow/max out
-        uint32_t actual_count = sections[i].overflow ? PROF_MAX_TIMES : sections[i].count;
-        for (unsigned int j = 0; j < actual_count; j++) {
-            // if end() was not called when we decide to print, ignore the "bad" section reading
-            if (sections[i].started && j == sections[i].count) continue;
-
-            uint32_t delta = sections[i].end_times[j] - sections[i].start_times[j];
-            // sum all deltas to be averaged upon printing
-            sum += delta;
-            if (delta < min) min = delta;
-            if (delta > max) max = delta;
+        if (strcmp(sections[i].name, name) == 0) {
+            // calculate values
+            uint32_t trueCount = sections[i].overflowed ? PROF_MAX_SECTIONS : sections[i].count;
+            for (uint32_t j = 0; j < trueCount; j++) {
+                // if the last run was started and not ended, ignore it
+                if (sections[i].started && j == sections[i].count)
+                    continue;
+
+                uint32_t delta = sections[i].time_lengths[j];
+                sum += delta;
+                if(delta < min)
+                    min = delta;
+                if(delta > max)
+                    max = delta;
+            }
+
+            // print values
+            Serial.printf("Profiling for: %s\n Min: %u us\n Max: %u us\n Avg: %u us\n", name, min, max,
+                          sum / trueCount);
+            return;
         }
-        // print stats
-        Serial.printf("Profiling for: %s\n  Min: %u us\n  Max: %u us\n  Avg: %u us\n",
-                        name, min, max, sum / actual_count);
-        return;
     }
 #endif
 }

src/utils/profiler.hpp

@@ -2,53 +2,51 @@
 #define PROFILER_H
 
 // Use this flag to toggle profiling globally.
-// #define PROFILE
+#define PROFILE
 
 #include <Arduino.h>
 
-#define PROF_MAX_SECTIONS 8  // max number of active profiling sections
+#define PROF_MAX_SECTIONS 8   // max number of active profiling sections
 #define PROF_MAX_NAME 16      // max length of section name
-#define PROF_MAX_TIMES (5000)   // max number of start/end times per section
+#define PROF_MAX_TIMES (5000) // max number of start/end times per section
 
 /// @brief Object for profiling sections of code.
 struct Profiler {
     /// @brief Constructor for the profiler.
-    Profiler() {
-        clear();
-    }
+    Profiler() { clear(); }
 
-    /// @brief Data structure for a profiling section. 
+    // @brief Data structure for a profiling section
     struct profiler_section_t {
-        /// @brief Start time for each profiling section.
-        uint32_t start_times[PROF_MAX_TIMES] = { 0 };
-        /// @brief End time for each profiling section.
-        uint32_t end_times[PROF_MAX_TIMES] = { 0 };
-        /// @brief Number of start/end times recorded (how many deltas can be calculated).
+        /// @brief the time lengths of each profiling section
+        uint32_t time_lengths[PROF_MAX_TIMES] = {0};
+        /// @brief Start time for the current profiling section
+        uint32_t start_time = 0;
+        /// @brief Number of start/end times recorded
         uint16_t count = 0;
-        /// @brief Flag on whether count has overflowed or not
-        uint8_t overflow : 7;
-        /// @brief Flag on whether this section had begin() called on it
-        uint8_t started : 1;
-        /// @brief A unique name to identify the section.
-        char name[PROF_MAX_NAME + 1] = { 0 };  // extra for null terminator
+        /// @brief Label on if count has overflowed
+        uint8_t overflowed = 0;
+        /// @brief Label on if a begin() has been called and the corresponding end() hasn't yet
+        uint8_t started = 0;
+        /// @brief Name for each section
+        char name[PROF_MAX_NAME] = {0};
     };
 
-    /// @brief  Clear all profiling sections.
+    /// @brief clear all profiling sections
     void clear();
 
-    /// @brief Start a profiling section.
-    /// @param name A unique name to identify the section.
-    void begin(const char* name);
+    /// @brief Start a profiling section
+    /// @param name A unique name to identify the section
+    void begin(const char *name);
 
-    /// @brief End a profiling section.
-    /// @param name The name of the section to end.
-    void end(const char* name);
+    /// @brief End a profiling section
+    /// @param name The name of the section to end
+    void end(const char *name);
 
-    /// @brief Print stats for a particular profiling section.
-    /// @param name The name of the section to print statistics for.
-    void print(const char* name);
+    /// @brief Print stats for a profiling section
+    /// @param name The name of the section to print stats for
+    void print(const char *name);
 };
 
-extern Profiler prof;  // Global profiler
+extern Profiler prof; // Global profiler
 
-#endif  // PROFILER_H
+#endif // PROFILER_H