[tor-commits] [tor/master] trace: Add a basic event-tracing infrastructure.
nickm at torproject.org
nickm at torproject.org
Tue Apr 25 14:43:30 UTC 2017
commit cb8ac1f33102dbe509edf50aa3cac2a106241466
Author: David Goulet <dgoulet at torproject.org>
Date: Mon Jan 23 14:28:10 2017 -0500
trace: Add a basic event-tracing infrastructure.
This commit adds the src/trace directory containing the basics for our tracing
subsystem. It is not used in the code base. The "src/trace/debug.h" file
contains an example on how we can map our tor trace events to log_debug().
The tracing subsystem can only be enabled by tracing framework at compile
time. This commit introduces the "--enable-tracing-debug" option that will
make all "tor_trace()" function be maped to "log_debug()".
Closes #13802
Signed-off-by: David Goulet <dgoulet at torproject.org>
---
.gitignore | 3 ++
changes/ticket13802 | 5 +++
configure.ac | 10 ++++++
doc/HACKING/Tracing.md | 90 ++++++++++++++++++++++++++++++++++++++++++++++++++
src/include.am | 1 +
src/or/include.am | 1 +
src/test/include.am | 5 +++
src/trace/debug.h | 25 ++++++++++++++
src/trace/events.h | 45 +++++++++++++++++++++++++
src/trace/include.am | 20 +++++++++++
10 files changed, 205 insertions(+)
diff --git a/.gitignore b/.gitignore
index f8d6e13..68bad5f 100644
--- a/.gitignore
+++ b/.gitignore
@@ -125,6 +125,9 @@ uptime-*.json
/src/Makefile
/src/Makefile.in
+# /src/trace
+/src/trace/libor-trace.a
+
# /src/common/
/src/common/Makefile
/src/common/Makefile.in
diff --git a/changes/ticket13802 b/changes/ticket13802
new file mode 100644
index 0000000..581d5bd
--- /dev/null
+++ b/changes/ticket13802
@@ -0,0 +1,5 @@
+ o Minor features (testing):
+ - Add general tracing instrumentation to Tor. For now, this subsystem is
+ not being used by any part of the code, it is for future use or external
+ testing that is not part of the upstream code base. Any tracing
+ framework needs to be enabled at compile time. Closes #13802.
diff --git a/configure.ac b/configure.ac
index c7960fa..ff91735 100644
--- a/configure.ac
+++ b/configure.ac
@@ -189,6 +189,16 @@ AC_ARG_ENABLE(seccomp,
AC_ARG_ENABLE(libscrypt,
AS_HELP_STRING(--disable-libscrypt, [do not attempt to use libscrypt]))
+dnl Enable event tracing which are transformed to debug log statement.
+AC_ARG_ENABLE(event-tracing-debug,
+ AS_HELP_STRING(--enable-event-tracing-debug, [build with event tracing to debug log]))
+AM_CONDITIONAL([USE_EVENT_TRACING_DEBUG], [test "x$enable_event_tracing_debug" = "xyes"])
+
+if test x$enable_event_tracing_debug = xyes; then
+ AC_DEFINE([USE_EVENT_TRACING_DEBUG], [1], [Tracing framework to log debug])
+ AC_DEFINE([TOR_EVENT_TRACING_ENABLED], [1], [Compile the event tracing instrumentation])
+fi
+
dnl check for the correct "ar" when cross-compiling.
dnl (AM_PROG_AR was new in automake 1.11.2, which we do not yet require,
dnl so kludge up a replacement for the case where it isn't there yet.)
diff --git a/doc/HACKING/Tracing.md b/doc/HACKING/Tracing.md
new file mode 100644
index 0000000..f4a55b7
--- /dev/null
+++ b/doc/HACKING/Tracing.md
@@ -0,0 +1,90 @@
+# Tracing #
+
+This document describes how the tracing subsystem works in tor so developers
+can add events to the code base but also hook them to a tracing framework.
+
+## Basics ###
+
+Tracing is seperated in two concepts, trace events and a tracer. The tracing
+subsystem can be found in `src/trace`. The `events.h` header file is the
+main file that maps the different tracers to trace events.
+
+### Events ###
+
+A trace event is basically a function from which we can pass any data that
+we want to collect. In addition, we specify a context for the event such as
+a subsystem and an event name.
+
+A trace event in tor has the following standard format:
+
+ tor_trace(subsystem, event\_name, args...)
+
+The `subsystem` parameter is the name of the subsytem the trace event is in.
+For example that could be "scheduler" or "vote" or "hs". The idea is to add
+some context to the event so when we collect them we know where it's coming
+from. The `event_name` is the name of the event which helps a lot with
+adding some semantic to the event. Finally, `args` is any number of
+arguments we want to collect.
+
+Here is an example of a possible tracepoint in main():
+
+ tor_trace(main, init_phase, argc)
+
+The above is a tracepoint in the `main` subsystem with `init_phase` as the
+event name and the `int argc` is passed to the event as well.
+
+How `argc` is collected or used has nothing to do with the instrumentation
+(adding trace events to the code). It is the work of the tracer so this is why
+the trace events and collection framework (tracer) are decoupled. You _can_
+have trace events without a tracer.
+
+### Tracer ###
+
+In `src/trace/events.h`, we map the `tor_trace()` function to the right
+tracer. A tracer support is only enabled at compile time. For instance, the
+file `src/trace/debug.h` contains the mapping of the generic tracing function
+`tor_trace()` to the `log_debug()` function. More specialized function can be
+mapped depending on the tracepoint.
+
+## Build System ##
+
+This section describes how it is integrated into the build system of tor.
+
+By default, every tracing events are disabled in tor that is `tor_trace()`
+is a NOP.
+
+To enable a tracer, there is a configure option on the form of:
+
+ --enable-tracing-<tracer>
+
+We have an option that will send every trace events to a `log_debug()` (as
+mentionned above) which will print you the subsystem and name of the event but
+not the arguments for technical reasons. This is useful if you want to quickly
+see if your trace event is being hit or well written. To do so, use this
+configure option:
+
+ --enable-tracing-debug
+
+## Instrument Tor ##
+
+This is pretty easy. Let's say you want to add a trace event in
+`src/or/rendcache.c`, you only have to add this include statement:
+
+ #include "trace/events.h"
+
+Once done, you can add as many as you want `tor_trace()` that you need.
+Please use the right subsystem (here it would be `hs`) and a unique name that
+tells what the event is for. For example:
+
+ tor_trace(hs, store_desc_as_client, desc, desc_id);
+
+If you look in `src/trace/events.h`, you'll see that if tracing is enabled it
+will be mapped to a function called:
+
+ tor_trace_hs_store_desc_as_client(desc, desc_id)
+
+And the point of all this is for that function to be defined in a new file
+that you might want to add named `src/trace/hs.{c|h}` which would defined how
+to collect the data for the `tor_trace_hs_store_desc_as_client()` function
+like for instance sending it to a `log_debug()` or do more complex operations
+or use a userspace tracer like LTTng (https://lttng.org).
diff --git a/src/include.am b/src/include.am
index d12684e..f78853f 100644
--- a/src/include.am
+++ b/src/include.am
@@ -7,3 +7,4 @@ include src/tools/include.am
include src/win32/include.am
include src/config/include.am
include src/test/fuzz/include.am
+include src/trace/include.am
diff --git a/src/or/include.am b/src/or/include.am
index 483ea2f..4c24dd2 100644
--- a/src/or/include.am
+++ b/src/or/include.am
@@ -120,6 +120,7 @@ src_or_tor_LDFLAGS = @TOR_LDFLAGS_zlib@ @TOR_LDFLAGS_openssl@ @TOR_LDFLAGS_libev
src_or_tor_LDADD = src/or/libtor.a src/common/libor.a src/common/libor-ctime.a \
src/common/libor-crypto.a $(LIBKECCAK_TINY) $(LIBDONNA) \
src/common/libor-event.a src/trunnel/libor-trunnel.a \
+ src/trace/libor-trace.a \
@TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ @TOR_LIBEVENT_LIBS@ @TOR_OPENSSL_LIBS@ \
@TOR_LIB_WS32@ @TOR_LIB_GDI@ @CURVE25519_LIBS@ @TOR_SYSTEMD_LIBS@ \
@TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@
diff --git a/src/test/include.am b/src/test/include.am
index 653adad..230a6c8 100644
--- a/src/test/include.am
+++ b/src/test/include.am
@@ -193,6 +193,7 @@ src_test_test_LDADD = src/or/libtor-testing.a \
src/common/libor-ctime-testing.a \
src/common/libor-event-testing.a \
src/trunnel/libor-trunnel-testing.a \
+ src/trace/libor-trace.a \
@TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ @TOR_LIBEVENT_LIBS@ \
@TOR_OPENSSL_LIBS@ @TOR_LIB_WS32@ @TOR_LIB_GDI@ @CURVE25519_LIBS@ \
@TOR_SYSTEMD_LIBS@ @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@
@@ -216,6 +217,7 @@ src_test_bench_LDADD = src/or/libtor.a src/common/libor.a \
src/common/libor-ctime.a \
src/common/libor-crypto.a $(LIBKECCAK_TINY) $(LIBDONNA) \
src/common/libor-event.a src/trunnel/libor-trunnel.a \
+ src/trace/libor-trace.a \
@TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ @TOR_LIBEVENT_LIBS@ \
@TOR_OPENSSL_LIBS@ @TOR_LIB_WS32@ @TOR_LIB_GDI@ @CURVE25519_LIBS@ \
@TOR_SYSTEMD_LIBS@ @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@
@@ -227,6 +229,7 @@ src_test_test_workqueue_LDADD = src/or/libtor-testing.a \
src/common/libor-ctime-testing.a \
src/common/libor-crypto-testing.a $(LIBKECCAK_TINY) $(LIBDONNA) \
src/common/libor-event-testing.a \
+ src/trace/libor-trace.a \
@TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ @TOR_LIBEVENT_LIBS@ \
@TOR_OPENSSL_LIBS@ @TOR_LIB_WS32@ @TOR_LIB_GDI@ @CURVE25519_LIBS@ \
@TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@
@@ -264,6 +267,7 @@ src_test_test_ntor_cl_LDFLAGS = @TOR_LDFLAGS_zlib@ @TOR_LDFLAGS_openssl@
src_test_test_ntor_cl_LDADD = src/or/libtor.a src/common/libor.a \
src/common/libor-ctime.a \
src/common/libor-crypto.a $(LIBKECCAK_TINY) $(LIBDONNA) \
+ src/trace/libor-trace.a \
@TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ \
@TOR_OPENSSL_LIBS@ @TOR_LIB_WS32@ @TOR_LIB_GDI@ @CURVE25519_LIBS@ \
@TOR_LZMA_LIBS@
@@ -285,6 +289,7 @@ noinst_PROGRAMS += src/test/test-bt-cl
src_test_test_bt_cl_SOURCES = src/test/test_bt_cl.c
src_test_test_bt_cl_LDADD = src/common/libor-testing.a \
src/common/libor-ctime-testing.a \
+ src/trace/libor-trace.a \
@TOR_LIB_MATH@ \
@TOR_LIB_WS32@ @TOR_LIB_GDI@
src_test_test_bt_cl_CFLAGS = $(AM_CFLAGS) $(TEST_CFLAGS)
diff --git a/src/trace/debug.h b/src/trace/debug.h
new file mode 100644
index 0000000..3a16525
--- /dev/null
+++ b/src/trace/debug.h
@@ -0,0 +1,25 @@
+/* Copyright (c) 2017, The Tor Project, Inc. */
+/* See LICENSE for licensing information */
+
+#ifndef TOR_TRACE_LOG_DEBUG_H
+#define TOR_TRACE_LOG_DEBUG_H
+
+#include "torlog.h"
+
+/* Stringify pre-processor trick. */
+#define XSTR(d) STR(d)
+#define STR(s) #s
+
+/* Send every event to a debug log level. This is useful to debug new trace
+ * events without implementing them for a specific event tracing framework.
+ * Note that the arguments are ignored since at this step we do not know the
+ * types and amount there is. */
+
+/* Example on how to map a tracepoint to log_debug(). */
+#undef tor_trace
+#define tor_trace(subsystem, name, args...) \
+ log_debug(LD_GENERAL, "Trace event \"" XSTR(name) "\" from " \
+ "\"" XSTR(subsystem) "\" hit. " \
+ "(line "XSTR(__LINE__) ")")
+
+#endif /* TOR_TRACE_LOG_DEBUG_H */
diff --git a/src/trace/events.h b/src/trace/events.h
new file mode 100644
index 0000000..1be1fd5
--- /dev/null
+++ b/src/trace/events.h
@@ -0,0 +1,45 @@
+/* Copyright (c) 2017, The Tor Project, Inc. */
+/* See LICENSE for licensing information */
+
+/**
+ * \file events.h
+ * \brief Header file for Tor event tracing.
+ **/
+
+#ifndef TOR_TRACE_EVENTS_H
+#define TOR_TRACE_EVENTS_H
+
+/*
+ * The following defines a generic event tracing function name that has to be
+ * used to trace events in the code base.
+ *
+ * That generic function is then defined by a event tracing framework. For
+ * instance, the "log debug" framework sends all trace events to log_debug()
+ * which is defined in src/trace/debug.h which can only be enabled at compile
+ * time (--enable-event-tracing-debug).
+ *
+ * By default, every trace events in the code base are replaced by a NOP. See
+ * doc/HACKING/Tracing.md for more information on how to use event tracing or
+ * add events.
+ */
+
+#ifdef TOR_EVENT_TRACING_ENABLED
+/* Map every trace event to a per subsystem macro. */
+#define tor_trace(subsystem, name, ...) \
+ tor_trace_##subsystem(name, __VA_ARGS__)
+
+/* Enable event tracing for the debug framework where all trace events are
+ * mapped to a log_debug(). */
+#ifdef USE_EVENT_TRACING_DEBUG
+#include "trace/debug.h"
+#endif
+
+#else /* TOR_EVENT_TRACING_ENABLED */
+
+/* Reaching this point, we NOP every event declaration because event tracing
+ * is not been enabled at compile time. */
+#define tor_trace(subsystem, name, args...)
+
+#endif /* TOR_EVENT_TRACING_ENABLED */
+
+#endif /* TOR_TRACE_EVENTS_H */
diff --git a/src/trace/include.am b/src/trace/include.am
new file mode 100644
index 0000000..f7de1fb
--- /dev/null
+++ b/src/trace/include.am
@@ -0,0 +1,20 @@
+# Include the src/ so we can use the trace/events.h statement when including
+# any file in that directory.
+AM_CPPFLAGS += -I$(srcdir)/src
+
+noinst_LIBRARIES += \
+ src/trace/libor-trace.a
+LIBOR_TRACE_A_SOURCES =
+
+TRACEHEADERS = \
+ src/trace/events.h
+
+if USE_EVENT_TRACING_DEBUG
+TRACEHEADERS += \
+ src/trace/debug.h
+endif
+
+# Library source files.
+src_trace_libor_trace_a_SOURCES = $(LIBOR_TRACE_A_SOURCES)
+
+noinst_HEADERS+= $(TRACEHEADERS)
More information about the tor-commits
mailing list