Profiler improvements #2724

andresovela · 2024-10-18T13:11:09Z

This PR adds a few improvements to the MicroProfiler class.

First, I made it a template so that it's possible to adjust the maximum number of events the profiler can handle via a template parameter.

The motivation for this change is to save memory. #1835 increased the maximum number of events from 1024 to 4096, which is a huge waste of RAM. The MicroProfiler class has these buffers:

const char* tags_[kMaxEvents];
uint32_t start_ticks_[kMaxEvents];
uint32_t end_ticks_[kMaxEvents];

struct TicksPerTag {
  const char* tag;
  uint32_t ticks;
};

TicksPerTag total_ticks_per_tag[kMaxEvents];

We need 20 bytes per event, so an instance of MicroProfiler uses 80 KB of RAM, even if the model you're profiling has only a few nodes.

This PR also adds the following enum to specify the logging format and remove some duplicated code and clean the API.

enum class MicroProfilerLogFormat {
  HumanReadable,
  Csv,
};

I replaced LogTicksPerTagCsv() with LogGrouped(), which does essentially the same thing, but also prints in a human readable format which looks like this:

Cumulative event times:
Count    Tag                              Ticks        Time
6        DEPTHWISE_CONV_2D                3085702      5.194 ms
2        SUM                              1281206      2.156 ms
66       FULLY_CONNECTED                  934142       1.572 ms
10       CONV_2D                          765357       1.288 ms
67       QUANTIZE                         731923       1.232 ms
20       CONCATENATION                    362212       0.609 ms
76       STRIDED_SLICE                    335828       0.565 ms
3        RELU                             245643       0.413 ms
4        DEQUANTIZE                       156682       0.263 ms
6        PAD                              145834       0.245 ms
29       ADD                              130229       0.219 ms
65       RESHAPE                          49593        0.083 ms
13       MUL                              48852        0.082 ms
4        SUB                              16371        0.027 ms
6        LOGISTIC                         10336        0.017 ms
3        TANH                             4761         0.008 ms
3        UNPACK                           2738         0.004 ms

Total time: 13.985 ms (8307409 ticks)

Finally I also added TicksToUs() to micro_time.h for convenience.

ddavis-2015 · 2024-10-19T21:16:44Z

tensorflow/lite/micro/micro_profiler.h

 // sections. This can be used in conjunction with running the relevant micro
 // benchmark to evaluate end-to-end performance.
+template <int MAX_EVENTS>


This should be template <int MAX_EVENTS = 4096> so that all existing applications using the profiler do not need to be changed.

ddavis-2015 · 2024-10-19T21:21:39Z

tensorflow/lite/micro/micro_profiler.h

+      case MicroProfilerLogFormat::Csv:
+        MicroPrintf("\"Event\",\"Tag\",\"Ms\",\"Ticks\"");
+        for (int i = 0; i < num_events_; ++i) {
+#if defined(HEXAGON) || defined(CMSIS_NN)
+          int ticks = end_ticks_[i] - start_ticks_[i];
+          MicroPrintf("%d,%s,%u,%d", i, tags_[i], TicksToMs(ticks), ticks);
+#else
+          uint32_t ticks = end_ticks_[i] - start_ticks_[i];
+          uint64_t us = TicksToUs(ticks);
+          MicroPrintf("%d,%s,%" PRIu64 ".%" PRIu64 ",%" PRIu32, i, tags_[i],
+                      us / 1000, us % 1000, ticks);
+#endif


Changing the CSV format probably won't pass review, as it most likely breaks countless internal Google, and external third-party scripts.

Removed the Ms column

ddavis-2015 · 2024-10-19T21:23:12Z

tensorflow/lite/micro/micro_profiler.h

    const char* tag;
    uint32_t ticks;
+    uint32_t tag_count;


Only used by the "human readable" log format.

What should I do about that? #1290 introduced

struct TicksPerTag { const char* tag; uint32_t ticks; }; // In practice, the number of tags will be much lower than the number of // events. But it is theoretically possible that each event to be unique and // hence we allow total_ticks_per_tag to have kMaxEvents entries. TicksPerTag total_ticks_per_tag[kMaxEvents];

which was "only" used by the CSV log format.

@andresovela

The comment is really just there for @suleshahid to see.

ddavis-2015 · 2024-10-19T21:24:42Z

tensorflow/lite/micro/micro_profiler.h

+  void SortTagGroups() {
+    for (int i = 0; i < num_tag_groups_ - 1; ++i) {
+      for (int j = i + 1; j < num_tag_groups_; ++j) {
+        if (tag_groups_[j].ticks > tag_groups_[i].ticks) {
+          TagGroup temp_tag_group = tag_groups_[i];
+          tag_groups_[i] = tag_groups_[j];
+          tag_groups_[j] = temp_tag_group;
+        }
+      }
+    }
+  }


Please use standard C++ library algorithms (as long as they don't require memory allocation). Here std::sort should be used.

ddavis-2015 · 2024-10-19T21:27:45Z

tensorflow/lite/micro/micro_profiler.h

-  virtual uint32_t BeginEvent(const char* tag) override;
+  uint32_t BeginEvent(const char* tag) {


This is an override of the abstract base class, and should remain as such.

ddavis-2015 · 2024-10-19T21:28:18Z

tensorflow/lite/micro/micro_profiler.h

-  virtual void EndEvent(uint32_t event_handle) override;
+  void EndEvent(uint32_t event_handle) {


This is an override of the abstract base class, and should remain as such.

ddavis-2015 · 2024-10-19T21:41:58Z

tensorflow/lite/micro/micro_profiler.h


  // Prints the profiling information of each of the events in human readable
  // form.
-  void Log() const;
+  void Log(MicroProfilerLogFormat format) const {


Should have a default argument of MicroProfilerLogFormt::Csv so that all existing applications continue to compile without modification.

Why CSV though? This method logs in human readable by default?

I added HumanReadable as default argument since that's what would keep the existing behavior while continuing to compile

ddavis-2015 · 2024-10-19T22:01:50Z

tensorflow/lite/micro/micro_profiler.h


-  // Prints the profiling information of each of the events in CSV (Comma
-  // Separated Value) form.
-  void LogCsv() const;


LogCsv should be retained, and should call Log(MicroProfilerFormat::Csv), so that existing applications do not require modification.

ddavis-2015 · 2024-10-19T22:03:42Z

tensorflow/lite/micro/micro_profiler.h

+      case MicroProfilerLogFormat::Csv: {
+        MicroPrintf("\"Tag\",\"Total ms\",\"Total ticks\"");
+        for (int i = 0; i < num_tag_groups_; ++i) {
+          uint64_t us = TicksToUs(tag_groups_[i].ticks);
+          MicroPrintf("%s, %" PRIu64 ".%" PRIu64 ", %u", tag_groups_[i].tag,
+                      us / 1000, us % 1000, tag_groups_[i].ticks);
+        }


Changing the CSV format probably won't pass review, as it most likely breaks countless internal Google, and external third-party scripts.

Removed the Total ms column

ddavis-2015 · 2024-10-19T22:09:13Z

@andresovela

Thanks for your PR submission (and all the spelling corrections!).

This will require some discussion with @suleshahid. I like the template change for sizing the timing data.

ddavis-2015 · 2024-10-21T11:16:49Z

tensorflow/lite/micro/micro_profiler.h

-  // Prints  total ticks for each unique tag in CSV format.
-  // Output will have one row for each unique tag along with the
-  // total ticks summed across all events with that particular tag.
-  void LogTicksPerTagCsv();


This method cannot be removed as it breaks existing applications.

Added it back

Is there a policy to never break stuff like this? IMO duplicating APIs like this is also not great.

@andresovela Let's just say, that at the present time, no one is allowed to break anything. 🙂

andresovela · 2024-11-04T12:16:26Z

Oops, closed by mistake.

github-actions · 2024-12-15T10:06:53Z

"This PR is being marked as stale due to inactivity. Remove label or comment to prevent closure in 5 days."

andresovela · 2024-12-15T11:22:44Z

Waiting for review

andresovela added 2 commits October 18, 2024 14:49

Improve micro_profiler

066652d

Fix formatting

adac799

andresovela requested a review from a team as a code owner October 18, 2024 13:11

andresovela added 2 commits October 18, 2024 17:46

Fixed formatting issues

f250291

Add decimals to missing logs

91c0fdf

ddavis-2015 reviewed Oct 19, 2024

View reviewed changes

ddavis-2015 requested a review from suleshahid October 19, 2024 22:05

Address code review

8911d4c

ddavis-2015 assigned andresovela Oct 21, 2024

ddavis-2015 added the ci:run_full label Oct 21, 2024

TFLM-bot removed the ci:run_full label Oct 21, 2024

ddavis-2015 reviewed Oct 21, 2024

View reviewed changes

Add LogTicksPerTagCsv() back

ec67287

ddavis-2015 added the ci:run_full label Oct 21, 2024

TFLM-bot removed the ci:run_full label Oct 21, 2024

Add missing zero padding to log

dce2a28

andresovela closed this Nov 2, 2024

andresovela deleted the profiling-improvements branch November 2, 2024 03:32

andresovela restored the profiling-improvements branch November 4, 2024 12:16

andresovela reopened this Nov 4, 2024

andresovela mentioned this pull request Nov 13, 2024

Reduce size of MicroProfiler #2725

Open

github-actions bot added the Stale label Dec 15, 2024

ddavis-2015 removed the Stale label Dec 15, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Profiler improvements #2724

Profiler improvements #2724

andresovela commented Oct 18, 2024 •

edited

Loading

ddavis-2015 Oct 19, 2024

andresovela Oct 21, 2024

ddavis-2015 Oct 19, 2024

andresovela Oct 21, 2024

ddavis-2015 Oct 19, 2024

andresovela Oct 19, 2024 •

edited

Loading

ddavis-2015 Oct 20, 2024

ddavis-2015 Oct 19, 2024

andresovela Oct 21, 2024

ddavis-2015 Oct 19, 2024

andresovela Oct 21, 2024

ddavis-2015 Oct 19, 2024

andresovela Oct 21, 2024

ddavis-2015 Oct 19, 2024

andresovela Oct 21, 2024

andresovela Oct 21, 2024

ddavis-2015 Oct 19, 2024

andresovela Oct 21, 2024

ddavis-2015 Oct 19, 2024

andresovela Oct 21, 2024

ddavis-2015 commented Oct 19, 2024

ddavis-2015 Oct 21, 2024

andresovela Oct 21, 2024

andresovela Oct 21, 2024

ddavis-2015 Oct 21, 2024

andresovela commented Nov 4, 2024

github-actions bot commented Dec 15, 2024

andresovela commented Dec 15, 2024

		virtual uint32_t BeginEvent(const char* tag) override;
		uint32_t BeginEvent(const char* tag) {

		virtual void EndEvent(uint32_t event_handle) override;
		void EndEvent(uint32_t event_handle) {

Profiler improvements #2724

Are you sure you want to change the base?

Profiler improvements #2724

Conversation

andresovela commented Oct 18, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

andresovela Oct 19, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ddavis-2015 commented Oct 19, 2024

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

andresovela commented Nov 4, 2024

github-actions bot commented Dec 15, 2024

andresovela commented Dec 15, 2024

andresovela commented Oct 18, 2024 •

edited

Loading

andresovela Oct 19, 2024 •

edited

Loading