trace-linker: Add Trace Buffering support.

Trace buffering traces into a static buffer complete with timestamp
and the executing context.

A shell command provides access to the data.

3 files changed, 249 insertions, 23 deletions

diff --git a/linkers/rtems-tld.cpp b/linkers/rtems-tld.cpp
index 5638317..3582a27 100644
--- a/linkers/rtems-tld.cpp
+++ b/linkers/rtems-tld.cpp
@@ -175,12 +175,13 @@ namespace rld
       std::string  lock_acquire;    /**< The lock acquire if provided. */
       std::string  lock_release;    /**< The lock release if provided. */
       std::string  buffer_local;    /**< Code template to declare a local buffer variable. */
-      std::string  buffer_alloc;    /**< Code template to perform a buffer allocation. */
       rld::strings headers;         /**< Include statements. */
       rld::strings defines;         /**< Define statements. */
       std::string  entry_trace;     /**< Code template to trace the function entry. */
+      std::string  entry_alloc;     /**< Code template to perform a buffer allocation. */
       std::string  arg_trace;       /**< Code template to trace an argument. */
       std::string  exit_trace;      /**< Code template to trace the function exit. */
+      std::string  exit_alloc;      /**< Code template to perform a buffer allocation. */
       std::string  ret_trace;       /**< Code template to trace the return value. */
       rld::strings code;            /**< Code block inserted before the trace code. */
 
@@ -645,14 +646,16 @@ namespace rld
         lock_release = rld::dequote (section.get_record_item ("lock-release"));
       if (section.has_record ("buffer-local"))
         buffer_local = rld::dequote (section.get_record_item ("buffer-local"));
-      if (section.has_record ("buffer-local"))
-        buffer_alloc = rld::dequote (section.get_record_item ("buffer-alloc"));
       if (section.has_record ("entry-trace"))
         entry_trace = rld::dequote (section.get_record_item ("entry-trace"));
+      if (section.has_record ("entry-alloc"))
+        entry_alloc = rld::dequote (section.get_record_item ("entry-alloc"));
       if (section.has_record ("arg-trace"))
         arg_trace = rld::dequote (section.get_record_item ("arg-trace"));
       if (section.has_record ("exit-trace"))
         exit_trace = rld::dequote (section.get_record_item ("exit-trace"));
+      if (section.has_record ("exit-alloc"))
+        exit_alloc = rld::dequote (section.get_record_item ("exit-alloc"));
       if (section.has_record ("ret-trace"))
         ret_trace = rld::dequote (section.get_record_item ("ret-trace"));
     }
@@ -954,7 +957,8 @@ namespace rld
       c.write_line (" */");
 
       std::stringstream sss;
-      sss << "const char const* __rld_trace_names[" << traces.size() << "] = " << std::endl
+      sss << "uint32_t __rtld_trace_names_size = " << traces.size() << ";" << std::endl
+          << "const char const* __rtld_trace_names[" << traces.size() << "] = " << std::endl
           << "{";
       c.write_line (sss.str ());
 
@@ -1075,37 +1079,60 @@ namespace rld
             std::stringstream lss;
             lss << count;
 
-            std::string l;
-
             c.write_line("");
 
             if (sig.has_args () || (sig.has_ret () && !generator_.ret_trace.empty ()))
             {
-              bool added = false;
-              l = "#define FUNC_DATA_SIZE_" + sig.name + " (";
+              std::string ds;
+              std::string des;
+              std::string drs;
+              bool        ds_added = false;
+              bool        des_added = false;
+              bool        drs_added = false;
+              ds  = "#define FUNC_DATA_SIZE_" + sig.name + " (";
+              des = "#define FUNC_DATA_ENTRY_SIZE_" + sig.name + " (";
+              drs = "#define FUNC_DATA_RET_SIZE_" + sig.name + " (";
               if (sig.has_args ())
               {
                 for (size_t a = 0; a < sig.args.size (); ++a)
                 {
-                  if (added)
-                    l += " + ";
+                  if (ds_added)
+                    ds += " + ";
                   else
-                    added = true;
-                  l += "sizeof(" + sig.args[a] + ')';
+                    ds_added = true;
+                  if (des_added)
+                    des += " + ";
+                  else
+                    des_added = true;
+                  ds += "sizeof(" + sig.args[a] + ')';
+                  des += "sizeof(" + sig.args[a] + ')';
                 }
               }
               if (sig.has_ret () && !generator_.ret_trace.empty ())
               {
-                if (added)
-                  l += " + ";
+                if (ds_added)
+                  ds += " + ";
+                else
+                  ds_added = true;
+                if (drs_added)
+                  drs += " + ";
                 else
-                  added = true;
-                l += "sizeof(" + sig.ret + ')';
+                  drs_added = true;
+                ds += "sizeof(" + sig.ret + ')';
+                drs += "sizeof(" + sig.ret + ')';
               }
-              if (!added)
-                l += '0';
-              l += ')';
-              c.write_line(l);
+              if (!ds_added)
+                ds += '0';
+              ds += ')';
+              if (!des_added)
+                des += '0';
+              des += ')';
+              if (!drs_added)
+                drs += '0';
+              drs += ')';
+              c.write_line(ds);
+              c.write_line(des);
+              c.write_line(drs);
             }
 
             c.write_line(sig.decl () + ";");
@@ -1122,16 +1149,20 @@ namespace rld
             if (sig.has_ret ())
               c.write_line(" " + sig.ret + " ret;");
 
+            std::string l;
+
             if (!generator_.lock_acquire.empty ())
               c.write_line(generator_.lock_acquire);
 
-            if (!generator_.buffer_alloc.empty ())
+            if (!generator_.entry_alloc.empty ())
             {
-              l = " " + generator_.buffer_alloc;
+              l = " " + generator_.entry_alloc;
               l = rld::find_replace (l, "@FUNC_NAME@", '"' + sig.name + '"');
               l = rld::find_replace (l, "@FUNC_INDEX@", lss.str ());
               l = rld::find_replace (l, "@FUNC_LABEL@", sig.name);
               l = rld::find_replace (l, "@FUNC_DATA_SIZE@", "FUNC_DATA_SIZE_" + sig.name);
+              l = rld::find_replace (l, "@FUNC_DATA_ENTRY_SIZE@", "FUNC_DATA_ENTRY_SIZE_" + sig.name);
+              l = rld::find_replace (l, "@FUNC_DATA_RET_SIZE@", "FUNC_DATA_RET_SIZE_" + sig.name);
               c.write_line(l);
             }
 
@@ -1145,6 +1176,8 @@ namespace rld
               l = rld::find_replace (l, "@FUNC_INDEX@", lss.str ());
               l = rld::find_replace (l, "@FUNC_LABEL@", sig.name);
               l = rld::find_replace (l, "@FUNC_DATA_SIZE@", "FUNC_DATA_SIZE_" + sig.name);
+              l = rld::find_replace (l, "@FUNC_DATA_ENTRY_SIZE@", "FUNC_DATA_ENTRY_SIZE_" + sig.name);
+              l = rld::find_replace (l, "@FUNC_DATA_RET_SIZE@", "FUNC_DATA_RET_SIZE_" + sig.name);
               c.write_line(l);
             }
 
@@ -1180,12 +1213,32 @@ namespace rld
             l += ");";
             c.write_line(l);
 
+            if (!generator_.lock_acquire.empty ())
+              c.write_line(generator_.lock_acquire);
+
+            if (!generator_.exit_alloc.empty ())
+            {
+              l = " " + generator_.exit_alloc;
+              l = rld::find_replace (l, "@FUNC_NAME@", '"' + sig.name + '"');
+              l = rld::find_replace (l, "@FUNC_INDEX@", lss.str ());
+              l = rld::find_replace (l, "@FUNC_LABEL@", sig.name);
+              l = rld::find_replace (l, "@FUNC_DATA_SIZE@", "FUNC_DATA_SIZE_" + sig.name);
+              l = rld::find_replace (l, "@FUNC_DATA_ENTRY_SIZE@", "FUNC_DATA_ENTRY_SIZE_" + sig.name);
+              l = rld::find_replace (l, "@FUNC_DATA_RET_SIZE@", "FUNC_DATA_RET_SIZE_" + sig.name);
+              c.write_line(l);
+            }
+
+            if (!generator_.lock_release.empty ())
+              c.write_line(generator_.lock_release);
+
             if (!generator_.exit_trace.empty ())
             {
               l = " " + generator_.exit_trace;
               l = rld::find_replace (l, "@FUNC_NAME@", '"' + sig.name + '"');
               l = rld::find_replace (l, "@FUNC_INDEX@", lss.str ());
               l = rld::find_replace (l, "@FUNC_LABEL@", sig.name);
+              l = rld::find_replace (l, "@FUNC_DATA_ENTRY_SIZE@", "FUNC_DATA_ENTRY_SIZE_" + sig.name);
+              l = rld::find_replace (l, "@FUNC_DATA_RET_SIZE@", "FUNC_DATA_RET_SIZE_" + sig.name);
               c.write_line(l);
             }
 
@@ -1220,7 +1273,8 @@ namespace rld
 
       std::stringstream ss;
 
-      ss << "const uint32_t __rtld_trace_" << label << "[" << bitmap_size << "] = " << std::endl
+      ss << "uint32_t __rtld_trace_" << label << "_size = " << traces.size() << ";" << std::endl
+         << "const uint32_t __rtld_trace_" << label << "[" << bitmap_size << "] = " << std::endl
          << "{" << std::endl;
 
       size_t   count = 0;
diff --git a/linkers/rtld-trace-buffer.ini b/linkers/rtld-trace-buffer.ini
new file mode 100644
index 0000000..f018410
--- /dev/null
+++ b/linkers/rtld-trace-buffer.ini
@@ -0,0 +1,171 @@
+;
+; RTEMS Trace Linker Trace Buffer
+;
+; Copyright 2015 Chris Johns <chrisj@rtems.org>
+;
+
+;
+; A trace buffer generator buffers records to a buffer that can be extracted
+; latter.
+;
+[trace-buffer-generator]
+headers = trace-buffer-generator-headers
+code-blocks = trace-buffer-tracers
+lock-local = " rtems_interrupt_lock_context lcontext;"
+lock-acquire = " rtems_interrupt_lock_acquire(&__rtld_tbg_lock, &lcontext);"
+lock-release = " rtems_interrupt_lock_release(&__rtld_tbg_lock, &lcontext);"
+entry-trace = "__rtld_tbg_buffer_entry(&in, @FUNC_INDEX@, RTLD_TBG_REC_OVERHEAD + @FUNC_DATA_ENTRY_SIZE@);"
+entry-alloc = "in = __rtld_tbg_buffer_alloc(@FUNC_INDEX@, RTLD_TBG_REC_OVERHEAD + @FUNC_DATA_ENTRY_SIZE@);"
+arg-trace = "__rtld_tbg_buffer_arg(&in, @ARG_SIZE@, (void*) &@ARG_LABEL@);"
+exit-trace = "__rtld_tbg_buffer_exit(&in, @FUNC_INDEX@, RTLD_TBG_REC_OVERHEAD + @FUNC_DATA_RET_SIZE@);"
+exit-alloc = "in = __rtld_tbg_buffer_alloc(@FUNC_INDEX@, RTLD_TBG_REC_OVERHEAD + @FUNC_DATA_RET_SIZE@);"
+ret-trace = "__rtld_tbg_buffer_ret(in, @RET_SIZE@, (void*) &@RET_LABEL@);"
+buffer-local = " uint8_t* in;"
+
+[trace-buffer-generator-headers]
+header = "#include <stdint.h>"
+header = "#include <rtems.h>"
+
+[trace-buffer-tracers]
+code = <<<CODE
+/*
+ * Mode bits.
+ */
+#define RTLD_TRACE_BUFFER_VERSION 0  /* data format version, lower 8bits */
+#if RTLD_TRACE_BUFFER_TIMESTAMP
+ #undef RTLD_TRACE_BUFFER_TIMESTAMP
+ #define RTLD_TRACE_BUFFER_TIMESTAMP (1 << 8)
+#else
+ #define RTLD_TRACE_BUFFER_TIMESTAMP 0
+#endif
+#if defined(RTLD_TRACE_BUFFER_THREAD)
+ #undef RTLD_TRACE_BUFFER_THREAD
+ #define RTLD_TRACE_BUFFER_THREAD    (1 << 9)
+#else
+ #define RTLD_TRACE_BUFFER_THREAD 0
+#endif
+#define RTLD_TRACE_BUFFER_MODE RTLD_TRACE_BUFFER_VERSION | \
+                               RTLD_TRACE_BUFFER_TIMESTAMP | \
+			       RTLD_TRACE_BUFFER_THREAD
+/*
+ * The number of word in the buffer.
+ */
+#define RTLD_TRACE_BUFFER_WORDS (RTLD_TRACE_BUFFER_SIZE / sizeof(uint32_t))
+/*
+ * We log the header record and then a 64bit timestamp.
+ */
+#define RTLD_TBG_REC_OVERHEAD (6 * sizeof(uint32_t))
+/*
+ * Symbols are public to allow external access to the buffers.
+ */
+const bool __rtld_tbg_present = true;
+const uint32_t __rtld_tbg_mode = RTLD_TRACE_BUFFER_MODE;
+const uint32_t __rtld_tbg_buffer_size = RTLD_TRACE_BUFFER_WORDS;
+uint32_t __rtld_tbg_buffer[RTLD_TRACE_BUFFER_WORDS];
+volatile uint32_t __rtld_tbg_buffer_in;
+volatile bool __rtld_tbg_finished;
+volatile bool __rtld_tbg_triggered;
+rtems_interrupt_lock __rtld_tbg_lock = RTEMS_INTERRUPT_LOCK_INITIALIZER("rtld-trace-buffer");
+
+static inline uint32_t __rtld_tbg_in_irq(void)
+{
+  return _ISR_Nest_level ? (1 << 31) : 0;
+}
+
+static inline uint32_t __rtld_tbg_executing_id(void)
+{
+  return _Thread_Executing->Object.id;
+}
+
+static inline uint32_t __rtld_tbg_executing_status(void)
+{
+  /* @fixme Add the current CPU for SMP. */
+  return (_Thread_Executing->current_priority << 8) | _Thread_Executing->real_priority;
+}
+
+static inline uint32_t __rtld_tbg_executing_state(void)
+{
+  return _Thread_Executing->current_state;
+}
+
+static inline bool __rtld_tbg_is_enabled(const uint32_t index)
+{
+  return (__rtld_trace_enables[index / 32] & (1 << (index & (32 - 1)))) != 0 ? true : false;
+}
+
+static inline bool __rtld_tbg_has_triggered(const uint32_t index)
+{
+  if (!__rtld_tbg_triggered)
+    __rtld_tbg_triggered =
+        (__rtld_trace_triggers[index / 32] & (1 << (index & (32 - 1)))) != 0 ? true : false;
+  return __rtld_tbg_triggered;
+}
+
+static inline uint8_t* __rtld_tbg_buffer_alloc(const uint32_t index, const uint32_t size)
+{
+  uint8_t* in = NULL;
+  if (!__rtld_tbg_finished && __rtld_tbg_has_triggered(index) && __rtld_tbg_is_enabled(index))
+  {
+    const uint32_t slots = ((size - 1) / sizeof(uint32_t)) + 1;
+    if (__rtld_tbg_buffer_in >= ((RTLD_TRACE_BUFFER_WORDS - slots)))
+    {
+      __rtld_tbg_finished = true;
+    }
+    else
+    {
+      in = (uint8_t*) &__rtld_tbg_buffer[__rtld_tbg_buffer_in];
+      __rtld_tbg_buffer_in += slots;
+    }
+  }
+  return in;
+}
+
+static inline void __rtld_tbg_buffer_entry(uint8_t** in, uint32_t func_index, uint32_t size)
+{
+  if (*in)
+  {
+    uint32_t* in32 = (uint32_t*) *in;
+    uint64_t  now = rtems_clock_get_uptime_nanoseconds();
+    *in32++ = func_index | (size << 16) | __rtld_tbg_in_irq();
+    *in32++ = __rtld_tbg_executing_id();
+    *in32++ = __rtld_tbg_executing_status();
+    *in32++ = __rtld_tbg_executing_state();
+    *in32++ = now >> 32;
+    *in32 = now;
+    *in += sizeof(func_index) + (3 * sizeof(uint32_t)) + sizeof(uint64_t);
+  }
+}
+
+static inline void __rtld_tbg_buffer_arg(uint8_t** in, int arg_size, void* arg)
+{
+  if (*in)
+  {
+    memcpy(*in, arg, arg_size);
+    *in += arg_size;
+  }
+}
+
+static inline void __rtld_tbg_buffer_exit(uint8_t** in, uint32_t func_index, uint32_t size)
+{
+  if (*in)
+  {
+    uint32_t* in32 = (uint32_t*) *in;
+    uint64_t  now = rtems_clock_get_uptime_nanoseconds();
+    *in32++ = (1 << 30) | func_index | (size << 16) | __rtld_tbg_in_irq();
+    *in32++ = __rtld_tbg_executing_id();
+    *in32++ = __rtld_tbg_executing_status();
+    *in32++ = __rtld_tbg_executing_state();
+    *in32++ = now >> 32;
+    *in32 = now;
+    *in += sizeof(func_index) + (3 * sizeof(uint32_t)) + sizeof(uint64_t);
+  }
+}
+
+static inline void __rtld_tbg_buffer_ret(uint8_t* in, int ret_size, void* ret)
+{
+  if (in)
+  {
+    memcpy(in, ret, ret_size);
+  }
+}
+CODE
diff --git a/linkers/wscript b/linkers/wscript
index b1a99c6..5927b75 100644
--- a/linkers/wscript
+++ b/linkers/wscript
@@ -100,6 +100,7 @@ def build(bld):
                        'rtems-score-heap.ini',
                        'rtems-score-coremutex.ini',
                        'rtld-base.ini',
+                       'rtld-trace-buffer.ini',
                        'rtld-print.ini'])
 
     #