Code section profiling timer

sdk/bare/common/sys/prof_timer.c

@@ -0,0 +1,137 @@
+#include "sys/prof_timer.h"
+#include "drv/fpga_timer.h"
+#include "sys/statistics.h"
+#include "sys/util.h"
+#include <assert.h>
+#include <stdbool.h>
+#include <stdint.h>
+#include <stdlib.h>
+
+static prof_timer_t *m_head = NULL;
+
+// Keep track of the number of registered items
+// so that we can limit the number of loop iterations
+static size_t m_num_registered = 0;
+
+void prof_timer_register(prof_timer_t *x)
+{
+    assert(x);
+
+    prof_timer_t *entry = m_head;
+    size_t i = 0;
+
+    // Find the end of the list. Since we track number of
+    // registrations we can limit our loop count in case of
+    // corruption in the linked list itself.
+    while (entry && entry->__next && (i < m_num_registered)) {
+        // If we are already registered don't double register. Just exit
+        if (entry == x) {
+            return;
+        }
+
+        entry = entry->__next;
+        i++;
+    }
+
+    if (entry) {
+        entry->__next = x;
+    } else {
+        // No registered entries
+        m_head = x;
+    }
+
+    m_num_registered++;
+}
+
+void prof_timer_unregister(prof_timer_t *x)
+{
+    assert(x);
+
+    if (!m_head) {
+        return;
+    }
+
+    // If we are the head then just remove the reference
+    // and make the next element in the list the head
+    if (x == m_head) {
+        m_head = m_head->__next;
+        x->__next = NULL;
+        m_num_registered--;
+    } else {
+        // Otherwise we will need to search for our reference by
+        // iterating over the list to find the element of the list
+        // that references us. Then we set the next reference of
+        // the previous element to our next reference.
+        prof_timer_t *prev = m_head;
+        size_t i = 0;
+        while (prev && (prev->__next) && (i < m_num_registered)) {
+            if (prev->__next == x) {
+                prev->__next = x->__next;
+                x->__next = NULL;
+                m_num_registered--;
+                break;
+            }
+
+            i++;
+        }
+    }
+}
+
+void __prof_timer_stop(prof_timer_t *x, uint32_t now_ticks)
+{
+    assert(x);
+
+    if (x->is_enabled) {
+        double dt_usec = fpga_timer_ticks_to_usec(now_ticks - x->__start_time);
+        statistics_push(&(x->stats), dt_usec);
+    }
+}
+
+void __prof_timer_stop_crit(prof_timer_t *x, uint32_t now_ticks)
+{
+    assert(x);
+
+    __prof_timer_stop(x, now_ticks);
+
+    if (x->is_enabled) {
+        util_critical_section_exit(x->__primask);
+    }
+}
+
+void prof_timer_reset(prof_timer_t *x)
+{
+    assert(x);
+
+    if (x->is_enabled) {
+        statistics_clear(&(x->stats));
+    }
+}
+
+size_t prof_timer_num_registered(void)
+{
+    return m_num_registered;
+}
+
+bool prof_timer_iterate(prof_timer_t **current)
+{
+    assert(current);
+
+    static size_t iteration = 0;
+    if (*current == NULL) {
+        *current = m_head;
+        iteration = 0;
+    } else {
+        *current = (*current)->__next;
+        iteration += 1;
+    }
+
+    return (*current != NULL) && (iteration < m_num_registered);
+}
+
+void prof_timer_reset_all(void)
+{
+    FOR_ALL_PROF_TIMERS(x)
+    {
+        prof_timer_reset(x);
+    }
+}

sdk/bare/common/sys/prof_timer.h

@@ -0,0 +1,158 @@
+/**
+ * Timer for profiling specific sections of code.
+ *
+ * Can be used to register profiling timers for printouts later, or
+ * on it's own. This implements a linked list with a static head
+ * which can be iterated over to print out all statistics. This timer
+ * uses the sys/statistics module and the high precision
+ * drv/fpga_timer module at its core to provide high precision
+ * profiling statistics for how long a piece of code takes to run.
+ *
+ * Usage:
+ *
+ * @code
+ * // Some module.c
+ *
+ * prof_timer_t my_math_timer = {
+ *   .name = "My Math",
+ *   .is_enabled = true
+ * };
+ *
+ * void module_init() {
+ *   prof_timer_register(&my_math_timer);
+ * }
+ *
+ * void module_update() {
+ *   // some code
+ *
+ *   prof_timer_start(&my_math_timer);
+ *
+ *   float x = sin(random()) * sqrt(PI);
+ *
+ *   prof_timer_stop(&my_math_timer);
+ *
+ *   // Some code
+ * }
+ *
+ * ///////////////
+ *
+ * // cmd_module.c
+ *
+ * ...
+ * // Print all profiling stats means
+ * FOR_ALL_PROF_TIMERS(t) {
+ *   if (t->is_enabled)
+ *     printf("%s %d", t->name, t->stats.mean);
+ * }
+ *
+ * /// OR
+ *
+ * prof_timer_t *t = NULL;
+ * while (prof_timer_iterate(&t)) {
+ *   if (t->is_enabled)
+ *     printf("%s %d", t->name, t->stats.mean);
+ * }
+ *
+ * ...
+ * @endcode
+ */
+
+#ifndef PROF_TIMER_H
+#define PROF_TIMER_H
+
+#include "drv/fpga_timer.h"
+#include "sys/statistics.h"
+#include "sys/util.h"
+
+#include <stdbool.h>
+#include <stdint.h>
+#include <stdlib.h>
+
+// ---------
+// Structure
+// ---------
+
+typedef struct prof_timer {
+    // A name for printouts
+    const char *name;
+
+    // Will the stats actually be calculated?
+    bool is_enabled;
+
+    // Statistics for the timer.
+    statistics_t stats;
+
+    // Private struct variables
+    uint32_t __start_time;
+    struct prof_timer *__next;
+    uint32_t __primask;
+} prof_timer_t;
+
+// ---------
+// Timer API
+// ---------
+
+// Start the timer
+static inline void prof_timer_start(prof_timer_t *x)
+{
+    x->__start_time = fpga_timer_now();
+}
+
+static inline void prof_timer_start_crit(prof_timer_t *x)
+{
+    if (x->is_enabled) {
+        x->__primask = util_critical_section_enter();
+    }
+
+    prof_timer_start(x);
+}
+
+// Stop the timer and calculate the running statistics
+void __prof_timer_stop(prof_timer_t *x, uint32_t now);
+void __prof_timer_stop_crit(prof_timer_t *x, uint32_t now);
+
+// To remove as much function call and logical overhead as possible,
+// measure now before __prof_timer_stop() is called.
+#define prof_timer_stop(x)      __prof_timer_stop(x, fpga_timer_now())
+#define prof_timer_stop_crit(x) __prof_timer_stop_crit(x, fpga_timer_now())
+
+/** Reset the timer statistics. */
+void prof_timer_reset(prof_timer_t *x);
+
+// ------------------------------
+// Linked List / Registration API
+// ------------------------------
+
+// Register the Profiling Timer with the internal linked list
+void prof_timer_register(prof_timer_t *x);
+
+// Unregister the Profiling Timer with the internal linked list
+void prof_timer_unregister(prof_timer_t *x);
+
+// Get the number of registered profile timers.
+size_t prof_timer_num_registered(void);
+
+// -------------
+// Iteration API
+// -------------
+
+/**
+ * Iterate through all registered timers:
+ *
+ * Usage:
+ *   prof_timer_t *current = NULL;
+ *   while (prof_timer_iterate(&current)) {
+ *     // DO stuff.
+ *   }
+ */
+bool prof_timer_iterate(prof_timer_t **current);
+
+/**
+ * FOR_ALL_PROF_TIMERS implements a safe use case of prof_timer_iterate() which
+ * scopes `var` within it. This iterates through all elements in the Profiling Timer List.
+ */
+#define FOR_ALL_PROF_TIMERS(var) for (prof_timer_t *var = NULL; prof_timer_iterate(&var);)
+
+void prof_timer_reset_all(void);
+
+#endif // PROF_TIMER_H

sdk/bare/common/sys/util.c

@@ -1 +1,19 @@
 #include "sys/util.h"
+#include "xil_exception.h"
+#include <stdint.h>
+
+uint32_t util_critical_section_enter(void)
+{
+    // This Xilinx driver only disables the IRQ exceptions which is fine for us.
+    Xil_ExceptionDisable();
+
+    // Return a garbage primask... This isn't used by us!
+    return 0;
+}
+
+void util_critical_section_exit(uint32_t primask)
+{
+    // TODO(NP): We are ignoring the mask!!! Just use the Xilinx driver
+    //           to return to the "normal" exception state.
+    Xil_ExceptionEnable();
+}

sdk/bare/common/sys/util.h

@@ -1,11 +1,16 @@
 #ifndef UTIL_H
 #define UTIL_H
 
+#include <stdint.h>
+
 #define MIN(x, y) (((x) > (y)) ? (y) : (x))
 #define MAX(x, y) (((x) > (y)) ? (x) : (y))
 
 #define ARRAY_SIZE(a) (sizeof(a) / sizeof(a[0]))
 
 #define STR_EQ(str1, str2) (strcmp(str1, str2) == 0)
 
+uint32_t util_critical_section_enter(void);
+void util_critical_section_exit(uint32_t primask);
+
 #endif // UTIL_H

sdk/bare/user/usr/blink/cmd/cmd_blink.c

@@ -20,7 +20,8 @@ static command_help_t cmd_help[] = {
     { "deinit", "Stop task" },
     { "stats print", "Print stats" },
     { "stats reset", "Reset stats" },
-
+    { "expen run<1|2|3> <N>", "Run an expensive operation N times" },
+    { "expen stats <N>", "Print stats for expensive operation" },
 };
 
 void cmd_blink_register(void)
@@ -120,6 +121,52 @@ int cmd_blink(int argc, char **argv)
         }
     }
 
+    if (argc >= 2 && strcmp("expen", argv[1]) == 0) {
+        if (argc == 4 && strcmp("run1", argv[2]) == 0) {
+            int N = atoi(argv[3]);
+
+            if (N < 0 || N > 1000) {
+                return CMD_INVALID_ARGUMENTS;
+            }
+
+            task_blink_expensive_run1(N);
+            return SUCCESS;
+        }
+
+        if (argc == 4 && strcmp("run2", argv[2]) == 0) {
+            int N = atoi(argv[3]);
+
+            if (N < 0 || N > 1000) {
+                return CMD_INVALID_ARGUMENTS;
+            }
+
+            task_blink_expensive_run2(N);
+            return SUCCESS;
+        }
+
+        if (argc == 4 && strcmp("run3", argv[2]) == 0) {
+            int N = atoi(argv[3]);
+
+            if (N < 0 || N > 1000) {
+                return CMD_INVALID_ARGUMENTS;
+            }
+
+            task_blink_expensive_run3(N);
+            return SUCCESS;
+        }
+
+        if (argc == 4 && strcmp("stats", argv[2]) == 0) {
+            int N = atoi(argv[3]);
+
+            if (N < 1 || N > 3) {
+                return CMD_INVALID_ARGUMENTS;
+            }
+
+            task_blink_expensive_stats(N);
+            return SUCCESS;
+        }
+    }
+
     // At any point, if an error is detected in given input command,
     // simply return an error code (defined in sys/defines.h)
     //