diff options
29 files changed, 895 insertions, 112 deletions
diff --git a/changes/ticket32910 b/changes/ticket32910 new file mode 100644 index 0000000000..e3d64d4333 --- /dev/null +++ b/changes/ticket32910 @@ -0,0 +1,5 @@ + o Major feature (tracing): + - Add a tracing library with USDT and LTTng-UST support. Few tracepoints + were added in the circuit subsystem. More will come incrementally. This + feature is compiled out by default. It needs to be enabled at configure + time. See documentation in doc/HACKING/Tracing.md. Closes ticket 32910. diff --git a/configure.ac b/configure.ac index a6df7149a0..75fd709f9b 100644 --- a/configure.ac +++ b/configure.ac @@ -256,15 +256,69 @@ 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 --- Tracing Options. --- + +TOR_TRACE_LIBS= + +dnl LTTng instrumentation option. +AC_ARG_ENABLE(tracing-instrumentation-lttng, + AS_HELP_STRING([--enable-tracing-instrumentation-lttng], + [build with LTTng-UST instrumentation])) +AM_CONDITIONAL([USE_TRACING_INSTRUMENTATION_LTTNG], + [test "x$enable_tracing_instrumentation_lttng" = "xyes"]) + +if test "x$enable_tracing_instrumentation_lttng" = "xyes"; then + AC_CHECK_HEADERS([lttng/tracepoint.h], [], + [AC_MSG_ERROR([LTTng instrumentation headers not found. + On Debian, apt install liblttng-ust-dev"])], []) + AC_DEFINE([USE_TRACING_INSTRUMENTATION_LTTNG], [1], [Using LTTng instrumentation]) + TOR_TRACE_LIBS="-llttng-ust -ldl" + have_tracing=1 +fi + +dnl USDT instrumentation option. +AC_ARG_ENABLE(tracing-instrumentation-usdt, + AS_HELP_STRING([--enable-tracing-instrumentation-usdt], + [build with tracing USDT instrumentation])) +AM_CONDITIONAL([USE_TRACING_INSTRUMENTATION_USDT], + [test "x$enable_tracing_instrumentation_usdt" = "xyes"]) + +if test "x$enable_tracing_instrumentation_usdt" = "xyes"; then + AC_CHECK_HEADERS([sys/sdt.h], [], + [AC_MSG_ERROR([USDT instrumentation requires sys/sdt.h header. + On Debian, apt install systemtap-sdt-dev])], []) + dnl LTTng generates USDT probes if the UST library was built with + dnl --with-sdt. There is unfortunately no way to check that so we always + dnl build the USDT probes even though LTTng instrumentation was requested. + AC_DEFINE([USE_TRACING_INSTRUMENTATION_USDT], [1], [Using USDT instrumentation]) + have_tracing=1 +fi + +dnl Tracepoints event to debug logs. +AC_ARG_ENABLE(tracing-instrumentation-log-debug, + AS_HELP_STRING([--enable-tracing-instrumentation-log-debug], + [build with tracing event to debug log]), + AC_DEFINE([USE_TRACING_INSTRUMENTATION_LOG_DEBUG], [1], + [Tracepoints to log debug]), []) +AM_CONDITIONAL([USE_TRACING_INSTRUMENTATION_LOG_DEBUG], + [test "x$enable_tracing_instrumentation_log_debug" = "xyes"]) +if test "x$enable_tracing_instrumentation_log_debug" = "xyes"; then + have_tracing=1 +fi + +dnl Define that tracing is supported if any instrumentation is used. +AM_COND_IF([USE_TRACING_INSTRUMENTATION_LOG_DEBUG], + AC_DEFINE([HAVE_TRACING], [1], [Compiled with tracing support])) +AM_COND_IF([USE_TRACING_INSTRUMENTATION_USDT], + AC_DEFINE([HAVE_TRACING], [1], [Compiled with tracing support])) +AM_COND_IF([USE_TRACING_INSTRUMENTATION_LTTNG], + AC_DEFINE([HAVE_TRACING], [1], [Compiled with tracing support])) +AM_CONDITIONAL([USE_TRACING], [test "x$have_tracing" = x1 ]) + +dnl Finally, define the trace libs. +AC_SUBST([TOR_TRACE_LIBS]) + +dnl -- End Tracing Options. -- dnl Enable Android only features. AC_ARG_ENABLE(android, @@ -2719,6 +2773,18 @@ test "x$enable_oss_fuzz" = "xyes" && value=1 || value=0 PPRINT_PROP_BOOL([OSS-Fuzz support (--enable-oss-fuzz)], $value) AS_ECHO +PPRINT_SUBTITLE([Tracing (--enable-tracing-instrumentation-<type>)]) + +test "x$enable_tracing_instrumentation_log_debug" = "xyes" && value=1 || value=0 +PPRINT_PROP_BOOL([Tracepoints to log_debug() (log-debug)], $value) + +test "x$enable_tracing_instrumentation_usdt" = "xyes" && value=1 || value=0 +PPRINT_PROP_BOOL([USDT Instrumentation (usdt)], $value) + +test "x$enable_tracing_instrumentation_lttng" = "xyes" && value=1 || value=0 +PPRINT_PROP_BOOL([LTTng Instrumentation (lttng)], $value) + +AS_ECHO PPRINT_SUBTITLE([Install Directories]) report_mandir="`eval eval echo $mandir`" diff --git a/doc/HACKING/Tracing.md b/doc/HACKING/Tracing.md index e1e97abe6d..d898bee172 100644 --- a/doc/HACKING/Tracing.md +++ b/doc/HACKING/Tracing.md @@ -2,19 +2,44 @@ This document describes how the event tracing subsystem works in tor so developers can add events to the code base but also hook them to an event -tracing framework. +tracing framework (i.e. tracer). -## Basics +## WARNING ## -Event tracing is separated 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. +Tracing the tor daemon **always** generates sensitive data if used in +production (on the public network). + +It **is** ethical for researchers to use tracing for their own tor client (for +example: building paths, timings, or performance). + +It is **NOT** ethical to archive, publish or keep data containing other users' +activity such as relay data or anything that handles users' traffic. This +of course includes any logs below notice level. + +Publishing analysis of tracing data containing user traffic is **NOT** safe +either. + +In other words, tracing data that contains other users's activity is **NOT** +safe to publish in any form. + +## Basics ### + +Tracing is separated in two different concepts. The tracing API and the +tracing probes. + +The API is in `src/lib/trace/` which defines how to call tracepoints in the +tor code. Every C files should include `src/lib/trace/events.h" if they want +to call a tracepoint. + +The probes are what actually record the tracepoint data. Because they often +need to access specific subsystem objects, the probes are within each +subsystem. They are defined in the `trace-probes-<subsystem>.c` files. ### 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 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 the +subsystem and an event name. A trace event in tor has the following standard format: @@ -23,69 +48,106 @@ A trace event in tor has the following standard format: 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. +from. + +The `event\_name` is the name of the event which adds better semantic to the +event. + +The `args` can be 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. +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 one argument. 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 +### Instrumentation ### + +In `src/lib/trace/events.h`, we map the high level `tor\_trace()` macro to one +or many enabled instrumentation. + +Currently, we have 3 types of possible instrumentation: -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. +1. Debug + + This will map every tracepoint to `log\_debug()`. However, none of the + arguments will be passed on because we don't know their type nor the string + format of the debug log. The output is standardized like this: + + [debug] __FUNC__: Tracepoint <event_name> from subsystem <subsystem> hit. + +2. USDT + + User Statically-Defined Tracing (USDT) is a kind of probe which can be + handled by a variety of tracers such as SystemTap, DTrace, perf, eBPF and + ftrace. + + For each tracer, one will need to define the ABI in order for the tracer to + be able to extract the data from the tracepoint objects. For instance, the + tracer needs to know how to print the circuit state of a `circuit\_t` + object. + +3. LTTng-UST + + LTTng Userspace is a tracer that has it own type of instrumentation. The + probe definitions are created within the C code and is strongly typed. + + For more information, see https://lttng.org/docs. ## Build System -This section describes how it is integrated into the build system of tor. +This section describes how the instrumentation is integrated into the build +system of tor. + +By default, every tracing events are disabled in tor that is `tor\_trace()` is +a NOP thus has no execution cost time. -By default, every tracing events are disabled in tor that is `tor_trace()` -is a NOP. +To enable a specific instrumentation, there are configure options: -To enable a tracer, there is a configure option on the form of: +1. Debug: `--enable-tracing-instrumentation-debug` - --enable-tracing-<tracer> +2. USDT: `--enable-tracing-instrumentation-usdt` -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: +3. LTTng: `--enable-tracing-instrumentation-lttng` - --enable-tracing-debug +They can all be used together or independently. If one of them is set, +`HAVE\_TRACING` define is set. And for each instrumentation, a +`USE\_TRACING\_INSTRUMENTATION\_<type>` is set. -## Instrument Tor +## Adding a Tracepoint ## This is pretty easy. Let's say you want to add a trace event in -`src/feature/rend/rendcache.c`, you only have to add this include statement: +`src/feature/rend/rendcache.c`, you first need to include this file: - #include "trace/events.h" + #include "lib/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: +Then, the `tor\_trace()` macro can be used with the specific format detailled +before in a previous section. As an 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: +For `Debug` instrumentation, you have nothing else to do. + +For `USDT`, instrumentation, you will need to define the probes in a way the +specific tracer can understand. For instance, SystemTap requires you to define +a `tapset` for each tracepoints. + +For `LTTng`, you will need to define the probes in the +`trace-probes-<subsystem>.{c|h}` file. See the `trace-probes-circuit.{c|h}` +file as an example and https://lttng.org/docs/v2.11/#doc-instrumenting. + +## Performance ## - tor_trace_hs_store_desc_as_client(desc, desc_id) +A word about performance when a tracepoint is enabled. One of the goal of a +tracepoint (USDT, LTTng-UST, ...) is that they can be enabled or disabled. By +default, they are disabled which means the tracer will not record the data but +it has to do a check thus the cost is basically the one of a `branch`. -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). +If enabled, then the performance depends on the tracer. In the case of +LTTng-UST, the event costs around 110nsec. diff --git a/scripts/maint/practracker/exceptions.txt b/scripts/maint/practracker/exceptions.txt index 25568f03f0..87581b6c8c 100644 --- a/scripts/maint/practracker/exceptions.txt +++ b/scripts/maint/practracker/exceptions.txt @@ -324,3 +324,5 @@ problem function-size /src/tools/tor-gencert.c:parse_commandline() 111 problem function-size /src/tools/tor-resolve.c:build_socks5_resolve_request() 102 problem function-size /src/tools/tor-resolve.c:do_resolve() 171 problem function-size /src/tools/tor-resolve.c:main() 112 +problem dependency-violation /src/core/or/trace_probes_circuit.c 1 +problem dependency-violation /src/core/or/trace_probes_circuit.h 1 diff --git a/src/app/include.am b/src/app/include.am index 97d53ec0fd..3caa0bab1c 100644 --- a/src/app/include.am +++ b/src/app/include.am @@ -20,7 +20,7 @@ src_app_tor_LDADD = $(TOR_INTERNAL_LIBS) \ @TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ @TOR_LIBEVENT_LIBS@ $(TOR_LIBS_CRYPTLIB) \ @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_GDI@ @TOR_LIB_USERENV@ \ @CURVE25519_LIBS@ @TOR_SYSTEMD_LIBS@ \ - @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@ + @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@ @TOR_TRACE_LIBS@ if COVERAGE_ENABLED src_app_tor_cov_SOURCES = $(src_app_tor_SOURCES) @@ -31,5 +31,5 @@ src_app_tor_cov_LDADD = $(TOR_INTERNAL_TESTING_LIBS) \ @TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ @TOR_LIBEVENT_LIBS@ $(TOR_LIBS_CRYPTLIB) \ @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_GDI@ \ @CURVE25519_LIBS@ @TOR_SYSTEMD_LIBS@ \ - @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@ + @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@ @TOR_TRACE_LIBS@ endif diff --git a/src/app/main/main.c b/src/app/main/main.c index 7b6a665b75..4b1308ddf0 100644 --- a/src/app/main/main.c +++ b/src/app/main/main.c @@ -60,6 +60,7 @@ #include "lib/crypt_ops/crypto_rand.h" #include "lib/crypt_ops/crypto_s2k.h" #include "lib/net/resolve.h" +#include "lib/trace/trace.h" #include "lib/process/waitpid.h" #include "lib/pubsub/pubsub_build.h" @@ -604,6 +605,9 @@ tor_init(int argc, char *argv[]) rust_log_welcome_string(); #endif /* defined(HAVE_RUST) */ + /* Warn _if_ the tracing subsystem is built in. */ + tracing_log_warning(); + int init_rv = options_init_from_torrc(argc,argv); if (init_rv < 0) { log_err(LD_CONFIG,"Reading config failed--see warnings above."); diff --git a/src/app/main/subsystem_list.c b/src/app/main/subsystem_list.c index e32083537f..c6da6f4893 100644 --- a/src/app/main/subsystem_list.c +++ b/src/app/main/subsystem_list.c @@ -26,6 +26,7 @@ #include "lib/thread/thread_sys.h" #include "lib/time/time_sys.h" #include "lib/tls/tortls_sys.h" +#include "lib/trace/trace_sys.h" #include "lib/wallclock/wallclock_sys.h" #include "lib/evloop/evloop_sys.h" @@ -47,6 +48,8 @@ const subsys_fns_t *tor_subsystems[] = { &sys_logging, &sys_threads, + &sys_tracing, + &sys_time, &sys_crypto, diff --git a/src/core/or/circuitbuild.c b/src/core/or/circuitbuild.c index cef70e3e76..24543d3ac0 100644 --- a/src/core/or/circuitbuild.c +++ b/src/core/or/circuitbuild.c @@ -50,6 +50,7 @@ #include "core/or/ocirc_event.h" #include "core/or/policies.h" #include "core/or/relay.h" +#include "core/or/trace_probes_circuit.h" #include "core/or/crypt_path.h" #include "feature/client/bridges.h" #include "feature/client/circpathbias.h" @@ -71,6 +72,7 @@ #include "feature/rend/rendcommon.h" #include "feature/stats/predict_ports.h" #include "lib/crypt_ops/crypto_rand.h" +#include "lib/trace/events.h" #include "core/or/cell_st.h" #include "core/or/cpath_build_state_st.h" @@ -497,6 +499,8 @@ circuit_establish_circuit(uint8_t purpose, extend_info_t *exit_ei, int flags) circuit_mark_for_close(TO_CIRCUIT(circ), -err_reason); return NULL; } + + tor_trace(TR_SUBSYS(circuit), TR_EV(establish), circ); return circ; } @@ -979,6 +983,7 @@ circuit_send_first_onion_skin(origin_circuit_t *circ) if (circuit_deliver_create_cell(TO_CIRCUIT(circ), &cc, 0) < 0) return - END_CIRC_REASON_RESOURCELIMIT; + tor_trace(TR_SUBSYS(circuit), TR_EV(first_onion_skin), circ, circ->cpath); circ->cpath->state = CPATH_STATE_AWAITING_KEYS; circuit_set_state(TO_CIRCUIT(circ), CIRCUIT_STATE_BUILDING); @@ -1142,6 +1147,7 @@ circuit_send_intermediate_onion_skin(origin_circuit_t *circ, return 0; /* circuit is closed */ } hop->state = CPATH_STATE_AWAITING_KEYS; + tor_trace(TR_SUBSYS(circuit), TR_EV(intermediate_onion_skin), circ, hop); return 0; } diff --git a/src/core/or/circuitlist.c b/src/core/or/circuitlist.c index 28b3fa8ff0..2455aa8779 100644 --- a/src/core/or/circuitlist.c +++ b/src/core/or/circuitlist.c @@ -65,6 +65,7 @@ #include "core/or/circuitpadding.h" #include "core/or/crypt_path.h" #include "core/or/extendinfo.h" +#include "core/or/trace_probes_circuit.h" #include "core/mainloop/connection.h" #include "app/config/config.h" #include "core/or/connection_edge.h" @@ -566,6 +567,8 @@ circuit_set_state(circuit_t *circ, uint8_t state) } if (state == CIRCUIT_STATE_GUARD_WAIT || state == CIRCUIT_STATE_OPEN) tor_assert(!circ->n_chan_create_cell); + + tor_trace(TR_SUBSYS(circuit), TR_EV(change_state), circ, circ->state, state); circ->state = state; if (CIRCUIT_IS_ORIGIN(circ)) circuit_state_publish(circ); @@ -1080,6 +1083,7 @@ origin_circuit_new(void) prediction_time_remaining); } + tor_trace(TR_SUBSYS(circuit), TR_EV(new_origin), circ); return circ; } @@ -1102,6 +1106,7 @@ or_circuit_new(circid_t p_circ_id, channel_t *p_chan) init_circuit_base(TO_CIRCUIT(circ)); + tor_trace(TR_SUBSYS(circuit), TR_EV(new_or), circ); return circ; } @@ -1254,6 +1259,10 @@ circuit_free_(circuit_t *circ) /* Clear all dangling handle references. */ circuit_handles_clear(circ); + /* Tracepoint. Data within the circuit object is recorded so do this before + * the actual memory free. */ + tor_trace(TR_SUBSYS(circuit), TR_EV(free), circ); + if (should_free) { memwipe(mem, 0xAA, memlen); /* poison memory */ tor_free(mem); @@ -2282,6 +2291,7 @@ circuit_mark_for_close_, (circuit_t *circ, int reason, int line, CIRCUIT_IS_ORIGIN(circ) ? TO_ORIGIN_CIRCUIT(circ)->global_identifier : 0, file, line, orig_reason, reason); + tor_trace(TR_SUBSYS(circuit), TR_EV(mark_for_close), circ); } /** Called immediately before freeing a marked circuit <b>circ</b> from diff --git a/src/core/or/circuituse.c b/src/core/or/circuituse.c index 6ff308dae2..d2bdf77d8d 100644 --- a/src/core/or/circuituse.c +++ b/src/core/or/circuituse.c @@ -39,6 +39,7 @@ #include "core/or/connection_edge.h" #include "core/or/extendinfo.h" #include "core/or/policies.h" +#include "core/or/trace_probes_circuit.h" #include "feature/client/addressmap.h" #include "feature/client/bridges.h" #include "feature/client/circpathbias.h" @@ -63,6 +64,7 @@ #include "feature/stats/predict_ports.h" #include "lib/math/fp.h" #include "lib/time/tvdiff.h" +#include "lib/trace/events.h" #include "core/or/cpath_build_state_st.h" #include "feature/dircommon/dir_connection_st.h" @@ -838,6 +840,7 @@ circuit_expire_building(void) -1); circuit_log_path(LOG_INFO,LD_CIRC,TO_ORIGIN_CIRCUIT(victim)); + tor_trace(TR_SUBSYS(circuit), TR_EV(timeout), TO_ORIGIN_CIRCUIT(victim)); if (victim->purpose == CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT) circuit_mark_for_close(victim, END_CIRC_REASON_MEASUREMENT_EXPIRED); else @@ -1501,8 +1504,11 @@ circuit_expire_old_circuits_clientside(void) circ->purpose); /* Don't do this magic for testing circuits. Their death is governed * by circuit_expire_building */ - if (circ->purpose != CIRCUIT_PURPOSE_PATH_BIAS_TESTING) + if (circ->purpose != CIRCUIT_PURPOSE_PATH_BIAS_TESTING) { + tor_trace(TR_SUBSYS(circuit), TR_EV(idle_timeout), + TO_ORIGIN_CIRCUIT(circ)); circuit_mark_for_close(circ, END_CIRC_REASON_FINISHED); + } } else if (!circ->timestamp_dirty && circ->state == CIRCUIT_STATE_OPEN) { if (timercmp(&circ->timestamp_began, &cutoff, OP_LT)) { if (circ->purpose == CIRCUIT_PURPOSE_C_GENERAL || @@ -1521,6 +1527,8 @@ circuit_expire_old_circuits_clientside(void) " that has been unused for %ld msec.", TO_ORIGIN_CIRCUIT(circ)->global_identifier, tv_mdiff(&circ->timestamp_began, &now)); + tor_trace(TR_SUBSYS(circuit), TR_EV(idle_timeout), + TO_ORIGIN_CIRCUIT(circ)); circuit_mark_for_close(circ, END_CIRC_REASON_FINISHED); } else if (!TO_ORIGIN_CIRCUIT(circ)->is_ancient) { /* Server-side rend joined circuits can end up really old, because @@ -1683,6 +1691,7 @@ circuit_testing_failed(origin_circuit_t *circ, int at_last_hop) void circuit_has_opened(origin_circuit_t *circ) { + tor_trace(TR_SUBSYS(circuit), TR_EV(opened), circ); circuit_event_status(circ, CIRC_EVENT_BUILT, 0); /* Remember that this circuit has finished building. Now if we start @@ -2204,6 +2213,8 @@ circuit_launch_by_extend_info(uint8_t purpose, tor_fragile_assert(); return NULL; } + + tor_trace(TR_SUBSYS(circuit), TR_EV(cannibalized), circ); return circ; } } @@ -3135,6 +3146,8 @@ circuit_change_purpose(circuit_t *circ, uint8_t new_purpose) old_purpose = circ->purpose; circ->purpose = new_purpose; + tor_trace(TR_SUBSYS(circuit), TR_EV(change_purpose), circ, old_purpose, + new_purpose); if (CIRCUIT_IS_ORIGIN(circ)) { control_event_circuit_purpose_changed(TO_ORIGIN_CIRCUIT(circ), diff --git a/src/core/or/include.am b/src/core/or/include.am index af7c5a6f51..9ff92adbde 100644 --- a/src/core/or/include.am +++ b/src/core/or/include.am @@ -96,3 +96,10 @@ noinst_HEADERS += \ src/core/or/tor_version_st.h \ src/core/or/var_cell_st.h \ src/core/or/versions.h + +if USE_TRACING_INSTRUMENTATION_LTTNG +LIBTOR_APP_A_SOURCES += \ + src/core/or/trace_probes_circuit.c +noinst_HEADERS += \ + src/core/or/trace_probes_circuit.h +endif diff --git a/src/core/or/lttng_circuit.inc b/src/core/or/lttng_circuit.inc new file mode 100644 index 0000000000..fc3e175c8a --- /dev/null +++ b/src/core/or/lttng_circuit.inc @@ -0,0 +1,322 @@ +/* Copyright (c) 2020, The Tor Project, Inc. */ +/* See LICENSE for licensing information */ + +/** + * \file lttng_circuit.inc + * \brief LTTng tracing probe declaration for the circuit subsystem. It is in +* this .inc file due to the non C standard syntax and the way we guard +* the header with the LTTng specific TRACEPOINT_HEADER_MULTI_READ. + **/ + +#include "orconfig.h" + +/* We only build the following if LTTng instrumentation has been enabled. */ +#ifdef USE_TRACING_INSTRUMENTATION_LTTNG + +/* The following defines are LTTng-UST specific. */ +#undef TRACEPOINT_PROVIDER +#define TRACEPOINT_PROVIDER tor_circuit + +#undef TRACEPOINT_INCLUDE +#define TRACEPOINT_INCLUDE "./src/core/or/lttng_circuit.inc" + +#if !defined(LTTNG_CIRCUIT_INC) || defined(TRACEPOINT_HEADER_MULTI_READ) +#define LTTNG_CIRCUIT_INC + +#include <lttng/tracepoint.h> + +/* + * Circuit Purposes + * + * The following defines an enumeration of all possible circuit purpose so + * they appear in the trace with the define name (first parameter of + * ctf_enum_value) instead of the numerical value. + */ +TRACEPOINT_ENUM(tor_circuit, purpose, + TP_ENUM_VALUES( + /* Initializing. */ + ctf_enum_value("<UNSET>", 0) + + /* OR Side. */ + ctf_enum_value("OR", CIRCUIT_PURPOSE_OR) + ctf_enum_value("OR_INTRO_POINT", CIRCUIT_PURPOSE_INTRO_POINT) + ctf_enum_value("OR_REND_POINT_WAITING", + CIRCUIT_PURPOSE_REND_POINT_WAITING) + ctf_enum_value("OR_REND_ESTABLISHED", CIRCUIT_PURPOSE_REND_ESTABLISHED) + + /* Client Side. */ + ctf_enum_value("C_GENERAL", CIRCUIT_PURPOSE_C_GENERAL) + ctf_enum_value("C_INTRODUCING", CIRCUIT_PURPOSE_C_INTRODUCING) + ctf_enum_value("C_INTRODUCE_ACK_WAIT", + CIRCUIT_PURPOSE_C_INTRODUCE_ACK_WAIT) + ctf_enum_value("C_INTRODUCE_ACKED", CIRCUIT_PURPOSE_C_INTRODUCE_ACKED) + ctf_enum_value("C_ESTABLISH_REND", CIRCUIT_PURPOSE_C_ESTABLISH_REND) + ctf_enum_value("C_REND_READY", CIRCUIT_PURPOSE_C_REND_READY) + ctf_enum_value("C_REND_READY_INTRO_ACKED", + CIRCUIT_PURPOSE_C_REND_READY_INTRO_ACKED) + ctf_enum_value("C_REND_JOINED", CIRCUIT_PURPOSE_C_REND_JOINED) + ctf_enum_value("C_HSDIR_GET", CIRCUIT_PURPOSE_C_HSDIR_GET) + + /* CBT and Padding. */ + ctf_enum_value("C_MEASURE_TIMEOUT", CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT) + ctf_enum_value("C_CIRCUIT_PADDING", CIRCUIT_PURPOSE_C_CIRCUIT_PADDING) + + /* Service Side. */ + ctf_enum_value("S_ESTABLISH_INTRO", CIRCUIT_PURPOSE_S_ESTABLISH_INTRO) + ctf_enum_value("S_INTRO", CIRCUIT_PURPOSE_S_INTRO) + ctf_enum_value("S_CONNECT_REND", CIRCUIT_PURPOSE_S_CONNECT_REND) + ctf_enum_value("S_REND_JOINED", CIRCUIT_PURPOSE_S_REND_JOINED) + ctf_enum_value("S_HSDIR_POST", CIRCUIT_PURPOSE_S_HSDIR_POST) + + /* Misc. */ + ctf_enum_value("TESTING", CIRCUIT_PURPOSE_TESTING) + ctf_enum_value("CONTROLER", CIRCUIT_PURPOSE_CONTROLLER) + ctf_enum_value("PATH_BIAS_TESTING", CIRCUIT_PURPOSE_PATH_BIAS_TESTING) + + /* VanGuard */ + ctf_enum_value("HS_VANGUARDS", CIRCUIT_PURPOSE_HS_VANGUARDS) + ) +) + +/* + * Circuit End Reasons + * + * The following defines an enumeration of all possible circuit end reasons so + * they appear in the trace with the define name (first parameter of + * ctf_enum_value) instead of the numerical value. + */ +TRACEPOINT_ENUM(tor_circuit, end_reason, + TP_ENUM_VALUES( + /* Local reasons. */ + ctf_enum_value("IP_NOW_REDUNDANT", END_CIRC_REASON_IP_NOW_REDUNDANT) + ctf_enum_value("MEASUREMENT_EXPIRED", END_CIRC_REASON_MEASUREMENT_EXPIRED) + ctf_enum_value("REASON_NOPATH", END_CIRC_REASON_NOPATH) + ctf_enum_value("AT_ORIGIN", END_CIRC_AT_ORIGIN) + ctf_enum_value("NONE", END_CIRC_REASON_NONE) + ctf_enum_value("TORPROTOCOL", END_CIRC_REASON_TORPROTOCOL) + ctf_enum_value("INTERNAL", END_CIRC_REASON_INTERNAL) + ctf_enum_value("REQUESTED", END_CIRC_REASON_REQUESTED) + ctf_enum_value("HIBERNATING", END_CIRC_REASON_HIBERNATING) + ctf_enum_value("RESOURCELIMIT", END_CIRC_REASON_RESOURCELIMIT) + ctf_enum_value("CONNECTFAILED", END_CIRC_REASON_CONNECTFAILED) + ctf_enum_value("OR_IDENTITY", END_CIRC_REASON_OR_IDENTITY) + ctf_enum_value("CHANNEL_CLOSED", END_CIRC_REASON_CHANNEL_CLOSED) + ctf_enum_value("FINISHED", END_CIRC_REASON_FINISHED) + ctf_enum_value("TIMEOUT", END_CIRC_REASON_TIMEOUT) + ctf_enum_value("DESTROYED", END_CIRC_REASON_DESTROYED) + ctf_enum_value("NOSUCHSERVICE", END_CIRC_REASON_NOSUCHSERVICE) + + /* Remote reasons. */ + ctf_enum_value("FLAG_REMOTE", END_CIRC_REASON_FLAG_REMOTE) + ctf_enum_value("REMOTE_TORPROTOCOL", + END_CIRC_REASON_FLAG_REMOTE | END_CIRC_REASON_TORPROTOCOL) + ctf_enum_value("REMOTE_INTERNAL", + END_CIRC_REASON_FLAG_REMOTE | END_CIRC_REASON_INTERNAL) + ctf_enum_value("REMOTE_REQUESTED", + END_CIRC_REASON_FLAG_REMOTE | END_CIRC_REASON_REQUESTED) + ctf_enum_value("REMOTE_HIBERNATING", + END_CIRC_REASON_FLAG_REMOTE | END_CIRC_REASON_HIBERNATING) + ctf_enum_value("REMOTE_RESOURCELIMIT", + END_CIRC_REASON_FLAG_REMOTE | END_CIRC_REASON_RESOURCELIMIT) + ctf_enum_value("REMOTE_CONNECTFAILED", + END_CIRC_REASON_FLAG_REMOTE | END_CIRC_REASON_CONNECTFAILED) + ctf_enum_value("REMOTE_OR_IDENTITY", + END_CIRC_REASON_FLAG_REMOTE | END_CIRC_REASON_OR_IDENTITY) + ctf_enum_value("REMOTE_CHANNEL_CLOSED", + END_CIRC_REASON_FLAG_REMOTE | END_CIRC_REASON_CHANNEL_CLOSED) + ctf_enum_value("REMOTE_FINISHED", + END_CIRC_REASON_FLAG_REMOTE | END_CIRC_REASON_FINISHED) + ctf_enum_value("REMOTE_TIMEOUT", + END_CIRC_REASON_FLAG_REMOTE | END_CIRC_REASON_TIMEOUT) + ctf_enum_value("REMOTE_DESTROYED", + END_CIRC_REASON_FLAG_REMOTE | END_CIRC_REASON_DESTROYED) + ctf_enum_value("REMOTE_NOSUCHSERVICE", + END_CIRC_REASON_FLAG_REMOTE | END_CIRC_REASON_NOSUCHSERVICE) + ) +) + +/* + * Circuit State + * + * The following defines an enumeration of all possible circuit state so they + * appear in the trace with the define name (first parameter of + * ctf_enum_value) instead of the numerical value. + */ +TRACEPOINT_ENUM(tor_circuit, state, + TP_ENUM_VALUES( + ctf_enum_value("BUILDING", CIRCUIT_STATE_BUILDING) + ctf_enum_value("ONIONSKIN_PENDING", CIRCUIT_STATE_ONIONSKIN_PENDING) + ctf_enum_value("CHAN_WAIT", CIRCUIT_STATE_CHAN_WAIT) + ctf_enum_value("GUARD_WAIT", CIRCUIT_STATE_GUARD_WAIT) + ctf_enum_value("OPEN", CIRCUIT_STATE_OPEN) + ) +) + +/* + * Event Class + * + * A tracepoint class is a class of tracepoints which share the same output + * event field definitions. They are then used by the + * TRACEPOINT_EVENT_INSTANCE() macro as a base field definition. + */ + +/* Class for origin circuit. */ +TRACEPOINT_EVENT_CLASS(tor_circuit, origin_circuit_t_class, + TP_ARGS(const origin_circuit_t *, circ), + TP_FIELDS( + ctf_integer(uint32_t, circ_id, circ->global_identifier) + ctf_enum(tor_circuit, purpose, int, purpose, TO_CIRCUIT(circ)->purpose) + ctf_enum(tor_circuit, state, int, state, TO_CIRCUIT(circ)->state) + ) +) + +/* Class for or circuit. */ +TRACEPOINT_EVENT_CLASS(tor_circuit, or_circuit_t_class, + TP_ARGS(const or_circuit_t *, circ), + TP_FIELDS( + ctf_enum(tor_circuit, purpose, int, purpose, TO_CIRCUIT(circ)->purpose) + ctf_enum(tor_circuit, state, int, state, TO_CIRCUIT(circ)->state) + ) +) + +/* + * Origin circuit events. + * + * Tracepoint use the origin_circuit_t object. + */ + +/* Tracepoint emitted when a new origin circuit has been created. */ +TRACEPOINT_EVENT_INSTANCE(tor_circuit, origin_circuit_t_class, new_origin, + TP_ARGS(const origin_circuit_t *, circ) +) + +/* Tracepoint emitted when an origin circuit has opened. */ +TRACEPOINT_EVENT_INSTANCE(tor_circuit, origin_circuit_t_class, opened, + TP_ARGS(const origin_circuit_t *, circ) +) + +/* Tracepoint emitted when an origin circuit has established. */ +TRACEPOINT_EVENT_INSTANCE(tor_circuit, origin_circuit_t_class, establish, + TP_ARGS(const origin_circuit_t *, circ) +) + +/* Tracepoint emitted when an origin circuit has been cannibalized. */ +TRACEPOINT_EVENT_INSTANCE(tor_circuit, origin_circuit_t_class, cannibalized, + TP_ARGS(const origin_circuit_t *, circ) +) + +/* Tracepoint emitted when an origin circuit has timed out. This is called + * when circuit_expire_building() as selected the circuit and is about to + * close it for timeout. */ +TRACEPOINT_EVENT_INSTANCE(tor_circuit, origin_circuit_t_class, timeout, + TP_ARGS(const origin_circuit_t *, circ) +) + +/* Tracepoint emitted when an origin circuit has timed out due to idleness. + * This is when the circuit is closed after MaxCircuitDirtiness. */ +TRACEPOINT_EVENT_INSTANCE(tor_circuit, origin_circuit_t_class, idle_timeout, + TP_ARGS(const origin_circuit_t *, circ) +) + +/* Tracepoint emitted when an origin circuit sends out its first onion skin. */ +TRACEPOINT_EVENT(tor_circuit, first_onion_skin, + TP_ARGS(const origin_circuit_t *, circ, const crypt_path_t *, hop), + TP_FIELDS( + ctf_integer(uint32_t, circ_id, circ->global_identifier) + ctf_enum(tor_circuit, purpose, int, purpose, TO_CIRCUIT(circ)->purpose) + ctf_enum(tor_circuit, state, int, state, TO_CIRCUIT(circ)->state) + ctf_array_hex(char, fingerprint, hop->extend_info->identity_digest, + DIGEST_LEN) + ) +) + +/* Tracepoint emitted when an origin circuit sends out an intermediate onion + * skin. */ +TRACEPOINT_EVENT(tor_circuit, intermediate_onion_skin, + TP_ARGS(const origin_circuit_t *, circ, const crypt_path_t *, hop), + TP_FIELDS( + ctf_integer(uint32_t, circ_id, circ->global_identifier) + ctf_enum(tor_circuit, purpose, int, purpose, TO_CIRCUIT(circ)->purpose) + ctf_enum(tor_circuit, state, int, state, TO_CIRCUIT(circ)->state) + ctf_array_hex(char, fingerprint, hop->extend_info->identity_digest, + DIGEST_LEN) + ) +) + +/* + * OR circuit events. + * + * Tracepoint use the or_circuit_t object. + */ + +/* Tracepoint emitted when a new or circuit has been created. */ +TRACEPOINT_EVENT_INSTANCE(tor_circuit, or_circuit_t_class, new_or, + TP_ARGS(const or_circuit_t *, circ) +) + +/* + * General circuit events. + * + * Tracepoint use the circuit_t object. + */ + +/* Tracepoint emitted when a circuit is freed. */ +TRACEPOINT_EVENT(tor_circuit, free, + TP_ARGS(const circuit_t *, circ), + TP_FIELDS( + ctf_integer(uint32_t, circ_id, + (CIRCUIT_IS_ORIGIN(circ) ? + TO_ORIGIN_CIRCUIT(circ)->global_identifier : 0)) + ctf_enum(tor_circuit, purpose, int, purpose, circ->purpose) + ctf_enum(tor_circuit, state, int, state, circ->state) + ) +) + +/* Tracepoint emitted when a circuit is marked for close. */ +TRACEPOINT_EVENT(tor_circuit, mark_for_close, + TP_ARGS(const circuit_t *, circ), + TP_FIELDS( + ctf_integer(uint32_t, circ_id, + (CIRCUIT_IS_ORIGIN(circ) ? + TO_ORIGIN_CIRCUIT(circ)->global_identifier : 0)) + ctf_enum(tor_circuit, purpose, int, purpose, circ->purpose) + ctf_enum(tor_circuit, state, int, state, circ->state) + ctf_enum(tor_circuit, end_reason, int, close_reason, + circ->marked_for_close_reason) + ctf_enum(tor_circuit, end_reason, int, orig_close_reason, + circ->marked_for_close_orig_reason) + ) +) + +/* Tracepoint emitted when a circuit changes purpose. */ +TRACEPOINT_EVENT(tor_circuit, change_purpose, + TP_ARGS(const circuit_t *, circ, int, old_purpose, int, new_purpose), + TP_FIELDS( + ctf_integer(uint32_t, circ_id, + (CIRCUIT_IS_ORIGIN(circ) ? + TO_ORIGIN_CIRCUIT(circ)->global_identifier : 0)) + ctf_enum(tor_circuit, state, int, state, circ->state) + ctf_enum(tor_circuit, purpose, int, purpose, old_purpose) + ctf_enum(tor_circuit, purpose, int, new, new_purpose) + ) +) + +/* Tracepoint emitted when a circuit changes state. */ +TRACEPOINT_EVENT(tor_circuit, change_state, + TP_ARGS(const circuit_t *, circ, int, old_state, int, new_state), + TP_FIELDS( + ctf_integer(uint32_t, circ_id, + (CIRCUIT_IS_ORIGIN(circ) ? + TO_ORIGIN_CIRCUIT(circ)->global_identifier : 0)) + ctf_enum(tor_circuit, purpose, int, purpose, circ->purpose) + ctf_enum(tor_circuit, state, int, old, old_state) + ctf_enum(tor_circuit, state, int, new, new_state) + ) +) + +#endif /* LTTNG_CIRCUIT_INC || TRACEPOINT_HEADER_MULTI_READ */ + +/* Must be included after the probes declaration. */ +#include <lttng/tracepoint-event.h> + +#endif /* USE_TRACING_INSTRUMENTATION_LTTNG */ diff --git a/src/core/or/trace_probes_circuit.c b/src/core/or/trace_probes_circuit.c new file mode 100644 index 0000000000..b186ffda7f --- /dev/null +++ b/src/core/or/trace_probes_circuit.c @@ -0,0 +1,30 @@ +/* Copyright (c) 2020, The Tor Project, Inc. */ +/* See LICENSE for licensing information */ + +/** + * \file trace_probes_circuit.c + * \brief Tracepoint provider source file for the circuit subsystem. Probes + * are generated within this C file for LTTng-UST + **/ + +#include "orconfig.h" + +/* + * Following section is specific to LTTng-UST. + */ +#ifdef USE_TRACING_INSTRUMENTATION_LTTNG + +/* Header files that the probes need. */ +#include "core/or/circuitlist.h" +#include "core/or/crypt_path_st.h" +#include "core/or/extend_info_st.h" +#include "core/or/or.h" +#include "core/or/or_circuit_st.h" +#include "core/or/origin_circuit_st.h" + +#define TRACEPOINT_DEFINE +#define TRACEPOINT_CREATE_PROBES + +#include "trace_probes_circuit.h" + +#endif /* USE_TRACING_INSTRUMENTATION_LTTNG */ diff --git a/src/core/or/trace_probes_circuit.h b/src/core/or/trace_probes_circuit.h new file mode 100644 index 0000000000..59f53c324a --- /dev/null +++ b/src/core/or/trace_probes_circuit.h @@ -0,0 +1,22 @@ +/* Copyright (c) 2020, The Tor Project, Inc. */ +/* See LICENSE for licensing information */ + +/** + * \file trace_probes_circuit.c + * \brief The tracing probes for the circuit subsystem. Currently, only + * LTTng-UST probes are available. + **/ + +#ifndef TOR_TRACE_PROBES_CIRCUIT_H +#define TOR_TRACE_PROBES_CIRCUIT_H + +#include "lib/trace/events.h" + +/* We only build the following if LTTng instrumentation has been enabled. */ +#ifdef USE_TRACING_INSTRUMENTATION_LTTNG + +#include "core/or/lttng_circuit.inc" + +#endif /* USE_TRACING_INSTRUMENTATION_LTTNG */ + +#endif /* TOR_TRACE_PROBES_CIRCUIT_H */ diff --git a/src/lib/trace/.may_include b/src/lib/trace/.may_include index 45cd13676b..1ed533cc7a 100644 --- a/src/lib/trace/.may_include +++ b/src/lib/trace/.may_include @@ -1,3 +1,4 @@ orconfig.h lib/log/*.h lib/trace/*.h +lib/subsys/*.h diff --git a/src/lib/trace/debug.h b/src/lib/trace/debug.h index 87b3074e0b..84a2867a6d 100644 --- a/src/lib/trace/debug.h +++ b/src/lib/trace/debug.h @@ -6,8 +6,10 @@ * \brief Macros for debugging our event-trace support. **/ -#ifndef TOR_TRACE_LOG_DEBUG_H -#define TOR_TRACE_LOG_DEBUG_H +#ifndef TOR_TRACE_DEBUG_H +#define TOR_TRACE_DEBUG_H + +#ifdef USE_TRACING_INSTRUMENTATION_LOG_DEBUG #include "lib/log/log.h" @@ -17,14 +19,20 @@ /* 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. */ + * + * NOTE: arguments can't be used becaue there is no easy generic ways to learn + * their type and amount. It is probably doable with massive C pre-processor + * trickery but this is meant to be simple. */ + +#define TOR_TRACE_LOG_DEBUG(subsystem, event_name, ...) \ + log_debug(LD_GENERAL, "Tracepoint \"" XSTR(event_name) "\" from " \ + "subsystem \"" XSTR(subsystem) "\" hit.") + +#else /* defined(USE_TRACING_INSTRUMENTATION_LOG_DEBUG) */ + +/* NOP the debug event. */ +#define TOR_TRACE_LOG_DEBUG(subsystem, name, ...) -/* 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 /* defined(USE_TRACING_INSTRUMENTATION_LOG_DEBUG) */ -#endif /* !defined(TOR_TRACE_LOG_DEBUG_H) */ +#endif /* !defined(TOR_TRACE_DEBUG_H) */ diff --git a/src/lib/trace/events.h b/src/lib/trace/events.h index 368f85dd02..ce1604de22 100644 --- a/src/lib/trace/events.h +++ b/src/lib/trace/events.h @@ -3,43 +3,75 @@ /** * \file events.h - * \brief Header file for Tor event tracing. + * \brief Header file for Tor tracing instrumentation definition. **/ -#ifndef TOR_TRACE_EVENTS_H -#define TOR_TRACE_EVENTS_H +#ifndef TOR_LIB_TRACE_EVENTS_H +#define TOR_LIB_TRACE_EVENTS_H + +#include "orconfig.h" /* - * The following defines a generic event tracing function name that has to be - * used to trace events in the code base. + * A tracepoint signature is defined as follow: + * + * tor_trace(<subsystem>, <event_name>, <args>...) + * + * If tracing is enabled, the tor_trace() macro is mapped to all possible + * instrumentations (defined below). Each instrumentation type MUST define a + * top level macro (TOR_TRACE_<type>) so it can be inserted into each + * tracepoint. + * + * In case no tracing is enabled (HAVE_TRACING), tracepoints are NOP and thus + * have no execution cost. * - * 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). + * Currently, three types of instrumentation are supported: * - * 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. + * log-debug: Every tracepoints is mapped to a log_debug() statement. + * + * User Statically-Defined Tracing (USDT): Probes that can be used with perf, + * dtrace, SystemTap, DTrace and BPF Compiler Collection (BCC). + * + * LTTng-UST: Probes for the LTTng Userspace Tracer. If USDT interface + * (sdt.h) is available, the USDT probes are also generated by LTTng thus + * enabling this instrumentation provides both probes. */ -#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__) +/** Helper to disambiguate these identifiers in the code base. They should + * only be used with tor_trace() like so: + * + * tor_trace(TR_SUBSYS(circuit), TR_EV(opened), ...); + */ + +#define TR_SUBSYS(name) tor_ ## name +#define TR_EV(name) name + +#ifdef HAVE_TRACING -/* Enable event tracing for the debug framework where all trace events are - * mapped to a log_debug(). */ -#ifdef USE_EVENT_TRACING_DEBUG +#define tor_trace(subsystem, event_name, ...) \ + do { \ + TOR_TRACE_LOG_DEBUG(subsystem, event_name); \ + TOR_TRACE_USDT(subsystem, event_name, ## __VA_ARGS__); \ + TOR_TRACE_LTTNG(subsystem, event_name, ## __VA_ARGS__); \ + } while (0) + +/* This corresponds to the --enable-tracing-instrumentation-log-debug + * configure option which maps all tracepoints to a log_debug() statement. */ #include "lib/trace/debug.h" -#endif -#else /* !defined(TOR_EVENT_TRACING_ENABLED) */ +/* This corresponds to the --enable-tracing-instrumentation-usdt configure + * option which will generate USDT probes for each tracepoints. */ +#include "lib/trace/usdt/usdt.h" + +/* This corresponds to the --enable-tracing-instrumentation-lttng configure + * option which will generate LTTng probes for each tracepoints. */ +#include "lib/trace/lttng/lttng.h" + +#else /* !defined(HAVE_TRACING) */ -/* Reaching this point, we NOP every event declaration because event tracing - * is not been enabled at compile time. */ -#define tor_trace(subsystem, name, args...) +/* Reaching this point, tracing is disabled thus we NOP every tracepoints + * declaration so we have no execution cost at runtime. */ +#define tor_trace(subsystem, name, ...) -#endif /* defined(TOR_EVENT_TRACING_ENABLED) */ +#endif /* defined(HAVE_TRACING) */ -#endif /* !defined(TOR_TRACE_EVENTS_H) */ +#endif /* !defined(TOR_LIB_TRACE_EVENTS_H) */ diff --git a/src/lib/trace/include.am b/src/lib/trace/include.am index 98098c87f4..6fe1365652 100644 --- a/src/lib/trace/include.am +++ b/src/lib/trace/include.am @@ -2,18 +2,34 @@ noinst_LIBRARIES += \ src/lib/libtor-trace.a +# ADD_C_FILE: INSERT SOURCES HERE. +LIBTOR_TRACE_A_SOURCES = \ + src/lib/trace/trace.c \ + src/lib/trace/trace_sys.c + # ADD_C_FILE: INSERT HEADERS HERE. TRACEHEADERS = \ - src/lib/trace/trace.h \ + src/lib/trace/trace.h \ + src/lib/trace/trace_sys.h \ src/lib/trace/events.h -if USE_EVENT_TRACING_DEBUG +if USE_TRACING_INSTRUMENTATION_LOG_DEBUG TRACEHEADERS += \ src/lib/trace/debug.h endif -# ADD_C_FILE: INSERT SOURCES HERE. -src_lib_libtor_trace_a_SOURCES = \ - src/lib/trace/trace.c +if USE_TRACING_INSTRUMENTATION_USDT +include src/lib/trace/usdt/include.am +endif + +if USE_TRACING_INSTRUMENTATION_LTTNG +include src/lib/trace/lttng/include.am +endif + +if USE_TRACING +src_lib_libtor_trace_a_SOURCES = $(LIBTOR_TRACE_A_SOURCES) +else +src_lib_libtor_trace_a_SOURCES = src/lib/trace/trace_stub.c +endif noinst_HEADERS+= $(TRACEHEADERS) diff --git a/src/lib/trace/lttng/include.am b/src/lib/trace/lttng/include.am new file mode 100644 index 0000000000..4495ce0900 --- /dev/null +++ b/src/lib/trace/lttng/include.am @@ -0,0 +1,3 @@ +# ADD_C_FILE: INSERT HEADERS HERE. +TRACEHEADERS += \ + src/lib/trace/lttng/lttng.h diff --git a/src/lib/trace/lttng/lttng.h b/src/lib/trace/lttng/lttng.h new file mode 100644 index 0000000000..8ede98bb02 --- /dev/null +++ b/src/lib/trace/lttng/lttng.h @@ -0,0 +1,28 @@ +/* Copyright (c) 2020, The Tor Project, Inc. */ +/* See LICENSE for licensing information */ + +/** + * \file lttng.h + * \brief Header file for lttng.c. + **/ + +#ifndef TOR_TRACE_LTTNG_LTTNG_H +#define TOR_TRACE_LTTNG_LTTNG_H + +#ifdef USE_TRACING_INSTRUMENTATION_LTTNG + +#include <lttng/tracepoint.h> + +/* Map event to an LTTng tracepoint. */ +#define TOR_TRACE_LTTNG(subsystem, event_name, ...) \ + tracepoint(subsystem, event_name, ## __VA_ARGS__) + +#else /* !defined(USE_TRACING_INSTRUMENTATION_LTTNG) */ + +/* NOP event. */ +#define TOR_TRACE_LTTNG(subsystem, event_name, ...) + +#endif /* !defined(USE_TRACING_INSTRUMENTATION_LTTNG) */ + +#endif /* TOR_TRACE_LTTNG_LTTNG_H */ + diff --git a/src/lib/trace/trace.c b/src/lib/trace/trace.c index 4e5c66b4c6..10d11c17c5 100644 --- a/src/lib/trace/trace.c +++ b/src/lib/trace/trace.c @@ -1,4 +1,4 @@ -/* Copyright (c) 2017-2020, The Tor Project, Inc. */ +/* Copyright (c) 2020, The Tor Project, Inc. */ /* See LICENSE for licensing information */ /** @@ -15,3 +15,9 @@ void tor_trace_init(void) { } + +/** Free all the tracing library. */ +void +tor_trace_free_all(void) +{ +} diff --git a/src/lib/trace/trace.h b/src/lib/trace/trace.h index 5e24678c3c..22589dbe94 100644 --- a/src/lib/trace/trace.h +++ b/src/lib/trace/trace.h @@ -1,4 +1,4 @@ -/* Copyright (c) 2017-2020, The Tor Project, Inc. */ +/* Copyright (c) 2020, The Tor Project, Inc. */ /* See LICENSE for licensing information */ /** @@ -6,9 +6,31 @@ * \brief Header for trace.c **/ -#ifndef TOR_TRACE_TRACE_H -#define TOR_TRACE_TRACE_H +#ifndef TOR_LIB_TRACE_TRACE_H +#define TOR_LIB_TRACE_TRACE_H + +#include "orconfig.h" void tor_trace_init(void); +void tor_trace_free_all(void); + +#ifdef HAVE_TRACING + +#include "lib/log/log.h" + +static inline void +tracing_log_warning(void) +{ + log_warn(LD_GENERAL, + "Tracing capabilities have been built in. If this is NOT on " + "purpose, your tor is NOT safe to run."); +} + +#else + +/* NOP it. */ +#define tracing_log_warning() + +#endif /* defined(HAVE_TRACING) */ -#endif /* !defined(TOR_TRACE_TRACE_H) */ +#endif /* !defined(TOR_LIB_TRACE_TRACE_H) */ diff --git a/src/lib/trace/trace_stub.c b/src/lib/trace/trace_stub.c new file mode 100644 index 0000000000..9043efe360 --- /dev/null +++ b/src/lib/trace/trace_stub.c @@ -0,0 +1,19 @@ +/* Copyright (c) 2020, The Tor Project, Inc. */ +/* See LICENSE for licensing information */ + +/** + * \file trace_stub.c + * \brief Stub declaratinos for use when trace library is disabled. + **/ + +#include "lib/subsys/subsys.h" + +#include "lib/trace/trace_sys.h" + +const subsys_fns_t sys_tracing = { + SUBSYS_DECLARE_LOCATION(), + + .name = "tracing", + .supported = false, + .level = TRACE_SUBSYS_LEVEL, +}; diff --git a/src/lib/trace/trace_sys.c b/src/lib/trace/trace_sys.c new file mode 100644 index 0000000000..2ba0258407 --- /dev/null +++ b/src/lib/trace/trace_sys.c @@ -0,0 +1,36 @@ +/* Copyright (c) 2018-2019, The Tor Project, Inc. */ +/* See LICENSE for licensing information */ + +/** + * \file log_sys.c + * \brief Setup and tear down the tracing module. + **/ + +#include "lib/subsys/subsys.h" + +#include "lib/trace/trace.h" +#include "lib/trace/trace_sys.h" + +static int +subsys_tracing_initialize(void) +{ + tor_trace_init(); + return 0; +} + +static void +subsys_tracing_shutdown(void) +{ + tor_trace_free_all(); +} + +const subsys_fns_t sys_tracing = { + SUBSYS_DECLARE_LOCATION(), + + .name = "tracing", + .supported = true, + .level = TRACE_SUBSYS_LEVEL, + + .initialize = subsys_tracing_initialize, + .shutdown = subsys_tracing_shutdown, +}; diff --git a/src/lib/trace/trace_sys.h b/src/lib/trace/trace_sys.h new file mode 100644 index 0000000000..d4da5a9701 --- /dev/null +++ b/src/lib/trace/trace_sys.h @@ -0,0 +1,22 @@ +/* Copyright (c) 2018-2019, The Tor Project, Inc. */ +/* See LICENSE for licensing information */ + +/** + * \file log_sys.h + * \brief Declare subsystem object for the logging module. + **/ + +#ifndef TOR_TRACE_SYS_H +#define TOR_TRACE_SYS_H + +extern const struct subsys_fns_t sys_tracing; + +/** + * Subsystem level for the tracing system. + * + * Defined here so that it can be shared between the real and stub + * definitions. + **/ +#define TRACE_SUBSYS_LEVEL (-85) + +#endif /* !defined(TOR_TRACE_SYS_H) */ diff --git a/src/lib/trace/usdt/include.am b/src/lib/trace/usdt/include.am new file mode 100644 index 0000000000..4e7e04c326 --- /dev/null +++ b/src/lib/trace/usdt/include.am @@ -0,0 +1,3 @@ +# ADD_C_FILE: INSERT HEADERS HERE. +TRACEHEADERS += \ + src/lib/trace/usdt/usdt.h diff --git a/src/lib/trace/usdt/usdt.h b/src/lib/trace/usdt/usdt.h new file mode 100644 index 0000000000..0b5fd6c444 --- /dev/null +++ b/src/lib/trace/usdt/usdt.h @@ -0,0 +1,33 @@ +/* Copyright (c) 2020, The Tor Project, Inc. */ +/* See LICENSE for licensing information */ + +/** + * \file trace.h + * \brief Header for usdt.h + **/ + +#ifndef TOR_TRACE_USDT_USDT_H +#define TOR_TRACE_USDT_USDT_H + +#ifdef USE_TRACING_INSTRUMENTATION_USDT + +#ifdef HAVE_SYS_SDT_H +#define SDT_USE_VARIADIC +#include <sys/sdt.h> +#define TOR_STAP_PROBEV STAP_PROBEV +#else /* defined(HAVE_SYS_SDT_H) */ +#define TOR_STAP_PROBEV(...) +#endif + +/* Map events to an USDT probe. */ +#define TOR_TRACE_USDT(subsystem, event_name, ...) \ + TOR_STAP_PROBEV(subsystem, event_name, ## __VA_ARGS__); + +#else /* !defined(USE_TRACING_INSTRUMENTATION_USDT) */ + +/* NOP event. */ +#define TOR_TRACE_USDT(subsystem, event_name, ...) + +#endif /* !defined(USE_TRACING_INSTRUMENTATION_USDT) */ + +#endif /* !defined(TOR_TRACE_USDT_USDT_H) */ diff --git a/src/test/fuzz/include.am b/src/test/fuzz/include.am index d0711f05d6..f3f7202ce2 100644 --- a/src/test/fuzz/include.am +++ b/src/test/fuzz/include.am @@ -14,7 +14,7 @@ FUZZING_LIBS = \ @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_GDI@ @TOR_LIB_USERENV@ @CURVE25519_LIBS@ \ @TOR_SYSTEMD_LIBS@ \ @TOR_LZMA_LIBS@ \ - @TOR_ZSTD_LIBS@ + @TOR_ZSTD_LIBS@ @TOR_TRACE_LIBS@ oss-fuzz-prereqs: \ $(TOR_INTERNAL_TESTING_LIBS) diff --git a/src/test/include.am b/src/test/include.am index e7647260c5..d7be1a5f77 100644 --- a/src/test/include.am +++ b/src/test/include.am @@ -297,7 +297,7 @@ src_test_test_switch_id_LDADD = \ $(rust_ldadd) \ @TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ \ @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_USERENV@ \ - @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@ + @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@ @TOR_TRACE_LIBS@ src_test_test_LDFLAGS = @TOR_LDFLAGS_zlib@ $(TOR_LDFLAGS_CRYPTLIB) \ @TOR_LDFLAGS_libevent@ @@ -307,7 +307,7 @@ src_test_test_LDADD = \ @TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ @TOR_LIBEVENT_LIBS@ \ $(TOR_LIBS_CRYPTLIB) @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_GDI@ @TOR_LIB_USERENV@ \ @CURVE25519_LIBS@ \ - @TOR_SYSTEMD_LIBS@ @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@ + @TOR_SYSTEMD_LIBS@ @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@ @TOR_TRACE_LIBS@ src_test_test_slow_CPPFLAGS = $(src_test_test_CPPFLAGS) src_test_test_slow_CFLAGS = $(src_test_test_CFLAGS) @@ -336,7 +336,7 @@ src_test_bench_LDADD = \ @TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ @TOR_LIBEVENT_LIBS@ \ $(TOR_LIBS_CRYPTLIB) @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_GDI@ @TOR_LIB_USERENV@ \ @CURVE25519_LIBS@ \ - @TOR_SYSTEMD_LIBS@ @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@ + @TOR_SYSTEMD_LIBS@ @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@ @TOR_TRACE_LIBS@ src_test_test_workqueue_LDFLAGS = @TOR_LDFLAGS_zlib@ $(TOR_LDFLAGS_CRYPTLIB) \ @TOR_LDFLAGS_libevent@ @@ -346,7 +346,7 @@ src_test_test_workqueue_LDADD = \ @TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ @TOR_LIBEVENT_LIBS@ \ $(TOR_LIBS_CRYPTLIB) @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_GDI@ @TOR_LIB_USERENV@ \ @CURVE25519_LIBS@ \ - @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@ + @TOR_LZMA_LIBS@ @TOR_ZSTD_LIBS@ @TOR_TRACE_LIBS@ src_test_test_timers_CPPFLAGS = $(src_test_test_CPPFLAGS) src_test_test_timers_CFLAGS = $(src_test_test_CFLAGS) @@ -358,7 +358,7 @@ src_test_test_timers_LDADD = \ @TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ @TOR_LIBEVENT_LIBS@ \ $(TOR_LIBS_CRYPTLIB) @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_GDI@ @TOR_LIB_USERENV@ \ @CURVE25519_LIBS@ \ - @TOR_LZMA_LIBS@ + @TOR_LZMA_LIBS@ @TOR_TRACE_LIBS@ src_test_test_timers_LDFLAGS = $(src_test_test_LDFLAGS) # ADD_C_FILE: INSERT HEADERS HERE. @@ -394,7 +394,7 @@ src_test_test_ntor_cl_LDADD = \ $(rust_ldadd) \ @TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ \ $(TOR_LIBS_CRYPTLIB) @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_GDI@ @TOR_LIB_USERENV@ \ - @CURVE25519_LIBS@ @TOR_LZMA_LIBS@ + @CURVE25519_LIBS@ @TOR_LZMA_LIBS@ @TOR_TRACE_LIBS@ src_test_test_ntor_cl_AM_CPPFLAGS = \ $(AM_CPPFLAGS) @@ -403,7 +403,8 @@ src_test_test_hs_ntor_cl_LDFLAGS = @TOR_LDFLAGS_zlib@ $(TOR_LDFLAGS_CRYPTLIB) src_test_test_hs_ntor_cl_LDADD = \ $(TOR_INTERNAL_LIBS) \ @TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ \ - $(TOR_LIBS_CRYPTLIB) @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_GDI@ @CURVE25519_LIBS@ + $(TOR_LIBS_CRYPTLIB) @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_GDI@ \ + @CURVE25519_LIBS@ @TOR_TRACE_LIBS@ src_test_test_hs_ntor_cl_AM_CPPFLAGS = \ $(AM_CPPFLAGS) @@ -415,7 +416,8 @@ src_test_test_bt_cl_LDADD = \ $(TOR_UTIL_TESTING_LIBS) \ $(rust_ldadd) \ @TOR_LIB_MATH@ \ - @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_GDI@ @TOR_LIB_USERENV@ + @TOR_LIB_WS32@ @TOR_LIB_IPHLPAPI@ @TOR_LIB_GDI@ @TOR_LIB_USERENV@ \ + @TOR_TRACE_LIBS@ src_test_test_bt_cl_CFLAGS = $(AM_CFLAGS) $(TEST_CFLAGS) src_test_test_bt_cl_CPPFLAGS= $(src_test_AM_CPPFLAGS) $(TEST_CPPFLAGS) endif |