diff --git a/src/or/relay.c b/src/or/relay.c index 1c308f1f55..8dbe4acc12 100644 --- a/src/or/relay.c +++ b/src/or/relay.c @@ -123,7 +123,7 @@ relay_crypt_one_payload(crypto_cipher_env_t *cipher, char *in, r = crypto_cipher_decrypt(cipher, out, in, CELL_PAYLOAD_SIZE); if (r) { - warn(LD_BUG,"Error during relay encryption"); + log_warn(LD_BUG,"Error during relay encryption"); return -1; } memcpy(in,out,CELL_PAYLOAD_SIZE); @@ -157,7 +157,7 @@ circuit_receive_relay_cell(cell_t *cell, circuit_t *circ, int cell_direction) return 0; if (relay_crypt(circ, cell, cell_direction, &layer_hint, &recognized) < 0) { - warn(LD_BUG,"relay crypt failed. Dropping connection."); + log_warn(LD_BUG,"relay crypt failed. Dropping connection."); return -1; } @@ -165,7 +165,7 @@ circuit_receive_relay_cell(cell_t *cell, circuit_t *circ, int cell_direction) conn = relay_lookup_conn(circ, cell, cell_direction); if (cell_direction == CELL_DIRECTION_OUT) { ++stats_n_relay_cells_delivered; - debug(LD_OR,"Sending away from origin."); + log_debug(LD_OR,"Sending away from origin."); if ((reason=connection_edge_process_relay_cell(cell, circ, conn, NULL)) < 0) { log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, @@ -176,10 +176,11 @@ circuit_receive_relay_cell(cell_t *cell, circuit_t *circ, int cell_direction) } if (cell_direction == CELL_DIRECTION_IN) { ++stats_n_relay_cells_delivered; - debug(LD_OR,"Sending to origin."); + log_debug(LD_OR,"Sending to origin."); if ((reason = connection_edge_process_relay_cell(cell, circ, conn, layer_hint)) < 0) { - warn(LD_OR,"connection_edge_process_relay_cell (at origin) failed."); + log_warn(LD_OR, + "connection_edge_process_relay_cell (at origin) failed."); return reason; } } @@ -203,8 +204,8 @@ circuit_receive_relay_cell(cell_t *cell, circuit_t *circ, int cell_direction) cell->circ_id = circ->rend_splice->p_circ_id; if ((reason = circuit_receive_relay_cell(cell, circ->rend_splice, CELL_DIRECTION_IN)) < 0) { - warn(LD_REND, "Error relaying cell across rendezvous; closing " - "circuits"); + log_warn(LD_REND, "Error relaying cell across rendezvous; closing " + "circuits"); /* XXXX Do this here, or just return -1? */ circuit_mark_for_close(circ, -reason); return reason; @@ -216,7 +217,7 @@ circuit_receive_relay_cell(cell_t *cell, circuit_t *circ, int cell_direction) return -END_CIRC_REASON_TORPROTOCOL; } - debug(LD_OR,"Passing on unrecognized cell."); + log_debug(LD_OR,"Passing on unrecognized cell."); ++stats_n_relay_cells_relayed; connection_or_write_cell_to_buf(cell, conn); return 0; @@ -281,7 +282,7 @@ relay_crypt(circuit_t *circ, cell_t *cell, int cell_direction, thishop = thishop->next; } while (thishop != circ->cpath && thishop->state == CPATH_STATE_OPEN); - warn(LD_OR,"in-cell at OP not recognized. Closing."); + log_warn(LD_OR,"in-cell at OP not recognized. Closing."); return -1; } else { /* we're in the middle. Just one crypt. */ if (relay_crypt_one_payload(circ->p_crypto, cell->payload, 1) < 0) @@ -322,7 +323,7 @@ circuit_package_relay_cell(cell_t *cell, circuit_t *circ, if (cell_direction == CELL_DIRECTION_OUT) { conn = circ->n_conn; if (!conn) { - warn(LD_BUG,"outgoing relay cell has n_conn==NULL. Dropping."); + log_warn(LD_BUG,"outgoing relay cell has n_conn==NULL. Dropping."); return 0; /* just drop it */ } relay_set_digest(layer_hint->f_digest, cell); @@ -332,7 +333,7 @@ circuit_package_relay_cell(cell_t *cell, circuit_t *circ, do { tor_assert(thishop); /* XXXX RD This is a bug, right? */ - debug(LD_OR,"crypting a layer of the relay cell."); + log_debug(LD_OR,"crypting a layer of the relay cell."); if (relay_crypt_one_payload(thishop->f_crypto, cell->payload, 1) < 0) { return -1; } @@ -344,7 +345,7 @@ circuit_package_relay_cell(cell_t *cell, circuit_t *circ, conn = circ->p_conn; if (!conn) { /* XXXX RD This is a bug, right? */ - warn(LD_BUG,"incoming relay cell has p_conn==NULL. Dropping."); + log_warn(LD_BUG,"incoming relay cell has p_conn==NULL. Dropping."); assert_circuit_ok(circ); return 0; /* just drop it */ } @@ -377,7 +378,7 @@ relay_lookup_conn(circuit_t *circ, cell_t *cell, int cell_direction) for (tmpconn = circ->n_streams; tmpconn; tmpconn=tmpconn->next_stream) { if (rh.stream_id == tmpconn->stream_id && !tmpconn->marked_for_close) { - debug(LD_EXIT,"found conn for stream %d.", rh.stream_id); + log_debug(LD_EXIT,"found conn for stream %d.", rh.stream_id); if (cell_direction == CELL_DIRECTION_OUT || connection_edge_is_rendezvous_stream(tmpconn)) return tmpconn; @@ -385,14 +386,14 @@ relay_lookup_conn(circuit_t *circ, cell_t *cell, int cell_direction) } for (tmpconn = circ->p_streams; tmpconn; tmpconn=tmpconn->next_stream) { if (rh.stream_id == tmpconn->stream_id && !tmpconn->marked_for_close) { - debug(LD_APP,"found conn for stream %d.", rh.stream_id); + log_debug(LD_APP,"found conn for stream %d.", rh.stream_id); return tmpconn; } } for (tmpconn = circ->resolving_streams; tmpconn; tmpconn=tmpconn->next_stream) { if (rh.stream_id == tmpconn->stream_id && !tmpconn->marked_for_close) { - debug(LD_EXIT,"found conn for stream %d.", rh.stream_id); + log_debug(LD_EXIT,"found conn for stream %d.", rh.stream_id); return tmpconn; } } @@ -447,19 +448,19 @@ connection_edge_send_command(connection_t *fromconn, circuit_t *circ, int cell_direction; if (fromconn && fromconn->marked_for_close) { - warn(LD_BUG, - "Bug: called on conn that's already marked for close at %s:%d.", - fromconn->marked_for_close_file, fromconn->marked_for_close); + log_warn(LD_BUG, + "Bug: called on conn that's already marked for close at %s:%d.", + fromconn->marked_for_close_file, fromconn->marked_for_close); return 0; } if (!circ) { tor_assert(fromconn); if (fromconn->type == CONN_TYPE_AP) { - info(LD_APP,"no circ. Closing conn."); + log_info(LD_APP,"no circ. Closing conn."); connection_mark_unattached_ap(fromconn, END_STREAM_REASON_INTERNAL); } else { - info(LD_EXIT,"no circ. Closing conn."); + log_info(LD_EXIT,"no circ. Closing conn."); fromconn->has_sent_end = 1; /* no circ to send to */ connection_mark_for_close(fromconn); } @@ -487,12 +488,12 @@ connection_edge_send_command(connection_t *fromconn, circuit_t *circ, memcpy(cell.payload+RELAY_HEADER_SIZE, payload, payload_len); } - debug(LD_OR,"delivering %d cell %s.", relay_command, - cell_direction == CELL_DIRECTION_OUT ? "forward" : "backward"); + log_debug(LD_OR,"delivering %d cell %s.", relay_command, + cell_direction == CELL_DIRECTION_OUT ? "forward" : "backward"); if (circuit_package_relay_cell(&cell, circ, cell_direction, cpath_layer) < 0) { - warn(LD_BUG,"circuit_package_relay_cell failed. Closing."); + log_warn(LD_BUG,"circuit_package_relay_cell failed. Closing."); circuit_mark_for_close(circ, END_CIRC_REASON_INTERNAL); return -1; } @@ -508,8 +509,8 @@ connection_edge_end_reason_str(int reason) { switch (reason) { case -1: - warn(LD_PROTOCOL, - "End cell arrived with length 0. Should be at least 1."); + log_warn(LD_PROTOCOL, + "End cell arrived with length 0. Should be at least 1."); return "MALFORMED"; case END_STREAM_REASON_MISC: return "misc error"; case END_STREAM_REASON_RESOLVEFAILED: return "resolve failed"; @@ -524,7 +525,7 @@ connection_edge_end_reason_str(int reason) case END_STREAM_REASON_CONNRESET: return "connection reset"; case END_STREAM_REASON_TORPROTOCOL: return "Tor protocol error"; default: - warn(LD_PROTOCOL,"Reason for ending (%d) not recognized.",reason); + log_warn(LD_PROTOCOL,"Reason for ending (%d) not recognized.",reason); return "unknown"; } } @@ -568,7 +569,7 @@ connection_edge_end_reason_socks5_response(int reason) case END_STREAM_REASON_NET_UNREACHABLE: return SOCKS5_NET_UNREACHABLE; default: - warn(LD_PROTOCOL,"Reason for ending (%d) not recognized.",reason); + log_warn(LD_PROTOCOL,"Reason for ending (%d) not recognized.",reason); return SOCKS5_GENERAL_ERROR; } } @@ -618,9 +619,9 @@ errno_to_end_reason(int e) E_CASE(EMFILE): return END_STREAM_REASON_RESOURCELIMIT; default: - info(LD_EXIT, "Didn't recognize errno %d (%s); telling the OP that " - "we are ending a stream for 'misc' reason.", - e, tor_socket_strerror(e)); + log_info(LD_EXIT, "Didn't recognize errno %d (%s); telling the OP that " + "we are ending a stream for 'misc' reason.", + e, tor_socket_strerror(e)); return END_STREAM_REASON_MISC; } } @@ -656,9 +657,9 @@ connection_edge_process_end_not_open( if (rh->length > 0 && edge_reason_is_retriable(reason) && conn->type == CONN_TYPE_AP) { - info(LD_APP,"Address '%s' refused due to '%s'. Considering retrying.", - safe_str(conn->socks_request->address), - connection_edge_end_reason_str(reason)); + log_info(LD_APP,"Address '%s' refused due to '%s'. Considering retrying.", + safe_str(conn->socks_request->address), + connection_edge_end_reason_str(reason)); exitrouter = router_get_by_digest(circ->build_state->chosen_exit->identity_digest); switch (reason) { @@ -667,8 +668,8 @@ connection_edge_process_end_not_open( uint32_t addr = ntohl(get_uint32(cell->payload+RELAY_HEADER_SIZE+1)); int ttl; if (!addr) { - info(LD_APP,"Address '%s' resolved to 0.0.0.0. Closing,", - safe_str(conn->socks_request->address)); + log_info(LD_APP,"Address '%s' resolved to 0.0.0.0. Closing,", + safe_str(conn->socks_request->address)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); return 0; } @@ -684,7 +685,7 @@ connection_edge_process_end_not_open( (rh->length < 5 || (tor_inet_aton(conn->socks_request->address, &in) && !conn->chosen_exit_name))) { - notice(LD_APP, + log_notice(LD_APP, "Exitrouter '%s' seems to be more restrictive than its exit " "policy. Not using this router as exit for now.", exitrouter->nickname); @@ -712,9 +713,11 @@ connection_edge_process_end_not_open( return 0; /* else, conn will get closed below */ } else { - notice(LD_APP,"Have tried resolving or connecting to address '%s' " - "at %d different places. Giving up.", - safe_str(conn->socks_request->address), MAX_RESOLVE_FAILURES); + log_notice(LD_APP, + "Have tried resolving or connecting to address '%s' " + "at %d different places. Giving up.", + safe_str(conn->socks_request->address), + MAX_RESOLVE_FAILURES); /* clear the failures, so it will have a full try next time */ client_dns_clear_failures(conn->socks_request->address); } @@ -731,10 +734,11 @@ connection_edge_process_end_not_open( /* else, will close below */ break; } /* end switch */ - info(LD_APP,"Giving up on retrying; conn can't be handled."); + log_info(LD_APP,"Giving up on retrying; conn can't be handled."); } - info(LD_APP,"Edge got end (%s) before we're connected. Marking for close.", + log_info(LD_APP, + "Edge got end (%s) before we're connected. Marking for close.", connection_edge_end_reason_str(rh->length > 0 ? reason : -1)); if (conn->type == CONN_TYPE_AP) { circuit_log_path(LOG_INFO,LD_APP,circ); @@ -764,19 +768,20 @@ connection_edge_process_relay_cell_not_open( if (conn->type == CONN_TYPE_AP && rh->command == RELAY_COMMAND_CONNECTED) { if (conn->state != AP_CONN_STATE_CONNECT_WAIT) { - warn(LD_APP,"Got 'connected' while not in state connect_wait. " - "Dropping."); + log_warn(LD_APP,"Got 'connected' while not in state connect_wait. " + "Dropping."); return 0; } // log_fn(LOG_INFO,"Connected! Notifying application."); conn->state = AP_CONN_STATE_OPEN; - info(LD_APP,"'connected' received after %d seconds.", - (int)(time(NULL) - conn->timestamp_lastread)); + log_info(LD_APP,"'connected' received after %d seconds.", + (int)(time(NULL) - conn->timestamp_lastread)); if (rh->length >= 4) { uint32_t addr = ntohl(get_uint32(cell->payload+RELAY_HEADER_SIZE)); int ttl; if (!addr) { - info(LD_APP,"...but it claims the IP address was 0.0.0.0. Closing."); + log_info(LD_APP, + "...but it claims the IP address was 0.0.0.0. Closing."); connection_edge_end(conn, END_STREAM_REASON_TORPROTOCOL, conn->cpath_layer); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); @@ -803,14 +808,14 @@ connection_edge_process_relay_cell_not_open( int ttl; int answer_len; if (conn->state != AP_CONN_STATE_RESOLVE_WAIT) { - warn(LD_APP,"Got a 'resolved' cell while not in state resolve_wait. " - "Dropping."); + log_warn(LD_APP,"Got a 'resolved' cell while not in state resolve_wait. " + "Dropping."); return 0; } tor_assert(conn->socks_request->command == SOCKS_COMMAND_RESOLVE); answer_len = cell->payload[RELAY_HEADER_SIZE+1]; if (rh->length < 2 || answer_len+2>rh->length) { - warn(LD_PROTOCOL, "Dropping malformed 'resolved' cell"); + log_warn(LD_PROTOCOL, "Dropping malformed 'resolved' cell"); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); return 0; } @@ -865,10 +870,11 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, relay_header_unpack(&rh, cell->payload); // log_fn(LOG_DEBUG,"command %d stream %d", rh.command, rh.stream_id); num_seen++; - debug(domain, "Now seen %d relay cells here.", num_seen); + log_debug(domain, "Now seen %d relay cells here.", num_seen); if (rh.length > RELAY_PAYLOAD_SIZE) { - warn(LD_PROTOCOL, "Relay cell length field too long. Closing circuit."); + log_warn(LD_PROTOCOL, + "Relay cell length field too long. Closing circuit."); return - END_CIRC_REASON_TORPROTOCOL; } @@ -881,16 +887,16 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, switch (rh.command) { case RELAY_COMMAND_DROP: - info(domain,"Got a relay-level padding cell. Dropping."); + log_info(domain,"Got a relay-level padding cell. Dropping."); return 0; case RELAY_COMMAND_BEGIN: if (layer_hint && circ->purpose != CIRCUIT_PURPOSE_S_REND_JOINED) { - warn(LD_APP,"relay begin request unsupported at AP. Dropping."); + log_warn(LD_APP,"relay begin request unsupported at AP. Dropping."); return 0; } if (conn) { - warn(domain,"begin cell for known stream. Dropping."); + log_warn(domain,"begin cell for known stream. Dropping."); return 0; } connection_exit_begin_conn(cell, circ); @@ -906,13 +912,13 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection_mark_for_close(conn); return -END_CIRC_REASON_TORPROTOCOL; } - debug(domain,"circ deliver_window now %d.", layer_hint ? - layer_hint->deliver_window : circ->deliver_window); + log_debug(domain,"circ deliver_window now %d.", layer_hint ? + layer_hint->deliver_window : circ->deliver_window); circuit_consider_sending_sendme(circ, layer_hint); if (!conn) { - info(domain,"data cell dropped, unknown stream."); + log_info(domain,"data cell dropped, unknown stream."); return 0; } @@ -929,19 +935,20 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, return 0; case RELAY_COMMAND_END: if (!conn) { - info(domain,"end cell (%s) dropped, unknown stream.", - connection_edge_end_reason_str(rh.length > 0 ? - *(char *)(cell->payload+RELAY_HEADER_SIZE) : -1)); + log_info(domain,"end cell (%s) dropped, unknown stream.", + connection_edge_end_reason_str(rh.length > 0 ? + *(char *)(cell->payload+RELAY_HEADER_SIZE) : -1)); return 0; } /* XXX add to this log_fn the exit node's nickname? */ - info(domain,"%d: end cell (%s) for stream %d. Removing stream.", - conn->s, - connection_edge_end_reason_str(rh.length > 0 ? - *(char *)(cell->payload+RELAY_HEADER_SIZE) : -1), - conn->stream_id); + log_info(domain,"%d: end cell (%s) for stream %d. Removing stream.", + conn->s, + connection_edge_end_reason_str(rh.length > 0 ? + *(char *)(cell->payload+RELAY_HEADER_SIZE) : -1), + conn->stream_id); if (conn->socks_request && !conn->socks_request->has_finished) - warn(LD_BUG,"Bug: open stream hasn't sent socks answer yet? Closing."); + log_warn(LD_BUG, + "Bug: open stream hasn't sent socks answer yet? Closing."); #ifdef HALF_OPEN conn->done_sending = 1; shutdown(conn->s, 1); /* XXX check return; refactor NM */ @@ -964,29 +971,30 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, return 0; case RELAY_COMMAND_EXTEND: if (conn) { - warn(domain,"'extend' for non-zero stream. Dropping."); + log_warn(domain,"'extend' for non-zero stream. Dropping."); return 0; } return circuit_extend(cell, circ); case RELAY_COMMAND_EXTENDED: if (!layer_hint) { - warn(LD_PROTOCOL,"'extended' unsupported at non-origin. Dropping."); + log_warn(LD_PROTOCOL, + "'extended' unsupported at non-origin. Dropping."); return 0; } - debug(domain,"Got an extended cell! Yay."); + log_debug(domain,"Got an extended cell! Yay."); if ((reason = circuit_finish_handshake(circ, CELL_CREATED, cell->payload+RELAY_HEADER_SIZE)) < 0) { - warn(domain,"circuit_finish_handshake failed."); + log_warn(domain,"circuit_finish_handshake failed."); return reason; } if ((reason=circuit_send_next_onion_skin(circ))<0) { - info(domain,"circuit_send_next_onion_skin() failed."); + log_info(domain,"circuit_send_next_onion_skin() failed."); return reason; } return 0; case RELAY_COMMAND_TRUNCATE: if (layer_hint) { - warn(LD_APP,"'truncate' unsupported at origin. Dropping."); + log_warn(LD_APP,"'truncate' unsupported at origin. Dropping."); return 0; } if (circ->n_conn) { @@ -994,7 +1002,7 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection_or_send_destroy(circ->n_circ_id, circ->n_conn, reason); circuit_set_circid_orconn(circ, 0, NULL, N_CONN_CHANGED); } - debug(LD_EXIT, "Processed 'truncate', replying."); + log_debug(LD_EXIT, "Processed 'truncate', replying."); { char payload[1]; payload[0] = (char)END_CIRC_REASON_REQUESTED; @@ -1004,7 +1012,7 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, return 0; case RELAY_COMMAND_TRUNCATED: if (!layer_hint) { - warn(LD_EXIT,"'truncated' unsupported at non-origin. Dropping."); + log_warn(LD_EXIT,"'truncated' unsupported at non-origin. Dropping."); return 0; } circuit_truncated(circ, layer_hint); @@ -1015,26 +1023,28 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, "'connected' unsupported while open. Closing circ."); return -END_CIRC_REASON_TORPROTOCOL; } - info(domain,"'connected' received, no conn attached anymore. Ignoring."); + log_info(domain, + "'connected' received, no conn attached anymore. Ignoring."); return 0; case RELAY_COMMAND_SENDME: if (!conn) { if (layer_hint) { layer_hint->package_window += CIRCWINDOW_INCREMENT; - debug(LD_APP,"circ-level sendme at origin, packagewindow %d.", - layer_hint->package_window); + log_debug(LD_APP,"circ-level sendme at origin, packagewindow %d.", + layer_hint->package_window); circuit_resume_edge_reading(circ, layer_hint); } else { circ->package_window += CIRCWINDOW_INCREMENT; - debug(LD_APP,"circ-level sendme at non-origin, packagewindow %d.", - circ->package_window); + log_debug(LD_APP, + "circ-level sendme at non-origin, packagewindow %d.", + circ->package_window); circuit_resume_edge_reading(circ, layer_hint); } return 0; } conn->package_window += STREAMWINDOW_INCREMENT; - debug(domain,"stream-level sendme, packagewindow now %d.", - conn->package_window); + log_debug(domain,"stream-level sendme, packagewindow now %d.", + conn->package_window); connection_start_reading(conn); /* handle whatever might still be on the inbuf */ if (connection_edge_package_raw_inbuf(conn, 1) < 0) { @@ -1045,24 +1055,25 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, return 0; case RELAY_COMMAND_RESOLVE: if (layer_hint) { - warn(LD_APP,"resolve request unsupported at AP; dropping."); + log_warn(LD_APP,"resolve request unsupported at AP; dropping."); return 0; } else if (conn) { - warn(domain, "resolve request for known stream; dropping."); + log_warn(domain, "resolve request for known stream; dropping."); return 0; } else if (circ->purpose != CIRCUIT_PURPOSE_OR) { - warn(domain, "resolve request on circ with purpose %d; dropping", - circ->purpose); + log_warn(domain, "resolve request on circ with purpose %d; dropping", + circ->purpose); return 0; } connection_exit_begin_resolve(cell, circ); return 0; case RELAY_COMMAND_RESOLVED: if (conn) { - warn(domain,"'resolved' unsupported while open. Closing circ."); + log_warn(domain,"'resolved' unsupported while open. Closing circ."); return -END_CIRC_REASON_TORPROTOCOL; } - info(domain,"'resolved' received, no conn attached anymore. Ignoring."); + log_info(domain, + "'resolved' received, no conn attached anymore. Ignoring."); return 0; case RELAY_COMMAND_ESTABLISH_INTRO: case RELAY_COMMAND_ESTABLISH_RENDEZVOUS: @@ -1107,9 +1118,9 @@ connection_edge_package_raw_inbuf(connection_t *conn, int package_partial) tor_assert(conn); tor_assert(!connection_speaks_cells(conn)); if (conn->marked_for_close) { - warn(LD_BUG, - "Bug: called on conn that's already marked for close at %s:%d.", - conn->marked_for_close_file, conn->marked_for_close); + log_warn(LD_BUG, + "Bug: called on conn that's already marked for close at %s:%d.", + conn->marked_for_close_file, conn->marked_for_close); return 0; } @@ -1117,7 +1128,7 @@ repeat_connection_edge_package_raw_inbuf: circ = circuit_get_by_edge_conn(conn); if (!circ) { - info(domain,"conn has no circuit! Closing."); + log_info(domain,"conn has no circuit! Closing."); return -1; } @@ -1125,8 +1136,8 @@ repeat_connection_edge_package_raw_inbuf: return 0; if (conn->package_window <= 0) { - info(domain,"called with package_window %d. Skipping.", - conn->package_window); + log_info(domain,"called with package_window %d. Skipping.", + conn->package_window); connection_stop_reading(conn); return 0; } @@ -1149,8 +1160,8 @@ repeat_connection_edge_package_raw_inbuf: connection_fetch_from_buf(payload, length, conn); - debug(domain,"(%d) Packaging %d bytes (%d waiting).", conn->s, - (int)length, (int)buf_datalen(conn->inbuf)); + log_debug(domain,"(%d) Packaging %d bytes (%d waiting).", conn->s, + (int)length, (int)buf_datalen(conn->inbuf)); if (connection_edge_send_command(conn, circ, RELAY_COMMAND_DATA, payload, length, conn->cpath_layer) < 0) @@ -1167,11 +1178,11 @@ repeat_connection_edge_package_raw_inbuf: if (--conn->package_window <= 0) { /* is it 0 after decrement? */ connection_stop_reading(conn); - debug(domain,"conn->package_window reached 0."); + log_debug(domain,"conn->package_window reached 0."); circuit_consider_stop_edge_reading(circ, conn->cpath_layer); return 0; /* don't process the inbuf any more */ } - debug(domain,"conn->package_window is now %d",conn->package_window); + log_debug(domain,"conn->package_window is now %d",conn->package_window); /* handle more if there's more, or return 0 if there isn't */ goto repeat_connection_edge_package_raw_inbuf; @@ -1195,17 +1206,18 @@ connection_edge_consider_sending_sendme(connection_t *conn) if (!circ) { /* this can legitimately happen if the destroy has already * arrived and torn down the circuit */ - info(LD_APP,"No circuit associated with conn. Skipping."); + log_info(LD_APP,"No circuit associated with conn. Skipping."); return; } while (conn->deliver_window < STREAMWINDOW_START - STREAMWINDOW_INCREMENT) { - debug(conn->cpath_layer?LD_APP:LD_EXIT, - "Outbuf %d, Queueing stream sendme.", (int)conn->outbuf_flushlen); + log_debug(conn->cpath_layer?LD_APP:LD_EXIT, + "Outbuf %d, Queueing stream sendme.", + (int)conn->outbuf_flushlen); conn->deliver_window += STREAMWINDOW_INCREMENT; if (connection_edge_send_command(conn, circ, RELAY_COMMAND_SENDME, NULL, 0, conn->cpath_layer) < 0) { - warn(LD_APP,"connection_edge_send_command failed. Returning."); + log_warn(LD_APP,"connection_edge_send_command failed. Returning."); return; /* the circuit's closed, don't continue */ } } @@ -1220,7 +1232,7 @@ static void circuit_resume_edge_reading(circuit_t *circ, crypt_path_t *layer_hint) { - debug(layer_hint?LD_APP:LD_EXIT,"resuming"); + log_debug(layer_hint?LD_APP:LD_EXIT,"resuming"); /* have to check both n_streams and p_streams, to handle rendezvous */ if (circuit_resume_edge_reading_helper(circ->n_streams, circ, layer_hint) @@ -1274,9 +1286,10 @@ circuit_consider_stop_edge_reading(circuit_t *circ, crypt_path_t *layer_hint) unsigned domain = layer_hint ? LD_APP : LD_EXIT; if (!layer_hint) { - debug(domain,"considering circ->package_window %d", circ->package_window); + log_debug(domain,"considering circ->package_window %d", + circ->package_window); if (circ->package_window <= 0) { - debug(domain,"yes, not-at-origin. stopped."); + log_debug(domain,"yes, not-at-origin. stopped."); for (conn = circ->n_streams; conn; conn=conn->next_stream) connection_stop_reading(conn); return 1; @@ -1284,10 +1297,10 @@ circuit_consider_stop_edge_reading(circuit_t *circ, crypt_path_t *layer_hint) return 0; } /* else, layer hint is defined, use it */ - debug(domain,"considering layer_hint->package_window %d", - layer_hint->package_window); + log_debug(domain,"considering layer_hint->package_window %d", + layer_hint->package_window); if (layer_hint->package_window <= 0) { - debug(domain,"yes, at-origin. stopped."); + log_debug(domain,"yes, at-origin. stopped."); for (conn = circ->n_streams; conn; conn=conn->next_stream) if (conn->cpath_layer == layer_hint) connection_stop_reading(conn); @@ -1312,14 +1325,15 @@ circuit_consider_sending_sendme(circuit_t *circ, crypt_path_t *layer_hint) // layer_hint ? "defined" : "null"); while ((layer_hint ? layer_hint->deliver_window : circ->deliver_window) < CIRCWINDOW_START - CIRCWINDOW_INCREMENT) { - debug(LD_CIRC,"Queueing circuit sendme."); + log_debug(LD_CIRC,"Queueing circuit sendme."); if (layer_hint) layer_hint->deliver_window += CIRCWINDOW_INCREMENT; else circ->deliver_window += CIRCWINDOW_INCREMENT; if (connection_edge_send_command(NULL, circ, RELAY_COMMAND_SENDME, NULL, 0, layer_hint) < 0) { - warn(LD_CIRC,"connection_edge_send_command failed. Circuit's closed."); + log_warn(LD_CIRC, + "connection_edge_send_command failed. Circuit's closed."); return; /* the circuit's closed, don't continue */ } } diff --git a/src/or/rendclient.c b/src/or/rendclient.c index dfb5186104..82be7f0d84 100644 --- a/src/or/rendclient.c +++ b/src/or/rendclient.c @@ -20,7 +20,7 @@ rend_client_introcirc_has_opened(circuit_t *circ) tor_assert(CIRCUIT_IS_ORIGIN(circ)); tor_assert(circ->cpath); - info(LD_REND,"introcirc is open"); + log_info(LD_REND,"introcirc is open"); connection_ap_attach_pending(); } @@ -31,10 +31,10 @@ static int rend_client_send_establish_rendezvous(circuit_t *circ) { tor_assert(circ->purpose == CIRCUIT_PURPOSE_C_ESTABLISH_REND); - info(LD_REND, "Sending an ESTABLISH_RENDEZVOUS cell"); + log_info(LD_REND, "Sending an ESTABLISH_RENDEZVOUS cell"); if (crypto_rand(circ->rend_cookie, REND_COOKIE_LEN) < 0) { - warn(LD_BUG, "Internal error: Couldn't produce random cookie."); + log_warn(LD_BUG, "Internal error: Couldn't produce random cookie."); circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN); return -1; } @@ -43,7 +43,7 @@ rend_client_send_establish_rendezvous(circuit_t *circ) circ->rend_cookie, REND_COOKIE_LEN, circ->cpath->prev)<0) { /* circ is already marked for close */ - warn(LD_GENERAL, "Couldn't send ESTABLISH_RENDEZVOUS cell"); + log_warn(LD_GENERAL, "Couldn't send ESTABLISH_RENDEZVOUS cell"); return -1; } @@ -70,14 +70,15 @@ rend_client_send_introduction(circuit_t *introcirc, circuit_t *rendcirc) rendcirc->rend_query)); if (rend_cache_lookup_entry(introcirc->rend_query, -1, &entry) < 1) { - warn(LD_REND,"query '%s' didn't have valid rend desc in cache. Failing.", - safe_str(introcirc->rend_query)); + log_warn(LD_REND, + "query '%s' didn't have valid rend desc in cache. Failing.", + safe_str(introcirc->rend_query)); goto err; } /* first 20 bytes of payload are the hash of bob's pk */ if (crypto_pk_get_digest(entry->parsed->pk, payload)<0) { - warn(LD_BUG, "Internal error: couldn't hash public key."); + log_warn(LD_BUG, "Internal error: couldn't hash public key."); goto err; } @@ -88,11 +89,11 @@ rend_client_send_introduction(circuit_t *introcirc, circuit_t *rendcirc) tor_malloc_zero(sizeof(crypt_path_t)); cpath->magic = CRYPT_PATH_MAGIC; if (!(cpath->dh_handshake_state = crypto_dh_new())) { - warn(LD_BUG, "Internal error: couldn't allocate DH."); + log_warn(LD_BUG, "Internal error: couldn't allocate DH."); goto err; } if (crypto_dh_generate_public(cpath->dh_handshake_state)<0) { - warn(LD_BUG, "Internal error: couldn't generate g^x."); + log_warn(LD_BUG, "Internal error: couldn't generate g^x."); goto err; } } @@ -122,7 +123,7 @@ rend_client_send_introduction(circuit_t *introcirc, circuit_t *rendcirc) if (crypto_dh_get_public(cpath->dh_handshake_state, tmp+dh_offset, DH_KEY_LEN)<0) { - warn(LD_BUG, "Internal error: couldn't extract g^x."); + log_warn(LD_BUG, "Internal error: couldn't extract g^x."); goto err; } @@ -133,7 +134,7 @@ rend_client_send_introduction(circuit_t *introcirc, circuit_t *rendcirc) dh_offset+DH_KEY_LEN, PK_PKCS1_OAEP_PADDING, 0); if (r<0) { - warn(LD_BUG,"Internal error: hybrid pk encrypt failed."); + log_warn(LD_BUG,"Internal error: hybrid pk encrypt failed."); goto err; } @@ -145,7 +146,7 @@ rend_client_send_introduction(circuit_t *introcirc, circuit_t *rendcirc) payload, payload_len, introcirc->cpath->prev)<0) { /* introcirc is already marked for close. leave rendcirc alone. */ - warn(LD_BUG, "Couldn't send INTRODUCE1 cell"); + log_warn(LD_BUG, "Couldn't send INTRODUCE1 cell"); return -1; } @@ -167,7 +168,7 @@ rend_client_rendcirc_has_opened(circuit_t *circ) tor_assert(circ->purpose == CIRCUIT_PURPOSE_C_ESTABLISH_REND); tor_assert(CIRCUIT_IS_ORIGIN(circ)); - info(LD_REND,"rendcirc is open"); + log_info(LD_REND,"rendcirc is open"); /* generate a rendezvous cookie, store it in circ */ if (rend_client_send_establish_rendezvous(circ) < 0) { @@ -184,8 +185,9 @@ rend_client_introduction_acked(circuit_t *circ, circuit_t *rendcirc; if (circ->purpose != CIRCUIT_PURPOSE_C_INTRODUCE_ACK_WAIT) { - warn(LD_PROTOCOL, "Received REND_INTRODUCE_ACK on unexpected circuit %d.", - circ->n_circ_id); + log_warn(LD_PROTOCOL, + "Received REND_INTRODUCE_ACK on unexpected circuit %d.", + circ->n_circ_id); circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN); return -1; } @@ -198,13 +200,13 @@ rend_client_introduction_acked(circuit_t *circ, /* Locate the rend circ which is waiting to hear about this ack, * and tell it. */ - info(LD_REND,"Received ack. Telling rend circ..."); + log_info(LD_REND,"Received ack. Telling rend circ..."); rendcirc = circuit_get_by_rend_query_and_purpose( circ->rend_query, CIRCUIT_PURPOSE_C_REND_READY); if (rendcirc) { /* remember the ack */ rendcirc->purpose = CIRCUIT_PURPOSE_C_REND_READY_INTRO_ACKED; } else { - info(LD_REND,"...Found no rend circ. Dropping on the floor."); + log_info(LD_REND,"...Found no rend circ. Dropping on the floor."); } /* close the circuit: we won't need it anymore. */ circ->purpose = CIRCUIT_PURPOSE_C_INTRODUCE_ACKED; @@ -224,16 +226,17 @@ rend_client_introduction_acked(circuit_t *circ, int result; extend_info = rend_client_get_random_intro(circ->rend_query); if (!extend_info) { - warn(LD_REND, "No introduction points left for %s. Closing.", - safe_str(circ->rend_query)); + log_warn(LD_REND, "No introduction points left for %s. Closing.", + safe_str(circ->rend_query)); circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN); return -1; } - info(LD_REND, - "Got nack for %s from %s. Re-extending circ %d, this time to %s.", - safe_str(circ->rend_query), - circ->build_state->chosen_exit->nickname, circ->n_circ_id, - extend_info->nickname); + log_info(LD_REND, + "Got nack for %s from %s. Re-extending circ %d, " + "this time to %s.", + safe_str(circ->rend_query), + circ->build_state->chosen_exit->nickname, circ->n_circ_id, + extend_info->nickname); result = circuit_extend_to_new_exit(circ, extend_info); extend_info_free(extend_info); return result; @@ -250,8 +253,8 @@ void rend_client_refetch_renddesc(const char *query) { if (connection_get_by_type_state_rendquery(CONN_TYPE_DIR, 0, query)) { - info(LD_REND,"Would fetch a new renddesc here (for %s), but one is " - "already in progress.", safe_str(query)); + log_info(LD_REND,"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); @@ -273,12 +276,12 @@ rend_client_remove_intro_point(extend_info_t *failed_intro, const char *query) r = rend_cache_lookup_entry(query, -1, &ent); if (r<0) { - warn(LD_BUG, "Bug: malformed service ID '%s'.", safe_str(query)); + log_warn(LD_BUG, "Bug: malformed service ID '%s'.", safe_str(query)); return -1; } if (r==0) { - info(LD_REND, "Unknown service %s. Re-fetching descriptor.", - safe_str(query)); + log_info(LD_REND, "Unknown service %s. Re-fetching descriptor.", + safe_str(query)); rend_client_refetch_renddesc(query); return 0; } @@ -312,8 +315,9 @@ rend_client_remove_intro_point(extend_info_t *failed_intro, const char *query) } if (!ent->parsed->n_intro_points) { - info(LD_REND,"No more intro points remain for %s. Re-fetching descriptor.", - safe_str(query)); + log_info(LD_REND, + "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 */ @@ -324,8 +328,8 @@ rend_client_remove_intro_point(extend_info_t *failed_intro, const char *query) return 0; } - info(LD_REND,"%d options left for %s.", - ent->parsed->n_intro_points, safe_str(query)); + log_info(LD_REND,"%d options left for %s.", + ent->parsed->n_intro_points, safe_str(query)); return 1; } @@ -338,13 +342,13 @@ rend_client_rendezvous_acked(circuit_t *circ, const char *request, { /* we just got an ack for our establish-rendezvous. switch purposes. */ if (circ->purpose != CIRCUIT_PURPOSE_C_ESTABLISH_REND) { - warn(LD_PROTOCOL,"Got a rendezvous ack when we weren't expecting one. " - "Closing circ."); + log_warn(LD_PROTOCOL,"Got a rendezvous ack when we weren't expecting one. " + "Closing circ."); circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN); return -1; } - info(LD_REND,"Got rendezvous ack. This circuit is now ready for " - "rendezvous."); + log_info(LD_REND,"Got rendezvous ack. This circuit is now ready for " + "rendezvous."); circ->purpose = CIRCUIT_PURPOSE_C_REND_READY; return 0; } @@ -360,15 +364,15 @@ rend_client_receive_rendezvous(circuit_t *circ, const char *request, if ((circ->purpose != CIRCUIT_PURPOSE_C_REND_READY && circ->purpose != CIRCUIT_PURPOSE_C_REND_READY_INTRO_ACKED) || !circ->build_state->pending_final_cpath) { - warn(LD_PROTOCOL,"Got rendezvous2 cell from hidden service, but not " - "expecting it. Closing."); + log_warn(LD_PROTOCOL,"Got rendezvous2 cell from hidden service, but not " + "expecting it. Closing."); circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN); return -1; } if (request_len != DH_KEY_LEN+DIGEST_LEN) { - warn(LD_PROTOCOL,"Incorrect length (%d) on RENDEZVOUS2 cell.", - (int)request_len); + log_warn(LD_PROTOCOL,"Incorrect length (%d) on RENDEZVOUS2 cell.", + (int)request_len); goto err; } @@ -379,7 +383,7 @@ rend_client_receive_rendezvous(circuit_t *circ, const char *request, tor_assert(hop->dh_handshake_state); if (crypto_dh_compute_secret(hop->dh_handshake_state, request, DH_KEY_LEN, keys, DIGEST_LEN+CPATH_KEY_MATERIAL_LEN)<0) { - warn(LD_GENERAL, "Couldn't complete DH handshake."); + log_warn(LD_GENERAL, "Couldn't complete DH handshake."); goto err; } /* ... and set up cpath. */ @@ -388,7 +392,7 @@ rend_client_receive_rendezvous(circuit_t *circ, const char *request, /* Check whether the digest is right... */ if (memcmp(keys, request+DH_KEY_LEN, DIGEST_LEN)) { - warn(LD_PROTOCOL, "Incorrect digest of key material."); + log_warn(LD_PROTOCOL, "Incorrect digest of key material."); goto err; } @@ -440,7 +444,7 @@ rend_client_desc_here(const char *query) entry->parsed->n_intro_points > 0) { /* either this fetch worked, or it failed but there was a * valid entry from before which we should reuse */ - info(LD_REND,"Rend desc is usable. Launching circuits."); + log_info(LD_REND,"Rend desc is usable. Launching circuits."); conn->state = AP_CONN_STATE_CIRCUIT_WAIT; /* restart their timeout values, so they get a fair shake at @@ -451,12 +455,12 @@ rend_client_desc_here(const char *query) if (connection_ap_handshake_attach_circuit(conn) < 0) { /* it will never work */ - warn(LD_REND,"Rendezvous attempt failed. Closing."); + log_warn(LD_REND,"Rendezvous attempt failed. Closing."); connection_mark_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH); } } else { /* 404, or fetch didn't get that far */ - notice(LD_REND,"Closing stream for '%s.onion': hidden service is " - "unavailable (try again later).", safe_str(query)); + log_notice(LD_REND,"Closing stream for '%s.onion': hidden service is " + "unavailable (try again later).", safe_str(query)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT); } } @@ -473,8 +477,9 @@ rend_client_get_random_intro(const char *query) rend_cache_entry_t *entry; if (rend_cache_lookup_entry(query, -1, &entry) < 1) { - warn(LD_REND,"Query '%s' didn't have valid rend desc in cache. Failing.", - safe_str(query)); + log_warn(LD_REND, + "Query '%s' didn't have valid rend desc in cache. Failing.", + safe_str(query)); return NULL; } @@ -491,8 +496,8 @@ rend_client_get_random_intro(const char *query) char *choice = entry->parsed->intro_points[i]; routerinfo_t *router = router_get_by_nickname(choice, 0); if (!router) { - info(LD_REND, "Unknown router with nickname '%s'; trying another.", - choice); + log_info(LD_REND, "Unknown router with nickname '%s'; trying another.", + choice); tor_free(choice); entry->parsed->intro_points[i] = entry->parsed->intro_points[--entry->parsed->n_intro_points]; diff --git a/src/or/rendcommon.c b/src/or/rendcommon.c index 1e0fb8af1d..40f84625b3 100644 --- a/src/or/rendcommon.c +++ b/src/or/rendcommon.c @@ -182,8 +182,8 @@ rend_parse_service_descriptor(const char *str, size_t len) cp += 8+DIGEST_LEN; if (end-cp < klen) goto truncated; if (!(info->onion_key = crypto_pk_asn1_decode(cp,klen))) { - warn(LD_PROTOCOL, - "Internal error decoding onion key for intro point."); + log_warn(LD_PROTOCOL, + "Internal error decoding onion key for intro point."); goto error; } cp += klen; @@ -193,21 +193,22 @@ rend_parse_service_descriptor(const char *str, size_t len) tor_assert(end-cp >= 0); if ((size_t)(end-cp) < keylen) goto truncated; if ((size_t)(end-cp) > keylen) { - warn(LD_PROTOCOL, "Signature is %d bytes too long on service descriptor.", - (int)((size_t)(end-cp) - keylen)); + log_warn(LD_PROTOCOL, + "Signature is %d bytes too long on service descriptor.", + (int)((size_t)(end-cp) - keylen)); goto error; } if (crypto_pk_public_checksig_digest(result->pk, (char*)str,cp-str, /* data */ (char*)cp,end-cp /* signature*/ )<0) { - warn(LD_PROTOCOL, "Bad signature on service descriptor."); + log_warn(LD_PROTOCOL, "Bad signature on service descriptor."); goto error; } return result; truncated: - warn(LD_PROTOCOL, "Truncated service descriptor."); + log_warn(LD_PROTOCOL, "Truncated service descriptor."); error: rend_service_descriptor_free(result); return NULL; @@ -367,37 +368,37 @@ rend_cache_store(const char *desc, size_t desc_len) tor_assert(rend_cache); parsed = rend_parse_service_descriptor(desc,desc_len); if (!parsed) { - warn(LD_PROTOCOL,"Couldn't parse service descriptor."); + log_warn(LD_PROTOCOL,"Couldn't parse service descriptor."); return -1; } if (rend_get_service_id(parsed->pk, query)<0) { - warn(LD_BUG,"Couldn't compute service ID."); + log_warn(LD_BUG,"Couldn't compute service ID."); rend_service_descriptor_free(parsed); return -1; } tor_snprintf(key, sizeof(key), "%c%s", parsed->version?'1':'0', query); now = time(NULL); if (parsed->timestamp < now-REND_CACHE_MAX_AGE-REND_CACHE_MAX_SKEW) { - warn(LD_REND,"Service descriptor %s is too old.", safe_str(query)); + log_warn(LD_REND,"Service descriptor %s is too old.", safe_str(query)); rend_service_descriptor_free(parsed); return -1; } if (parsed->timestamp > now+REND_CACHE_MAX_SKEW) { - warn(LD_REND,"Service descriptor %s is too far in the future.", - safe_str(query)); + log_warn(LD_REND,"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, key); if (e && e->parsed->timestamp > parsed->timestamp) { - info(LD_REND,"We already have a newer service descriptor %s with the " - "same ID and version.", safe_str(query)); + log_info(LD_REND,"We already have a newer service descriptor %s with the " + "same ID and version.", safe_str(query)); rend_service_descriptor_free(parsed); return 0; } if (e && e->len == desc_len && !memcmp(desc,e->desc,desc_len)) { - info(LD_REND,"We already have this service descriptor %s.", - safe_str(query)); + log_info(LD_REND,"We already have this service descriptor %s.", + safe_str(query)); e->received = time(NULL); rend_service_descriptor_free(parsed); return 0; @@ -415,8 +416,8 @@ rend_cache_store(const char *desc, size_t desc_len) e->desc = tor_malloc(desc_len); memcpy(e->desc, desc, desc_len); - debug(LD_REND,"Successfully stored rend desc '%s', len %d.", - safe_str(query), (int)desc_len); + log_debug(LD_REND,"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 fd2c66d235..c1252289bc 100644 --- a/src/or/rendmid.c +++ b/src/or/rendmid.c @@ -27,8 +27,9 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, char serviceid[REND_SERVICE_ID_LEN+1]; int reason = END_CIRC_REASON_INTERNAL; - info(LD_REND, - "Received an ESTABLISH_INTRO request on circuit %d", circ->p_circ_id); + log_info(LD_REND, + "Received an ESTABLISH_INTRO request on circuit %d", + circ->p_circ_id); if (circ->purpose != CIRCUIT_PURPOSE_OR || circ->n_conn) { log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL, @@ -47,7 +48,7 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, pk = crypto_pk_asn1_decode(request+2, asn1len); if (!pk) { reason = END_CIRC_REASON_TORPROTOCOL; - warn(LD_PROTOCOL, "Couldn't decode public key."); + log_warn(LD_PROTOCOL, "Couldn't decode public key."); goto err; } @@ -55,11 +56,11 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, memcpy(buf, circ->handshake_digest, DIGEST_LEN); memcpy(buf+DIGEST_LEN, "INTRODUCE", 9); if (crypto_digest(expected_digest, buf, DIGEST_LEN+9) < 0) { - warn(LD_BUG, "Internal error computing digest."); + log_warn(LD_BUG, "Internal error computing digest."); goto err; } if (memcmp(expected_digest, request+2+asn1len, DIGEST_LEN)) { - warn(LD_PROTOCOL, "Hash of session info was not as expected."); + log_warn(LD_PROTOCOL, "Hash of session info was not as expected."); reason = END_CIRC_REASON_TORPROTOCOL; goto err; } @@ -67,15 +68,15 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, if (crypto_pk_public_checksig_digest(pk, request, 2+asn1len+DIGEST_LEN, request+2+DIGEST_LEN+asn1len, request_len-(2+DIGEST_LEN+asn1len))<0) { - warn(LD_PROTOCOL, - "Incorrect signature on ESTABLISH_INTRO cell; rejecting."); + log_warn(LD_PROTOCOL, + "Incorrect signature on ESTABLISH_INTRO cell; rejecting."); reason = END_CIRC_REASON_TORPROTOCOL; goto err; } /* The request is valid. First, compute the hash of Bob's PK.*/ if (crypto_pk_get_digest(pk, pk_digest)<0) { - warn(LD_BUG, "Internal error: couldn't hash public key."); + log_warn(LD_BUG, "Internal error: couldn't hash public key."); goto err; } @@ -88,8 +89,8 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, c = NULL; while ((c = circuit_get_next_by_pk_and_purpose( c,pk_digest,CIRCUIT_PURPOSE_INTRO_POINT))) { - info(LD_REND, "Replacing old circuit %d for service %s", - c->p_circ_id, safe_str(serviceid)); + log_info(LD_REND, "Replacing old circuit %d for service %s", + c->p_circ_id, safe_str(serviceid)); circuit_mark_for_close(c, END_CIRC_REASON_REQUESTED); } @@ -97,7 +98,7 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, if (connection_edge_send_command(NULL,circ, RELAY_COMMAND_INTRO_ESTABLISHED, "", 0, NULL)<0) { - info(LD_GENERAL, "Couldn't send INTRO_ESTABLISHED cell."); + log_info(LD_GENERAL, "Couldn't send INTRO_ESTABLISHED cell."); goto err; } @@ -105,13 +106,13 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, circ->purpose = CIRCUIT_PURPOSE_INTRO_POINT; memcpy(circ->rend_pk_digest, pk_digest, DIGEST_LEN); - info(LD_REND, - "Established introduction point on circuit %d for service %s", - circ->p_circ_id, safe_str(serviceid)); + log_info(LD_REND, + "Established introduction point on circuit %d for service %s", + circ->p_circ_id, safe_str(serviceid)); return 0; truncated: - warn(LD_PROTOCOL, "Rejecting truncated ESTABLISH_INTRO cell."); + log_warn(LD_PROTOCOL, "Rejecting truncated ESTABLISH_INTRO cell."); reason = END_CIRC_REASON_TORPROTOCOL; err: if (pk) crypto_free_pk_env(pk); @@ -131,17 +132,18 @@ rend_mid_introduce(circuit_t *circ, const char *request, size_t request_len) char nak_body[1]; if (circ->purpose != CIRCUIT_PURPOSE_OR || circ->n_conn) { - warn(LD_PROTOCOL, "Rejecting INTRODUCE1 on non-OR or non-edge circuit %d.", - circ->p_circ_id); + log_warn(LD_PROTOCOL, + "Rejecting INTRODUCE1 on non-OR or non-edge circuit %d.", + circ->p_circ_id); goto err; } /* change to MAX_HEX_NICKNAME_LEN once 0.0.9.x is obsolete */ if (request_len < (DIGEST_LEN+(MAX_NICKNAME_LEN+1)+REND_COOKIE_LEN+ DH_KEY_LEN+CIPHER_KEY_LEN+PKCS1_OAEP_PADDING_OVERHEAD)) { - warn(LD_PROTOCOL, "Impossibly short INTRODUCE1 cell on circuit %d; " - "responding with nack.", - circ->p_circ_id); + log_warn(LD_PROTOCOL, "Impossibly short INTRODUCE1 cell on circuit %d; " + "responding with nack.", + circ->p_circ_id); goto err; } @@ -151,29 +153,30 @@ rend_mid_introduce(circuit_t *circ, const char *request, size_t request_len) intro_circ = circuit_get_next_by_pk_and_purpose( NULL, request, CIRCUIT_PURPOSE_INTRO_POINT); if (!intro_circ) { - info(LD_REND, - "No intro circ found for INTRODUCE1 cell (%s) from circuit %d; " - "responding with nack.", - safe_str(serviceid), circ->p_circ_id); + log_info(LD_REND, + "No intro circ found for INTRODUCE1 cell (%s) from circuit %d; " + "responding with nack.", + safe_str(serviceid), circ->p_circ_id); goto err; } - info(LD_REND, - "Sending introduction request for service %s from circ %d to circ %d", - safe_str(serviceid), circ->p_circ_id, intro_circ->p_circ_id); + log_info(LD_REND, + "Sending introduction request for service %s " + "from circ %d to circ %d", + 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, RELAY_COMMAND_INTRODUCE2, request, request_len, NULL)) { - warn(LD_GENERAL, - "Unable to send INTRODUCE2 cell to Tor client."); + log_warn(LD_GENERAL, + "Unable to send INTRODUCE2 cell to Tor client."); goto err; } /* And sent an ack down Alice's circuit. Empty body means succeeded. */ if (connection_edge_send_command(NULL,circ,RELAY_COMMAND_INTRODUCE_ACK, NULL,0,NULL)) { - warn(LD_GENERAL, "Unable to send INTRODUCE_ACK cell to Tor client."); + log_warn(LD_GENERAL, "Unable to send INTRODUCE_ACK cell to Tor client."); circuit_mark_for_close(circ, END_CIRC_REASON_INTERNAL); return -1; } @@ -184,7 +187,7 @@ rend_mid_introduce(circuit_t *circ, const char *request, size_t request_len) nak_body[0] = 1; if (connection_edge_send_command(NULL,circ,RELAY_COMMAND_INTRODUCE_ACK, nak_body, 1, NULL)) { - warn(LD_GENERAL, "Unable to send NAK to Tor client."); + log_warn(LD_GENERAL, "Unable to send NAK to Tor client."); /* Is this right? */ circuit_mark_for_close(circ, END_CIRC_REASON_INTERNAL); } @@ -202,18 +205,19 @@ rend_mid_establish_rendezvous(circuit_t *circ, const char *request, int reason = END_CIRC_REASON_TORPROTOCOL; if (circ->purpose != CIRCUIT_PURPOSE_OR || circ->n_conn) { - warn(LD_PROTOCOL, - "Tried to establish rendezvous on non-OR or non-edge circuit."); + log_warn(LD_PROTOCOL, + "Tried to establish rendezvous on non-OR or non-edge circuit."); goto err; } if (request_len != REND_COOKIE_LEN) { - warn(LD_PROTOCOL, "Invalid length on ESTABLISH_RENDEZVOUS."); + log_warn(LD_PROTOCOL, "Invalid length on ESTABLISH_RENDEZVOUS."); goto err; } if (circuit_get_rendezvous(request)) { - warn(LD_PROTOCOL, "Duplicate rendezvous cookie in ESTABLISH_RENDEZVOUS."); + log_warn(LD_PROTOCOL, + "Duplicate rendezvous cookie in ESTABLISH_RENDEZVOUS."); goto err; } @@ -221,7 +225,7 @@ rend_mid_establish_rendezvous(circuit_t *circ, const char *request, if (connection_edge_send_command(NULL,circ, RELAY_COMMAND_RENDEZVOUS_ESTABLISHED, "", 0, NULL)<0) { - warn(LD_PROTOCOL, "Couldn't send RENDEZVOUS_ESTABLISHED cell."); + log_warn(LD_PROTOCOL, "Couldn't send RENDEZVOUS_ESTABLISHED cell."); reason = END_CIRC_REASON_INTERNAL; goto err; } @@ -231,8 +235,9 @@ rend_mid_establish_rendezvous(circuit_t *circ, const char *request, base16_encode(hexid,9,request,4); - info(LD_REND, "Established rendezvous point on circuit %d for cookie %s", - circ->p_circ_id, hexid); + log_info(LD_REND, + "Established rendezvous point on circuit %d for cookie %s", + circ->p_circ_id, hexid); return 0; err: @@ -253,14 +258,15 @@ rend_mid_rendezvous(circuit_t *circ, const char *request, size_t request_len) base16_encode(hexid,9,request,request_len<4?request_len:4); if (request_len>=4) { - info(LD_REND, "Got request for rendezvous from circuit %d to cookie %s.", - circ->p_circ_id, hexid); + log_info(LD_REND, + "Got request for rendezvous from circuit %d to cookie %s.", + circ->p_circ_id, hexid); } if (circ->purpose != CIRCUIT_PURPOSE_OR || circ->n_conn) { - info(LD_REND, - "Tried to complete rendezvous on non-OR or non-edge circuit %d.", - circ->p_circ_id); + log_info(LD_REND, + "Tried to complete rendezvous on non-OR or non-edge circuit %d.", + circ->p_circ_id); reason = END_CIRC_REASON_TORPROTOCOL; goto err; } @@ -287,16 +293,16 @@ rend_mid_rendezvous(circuit_t *circ, const char *request, size_t request_len) RELAY_COMMAND_RENDEZVOUS2, request+REND_COOKIE_LEN, request_len-REND_COOKIE_LEN, NULL)) { - warn(LD_GENERAL, - "Unable to send RENDEZVOUS2 cell to OP on circuit %d.", - rend_circ->p_circ_id); + log_warn(LD_GENERAL, + "Unable to send RENDEZVOUS2 cell to OP on circuit %d.", + rend_circ->p_circ_id); goto err; } /* Join the circuits. */ - info(LD_REND, - "Completing rendezvous: circuit %d joins circuit %d (cookie %s)", - circ->p_circ_id, rend_circ->p_circ_id, hexid); + log_info(LD_REND, + "Completing rendezvous: circuit %d joins circuit %d (cookie %s)", + circ->p_circ_id, rend_circ->p_circ_id, hexid); circ->purpose = CIRCUIT_PURPOSE_REND_ESTABLISHED; rend_circ->purpose = CIRCUIT_PURPOSE_REND_ESTABLISHED; diff --git a/src/or/rendservice.c b/src/or/rendservice.c index 7881d3ffcd..5124f93dba 100644 --- a/src/or/rendservice.c +++ b/src/or/rendservice.c @@ -121,20 +121,20 @@ add_service(rend_service_t *service) service->intro_exclude_nodes = tor_strdup(""); if (!smartlist_len(service->ports)) { - warn(LD_CONFIG, "Hidden service with no ports configured; ignoring."); + log_warn(LD_CONFIG, "Hidden service with no ports configured; ignoring."); rend_service_free(service); } else { smartlist_set_capacity(service->ports, -1); smartlist_add(rend_service_list, service); - debug(LD_REND,"Configuring service with directory \"%s\"", - service->directory); + log_debug(LD_REND,"Configuring service with directory \"%s\"", + service->directory); for (i = 0; i < smartlist_len(service->ports); ++i) { char addrbuf[INET_NTOA_BUF_LEN]; p = smartlist_get(service->ports, i); addr.s_addr = htonl(p->real_addr); tor_inet_ntoa(&addr, addrbuf, sizeof(addrbuf)); - debug(LD_REND,"Service maps port %d to %s:%d", - p->virtual_port, addrbuf, p->real_port); + log_debug(LD_REND,"Service maps port %d to %s:%d", + p->virtual_port, addrbuf, p->real_port); } } } @@ -161,14 +161,14 @@ parse_port_config(const char *string) smartlist_split_string(sl, string, " ", SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 0); if (smartlist_len(sl) < 1 || smartlist_len(sl) > 2) { - warn(LD_CONFIG, "Bad syntax in hidden service port configuration."); + log_warn(LD_CONFIG, "Bad syntax in hidden service port configuration."); goto err; } virtport = atoi(smartlist_get(sl,0)); if (virtport < 1 || virtport > 65535) { - warn(LD_CONFIG, "Missing or invalid port in hidden service port " - "configuration."); + log_warn(LD_CONFIG, "Missing or invalid port in hidden service port " + "configuration."); goto err; } @@ -180,8 +180,8 @@ parse_port_config(const char *string) addrport = smartlist_get(sl,1); if (strchr(addrport, ':') || strchr(addrport, '.')) { if (parse_addr_port(addrport, NULL, &addr, &p)<0) { - warn(LD_CONFIG,"Unparseable address in hidden service port " - "configuration."); + log_warn(LD_CONFIG,"Unparseable address in hidden service port " + "configuration."); goto err; } realport = p?p:virtport; @@ -237,8 +237,8 @@ rend_config_services(or_options_t *options, int validate_only) continue; } if (!service) { - warn(LD_CONFIG, "%s with no preceding HiddenServiceDir directive", - line->key); + log_warn(LD_CONFIG, "%s with no preceding HiddenServiceDir directive", + line->key); rend_service_free(service); return -1; } @@ -251,16 +251,18 @@ rend_config_services(or_options_t *options, int validate_only) smartlist_add(service->ports, portcfg); } else if (!strcasecmp(line->key, "HiddenServiceNodes")) { if (service->intro_prefer_nodes) { - warn(LD_CONFIG, "Got multiple HiddenServiceNodes lines for a single " - "service."); + log_warn(LD_CONFIG, + "Got multiple HiddenServiceNodes lines for a single " + "service."); return -1; } service->intro_prefer_nodes = tor_strdup(line->value); } else { tor_assert(!strcasecmp(line->key, "HiddenServiceExcludeNodes")); if (service->intro_exclude_nodes) { - warn(LD_CONFIG, "Got multiple HiddenServiceExcludedNodes lines for " - "a single service."); + log_warn(LD_CONFIG, + "Got multiple HiddenServiceExcludedNodes lines for " + "a single service."); return -1; } service->intro_exclude_nodes = tor_strdup(line->value); @@ -303,8 +305,8 @@ rend_service_update_descriptor(rend_service_t *service) for (i=0; i < n; ++i) { router = router_get_by_nickname(smartlist_get(service->intro_nodes, i),1); if (!router) { - info(LD_REND,"Router '%s' not found. Skipping.", - (char*)smartlist_get(service->intro_nodes, i)); + log_info(LD_REND,"Router '%s' not found. Skipping.", + (char*)smartlist_get(service->intro_nodes, i)); continue; } circ = find_intro_circuit(router, service->pk_digest); @@ -333,7 +335,8 @@ rend_service_load_keys(void) s = smartlist_get(rend_service_list,i); if (s->private_key) continue; - info(LD_REND, "Loading hidden-service keys from \"%s\"", s->directory); + log_info(LD_REND, "Loading hidden-service keys from \"%s\"", + s->directory); /* Check/create directory */ if (check_private_dir(s->directory, CPD_CREATE) < 0) @@ -342,7 +345,7 @@ rend_service_load_keys(void) /* Load key */ if (strlcpy(fname,s->directory,sizeof(fname)) >= sizeof(fname) || strlcat(fname,"/private_key",sizeof(fname)) >= sizeof(fname)) { - warn(LD_CONFIG, "Directory name too long: \"%s\".", s->directory); + log_warn(LD_CONFIG, "Directory name too long: \"%s\".", s->directory); return -1; } s->private_key = init_key_from_file(fname); @@ -351,16 +354,16 @@ rend_service_load_keys(void) /* Create service file */ if (rend_get_service_id(s->private_key, s->service_id)<0) { - warn(LD_BUG, "Internal error: couldn't encode service ID."); + log_warn(LD_BUG, "Internal error: couldn't encode service ID."); return -1; } if (crypto_pk_get_digest(s->private_key, s->pk_digest)<0) { - warn(LD_BUG, "Bug: Couldn't compute hash of public key."); + log_warn(LD_BUG, "Bug: Couldn't compute hash of public key."); return -1; } if (strlcpy(fname,s->directory,sizeof(fname)) >= sizeof(fname) || strlcat(fname,"/hostname",sizeof(fname)) >= sizeof(fname)) { - warn(LD_CONFIG, "Directory name too long: \"%s\".", s->directory); + log_warn(LD_CONFIG, "Directory name too long: \"%s\".", s->directory); return -1; } tor_snprintf(buf, sizeof(buf),"%s.onion\n", s->service_id); @@ -426,41 +429,42 @@ rend_service_introduce(circuit_t *circuit, const char *request, base32_encode(serviceid, REND_SERVICE_ID_LEN+1, circuit->rend_pk_digest,10); - info(LD_REND, "Received INTRODUCE2 cell for service %s on circ %d.", - serviceid, circuit->n_circ_id); + log_info(LD_REND, "Received INTRODUCE2 cell for service %s on circ %d.", + serviceid, circuit->n_circ_id); if (circuit->purpose != CIRCUIT_PURPOSE_S_INTRO) { - warn(LD_PROTOCOL, "Got an INTRODUCE2 over a non-introduction circuit %d.", - circuit->n_circ_id); + log_warn(LD_PROTOCOL, + "Got an INTRODUCE2 over a non-introduction circuit %d.", + circuit->n_circ_id); return -1; } /* min key length plus digest length plus nickname length */ if (request_len < DIGEST_LEN+REND_COOKIE_LEN+(MAX_NICKNAME_LEN+1)+ DH_KEY_LEN+42) { - warn(LD_PROTOCOL, "Got a truncated INTRODUCE2 cell on circ %d.", - circuit->n_circ_id); + log_warn(LD_PROTOCOL, "Got a truncated INTRODUCE2 cell on circ %d.", + circuit->n_circ_id); return -1; } /* first DIGEST_LEN bytes of request is service pk digest */ service = rend_service_get_by_pk_digest(request); if (!service) { - warn(LD_REND, "Got an INTRODUCE2 cell for an unrecognized service %s.", - serviceid); + log_warn(LD_REND, "Got an INTRODUCE2 cell for an unrecognized service %s.", + serviceid); return -1; } if (memcmp(circuit->rend_pk_digest, request, DIGEST_LEN)) { base32_encode(serviceid, REND_SERVICE_ID_LEN+1, request, 10); - warn(LD_REND, "Got an INTRODUCE2 cell for the wrong service (%s).", - serviceid); + log_warn(LD_REND, "Got an INTRODUCE2 cell for the wrong service (%s).", + serviceid); return -1; } keylen = crypto_pk_keysize(service->private_key); if (request_len < keylen+DIGEST_LEN) { - warn(LD_PROTOCOL, - "PK-encrypted portion of INTRODUCE2 cell was truncated."); + log_warn(LD_PROTOCOL, + "PK-encrypted portion of INTRODUCE2 cell was truncated."); return -1; } /* Next N bytes is encrypted with service key */ @@ -468,7 +472,7 @@ rend_service_introduce(circuit_t *circuit, const char *request, service->private_key,buf,request+DIGEST_LEN,request_len-DIGEST_LEN, PK_PKCS1_OAEP_PADDING,1); if (r<0) { - warn(LD_PROTOCOL, "Couldn't decrypt INTRODUCE2 cell."); + log_warn(LD_PROTOCOL, "Couldn't decrypt INTRODUCE2 cell."); return -1; } len = r; @@ -485,14 +489,14 @@ rend_service_introduce(circuit_t *circuit, const char *request, klen = ntohs(get_uint16(buf+7+DIGEST_LEN)); if ((int)len != 7+DIGEST_LEN+2+klen+20+128) { - warn(LD_PROTOCOL, "Bad length %u for version 2 INTRODUCE2 cell.", - (int)len); + log_warn(LD_PROTOCOL, "Bad length %u for version 2 INTRODUCE2 cell.", + (int)len); goto err; } extend_info->onion_key = crypto_pk_asn1_decode(buf+7+DIGEST_LEN+2, klen); if (!extend_info->onion_key) { - warn(LD_PROTOCOL, - "Error decoding onion key in version 2 INTRODUCE2 cell."); + log_warn(LD_PROTOCOL, + "Error decoding onion key in version 2 INTRODUCE2 cell."); goto err; } ptr = buf+7+DIGEST_LEN+2+klen; @@ -514,13 +518,13 @@ rend_service_introduce(circuit_t *circuit, const char *request, /* XXX when 0.1.0.x is obsolete, change this to reject version < 2. */ ptr=memchr(rp_nickname,0,nickname_field_len); if (!ptr || ptr == rp_nickname) { - warn(LD_PROTOCOL, - "Couldn't find a null-padded nickname in INTRODUCE2 cell."); + log_warn(LD_PROTOCOL, + "Couldn't find a null-padded nickname in INTRODUCE2 cell."); return -1; } if ((version == 0 && !is_legal_nickname(rp_nickname)) || (version == 1 && !is_legal_nickname_or_hexdigest(rp_nickname))) { - warn(LD_PROTOCOL, "Bad nickname in INTRODUCE2 cell."); + log_warn(LD_PROTOCOL, "Bad nickname in INTRODUCE2 cell."); return -1; } /* Okay, now we know that a nickname is at the start of the buffer. */ @@ -530,8 +534,8 @@ rend_service_introduce(circuit_t *circuit, const char *request, * any */ router = router_get_by_nickname(rp_nickname, 0); if (!router) { - info(LD_REND, "Couldn't find router '%s' named in rendezvous cell.", - rp_nickname); + log_info(LD_REND, "Couldn't find router '%s' named in rendezvous cell.", + rp_nickname); goto err; } @@ -539,7 +543,7 @@ rend_service_introduce(circuit_t *circuit, const char *request, } if (len != REND_COOKIE_LEN+DH_KEY_LEN) { - warn(LD_PROTOCOL, "Bad length %u for INTRODUCE2 cell.", (int)len); + log_warn(LD_PROTOCOL, "Bad length %u for INTRODUCE2 cell.", (int)len); return -1; } @@ -549,13 +553,13 @@ rend_service_introduce(circuit_t *circuit, const char *request, /* Try DH handshake... */ dh = crypto_dh_new(); if (!dh || crypto_dh_generate_public(dh)<0) { - warn(LD_BUG,"Internal error: couldn't build DH state " - "or generate public key."); + log_warn(LD_BUG,"Internal error: couldn't build DH state " + "or generate public key."); goto err; } if (crypto_dh_compute_secret(dh, ptr+REND_COOKIE_LEN, DH_KEY_LEN, keys, DIGEST_LEN+CPATH_KEY_MATERIAL_LEN)<0) { - warn(LD_BUG, "Internal error: couldn't complete DH handshake"); + log_warn(LD_BUG, "Internal error: couldn't complete DH handshake"); goto err; } @@ -575,14 +579,15 @@ rend_service_introduce(circuit_t *circuit, const char *request, break; } if (!launched) { /* give up */ - warn(LD_REND, "Giving up launching first hop of circuit to rendezvous " - "point '%s' for service %s.", - extend_info->nickname, serviceid); + log_warn(LD_REND, "Giving up launching first hop of circuit to rendezvous " + "point '%s' for service %s.", + extend_info->nickname, serviceid); goto err; } - info(LD_REND, - "Accepted intro; launching circuit to '%s' (cookie %s) for service %s.", - extend_info->nickname, hexcookie, serviceid); + log_info(LD_REND, + "Accepted intro; launching circuit to '%s' " + "(cookie %s) for service %s.", + extend_info->nickname, hexcookie, serviceid); tor_assert(launched->build_state); /* Fill in the circuit's state. */ memcpy(launched->rend_pk_digest, circuit->rend_pk_digest, @@ -624,10 +629,11 @@ rend_service_relaunch_rendezvous(circuit_t *oldcirc) if (!oldcirc->build_state || oldcirc->build_state->failure_count > MAX_REND_FAILURES || oldcirc->build_state->expiry_time < time(NULL)) { - info(LD_REND,"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*"); + log_info(LD_REND, + "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*"); return; } @@ -635,19 +641,19 @@ rend_service_relaunch_rendezvous(circuit_t *oldcirc) tor_assert(oldstate); if (oldstate->pending_final_cpath == NULL) { - info(LD_REND,"Skipping relaunch of circ that failed on its first hop. " - "Initiator will retry."); + log_info(LD_REND,"Skipping relaunch of circ that failed on its first hop. " + "Initiator will retry."); return; } - info(LD_REND,"Reattempting rendezvous circuit to %s", - oldstate->chosen_exit->nickname); + log_info(LD_REND,"Reattempting rendezvous circuit to %s", + oldstate->chosen_exit->nickname); newcirc = circuit_launch_by_extend_info(CIRCUIT_PURPOSE_S_CONNECT_REND, oldstate->chosen_exit, 0, 1, 1); if (!newcirc) { - warn(LD_REND,"Couldn't relaunch rendezvous circuit to %s.", - oldstate->chosen_exit->nickname); + log_warn(LD_REND,"Couldn't relaunch rendezvous circuit to %s.", + oldstate->chosen_exit->nickname); return; } newstate = newcirc->build_state; @@ -671,8 +677,9 @@ rend_service_launch_establish_intro(rend_service_t *service, { circuit_t *launched; - info(LD_REND, "Launching circuit to introduction point %s for service %s", - nickname, service->service_id); + log_info(LD_REND, + "Launching circuit to introduction point %s for service %s", + nickname, service->service_id); rep_hist_note_used_internal(time(NULL), 1, 0); @@ -680,8 +687,9 @@ rend_service_launch_establish_intro(rend_service_t *service, launched = circuit_launch_by_nickname(CIRCUIT_PURPOSE_S_ESTABLISH_INTRO, nickname, 1, 0, 1); if (!launched) { - info(LD_REND, "Can't launch circuit to establish introduction at '%s'.", - nickname); + log_info(LD_REND, + "Can't launch circuit to establish introduction at '%s'.", + nickname); return -1; } strlcpy(launched->rend_query, service->service_id, @@ -715,14 +723,14 @@ rend_service_intro_has_opened(circuit_t *circuit) service = rend_service_get_by_pk_digest(circuit->rend_pk_digest); if (!service) { - warn(LD_REND, "Unrecognized service ID %s on introduction circuit %d.", - serviceid, circuit->n_circ_id); + log_warn(LD_REND, "Unrecognized service ID %s on introduction circuit %d.", + serviceid, circuit->n_circ_id); goto err; } - info(LD_REND, - "Established circuit %d as introduction point for service %s", - circuit->n_circ_id, serviceid); + log_info(LD_REND, + "Established circuit %d as introduction point for service %s", + circuit->n_circ_id, serviceid); /* Build the payload for a RELAY_ESTABLISH_INTRO cell. */ len = crypto_pk_asn1_encode(service->private_key, buf+2, @@ -736,16 +744,16 @@ rend_service_intro_has_opened(circuit_t *circuit) len += 20; r = crypto_pk_private_sign_digest(service->private_key, buf+len, buf, len); if (r<0) { - warn(LD_BUG, "Internal error: couldn't sign introduction request."); + log_warn(LD_BUG, "Internal error: couldn't sign introduction request."); goto err; } len += r; if (connection_edge_send_command(NULL, circuit,RELAY_COMMAND_ESTABLISH_INTRO, buf, len, circuit->cpath->prev)<0) { - info(LD_GENERAL, - "Couldn't send introduction request for service %s on circuit %d", - serviceid, circuit->n_circ_id); + log_info(LD_GENERAL, + "Couldn't send introduction request for service %s on circuit %d", + serviceid, circuit->n_circ_id); goto err; } @@ -764,13 +772,14 @@ rend_service_intro_established(circuit_t *circuit, const char *request, rend_service_t *service; if (circuit->purpose != CIRCUIT_PURPOSE_S_ESTABLISH_INTRO) { - warn(LD_PROTOCOL, "received INTRO_ESTABLISHED cell on non-intro circuit."); + log_warn(LD_PROTOCOL, + "received INTRO_ESTABLISHED cell on non-intro circuit."); goto err; } service = rend_service_get_by_pk_digest(circuit->rend_pk_digest); if (!service) { - warn(LD_REND, "Unknown service on introduction circuit %d.", - circuit->n_circ_id); + log_warn(LD_REND, "Unknown service on introduction circuit %d.", + circuit->n_circ_id); goto err; } service->desc_is_dirty = time(NULL); @@ -804,14 +813,15 @@ rend_service_rendezvous_has_opened(circuit_t *circuit) base32_encode(serviceid, REND_SERVICE_ID_LEN+1, circuit->rend_pk_digest,10); - info(LD_REND, - "Done building circuit %d to rendezvous with cookie %s for service %s", - circuit->n_circ_id, hexcookie, serviceid); + log_info(LD_REND, + "Done building circuit %d to rendezvous with " + "cookie %s for service %s", + circuit->n_circ_id, hexcookie, serviceid); service = rend_service_get_by_pk_digest(circuit->rend_pk_digest); if (!service) { - warn(LD_GENERAL, "Internal error: unrecognized service ID on " - "introduction circuit."); + log_warn(LD_GENERAL, "Internal error: unrecognized service ID on " + "introduction circuit."); goto err; } @@ -819,7 +829,7 @@ rend_service_rendezvous_has_opened(circuit_t *circuit) memcpy(buf, circuit->rend_cookie, REND_COOKIE_LEN); if (crypto_dh_get_public(hop->dh_handshake_state, buf+REND_COOKIE_LEN, DH_KEY_LEN)<0) { - warn(LD_GENERAL,"Couldn't get DH public key."); + log_warn(LD_GENERAL,"Couldn't get DH public key."); goto err; } memcpy(buf+REND_COOKIE_LEN+DH_KEY_LEN, hop->handshake_digest, @@ -829,7 +839,7 @@ rend_service_rendezvous_has_opened(circuit_t *circuit) if (connection_edge_send_command(NULL, circuit, RELAY_COMMAND_RENDEZVOUS1, buf, REND_COOKIE_LEN+DH_KEY_LEN+DIGEST_LEN, circuit->cpath->prev)<0) { - warn(LD_GENERAL, "Couldn't send RENDEZVOUS1 cell."); + log_warn(LD_GENERAL, "Couldn't send RENDEZVOUS1 cell."); goto err; } @@ -905,8 +915,8 @@ upload_service_descriptor(rend_service_t *service, int version) version, service->private_key, &desc, &desc_len)<0) { - warn(LD_BUG, "Internal error: couldn't encode service descriptor; " - "not uploading."); + log_warn(LD_BUG, "Internal error: couldn't encode service descriptor; " + "not uploading."); return; } @@ -963,8 +973,8 @@ rend_services_introduce(void) intro = smartlist_get(service->intro_nodes, j); router = router_get_by_nickname(intro, 0); if (!router || !find_intro_circuit(router,service->pk_digest)) { - info(LD_REND,"Giving up on %s as intro point for %s.", - intro, service->service_id); + log_info(LD_REND,"Giving up on %s as intro point for %s.", + intro, service->service_id); tor_free(intro); smartlist_del(service->intro_nodes,j--); changed = 1; @@ -996,8 +1006,9 @@ rend_services_introduce(void) get_options()->_AllowUnverified & ALLOW_UNVERIFIED_INTRODUCTION, 0); if (!router) { - warn(LD_REND, "Could only establish %d introduction points for %s.", - smartlist_len(service->intro_nodes), service->service_id); + log_warn(LD_REND, + "Could only establish %d introduction points for %s.", + smartlist_len(service->intro_nodes), service->service_id); break; } changed = 1; @@ -1009,8 +1020,8 @@ rend_services_introduce(void) smartlist_add(intro_routers, router); smartlist_add(exclude_routers, router); smartlist_add(service->intro_nodes, hex_digest); - info(LD_REND, "Picked router %s as an intro point for %s.", - router->nickname, service->service_id); + log_info(LD_REND, "Picked router %s as an intro point for %s.", + router->nickname, service->service_id); } /* Reset exclude_routers, for the next time around the loop. */ @@ -1025,8 +1036,8 @@ rend_services_introduce(void) intro = smartlist_get(service->intro_nodes, j); r = rend_service_launch_establish_intro(service, intro); if (r<0) { - warn(LD_REND, "Error launching circuit to node %s for service %s.", - intro, service->service_id); + log_warn(LD_REND, "Error launching circuit to node %s for service %s.", + intro, service->service_id); } } } @@ -1117,14 +1128,14 @@ rend_service_set_connection_addr_port(connection_t *conn, circuit_t *circ) char serviceid[REND_SERVICE_ID_LEN+1]; tor_assert(circ->purpose == CIRCUIT_PURPOSE_S_REND_JOINED); - debug(LD_REND,"beginning to hunt for addr/port"); + log_debug(LD_REND,"beginning to hunt for addr/port"); base32_encode(serviceid, REND_SERVICE_ID_LEN+1, circ->rend_pk_digest,10); service = rend_service_get_by_pk_digest(circ->rend_pk_digest); if (!service) { - warn(LD_REND, "Couldn't find any service associated with pk %s on " - "rendezvous circuit %d; closing.", - serviceid, circ->n_circ_id); + log_warn(LD_REND, "Couldn't find any service associated with pk %s on " + "rendezvous circuit %d; closing.", + serviceid, circ->n_circ_id); return -1; } for (i = 0; i < smartlist_len(service->ports); ++i) { @@ -1135,8 +1146,8 @@ rend_service_set_connection_addr_port(connection_t *conn, circuit_t *circ) return 0; } } - info(LD_REND, "No virtual port mapping exists for port %d on service %s", - conn->port,serviceid); + log_info(LD_REND, "No virtual port mapping exists for port %d on service %s", + conn->port,serviceid); return -1; } diff --git a/src/or/rephist.c b/src/or/rephist.c index 9e7c2e5a91..62d07b966a 100644 --- a/src/or/rephist.c +++ b/src/or/rephist.c @@ -717,7 +717,7 @@ rep_hist_load_state(or_state_t *state, const char **err) v = tor_parse_uint64(cp, 10, 0, UINT64_MAX, &ok, NULL); if (!ok) { all_ok=0; - notice(LD_GENERAL, "Could not parse '%s' into a number.'", cp); + log_notice(LD_GENERAL, "Could not parse '%s' into a number.'", cp); } add_obs(b, start, v); start += NUM_SECS_BW_SUM_INTERVAL; @@ -840,7 +840,7 @@ rep_hist_get_predicted_ports(time_t now) tmp_time = smartlist_get(predicted_ports_times, i); if (*tmp_time + PREDICTED_CIRCS_RELEVANCE_TIME < now) { tmp_port = smartlist_get(predicted_ports_list, i); - debug(LD_CIRC, "Expiring predicted port %d", *tmp_port); + log_debug(LD_CIRC, "Expiring predicted port %d", *tmp_port); smartlist_del(predicted_ports_list, i); smartlist_del(predicted_ports_times, i); rephist_total_alloc -= sizeof(uint16_t)+sizeof(time_t); diff --git a/src/or/router.c b/src/or/router.c index 1ec3e16329..d3264d3091 100644 --- a/src/or/router.c +++ b/src/or/router.c @@ -127,11 +127,11 @@ rotate_onion_key(void) tor_snprintf(fname_prev,sizeof(fname_prev), "%s/keys/secret_onion_key.old",get_options()->DataDirectory); if (!(prkey = crypto_new_pk_env())) { - err(LD_GENERAL,"Error creating crypto environment."); + log_err(LD_GENERAL,"Error creating crypto environment."); goto error; } if (crypto_pk_generate_key(prkey)) { - err(LD_BUG,"Error generating onion key"); + log_err(LD_BUG,"Error generating onion key"); goto error; } if (file_status(fname) == FN_FILE) { @@ -139,10 +139,10 @@ rotate_onion_key(void) goto error; } if (crypto_pk_write_private_key_to_filename(prkey, fname)) { - err(LD_FS,"Couldn't write generated key to \"%s\".", fname); + log_err(LD_FS,"Couldn't write generated key to \"%s\".", fname); goto error; } - info(LD_GENERAL, "Rotating onion key"); + log_info(LD_GENERAL, "Rotating onion key"); tor_mutex_acquire(key_lock); if (lastonionkey) crypto_free_pk_env(lastonionkey); @@ -153,7 +153,7 @@ rotate_onion_key(void) mark_my_descriptor_dirty(); return; error: - warn(LD_GENERAL, "Couldn't rotate onion key."); + log_warn(LD_GENERAL, "Couldn't rotate onion key."); } /* Read an RSA secret key key from a file that was once named fname_old, @@ -187,34 +187,35 @@ init_key_from_file(const char *fname) FILE *file = NULL; if (!(prkey = crypto_new_pk_env())) { - err(LD_GENERAL,"Error creating crypto environment."); + log_err(LD_GENERAL,"Error creating crypto environment."); goto error; } switch (file_status(fname)) { case FN_DIR: case FN_ERROR: - err(LD_FS,"Can't read key from \"%s\"", fname); + log_err(LD_FS,"Can't read key from \"%s\"", fname); goto error; case FN_NOENT: - info(LD_GENERAL, "No key found in \"%s\"; generating fresh key.", fname); + log_info(LD_GENERAL, "No key found in \"%s\"; generating fresh key.", + fname); if (crypto_pk_generate_key(prkey)) { - err(LD_GENERAL,"Error generating onion key"); + log_err(LD_GENERAL,"Error generating onion key"); goto error; } if (crypto_pk_check_key(prkey) <= 0) { - err(LD_GENERAL,"Generated key seems invalid"); + log_err(LD_GENERAL,"Generated key seems invalid"); goto error; } - info(LD_GENERAL, "Generated key seems valid"); + log_info(LD_GENERAL, "Generated key seems valid"); if (crypto_pk_write_private_key_to_filename(prkey, fname)) { - err(LD_FS,"Couldn't write generated key to \"%s\".", fname); + log_err(LD_FS,"Couldn't write generated key to \"%s\".", fname); goto error; } return prkey; case FN_FILE: if (crypto_pk_read_private_key_from_filename(prkey, fname)) { - err(LD_GENERAL,"Error loading private key."); + log_err(LD_GENERAL,"Error loading private key."); goto error; } return prkey; @@ -266,7 +267,7 @@ init_keys(void) if (tor_tls_context_new(get_identity_key(), 1, options->Nickname ? options->Nickname : "client", MAX_SSL_KEY_LIFETIME) < 0) { - err(LD_GENERAL,"Error creating TLS context for OP."); + log_err(LD_GENERAL,"Error creating TLS context for OP."); return -1; } return 0; @@ -286,14 +287,14 @@ init_keys(void) /* 1. Read identity key. Make it if none is found. */ tor_snprintf(keydir,sizeof(keydir),"%s/keys/identity.key",datadir); tor_snprintf(keydir2,sizeof(keydir2),"%s/keys/secret_id_key",datadir); - info(LD_GENERAL,"Reading/making identity key \"%s\"...",keydir2); + log_info(LD_GENERAL,"Reading/making identity key \"%s\"...",keydir2); prkey = init_key_from_file_name_changed(keydir,keydir2); if (!prkey) return -1; set_identity_key(prkey); /* 2. Read onion key. Make it if none is found. */ tor_snprintf(keydir,sizeof(keydir),"%s/keys/onion.key",datadir); tor_snprintf(keydir2,sizeof(keydir2),"%s/keys/secret_onion_key",datadir); - info(LD_GENERAL,"Reading/making onion key \"%s\"...",keydir2); + log_info(LD_GENERAL,"Reading/making onion key \"%s\"...",keydir2); prkey = init_key_from_file_name_changed(keydir,keydir2); if (!prkey) return -1; set_onion_key(prkey); @@ -307,59 +308,59 @@ init_keys(void) /* 3. Initialize link key and TLS context. */ if (tor_tls_context_new(get_identity_key(), 1, options->Nickname, MAX_SSL_KEY_LIFETIME) < 0) { - err(LD_GENERAL,"Error initializing TLS context"); + log_err(LD_GENERAL,"Error initializing TLS context"); return -1; } /* 4. Dump router descriptor to 'router.desc' */ /* Must be called after keys are initialized. */ mydesc = router_get_my_descriptor(); if (!mydesc) { - err(LD_GENERAL,"Error initializing descriptor."); + log_err(LD_GENERAL,"Error initializing descriptor."); return -1; } if (authdir_mode(options)) { const char *m; /* We need to add our own fingerprint so it gets recognized. */ if (dirserv_add_own_fingerprint(options->Nickname, get_identity_key())) { - err(LD_GENERAL,"Error adding own fingerprint to approved set"); + log_err(LD_GENERAL,"Error adding own fingerprint to approved set"); return -1; } if (dirserv_add_descriptor(mydesc, &m) < 0) { - err(LD_GENERAL,"Unable to add own descriptor to directory: %s", - m?m:""); + log_err(LD_GENERAL,"Unable to add own descriptor to directory: %s", + m?m:""); return -1; } } tor_snprintf(keydir,sizeof(keydir),"%s/router.desc", datadir); - info(LD_GENERAL,"Dumping descriptor to \"%s\"...",keydir); + log_info(LD_GENERAL,"Dumping descriptor to \"%s\"...",keydir); if (write_str_to_file(keydir, mydesc,0)) { return -1; } /* 5. Dump fingerprint to 'fingerprint' */ tor_snprintf(keydir,sizeof(keydir),"%s/fingerprint", datadir); - info(LD_GENERAL,"Dumping fingerprint to \"%s\"...",keydir); + log_info(LD_GENERAL,"Dumping fingerprint to \"%s\"...",keydir); if (crypto_pk_get_fingerprint(get_identity_key(), fingerprint, 1)<0) { - err(LD_GENERAL,"Error computing fingerprint"); + log_err(LD_GENERAL,"Error computing fingerprint"); return -1; } tor_assert(strlen(options->Nickname) <= MAX_NICKNAME_LEN); if (tor_snprintf(fingerprint_line, sizeof(fingerprint_line), "%s %s\n",options->Nickname, fingerprint) < 0) { - err(LD_GENERAL,"Error writing fingerprint line"); + log_err(LD_GENERAL,"Error writing fingerprint line"); return -1; } if (write_str_to_file(keydir, fingerprint_line, 0)) { - err(LD_FS, "Error writing fingerprint line to file"); + log_err(LD_FS, "Error writing fingerprint line to file"); return -1; } if (!authdir_mode(options)) return 0; /* 6. [authdirserver only] load approved-routers file */ tor_snprintf(keydir,sizeof(keydir),"%s/approved-routers", datadir); - info(LD_DIRSERV,"Loading approved fingerprints from \"%s\"...",keydir); + log_info(LD_DIRSERV,"Loading approved fingerprints from \"%s\"...",keydir); if (dirserv_parse_fingerprint_file(keydir) < 0) { - err(LD_GENERAL,"Error loading fingerprints"); + log_err(LD_GENERAL,"Error loading fingerprints"); return -1; } /* 6b. [authdirserver only] add own key to approved directories. */ @@ -447,7 +448,8 @@ consider_testing_reachability(void) { routerinfo_t *me = router_get_my_routerinfo(); if (!me) { - warn(LD_BUG,"Bug: router_get_my_routerinfo() did not find my routerinfo?"); + log_warn(LD_BUG, + "Bug: router_get_my_routerinfo() did not find my routerinfo?"); return; } @@ -468,9 +470,10 @@ router_orport_found_reachable(void) { if (!can_reach_or_port) { if (!clique_mode(get_options())) - notice(LD_OR,"Self-testing indicates your ORPort is reachable from " - "the outside. Excellent.%s", - get_options()->NoPublish ? "" : " Publishing server descriptor."); + log_notice(LD_OR,"Self-testing indicates your ORPort is reachable from " + "the outside. Excellent.%s", + get_options()->NoPublish ? + "" : " Publishing server descriptor."); can_reach_or_port = 1; mark_my_descriptor_dirty(); consider_publishable_server(time(NULL), 1); @@ -482,8 +485,8 @@ void router_dirport_found_reachable(void) { if (!can_reach_dir_port) { - notice(LD_DIRSERV,"Self-testing indicates your DirPort is reachable " - "from the outside. Excellent."); + log_notice(LD_DIRSERV,"Self-testing indicates your DirPort is reachable " + "from the outside. Excellent."); can_reach_dir_port = 1; } } @@ -638,9 +641,9 @@ router_retry_connections(int testing_reachability, int try_all) (try_all || (((uint8_t)id_digest[0]) % 128) == ctr)) || (!testing_reachability && !connection_or_get_by_identity_digest(id_digest))) { - debug(LD_OR,"%sconnecting to %s at %s:%u.", - clique_mode(options) ? "(forced) " : "", - router->nickname, router->address, router->or_port); + log_debug(LD_OR,"%sconnecting to %s at %s:%u.", + clique_mode(options) ? "(forced) " : "", + router->nickname, router->address, router->or_port); /* Remember when we started trying to determine reachability */ if (!router->testing_since) router->testing_since = now; @@ -685,7 +688,7 @@ router_upload_dir_desc_to_dirservers(int force) s = router_get_my_descriptor(); if (!s) { - warn(LD_GENERAL, "No descriptor; skipping upload"); + log_warn(LD_GENERAL, "No descriptor; skipping upload"); return; } if (!force && !desc_needs_upload) @@ -768,7 +771,7 @@ router_get_my_descriptor(void) return NULL; } body = signed_descriptor_get_body(&desc_routerinfo->cache_info); - debug(LD_GENERAL,"my desc is '%s'", body); + log_debug(LD_GENERAL,"my desc is '%s'", body); return body; } @@ -792,7 +795,7 @@ router_rebuild_descriptor(int force) return 0; if (resolve_my_address(options, &addr, NULL) < 0) { - warn(LD_CONFIG,"options->Address didn't resolve into an IP."); + log_warn(LD_CONFIG,"options->Address didn't resolve into an IP."); return -1; } @@ -847,9 +850,10 @@ router_rebuild_descriptor(int force) member = router_get_by_nickname(name, 1); if (!member) { if (!smartlist_string_isin(warned_nonexistent_family, name)) { - warn(LD_CONFIG, "I have no descriptor for the router named \"%s\" " - "in my declared family; I'll use the nickname as is, but " - "this may confuse clients.", name); + log_warn(LD_CONFIG, + "I have no descriptor for the router named \"%s\" " + "in my declared family; I'll use the nickname as is, but " + "this may confuse clients.", name); smartlist_add(warned_nonexistent_family, tor_strdup(name)); } smartlist_add(ri->declared_family, name); @@ -870,7 +874,7 @@ router_rebuild_descriptor(int force) ri->cache_info.signed_descriptor_body = tor_malloc(8192); if (router_dump_router_to_string(ri->cache_info.signed_descriptor_body, 8192, ri, get_identity_key())<0) { - warn(LD_BUG, "Couldn't allocate string for descriptor."); + log_warn(LD_BUG, "Couldn't allocate string for descriptor."); return -1; } ri->cache_info.signed_descriptor_len = @@ -920,8 +924,8 @@ check_descriptor_bandwidth_changed(time_t now) cur > prev*2 || cur < prev/2) { if (last_changed+MAX_BANDWIDTH_CHANGE_FREQ < now) { - info(LD_GENERAL, - "Measured bandwidth has changed; rebuilding descriptor."); + log_info(LD_GENERAL, + "Measured bandwidth has changed; rebuilding descriptor."); mark_my_descriptor_dirty(); last_changed = now; } @@ -942,7 +946,7 @@ check_descriptor_ipaddress_changed(time_t now) prev = desc_routerinfo->addr; if (resolve_my_address(options, &cur, NULL) < 0) { - warn(LD_CONFIG,"options->Address didn't resolve into an IP."); + log_warn(LD_CONFIG,"options->Address didn't resolve into an IP."); return; } @@ -958,9 +962,10 @@ check_descriptor_ipaddress_changed(time_t now) in_cur.s_addr = htonl(cur); tor_inet_ntoa(&in_cur, addrbuf_cur, sizeof(addrbuf_cur)); - info(LD_GENERAL, - "Our IP Address has changed from %s to %s; rebuilding descriptor.", - addrbuf_prev, addrbuf_cur); + log_info(LD_GENERAL, + "Our IP Address has changed from %s to %s; " + "rebuilding descriptor.", + addrbuf_prev, addrbuf_cur); mark_my_descriptor_dirty(); } } @@ -1014,28 +1019,28 @@ router_dump_router_to_string(char *s, size_t maxlen, routerinfo_t *router, /* Make sure the identity key matches the one in the routerinfo. */ if (crypto_pk_cmp_keys(ident_key, router->identity_pkey)) { - warn(LD_BUG,"Tried to sign a router with a private key that didn't " - "match router's public key!"); + log_warn(LD_BUG,"Tried to sign a router with a private key that didn't " + "match router's public key!"); return -1; } /* record our fingerprint, so we can include it in the descriptor */ if (crypto_pk_get_fingerprint(router->identity_pkey, fingerprint, 1)<0) { - err(LD_BUG,"Error computing fingerprint"); + log_err(LD_BUG,"Error computing fingerprint"); return -1; } /* PEM-encode the onion key */ if (crypto_pk_write_public_key_to_string(router->onion_pkey, &onion_pkey,&onion_pkeylen)<0) { - warn(LD_BUG,"write onion_pkey to string failed!"); + log_warn(LD_BUG,"write onion_pkey to string failed!"); return -1; } /* PEM-encode the identity key key */ if (crypto_pk_write_public_key_to_string(router->identity_pkey, &identity_pkey,&identity_pkeylen)<0) { - warn(LD_BUG,"write identity_pkey to string failed!"); + log_warn(LD_BUG,"write identity_pkey to string failed!"); tor_free(onion_pkey); return -1; } @@ -1160,7 +1165,7 @@ router_dump_router_to_string(char *s, size_t maxlen, routerinfo_t *router, if (router_append_dirobj_signature(s+written,maxlen-written, digest,ident_key)<0) { - warn(LD_BUG, "Couldn't sign router descriptor"); + log_warn(LD_BUG, "Couldn't sign router descriptor"); return -1; } written += strlen(s+written); @@ -1175,8 +1180,9 @@ router_dump_router_to_string(char *s, size_t maxlen, routerinfo_t *router, cp = s_tmp = s_dup = tor_strdup(s); ri_tmp = router_parse_entry_from_string(cp, NULL); if (!ri_tmp) { - err(LD_BUG,"We just generated a router descriptor we can't parse: <<%s>>", - s); + log_err(LD_BUG, + "We just generated a router descriptor we can't parse: <<%s>>", + s); return -1; } tor_free(s_dup); diff --git a/src/or/routerlist.c b/src/or/routerlist.c index 8a341aa13b..65a341b9ca 100644 --- a/src/or/routerlist.c +++ b/src/or/routerlist.c @@ -103,8 +103,8 @@ router_reload_networkstatus(void) char buf[DIGEST_LEN]; if (strlen(fn) != HEX_DIGEST_LEN || base16_decode(buf, sizeof(buf), fn, strlen(fn))) { - info(LD_DIR, - "Skipping cached-status file with unexpected name \"%s\"",fn); + log_info(LD_DIR, + "Skipping cached-status file with unexpected name \"%s\"",fn); continue; } tor_snprintf(filename,sizeof(filename),"%s/cached-status/%s", @@ -113,7 +113,7 @@ router_reload_networkstatus(void) if (s) { stat(filename, &st); if (router_set_networkstatus(s, st.st_mtime, NS_FROM_CACHE, NULL)<0) { - warn(LD_FS, "Couldn't load networkstatus from \"%s\"",filename); + log_warn(LD_FS, "Couldn't load networkstatus from \"%s\"",filename); } tor_free(s); } @@ -173,7 +173,7 @@ router_append_to_journal(signed_descriptor_t *desc) tor_assert(len == strlen(body)); if (append_bytes_to_file(fname, body, len, 0)) { - warn(LD_FS, "Unable to store router descriptor"); + log_warn(LD_FS, "Unable to store router descriptor"); tor_free(fname); return -1; } @@ -221,7 +221,7 @@ router_rebuild_store(int force) sized_chunk_t *c; const char *body = signed_descriptor_get_body(sd); if (!body) { - warn(LD_BUG, "Bug! No descriptor available for router."); + log_warn(LD_BUG, "Bug! No descriptor available for router."); goto done; } c = tor_malloc(sizeof(sized_chunk_t)); @@ -231,7 +231,7 @@ router_rebuild_store(int force) }); } if (write_chunks_to_file(fname, chunk_list, 0)<0) { - warn(LD_FS, "Error writing router store to disk."); + log_warn(LD_FS, "Error writing router store to disk."); goto done; } @@ -339,8 +339,9 @@ router_pick_directory_server(int requireother, if (choice || !retry_if_no_servers) return choice; - info(LD_DIR, - "No reachable router entries for dirservers. Trying them all again."); + log_info(LD_DIR, + "No reachable router entries for dirservers. " + "Trying them all again."); /* mark all authdirservers as up again */ mark_all_trusteddirservers_up(); /* try again */ @@ -349,8 +350,8 @@ router_pick_directory_server(int requireother, if (choice) return choice; - info(LD_DIR,"Still no %s router entries. Reloading and trying again.", - fascistfirewall ? "reachable" : "known"); + log_info(LD_DIR,"Still no %s router entries. Reloading and trying again.", + fascistfirewall ? "reachable" : "known"); if (router_reload_router_list()) { return NULL; } @@ -398,7 +399,8 @@ router_pick_trusteddirserver(int need_v1_authority, if (choice || !retry_if_no_servers) return choice; - info(LD_DIR,"No trusted dirservers are reachable. Trying them all again."); + log_info(LD_DIR, + "No trusted dirservers are reachable. Trying them all again."); mark_all_trusteddirservers_up(); return router_pick_trusteddirserver_impl(need_v1_authority, requireother, fascistfirewall); @@ -586,7 +588,7 @@ add_nickname_list_to_smartlist(smartlist_t *sl, const char *list, SMARTLIST_FOREACH(nickname_list, const char *, nick, { int warned; if (!is_legal_nickname_or_hexdigest(nick)) { - warn(LD_CONFIG, "Nickname '%s' is misformed; skipping", nick); + log_warn(LD_CONFIG, "Nickname '%s' is misformed; skipping", nick); continue; } router = router_get_by_nickname(nick, warn_if_unnamed); @@ -848,18 +850,20 @@ router_choose_random_node(const char *preferred, smartlist_free(sl); if (!choice && (need_uptime || need_capacity || need_guard)) { /* try once more -- recurse but with fewer restrictions. */ - info(LD_CIRC, "We couldn't find any live%s%s%s routers; falling back " - "to list of all routers.", - need_capacity?", fast":"", - need_uptime?", stable":"", - need_guard?", guard":""); + log_info(LD_CIRC, + "We couldn't find any live%s%s%s routers; falling back " + "to list of all routers.", + need_capacity?", fast":"", + need_uptime?", stable":"", + need_guard?", guard":""); choice = router_choose_random_node( NULL, excluded, excludedsmartlist, 0, 0, 0, allow_unverified, 0); } } smartlist_free(excludednodes); if (!choice) - warn(LD_CIRC,"No available nodes when trying to choose node. Failing."); + log_warn(LD_CIRC, + "No available nodes when trying to choose node. Failing."); return choice; } @@ -962,10 +966,11 @@ router_get_by_nickname(const char *nickname, int warn_if_unnamed) }); if (any_unwarned) { char *alternatives = smartlist_join_strings(fps, "; ",0,NULL); - warn(LD_CONFIG, "There are multiple matches for the nickname \"%s\"," - " but none is listed as named by the directory authories. " - "Choosing one arbitrarily. If you meant one in particular, " - "you should say %s.", nickname, alternatives); + log_warn(LD_CONFIG, + "There are multiple matches for the nickname \"%s\"," + " but none is listed as named by the directory authories. " + "Choosing one arbitrarily. If you meant one in particular, " + "you should say %s.", nickname, alternatives); tor_free(alternatives); } SMARTLIST_FOREACH(fps, char *, cp, tor_free(cp)); @@ -977,7 +982,7 @@ router_get_by_nickname(const char *nickname, int warn_if_unnamed) char fp[HEX_DIGEST_LEN+1]; base16_encode(fp, sizeof(fp), best_match->cache_info.identity_digest, DIGEST_LEN); - warn(LD_CONFIG, "You specified a server \"%s\" by name, but the " + log_warn(LD_CONFIG, "You specified a server \"%s\" by name, but the " "directory authorities do not have a listing for this name. " "To make sure you get the same server in the future, refer to " "it by key, as \"$%s\".", nickname, fp); @@ -1274,7 +1279,7 @@ routerlist_replace(routerlist_t *rl, routerinfo_t *ri_old, if (idx >= 0) { smartlist_set(rl->routers, idx, ri_new); } else { - warn(LD_BUG, "Appending entry from routerlist_replace."); + log_warn(LD_BUG, "Appending entry from routerlist_replace."); routerlist_insert(rl, ri_new); return; } @@ -1412,10 +1417,10 @@ router_mark_as_down(const char *digest) router = router_get_by_digest(digest); if (router) { - debug(LD_DIR,"Marking router '%s' as down.",router->nickname); + log_debug(LD_DIR,"Marking router '%s' as down.",router->nickname); if (router_is_me(router) && !we_are_hibernating()) - warn(LD_NET, "We just marked ourself as down. Are your external " - "addresses reachable?"); + log_warn(LD_NET, "We just marked ourself as down. Are your external " + "addresses reachable?"); router->is_running = 0; } status = router_get_combined_status_by_digest(digest); @@ -1474,8 +1479,9 @@ router_add_to_routerlist(routerinfo_t *router, const char **msg, /* Make sure that we haven't already got this exact descriptor. */ if (digestmap_get(routerlist->desc_digest_map, router->cache_info.signed_descriptor_digest)) { - info(LD_DIR, "Dropping descriptor that we already have for router '%s'", - router->nickname); + log_info(LD_DIR, + "Dropping descriptor that we already have for router '%s'", + router->nickname); *msg = "Router descriptor was not new."; routerinfo_free(router); return -1; @@ -1496,8 +1502,8 @@ router_add_to_routerlist(routerinfo_t *router, const char **msg, /* Only check the descriptor digest against the network statuses when * we are receiving in response to a fetch. */ if (!signed_desc_digest_is_recognized(&router->cache_info)) { - warn(LD_DIR, "Dropping unrecognized descriptor for router '%s'", - router->nickname); + log_warn(LD_DIR, "Dropping unrecognized descriptor for router '%s'", + router->nickname); *msg = "Router descriptor is not referenced by any network-status."; routerinfo_free(router); return -1; @@ -1515,17 +1521,17 @@ router_add_to_routerlist(routerinfo_t *router, const char **msg, if (router->cache_info.published_on <= old_router->cache_info.published_on) { /* Same key, but old */ - debug(LD_DIR, "Skipping not-new descriptor for router '%s'", - router->nickname); + log_debug(LD_DIR, "Skipping not-new descriptor for router '%s'", + router->nickname); routerlist_insert_old(routerlist, router); *msg = "Router descriptor was not new."; return -1; } else { /* Same key, new. */ int unreachable = 0; - 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/%s' [%s]", + router->nickname, old_router->nickname, + hex_str(id_digest,DIGEST_LEN)); if (router->addr == old_router->addr && router->or_port == old_router->or_port) { /* these carry over when the address and orport are unchanged.*/ @@ -1539,15 +1545,15 @@ router_add_to_routerlist(routerinfo_t *router, const char **msg, time(NULL))) { if (router->num_unreachable_notifications >= 3) { unreachable = 1; - notice(LD_DIR, "Notifying server '%s' that it's unreachable. " - "(ContactInfo '%s', platform '%s').", - router->nickname, - router->contact_info ? router->contact_info : "", - router->platform ? router->platform : ""); + log_notice(LD_DIR, "Notifying server '%s' that it's unreachable. " + "(ContactInfo '%s', platform '%s').", + router->nickname, + router->contact_info ? router->contact_info : "", + router->platform ? router->platform : ""); } else { - info(LD_DIR,"'%s' may be unreachable -- the %d previous " - "descriptors were thought to be unreachable.", - router->nickname, router->num_unreachable_notifications); + log_info(LD_DIR,"'%s' may be unreachable -- the %d previous " + "descriptors were thought to be unreachable.", + router->nickname, router->num_unreachable_notifications); router->num_unreachable_notifications++; } } @@ -1576,16 +1582,16 @@ router_add_to_routerlist(routerinfo_t *router, const char **msg, while ((conn = connection_or_get_by_identity_digest( old_router->cache_info.identity_digest))) { // And LD_OR? XXXXNM - info(LD_DIR,"Closing conn to router '%s'; there is now a named " - "router with that name.", - old_router->nickname); + log_info(LD_DIR,"Closing conn to router '%s'; there is now a named " + "router with that name.", + old_router->nickname); connection_mark_for_close(conn); } routerlist_remove(routerlist, old_router, i--, 0); } else if (old_router->is_named) { /* Can't replace a verified router with an unverified one. */ - debug(LD_DIR, "Skipping unverified entry for verified router '%s'", - router->nickname); + log_debug(LD_DIR, "Skipping unverified entry for verified router '%s'", + router->nickname); routerinfo_free(router); *msg = "Already have named router with same nickname and different key."; @@ -1746,8 +1752,9 @@ routerlist_remove_old_routers(void) if (router->cache_info.published_on <= cutoff && !digestmap_get(retain, router->cache_info.signed_descriptor_digest)) { /* Too old. Remove it. */ - info(LD_DIR, "Forgetting obsolete (too old) routerinfo for router '%s'", - router->nickname); + log_info(LD_DIR, + "Forgetting obsolete (too old) routerinfo for router '%s'", + router->nickname); routerlist_remove(routerlist, router, i--, 1); } } @@ -1818,12 +1825,12 @@ router_load_single_router(const char *s, const char **msg) *msg = NULL; if (!(ri = router_parse_entry_from_string(s, NULL))) { - warn(LD_DIR, "Error parsing router descriptor; dropping."); + log_warn(LD_DIR, "Error parsing router descriptor; dropping."); *msg = "Couldn't parse router descriptor."; return -1; } if (router_is_me(ri)) { - warn(LD_DIR, "Router's identity key matches mine; dropping."); + log_warn(LD_DIR, "Router's identity key matches mine; dropping."); *msg = "Router's identity key matches mine."; routerinfo_free(ri); return 0; @@ -1834,15 +1841,15 @@ router_load_single_router(const char *s, const char **msg) routers_update_status_from_networkstatus(lst, 0); if (router_add_to_routerlist(ri, msg, 0, 0)<0) { - warn(LD_DIR, "Couldn't add router to list: %s Dropping.", - *msg?*msg:"(No message)."); + log_warn(LD_DIR, "Couldn't add router to list: %s Dropping.", + *msg?*msg:"(No message)."); /* we've already assigned to *msg now, and ri is already freed */ smartlist_free(lst); return 0; } else { control_event_descriptors_changed(lst); smartlist_free(lst); - debug(LD_DIR, "Added router to list"); + log_debug(LD_DIR, "Added router to list"); return 1; } } @@ -1868,7 +1875,7 @@ router_load_routers_from_string(const char *s, int from_cache, routers_update_status_from_networkstatus(routers, !from_cache); - info(LD_DIR, "%d elements to add", smartlist_len(routers)); + log_info(LD_DIR, "%d elements to add", smartlist_len(routers)); SMARTLIST_FOREACH(routers, routerinfo_t *, ri, { @@ -1880,10 +1887,10 @@ router_load_routers_from_string(const char *s, int from_cache, } else { char *requested = smartlist_join_strings(requested_fingerprints," ",0,NULL); - warn(LD_DIR, - "We received a router descriptor with a fingerprint (%s) " - "that we never requested. (We asked for: %s.) Dropping.", - fp, requested); + log_warn(LD_DIR, + "We received a router descriptor with a fingerprint (%s) " + "that we never requested. (We asked for: %s.) Dropping.", + fp, requested); tor_free(requested); routerinfo_free(ri); continue; @@ -1943,7 +1950,7 @@ add_networkstatus_to_cache(const char *s, if (source != NS_FROM_CACHE) { char *fn = networkstatus_get_cache_filename(ns); if (write_str_to_file(fn, s, 0)<0) { - notice(LD_FS, "Couldn't write cached network status to \"%s\"", fn); + log_notice(LD_FS, "Couldn't write cached network status to \"%s\"", fn); } tor_free(fn); } @@ -1994,14 +2001,14 @@ router_set_networkstatus(const char *s, time_t arrived_at, ns = networkstatus_parse_from_string(s); if (!ns) { - warn(LD_DIR, "Couldn't parse network status."); + log_warn(LD_DIR, "Couldn't parse network status."); return -1; } base16_encode(fp, HEX_DIGEST_LEN+1, ns->identity_digest, DIGEST_LEN); if (!(trusted_dir = router_get_trusteddirserver_by_digest(ns->identity_digest))) { - info(LD_DIR, "Network status was signed, but not by an authoritative " - "directory we recognize."); + log_info(LD_DIR, "Network status was signed, but not by an authoritative " + "directory we recognize."); if (!get_options()->DirPort) { networkstatus_free(ns); return 0; @@ -2019,9 +2026,10 @@ router_set_networkstatus(const char *s, time_t arrived_at, format_iso_time(published, ns->published_on); if (ns->published_on > now + NETWORKSTATUS_ALLOW_SKEW) { - warn(LD_GENERAL, "Network status from %s was published in the future " - "(%s GMT). Somebody is skewed here: check your clock. Not caching.", - source_desc, published); + log_warn(LD_GENERAL, "Network status from %s was published in the future " + "(%s GMT). Somebody is skewed here: check your clock. " + "Not caching.", + source_desc, published); skewed = 1; } @@ -2040,9 +2048,10 @@ router_set_networkstatus(const char *s, time_t arrived_at, } else { char *requested = smartlist_join_strings(requested_fingerprints," ",0,NULL); - warn(LD_DIR, - "We received a network status with a fingerprint (%s) that we " - "never requested. (We asked for: %s.) Dropping.", fp, requested); + log_warn(LD_DIR, + "We received a network status with a fingerprint (%s) that we " + "never requested. (We asked for: %s.) Dropping.", + fp, requested); tor_free(requested); return 0; } @@ -2068,10 +2077,10 @@ router_set_networkstatus(const char *s, time_t arrived_at, ns->networkstatus_digest, DIGEST_LEN)) { /* Same one we had before. */ networkstatus_free(ns); - info(LD_DIR, - "Not replacing network-status from %s (published %s); " - "we already have it.", - trusted_dir->description, published); + log_info(LD_DIR, + "Not replacing network-status from %s (published %s); " + "we already have it.", + trusted_dir->description, published); if (old_ns->received_on < arrived_at) { if (source != NS_FROM_CACHE) { char *fn = networkstatus_get_cache_filename(old_ns); @@ -2085,11 +2094,11 @@ router_set_networkstatus(const char *s, time_t arrived_at, } else if (old_ns->published_on >= ns->published_on) { char old_published[ISO_TIME_LEN+1]; format_iso_time(old_published, old_ns->published_on); - info(LD_DIR, - "Not replacing network-status from %s (published %s);" - " we have a newer one (published %s) for this authority.", - trusted_dir->description, published, - old_published); + log_info(LD_DIR, + "Not replacing network-status from %s (published %s);" + " we have a newer one (published %s) for this authority.", + trusted_dir->description, published, + old_published); networkstatus_free(ns); return 0; } else { @@ -2110,10 +2119,10 @@ router_set_networkstatus(const char *s, time_t arrived_at, rs->need_to_mirror = 1; }); - info(LD_DIR, "Setting networkstatus %s %s (published %s)", - source == NS_FROM_CACHE?"cached from": - (source==NS_FROM_DIR?"downloaded from":"generated for"), - trusted_dir->description, published); + log_info(LD_DIR, "Setting networkstatus %s %s (published %s)", + source == NS_FROM_CACHE?"cached from": + (source==NS_FROM_DIR?"downloaded from":"generated for"), + trusted_dir->description, published); networkstatus_list_has_changed = 1; smartlist_sort(networkstatus_list, _compare_networkstatus_published_on); @@ -2148,7 +2157,7 @@ networkstatus_list_clean(time_t now) smartlist_del(networkstatus_list, i--); fname = networkstatus_get_cache_filename(ns); if (file_status(fname) == FN_FILE) { - info(LD_DIR, "Removing too-old networkstatus in %s", fname); + log_info(LD_DIR, "Removing too-old networkstatus in %s", fname); unlink(fname); } tor_free(fname); @@ -2324,18 +2333,18 @@ update_networkstatus_client_downloads(time_t now) needed = n_running_dirservers; if (needed) - info(LD_DIR, "For %d/%d running directory servers, we have %d live" - " network-status documents. Downloading %d.", - n_running_dirservers, n_dirservers, n_live, needed); + log_info(LD_DIR, "For %d/%d running directory servers, we have %d live" + " network-status documents. Downloading %d.", + n_running_dirservers, n_dirservers, n_live, needed); /* Also, download at least 1 every NETWORKSTATUS_CLIENT_DL_INTERVAL. */ if (n_running_dirservers && most_recent_received < now-NETWORKSTATUS_CLIENT_DL_INTERVAL && needed < 1) { - info(LD_DIR, "Our most recent network-status document (from %s) " - "is %d seconds old; downloading another.", - most_recent?most_recent->description:"nobody", - (int)(now-most_recent_received)); + log_info(LD_DIR, "Our most recent network-status document (from %s) " + "is %d seconds old; downloading another.", + most_recent?most_recent->description:"nobody", + (int)(now-most_recent_received)); needed = 1; } @@ -2553,13 +2562,14 @@ exit_policy_implicitly_allows_local_networks(addr_policy_t *policy, }; for (i=0; private_networks[i].mask; ++i) { p = NULL; - /* info(LD_CONFIG,"Checking network %s", private_networks[i].network); */ + /* log_info(LD_CONFIG, + "Checking network %s", private_networks[i].network); */ if (policy_includes_addr_mask_implicitly( policy, private_networks[i].addr, private_networks[i].mask, &p)) { if (should_warn) - warn(LD_CONFIG, "Exit policy %s implicitly accepts %s", - p?p->string:"(default)", - private_networks[i].network); + log_warn(LD_CONFIG, "Exit policy %s implicitly accepts %s", + p?p->string:"(default)", + private_networks[i].network); r = 1; } } @@ -2593,15 +2603,16 @@ add_trusted_dir_server(const char *nickname, const char *address, if (!address) { /* The address is us; we should guess. */ if (resolve_my_address(get_options(), &a, &hostname) < 0) { - warn(LD_CONFIG, - "Couldn't find a suitable address when adding ourself as a " - "trusted directory server."); + log_warn(LD_CONFIG, + "Couldn't find a suitable address when adding ourself as a " + "trusted directory server."); return; } } else { if (tor_lookup_hostname(address, &a)) { - warn(LD_CONFIG, "Unable to lookup address for directory server at '%s'", - address); + log_warn(LD_CONFIG, + "Unable to lookup address for directory server at '%s'", + address); return; } hostname = tor_strdup(address); @@ -2779,16 +2790,16 @@ routers_update_all_from_networkstatus(void) * network-statuses we have. Perhaps we should wait until we * have tried all of them? -RD */ if (n_valid <= n_recent/2) { - warn(LD_GENERAL, - "%d/%d recent directory servers list us as invalid. Please " - "consider sending your identity fingerprint to the tor-ops.", - n_recent-n_valid, n_recent); + log_warn(LD_GENERAL, + "%d/%d recent directory servers list us as invalid. Please " + "consider sending your identity fingerprint to the tor-ops.", + n_recent-n_valid, n_recent); have_warned_about_unverified_status = 1; } else if (!n_named) { // (n_named <= n_recent/2) { - warn(LD_GENERAL, "0/%d recent directory servers recognize this " - "server. Please consider sending your identity fingerprint to " - "the tor-ops.", - n_recent); + log_warn(LD_GENERAL, "0/%d recent directory servers recognize this " + "server. Please consider sending your identity fingerprint " + "to the tor-ops.", + n_recent); have_warned_about_unverified_status = 1; } } @@ -2821,7 +2832,7 @@ routers_update_all_from_networkstatus(void) if (consensus == VS_NEW || consensus == VS_NEW_IN_SERIES) { if (!have_warned_about_new_version) { char *rec = compute_recommended_versions(now, !is_server); - notice(LD_GENERAL, "This version of Tor (%s) is newer than any " + log_notice(LD_GENERAL, "This version of Tor (%s) is newer than any " "recommended version%s, according to %d/%d recent network " "statuses. Versions recommended by at least %d recent " "authorities are: %s", @@ -2833,19 +2844,19 @@ routers_update_all_from_networkstatus(void) } } else { char *rec = compute_recommended_versions(now, !is_server); - warn(LD_GENERAL, "Please upgrade! " - "This version of Tor (%s) is %s, according to " - "%d/%d recent network statuses. Versions recommended by " - "at least %d recent authorit%s are: %s", - VERSION, consensus == VS_OLD ? "obsolete" : "not recommended", - n_recent-n_recommended, n_recent, n_recent/2, - n_recent/2 > 1 ? "ies" : "y", rec); + log_warn(LD_GENERAL, "Please upgrade! " + "This version of Tor (%s) is %s, according to " + "%d/%d recent network statuses. Versions recommended by " + "at least %d recent authorit%s are: %s", + VERSION, consensus == VS_OLD ? "obsolete" : "not recommended", + n_recent-n_recommended, n_recent, n_recent/2, + n_recent/2 > 1 ? "ies" : "y", rec); have_warned_about_old_version = 1; tor_free(rec); } } else { - info(LD_GENERAL, "%d/%d recent directories think my version is ok.", - n_recommended, n_recent); + log_info(LD_GENERAL, "%d/%d recent directories think my version is ok.", + n_recommended, n_recent); } } @@ -2885,9 +2896,9 @@ networkstatus_list_update_recent(time_t now) ns->published_on + DEFAULT_RUNNING_INTERVAL > now) { if (!ns->is_recent) { format_iso_time(published, ns->published_on); - info(LD_DIR, - "Networkstatus from %s (published %s) is now \"recent\"", - src, published); + log_info(LD_DIR, + "Networkstatus from %s (published %s) is now \"recent\"", + src, published); changed = 1; } ns->is_recent = 1; @@ -2895,9 +2906,10 @@ networkstatus_list_update_recent(time_t now) } else { if (ns->is_recent) { format_iso_time(published, ns->published_on); - info(LD_DIR, - "Networkstatus from %s (published %s) is no longer \"recent\"", - src, published); + log_info(LD_DIR, + "Networkstatus from %s (published %s) is " + "no longer \"recent\"", + src, published); changed = 1; ns->is_recent = 0; } @@ -2951,12 +2963,13 @@ routerstatus_list_update_from_networkstatus(time_t now) if (n_statuses < (n_trusted/2)+1) { /* Not enough statuses to adjust status. */ - notice(LD_DIR,"Not enough statuses to update router status list. (%d/%d)", - n_statuses, n_trusted); + log_notice(LD_DIR, + "Not enough statuses to update router status list. (%d/%d)", + n_statuses, n_trusted); return; } - info(LD_DIR, "Rebuilding router status list."); + log_info(LD_DIR, "Rebuilding router status list."); index = tor_malloc(sizeof(int)*n_statuses); size = tor_malloc(sizeof(int)*n_statuses); @@ -3075,9 +3088,10 @@ routerstatus_list_update_from_networkstatus(time_t now) char hd[HEX_DIGEST_LEN+1]; base16_encode(hd, HEX_DIGEST_LEN+1, rs->identity_digest, DIGEST_LEN); if (! smartlist_string_isin(warned_conflicts, hd)) { - warn(LD_DIR, "Naming authorities disagree about nicknames for $%s " - "(\"%s\" vs \"%s\")", - hd, the_name, rs->nickname); + log_warn(LD_DIR, + "Naming authorities disagree about nicknames for $%s " + "(\"%s\" vs \"%s\")", + hd, the_name, rs->nickname); smartlist_add(warned_conflicts, tor_strdup(hd)); } the_name = "**mismatch**"; @@ -3138,12 +3152,12 @@ routerstatus_list_update_from_networkstatus(time_t now) rs_out->name_lookup_warned = rs_old->name_lookup_warned; } smartlist_add(result, rs_out); - debug(LD_DIR, "Router '%s' is listed by %d/%d directories, " - "named by %d/%d, validated by %d/%d, and %d/%d recent directories " - "think it's running.", - rs_out->status.nickname, - n_listing, n_statuses, n_named, n_naming, n_valid, n_statuses, - n_running, n_recent); + log_debug(LD_DIR, "Router '%s' is listed by %d/%d directories, " + "named by %d/%d, validated by %d/%d, and %d/%d recent " + "directories think it's running.", + rs_out->status.nickname, + n_listing, n_statuses, n_named, n_naming, n_valid, n_statuses, + n_running, n_recent); rs_out->status.is_named = 0; if (the_name && strcmp(the_name, "**mismatch**") && n_named > 0) { const char *d = strmap_get_lc(name_map, the_name); @@ -3371,7 +3385,7 @@ router_list_client_downloadable(void) }); #if 0 - info(LD_DIR, + log_info(LD_DIR, "%d router descriptors are downloadable. %d are too old to consider. " "%d are in progress. %d are up-to-date. %d are too young to consider. " "%d are non-useful. %d failed too recently to retry.", @@ -3411,28 +3425,31 @@ update_router_descriptor_client_downloads(time_t now) or_options_t *options = get_options(); if (server_mode(options) && options->DirPort) { - warn(LD_BUG, "Called router_descriptor_client_downloads() on a mirror?"); + log_warn(LD_BUG, + "Called router_descriptor_client_downloads() on a mirror?"); } if (networkstatus_list && smartlist_len(networkstatus_list) < 2) { /* XXXX Is this redundant? -NM */ - info(LD_DIR, "Not enough networkstatus documents to launch requests."); + log_info(LD_DIR, + "Not enough networkstatus documents to launch requests."); } downloadable = router_list_client_downloadable(); n_downloadable = smartlist_len(downloadable); if (n_downloadable >= MAX_DL_TO_DELAY) { - debug(LD_DIR, - "There are enough downloadable routerdescs to launch requests."); + log_debug(LD_DIR, + "There are enough downloadable routerdescs to launch requests."); should_delay = 0; } else if (n_downloadable == 0) { -// debug(LD_DIR, "No routerdescs need to be downloaded."); +// log_debug(LD_DIR, "No routerdescs need to be downloaded."); should_delay = 1; } else { should_delay = (last_routerdesc_download_attempted + MAX_CLIENT_INTERVAL_WITHOUT_REQUEST) > now; if (!should_delay) - info(LD_DIR, "There are not many downloadable routerdescs, but we've " + log_info(LD_DIR, + "There are not many downloadable routerdescs, but we've " "been waiting long enough (%d seconds). Downloading.", (int)(now-last_routerdesc_download_attempted)); } @@ -3445,10 +3462,11 @@ update_router_descriptor_client_downloads(time_t now) if (n_per_request < MIN_DL_PER_REQUEST) n_per_request = MIN_DL_PER_REQUEST; - info(LD_DIR, "Launching %d request%s for %d router%s, %d at a time", - (n_downloadable+n_per_request-1)/n_per_request, - n_downloadable>n_per_request?"s":"", - n_downloadable, n_downloadable>1?"s":"", n_per_request); + log_info(LD_DIR, + "Launching %d request%s for %d router%s, %d at a time", + (n_downloadable+n_per_request-1)/n_per_request, + n_downloadable>n_per_request?"s":"", + n_downloadable, n_downloadable>1?"s":"", n_per_request); for (i=0; i < n_downloadable; i += n_per_request) { initiate_descriptor_downloads(NULL, downloadable, i, i+n_per_request); } @@ -3469,8 +3487,8 @@ update_router_descriptor_cache_downloads(time_t now) or_options_t *options = get_options(); if (!(server_mode(options) && options->DirPort)) { - warn(LD_BUG, "Called update_router_descriptor_cache_downloads() " - "on a non-mirror?"); + log_warn(LD_BUG, "Called update_router_descriptor_cache_downloads() " + "on a non-mirror?"); } if (!networkstatus_list || !smartlist_len(networkstatus_list)) @@ -3502,7 +3520,8 @@ update_router_descriptor_cache_downloads(time_t now) if (!rs->need_to_mirror) continue; if (router_get_by_descriptor_digest(rs->descriptor_digest)) { - warn(LD_BUG, "We have a router descriptor, but need_to_mirror=1."); + log_warn(LD_BUG, + "We have a router descriptor, but need_to_mirror=1."); rs->need_to_mirror = 0; continue; } @@ -3556,13 +3575,13 @@ update_router_descriptor_cache_downloads(time_t now) router_get_trusteddirserver_by_digest(ns->identity_digest); smartlist_t *dl = download_from[i]; if (!ds) { - warn(LD_BUG, "Networkstatus with no corresponding authority!"); + log_warn(LD_BUG, "Networkstatus with no corresponding authority!"); continue; } if (! smartlist_len(dl)) continue; - info(LD_DIR, "Requesting %d descriptors from authority \"%s\"", - smartlist_len(dl), ds->nickname); + log_info(LD_DIR, "Requesting %d descriptors from authority \"%s\"", + smartlist_len(dl), ds->nickname); for (j=0; j < smartlist_len(dl); j += MAX_DL_PER_REQUEST) { initiate_descriptor_downloads(&(ds->fake_status), dl, j, j+MAX_DL_PER_REQUEST); diff --git a/src/or/routerparse.c b/src/or/routerparse.c index a5abae3fda..4bdd1ce06a 100644 --- a/src/or/routerparse.c +++ b/src/or/routerparse.c @@ -223,7 +223,7 @@ router_append_dirobj_signature(char *buf, size_t buf_len, const char *digest, if (crypto_pk_private_sign(private_key, signature, digest, DIGEST_LEN) < 0) { - warn(LD_BUG,"Couldn't sign digest."); + log_warn(LD_BUG,"Couldn't sign digest."); return -1; } if (strlcat(buf, "-----BEGIN SIGNATURE-----\n", buf_len) >= buf_len) @@ -231,7 +231,7 @@ router_append_dirobj_signature(char *buf, size_t buf_len, const char *digest, i = strlen(buf); if (base64_encode(buf+i, buf_len-i, signature, 128) < 0) { - warn(LD_BUG,"couldn't base64-encode signature"); + log_warn(LD_BUG,"couldn't base64-encode signature"); tor_free(buf); return -1; } @@ -241,7 +241,7 @@ router_append_dirobj_signature(char *buf, size_t buf_len, const char *digest, return 0; truncated: - warn(LD_BUG,"tried to exceed string length."); + log_warn(LD_BUG,"tried to exceed string length."); return -1; } @@ -270,11 +270,11 @@ tor_version_is_obsolete(const char *myversion, const char *versionlist) vl = versionlist; - debug(LD_CONFIG,"Checking whether version '%s' is in '%s'", - myversion, versionlist); + log_debug(LD_CONFIG,"Checking whether version '%s' is in '%s'", + myversion, versionlist); if (tor_version_parse(myversion, &mine)) { - err(LD_BUG,"I couldn't parse my own version (%s)", myversion); + log_err(LD_BUG,"I couldn't parse my own version (%s)", myversion); tor_assert(0); } version_sl = smartlist_create(); @@ -370,29 +370,29 @@ router_parse_directory(const char *str) * touch it. */ if (router_get_dir_hash(str, digest)) { - warn(LD_DIR, "Unable to compute digest of directory"); + log_warn(LD_DIR, "Unable to compute digest of directory"); goto err; } - debug(LD_DIR,"Received directory hashes to %s",hex_str(digest,4)); + log_debug(LD_DIR,"Received directory hashes to %s",hex_str(digest,4)); /* Check signature first, before we try to tokenize. */ cp = str; while (cp && (end = strstr(cp+1, "\ndirectory-signature"))) cp = end; if (cp == str || !cp) { - warn(LD_DIR, "No signature found on directory."); goto err; + log_warn(LD_DIR, "No signature found on directory."); goto err; } ++cp; tokens = smartlist_create(); if (tokenize_string(cp,strchr(cp,'\0'),tokens,DIR)) { - warn(LD_DIR, "Error tokenizing directory signature"); goto err; + log_warn(LD_DIR, "Error tokenizing directory signature"); goto err; } if (smartlist_len(tokens) != 1) { - warn(LD_DIR, "Unexpected number of tokens in signature"); goto err; + log_warn(LD_DIR, "Unexpected number of tokens in signature"); goto err; } tok=smartlist_get(tokens,0); if (tok->tp != K_DIRECTORY_SIGNATURE) { - warn(LD_DIR,"Expected a single directory signature"); goto err; + log_warn(LD_DIR,"Expected a single directory signature"); goto err; } declared_key = find_dir_signing_key(str); if (check_directory_signature(digest, tok, NULL, declared_key, 1)<0) @@ -413,11 +413,11 @@ router_parse_directory(const char *str) tokens = smartlist_create(); if (tokenize_string(str,end,tokens,DIR)) { - warn(LD_DIR, "Error tokenizing directory"); goto err; + log_warn(LD_DIR, "Error tokenizing directory"); goto err; } if (!(tok = find_first_by_keyword(tokens, K_PUBLISHED))) { - warn(LD_DIR, "Missing published time on directory."); + log_warn(LD_DIR, "Missing published time on directory."); goto err; } tor_assert(tok->n_args == 1); @@ -458,26 +458,26 @@ router_parse_runningrouters(const char *str) smartlist_t *tokens = NULL; if (router_get_runningrouters_hash(str, digest)) { - warn(LD_DIR, "Unable to compute digest of directory"); + log_warn(LD_DIR, "Unable to compute digest of directory"); goto err; } tokens = smartlist_create(); if (tokenize_string(str,str+strlen(str),tokens,DIR)) { - warn(LD_DIR, "Error tokenizing directory"); goto err; + log_warn(LD_DIR, "Error tokenizing directory"); goto err; } if ((tok = find_first_by_keyword(tokens, _UNRECOGNIZED))) { - warn(LD_DIR, "Unrecognized keyword '%s'; can't parse running-routers", - tok->args[0]); + log_warn(LD_DIR, "Unrecognized keyword '%s'; can't parse running-routers", + tok->args[0]); goto err; } tok = smartlist_get(tokens,0); if (tok->tp != K_NETWORK_STATUS) { - warn(LD_DIR, "Network-status starts with wrong token"); + log_warn(LD_DIR, "Network-status starts with wrong token"); goto err; } if (!(tok = find_first_by_keyword(tokens, K_PUBLISHED))) { - warn(LD_DIR, "Missing published time on directory."); + log_warn(LD_DIR, "Missing published time on directory."); goto err; } tor_assert(tok->n_args == 1); @@ -485,7 +485,7 @@ router_parse_runningrouters(const char *str) goto err; } if (!(tok = find_first_by_keyword(tokens, K_DIRECTORY_SIGNATURE))) { - warn(LD_DIR, "Missing signature on running-routers"); + log_warn(LD_DIR, "Missing signature on running-routers"); goto err; } declared_key = find_dir_signing_key(str); @@ -527,11 +527,11 @@ find_dir_signing_key(const char *str) tok = get_next_token(&cp, DIR); if (!tok) { - warn(LD_DIR, "Unparseable dir-signing-key token"); + log_warn(LD_DIR, "Unparseable dir-signing-key token"); return NULL; } if (tok->tp != K_DIR_SIGNING_KEY) { - warn(LD_DIR, "Dir-signing-key token did not parse as expected"); + log_warn(LD_DIR, "Dir-signing-key token did not parse as expected"); return NULL; } @@ -543,11 +543,11 @@ find_dir_signing_key(const char *str) * can remove this logic. */ key = crypto_pk_DER64_decode_public_key(tok->args[0]); if (!key) { - warn(LD_DIR, "Unparseable dir-signing-key argument"); + log_warn(LD_DIR, "Unparseable dir-signing-key argument"); return NULL; } } else { - warn(LD_DIR, "Dir-signing-key token contained no key"); + log_warn(LD_DIR, "Dir-signing-key token contained no key"); return NULL; } @@ -563,11 +563,11 @@ dir_signing_key_is_trusted(crypto_pk_env_t *key) char digest[DIGEST_LEN]; if (!key) return 0; if (crypto_pk_get_digest(key, digest) < 0) { - warn(LD_DIR, "Error computing dir-signing-key digest"); + log_warn(LD_DIR, "Error computing dir-signing-key digest"); return 0; } if (!router_digest_is_trusted_dir(digest)) { - warn(LD_DIR, "Listed dir-signing-key is not trusted"); + log_warn(LD_DIR, "Listed dir-signing-key is not trusted"); return 0; } return 1; @@ -596,7 +596,7 @@ check_directory_signature(const char *digest, crypto_pk_env_t *_pkey = NULL; if (tok->n_args != 1) { - warn(LD_DIR, "Too many or too few arguments to directory-signature"); + log_warn(LD_DIR, "Too many or too few arguments to directory-signature"); return -1; } @@ -609,13 +609,14 @@ check_directory_signature(const char *digest, _pkey = pkey; } if (!_pkey) { - warn(LD_DIR, "Obsolete directory format (dir signing key not present) or " - "signing key not trusted--rejecting."); + log_warn(LD_DIR, + "Obsolete directory format (dir signing key not present) or " + "signing key not trusted--rejecting."); return -1; } if (strcmp(tok->object_type, "SIGNATURE") || tok->object_size != 128) { - warn(LD_DIR, "Bad object type or length on directory signature"); + log_warn(LD_DIR, "Bad object type or length on directory signature"); return -1; } @@ -623,12 +624,13 @@ check_directory_signature(const char *digest, if (crypto_pk_public_checksig(_pkey, signed_digest, tok->object_body, 128) != 20) { - warn(LD_DIR, "Error reading directory: invalid signature."); + log_warn(LD_DIR, "Error reading directory: invalid signature."); return -1; } - debug(LD_DIR,"Signed directory hash starts %s", hex_str(signed_digest,4)); + log_debug(LD_DIR,"Signed directory hash starts %s", + hex_str(signed_digest,4)); if (memcmp(digest, signed_digest, DIGEST_LEN)) { - warn(LD_DIR, "Error reading directory: signature does not match."); + log_warn(LD_DIR, "Error reading directory: signature does not match."); return -1; } return 0; @@ -675,7 +677,7 @@ router_parse_list_from_string(const char **s, smartlist_t *dest) * descriptor */ if (strcmpstart(cp, "\n-----END SIGNATURE-----\n")) { - info(LD_DIR, "Ignoring truncated router descriptor."); + log_info(LD_DIR, "Ignoring truncated router descriptor."); *s = end; continue; } @@ -684,7 +686,7 @@ router_parse_list_from_string(const char **s, smartlist_t *dest) *s = end; if (!router) { - warn(LD_DIR, "Error reading router; skipping"); + log_warn(LD_DIR, "Error reading router; skipping"); continue; } smartlist_add(dest, router); @@ -717,30 +719,30 @@ router_parse_entry_from_string(const char *s, const char *end) --end; if (router_get_router_hash(s, digest) < 0) { - warn(LD_DIR, "Couldn't compute router hash."); + log_warn(LD_DIR, "Couldn't compute router hash."); return NULL; } tokens = smartlist_create(); if (tokenize_string(s,end,tokens,RTR)) { - warn(LD_DIR, "Error tokeninzing router descriptor."); + log_warn(LD_DIR, "Error tokeninzing router descriptor."); goto err; } if (smartlist_len(tokens) < 2) { - warn(LD_DIR, "Impossibly short router descriptor."); + log_warn(LD_DIR, "Impossibly short router descriptor."); goto err; } if ((tok = find_first_by_keyword(tokens, _UNRECOGNIZED))) { - warn(LD_DIR, - "Unrecognized critical keyword '%s'; skipping descriptor. " - "(It may be from another version of Tor.)", - tok->args[0]); + log_warn(LD_DIR, + "Unrecognized critical keyword '%s'; skipping descriptor. " + "(It may be from another version of Tor.)", + tok->args[0]); goto err; } tok = smartlist_get(tokens,0); if (tok->tp != K_ROUTER) { - warn(LD_DIR,"Entry does not start with \"router\""); + log_warn(LD_DIR,"Entry does not start with \"router\""); goto err; } @@ -752,12 +754,12 @@ router_parse_entry_from_string(const char *s, const char *end) if (tok->n_args >= 5) { router->nickname = tor_strdup(tok->args[0]); if (!is_legal_nickname(router->nickname)) { - warn(LD_DIR,"Router nickname is invalid"); + log_warn(LD_DIR,"Router nickname is invalid"); goto err; } router->address = tor_strdup(tok->args[1]); if (!tor_inet_aton(router->address, &in)) { - warn(LD_DIR,"Router address is not an IP."); + log_warn(LD_DIR,"Router address is not an IP."); goto err; } router->addr = ntohl(in.s_addr); @@ -767,18 +769,18 @@ router_parse_entry_from_string(const char *s, const char *end) router->dir_port = (uint16_t) tor_parse_long(tok->args[4],10,0,65535,NULL,NULL); } else { - warn(LD_DIR,"Wrong # of arguments to \"router\" (%d)",tok->n_args); + log_warn(LD_DIR,"Wrong # of arguments to \"router\" (%d)",tok->n_args); goto err; } tok = find_first_by_keyword(tokens, K_BANDWIDTH); if (!tok) { - warn(LD_DIR,"No bandwidth declared; failing."); + log_warn(LD_DIR,"No bandwidth declared; failing."); goto err; } else { if (tok->n_args < 3) { - warn(LD_DIR, - "Not enough arguments to \"bandwidth\" in server descriptor."); + log_warn(LD_DIR, + "Not enough arguments to \"bandwidth\" in server descriptor."); goto err; } router->bandwidthrate = @@ -791,7 +793,7 @@ router_parse_entry_from_string(const char *s, const char *end) if ((tok = find_first_by_keyword(tokens, K_UPTIME))) { if (tok->n_args != 1) { - warn(LD_DIR, "Unrecognized number of args on K_UPTIME; skipping."); + log_warn(LD_DIR, "Unrecognized number of args on K_UPTIME; skipping."); } else { router->uptime = tor_parse_long(tok->args[0],10,0,LONG_MAX,NULL,NULL); } @@ -799,7 +801,7 @@ router_parse_entry_from_string(const char *s, const char *end) if ((tok = find_first_by_keyword(tokens, K_HIBERNATING))) { if (tok->n_args < 1) { - warn(LD_DIR, "Too few args on 'hibernating' keyword. Skipping."); + log_warn(LD_DIR, "Too few args on 'hibernating' keyword. Skipping."); } else { router->is_hibernating = (tor_parse_long(tok->args[0],10,0,LONG_MAX,NULL,NULL) != 0); @@ -807,28 +809,28 @@ router_parse_entry_from_string(const char *s, const char *end) } if (!(tok = find_first_by_keyword(tokens, K_PUBLISHED))) { - warn(LD_DIR, "Missing published time"); goto err; + log_warn(LD_DIR, "Missing published time"); goto err; } tor_assert(tok->n_args == 1); if (parse_iso_time(tok->args[0], &router->cache_info.published_on) < 0) goto err; if (!(tok = find_first_by_keyword(tokens, K_ONION_KEY))) { - warn(LD_DIR, "Missing onion key"); goto err; + log_warn(LD_DIR, "Missing onion key"); goto err; } if (crypto_pk_keysize(tok->key) != PK_BYTES) { - warn(LD_DIR, "Wrong size on onion key: %d bits!", - (int)crypto_pk_keysize(tok->key)*8); + log_warn(LD_DIR, "Wrong size on onion key: %d bits!", + (int)crypto_pk_keysize(tok->key)*8); goto err; } router->onion_pkey = tok->key; tok->key = NULL; /* Prevent free */ if (!(tok = find_first_by_keyword(tokens, K_SIGNING_KEY))) { - warn(LD_DIR, "Missing identity key"); goto err; + log_warn(LD_DIR, "Missing identity key"); goto err; } if (crypto_pk_keysize(tok->key) != PK_BYTES) { - warn(LD_DIR, "Wrong size on identity key: %d bits!", + log_warn(LD_DIR, "Wrong size on identity key: %d bits!", (int)crypto_pk_keysize(tok->key)*8); goto err; } @@ -836,24 +838,24 @@ router_parse_entry_from_string(const char *s, const char *end) tok->key = NULL; /* Prevent free */ if (crypto_pk_get_digest(router->identity_pkey, router->cache_info.identity_digest)) { - warn(LD_DIR, "Couldn't calculate key digest"); goto err; + log_warn(LD_DIR, "Couldn't calculate key digest"); goto err; } if ((tok = find_first_by_keyword(tokens, K_FINGERPRINT))) { /* If there's a fingerprint line, it must match the identity digest. */ char d[DIGEST_LEN]; if (tok->n_args < 1) { - warn(LD_DIR, "Too few arguments to fingerprint"); + log_warn(LD_DIR, "Too few arguments to fingerprint"); goto err; } tor_strstrip(tok->args[0], " "); if (base16_decode(d, DIGEST_LEN, tok->args[0], strlen(tok->args[0]))) { - warn(LD_DIR, "Couldn't decode fingerprint '%s'", tok->args[0]); + log_warn(LD_DIR, "Couldn't decode fingerprint '%s'", tok->args[0]); goto err; } if (memcmp(d,router->cache_info.identity_digest, DIGEST_LEN)!=0) { - warn(LD_DIR, "Fingerprint '%s' does not match identity digest.", - tok->args[0]); + log_warn(LD_DIR, "Fingerprint '%s' does not match identity digest.", + tok->args[0]); goto err; } } @@ -869,7 +871,7 @@ router_parse_entry_from_string(const char *s, const char *end) exit_policy_tokens = find_all_exitpolicy(tokens); SMARTLIST_FOREACH(exit_policy_tokens, directory_token_t *, t, if (router_add_exit_policy(router,t)<0) { - warn(LD_DIR,"Error in exit policy"); + log_warn(LD_DIR,"Error in exit policy"); goto err; }); @@ -878,7 +880,7 @@ router_parse_entry_from_string(const char *s, const char *end) router->declared_family = smartlist_create(); for (i=0;in_args;++i) { if (!is_legal_nickname_or_hexdigest(tok->args[i])) { - warn(LD_DIR, "Illegal nickname '%s' in family line", tok->args[i]); + log_warn(LD_DIR, "Illegal nickname '%s' in family line", tok->args[i]); goto err; } smartlist_add(router->declared_family, tor_strdup(tok->args[i])); @@ -886,29 +888,29 @@ router_parse_entry_from_string(const char *s, const char *end) } if (!(tok = find_first_by_keyword(tokens, K_ROUTER_SIGNATURE))) { - warn(LD_DIR, "Missing router signature"); + log_warn(LD_DIR, "Missing router signature"); goto err; } if (strcmp(tok->object_type, "SIGNATURE") || tok->object_size != 128) { - warn(LD_DIR, "Bad object type or length on router signature"); + log_warn(LD_DIR, "Bad object type or length on router signature"); goto err; } if ((t=crypto_pk_public_checksig(router->identity_pkey, signed_digest, tok->object_body, 128)) != 20) { - warn(LD_DIR, "Invalid signature %d",t); + log_warn(LD_DIR, "Invalid signature %d",t); goto err; } if (memcmp(digest, signed_digest, DIGEST_LEN)) { - warn(LD_DIR, "Mismatched signature"); + log_warn(LD_DIR, "Mismatched signature"); goto err; } if (!router->or_port) { - warn(LD_DIR,"or_port unreadable or 0. Failing."); + log_warn(LD_DIR,"or_port unreadable or 0. Failing."); goto err; } if (!router->bandwidthrate) { - warn(LD_DIR,"bandwidthrate unreadable or 0. Failing."); + log_warn(LD_DIR,"bandwidthrate unreadable or 0. Failing."); goto err; } if (!router->platform) { @@ -965,54 +967,56 @@ routerstatus_parse_entry_from_string(const char **s, smartlist_t *tokens) eos = find_start_of_next_routerstatus(*s); if (tokenize_string(*s, eos, tokens, RTRSTATUS)) { - warn(LD_DIR, "Error tokenizing router status"); + log_warn(LD_DIR, "Error tokenizing router status"); goto err; } if (smartlist_len(tokens) < 1) { - warn(LD_DIR, "Impossibly short router status"); + log_warn(LD_DIR, "Impossibly short router status"); goto err; } if ((tok = find_first_by_keyword(tokens, _UNRECOGNIZED))) { - warn(LD_DIR, "Unrecognized keyword \"%s\" in router status; skipping.", - tok->args[0]); + log_warn(LD_DIR, "Unrecognized keyword \"%s\" in router status; skipping.", + tok->args[0]); goto err; } if (!(tok = find_first_by_keyword(tokens, K_R))) { - warn(LD_DIR, "Missing 'r' keywork in router status; skipping."); + log_warn(LD_DIR, "Missing 'r' keywork in router status; skipping."); goto err; } if (tok->n_args < 8) { - warn(LD_DIR, + log_warn(LD_DIR, "Too few arguments to 'r' keywork in router status; skipping."); } rs = tor_malloc_zero(sizeof(routerstatus_t)); if (!is_legal_nickname(tok->args[0])) { - warn(LD_DIR, - "Invalid nickname '%s' in router status; skipping.", tok->args[0]); + log_warn(LD_DIR, + "Invalid nickname '%s' in router status; skipping.", + tok->args[0]); goto err; } strlcpy(rs->nickname, tok->args[0], sizeof(rs->nickname)); if (digest_from_base64(rs->identity_digest, tok->args[1])) { - warn(LD_DIR, "Error decoding digest '%s'", tok->args[1]); + log_warn(LD_DIR, "Error decoding digest '%s'", tok->args[1]); goto err; } if (digest_from_base64(rs->descriptor_digest, tok->args[2])) { - warn(LD_DIR, "Error decoding digest '%s'", tok->args[2]); + log_warn(LD_DIR, "Error decoding digest '%s'", tok->args[2]); goto err; } if (tor_snprintf(timebuf, sizeof(timebuf), "%s %s", tok->args[3], tok->args[4]) < 0 || parse_iso_time(timebuf, &rs->published_on)<0) { - warn(LD_DIR, "Error parsing time '%s %s'", tok->args[3], tok->args[4]); + log_warn(LD_DIR, "Error parsing time '%s %s'", + tok->args[3], tok->args[4]); goto err; } if (tor_inet_aton(tok->args[5], &in) == 0) { - warn(LD_DIR, "Error parsing address '%s'", tok->args[5]); + log_warn(LD_DIR, "Error parsing address '%s'", tok->args[5]); goto err; } rs->addr = ntohl(in.s_addr); @@ -1081,60 +1085,60 @@ networkstatus_parse_from_string(const char *s) int i; if (router_get_networkstatus_v2_hash(s, ns_digest)) { - warn(LD_DIR, "Unable to compute digest of network-status"); + log_warn(LD_DIR, "Unable to compute digest of network-status"); goto err; } eos = find_start_of_next_routerstatus(s); if (tokenize_string(s, eos, tokens, NETSTATUS)) { - warn(LD_DIR, "Error tokenizing network-status header."); + log_warn(LD_DIR, "Error tokenizing network-status header."); goto err; } if ((tok = find_first_by_keyword(tokens, _UNRECOGNIZED))) { - warn(LD_DIR, "Unrecognized keyword '%s'; can't parse network-status", - tok->args[0]); + log_warn(LD_DIR, "Unrecognized keyword '%s'; can't parse network-status", + tok->args[0]); goto err; } ns = tor_malloc_zero(sizeof(networkstatus_t)); memcpy(ns->networkstatus_digest, ns_digest, DIGEST_LEN); if (!(tok = find_first_by_keyword(tokens, K_NETWORK_STATUS_VERSION))) { - warn(LD_DIR, "Couldn't find network-status-version keyword"); + log_warn(LD_DIR, "Couldn't find network-status-version keyword"); goto err; } if (!(tok = find_first_by_keyword(tokens, K_DIR_SOURCE))) { - warn(LD_DIR, "Couldn't find dir-source keyword"); + log_warn(LD_DIR, "Couldn't find dir-source keyword"); goto err; } if (tok->n_args < 3) { - warn(LD_DIR, "Too few arguments to dir-source keyword"); + log_warn(LD_DIR, "Too few arguments to dir-source keyword"); goto err; } ns->source_address = tok->args[0]; tok->args[0] = NULL; if (tor_inet_aton(tok->args[1], &in) == 0) { - warn(LD_DIR, "Error parsing address '%s'", tok->args[1]); + log_warn(LD_DIR, "Error parsing address '%s'", tok->args[1]); goto err; } ns->source_addr = ntohl(in.s_addr); ns->source_dirport = (uint16_t) tor_parse_long(tok->args[2],10,0,65535,NULL,NULL); if (ns->source_dirport == 0) { - warn(LD_DIR, "Directory source without dirport; skipping."); + log_warn(LD_DIR, "Directory source without dirport; skipping."); goto err; } if (!(tok = find_first_by_keyword(tokens, K_FINGERPRINT))) { - warn(LD_DIR, "Couldn't find fingerprint keyword"); + log_warn(LD_DIR, "Couldn't find fingerprint keyword"); goto err; } if (tok->n_args < 1) { - warn(LD_DIR, "Too few arguments to fingerprint"); + log_warn(LD_DIR, "Too few arguments to fingerprint"); goto err; } if (base16_decode(ns->identity_digest, DIGEST_LEN, tok->args[0], strlen(tok->args[0]))) { - warn(LD_DIR, "Couldn't decode fingerprint '%s'", tok->args[0]); + log_warn(LD_DIR, "Couldn't decode fingerprint '%s'", tok->args[0]); goto err; } @@ -1144,18 +1148,19 @@ networkstatus_parse_from_string(const char *s) } if (!(tok = find_first_by_keyword(tokens, K_DIR_SIGNING_KEY)) || !tok->key) { - warn(LD_DIR, "Missing dir-signing-key"); + log_warn(LD_DIR, "Missing dir-signing-key"); goto err; } ns->signing_key = tok->key; tok->key = NULL; if (crypto_pk_get_digest(ns->signing_key, tmp_digest)<0) { - warn(LD_DIR, "Couldn't compute signing key digest"); + log_warn(LD_DIR, "Couldn't compute signing key digest"); goto err; } if (memcmp(tmp_digest, ns->identity_digest, DIGEST_LEN)) { - warn(LD_DIR, "network-status fingerprint did not match dir-signing-key"); + log_warn(LD_DIR, + "network-status fingerprint did not match dir-signing-key"); goto err; } @@ -1171,14 +1176,14 @@ networkstatus_parse_from_string(const char *s) if (ns->recommends_versions) { if (!(tok = find_first_by_keyword(tokens, K_CLIENT_VERSIONS)) || tok->n_args<1) { - warn(LD_DIR, "Missing client-versions"); + log_warn(LD_DIR, "Missing client-versions"); } ns->client_versions = tok->args[0]; tok->args[0] = NULL; if (!(tok = find_first_by_keyword(tokens, K_SERVER_VERSIONS)) || tok->n_args<1) { - warn(LD_DIR, "Missing server-versions on versioning directory"); + log_warn(LD_DIR, "Missing server-versions on versioning directory"); goto err; } ns->server_versions = tok->args[0]; @@ -1186,7 +1191,7 @@ networkstatus_parse_from_string(const char *s) } if (!(tok = find_first_by_keyword(tokens, K_PUBLISHED))) { - warn(LD_DIR, "Missing published time on directory."); + log_warn(LD_DIR, "Missing published time on directory."); goto err; } tor_assert(tok->n_args == 1); @@ -1211,24 +1216,26 @@ networkstatus_parse_from_string(const char *s) routerstatus_t *rs2 = smartlist_get(ns->entries, i+1); if (!memcmp(rs1->identity_digest, rs2->identity_digest, DIGEST_LEN)) { - warn(LD_DIR, - "Network-status has two entries for the same router. Dropping one."); + log_warn(LD_DIR, + "Network-status has two entries for the same router. " + "Dropping one."); smartlist_del_keeporder(ns->entries, i--); routerstatus_free(rs1); } } if (tokenize_string(s, NULL, tokens, NETSTATUS)) { - warn(LD_DIR, "Error tokenizing network-status footer."); + log_warn(LD_DIR, "Error tokenizing network-status footer."); goto err; } if (smartlist_len(tokens) < 1) { - warn(LD_DIR, "Too few items in network-status footer."); + log_warn(LD_DIR, "Too few items in network-status footer."); goto err; } tok = smartlist_get(tokens, smartlist_len(tokens)-1); if (tok->tp != K_DIRECTORY_SIGNATURE) { - warn(LD_DIR, "Expected network-status footer to end with a signature."); + log_warn(LD_DIR, + "Expected network-status footer to end with a signature."); goto err; } @@ -1279,11 +1286,11 @@ router_parse_addr_policy_from_string(const char *s, int assume_action) } tok = get_next_token(&cp, RTR); if (tok->tp == _ERR) { - warn(LD_DIR, "Error reading exit policy: %s", tok->error); + log_warn(LD_DIR, "Error reading exit policy: %s", tok->error); goto err; } if (tok->tp != K_ACCEPT && tok->tp != K_REJECT) { - warn(LD_DIR, "Expected 'accept' or 'reject'."); + log_warn(LD_DIR, "Expected 'accept' or 'reject'."); goto err; } @@ -1357,7 +1364,7 @@ router_parse_addr_policy(directory_token_t *tok) policy_read_failed: tor_assert(newe->string); - warn(LD_DIR,"Couldn't parse line '%s'. Dropping", newe->string); + log_warn(LD_DIR,"Couldn't parse line '%s'. Dropping", newe->string); tor_free(newe->string); tor_free(newe); return NULL; @@ -1618,7 +1625,7 @@ tokenize_string(const char *start, const char *end, smartlist_t *out, while (*s < end && (!tok || tok->tp != _EOF)) { tok = get_next_token(s, where); if (tok->tp == _ERR) { - warn(LD_DIR, "parse error: %s", tok->error); + log_warn(LD_DIR, "parse error: %s", tok->error); return -1; } smartlist_add(out, tok); @@ -1666,28 +1673,29 @@ router_get_hash_impl(const char *s, char *digest, char *start, *end; start = strstr(s, start_str); if (!start) { - warn(LD_DIR,"couldn't find \"%s\"",start_str); + log_warn(LD_DIR,"couldn't find \"%s\"",start_str); return -1; } if (start != s && *(start-1) != '\n') { - warn(LD_DIR, "first occurrence of \"%s\" is not at the start of a line", - start_str); + log_warn(LD_DIR, + "first occurrence of \"%s\" is not at the start of a line", + start_str); return -1; } end = strstr(start+strlen(start_str), end_str); if (!end) { - warn(LD_DIR,"couldn't find \"%s\"",end_str); + log_warn(LD_DIR,"couldn't find \"%s\"",end_str); return -1; } end = strchr(end+strlen(end_str), '\n'); if (!end) { - warn(LD_DIR,"couldn't find EOL"); + log_warn(LD_DIR,"couldn't find EOL"); return -1; } ++end; if (crypto_digest(digest, start, end-start)) { - warn(LD_DIR,"couldn't compute digest"); + log_warn(LD_DIR,"couldn't compute digest"); return -1; } @@ -1706,7 +1714,7 @@ tor_version_as_new_as(const char *platform, const char *cutoff) char tmp[128]; if (tor_version_parse(cutoff, &cutoff_version)<0) { - warn(LD_DIR,"Bug: cutoff version '%s' unparseable.",cutoff); + log_warn(LD_DIR,"Bug: cutoff version '%s' unparseable.",cutoff); return 0; } if (strcmpstart(platform,"Tor ")) /* nonstandard Tor; be safe and say yes */ @@ -1720,7 +1728,7 @@ tor_version_as_new_as(const char *platform, const char *cutoff) strlcpy(tmp, start, s-start+1); if (tor_version_parse(tmp, &router_version)<0) { - info(LD_DIR,"Router version '%s' unparseable.",tmp); + log_info(LD_DIR,"Router version '%s' unparseable.",tmp); return 1; /* be safe and say yes */ } diff --git a/src/tools/tor-resolve.c b/src/tools/tor-resolve.c index 60daaaff0a..fbe787f689 100644 --- a/src/tools/tor-resolve.c +++ b/src/tools/tor-resolve.c @@ -82,20 +82,20 @@ parse_socks4a_resolve_response(const char *response, size_t len, tor_assert(addr_out); if (len < RESPONSE_LEN) { - warn(LD_PROTOCOL,"Truncated socks response."); + log_warn(LD_PROTOCOL,"Truncated socks response."); return -1; } if (((uint8_t)response[0])!=0) { /* version: 0 */ - warn(LD_PROTOCOL,"Nonzero version in socks response: bad format."); + log_warn(LD_PROTOCOL,"Nonzero version in socks response: bad format."); return -1; } status = (uint8_t)response[1]; if (get_uint16(response+2)!=0) { /* port: 0 */ - warn(LD_PROTOCOL,"Nonzero port in socks response: bad format."); + log_warn(LD_PROTOCOL,"Nonzero port in socks response: bad format."); return -1; } if (status != 90) { - warn(LD_NET,"Got status response '%d': socks request failed.", status); + log_warn(LD_NET,"Got status response '%d': socks request failed.", status); return -1; } @@ -136,7 +136,7 @@ do_resolve(const char *hostname, uint32_t sockshost, uint16_t socksport, } if ((len = build_socks4a_resolve_request(&req, "", hostname))<0) { - err(LD_BUG,"Error generating SOCKS request"); + log_err(LD_BUG,"Error generating SOCKS request"); return -1; } @@ -157,7 +157,7 @@ do_resolve(const char *hostname, uint32_t sockshost, uint16_t socksport, while (len < RESPONSE_LEN) { r = recv(s, response_buf+len, RESPONSE_LEN-len, 0); if (r==0) { - warn(LD_NET,"EOF while reading SOCKS response"); + log_warn(LD_NET,"EOF while reading SOCKS response"); return -1; } if (r<0) { @@ -212,7 +212,7 @@ main(int argc, char **argv) add_stream_log(LOG_WARN, LOG_ERR, "", stderr); } if (n_args == 1) { - debug(LD_CONFIG, "defaulting to localhost:9050"); + log_debug(LD_CONFIG, "defaulting to localhost:9050"); sockshost = 0x7f000001u; /* localhost */ socksport = 9050; /* 9050 */ } else if (n_args == 2) { @@ -221,7 +221,7 @@ main(int argc, char **argv) return 1; } if (socksport == 0) { - debug(LD_CONFIG, "defaulting to port 9050"); + log_debug(LD_CONFIG, "defaulting to port 9050"); socksport = 9050; } } else { @@ -236,7 +236,7 @@ main(int argc, char **argv) } if (network_init()<0) { - err(LD_NET,"Error initializing network; exiting."); + log_err(LD_NET,"Error initializing network; exiting."); return 1; }