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

the last of the log convention conversion. finally.

Browse Source 
svn:r6005
This commit is contained in:
Roger Dingledine 2006-02-13 10:33:00 +00:00
parent aa63a84fe1
commit 259c65ab08
10 changed files with 741 additions and 671 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

232
src/or/relay.c
View File

@ -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 */
}
}

107
src/or/rendclient.c
View File

@ -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];

35
src/or/rendcommon.c
View File

@ -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;
}

104
src/or/rendmid.c
View File

@ -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;

219
src/or/rendservice.c
View File

@ -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;
}

4
src/or/rephist.c
View File

@ -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);

122
src/or/router.c
View File

@ -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:"<unknown error>");
log_err(LD_GENERAL,"Unable to add own descriptor to directory: %s",
m?m:"<unknown error>");
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);

327
src/or/routerlist.c
View File

@ -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);

244
src/or/routerparse.c
View File

@ -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;i<tok->n_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 */
}

18
src/tools/tor-resolve.c
View File

@ -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>", 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;
}