Skip to content
95 changes: 48 additions & 47 deletions src/utils/profiler.cpp
Original file line number Diff line number Diff line change
@@ -1,53 +1,49 @@
#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
// 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);
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"
}
sections[i].name[PROF_MAX_NAME] = '\0';// ensure null termination
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;
Expand All @@ -56,30 +52,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_TIMES : 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,
(trueCount == 0 ? 0 : 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
}
58 changes: 28 additions & 30 deletions src/utils/profiler.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -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 + 1] = {0};// +1 extra space for null terminator
};

/// @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