From b95dd03e5f6505ce2e78fe34a20bf5e5c970e6eb Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Sun, 15 May 2011 21:58:46 -0400 Subject: Log descriptions of nodes, not just nicknames. This patch introduces a few new functions in router.c to produce a more helpful description of a node than its nickame, and then tweaks nearly all log messages taking a nickname as an argument to call these functions instead. There are a few cases where I left the old log messages alone: in these cases, the nickname was that of an authority (whose nicknames are useful and unique), or the message already included an identity and/or an address. I might have missed a couple more too. This is a fix for bug 3045. --- src/or/circuitbuild.c | 43 +++++++++------- src/or/circuitlist.c | 6 ++- src/or/circuituse.c | 4 +- src/or/command.c | 4 +- src/or/connection_edge.c | 7 +-- src/or/directory.c | 9 ++-- src/or/dirserv.c | 45 ++++++++++------- src/or/relay.c | 5 +- src/or/rendclient.c | 19 ++++--- src/or/rendservice.c | 31 +++++++----- src/or/rephist.c | 6 ++- src/or/router.c | 127 +++++++++++++++++++++++++++++++++++++++++++++++ src/or/router.h | 15 ++++++ src/or/routerlist.c | 36 +++++++------- src/or/routerparse.c | 5 +- 15 files changed, 269 insertions(+), 93 deletions(-) diff --git a/src/or/circuitbuild.c b/src/or/circuitbuild.c index 860cd27567..469e180072 100644 --- a/src/or/circuitbuild.c +++ b/src/or/circuitbuild.c @@ -1753,10 +1753,9 @@ circuit_handle_first_hop(origin_circuit_t *circ) if (!n_conn) { /* not currently connected in a useful way. */ - const char *name = strlen(firsthop->extend_info->nickname) ? - firsthop->extend_info->nickname : fmt_addr(&firsthop->extend_info->addr); log_info(LD_CIRC, "Next router is %s: %s ", - safe_str_client(name), msg?msg:"???"); + safe_str_client(extend_info_describe(firsthop->extend_info)), + msg?msg:"???"); circ->_base.n_hop = extend_info_dup(firsthop->extend_info); if (should_launch) { @@ -2039,7 +2038,7 @@ circuit_send_next_onion_skin(origin_circuit_t *circ) circuit_set_state(TO_CIRCUIT(circ), CIRCUIT_STATE_BUILDING); log_info(LD_CIRC,"First hop: finished sending %s cell to '%s'", fast ? "CREATE_FAST" : "CREATE", - router ? router->nickname : ""); + router ? router_describe(router) : ""); } else { tor_assert(circ->cpath->state == CPATH_STATE_OPEN); tor_assert(circ->_base.state == CIRCUIT_STATE_BUILDING); @@ -2829,7 +2828,7 @@ choose_good_exit_server_general(routerlist_t *dir, int need_uptime, tor_free(n_supported); if (router) { - log_info(LD_CIRC, "Chose exit server '%s'", router->nickname); + log_info(LD_CIRC, "Chose exit server '%s'", router_describe(router)); return router; } if (options->ExitNodes) { @@ -2936,7 +2935,7 @@ warn_if_last_router_excluded(origin_circuit_t *circ, const extend_info_t *exit) log_warn(LD_BUG, "Using %s '%s' which is listed in ExcludeNodes%s, " "even though StrictNodes is set. Please report. " "(Circuit purpose: %s)", - description, exit->nickname, + description, extend_info_describe(exit), rs==options->ExcludeNodes?"":" or ExcludeExitNodes", circuit_purpose_to_string(purpose)); } else { @@ -2945,7 +2944,7 @@ warn_if_last_router_excluded(origin_circuit_t *circ, const extend_info_t *exit) "prevent this (and possibly break your Tor functionality), " "set the StrictNodes configuration option. " "(Circuit purpose: %s)", - description, exit->nickname, + description, extend_info_describe(exit), rs==options->ExcludeNodes?"":" or ExcludeExitNodes", circuit_purpose_to_string(purpose)); } @@ -2976,7 +2975,8 @@ onion_pick_cpath_exit(origin_circuit_t *circ, extend_info_t *exit) if (exit) { /* the circuit-builder pre-requested one */ warn_if_last_router_excluded(circ, exit); - log_info(LD_CIRC,"Using requested exit node '%s'", exit->nickname); + log_info(LD_CIRC,"Using requested exit node '%s'", + extend_info_describe(exit)); exit = extend_info_dup(exit); } else { /* we have to decide one */ routerinfo_t *router = @@ -3025,8 +3025,8 @@ circuit_extend_to_new_exit(origin_circuit_t *circ, extend_info_t *exit) circuit_append_new_exit(circ, exit); circuit_set_state(TO_CIRCUIT(circ), CIRCUIT_STATE_BUILDING); if ((err_reason = circuit_send_next_onion_skin(circ))<0) { - log_warn(LD_CIRC, "Couldn't extend circuit to new point '%s'.", - exit->nickname); + log_warn(LD_CIRC, "Couldn't extend circuit to new point %s.", + extend_info_describe(exit)); circuit_mark_for_close(TO_CIRCUIT(circ), -err_reason); return -1; } @@ -3250,7 +3250,8 @@ onion_extend_cpath(origin_circuit_t *circ) } log_debug(LD_CIRC,"Chose router %s for hop %d (exit is %s)", - info->nickname, cur_len+1, build_state_get_exit_nickname(state)); + extend_info_describe(info), + cur_len+1, build_state_get_exit_nickname(state)); onion_append_hop(&circ->cpath, info); extend_info_free(info); @@ -3526,20 +3527,24 @@ log_entry_guards(int severity) smartlist_t *elements = smartlist_create(); char *s; - SMARTLIST_FOREACH(entry_guards, entry_guard_t *, e, + SMARTLIST_FOREACH_BEGIN(entry_guards, entry_guard_t *, e) { const char *msg = NULL; char *cp; if (entry_is_live(e, 0, 1, 0, &msg)) - tor_asprintf(&cp, "%s (up %s)", + tor_asprintf(&cp, "%s [%s] (up %s)", e->nickname, + hex_str(e->identity, DIGEST_LEN), e->made_contact ? "made-contact" : "never-contacted"); else - tor_asprintf(&cp, "%s (%s, %s)", - e->nickname, msg, + tor_asprintf(&cp, "%s [%s] (%s, %s)", + e->nickname, + hex_str(e->identity, DIGEST_LEN), + msg, e->made_contact ? "made-contact" : "never-contacted"); smartlist_add(elements, cp); - }); + } + SMARTLIST_FOREACH_END(e); s = smartlist_join_strings(elements, ",", 0, NULL); SMARTLIST_FOREACH(elements, char*, cp, tor_free(cp)); @@ -3607,7 +3612,8 @@ add_an_entry_guard(routerinfo_t *chosen, int reset_status) return NULL; } entry = tor_malloc_zero(sizeof(entry_guard_t)); - log_info(LD_CIRC, "Chose '%s' as new entry guard.", router->nickname); + log_info(LD_CIRC, "Chose '%s' as new entry guard.", + router_describe(router)); strlcpy(entry->nickname, router->nickname, sizeof(entry->nickname)); memcpy(entry->identity, router->cache_info.identity_digest, DIGEST_LEN); /* Choose expiry time smudged over the past month. The goal here @@ -3800,8 +3806,9 @@ entry_guards_compute_status(or_options_t *options, time_t now) const char *reason = digestmap_get(reasons, entry->identity); const char *live_msg = ""; routerinfo_t *r = entry_is_live(entry, 0, 1, 0, &live_msg); - log_info(LD_CIRC, "Summary: Entry '%s' is %s, %s%s%s, and %s%s.", + log_info(LD_CIRC, "Summary: Entry %s [%s] is %s, %s%s%s, and %s%s.", entry->nickname, + hex_str(entry->identity, DIGEST_LEN), entry->unreachable_since ? "unreachable" : "reachable", entry->bad_since ? "unusable" : "usable", reason ? ", ": "", diff --git a/src/or/circuitlist.c b/src/or/circuitlist.c index 8ec46186d9..4ad244dfda 100644 --- a/src/or/circuitlist.c +++ b/src/or/circuitlist.c @@ -274,8 +274,10 @@ circuit_count_pending_on_or_conn(or_connection_t *or_conn) circuit_get_all_pending_on_or_conn(sl, or_conn); cnt = smartlist_len(sl); smartlist_free(sl); - log_debug(LD_CIRC,"or_conn to %s, %d pending circs", - or_conn->nickname ? or_conn->nickname : "NULL", cnt); + log_debug(LD_CIRC,"or_conn to %s at %s, %d pending circs", + or_conn->nickname ? or_conn->nickname : "NULL", + or_conn->_base.address, + cnt); return cnt; } diff --git a/src/or/circuituse.c b/src/or/circuituse.c index 7289aa5c11..4c29bf8359 100644 --- a/src/or/circuituse.c +++ b/src/or/circuituse.c @@ -1335,8 +1335,8 @@ circuit_get_open_circ_or_launch(edge_connection_t *conn, conn->_base.state = AP_CONN_STATE_RENDDESC_WAIT; return 0; } - log_info(LD_REND,"Chose '%s' as intro point for '%s'.", - extend_info->nickname, + log_info(LD_REND,"Chose %s as intro point for '%s'.", + extend_info_describe(extend_info), safe_str_client(conn->rend_data->onion_address)); } diff --git a/src/or/command.c b/src/or/command.c index 00d9af33fa..d25918b841 100644 --- a/src/or/command.c +++ b/src/or/command.c @@ -274,8 +274,8 @@ command_process_create_cell(cell_t *cell, or_connection_t *conn) cell->circ_id, (int)(time(NULL) - conn->_base.timestamp_created)); if (router) log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, - "Details: nickname \"%s\", platform %s.", - router->nickname, escaped(router->platform)); + "Details: router %s, platform %s.", + router_describe(router), escaped(router->platform)); return; } diff --git a/src/or/connection_edge.c b/src/or/connection_edge.c index 7828f16386..78b1b92de9 100644 --- a/src/or/connection_edge.c +++ b/src/or/connection_edge.c @@ -503,12 +503,12 @@ connection_ap_expire_beginning(void) } tor_assert(circ->purpose == CIRCUIT_PURPOSE_C_GENERAL); log_fn(cutoff < 15 ? LOG_INFO : severity, LD_APP, - "We tried for %d seconds to connect to '%s' using exit '%s'." + "We tried for %d seconds to connect to '%s' using exit %s." " Retrying on a new circuit.", seconds_idle, safe_str_client(conn->socks_request->address), conn->cpath_layer ? - conn->cpath_layer->extend_info->nickname : "*unnamed*"); + extend_info_describe(conn->cpath_layer->extend_info): "*unnamed*"); /* send an end down the circuit */ connection_edge_end(conn, END_STREAM_REASON_TIMEOUT); /* un-mark it as ending, since we're going to reuse it */ @@ -1830,7 +1830,8 @@ connection_ap_handshake_rewrite_and_attach(edge_connection_t *conn, if (r) { log_info(LD_APP, "Redirecting address %s to exit at enclave router %s", - safe_str_client(socks->address), r->nickname); + safe_str_client(socks->address), + router_describe(r)); /* use the hex digest, not nickname, in case there are two routers with this nickname */ conn->chosen_exit_name = diff --git a/src/or/directory.c b/src/or/directory.c index 347ed42cb8..b238be2abc 100644 --- a/src/or/directory.c +++ b/src/or/directory.c @@ -525,8 +525,9 @@ directory_initiate_command_routerstatus_rend(routerstatus_t *status, router = router_get_by_digest(status->identity_digest); if (!router && anonymized_connection) { - log_info(LD_DIR, "Not sending anonymized request to directory '%s'; we " - "don't have its router descriptor.", status->nickname); + log_info(LD_DIR, "Not sending anonymized request to directory %s; we " + "don't have its router descriptor.", + routerstatus_describe(status)); return; } else if (router) { address = router->address; @@ -539,10 +540,10 @@ directory_initiate_command_routerstatus_rend(routerstatus_t *status, if (options->ExcludeNodes && options->StrictNodes && routerset_contains_routerstatus(options->ExcludeNodes, status)) { - log_warn(LD_DIR, "Wanted to contact directory mirror '%s' for %s, but " + log_warn(LD_DIR, "Wanted to contact directory mirror %s for %s, but " "it's in our ExcludedNodes list and StrictNodes is set. " "Skipping. This choice might make your Tor not work.", - status->nickname, + routerstatus_describe(status), dir_conn_purpose_to_string(dir_purpose)); return; } diff --git a/src/or/dirserv.c b/src/or/dirserv.c index 79b68cdac8..e9355fedb4 100644 --- a/src/or/dirserv.c +++ b/src/or/dirserv.c @@ -518,14 +518,15 @@ dirserv_router_has_valid_address(routerinfo_t *ri) if (get_options()->DirAllowPrivateAddresses) return 0; /* whatever it is, we're fine with it */ if (!tor_inet_aton(ri->address, &iaddr)) { - log_info(LD_DIRSERV,"Router '%s' published non-IP address '%s'. Refusing.", - ri->nickname, ri->address); + log_info(LD_DIRSERV,"Router %s published non-IP address '%s'. Refusing.", + router_describe(ri), + ri->address); return -1; } if (is_internal_IP(ntohl(iaddr.s_addr), 0)) { log_info(LD_DIRSERV, - "Router '%s' published internal IP address '%s'. Refusing.", - ri->nickname, ri->address); + "Router %s published internal IP address '%s'. Refusing.", + router_describe(ri), ri->address); return -1; /* it's a private IP, we should reject it */ } return 0; @@ -554,10 +555,11 @@ authdir_wants_to_reject_router(routerinfo_t *ri, const char **msg, /* Is there too much clock skew? */ now = time(NULL); if (ri->cache_info.published_on > now+ROUTER_ALLOW_SKEW) { - log_fn(severity, LD_DIRSERV, "Publication time for nickname '%s' is too " + log_fn(severity, LD_DIRSERV, "Publication time for %s is too " "far (%d minutes) in the future; possible clock skew. Not adding " "(%s)", - ri->nickname, (int)((ri->cache_info.published_on-now)/60), + router_describe(ri), + (int)((ri->cache_info.published_on-now)/60), esc_router_info(ri)); *msg = "Rejected: Your clock is set too far in the future, or your " "timezone is not correct."; @@ -565,9 +567,10 @@ authdir_wants_to_reject_router(routerinfo_t *ri, const char **msg, } if (ri->cache_info.published_on < now-ROUTER_MAX_AGE_TO_PUBLISH) { log_fn(severity, LD_DIRSERV, - "Publication time for router with nickname '%s' is too far " + "Publication time for %s is too far " "(%d minutes) in the past. Not adding (%s)", - ri->nickname, (int)((now-ri->cache_info.published_on)/60), + router_describe(ri), + (int)((now-ri->cache_info.published_on)/60), esc_router_info(ri)); *msg = "Rejected: Server is expired, or your clock is too far in the past," " or your timezone is not correct."; @@ -575,9 +578,10 @@ authdir_wants_to_reject_router(routerinfo_t *ri, const char **msg, } if (dirserv_router_has_valid_address(ri) < 0) { log_fn(severity, LD_DIRSERV, - "Router with nickname '%s' has invalid address '%s'. " + "Router %s has invalid address '%s'. " "Not adding (%s).", - ri->nickname, ri->address, + router_describe(ri), + ri->address, esc_router_info(ri)); *msg = "Rejected: Address is not an IP, or IP is a private address."; return -1; @@ -720,9 +724,9 @@ dirserv_add_descriptor(routerinfo_t *ri, const char **msg, const char *source) && router_differences_are_cosmetic(ri_old, ri) && !router_is_me(ri)) { log_info(LD_DIRSERV, - "Not replacing descriptor from '%s' (source: %s); " + "Not replacing descriptor from %s (source: %s); " "differences are cosmetic.", - ri->nickname, source); + router_describe(ri), source); *msg = "Not replacing router descriptor; no information has changed since " "the last one with this identity."; control_event_or_authdir_new_descriptor("DROPPED", @@ -824,10 +828,12 @@ directory_remove_invalid(void) for (i = 0; i < smartlist_len(rl->routers); ++i) { const char *msg; routerinfo_t *ent = smartlist_get(rl->routers, i); + char description[NODE_DESC_BUF_LEN]; uint32_t r = dirserv_router_get_status(ent, &msg); + router_get_description(description, ent); if (r & FP_REJECT) { - log_info(LD_DIRSERV, "Router '%s' is now rejected: %s", - ent->nickname, msg?msg:""); + log_info(LD_DIRSERV, "Router %s is now rejected: %s", + description, msg?msg:""); routerlist_remove(rl, ent, 0, time(NULL)); i--; changed = 1; @@ -835,25 +841,25 @@ directory_remove_invalid(void) } if (bool_neq((r & FP_NAMED), ent->is_named)) { log_info(LD_DIRSERV, - "Router '%s' is now %snamed.", ent->nickname, + "Router %s is now %snamed.", description, (r&FP_NAMED)?"":"un"); ent->is_named = (r&FP_NAMED)?1:0; changed = 1; } if (bool_neq((r & FP_INVALID), !ent->is_valid)) { - log_info(LD_DIRSERV, "Router '%s' is now %svalid.", ent->nickname, + log_info(LD_DIRSERV, "Router '%s' is now %svalid.", description, (r&FP_INVALID) ? "in" : ""); ent->is_valid = (r&FP_INVALID)?0:1; changed = 1; } if (bool_neq((r & FP_BADDIR), ent->is_bad_directory)) { - log_info(LD_DIRSERV, "Router '%s' is now a %s directory", ent->nickname, + log_info(LD_DIRSERV, "Router '%s' is now a %s directory", description, (r & FP_BADDIR) ? "bad" : "good"); ent->is_bad_directory = (r&FP_BADDIR) ? 1: 0; changed = 1; } if (bool_neq((r & FP_BADEXIT), ent->is_bad_exit)) { - log_info(LD_DIRSERV, "Router '%s' is now a %s exit", ent->nickname, + log_info(LD_DIRSERV, "Router '%s' is now a %s exit", description, (r & FP_BADEXIT) ? "bad" : "good"); ent->is_bad_exit = (r&FP_BADEXIT) ? 1: 0; changed = 1; @@ -3163,7 +3169,8 @@ dirserv_orconn_tls_done(const char *address, if (!bridge_auth || ri->purpose == ROUTER_PURPOSE_BRIDGE) { tor_addr_t addr, *addrp=NULL; log_info(LD_DIRSERV, "Found router %s to be reachable at %s:%d. Yay.", - ri->nickname, address, ri->or_port ); + router_describe(ri), + address, ri->or_port); if (tor_addr_from_str(&addr, ri->address) != -1) addrp = &addr; else diff --git a/src/or/relay.c b/src/or/relay.c index 9effae3036..46e852217d 100644 --- a/src/or/relay.c +++ b/src/or/relay.c @@ -28,6 +28,7 @@ #include "reasons.h" #include "relay.h" #include "rendcommon.h" +#include "router.h" #include "routerlist.h" #include "routerparse.h" @@ -749,9 +750,9 @@ connection_ap_process_end_not_open( (tor_inet_aton(conn->socks_request->address, &in) && !conn->chosen_exit_name))) { log_info(LD_APP, - "Exitrouter '%s' seems to be more restrictive than its exit " + "Exitrouter %s seems to be more restrictive than its exit " "policy. Not using this router as exit for now.", - exitrouter->nickname); + router_describe(exitrouter)); policies_set_router_exitpolicy_to_reject_all(exitrouter); } /* rewrite it to an IP if we learned one. */ diff --git a/src/or/rendclient.c b/src/or/rendclient.c index 77e11c2a07..af6f43aa28 100644 --- a/src/or/rendclient.c +++ b/src/or/rendclient.c @@ -20,6 +20,7 @@ #include "rendclient.h" #include "rendcommon.h" #include "rephist.h" +#include "router.h" #include "routerlist.h" static extend_info_t *rend_client_get_random_intro_impl( @@ -90,12 +91,13 @@ rend_client_reextend_intro_circuit(origin_circuit_t *circ) if (circ->remaining_relay_early_cells) { log_info(LD_REND, "Re-extending circ %d, this time to %s.", - circ->_base.n_circ_id, extend_info->nickname); + circ->_base.n_circ_id, + safe_str_client(extend_info_describe(extend_info))); result = circuit_extend_to_new_exit(circ, extend_info); } else { log_info(LD_REND, "Building a new introduction circuit, this time to %s.", - extend_info->nickname); + safe_str_client(extend_info_describe(extend_info))); circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_FINISHED); if (!circuit_launch_by_extend_info(CIRCUIT_PURPOSE_C_INTRODUCING, extend_info, @@ -168,7 +170,8 @@ rend_client_send_introduction(origin_circuit_t *introcirc, "have a v2 rend desc with %d intro points. " "Trying a different intro point...", safe_str_client(introcirc->rend_data->onion_address), - introcirc->build_state->chosen_exit->nickname, + safe_str_client(extend_info_describe( + introcirc->build_state->chosen_exit)), smartlist_len(entry->parsed->intro_nodes)); if (rend_client_reextend_intro_circuit(introcirc)) { @@ -343,8 +346,8 @@ rend_client_introduction_acked(origin_circuit_t *circ, * If none remain, refetch the service descriptor. */ log_info(LD_REND, "Got nack for %s from %s...", - safe_str_client(circ->rend_data->onion_address), - circ->build_state->chosen_exit->nickname); + safe_str_client(circ->rend_data->onion_address), + safe_str_client(extend_info_describe(circ->build_state->chosen_exit))); if (rend_client_remove_intro_point(circ->build_state->chosen_exit, circ->rend_data) > 0) { /* There are introduction points left. Re-extend the circuit to @@ -497,12 +500,12 @@ directory_get_from_hs_dir(const char *desc_id, const rend_data_t *rend_query) log_info(LD_REND, "Sending fetch request for v2 descriptor for " "service '%s' with descriptor ID '%s', auth type %d, " "and descriptor cookie '%s' to hidden service " - "directory '%s' on port %d.", + "directory %s", rend_query->onion_address, desc_id_base32, rend_query->auth_type, (rend_query->auth_type == REND_NO_AUTH ? "[none]" : - escaped_safe_str_client(descriptor_cookie_base64)), - hs_dir->nickname, hs_dir->dir_port); + escaped_safe_str_client(descriptor_cookie_base64)), + routerstatus_describe(hs_dir)); return 1; } diff --git a/src/or/rendservice.c b/src/or/rendservice.c index 35e8b9057a..edcf59d870 100644 --- a/src/or/rendservice.c +++ b/src/or/rendservice.c @@ -474,7 +474,8 @@ rend_config_services(or_options_t *options, int validate_only) if (keep_it) continue; log_info(LD_REND, "Closing intro point %s for service %s.", - safe_str_client(oc->build_state->chosen_exit->nickname), + safe_str_client(extend_info_describe( + oc->build_state->chosen_exit)), oc->rend_data->onion_address); circuit_mark_for_close(circ, END_CIRC_REASON_FINISHED); /* XXXX Is there another reason we should use here? */ @@ -1146,7 +1147,7 @@ rend_service_introduce(origin_circuit_t *circuit, const uint8_t *request, if (!launched) { /* give up */ log_warn(LD_REND, "Giving up launching first hop of circuit to rendezvous " "point %s for service %s.", - escaped_safe_str_client(extend_info->nickname), + safe_str_client(extend_info_describe(extend_info)), serviceid); reason = END_CIRC_REASON_CONNECTFAILED; goto err; @@ -1154,7 +1155,7 @@ rend_service_introduce(origin_circuit_t *circuit, const uint8_t *request, log_info(LD_REND, "Accepted intro; launching circuit to %s " "(cookie %s) for service %s.", - escaped_safe_str_client(extend_info->nickname), + safe_str_client(extend_info_describe(extend_info)), hexcookie, serviceid); tor_assert(launched->build_state); /* Fill in the circuit's state. */ @@ -1206,7 +1207,8 @@ rend_service_relaunch_rendezvous(origin_circuit_t *oldcirc) "Attempt to build circuit to %s for rendezvous has failed " "too many times or expired; giving up.", oldcirc->build_state ? - oldcirc->build_state->chosen_exit->nickname : "*unknown*"); + safe_str(extend_info_describe(oldcirc->build_state->chosen_exit)) + : "*unknown*"); return; } @@ -1220,7 +1222,7 @@ rend_service_relaunch_rendezvous(origin_circuit_t *oldcirc) } log_info(LD_REND,"Reattempting rendezvous circuit to '%s'", - oldstate->chosen_exit->nickname); + safe_str(extend_info_describe(oldstate->chosen_exit))); newcirc = circuit_launch_by_extend_info(CIRCUIT_PURPOSE_S_CONNECT_REND, oldstate->chosen_exit, @@ -1228,7 +1230,7 @@ rend_service_relaunch_rendezvous(origin_circuit_t *oldcirc) if (!newcirc) { log_warn(LD_REND,"Couldn't relaunch rendezvous circuit to '%s'.", - oldstate->chosen_exit->nickname); + safe_str(extend_info_describe(oldstate->chosen_exit))); return; } newstate = newcirc->build_state; @@ -1252,7 +1254,7 @@ rend_service_launch_establish_intro(rend_service_t *service, log_info(LD_REND, "Launching circuit to introduction point %s for service %s", - escaped_safe_str_client(intro->extend_info->nickname), + safe_str_client(extend_info_describe(intro->extend_info)), service->service_id); rep_hist_note_used_internal(time(NULL), 1, 0); @@ -1265,7 +1267,7 @@ rend_service_launch_establish_intro(rend_service_t *service, if (!launched) { log_info(LD_REND, "Can't launch circuit to establish introduction at %s.", - escaped_safe_str_client(intro->extend_info->nickname)); + safe_str_client(extend_info_describe(intro->extend_info))); return -1; } @@ -1608,9 +1610,9 @@ directory_post_to_hs_dir(rend_service_descriptor_t *renddesc, continue; if (!router_get_by_digest(hs_dir->identity_digest)) { log_info(LD_REND, "Not sending publish request for v2 descriptor to " - "hidden service directory '%s'; we don't have its " + "hidden service directory %s; we don't have its " "router descriptor. Queuing for later upload.", - hs_dir->nickname); + safe_str_client(routerstatus_describe(hs_dir))); failed_upload = -1; continue; } @@ -1818,7 +1820,8 @@ rend_services_introduce(void) router = router_get_by_digest(intro->extend_info->identity_digest); if (!router || !find_intro_circuit(intro, service->pk_digest)) { log_info(LD_REND,"Giving up on %s as intro point for %s.", - intro->extend_info->nickname, service->service_id); + safe_str_client(extend_info_describe(intro->extend_info)), + safe_str_client(service->service_id)); if (service->desc) { SMARTLIST_FOREACH(service->desc->intro_nodes, rend_intro_point_t *, dintro, { @@ -1884,7 +1887,8 @@ rend_services_introduce(void) tor_assert(!crypto_pk_generate_key(intro->intro_key)); smartlist_add(service->intro_nodes, intro); log_info(LD_REND, "Picked router %s as an intro point for %s.", - router->nickname, service->service_id); + safe_str_client(router_describe(router)), + safe_str_client(service->service_id)); } /* If there's no need to launch new circuits, stop here. */ @@ -1897,7 +1901,8 @@ rend_services_introduce(void) r = rend_service_launch_establish_intro(service, intro); if (r<0) { log_warn(LD_REND, "Error launching circuit to node %s for service %s.", - intro->extend_info->nickname, service->service_id); + safe_str_client(extend_info_describe(intro->extend_info)), + safe_str_client(service->service_id)); } } } diff --git a/src/or/rephist.c b/src/or/rephist.c index 8cddd2b5eb..6be8484cc5 100644 --- a/src/or/rephist.c +++ b/src/or/rephist.c @@ -634,6 +634,7 @@ rep_hist_dump_stats(time_t now, int severity) digestmap_iter_t *orhist_it; const char *name1, *name2, *digest1, *digest2; char hexdigest1[HEX_DIGEST_LEN+1]; + char hexdigest2[HEX_DIGEST_LEN+1]; or_history_t *or_history; link_history_t *link_history; void *or_history_p, *link_history_p; @@ -694,7 +695,10 @@ rep_hist_dump_stats(time_t now, int severity) link_history = (link_history_t*) link_history_p; - ret = tor_snprintf(buffer+len, 2048-len, "%s(%ld/%ld); ", name2, + base16_encode(hexdigest2, sizeof(hexdigest2), digest2, DIGEST_LEN); + ret = tor_snprintf(buffer+len, 2048-len, "%s [%s](%ld/%ld); ", + name2, + hexdigest2, link_history->n_extend_ok, link_history->n_extend_ok+link_history->n_extend_fail); if (ret<0) diff --git a/src/or/router.c b/src/or/router.c index 616a290d8a..a11d3a5923 100644 --- a/src/or/router.c +++ b/src/or/router.c @@ -2217,6 +2217,133 @@ is_legal_hexdigest(const char *s) strspn(s,HEX_CHARACTERS)==HEX_DIGEST_LEN); } +/** Use buf (which must be at least NODE_DESC_BUF_LEN bytes long) to + * hold a human-readable description of a node with identity digest + * id_digest, named-status is_named, nickname nickname, + * and address addr or addr32h. + * + * The nickname and addr fields are optional and may be set to + * NULL. The addr32h field is optional and may be set to + * addr32h. + * + * Return a pointer to the front of buf. + */ +const char * +format_node_description(char *buf, + const char *id_digest, + int is_named, + const char *nickname, + const tor_addr_t *addr, + uint32_t addr32h) +{ + char *cp; + buf[0] = '$'; + base16_encode(buf+1, HEX_DIGEST_LEN+1, id_digest, DIGEST_LEN); + cp = buf+1+HEX_DIGEST_LEN; + if (nickname) { + buf[1+HEX_DIGEST_LEN] = is_named ? '=' : '~'; + strlcpy(buf+1+HEX_DIGEST_LEN+1, nickname, MAX_NICKNAME_LEN+1); + cp += strlen(cp); + } + if (addr32h || addr) { + memcpy(cp, " at ", 4); + cp += 4; + if (addr) { + tor_addr_to_str(cp, addr, TOR_ADDR_BUF_LEN, 0); + } else { + struct in_addr in; + in.s_addr = htonl(addr32h); + tor_inet_ntoa(&in, cp, INET_NTOA_BUF_LEN); + } + } + return buf; +} + +/** Use buf (which must be at least NODE_DESC_BUF_LEN bytes long) to + * hold a human-readable description of ri. + * + * + * Return a pointer to the front of buf. + */ +const char * +router_get_description(char *buf, const routerinfo_t *ri) +{ + return format_node_description(buf, + ri->cache_info.identity_digest, + ri->is_named, + ri->nickname, + NULL, + ri->addr); +} + +/** Use buf (which must be at least NODE_DESC_BUF_LEN bytes long) to + * hold a human-readable description of rs. + * + * Return a pointer to the front of buf. + */ +const char * +routerstatus_get_description(char *buf, const routerstatus_t *rs) +{ + return format_node_description(buf, + rs->identity_digest, + rs->is_named, + rs->nickname, + NULL, + rs->addr); +} + +/** Use buf (which must be at least NODE_DESC_BUF_LEN bytes long) to + * hold a human-readable description of ei. + * + * Return a pointer to the front of buf. + */ +const char * +extend_info_get_description(char *buf, const extend_info_t *ei) +{ + return format_node_description(buf, + ei->identity_digest, + 0, + ei->nickname, + &ei->addr, + 0); +} + +/** Return a human-readable description of the routerinfo_t ri. + * + * This function is not thread-safe. Each call to this function invalidates + * previous values returned by this function. + */ +const char * +router_describe(const routerinfo_t *ri) +{ + static char buf[NODE_DESC_BUF_LEN]; + return router_get_description(buf, ri); +} + +/** Return a human-readable description of the routerstatus_t rs. + * + * This function is not thread-safe. Each call to this function invalidates + * previous values returned by this function. + */ +const char * +routerstatus_describe(const routerstatus_t *rs) +{ + static char buf[NODE_DESC_BUF_LEN]; + return routerstatus_get_description(buf, rs); +} + +/** Return a human-readable description of the extend_info_t ri. + * + * This function is not thread-safe. Each call to this function invalidates + * previous values returned by this function. + */ +const char * +extend_info_describe(const extend_info_t *ei) +{ + static char buf[NODE_DESC_BUF_LEN]; + return extend_info_get_description(buf, ei); +} + /** Set buf (which must have MAX_VERBOSE_NICKNAME_LEN+1 bytes) to the * verbose representation of the identity of router. The format is: * A dollar sign. diff --git a/src/or/router.h b/src/or/router.h index 1bf1a51ae1..6cabfd56e8 100644 --- a/src/or/router.h +++ b/src/or/router.h @@ -85,6 +85,21 @@ int extrainfo_dump_to_string(char **s, extrainfo_t *extrainfo, int is_legal_nickname(const char *s); int is_legal_nickname_or_hexdigest(const char *s); int is_legal_hexdigest(const char *s); + +#define NODE_DESC_BUF_LEN (MAX_VERBOSE_NICKNAME_LEN+4+TOR_ADDR_BUF_LEN) +const char *format_node_description(char *buf, + const char *id_digest, + int is_named, + const char *nickname, + const tor_addr_t *addr, + uint32_t addr32h); +const char *router_get_description(char *buf, const routerinfo_t *ri); +const char *routerstatus_get_description(char *buf, const routerstatus_t *rs); +const char *extend_info_get_description(char *buf, const extend_info_t *ei); +const char *router_describe(const routerinfo_t *ri); +const char *routerstatus_describe(const routerstatus_t *ri); +const char *extend_info_describe(const extend_info_t *ei); + void router_get_verbose_nickname(char *buf, const routerinfo_t *router); void routerstatus_get_verbose_nickname(char *buf, const routerstatus_t *router); diff --git a/src/or/routerlist.c b/src/or/routerlist.c index a3d9b78ee7..47a57a872d 100644 --- a/src/or/routerlist.c +++ b/src/or/routerlist.c @@ -3210,8 +3210,8 @@ router_set_status(const char *digest, int up) router = router_get_by_digest(digest); if (router) { - log_debug(LD_DIR,"Marking router '%s/%s' as %s.", - router->nickname, router->address, up ? "up" : "down"); + log_debug(LD_DIR,"Marking router %s as %s.", + router_describe(router), up ? "up" : "down"); if (!up && router_is_me(router) && !we_are_hibernating()) log_warn(LD_NET, "We just marked ourself as down. Are your external " "addresses reachable?"); @@ -3283,11 +3283,12 @@ router_add_to_routerlist(routerinfo_t *router, const char **msg, router->purpose == ROUTER_PURPOSE_BRIDGE && !was_bridge) { log_info(LD_DIR, "Replacing non-bridge descriptor with bridge " - "descriptor for router '%s'", router->nickname); + "descriptor for router %s", + router_describe(router)); } else { log_info(LD_DIR, - "Dropping descriptor that we already have for router '%s'", - router->nickname); + "Dropping descriptor that we already have for router %s", + router_describe(router)); *msg = "Router descriptor was not new."; routerinfo_free(router); return ROUTER_WAS_NOT_NEW; @@ -3311,8 +3312,8 @@ router_add_to_routerlist(routerinfo_t *router, const char **msg, /* We asked for it, so some networkstatus must have listed it when we * did. Save it if we're a cache in case somebody else asks for it. */ log_info(LD_DIR, - "Received a no-longer-recognized descriptor for router '%s'", - router->nickname); + "Received a no-longer-recognized descriptor for router %s", + router_describe(router)); *msg = "Router descriptor is not referenced by any network-status."; /* Only journal this desc if we'll be serving it. */ @@ -3363,8 +3364,9 @@ router_add_to_routerlist(routerinfo_t *router, const char **msg, if (router->purpose == ROUTER_PURPOSE_BRIDGE && from_cache && !authdir_mode_bridge(options) && !routerinfo_is_a_configured_bridge(router)) { - log_info(LD_DIR, "Dropping bridge descriptor for '%s' because we have " - "no bridge configured at that address.", router->nickname); + log_info(LD_DIR, "Dropping bridge descriptor for %s because we have " + "no bridge configured at that address.", + safe_str_client(router_describe(router))); *msg = "Router descriptor was not a configured bridge."; routerinfo_free(router); return ROUTER_WAS_NOT_WANTED; @@ -3375,8 +3377,8 @@ router_add_to_routerlist(routerinfo_t *router, const char **msg, if (!in_consensus && (router->cache_info.published_on <= old_router->cache_info.published_on)) { /* Same key, but old. This one is not listed in the consensus. */ - log_debug(LD_DIR, "Not-new descriptor for router '%s'", - router->nickname); + log_debug(LD_DIR, "Not-new descriptor for router %s", + router_describe(router)); /* Only journal this desc if we'll be serving it. */ if (!from_cache && should_cache_old_descriptors()) signed_desc_append_to_journal(&router->cache_info, @@ -3386,9 +3388,8 @@ router_add_to_routerlist(routerinfo_t *router, const char **msg, return ROUTER_WAS_NOT_NEW; } else { /* Same key, and either new, or listed in the consensus. */ - log_debug(LD_DIR, "Replacing entry for router '%s/%s' [%s]", - router->nickname, old_router->nickname, - hex_str(id_digest,DIGEST_LEN)); + log_debug(LD_DIR, "Replacing entry for router %s", + router_describe(router)); if (routers_have_same_or_addr(router, old_router)) { /* these carry over when the address and orport are unchanged. */ router->last_reachable = old_router->last_reachable; @@ -3664,8 +3665,8 @@ routerlist_remove_old_routers(void) /* Too old: remove it. (If we're a cache, just move it into * old_routers.) */ log_info(LD_DIR, - "Forgetting obsolete (too old) routerinfo for router '%s'", - router->nickname); + "Forgetting obsolete (too old) routerinfo for router %s", + router_describe(router)); routerlist_remove(routerlist, router, 1, now); i--; } @@ -4585,7 +4586,8 @@ update_consensus_router_descriptor_downloads(time_t now, int is_vote, if (oldrouter) format_iso_time(time_bufold, oldrouter->cache_info.published_on); log_info(LD_DIR, "Learned about %s (%s vs %s) from %s's vote (%s)", - rs->nickname, time_bufnew, + routerstatus_describe(rs), + time_bufnew, oldrouter ? time_bufold : "none", source->nickname, oldrouter ? "known" : "unknown"); } diff --git a/src/or/routerparse.c b/src/or/routerparse.c index 389f22fd99..a877cdff84 100644 --- a/src/or/routerparse.c +++ b/src/or/routerparse.c @@ -1210,7 +1210,8 @@ router_parse_list_from_string(const char **s, const char *eos, prepend_annotations); if (router) { log_debug(LD_DIR, "Read router '%s', purpose '%s'", - router->nickname, router_purpose_to_string(router->purpose)); + router_describe(router), + router_purpose_to_string(router->purpose)); signed_desc = &router->cache_info; elt = router; } @@ -2488,7 +2489,7 @@ networkstatus_verify_bw_weights(networkstatus_t *ns) } } else { log_warn(LD_BUG, "Missing consensus bandwidth for router %s", - rs->nickname); + routerstatus_describe(rs)); } } SMARTLIST_FOREACH_END(rs); -- cgit v1.2.3-54-g00ecf From b6eee716a88cba0d0ae4be4e542f61b2d300ecec Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Sun, 15 May 2011 22:02:24 -0400 Subject: changes file for bug3045 --- changes/bug3045 | 6 ++++++ 1 file changed, 6 insertions(+) create mode 100644 changes/bug3045 diff --git a/changes/bug3045 b/changes/bug3045 new file mode 100644 index 0000000000..1cbcabaff6 --- /dev/null +++ b/changes/bug3045 @@ -0,0 +1,6 @@ + o Minor features: + - Revise most log messages that refer to nodes by nickname to + instead use the "$key=nickname at address" format. This should be + more useful, especially since nicknames are less and less likely + to be unique. Fixes bug 3045. + -- cgit v1.2.3-54-g00ecf From 3c0d944b076aa552216ca598a6cdc50e77ad1a58 Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Mon, 30 May 2011 15:15:10 -0400 Subject: Improve comments and defensive programming for 3045 The comment fixes are trivial. The defensive programming trick is to tolerate receiving NULL inputs on the describe functions. That should never actually happen, but it seems like the likeliest mistake for us to make in the future. --- src/or/router.c | 13 +++++++++++-- src/or/router.h | 7 +++++++ 2 files changed, 18 insertions(+), 2 deletions(-) diff --git a/src/or/router.c b/src/or/router.c index a11d3a5923..0bd4c55026 100644 --- a/src/or/router.c +++ b/src/or/router.c @@ -2223,8 +2223,7 @@ is_legal_hexdigest(const char *s) * and address addr or addr32h. * * The nickname and addr fields are optional and may be set to - * NULL. The addr32h field is optional and may be set to - * addr32h. + * NULL. The addr32h field is optional and may be set to 0. * * Return a pointer to the front of buf. */ @@ -2237,6 +2236,10 @@ format_node_description(char *buf, uint32_t addr32h) { char *cp; + + if (!buf) + return ""; + buf[0] = '$'; base16_encode(buf+1, HEX_DIGEST_LEN+1, id_digest, DIGEST_LEN); cp = buf+1+HEX_DIGEST_LEN; @@ -2268,6 +2271,8 @@ format_node_description(char *buf, const char * router_get_description(char *buf, const routerinfo_t *ri) { + if (!ri) + return ""; return format_node_description(buf, ri->cache_info.identity_digest, ri->is_named, @@ -2284,6 +2289,8 @@ router_get_description(char *buf, const routerinfo_t *ri) const char * routerstatus_get_description(char *buf, const routerstatus_t *rs) { + if (!rs) + return ""; return format_node_description(buf, rs->identity_digest, rs->is_named, @@ -2300,6 +2307,8 @@ routerstatus_get_description(char *buf, const routerstatus_t *rs) const char * extend_info_get_description(char *buf, const extend_info_t *ei) { + if (!ei) + return ""; return format_node_description(buf, ei->identity_digest, 0, diff --git a/src/or/router.h b/src/or/router.h index 6cabfd56e8..a285a3e773 100644 --- a/src/or/router.h +++ b/src/or/router.h @@ -86,6 +86,13 @@ int is_legal_nickname(const char *s); int is_legal_nickname_or_hexdigest(const char *s); int is_legal_hexdigest(const char *s); +/** + * Longest allowed output of format_node_description, plus 1 character for + * NUL. This allows space for: + * "$FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF~xxxxxxxxxxxxxxxxxxx at" + * " [ffff:ffff:ffff:ffff:ffff:ffff:255.255.255.255]" + * plus a terminating NUL. + */ #define NODE_DESC_BUF_LEN (MAX_VERBOSE_NICKNAME_LEN+4+TOR_ADDR_BUF_LEN) const char *format_node_description(char *buf, const char *id_digest, -- cgit v1.2.3-54-g00ecf