trace: Helper macro to disambiguate identifiers

In order to disambiguate the subsystem and event_name identifiers in the
tor_trace() macro, add TR_SUBSYS() and TR_EV() which help to identify the
parameters of tor_trace() explicitly.

Signed-off-by: David Goulet <dgoulet@torproject.org>
This commit is contained in:
David Goulet 2020-03-11 10:54:47 -04:00
parent d80c34d214
commit 3604d86a01
5 changed files with 32 additions and 19 deletions

View File

@ -500,7 +500,7 @@ circuit_establish_circuit(uint8_t purpose, extend_info_t *exit_ei, int flags)
return NULL; return NULL;
} }
tor_trace(circuit, establish, circ); tor_trace(TR_SUBSYS(circuit), TR_EV(establish), circ);
return circ; return circ;
} }
@ -983,7 +983,7 @@ circuit_send_first_onion_skin(origin_circuit_t *circ)
if (circuit_deliver_create_cell(TO_CIRCUIT(circ), &cc, 0) < 0) if (circuit_deliver_create_cell(TO_CIRCUIT(circ), &cc, 0) < 0)
return - END_CIRC_REASON_RESOURCELIMIT; return - END_CIRC_REASON_RESOURCELIMIT;
tor_trace(circuit, first_onion_skin, circ, circ->cpath); tor_trace(TR_SUBSYS(circuit), TR_EV(first_onion_skin), circ, circ->cpath);
circ->cpath->state = CPATH_STATE_AWAITING_KEYS; circ->cpath->state = CPATH_STATE_AWAITING_KEYS;
circuit_set_state(TO_CIRCUIT(circ), CIRCUIT_STATE_BUILDING); circuit_set_state(TO_CIRCUIT(circ), CIRCUIT_STATE_BUILDING);
@ -1147,7 +1147,7 @@ circuit_send_intermediate_onion_skin(origin_circuit_t *circ,
return 0; /* circuit is closed */ return 0; /* circuit is closed */
} }
hop->state = CPATH_STATE_AWAITING_KEYS; hop->state = CPATH_STATE_AWAITING_KEYS;
tor_trace(circuit, intermediate_onion_skin, circ, hop); tor_trace(TR_SUBSYS(circuit), TR_EV(intermediate_onion_skin), circ, hop);
return 0; return 0;
} }

View File

@ -100,7 +100,6 @@
#include "lib/compress/compress_zlib.h" #include "lib/compress/compress_zlib.h"
#include "lib/compress/compress_zstd.h" #include "lib/compress/compress_zstd.h"
#include "lib/buf/buffers.h" #include "lib/buf/buffers.h"
#include "lib/trace/events.h"
#include "core/or/ocirc_event.h" #include "core/or/ocirc_event.h"
@ -568,7 +567,7 @@ circuit_set_state(circuit_t *circ, uint8_t state)
if (state == CIRCUIT_STATE_GUARD_WAIT || state == CIRCUIT_STATE_OPEN) if (state == CIRCUIT_STATE_GUARD_WAIT || state == CIRCUIT_STATE_OPEN)
tor_assert(!circ->n_chan_create_cell); tor_assert(!circ->n_chan_create_cell);
tor_trace(circuit, change_state, circ, circ->state, state); tor_trace(TR_SUBSYS(circuit), TR_EV(change_state), circ, circ->state, state);
circ->state = state; circ->state = state;
if (CIRCUIT_IS_ORIGIN(circ)) if (CIRCUIT_IS_ORIGIN(circ))
circuit_state_publish(circ); circuit_state_publish(circ);
@ -1083,7 +1082,7 @@ origin_circuit_new(void)
prediction_time_remaining); prediction_time_remaining);
} }
tor_trace(circuit, new_origin, circ); tor_trace(TR_SUBSYS(circuit), TR_EV(new_origin), circ);
return circ; return circ;
} }
@ -1106,7 +1105,7 @@ or_circuit_new(circid_t p_circ_id, channel_t *p_chan)
init_circuit_base(TO_CIRCUIT(circ)); init_circuit_base(TO_CIRCUIT(circ));
tor_trace(circuit, new_or, circ); tor_trace(TR_SUBSYS(circuit), TR_EV(new_or), circ);
return circ; return circ;
} }
@ -1261,7 +1260,7 @@ circuit_free_(circuit_t *circ)
/* Tracepoint. Data within the circuit object is recorded so do this before /* Tracepoint. Data within the circuit object is recorded so do this before
* the actual memory free. */ * the actual memory free. */
tor_trace(circuit, free, circ); tor_trace(TR_SUBSYS(circuit), TR_EV(free), circ);
if (should_free) { if (should_free) {
memwipe(mem, 0xAA, memlen); /* poison memory */ memwipe(mem, 0xAA, memlen); /* poison memory */
@ -2285,7 +2284,7 @@ circuit_mark_for_close_, (circuit_t *circ, int reason, int line,
CIRCUIT_IS_ORIGIN(circ) ? CIRCUIT_IS_ORIGIN(circ) ?
TO_ORIGIN_CIRCUIT(circ)->global_identifier : 0, TO_ORIGIN_CIRCUIT(circ)->global_identifier : 0,
file, line, orig_reason, reason); file, line, orig_reason, reason);
tor_trace(circuit, mark_for_close, circ); tor_trace(TR_SUBSYS(circuit), TR_EV(mark_for_close), circ);
} }
/** Called immediately before freeing a marked circuit <b>circ</b> from /** Called immediately before freeing a marked circuit <b>circ</b> from

View File

@ -840,7 +840,7 @@ circuit_expire_building(void)
-1); -1);
circuit_log_path(LOG_INFO,LD_CIRC,TO_ORIGIN_CIRCUIT(victim)); circuit_log_path(LOG_INFO,LD_CIRC,TO_ORIGIN_CIRCUIT(victim));
tor_trace(circuit, timeout, TO_ORIGIN_CIRCUIT(victim)); tor_trace(TR_SUBSYS(circuit), TR_EV(timeout), TO_ORIGIN_CIRCUIT(victim));
if (victim->purpose == CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT) if (victim->purpose == CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT)
circuit_mark_for_close(victim, END_CIRC_REASON_MEASUREMENT_EXPIRED); circuit_mark_for_close(victim, END_CIRC_REASON_MEASUREMENT_EXPIRED);
else else
@ -1505,7 +1505,8 @@ circuit_expire_old_circuits_clientside(void)
/* Don't do this magic for testing circuits. Their death is governed /* Don't do this magic for testing circuits. Their death is governed
* by circuit_expire_building */ * by circuit_expire_building */
if (circ->purpose != CIRCUIT_PURPOSE_PATH_BIAS_TESTING) { if (circ->purpose != CIRCUIT_PURPOSE_PATH_BIAS_TESTING) {
tor_trace(circuit, idle_timeout, TO_ORIGIN_CIRCUIT(circ)); tor_trace(TR_SUBSYS(circuit), TR_EV(idle_timeout),
TO_ORIGIN_CIRCUIT(circ));
circuit_mark_for_close(circ, END_CIRC_REASON_FINISHED); circuit_mark_for_close(circ, END_CIRC_REASON_FINISHED);
} }
} else if (!circ->timestamp_dirty && circ->state == CIRCUIT_STATE_OPEN) { } else if (!circ->timestamp_dirty && circ->state == CIRCUIT_STATE_OPEN) {
@ -1526,7 +1527,8 @@ circuit_expire_old_circuits_clientside(void)
" that has been unused for %ld msec.", " that has been unused for %ld msec.",
TO_ORIGIN_CIRCUIT(circ)->global_identifier, TO_ORIGIN_CIRCUIT(circ)->global_identifier,
tv_mdiff(&circ->timestamp_began, &now)); tv_mdiff(&circ->timestamp_began, &now));
tor_trace(circuit, idle_timeout, TO_ORIGIN_CIRCUIT(circ)); tor_trace(TR_SUBSYS(circuit), TR_EV(idle_timeout),
TO_ORIGIN_CIRCUIT(circ));
circuit_mark_for_close(circ, END_CIRC_REASON_FINISHED); circuit_mark_for_close(circ, END_CIRC_REASON_FINISHED);
} else if (!TO_ORIGIN_CIRCUIT(circ)->is_ancient) { } else if (!TO_ORIGIN_CIRCUIT(circ)->is_ancient) {
/* Server-side rend joined circuits can end up really old, because /* Server-side rend joined circuits can end up really old, because
@ -1689,7 +1691,7 @@ circuit_testing_failed(origin_circuit_t *circ, int at_last_hop)
void void
circuit_has_opened(origin_circuit_t *circ) circuit_has_opened(origin_circuit_t *circ)
{ {
tor_trace(circuit, opened, circ); tor_trace(TR_SUBSYS(circuit), TR_EV(opened), circ);
circuit_event_status(circ, CIRC_EVENT_BUILT, 0); circuit_event_status(circ, CIRC_EVENT_BUILT, 0);
/* Remember that this circuit has finished building. Now if we start /* Remember that this circuit has finished building. Now if we start
@ -2212,7 +2214,7 @@ circuit_launch_by_extend_info(uint8_t purpose,
return NULL; return NULL;
} }
tor_trace(circuit, cannibalized, circ); tor_trace(TR_SUBSYS(circuit), TR_EV(cannibalized), circ);
return circ; return circ;
} }
} }
@ -3144,7 +3146,8 @@ circuit_change_purpose(circuit_t *circ, uint8_t new_purpose)
old_purpose = circ->purpose; old_purpose = circ->purpose;
circ->purpose = new_purpose; circ->purpose = new_purpose;
tor_trace(circuit, change_purpose, circ, old_purpose, new_purpose); tor_trace(TR_SUBSYS(circuit), TR_EV(change_purpose), circ, old_purpose,
new_purpose);
if (CIRCUIT_IS_ORIGIN(circ)) { if (CIRCUIT_IS_ORIGIN(circ)) {
control_event_circuit_purpose_changed(TO_ORIGIN_CIRCUIT(circ), control_event_circuit_purpose_changed(TO_ORIGIN_CIRCUIT(circ),

View File

@ -10,7 +10,7 @@
#ifndef TOR_TRACE_PROBES_CIRCUIT_H #ifndef TOR_TRACE_PROBES_CIRCUIT_H
#define TOR_TRACE_PROBES_CIRCUIT_H #define TOR_TRACE_PROBES_CIRCUIT_H
#include "orconfig.h" #include "lib/trace/events.h"
/* We only build the following if LTTng instrumentation has been enabled. */ /* We only build the following if LTTng instrumentation has been enabled. */
#ifdef USE_TRACING_INSTRUMENTATION_LTTNG #ifdef USE_TRACING_INSTRUMENTATION_LTTNG

View File

@ -9,6 +9,8 @@
#ifndef TOR_LIB_TRACE_EVENTS_H #ifndef TOR_LIB_TRACE_EVENTS_H
#define TOR_LIB_TRACE_EVENTS_H #define TOR_LIB_TRACE_EVENTS_H
#include "orconfig.h"
/* /*
* A tracepoint signature is defined as follow: * A tracepoint signature is defined as follow:
* *
@ -34,13 +36,22 @@
* enabling this instrumentation provides both probes. * enabling this instrumentation provides both probes.
*/ */
/** 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 #ifdef HAVE_TRACING
#define tor_trace(subsystem, event_name, ...) \ #define tor_trace(subsystem, event_name, ...) \
do { \ do { \
TOR_TRACE_LOG_DEBUG(tor_ ## subsystem, event_name); \ TOR_TRACE_LOG_DEBUG(subsystem, event_name); \
TOR_TRACE_USDT(tor_ ## subsystem, event_name, ## __VA_ARGS__); \ TOR_TRACE_USDT(subsystem, event_name, ## __VA_ARGS__); \
TOR_TRACE_LTTNG(tor_ ## subsystem, event_name, ## __VA_ARGS__); \ TOR_TRACE_LTTNG(subsystem, event_name, ## __VA_ARGS__); \
} while (0) } while (0)
/* This corresponds to the --enable-tracing-instrumentation-log-debug /* This corresponds to the --enable-tracing-instrumentation-log-debug