Profiling Arduino Code

Projects Programming
27

It was more as a learning experience tool than anything, I guess you(I/we) can probably buy your way to the knowledge too but I wanted to grab a wrench and start taking things apart instead.

If anyone wanted to humour me, after a little more shuffling, tweaking, renaming, I'm currently here:

"Profiler.h"

#ifndef Profiler_h
#define Profiler_h

#ifndef PROFILE_RESULTS_MAX
#define PROFILE_RESULTS_MAX 100
#endif

struct ProfileResult {
  const char* name;
  uint32_t startTime, endTime;
};

class Profiler
{
  private:
    int resultCount;
  public:

    ProfileResult results[PROFILE_RESULTS_MAX] = {0};

    void beginSession() {
      Serial.println(F("Profiling..."));
      Serial.println();

      resultCount = 0;
    }

    void endSession()
    {
      printHeader();
      printResults();
      printFooter();

      resultCount = 0;

      Serial.println();
      Serial.println(F("Profiling Complete"));
    }

    void saveResult(const ProfileResult& result) {
      if (resultCount < PROFILE_RESULTS_MAX)
        results[resultCount++] = result;
    }

    void printResults() {
      for (byte i = 0; i < resultCount; i++) {
        Serial.println(F("{"));
        Serial.println(F("\"cat\":\"function\","));
        Serial.print(F("\"dur\":"));
        Serial.print(results[i].endTime - results[i].startTime);
        Serial.println(F(","));
        Serial.print(F("\"name\":\""));
        Serial.print(results[i].name);
        Serial.println(F("\","));
        Serial.println(F("\"ph\":\"X\","));
        Serial.println(F("\"pid\":0,"));
        Serial.println(F("\"tid\":0,"));
        Serial.print(F("\"ts\":"));
        Serial.println(results[i].startTime);

        if (i < resultCount - 1)
          Serial.println(F("},"));
        else
          Serial.println(F("}"));
      }
    }

    void printHeader() {
      Serial.println(F("{\"otherData\": {},\"traceEvents\":["));
    }

    void printFooter() {
      Serial.println(F("]}"));
    }

    static Profiler& get() {
      static Profiler instance;
      return instance;
    }
};

class ProfileTimer
{
  public:
    ProfileTimer(const char* name)
      : name(name), startTime(micros()) { }

    ~ProfileTimer() {
      Profiler::get().saveResult({name, startTime, micros()});
    }

  private:
    const char* name;
    const uint32_t startTime;
};


#if PROFILING
#define STR_INDIR(x) #x
#define STR(x) STR_INDIR(x)
#define PROFILE_BEGIN() Profiler::get().beginSession();
#define PROFILE_FUNCTION() ProfileTimer timer##__LINE__(__PRETTY_FUNCTION__);
#define PROFILE_SCOPE() ProfileTimer timer##__LINE__("Line:" STR(__LINE__));
#define PROFILE_END() Profiler::get().endSession();
#else
#define PROFILE_BEGIN()
#define PROFILE_FUNCTION()
#define PROFILE_SCOPE()
#define PROFILE_END()
#endif

#endif

It should still work with the example code in post #15.

It now stores up the results and prolongs all printing until the very end. So at any given capture point we're only saving the timestamps and const char* to an array.

Can I make this more lightweight / less intrusive on the performance it's intended to profile?