[ovs-dev] [PATCH] backtrace: add LOG_BACKTRACE()

[Andy Zhou]

LOG_BACKTRACE() logs the back trace into the log file. I find it
to be helpful when debugging unit tests. "backtrace.h" documents
the usage. It is not being called directly in the code, but rather as
a handy tool available when needed.

Signed-off-by: Andy Zhou <azhou at nicira.com>
---
 lib/backtrace.c |   30 ++++++++++++++++++++++++++++++
 lib/backtrace.h |   46 ++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 76 insertions(+)

diff --git a/lib/backtrace.c b/lib/backtrace.c
index 861a109..c606357 100644
--- a/lib/backtrace.c
+++ b/lib/backtrace.c
@@ -17,6 +17,10 @@
 #include <config.h>
 
 #include "backtrace.h"
+#include "inttypes.h"
+#include "vlog.h"
+
+VLOG_DEFINE_THIS_MODULE(backtrace);
 
 #ifdef HAVE_BACKTRACE
 #include <execinfo.h>
@@ -31,6 +35,7 @@ backtrace_capture(struct backtrace *b)
         b->frames[i] = (uintptr_t) frames[i];
     }
 }
+
 #else
 void
 backtrace_capture(struct backtrace *backtrace)
@@ -38,3 +43,28 @@ backtrace_capture(struct backtrace *backtrace)
     backtrace->n_frames = 0;
 }
 #endif
+
+char *
+backtrace_format(const struct backtrace *b, struct ds *ds)
+{
+    if (b->n_frames) {
+        int i;
+
+        ds_put_cstr(ds, " (backtrace:");
+        for (i = 0; i < b->n_frames; i++) {
+            ds_put_format(ds, " 0x%08"PRIxPTR, b->frames[i]);
+        }
+        ds_put_cstr(ds, ")");
+    }
+
+    return ds_cstr(ds);
+}
+
+void
+log_backtrace(const char *file, int line, const struct backtrace *b)
+{
+    struct ds ds = DS_EMPTY_INITIALIZER;
+    ds_put_format(&ds, "%s:%d:", file, line);
+    VLOG_ERR("%s", backtrace_format(b, &ds));
+    ds_destroy(&ds);
+}
diff --git a/lib/backtrace.h b/lib/backtrace.h
index cee0602..e9dc5ec 100644
--- a/lib/backtrace.h
+++ b/lib/backtrace.h
@@ -18,6 +18,50 @@
 #define BACKTRACE_H 1
 
 #include <stdint.h>
+#include "dynamic-string.h"
+
+/* LOG_BACKTRACE() will save the backtrace of a running program
+ * into the log at the DEBUG level.
+ *
+ * To use it, insert the following code to where backtrace is
+ * desired:
+ *       #include "backtrace.h"
+ *
+ *       LOG_BACKTRACE();
+ *
+ * A typical log will look like the following. The hex numbers listed after
+ * "backtrace" are the addresses of the backtrace.
+ *
+ * 2014-03-13T23:18:11.979Z|00002|backtrace(revalidator_6)|ERR|lib/dpif-netdev.c:1312: (backtrace: 0x00521f57 0x00460365 0x00463ea4 0x0046470b 0x0043b32d 0x0043bac3 0x0043bae2 0x0043943b 0x004c22b3 0x2b5b3ac94e9a 0x2b5b3b4a33fd)
+ *
+ * The following bash command can be used to  view backtrace in
+ * a more readable form.
+ * addr2line -p -e vswitchd/ovs-vswitchd <cut-and-paste back traces>
+ *
+ * An typical run and output will look like:
+ * addr2line -p -e vswitchd/ovs-vswitchd  0x00521f57 0x00460365 0x00463ea4
+ * 0x0046470b 0x0043b32d 0x0043bac3 0x0043bae2 0x0043943b 0x004c22b3
+ * 0x2b5b3ac94e9a 0x2b5b3b4a33fd
+ *
+ * openvswitch/lib/backtrace.c:33
+ * openvswitch/lib/dpif-netdev.c:1312
+ * openvswitch/lib/dpif.c:937
+ * openvswitch/lib/dpif.c:1258
+ * openvswitch/ofproto/ofproto-dpif-upcall.c:1440
+ * openvswitch/ofproto/ofproto-dpif-upcall.c:1595
+ * openvswitch/ofproto/ofproto-dpif-upcall.c:160
+ * openvswitch/ofproto/ofproto-dpif-upcall.c:717
+ * openvswitch/lib/ovs-thread.c:268
+ * ??:0
+ * ??:0
+ */
+
+#define LOG_BACKTRACE() \
+    { \
+        struct backtrace b; \
+        backtrace_capture(&b); \
+        log_backtrace(__FILE__, __LINE__, &b); \
+    } \
 
 #define BACKTRACE_MAX_FRAMES 31
 
@@ -27,5 +71,7 @@ struct backtrace {
 };
 
 void backtrace_capture(struct backtrace *);
+char *backtrace_format(const struct backtrace *b, struct ds *ds);
+void log_backtrace(const char *file, const int line, const struct backtrace *);
 
 #endif /* backtrace.h */
-- 
1.7.9.5