Commit 95e5384a authored by Nick Mathewson's avatar Nick Mathewson 🎨
Browse files

Change many files to new log_fn format


svn:r333
parent 6965a469
......@@ -23,7 +23,7 @@ NICK . Handle half-open connections
- Figure out what causes connections to close, standardize
when we mark a connection vs when we tear it down
o Look at what ssl does to keep from mutating data streams
NICK . On the fly compression of each stream
X On the fly compression of each stream
o Clean up the event loop (optimize and sanitize)
ARMA o Remove that awful concept of 'roles'
ARMA . Exit policies
......@@ -45,6 +45,10 @@ SPEC!! D Non-clique topologies
o Distribute queries onto the farm, get answers
o Preemptively grow a new worker before he's needed
- Prune workers when too many are idle
- DNS cache
- Clear DNS cache over time
- Honor DNS TTL info
- Have strategy when all workers are busy
o Keep track of which connections are in dns_wait
o Need to cache positives/negatives on the tor side
o Keep track of which queries have been asked
......@@ -54,9 +58,9 @@ SPEC!! D Non-clique topologies
- Consider taking the master out of the loop?
. Directory servers
D Automated reputation management
NICK . Include key in source; sign directories
. Include key in source; sign directories
o Signed directory backend
- Document
o Document
ARMA - Integrate
- Add versions to code
NICK . Have directories list recommended-versions
......
......@@ -159,17 +159,17 @@ crypto_create_init_cipher(int cipher_type, char *key, char *iv, int encrypt_mode
crypto_cipher_env_t *crypto = NULL;
if (! (crypto = crypto_new_cipher_env(cipher_type))) {
log(LOG_ERR, "Unable to allocate crypto object");
log_fn(LOG_ERR, "Unable to allocate crypto object");
return NULL;
}
if (crypto_cipher_set_key(crypto, key)) {
log(LOG_ERR, "Unable to set key: %s", crypto_perror());
log_fn(LOG_ERR, "Unable to set key: %s", crypto_perror());
goto error;
}
if (crypto_cipher_set_iv(crypto, iv)) {
log(LOG_ERR, "Unable to set iv: %s", crypto_perror());
log_fn(LOG_ERR, "Unable to set iv: %s", crypto_perror());
goto error;
}
......@@ -179,7 +179,7 @@ crypto_create_init_cipher(int cipher_type, char *key, char *iv, int encrypt_mode
r = crypto_cipher_decrypt_init_cipher(crypto);
if (r) {
log(LOG_ERR, "Unabble to initialize cipher: %s", crypto_perror());
log_fn(LOG_ERR, "Unabble to initialize cipher: %s", crypto_perror());
goto error;
}
return crypto;
......@@ -310,7 +310,7 @@ int crypto_pk_read_private_key_from_filename(crypto_pk_env_t *env, unsigned char
fclose(f_pr);
if (retval == -1)
{
log(LOG_ERR,"Error reading private key : %s",crypto_perror());
log_fn(LOG_ERR,"Error reading private key : %s",crypto_perror());
return -1;
}
......@@ -318,12 +318,12 @@ int crypto_pk_read_private_key_from_filename(crypto_pk_env_t *env, unsigned char
retval = crypto_pk_check_key(env);
if (retval == 0)
{
log(LOG_ERR,"Private key read but is invalid : %s.", crypto_perror());
log_fn(LOG_ERR,"Private key read but is invalid : %s.", crypto_perror());
return -1;
}
else if (retval == -1)
{
log(LOG_ERR,"Private key read but validity checking failed : %s",crypto_perror());
log_fn(LOG_ERR,"Private key read but validity checking failed : %s",crypto_perror());
return -1;
}
else if (retval == 1)
......@@ -799,19 +799,19 @@ int crypto_seed_rng()
for (i = 0; filenames[i]; ++i) {
f = fopen(filenames[i], "rb");
if (!f) continue;
log(LOG_INFO, "Seeding RNG from %s", filenames[i]);
log_fn(LOG_INFO, "Seeding RNG from %s", filenames[i]);
buf[20]='\xff';
n = fread(buf, 1, 20, f);
fclose(f);
if (n != 20) {
log(LOG_INFO, "Error reading from entropy source");
log_fn(LOG_INFO, "Error reading from entropy source");
return -1;
}
RAND_seed(buf, 20);
return 0;
}
log(LOG_INFO, "Cannot seed RNG -- no entropy source found.");
log_fn(LOG_INFO, "Cannot seed RNG -- no entropy source found.");
return -1;
}
......
......@@ -13,7 +13,7 @@ void *tor_malloc(size_t size) {
result = malloc(size);
if(!result) {
log(LOG_ERR,"tor_malloc(): Out of memory. Dying.");
log_fn(LOG_ERR, "Out of memory. Dying.");
exit(1);
}
......@@ -24,7 +24,7 @@ void
my_gettimeofday(struct timeval *timeval)
{
if (gettimeofday(timeval, NULL)) {
log(LOG_ERR, "my_gettimeofday: gettimeofday failed.");
log_fn(LOG_ERR, "gettimeofday failed.");
/* If gettimeofday dies, we have either given a bad timezone (we didn't),
or segfaulted.*/
exit(1);
......@@ -40,7 +40,7 @@ tv_udiff(struct timeval *start, struct timeval *end)
long secdiff = end->tv_sec - start->tv_sec;
if (secdiff+1 > LONG_MAX/1000000) {
log(LOG_NOTICE, "tv_udiff(): comparing times too far apart.");
log_fn(LOG_NOTICE, "comparing times too far apart.");
return LONG_MAX;
}
......@@ -54,7 +54,7 @@ tv_udiff(struct timeval *start, struct timeval *end)
*/
udiff = secdiff*1000000L + (end_usec - start->tv_usec);
if(udiff < 0) {
log(LOG_NOTICE, "tv_udiff(): start is after end. Returning 0.");
log_fn(LOG_NOTICE, "start is after end. Returning 0.");
return 0;
}
return udiff;
......
......@@ -60,7 +60,7 @@ int read_to_buf(int s, int at_most, char **buf, int *buflen, int *buf_datalen, i
*/
}
// log(LOG_DEBUG,"read_to_buf(): reading at most %d bytes.",at_most);
// log_fn(LOG_DEBUG,"reading at most %d bytes.",at_most);
read_result = read(s, *buf+*buf_datalen, at_most);
if (read_result < 0) {
if(errno!=EAGAIN) { /* it's a real error */
......@@ -68,12 +68,12 @@ int read_to_buf(int s, int at_most, char **buf, int *buflen, int *buf_datalen, i
}
return 0;
} else if (read_result == 0) {
log(LOG_DEBUG,"read_to_buf(): Encountered eof");
log_fn(LOG_DEBUG,"Encountered eof");
*reached_eof = 1;
return 0;
} else { /* we read some bytes */
*buf_datalen += read_result;
// log(LOG_DEBUG,"read_to_buf(): Read %d bytes. %d on inbuf.",read_result, *buf_datalen);
// log_fn(LOG_DEBUG,"Read %d bytes. %d on inbuf.",read_result, *buf_datalen);
return read_result;
}
}
......@@ -98,13 +98,13 @@ int flush_buf(int s, char **buf, int *buflen, int *buf_flushlen, int *buf_datale
if(errno!=EAGAIN) { /* it's a real error */
return -1;
}
log(LOG_DEBUG,"flush_buf(): write() would block, returning.");
log_fn(LOG_DEBUG,"write() would block, returning.");
return 0;
} else {
*buf_datalen -= write_result;
*buf_flushlen -= write_result;
memmove(*buf, *buf+write_result, *buf_datalen);
// log(LOG_DEBUG,"flush_buf(): flushed %d bytes, %d ready to flush, %d remain.",
// log_fn(LOG_DEBUG,"flushed %d bytes, %d ready to flush, %d remain.",
// write_result,*buf_flushlen,*buf_datalen);
return *buf_flushlen;
}
......@@ -122,13 +122,13 @@ int write_to_buf(char *string, int string_len,
/* this is the point where you would grow the buffer, if you want to */
if (string_len + *buf_datalen > *buflen) { /* we're out of luck */
log(LOG_DEBUG, "write_to_buf(): buflen too small. Time to implement growing dynamic bufs.");
log_fn(LOG_DEBUG, "buflen too small. Time to implement growing dynamic bufs.");
return -1;
}
memcpy(*buf+*buf_datalen, string, string_len);
*buf_datalen += string_len;
// log(LOG_DEBUG,"write_to_buf(): added %d bytes to buf (now %d total).",string_len, *buf_datalen);
// log_fn(LOG_DEBUG,"added %d bytes to buf (now %d total).",string_len, *buf_datalen);
return *buf_datalen;
}
......
......@@ -119,7 +119,7 @@ aci_t get_unique_aci_by_addr_port(uint32_t addr, uint16_t port, int aci_type) {
connection_t *conn;
try_again:
log(LOG_DEBUG,"get_unique_aci_by_addr_port() trying to get a unique aci");
log_fn(LOG_DEBUG,"trying to get a unique aci");
if (CRYPTO_PSEUDO_RAND_INT(test_aci))
return -1;
......@@ -207,7 +207,7 @@ circuit_t *circuit_get_newest_ap(void) {
for(circ=global_circuitlist;circ;circ = circ->next) {
if(circ->cpath && circ->state == CIRCUIT_STATE_OPEN && (!bestcirc ||
bestcirc->timestamp_created < circ->timestamp_created)) {
log(LOG_DEBUG,"circuit_get_newest_ap(): Choosing n_aci %d.", circ->n_aci);
log_fn(LOG_DEBUG,"Choosing n_aci %d.", circ->n_aci);
assert(circ->n_aci);
bestcirc = circ;
}
......@@ -227,10 +227,10 @@ int circuit_deliver_relay_cell(cell_t *cell, circuit_t *circ,
buf[0] = cell->length;
memcpy(buf+1, cell->payload, CELL_PAYLOAD_SIZE);
log(LOG_DEBUG,"circuit_deliver_relay_cell(): direction %d, streamid %d before crypt.", cell_direction, *(int*)(cell->payload+1));
log_fn(LOG_DEBUG,"direction %d, streamid %d before crypt.", cell_direction, *(int*)(cell->payload+1));
if(relay_crypt(circ, buf, 1+CELL_PAYLOAD_SIZE, cell_direction, &layer_hint, &recognized, &conn) < 0) {
log(LOG_DEBUG,"circuit_deliver_relay_cell(): relay crypt failed. Dropping connection.");
log_fn(LOG_DEBUG,"relay crypt failed. Dropping connection.");
return -1;
}
......@@ -239,11 +239,11 @@ int circuit_deliver_relay_cell(cell_t *cell, circuit_t *circ,
if(recognized) {
if(cell_direction == CELL_DIRECTION_OUT) {
log(LOG_DEBUG,"circuit_deliver_relay_cell(): Sending to exit.");
log_fn(LOG_DEBUG,"Sending to exit.");
return connection_edge_process_relay_cell(cell, circ, conn, EDGE_EXIT, NULL);
}
if(cell_direction == CELL_DIRECTION_IN) {
log(LOG_DEBUG,"circuit_deliver_relay_cell(): Sending to AP.");
log_fn(LOG_DEBUG,"Sending to AP.");
return connection_edge_process_relay_cell(cell, circ, conn, EDGE_AP, layer_hint);
}
}
......@@ -255,11 +255,11 @@ int circuit_deliver_relay_cell(cell_t *cell, circuit_t *circ,
conn = circ->p_conn;
if(!conn) { //|| !connection_speaks_cells(conn)) {
log(LOG_INFO,"circuit_deliver_relay_cell(): Didn't recognize cell (%d), but circ stops here! Dropping.", *(int *)(cell->payload+1));
log_fn(LOG_INFO,"Didn't recognize cell (%d), but circ stops here! Dropping.", *(int *)(cell->payload+1));
return 0;
}
log(LOG_DEBUG,"circuit_deliver_relay_cell(): Passing on unrecognized cell.");
log_fn(LOG_DEBUG,"Passing on unrecognized cell.");
return connection_write_cell_to_buf(cell, conn);
}
......@@ -276,20 +276,20 @@ int relay_crypt(circuit_t *circ, char *in, int inlen, char cell_direction,
if(circ->cpath) { /* we're at the beginning of the circuit. We'll want to do layered crypts. */
thishop = circ->cpath;
if(thishop->state != CPATH_STATE_OPEN) {
log(LOG_INFO,"relay_crypt(): Relay cell before first created cell?");
log_fn(LOG_INFO,"Relay cell before first created cell?");
return -1;
}
do { /* Remember: cpath is in forward order, that is, first hop first. */
assert(thishop);
log(LOG_DEBUG,"relay_crypt(): before decrypt: %d",*(int*)(in+2));
log_fn(LOG_DEBUG,"before decrypt: %d",*(int*)(in+2));
/* decrypt */
if(crypto_cipher_decrypt(thishop->b_crypto, in, inlen, out)) {
log(LOG_ERR,"Error performing decryption:%s",crypto_perror());
log_fn(LOG_ERR,"Error performing decryption:%s",crypto_perror());
return -1;
}
memcpy(in,out,inlen);
log(LOG_DEBUG,"relay_crypt(): after decrypt: %d",*(int*)(in+2));
log_fn(LOG_DEBUG,"after decrypt: %d",*(int*)(in+2));
if( (*recognized = relay_check_recognized(circ, cell_direction, in+2, conn))) {
*layer_hint = thishop;
......@@ -298,20 +298,20 @@ int relay_crypt(circuit_t *circ, char *in, int inlen, char cell_direction,
thishop = thishop->next;
} while(thishop != circ->cpath && thishop->state == CPATH_STATE_OPEN);
log(LOG_INFO,"relay_crypt(): in-cell at OP not recognized. Dropping.");
log_fn(LOG_INFO,"in-cell at OP not recognized. Dropping.");
return 0;
} else { /* we're in the middle. Just one crypt. */
log(LOG_DEBUG,"relay_crypt(): before encrypt: %d",*(int*)(in+2));
log_fn(LOG_DEBUG,"before encrypt: %d",*(int*)(in+2));
if(crypto_cipher_encrypt(circ->p_crypto, in, inlen, out)) {
log(LOG_ERR,"circuit_encrypt(): Encryption failed for ACI : %u (%s).",
log_fn(LOG_ERR,"Encryption failed for ACI : %u (%s).",
circ->p_aci, crypto_perror());
return -1;
}
memcpy(in,out,inlen);
log(LOG_DEBUG,"relay_crypt(): after encrypt: %d",*(int*)(in+2));
log_fn(LOG_DEBUG,"after encrypt: %d",*(int*)(in+2));
log(LOG_DEBUG,"circuit_encrypt(): Skipping recognized check, because we're not the OP.");
log_fn(LOG_DEBUG,"Skipping recognized check, because we're not the OP.");
/* don't check for recognized. only the OP can recognize a stream on the way back. */
}
......@@ -323,21 +323,21 @@ int relay_crypt(circuit_t *circ, char *in, int inlen, char cell_direction,
do {
assert(thishop);
log(LOG_DEBUG,"relay_crypt(): before encrypt: %d",*(int*)(in+2));
log_fn(LOG_DEBUG,"before encrypt: %d",*(int*)(in+2));
if(crypto_cipher_encrypt(thishop->f_crypto, in, inlen, out)) {
log(LOG_ERR,"Error performing encryption:%s",crypto_perror());
log_fn(LOG_ERR,"Error performing encryption:%s",crypto_perror());
return -1;
}
memcpy(in,out,inlen);
log(LOG_DEBUG,"relay_crypt(): after encrypt: %d",*(int*)(in+2));
log_fn(LOG_DEBUG,"after encrypt: %d",*(int*)(in+2));
thishop = thishop->prev;
} while(thishop != circ->cpath->prev);
} else { /* we're in the middle. Just one crypt. */
if(crypto_cipher_decrypt(circ->n_crypto,in, inlen, out)) {
log(LOG_ERR,"circuit_crypt(): Decryption failed for ACI : %u (%s).",
circ->n_aci, crypto_perror());
log_fn(LOG_ERR,"Decryption failed for ACI : %u (%s).",
circ->n_aci, crypto_perror());
return -1;
}
memcpy(in,out,inlen);
......@@ -347,7 +347,7 @@ int relay_crypt(circuit_t *circ, char *in, int inlen, char cell_direction,
}
} else {
log(LOG_ERR,"circuit_crypt(): unknown cell direction %d.", cell_direction);
log_fn(LOG_ERR,"unknown cell direction %d.", cell_direction);
assert(0);
}
......@@ -359,10 +359,10 @@ int relay_check_recognized(circuit_t *circ, int cell_direction, char *stream, co
connection_t *tmpconn;
if(!memcmp(stream,ZERO_STREAM,STREAM_ID_SIZE)) {
log(LOG_DEBUG,"relay_check_recognized(): It's the zero stream. Recognized.");
log_fn(LOG_DEBUG,"It's the zero stream. Recognized.");
return 1; /* the zero stream is always recognized */
}
log(LOG_DEBUG,"relay_check_recognized(): not the zero stream.");
log_fn(LOG_DEBUG,"not the zero stream.");
if(cell_direction == CELL_DIRECTION_OUT)
tmpconn = circ->n_streams;
......@@ -370,20 +370,20 @@ int relay_check_recognized(circuit_t *circ, int cell_direction, char *stream, co
tmpconn = circ->p_streams;
if(!tmpconn) {
log(LOG_DEBUG,"relay_check_recognized(): No conns. Not recognized.");
log_fn(LOG_DEBUG,"No conns. Not recognized.");
return 0;
}
for( ; tmpconn; tmpconn=tmpconn->next_stream) {
if(!memcmp(stream,tmpconn->stream_id, STREAM_ID_SIZE)) {
log(LOG_DEBUG,"relay_check_recognized(): recognized stream %d.", *(int*)stream);
log_fn(LOG_DEBUG,"recognized stream %d.", *(int*)stream);
*conn = tmpconn;
return 1;
}
log(LOG_DEBUG,"relay_check_recognized(): considered stream %d, not it.",*(int*)tmpconn->stream_id);
log_fn(LOG_DEBUG,"considered stream %d, not it.",*(int*)tmpconn->stream_id);
}
log(LOG_DEBUG,"relay_check_recognized(): Didn't recognize. Giving up.");
log_fn(LOG_DEBUG,"Didn't recognize. Giving up.");
return 0;
}
......@@ -393,7 +393,7 @@ void circuit_resume_edge_reading(circuit_t *circ, int edge_type, crypt_path_t *l
assert(edge_type == EDGE_EXIT || edge_type == EDGE_AP);
log(LOG_DEBUG,"circuit_resume_edge_reading(): resuming");
log_fn(LOG_DEBUG,"resuming");
if(edge_type == EDGE_EXIT)
conn = circ->n_streams;
......@@ -417,7 +417,7 @@ int circuit_consider_stop_edge_reading(circuit_t *circ, int edge_type, crypt_pat
assert(edge_type == EDGE_EXIT || edge_type == EDGE_AP);
assert(edge_type == EDGE_EXIT || layer_hint);
log(LOG_DEBUG,"circuit_consider_stop_edge_reading(): considering");
log_fn(LOG_DEBUG,"considering");
if(edge_type == EDGE_EXIT && circ->package_window <= 0)
conn = circ->n_streams;
else if(edge_type == EDGE_AP && layer_hint->package_window <= 0)
......@@ -429,7 +429,7 @@ int circuit_consider_stop_edge_reading(circuit_t *circ, int edge_type, crypt_pat
if(!layer_hint || conn->cpath_layer == layer_hint)
connection_stop_reading(conn);
log(LOG_DEBUG,"circuit_consider_stop_edge_reading(): yes. stopped.");
log_fn(LOG_DEBUG,"yes. stopped.");
return 1;
}
......@@ -447,7 +447,7 @@ int circuit_consider_sending_sendme(circuit_t *circ, int edge_type, crypt_path_t
if(edge_type == EDGE_AP) { /* i'm the AP */
cell.aci = circ->n_aci;
while(layer_hint->deliver_window < CIRCWINDOW_START-CIRCWINDOW_INCREMENT) {
log(LOG_DEBUG,"circuit_consider_sending_sendme(): deliver_window %d, Queueing sendme forward.", layer_hint->deliver_window);
log_fn(LOG_DEBUG,"deliver_window %d, Queueing sendme forward.", layer_hint->deliver_window);
layer_hint->deliver_window += CIRCWINDOW_INCREMENT;
if(circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION_OUT, layer_hint) < 0) {
return -1;
......@@ -456,7 +456,7 @@ int circuit_consider_sending_sendme(circuit_t *circ, int edge_type, crypt_path_t
} else if(edge_type == EDGE_EXIT) { /* i'm the exit */
cell.aci = circ->p_aci;
while(circ->deliver_window < CIRCWINDOW_START-CIRCWINDOW_INCREMENT) {
log(LOG_DEBUG,"circuit_consider_sending_sendme(): deliver_window %d, Queueing sendme back.", circ->deliver_window);
log_fn(LOG_DEBUG,"deliver_window %d, Queueing sendme back.", circ->deliver_window);
circ->deliver_window += CIRCWINDOW_INCREMENT;
if(circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION_IN, layer_hint) < 0) {
return -1;
......@@ -473,7 +473,7 @@ void circuit_close(circuit_t *circ) {
assert(circ);
if(options.APPort) {
youngest = circuit_get_newest_ap();
log(LOG_DEBUG,"circuit_close(): youngest %d, circ %d.",youngest,circ);
log_fn(LOG_DEBUG,"youngest %d, circ %d.",youngest, (int)circ);
}
circuit_remove(circ);
if(circ->n_conn)
......@@ -488,7 +488,7 @@ void circuit_close(circuit_t *circ) {
}
if(options.APPort && youngest == circ) { /* check this after we've sent the destroys, to reduce races */
/* our current circuit just died. Launch another one pronto. */
log(LOG_INFO,"circuit_close(): Youngest circuit dying. Launching a replacement.");
log_fn(LOG_INFO,"Youngest circuit dying. Launching a replacement.");
circuit_launch_new(1);
}
circuit_free(circ);
......@@ -530,11 +530,11 @@ void circuit_about_to_close_connection(connection_t *conn) {
prevconn->next_stream = conn->next_stream;
goto send_end;
}
log(LOG_ERR,"circuit_about_to_close_connection(): edge conn not in circuit's list?");
log_fn(LOG_ERR,"edge conn not in circuit's list?");
assert(0); /* should never get here */
send_end:
if(connection_edge_send_command(conn, circ, RELAY_COMMAND_END) < 0) {
log(LOG_DEBUG,"circuit_about_to_close_connection(): sending end failed. Closing.");
log_fn(LOG_DEBUG,"sending end failed. Closing.");
circuit_close(circ);
}
return;
......@@ -588,7 +588,7 @@ void circuit_expire_unused_circuits(void) {
tmpcirc = circ;
circ = circ->next;
if(tmpcirc != youngest && !tmpcirc->p_conn && !tmpcirc->p_streams) {
log(LOG_DEBUG,"circuit_expire_unused_circuits(): Closing n_aci %d",tmpcirc->n_aci);
log_fn(LOG_DEBUG,"Closing n_aci %d",tmpcirc->n_aci);
circuit_close(tmpcirc);
}
}
......@@ -614,7 +614,7 @@ void circuit_launch_new(int failure_status) {
retry_circuit:
if(failures > 5) {
log(LOG_INFO,"circuit_launch_new(): Giving up, %d failures.", failures);
log_fn(LOG_INFO,"Giving up, %d failures.", failures);
return;
}
......@@ -636,21 +636,21 @@ int circuit_establish_circuit(void) {
circ->state = CIRCUIT_STATE_OR_WAIT;
circ->cpath = onion_generate_cpath(&firsthop);
if(!circ->cpath) {
log(LOG_DEBUG,"circuit_establish_circuit(): Generating cpath failed.");
log_fn(LOG_DEBUG,"Generating cpath failed.");
circuit_close(circ);
return -1;
}
/* now see if we're already connected to the first OR in 'route' */
log(LOG_DEBUG,"circuit_establish_circuit(): Looking for firsthop '%s:%u'",
log_fn(LOG_DEBUG,"Looking for firsthop '%s:%u'",
firsthop->address,firsthop->or_port);
n_conn = connection_twin_get_by_addr_port(firsthop->addr,firsthop->or_port);
if(!n_conn || n_conn->state != OR_CONN_STATE_OPEN) { /* not currently connected */
circ->n_addr = firsthop->addr;
circ->n_port = firsthop->or_port;
if(options.OnionRouter) { /* we would be connected if he were up. but he's not. */
log(LOG_DEBUG,"circuit_establish_circuit(): Route's firsthop isn't connected.");
log_fn(LOG_DEBUG,"Route's firsthop isn't connected.");
circuit_close(circ);
return -1;
}
......@@ -658,13 +658,13 @@ int circuit_establish_circuit(void) {
if(!n_conn) { /* launch the connection */
n_conn = connection_or_connect(firsthop);
if(!n_conn) { /* connect failed, forget the whole thing */
log(LOG_DEBUG,"circuit_establish_circuit(): connect to firsthop failed. Closing.");
log_fn(LOG_DEBUG,"connect to firsthop failed. Closing.");
circuit_close(circ);
return -1;
}
}
log(LOG_DEBUG,"circuit_establish_circuit(): connecting in progress (or finished). Good.");
log_fn(LOG_DEBUG,"connecting in progress (or finished). Good.");
return 0; /* return success. The onion/circuit/etc will be taken care of automatically
* (may already have been) whenever n_conn reaches OR_CONN_STATE_OPEN.
*/
......@@ -672,9 +672,9 @@ int circuit_establish_circuit(void) {
circ->n_addr = n_conn->addr;
circ->n_port = n_conn->port;
circ->n_conn = n_conn;
log(LOG_DEBUG,"circuit_establish_circuit(): Conn open. Delivering first onion skin.");
log_fn(LOG_DEBUG,"Conn open. Delivering first onion skin.");
if(circuit_send_next_onion_skin(circ) < 0) {
log(LOG_DEBUG,"circuit_establish_circuit(): circuit_send_next_onion_skin failed.");
log_fn(LOG_DEBUG,"circuit_send_next_onion_skin failed.");
circuit_close(circ);
return -1;
}
......@@ -686,16 +686,16 @@ int circuit_establish_circuit(void) {
void circuit_n_conn_open(connection_t *or_conn) {
circuit_t *circ;
log(LOG_DEBUG,"circuit_n_conn_open(): Starting.");
log_fn(LOG_DEBUG,"Starting.");
circ = circuit_enumerate_by_naddr_nport(NULL, or_conn->addr, or_conn->port);
for(;;) {
if(!circ)
return;
log(LOG_DEBUG,"circuit_n_conn_open(): Found circ, sending onion skin.");
log_fn(LOG_DEBUG,"Found circ, sending onion skin.");
circ->n_conn = or_conn;
if(circuit_send_next_onion_skin(circ) < 0) {
log(LOG_DEBUG,"circuit_n_conn_open(): circuit marked for closing.");
log_fn(LOG_DEBUG,"circuit marked for closing.");
circuit_close(circ);
return; /* FIXME will want to try the other circuits too? */
}
......@@ -712,7 +712,7 @@ int circuit_send_next_onion_skin(circuit_t *circ) {
if(circ->cpath->state == CPATH_STATE_CLOSED) {
log(LOG_DEBUG,"circuit_send_next_onion_skin(): First skin; sending create cell.");
log_fn(LOG_DEBUG,"First skin; sending create cell.");
circ->n_aci = get_unique_aci_by_addr_port(circ->n_addr, circ->n_port, ACI_TYPE_BOTH);
memset(&cell, 0, sizeof(cell_t));
......@@ -721,7 +721,7 @@ int circuit_send_next_onion_skin(circuit_t *circ) {
cell.length = DH_ONIONSKIN_LEN;
if(onion_skin_create(circ->n_conn->pkey, &(circ->cpath->handshake_state), cell.payload) < 0) {
log(LOG_INFO,"circuit_send_next_onion_skin(): onion_skin_create (first hop) failed.");
log_fn(LOG_INFO,"onion_skin_create (first hop) failed.");
return -1;
}
......@@ -731,23 +731,23 @@ int circuit_send_next_onion_skin(circuit_t *circ) {
circ->cpath->state = CPATH_STATE_AWAITING_KEYS;
circ->state = CIRCUIT_STATE_BUILDING;
log(LOG_DEBUG,"circuit_send_next_onion_skin(): first skin; finished sending create cell.");
log_fn(LOG_DEBUG,"first skin; finished sending create cell.");
} else {
assert(circ->cpath->state == CPATH_STATE_OPEN);
assert(circ->state == CIRCUIT_STATE_BUILDING);
log(LOG_DEBUG,"circuit_send_next_onion_skin(): starting to send subsequent skin.");
log_fn(LOG_DEBUG,"starting to send subsequent skin.");
for(hop=circ->cpath->next;
hop != circ->cpath && hop->state == CPATH_STATE_OPEN;
hop=hop->next) ;
if(hop == circ->cpath) { /* done building the circuit. whew. */
circ->state = CIRCUIT_STATE_OPEN;
log(LOG_DEBUG,"circuit_send_next_onion_skin(): circuit built!");
log_fn(LOG_DEBUG,"circuit built!");
return 0;
}
router = router_get_by_addr_port(hop->addr,hop->port);
if(!router) {
log(LOG_INFO,"circuit_send_next_onion_skin(): couldn't lookup router %d:%d",hop->addr,hop->port);
log_fn(LOG_INFO,"couldn't lookup router %d:%d",hop->addr,hop->port);
return -1;
}
......@@ -761,14 +761,14 @@ int circuit_send_next_onion_skin(circuit_t *circ) {
*(uint32_t*)(cell.payload+RELAY_HEADER_SIZE) = htonl(hop->addr);
*(uint32_t*)(cell.payload+RELAY_HEADER_SIZE+4) = htons(hop->port);
if(onion_skin_create(router->pkey, &(hop->handshake_state), cell.payload+RELAY_HEADER_SIZE+6) < 0) {
log(LOG_INFO,"circuit_send_next_onion_skin(): onion_skin_create failed.");
log_fn(LOG_INFO,"onion_skin_create failed.");
return -1;
}
log(LOG_DEBUG,"circuit_send_next_onion_skin(): Sending extend relay cell.");
log_fn(LOG_DEBUG,"Sending extend relay cell.");
/* send it to hop->prev, because it will transfer it to a create cell and then send to hop */
if(circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION_OUT, hop->prev) < 0) {
log(LOG_DEBUG,"circuit_send_next_onion_skin(): failed to deliver extend cell. Closing.");
log_fn(LOG_DEBUG,"failed to deliver extend cell. Closing.");
return -1;
}
hop->state = CPATH_STATE_AWAITING_KEYS;
......@@ -786,7 +786,7 @@ int circuit_extend(cell_t *cell, circuit_t *circ) {
cell_t newcell;
if(circ->n_conn) {
log(LOG_WARNING,"circuit_extend(): n_conn already set. Bug/attack. Closing.");
log_fn(LOG_WARNING,"n_conn already set. Bug/attack. Closing.");
return -1;
}
......@@ -804,7 +804,7 @@ int circuit_extend(cell_t *cell, circuit_t *circ) {
/* note also that this will close circuits where the onion has the same
* router twice in a row in the path. i think that's ok. -RD
*/
log(LOG_DEBUG,"circuit_extend(): Next router not connected. Closing.");
log_fn(LOG_DEBUG,"Next router not connected. Closing.");
/* XXX later we should fail more gracefully here, like with a 'truncated' */
return -1;
}
......@@ -813,18 +813,18 @@ int circuit_extend(cell_t *cell, circuit_t *circ) {
circ->n_port = n_conn->port;
circ->n_conn = n_conn;
log(LOG_DEBUG,"circuit_extend(): n_conn is %s:%u",n_conn->address,n_conn->port);
log_fn(LOG_DEBUG,"n_conn is %s:%u",n_conn->address,n_conn->port);