nihilist/tor
1
0
Fork 0
mirror of https://gitlab.torproject.org/tpo/core/tor.git synced 2024-11-10 21:23:58 +01:00
Code Issues Packages Projects Releases Wiki Activity

Improve logging around the circpad module..

Browse Source 
- Add some more useful logs for future debugging.

- Stop usage of circpad_state_to_string(). It's innacurate.

- Reduce severity and fix up log domain of some logging messages.
This commit is contained in:
George Kadianakis 2019-03-28 15:38:33 +02:00
parent 953dc601d9
commit 42ea3a416e
2 changed files with 32 additions and 46 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

70
src/core/or/circuitpadding.c
View File

@ -131,34 +131,6 @@ STATIC smartlist_t *relay_padding_machines = NULL;
continue; continue;
#define FOR_EACH_ACTIVE_CIRCUIT_MACHINE_END } STMT_END ; #define FOR_EACH_ACTIVE_CIRCUIT_MACHINE_END } STMT_END ;
/**
* Return a human-readable description for a circuit padding state.
*/
static const char *
circpad_state_to_string(circpad_statenum_t state)
{
const char *descr;
switch (state) {
case CIRCPAD_STATE_START:
descr = "START";
break;
case CIRCPAD_STATE_BURST:
descr = "BURST";
break;
case CIRCPAD_STATE_GAP:
descr = "GAP";
break;
case CIRCPAD_STATE_END:
descr = "END";
break;
default:
descr = "CUSTOM"; // XXX: Just return # in static char buf?
}
return descr;
}
/** /**
* Free the machineinfo at an index * Free the machineinfo at an index
*/ */
@ -540,6 +512,8 @@ circpad_choose_state_length(circpad_machine_runtime_t *mi)
} }
mi->state_length = clamp_double_to_int64(length); mi->state_length = clamp_double_to_int64(length);
log_info(LD_CIRC, "State length sampled to %"PRIu64".", mi->state_length);
} }
/** /**
@ -914,7 +888,7 @@ circpad_machine_remove_closest_token(circpad_machine_runtime_t *mi,
bin_to_remove = lower; bin_to_remove = lower;
} }
mi->histogram[bin_to_remove]--; mi->histogram[bin_to_remove]--;
log_debug(LD_GENERAL, "Removing token from bin %d", bin_to_remove); log_debug(LD_CIRC, "Removing token from bin %d", bin_to_remove);
return; return;
} else { } else {
if (current - lower > higher - current) { if (current - lower > higher - current) {
@ -1224,14 +1198,16 @@ circpad_send_padding_cell_for_callback(circpad_machine_runtime_t *mi)
circpad_send_command_to_hop(TO_ORIGIN_CIRCUIT(mi->on_circ), circpad_send_command_to_hop(TO_ORIGIN_CIRCUIT(mi->on_circ),
CIRCPAD_GET_MACHINE(mi)->target_hopnum, CIRCPAD_GET_MACHINE(mi)->target_hopnum,
RELAY_COMMAND_DROP, NULL, 0); RELAY_COMMAND_DROP, NULL, 0);
log_fn(LOG_INFO,LD_CIRC, "Callback: Sending padding to origin circuit %u.", log_info(LD_CIRC, "Callback: Sending padding to origin circuit %u"
TO_ORIGIN_CIRCUIT(mi->on_circ)->global_identifier); " (%d) [length: %"PRIu64"]",
TO_ORIGIN_CIRCUIT(mi->on_circ)->global_identifier,
mi->on_circ->purpose, mi->state_length);
} else { } else {
// If we're a non-origin circ, we can just send from here as if we're the // If we're a non-origin circ, we can just send from here as if we're the
// edge. // edge.
if (TO_OR_CIRCUIT(circ)->p_chan_cells.n <= circpad_max_circ_queued_cells) { if (TO_OR_CIRCUIT(circ)->p_chan_cells.n <= circpad_max_circ_queued_cells) {
log_fn(LOG_INFO,LD_CIRC, log_info(LD_CIRC, "Callback: Sending padding to circuit (%d)"
"Callback: Sending padding to non-origin circuit."); " [length: %"PRIu64"]", mi->on_circ->purpose, mi->state_length);
relay_send_command_from_edge(0, mi->on_circ, RELAY_COMMAND_DROP, NULL, relay_send_command_from_edge(0, mi->on_circ, RELAY_COMMAND_DROP, NULL,
0, NULL); 0, NULL);
rep_hist_padding_count_write(PADDING_TYPE_DROP); rep_hist_padding_count_write(PADDING_TYPE_DROP);
@ -1599,9 +1575,8 @@ circpad_machine_spec_transition,(circpad_machine_runtime_t *mi,
* a transition to itself. All non-specified events are ignored. * a transition to itself. All non-specified events are ignored.
*/ */
log_fn(LOG_INFO, LD_CIRC, log_fn(LOG_INFO, LD_CIRC,
"Circpad machine %d transitioning from %s to %s", "Circpad machine %d transitioning from %u to %u",
mi->machine_index, circpad_state_to_string(mi->current_state), mi->machine_index, mi->current_state, s);
circpad_state_to_string(s));
/* If this is not the same state, switch and init tokens, /* If this is not the same state, switch and init tokens,
* otherwise just reschedule padding. */ * otherwise just reschedule padding. */
@ -2096,6 +2071,7 @@ circpad_add_matching_machines(origin_circuit_t *on_circ,
if (circpad_negotiate_padding(on_circ, machine->machine_num, if (circpad_negotiate_padding(on_circ, machine->machine_num,
machine->target_hopnum, machine->target_hopnum,
CIRCPAD_COMMAND_START) < 0) { CIRCPAD_COMMAND_START) < 0) {
log_info(LD_CIRC, "Padding not negotiated. Cleaning machine");
circpad_circuit_machineinfo_free_idx(circ, i); circpad_circuit_machineinfo_free_idx(circ, i);
circ->padding_machine[i] = NULL; circ->padding_machine[i] = NULL;
on_circ->padding_negotiation_failed = 1; on_circ->padding_negotiation_failed = 1;
@ -2369,6 +2345,16 @@ circpad_setup_machine_on_circ(circuit_t *on_circ,
== NULL); == NULL);
tor_assert_nonfatal(on_circ->padding_info[machine->machine_index] == NULL); tor_assert_nonfatal(on_circ->padding_info[machine->machine_index] == NULL);
/* Log message */
if (CIRCUIT_IS_ORIGIN(on_circ)) {
log_info(LD_CIRC, "Registering machine %s to origin circ %u (%d)",
machine->name,
TO_ORIGIN_CIRCUIT(on_circ)->global_identifier, on_circ->purpose);
} else {
log_info(LD_CIRC, "Registering machine %s to non-origin circ (%d)",
machine->name, on_circ->purpose);
}
on_circ->padding_info[machine->machine_index] = on_circ->padding_info[machine->machine_index] =
circpad_circuit_machineinfo_new(on_circ, machine->machine_index); circpad_circuit_machineinfo_new(on_circ, machine->machine_index);
on_circ->padding_machine[machine->machine_index] = machine; on_circ->padding_machine[machine->machine_index] = machine;
@ -2389,7 +2375,7 @@ padding_machine_state_is_valid(const circpad_state_t *state)
/* We need at least two bins in a histogram */ /* We need at least two bins in a histogram */
if (state->histogram_len < 2) { if (state->histogram_len < 2) {
log_warn(LD_GENERAL, "You can't have a histogram with less than 2 bins"); log_warn(LD_CIRC, "You can't have a histogram with less than 2 bins");
return false; return false;
} }
@ -2399,7 +2385,7 @@ padding_machine_state_is_valid(const circpad_state_t *state)
/* Check that histogram edges are strictly increasing. Ignore the first /* Check that histogram edges are strictly increasing. Ignore the first
* edge since it can be zero. */ * edge since it can be zero. */
if (prev_bin_edge >= state->histogram_edges[b] && b > 0) { if (prev_bin_edge >= state->histogram_edges[b] && b > 0) {
log_warn(LD_GENERAL, "Histogram edges are not increasing [%u/%u]", log_warn(LD_CIRC, "Histogram edges are not increasing [%u/%u]",
prev_bin_edge, state->histogram_edges[b]); prev_bin_edge, state->histogram_edges[b]);
return false; return false;
} }
@ -2411,7 +2397,7 @@ padding_machine_state_is_valid(const circpad_state_t *state)
} }
/* Verify that the total number of tokens is correct */ /* Verify that the total number of tokens is correct */
if (tokens_count != state->histogram_total_tokens) { if (tokens_count != state->histogram_total_tokens) {
log_warn(LD_GENERAL, "Histogram token count is wrong [%u/%u]", log_warn(LD_CIRC, "Histogram token count is wrong [%u/%u]",
tokens_count, state->histogram_total_tokens); tokens_count, state->histogram_total_tokens);
return false; return false;
} }
@ -2442,7 +2428,7 @@ circpad_register_padding_machine(circpad_machine_spec_t *machine,
smartlist_t *machine_list) smartlist_t *machine_list)
{ {
if (!padding_machine_is_valid(machine)) { if (!padding_machine_is_valid(machine)) {
log_warn(LD_GENERAL, "Machine #%u is invalid. Ignoring.", log_warn(LD_CIRC, "Machine #%u is invalid. Ignoring.",
machine->machine_num); machine->machine_num);
return; return;
} }
@ -2748,8 +2734,8 @@ circpad_negotiate_padding(origin_circuit_t *circ,
&type)) < 0) &type)) < 0)
return -1; return -1;
log_fn(LOG_INFO,LD_CIRC, "Negotiating padding on circuit %u", log_fn(LOG_INFO,LD_CIRC, "Negotiating padding on circuit %u (%d)",
circ->global_identifier); circ->global_identifier, TO_CIRCUIT(circ)->purpose);
return circpad_send_command_to_hop(circ, target_hopnum, return circpad_send_command_to_hop(circ, target_hopnum,
RELAY_COMMAND_PADDING_NEGOTIATE, RELAY_COMMAND_PADDING_NEGOTIATE,

8
src/core/or/circuitpadding_machines.c
View File

@ -212,7 +212,7 @@ circpad_machine_client_hide_intro_circuits(smartlist_t *machines_sl)
client_machine->machine_num = smartlist_len(machines_sl); client_machine->machine_num = smartlist_len(machines_sl);
circpad_register_padding_machine(client_machine, machines_sl); circpad_register_padding_machine(client_machine, machines_sl);
log_warn(LD_GENERAL, log_info(LD_CIRC,
"Registered client intro point hiding padding machine (%u)", "Registered client intro point hiding padding machine (%u)",
client_machine->machine_num); client_machine->machine_num);
} }
@ -253,7 +253,7 @@ circpad_machine_relay_hide_intro_circuits(smartlist_t *machines_sl)
relay_machine->machine_num = smartlist_len(machines_sl); relay_machine->machine_num = smartlist_len(machines_sl);
circpad_register_padding_machine(relay_machine, machines_sl); circpad_register_padding_machine(relay_machine, machines_sl);
log_warn(LD_GENERAL, log_info(LD_CIRC,
"Registered relay intro circuit hiding padding machine (%u)", "Registered relay intro circuit hiding padding machine (%u)",
relay_machine->machine_num); relay_machine->machine_num);
} }
@ -374,7 +374,7 @@ circpad_machine_client_hide_rend_circuits(smartlist_t *machines_sl)
client_machine->machine_num = smartlist_len(machines_sl); client_machine->machine_num = smartlist_len(machines_sl);
circpad_register_padding_machine(client_machine, machines_sl); circpad_register_padding_machine(client_machine, machines_sl);
log_warn(LD_GENERAL, log_info(LD_CIRC,
"Registered client rendezvous circuit hiding padding machine (%u)", "Registered client rendezvous circuit hiding padding machine (%u)",
client_machine->machine_num); client_machine->machine_num);
} }
@ -412,7 +412,7 @@ circpad_machine_relay_hide_rend_circuits(smartlist_t *machines_sl)
relay_machine->machine_num = smartlist_len(machines_sl); relay_machine->machine_num = smartlist_len(machines_sl);
circpad_register_padding_machine(relay_machine, machines_sl); circpad_register_padding_machine(relay_machine, machines_sl);
log_warn(LD_GENERAL, log_info(LD_CIRC,
"Registered relay rendezvous circuit hiding padding machine (%u)", "Registered relay rendezvous circuit hiding padding machine (%u)",
relay_machine->machine_num); relay_machine->machine_num);
} }