From 5265bbd2b8f4a28f26eabb48a4d167b765780b26 Mon Sep 17 00:00:00 2001 From: Roger Dingledine Date: Tue, 3 May 2005 10:04:08 +0000 Subject: [PATCH] first iteration of scrubbing sensitive strings from logs. also generally clean up log messages. svn:r4174 --- src/or/buffers.c | 2 +- src/or/circuitbuild.c | 3 +-- src/or/circuitlist.c | 4 ++-- src/or/circuituse.c | 16 +++++++------ src/or/command.c | 5 ++-- src/or/config.c | 22 +++++++++++++---- src/or/connection.c | 13 +++++----- src/or/connection_edge.c | 62 +++++++++++++++++++++++++++++------------------- src/or/connection_or.c | 2 +- src/or/control.c | 3 ++- src/or/dns.c | 43 +++++++++++++++++---------------- src/or/main.c | 22 +++++++++-------- src/or/or.h | 3 +++ src/or/relay.c | 6 ++--- src/or/rendclient.c | 27 ++++++++++++--------- src/or/rendcommon.c | 12 ++++++---- src/or/rendmid.c | 8 +++---- src/or/router.c | 1 - 18 files changed, 148 insertions(+), 106 deletions(-) diff --git a/src/or/buffers.c b/src/or/buffers.c index 6135923f09..aa8c7be910 100644 --- a/src/or/buffers.c +++ b/src/or/buffers.c @@ -918,7 +918,7 @@ int fetch_from_buf_socks(buf_t *buf, socks_request_t *req) { (int)strlen(tmpbuf)); return -1; } - log_fn(LOG_DEBUG,"socks4: successfully read destip (%s)", tmpbuf); + log_fn(LOG_DEBUG,"socks4: successfully read destip (%s)", safe_str(tmpbuf)); socks4_prot = socks4; } diff --git a/src/or/circuitbuild.c b/src/or/circuitbuild.c index 3734dc4b56..f2257690dc 100644 --- a/src/or/circuitbuild.c +++ b/src/or/circuitbuild.c @@ -791,8 +791,6 @@ int onionskin_answer(circuit_t *circ, uint8_t cell_type, unsigned char *payload, circ->state = CIRCUIT_STATE_OPEN; - log_fn(LOG_DEBUG,"Entering."); - memcpy(cell.payload, payload, cell_type == CELL_CREATED ? ONIONSKIN_REPLY_LEN : DIGEST_LEN*2); @@ -1497,3 +1495,4 @@ onion_append_hop(crypt_path_t **head_ptr, routerinfo_t *choice) { return 0; } + diff --git a/src/or/circuitlist.c b/src/or/circuitlist.c index 93df616922..cc1c0e517c 100644 --- a/src/or/circuitlist.c +++ b/src/or/circuitlist.c @@ -356,7 +356,7 @@ circuit_t *circuit_get_by_edge_conn(connection_t *conn) /* return NULL; */ circ = circuit_get_by_conn(conn); if (circ) { - log_fn(LOG_WARN, "BUG: conn->on_circuit==NULL, but there was in fact a circuit there. "); + log_fn(LOG_WARN, "BUG: conn->on_circuit==NULL, but there was in fact a circuit there."); } return circ; } @@ -562,7 +562,7 @@ void _circuit_mark_for_close(circuit_t *circ, int line, const char *file) tor_assert(circ->state == CIRCUIT_STATE_OPEN); /* treat this like getting a nack from it */ log_fn(LOG_INFO,"Failed intro circ %s to %s (awaiting ack). Removing from descriptor.", - circ->rend_query, circ->build_state->chosen_exit_name); + safe_str(circ->rend_query), safe_str(circ->build_state->chosen_exit_name)); rend_client_remove_intro_point(circ->build_state->chosen_exit_name, circ->rend_query); } diff --git a/src/or/circuituse.c b/src/or/circuituse.c index 5fde33d5bc..94c8dedeb0 100644 --- a/src/or/circuituse.c +++ b/src/or/circuituse.c @@ -666,8 +666,8 @@ void circuit_build_failed(circuit_t *circ) { /* Don't increment failure count, since Alice may have picked * the rendezvous point maliciously */ log_fn(LOG_INFO,"Couldn't connect to Alice's chosen rend point %s (%s hop failed).", - failed_at_last_hop?"last":"non-last", - circ->build_state->chosen_exit_name); + circ->build_state->chosen_exit_name, + failed_at_last_hop?"last":"non-last"); rend_service_relaunch_rendezvous(circ); break; default: @@ -838,7 +838,7 @@ circuit_get_open_circ_or_launch(connection_t *conn, if (router_exit_policy_all_routers_reject(addr, conn->socks_request->port, need_uptime)) { log_fn(LOG_NOTICE,"No Tor server exists that allows exit to %s:%d. Rejecting.", - conn->socks_request->address, conn->socks_request->port); + safe_str(conn->socks_request->address), conn->socks_request->port); return -1; } } @@ -856,19 +856,20 @@ try_an_intro_point: exitname = rend_client_get_random_intro(conn->rend_query); if (!exitname) { log_fn(LOG_INFO,"No intro points for '%s': refetching service descriptor.", - conn->rend_query); + safe_str(conn->rend_query)); rend_client_refetch_renddesc(conn->rend_query); conn->state = AP_CONN_STATE_RENDDESC_WAIT; return 0; } if (!router_get_by_nickname(exitname)) { log_fn(LOG_NOTICE,"Advertised intro point '%s' is not recognized for '%s'. Skipping over.", - exitname, conn->rend_query); + exitname, safe_str(conn->rend_query)); rend_client_remove_intro_point(exitname, conn->rend_query); tor_free(exitname); goto try_an_intro_point; } - log_fn(LOG_INFO,"Chose %s as intro point for %s.", exitname, conn->rend_query); + log_fn(LOG_INFO,"Chose %s as intro point for %s.", + exitname, safe_str(conn->rend_query)); } /* If we have specified a particular exit node for our @@ -878,7 +879,8 @@ try_an_intro_point: if (conn->chosen_exit_name) { exitname = tor_strdup(conn->chosen_exit_name); if (!router_get_by_nickname(exitname)) { - log_fn(LOG_NOTICE,"Requested exit point '%s' is not known. Closing.", exitname); + log_fn(LOG_NOTICE,"Requested exit point '%s' is not known. Closing.", + exitname); tor_free(exitname); return -1; } diff --git a/src/or/command.c b/src/or/command.c index 5f5fd5f3ac..fe476d4af3 100644 --- a/src/or/command.c +++ b/src/or/command.c @@ -265,7 +265,7 @@ static void command_process_relay_cell(cell_t *cell, connection_t *conn) { circ = circuit_get_by_circid_orconn(cell->circ_id, conn); if (!circ) { - log_fn(LOG_INFO,"unknown circuit %d on connection to %s:%d. Dropping.", + log_fn(LOG_INFO,"unknown circuit %d on connection from %s:%d. Dropping.", cell->circ_id, conn->address, conn->port); return; } @@ -310,7 +310,7 @@ static void command_process_destroy_cell(cell_t *cell, connection_t *conn) { circ = circuit_get_by_circid_orconn(cell->circ_id, conn); if (!circ) { - log_fn(LOG_INFO,"unknown circuit %d on connection to %s:%d. Dropping.", + log_fn(LOG_INFO,"unknown circuit %d on connection from %s:%d. Dropping.", cell->circ_id, conn->address, conn->port); return; } @@ -335,3 +335,4 @@ static void command_process_destroy_cell(cell_t *cell, connection_t *conn) { } } } + diff --git a/src/or/config.c b/src/or/config.c index d663c2c1d5..f374d8ab46 100644 --- a/src/or/config.c +++ b/src/or/config.c @@ -168,6 +168,7 @@ static config_var_t config_vars[] = { VAR("RecommendedVersions", LINELIST, RecommendedVersions, NULL), VAR("RendNodes", STRING, RendNodes, NULL), VAR("RendExcludeNodes", STRING, RendExcludeNodes, NULL), + VAR("SafeLogging", BOOL, SafeLogging, "1"), VAR("ShutdownWaitLength", INTERVAL, ShutdownWaitLength, "30 seconds"), VAR("SocksPort", UINT, SocksPort, "9050"), VAR("SocksBindAddress", LINELIST, SocksBindAddress, NULL), @@ -249,6 +250,17 @@ config_free_all(void) tor_free(config_fname); } +/** If options->SafeLogging is on, return a not very useful string, + * else return address. + */ +const char * +safe_str(const char *address) { + if (get_options()->SafeLogging) + return "[scrubbed]"; + else + return address; +} + /** Fetch the active option list, and take actions based on it. All * of the things we do should survive being done repeatedly. * Return 0 if all goes well, return -1 if it's time to die. @@ -930,7 +942,7 @@ static void print_usage(void) { printf( -"Copyright 2001-2004 Roger Dingledine, Nick Mathewson, Matej Pfajfar.\n\n" +"Copyright 2001-2005 Roger Dingledine, Nick Mathewson.\n\n" "tor -f [args]\n" "See man page for options, or http://tor.eff.org/ for documentation.\n"); } @@ -1617,8 +1629,8 @@ options_transition_allowed(or_options_t *old, or_options_t *new_val) { return -1; } - if (old->RunAsDaemon && !new_val->RunAsDaemon) { - log_fn(LOG_WARN,"During reload, change from RunAsDaemon=1 to =0 not allowed. Failing."); + if (old->RunAsDaemon != new_val->RunAsDaemon) { + log_fn(LOG_WARN,"During reload, changing RunAsDaemon is not allowed. Failing."); return -1; } @@ -1638,7 +1650,7 @@ options_transition_allowed(or_options_t *old, or_options_t *new_val) { } if (!opt_streq(old->Group, new_val->Group)) { - log_fn(LOG_WARN,"During reload, changing User is not allowed. Failing."); + log_fn(LOG_WARN,"During reload, changing Group is not allowed. Failing."); return -1; } @@ -2173,7 +2185,7 @@ config_parse_addr_policy(struct config_line_t *cfg, if (*nextp) { nextp = &((*nextp)->next); } else { - log_fn(LOG_WARN,"Malformed policy %s.", ent); + log_fn(LOG_WARN,"Malformed policy '%s'.", ent); r = -1; } }); diff --git a/src/or/connection.c b/src/or/connection.c index 665f246b1f..41a2ce38b6 100644 --- a/src/or/connection.c +++ b/src/or/connection.c @@ -173,12 +173,12 @@ connection_unregister(connection_t *conn) { if (conn->read_event) { if (event_del(conn->read_event)) - log_fn(LOG_WARN, "Error removing read event for %d", (int)conn->s); + log_fn(LOG_WARN, "Error removing read event for %d", conn->s); tor_free(conn->read_event); } if (conn->write_event) { if (event_del(conn->write_event)) - log_fn(LOG_WARN, "Error removing write event for %d", (int)conn->s); + log_fn(LOG_WARN, "Error removing write event for %d", conn->s); tor_free(conn->write_event); } } @@ -670,7 +670,8 @@ int connection_connect(connection_t *conn, char *address, uint32_t addr, uint16_ return -1; } else if (!SOCKET_IS_POLLABLE(s)) { log_fn(LOG_WARN, - "Too many connections; can't create pollable connection to %s", address); + "Too many connections; can't create pollable connection to %s", + safe_str(address)); tor_close_socket(s); return -1; } @@ -700,13 +701,13 @@ int connection_connect(connection_t *conn, char *address, uint32_t addr, uint16_ dest_addr.sin_port = htons(port); dest_addr.sin_addr.s_addr = htonl(addr); - log_fn(LOG_DEBUG,"Connecting to %s:%u.",address,port); + log_fn(LOG_DEBUG,"Connecting to %s:%u.",safe_str(address),port); if (connect(s,(struct sockaddr *)&dest_addr,sizeof(dest_addr)) < 0) { int e = tor_socket_errno(s); if (!ERRNO_IS_CONN_EINPROGRESS(e)) { /* yuck. kill it. */ - log_fn(LOG_INFO,"Connect() to %s:%u failed: %s",address,port, + log_fn(LOG_INFO,"Connect() to %s:%u failed: %s",safe_str(address),port, tor_socket_strerror(e)); tor_close_socket(s); return -1; @@ -721,7 +722,7 @@ int connection_connect(connection_t *conn, char *address, uint32_t addr, uint16_ } /* it succeeded. we're connected. */ - log_fn(LOG_INFO,"Connection to %s:%u established.",address,port); + log_fn(LOG_INFO,"Connection to %s:%u established.",safe_str(address),port); conn->s = s; if (connection_add(conn) < 0) /* no space, forget it */ return -1; diff --git a/src/or/connection_edge.c b/src/or/connection_edge.c index a0fa1605dd..1c86bbcd4d 100644 --- a/src/or/connection_edge.c +++ b/src/or/connection_edge.c @@ -265,7 +265,7 @@ int connection_edge_finished_connecting(connection_t *conn) tor_assert(conn->state == EXIT_CONN_STATE_CONNECTING); log_fn(LOG_INFO,"Exit connection to %s:%u established.", - conn->address,conn->port); + safe_str(conn->address),conn->port); conn->state = EXIT_CONN_STATE_OPEN; connection_watch_events(conn, EV_READ); /* stop writing, continue reading */ @@ -326,14 +326,15 @@ void connection_ap_expire_beginning(void) { circ = circuit_get_by_edge_conn(conn); if (!circ) { /* it's vanished? */ log_fn(LOG_INFO,"Conn is waiting (address %s), but lost its circ.", - conn->socks_request->address); + safe_str(conn->socks_request->address)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT); continue; } if (circ->purpose == CIRCUIT_PURPOSE_C_REND_JOINED) { if (now - conn->timestamp_lastread > 45) { log_fn(LOG_NOTICE,"Rend stream is %d seconds late. Giving up on address '%s'.", - (int)(now - conn->timestamp_lastread), conn->socks_request->address); + (int)(now - conn->timestamp_lastread), + safe_str(conn->socks_request->address)); connection_edge_end(conn, END_STREAM_REASON_TIMEOUT, conn->cpath_layer); connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT); } @@ -341,7 +342,8 @@ void connection_ap_expire_beginning(void) { } tor_assert(circ->purpose == CIRCUIT_PURPOSE_C_GENERAL); log_fn(LOG_NOTICE,"Stream is %d seconds late on address '%s'. Retrying.", - (int)(now - conn->timestamp_lastread), conn->socks_request->address); + (int)(now - conn->timestamp_lastread), + safe_str(conn->socks_request->address)); circuit_log_path(LOG_NOTICE, circ); /* send an end down the circuit */ connection_edge_end(conn, END_STREAM_REASON_TIMEOUT, conn->cpath_layer); @@ -546,11 +548,11 @@ void addressmap_rewrite(char *address, size_t maxlen) { return; /* done, no rewrite needed */ log_fn(LOG_INFO, "Addressmap: rewriting '%s' to '%s'", - address, ent->new_address); + safe_str(address), safe_str(ent->new_address)); strlcpy(address, ent->new_address, maxlen); } log_fn(LOG_WARN,"Loop detected: we've rewritten '%s' 16 times! Using it as-is.", - address); + safe_str(address)); /* it's fine to rewrite a rewrite, but don't loop forever */ } @@ -588,7 +590,8 @@ void addressmap_register(const char *address, char *new_address, time_t expires) strmap_set(addressmap, address, ent); } else if (ent->new_address) { /* we need to clean up the old mapping. */ if (expires > 1) { - log_fn(LOG_INFO,"Temporary addressmap ('%s' to '%s') not performed, since it's already mapped to '%s'", address, new_address, ent->new_address); + log_fn(LOG_INFO,"Temporary addressmap ('%s' to '%s') not performed, since it's already mapped to '%s'", + safe_str(address), safe_str(new_address), safe_str(ent->new_address)); tor_free(new_address); return; } @@ -606,7 +609,7 @@ void addressmap_register(const char *address, char *new_address, time_t expires) ent->num_resolve_failures = 0; log_fn(LOG_INFO, "Addressmap: (re)mapped '%s' to '%s'", - address, ent->new_address); + safe_str(address), safe_str(ent->new_address)); } /** An attempt to resolve address failed at some OR. @@ -624,7 +627,7 @@ int client_dns_incr_failures(const char *address) } ++ent->num_resolve_failures; log_fn(LOG_INFO,"Address %s now has %d resolve failures.", - address, ent->num_resolve_failures); + safe_str(address), ent->num_resolve_failures); return ent->num_resolve_failures; } @@ -768,7 +771,8 @@ addressmap_register_virtual_address(int type, char *new_address) return tor_strdup(*addrp); } else log_fn(LOG_WARN, "Internal confusion: I thought that '%s' was mapped to by '%s', but '%s' really maps to '%s'. This is a harmless bug.", - new_address, *addrp, *addrp, ent?ent->new_address:"(nothing)"); + safe_str(new_address), safe_str(*addrp), safe_str(*addrp), + ent?safe_str(ent->new_address):"(nothing)"); } tor_free(*addrp); @@ -786,7 +790,8 @@ addressmap_register_virtual_address(int type, char *new_address) tor_assert(!strcasecmp(*addrp, (type == RESOLVED_TYPE_IPV4) ? vent->ipv4_address : vent->hostname_address)); - log_fn(LOG_INFO, "Map from %s to %s okay.",*addrp,new_address); + log_fn(LOG_INFO, "Map from %s to %s okay.", + safe_str(*addrp),safe_str(new_address)); } #endif @@ -896,7 +901,7 @@ static int connection_ap_handshake_process_socks(connection_t *conn) { * information. */ log_fn(LOG_WARN,"Missing mapping for virtual address '%s'. Refusing.", - socks->address); + socks->address); /* don't safe_str() this yet. */ connection_mark_unattached_ap(conn, END_STREAM_REASON_INTERNAL); return -1; } @@ -910,7 +915,8 @@ static int connection_ap_handshake_process_socks(connection_t *conn) { /* .exit -- modify conn to specify the exit node. */ char *s = strrchr(socks->address,'.'); if (!s || s[1] == '\0') { - log_fn(LOG_WARN,"Malformed exit address '%s'. Refusing.", socks->address); + log_fn(LOG_WARN,"Malformed exit address '%s'. Refusing.", + safe_str(socks->address)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); return -1; } @@ -922,7 +928,8 @@ static int connection_ap_handshake_process_socks(connection_t *conn) { /* not a hidden-service request (i.e. normal or .exit) */ if (address_is_invalid_destination(socks->address)) { - log_fn(LOG_WARN,"Destination '%s' seems to be an invalid hostname. Failing.", socks->address); + log_fn(LOG_WARN,"Destination '%s' seems to be an invalid hostname. Failing.", + safe_str(socks->address)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); return -1; } @@ -981,17 +988,20 @@ static int connection_ap_handshake_process_socks(connection_t *conn) { } strlcpy(conn->rend_query, socks->address, sizeof(conn->rend_query)); - log_fn(LOG_INFO,"Got a hidden service request for ID '%s'", conn->rend_query); + log_fn(LOG_INFO,"Got a hidden service request for ID '%s'", + safe_str(conn->rend_query)); /* see if we already have it cached */ r = rend_cache_lookup_entry(conn->rend_query, &entry); if (r<0) { - log_fn(LOG_WARN,"Invalid service descriptor %s", conn->rend_query); + log_fn(LOG_WARN,"Invalid service descriptor %s", + safe_str(conn->rend_query)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); return -1; } if (r==0) { conn->state = AP_CONN_STATE_RENDDESC_WAIT; - log_fn(LOG_INFO, "Unknown descriptor %s. Fetching.", conn->rend_query); + log_fn(LOG_INFO, "Unknown descriptor %s. Fetching.", + safe_str(conn->rend_query)); rend_client_refetch_renddesc(conn->rend_query); return 0; } @@ -1007,7 +1017,8 @@ static int connection_ap_handshake_process_socks(connection_t *conn) { return 0; } else { conn->state = AP_CONN_STATE_RENDDESC_WAIT; - log_fn(LOG_INFO, "Stale descriptor %s. Refetching.", conn->rend_query); + log_fn(LOG_INFO, "Stale descriptor %s. Refetching.", + safe_str(conn->rend_query)); rend_client_refetch_renddesc(conn->rend_query); return 0; } @@ -1131,7 +1142,7 @@ int connection_ap_make_bridge(char *address, uint16_t port) { int fd[2]; connection_t *conn; - log_fn(LOG_INFO,"Making AP bridge to %s:%d ...",address,port); + log_fn(LOG_INFO,"Making AP bridge to %s:%d ...",safe_str(address),port); if (tor_socketpair(AF_UNIX, SOCK_STREAM, 0, fd) < 0) { log(LOG_WARN,"Couldn't construct socketpair (%s). Network down? Delaying.", @@ -1469,7 +1480,8 @@ connection_exit_connect(connection_t *conn) { if (!connection_edge_is_rendezvous_stream(conn) && router_compare_to_my_exit_policy(conn) == ADDR_POLICY_REJECTED) { - log_fn(LOG_INFO,"%s:%d failed exit policy. Closing.", conn->address, conn->port); + log_fn(LOG_INFO,"%s:%d failed exit policy. Closing.", + safe_str(conn->address), conn->port); connection_edge_end(conn, END_STREAM_REASON_EXITPOLICY, conn->cpath_layer); circuit_detach_stream(circuit_get_by_edge_conn(conn), conn); connection_free(conn); @@ -1491,7 +1503,7 @@ connection_exit_connect(connection_t *conn) { in.s_addr = htonl(addr); tor_inet_ntoa(&in, tmpbuf, sizeof(tmpbuf)); log_fn(LOG_DEBUG, "Redirecting connection from %s:%d to %s:%d", - conn->address, conn->port, tmpbuf, port); + safe_str(conn->address), conn->port, safe_str(tmpbuf), port); } break; } @@ -1525,12 +1537,14 @@ connection_exit_connect(connection_t *conn) { /* also, deliver a 'connected' cell back through the circuit. */ if (connection_edge_is_rendezvous_stream(conn)) { /* rendezvous stream */ /* don't send an address back! */ - connection_edge_send_command(conn, circuit_get_by_edge_conn(conn), RELAY_COMMAND_CONNECTED, + connection_edge_send_command(conn, circuit_get_by_edge_conn(conn), + RELAY_COMMAND_CONNECTED, NULL, 0, conn->cpath_layer); } else { /* normal stream */ /* This must be the original address, not the redirected address. */ *(uint32_t*)connected_payload = htonl(conn->addr); - connection_edge_send_command(conn, circuit_get_by_edge_conn(conn), RELAY_COMMAND_CONNECTED, + connection_edge_send_command(conn, circuit_get_by_edge_conn(conn), + RELAY_COMMAND_CONNECTED, connected_payload, 4, conn->cpath_layer); } } @@ -1558,7 +1572,7 @@ int connection_ap_can_use_exit(connection_t *conn, routerinfo_t *exit) tor_assert(exit); log_fn(LOG_DEBUG,"considering nickname %s, for address %s / port %d:", - exit->nickname, conn->socks_request->address, + exit->nickname, safe_str(conn->socks_request->address), conn->socks_request->port); /* If a particular exit node has been requested for the new connection, diff --git a/src/or/connection_or.c b/src/or/connection_or.c index 3a816cfaef..d83f42c8e8 100644 --- a/src/or/connection_or.c +++ b/src/or/connection_or.c @@ -322,7 +322,7 @@ connection_t *connection_or_connect(uint32_t addr, uint16_t port, if (server_mode(options) && (me=router_get_my_routerinfo()) && !memcmp(me->identity_digest, id_digest,DIGEST_LEN)) { - log_fn(LOG_WARN,"Bug: Client asked me to connect to myself! Refusing."); + log_fn(LOG_WARN,"Client asked me to connect to myself! Refusing."); return NULL; } diff --git a/src/or/control.c b/src/or/control.c index c1b44df7e2..41bc5d1782 100644 --- a/src/or/control.c +++ b/src/or/control.c @@ -579,7 +579,8 @@ handle_control_mapaddress(connection_t *conn, uint32_t len, const char *body) tor_strdup(to)); if (!addr) { log_fn(LOG_WARN, - "Unable to allocate address for '%s' in MapAddress msg",line); + "Unable to allocate address for '%s' in MapAddress msg", + safe_str(line)); } else { size_t anslen = strlen(addr)+strlen(to)+2; char *ans = tor_malloc(anslen); diff --git a/src/or/dns.c b/src/or/dns.c index 805218f68e..b1166c812d 100644 --- a/src/or/dns.c +++ b/src/or/dns.c @@ -137,9 +137,9 @@ static void purge_expired_resolves(uint32_t now) { while (oldest_cached_resolve && (oldest_cached_resolve->expire < now)) { resolve = oldest_cached_resolve; log(LOG_DEBUG,"Forgetting old cached resolve (address %s, expires %lu)", - resolve->address, (unsigned long)resolve->expire); + safe_str(resolve->address), (unsigned long)resolve->expire); if (resolve->state == CACHE_STATE_PENDING) { - log_fn(LOG_WARN,"Bug: Expiring a dns resolve ('%s') that's still pending. Forgot to cull it?", resolve->address); + log_fn(LOG_WARN,"Bug: Expiring a dns resolve ('%s') that's still pending. Forgot to cull it?", safe_str(resolve->address)); tor_fragile_assert(); } if (resolve->pending_connections) { @@ -259,19 +259,19 @@ int dns_resolve(connection_t *exitconn) { pending_connection->next = resolve->pending_connections; resolve->pending_connections = pending_connection; log_fn(LOG_DEBUG,"Connection (fd %d) waiting for pending DNS resolve of '%s'", - exitconn->s, exitconn->address); + exitconn->s, safe_str(exitconn->address)); exitconn->state = EXIT_CONN_STATE_RESOLVING; return 0; case CACHE_STATE_VALID: exitconn->addr = resolve->addr; log_fn(LOG_DEBUG,"Connection (fd %d) found cached answer for '%s'", - exitconn->s, exitconn->address); + exitconn->s, safe_str(exitconn->address)); if (exitconn->purpose == EXIT_PURPOSE_RESOLVE) send_resolved_cell(exitconn, RESOLVED_TYPE_IPV4); return 1; case CACHE_STATE_FAILED: log_fn(LOG_DEBUG,"Connection (fd %d) found cached error for '%s'", - exitconn->s, exitconn->address); + exitconn->s, safe_str(exitconn->address)); if (exitconn->purpose == EXIT_PURPOSE_RESOLVE) send_resolved_cell(exitconn, RESOLVED_TYPE_ERROR); circ = circuit_get_by_edge_conn(exitconn); @@ -322,7 +322,7 @@ static int assign_to_dnsworker(connection_t *exitconn) { } log_fn(LOG_DEBUG, "Connection (fd %d) needs to resolve '%s'; assigning to DNSWorker (fd %d)", - exitconn->s, exitconn->address, dnsconn->s); + exitconn->s, safe_str(exitconn->address), dnsconn->s); tor_free(dnsconn->address); dnsconn->address = tor_strdup(exitconn->address); @@ -333,7 +333,6 @@ static int assign_to_dnsworker(connection_t *exitconn) { connection_write_to_buf(&len, 1, dnsconn); connection_write_to_buf(dnsconn->address, len, dnsconn); -// log_fn(LOG_DEBUG,"submitted '%s'", exitconn->address); return 0; } @@ -352,7 +351,7 @@ void connection_dns_remove(connection_t *conn) resolve = SPLAY_FIND(cache_tree, &cache_root, &search); if (!resolve) { - log_fn(LOG_NOTICE,"Address '%s' is not pending. Dropping.", conn->address); + log_fn(LOG_NOTICE,"Address '%s' is not pending. Dropping.", safe_str(conn->address)); return; } @@ -365,7 +364,7 @@ void connection_dns_remove(connection_t *conn) resolve->pending_connections = pend->next; tor_free(pend); log_fn(LOG_DEBUG, "First connection (fd %d) no longer waiting for resolve of '%s'", - conn->s, conn->address); + conn->s, safe_str(conn->address)); return; } else { for ( ; pend->next; pend = pend->next) { @@ -374,7 +373,7 @@ void connection_dns_remove(connection_t *conn) pend->next = victim->next; tor_free(victim); log_fn(LOG_DEBUG, "Connection (fd %d) no longer waiting for resolve of '%s'", - conn->s, conn->address); + conn->s, safe_str(conn->address)); return; /* more are pending */ } } @@ -429,13 +428,14 @@ void dns_cancel_pending_resolve(char *address) { resolve = SPLAY_FIND(cache_tree, &cache_root, &search); if (!resolve) { - log_fn(LOG_NOTICE,"Address '%s' is not pending. Dropping.", address); + log_fn(LOG_NOTICE,"Address '%s' is not pending. Dropping.", safe_str(address)); return; } if (!resolve->pending_connections) { /* XXX this should never trigger, but sometimes it does */ - log_fn(LOG_WARN,"Bug: Address '%s' is pending but has no pending connections!", address); + log_fn(LOG_WARN,"Bug: Address '%s' is pending but has no pending connections!", + safe_str(address)); tor_fragile_assert(); return; } @@ -443,7 +443,7 @@ void dns_cancel_pending_resolve(char *address) { /* mark all pending connections to fail */ log_fn(LOG_DEBUG, "Failing all connections waiting on DNS resolve of '%s'", - address); + safe_str(address)); while (resolve->pending_connections) { pend = resolve->pending_connections; pend->conn->state = EXIT_CONN_STATE_RESOLVEFAILED; @@ -508,7 +508,8 @@ static void dns_found_answer(char *address, uint32_t addr, char outcome) { resolve = SPLAY_FIND(cache_tree, &cache_root, &search); if (!resolve) { - log_fn(LOG_INFO,"Resolved unasked address '%s'; caching anyway.", address); + log_fn(LOG_INFO,"Resolved unasked address '%s'; caching anyway.", + safe_str(address)); resolve = tor_malloc_zero(sizeof(struct cached_resolve)); resolve->state = (outcome == DNS_RESOLVE_SUCCEEDED) ? CACHE_STATE_VALID : CACHE_STATE_FAILED; @@ -522,7 +523,7 @@ static void dns_found_answer(char *address, uint32_t addr, char outcome) { /* XXXX Maybe update addr? or check addr for consistency? Or let * VALID replace FAILED? */ log_fn(LOG_NOTICE, "Resolved '%s' which was already resolved; ignoring", - address); + safe_str(address)); tor_assert(resolve->pending_connections == NULL); return; } @@ -633,7 +634,7 @@ int connection_dns_process_inbuf(connection_t *conn) { if (conn->state != DNSWORKER_STATE_BUSY && buf_datalen(conn->inbuf)) { log_fn(LOG_WARN,"Bug: read data (%d bytes) from an idle dns worker (fd %d, address '%s'). Please report.", - (int)buf_datalen(conn->inbuf), conn->s, conn->address); + (int)buf_datalen(conn->inbuf), conn->s, safe_str(conn->address)); tor_fragile_assert(); /* Pull it off the buffer anyway, or it will just stay there. @@ -643,7 +644,7 @@ int connection_dns_process_inbuf(connection_t *conn) { connection_fetch_from_buf(&success,1,conn); connection_fetch_from_buf((char *)&addr,sizeof(uint32_t),conn); log_fn(LOG_WARN,"Discarding idle dns answer (success %d, addr %d.)", - success, addr); + success, addr); // XXX safe_str } return 0; } @@ -656,7 +657,7 @@ int connection_dns_process_inbuf(connection_t *conn) { connection_fetch_from_buf((char *)&addr,sizeof(uint32_t),conn); log_fn(LOG_DEBUG, "DNSWorker (fd %d) returned answer for '%s'", - conn->s, conn->address); + conn->s, safe_str(conn->address)); tor_assert(success >= DNS_RESOLVE_FAILED_TRANSIENT); tor_assert(success <= DNS_RESOLVE_SUCCEEDED); @@ -754,15 +755,15 @@ static int dnsworker_main(void *data) { switch (result) { case 1: /* XXX result can never be 1, because we set it to -1 above on error */ - log_fn(LOG_INFO,"Could not resolve dest addr %s (transient).",address); + log_fn(LOG_INFO,"Could not resolve dest addr %s (transient).",safe_str(address)); answer[0] = DNS_RESOLVE_FAILED_TRANSIENT; break; case -1: - log_fn(LOG_INFO,"Could not resolve dest addr %s (permanent).",address); + log_fn(LOG_INFO,"Could not resolve dest addr %s (permanent).",safe_str(address)); answer[0] = DNS_RESOLVE_FAILED_PERMANENT; break; case 0: - log_fn(LOG_INFO,"Resolved address '%s'.",address); + log_fn(LOG_INFO,"Resolved address '%s'.",safe_str(address)); answer[0] = DNS_RESOLVE_SUCCEEDED; break; } diff --git a/src/or/main.c b/src/or/main.c index 1dbc396589..79e8120282 100644 --- a/src/or/main.c +++ b/src/or/main.c @@ -252,7 +252,7 @@ void connection_watch_events(connection_t *conn, short events) { if (r<0) log_fn(LOG_WARN, "Error from libevent setting read event state for %d to %swatched.", - (int)conn->s, (events & EV_READ)?"":"un"); + conn->s, (events & EV_READ)?"":"un"); if (events & EV_WRITE) { r = event_add(conn->write_event, NULL); @@ -263,7 +263,7 @@ void connection_watch_events(connection_t *conn, short events) { if (r<0) log_fn(LOG_WARN, "Error from libevent setting read event state for %d to %swatched.", - (int)conn->s, (events & EV_WRITE)?"":"un"); + conn->s, (events & EV_WRITE)?"":"un"); } /** Return true iff conn is listening for read events. */ @@ -281,7 +281,7 @@ void connection_stop_reading(connection_t *conn) { log(LOG_DEBUG,"connection_stop_reading() called."); if (event_del(conn->read_event)) log_fn(LOG_WARN, "Error from libevent setting read event state for %d to unwatched.", - (int)conn->s); + conn->s); } /** Tell the main loop to start notifying conn of any read events. */ @@ -291,7 +291,7 @@ void connection_start_reading(connection_t *conn) { if (event_add(conn->read_event, NULL)) log_fn(LOG_WARN, "Error from libevent setting read event state for %d to watched.", - (int)conn->s); + conn->s); } /** Return true iff conn is listening for write events. */ @@ -308,7 +308,7 @@ void connection_stop_writing(connection_t *conn) { if (event_del(conn->write_event)) log_fn(LOG_WARN, "Error from libevent setting write event state for %d to unwatched.", - (int)conn->s); + conn->s); } @@ -319,7 +319,7 @@ void connection_start_writing(connection_t *conn) { if (event_add(conn->write_event, NULL)) log_fn(LOG_WARN, "Error from libevent setting write event state for %d to watched.", - (int)conn->s); + conn->s); } /** Close all connections that have been scheduled to get closed */ @@ -442,7 +442,8 @@ static int conn_close_if_marked(int i) { } if (connection_wants_to_flush(conn)) { log_fn(LOG_NOTICE,"Conn (addr %s, fd %d, type %s, state %d) is being closed, but there are still %d bytes we can't write. (Marked at %s:%d)", - conn->address, conn->s, conn_type_to_string(conn->type), conn->state, + safe_str(conn->address), conn->s, conn_type_to_string(conn->type), + conn->state, (int)buf_datalen(conn->outbuf), conn->marked_for_close_file, conn->marked_for_close); } @@ -466,7 +467,7 @@ void directory_all_unreachable(time_t now) { while ((conn = connection_get_by_type_state(CONN_TYPE_AP, AP_CONN_STATE_CIRCUIT_WAIT))) { log_fn(LOG_NOTICE,"Network down? Failing connection to '%s:%d'.", - conn->socks_request->address, conn->socks_request->port); + safe_str(conn->socks_request->address), conn->socks_request->port); connection_mark_unattached_ap(conn, END_STREAM_REASON_NET_UNREACHABLE); } } @@ -553,7 +554,8 @@ static void run_connection_housekeeping(int i, time_t now) { if (conn->type == CONN_TYPE_DIR && !conn->marked_for_close && conn->timestamp_lastwritten + 5*60 < now) { - log_fn(LOG_INFO,"Expiring wedged directory conn (fd %d, purpose %d)", conn->s, conn->purpose); + log_fn(LOG_INFO,"Expiring wedged directory conn (fd %d, purpose %d)", + conn->s, conn->purpose); connection_mark_for_close(conn); return; } @@ -1066,7 +1068,7 @@ dumpstats(int severity) { i, conn->s, conn->type, conn_type_to_string(conn->type), conn->state, conn_state_to_string(conn->type, conn->state), (int)(now - conn->timestamp_created)); if (!connection_is_listener(conn)) { - log(severity,"Conn %d is to '%s:%d'.",i,conn->address, conn->port); + log(severity,"Conn %d is to '%s:%d'.",i,safe_str(conn->address), conn->port); log(severity,"Conn %d: %d bytes waiting on inbuf (last read %d secs ago)",i, (int)buf_datalen(conn->inbuf), (int)(now - conn->timestamp_lastread)); diff --git a/src/or/or.h b/src/or/or.h index f778daf72f..32c82d70f9 100644 --- a/src/or/or.h +++ b/src/or/or.h @@ -1093,6 +1093,8 @@ typedef struct { * to cope? (1) */ int ShutdownWaitLength; /**< When we get a SIGINT and we're a server, how * long do we wait before exiting? */ + int SafeLogging; /**< Boolean: are we allowed to log sensitive strings + * such as addresses (0), or do we scrub them first (1)? */ } or_options_t; #define MAX_SOCKS_REPLY_LEN 1024 @@ -1242,6 +1244,7 @@ or_options_t *get_options(void); void set_options(or_options_t *new_val); int options_act(void); void config_free_all(void); +const char *safe_str(const char *address); int config_get_lines(char *string, struct config_line_t **result); void config_free_lines(struct config_line_t *front); diff --git a/src/or/relay.c b/src/or/relay.c index cd237e020a..631c1ccf49 100644 --- a/src/or/relay.c +++ b/src/or/relay.c @@ -607,7 +607,7 @@ connection_edge_process_end_not_open( return -1; } log_fn(LOG_INFO,"Address '%s' refused due to '%s'. Considering retrying.", - conn->socks_request->address, + safe_str(conn->socks_request->address), connection_edge_end_reason_str(reason)); exitrouter = router_get_by_digest(circ->build_state->chosen_exit_digest); if (!exitrouter) { @@ -620,7 +620,7 @@ connection_edge_process_end_not_open( uint32_t addr = ntohl(get_uint32(cell->payload+RELAY_HEADER_SIZE+1)); if (!addr) { log_fn(LOG_INFO,"Address '%s' resolved to 0.0.0.0. Closing,", - conn->socks_request->address); + safe_str(conn->socks_request->address)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); return 0; } @@ -654,7 +654,7 @@ connection_edge_process_end_not_open( /* else, conn will get closed below */ } else { log_fn(LOG_NOTICE,"Have tried resolving address '%s' at %d different places. Giving up.", - conn->socks_request->address, MAX_RESOLVE_FAILURES); + safe_str(conn->socks_request->address), MAX_RESOLVE_FAILURES); } break; case END_STREAM_REASON_HIBERNATING: diff --git a/src/or/rendclient.c b/src/or/rendclient.c index 4e87146d52..8f23ddfcbc 100644 --- a/src/or/rendclient.c +++ b/src/or/rendclient.c @@ -67,7 +67,7 @@ rend_client_send_introduction(circuit_t *introcirc, circuit_t *rendcirc) { if (rend_cache_lookup_entry(introcirc->rend_query, &entry) < 1) { log_fn(LOG_WARN,"query '%s' didn't have valid rend desc in cache. Failing.", - introcirc->rend_query); + safe_str(introcirc->rend_query)); goto err; } @@ -216,16 +216,17 @@ rend_client_introduction_acked(circuit_t *circ, nickname = rend_client_get_random_intro(circ->rend_query); tor_assert(nickname); log_fn(LOG_INFO,"Got nack for %s from %s, extending to %s.", - circ->rend_query, circ->build_state->chosen_exit_name, nickname); + safe_str(circ->rend_query), + circ->build_state->chosen_exit_name, nickname); if (!(r = router_get_by_nickname(nickname))) { log_fn(LOG_WARN, "Advertised intro point '%s' for %s is not known. Closing.", - nickname, circ->rend_query); + nickname, safe_str(circ->rend_query)); tor_free(nickname); circuit_mark_for_close(circ); return -1; } log_fn(LOG_INFO, "Chose new intro point %s for %s (circ %d)", - nickname, circ->rend_query, circ->n_circ_id); + nickname, safe_str(circ->rend_query), circ->n_circ_id); tor_free(nickname); return circuit_extend_to_new_exit(circ, r); } @@ -241,7 +242,7 @@ void rend_client_refetch_renddesc(const char *query) { if (connection_get_by_type_state_rendquery(CONN_TYPE_DIR, 0, query)) { - log_fn(LOG_INFO,"Would fetch a new renddesc here (for %s), but one is already in progress.", query); + log_fn(LOG_INFO,"Would fetch a new renddesc here (for %s), but one is already in progress.", safe_str(query)); } else { /* not one already; initiate a dir rend desc lookup */ directory_get_from_dirserver(DIR_PURPOSE_FETCH_RENDDESC, query, 1); @@ -263,11 +264,12 @@ rend_client_remove_intro_point(char *failed_intro, const char *query) r = rend_cache_lookup_entry(query, &ent); if (r<0) { - log_fn(LOG_WARN, "Malformed service ID '%s'", query); + log_fn(LOG_WARN, "Malformed service ID '%s'", safe_str(query)); return -1; } if (r==0) { - log_fn(LOG_INFO, "Unknown service %s. Re-fetching descriptor.", query); + log_fn(LOG_INFO, "Unknown service %s. Re-fetching descriptor.", + safe_str(query)); rend_client_refetch_renddesc(query); return 0; } @@ -282,7 +284,8 @@ rend_client_remove_intro_point(char *failed_intro, const char *query) } if (!ent->parsed->n_intro_points) { - log_fn(LOG_INFO,"No more intro points remain for %s. Re-fetching descriptor.", query); + log_fn(LOG_INFO,"No more intro points remain for %s. Re-fetching descriptor.", + safe_str(query)); rend_client_refetch_renddesc(query); /* move all pending streams back to renddesc_wait */ @@ -293,7 +296,8 @@ rend_client_remove_intro_point(char *failed_intro, const char *query) return 0; } - log_fn(LOG_INFO,"%d options left for %s.", ent->parsed->n_intro_points, query); + log_fn(LOG_INFO,"%d options left for %s.", + ent->parsed->n_intro_points, safe_str(query)); return 1; } @@ -406,7 +410,7 @@ void rend_client_desc_here(char *query) { } tor_assert(conn->state != AP_CONN_STATE_RENDDESC_WAIT); /* avoid loop */ } else { /* 404, or fetch didn't get that far */ - log_fn(LOG_NOTICE,"Closing stream for '%s.onion': hidden service is unavailable (try again later).", query); + log_fn(LOG_NOTICE,"Closing stream for '%s.onion': hidden service is unavailable (try again later).", safe_str(query)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT); } } @@ -423,7 +427,8 @@ char *rend_client_get_random_intro(char *query) { rend_cache_entry_t *entry; if (rend_cache_lookup_entry(query, &entry) < 1) { - log_fn(LOG_WARN,"query '%s' didn't have valid rend desc in cache. Failing.", query); + log_fn(LOG_WARN,"query '%s' didn't have valid rend desc in cache. Failing.", + safe_str(query)); return NULL; } diff --git a/src/or/rendcommon.c b/src/or/rendcommon.c index 29028f4f70..3020663311 100644 --- a/src/or/rendcommon.c +++ b/src/or/rendcommon.c @@ -280,23 +280,24 @@ int rend_cache_store(const char *desc, size_t desc_len) } now = time(NULL); if (parsed->timestamp < now-REND_CACHE_MAX_AGE-REND_CACHE_MAX_SKEW) { - log_fn(LOG_WARN,"Service descriptor %s is too old", query); + log_fn(LOG_WARN,"Service descriptor %s is too old", safe_str(query)); rend_service_descriptor_free(parsed); return -1; } if (parsed->timestamp > now+REND_CACHE_MAX_SKEW) { - log_fn(LOG_WARN,"Service descriptor %s is too far in the future", query); + log_fn(LOG_WARN,"Service descriptor %s is too far in the future", + safe_str(query)); rend_service_descriptor_free(parsed); return -1; } e = (rend_cache_entry_t*) strmap_get_lc(rend_cache, query); if (e && e->parsed->timestamp > parsed->timestamp) { - log_fn(LOG_INFO,"We already have a newer service descriptor %s with the same ID", query); + log_fn(LOG_INFO,"We already have a newer service descriptor %s with the same ID", safe_str(query)); rend_service_descriptor_free(parsed); return 0; } if (e && e->len == desc_len && !memcmp(desc,e->desc,desc_len)) { - log_fn(LOG_INFO,"We already have this service descriptor %s", query); + log_fn(LOG_INFO,"We already have this service descriptor %s", safe_str(query)); e->received = time(NULL); rend_service_descriptor_free(parsed); return 0; @@ -314,7 +315,8 @@ int rend_cache_store(const char *desc, size_t desc_len) e->desc = tor_malloc(desc_len); memcpy(e->desc, desc, desc_len); - log_fn(LOG_INFO,"Successfully stored rend desc '%s', len %d", query, (int)desc_len); + log_fn(LOG_INFO,"Successfully stored rend desc '%s', len %d", + safe_str(query), (int)desc_len); return 1; } diff --git a/src/or/rendmid.c b/src/or/rendmid.c index 90881959fa..f2e3b0e8ab 100644 --- a/src/or/rendmid.c +++ b/src/or/rendmid.c @@ -77,7 +77,7 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, size_t request_le while ((c = circuit_get_next_by_pk_and_purpose( c,pk_digest,CIRCUIT_PURPOSE_INTRO_POINT))) { log_fn(LOG_INFO, "Replacing old circuit %d for service %s", - c->p_circ_id, serviceid); + c->p_circ_id, safe_str(serviceid)); circuit_mark_for_close(c); } @@ -95,7 +95,7 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, size_t request_le log_fn(LOG_INFO, "Established introduction point on circuit %d for service %s", - circ->p_circ_id, serviceid); + circ->p_circ_id, safe_str(serviceid)); return 0; truncated: @@ -140,13 +140,13 @@ rend_mid_introduce(circuit_t *circ, const char *request, size_t request_len) if (!intro_circ) { log_fn(LOG_WARN, "No intro circ found for INTRODUCE1 cell (%s) from circuit %d; responding with nack", - serviceid, circ->p_circ_id); + safe_str(serviceid), circ->p_circ_id); goto err; } log_fn(LOG_INFO, "Sending introduction request for service %s from circ %d to circ %d", - serviceid, circ->p_circ_id, intro_circ->p_circ_id); + safe_str(serviceid), circ->p_circ_id, intro_circ->p_circ_id); /* Great. Now we just relay the cell down the circuit. */ if (connection_edge_send_command(NULL, intro_circ, diff --git a/src/or/router.c b/src/or/router.c index 365de0f0e5..09a9bc6b92 100644 --- a/src/or/router.c +++ b/src/or/router.c @@ -616,7 +616,6 @@ int router_compare_to_my_exit_policy(connection_t *conn) return router_compare_addr_to_addr_policy(conn->addr, conn->port, desc_routerinfo->exit_policy) != ADDR_POLICY_ACCEPTED; - } /** Return true iff router has the same nickname as this OR. (For an -- 2.11.4.GIT