diff options
| -rw-r--r-- | doc/TODO | 10 | ||||
| -rw-r--r-- | src/common/crypto.c | 20 | ||||
| -rw-r--r-- | src/common/util.c | 8 | ||||
| -rw-r--r-- | src/or/buffers.c | 14 | ||||
| -rw-r--r-- | src/or/circuit.c | 144 | ||||
| -rw-r--r-- | src/or/command.c | 40 | ||||
| -rw-r--r-- | src/or/config.c | 4 | ||||
| -rw-r--r-- | src/or/connection.c | 47 | ||||
| -rw-r--r-- | src/or/connection_ap.c | 36 | ||||
| -rw-r--r-- | src/or/connection_edge.c | 70 | ||||
| -rw-r--r-- | src/or/connection_exit.c | 28 | ||||
| -rw-r--r-- | src/or/connection_or.c | 16 | ||||
| -rw-r--r-- | src/or/directory.c | 57 | ||||
| -rw-r--r-- | src/or/main.c | 2 | ||||
| -rw-r--r-- | src/or/routers.c | 3 |
15 files changed, 251 insertions, 248 deletions
@@ -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 diff --git a/src/common/crypto.c b/src/common/crypto.c index 8a9dd86c3..86851a14b 100644 --- a/src/common/crypto.c +++ b/src/common/crypto.c @@ -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; } diff --git a/src/common/util.c b/src/common/util.c index 191fa84cd..4160b1678 100644 --- a/src/common/util.c +++ b/src/common/util.c @@ -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; diff --git a/src/or/buffers.c b/src/or/buffers.c index 1bac63e26..b17940528 100644 --- a/src/or/buffers.c +++ b/src/or/buffers.c @@ -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; } diff --git a/src/or/circuit.c b/src/or/circuit.c index 13a5eaa6d..6b593f9c4 100644 --- a/src/or/circuit.c +++ b/src/or/circuit.c @@ -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); aci_type = decide_aci_type(ntohl(me.sin_addr.s_addr), ntohs(me.sin_port), circ->n_addr, circ->n_port); - log(LOG_DEBUG,"circuit_extend(): aci_type = %u.",aci_type); + log_fn(LOG_DEBUG,"aci_type = %u.",aci_type); circ->n_aci = get_unique_aci_by_addr_port(circ->n_addr, circ->n_port, aci_type); if(!circ->n_aci) { - log(LOG_ERR,"circuit_extend(): failed to get unique aci."); + log_fn(LOG_ERR,"failed to get unique aci."); return -1; } - log(LOG_DEBUG,"circuit_extend(): Chosen ACI %u.",circ->n_aci); + log_fn(LOG_DEBUG,"Chosen ACI %u.",circ->n_aci); memset(&newcell, 0, sizeof(cell_t)); newcell.command = CELL_CREATE; @@ -855,21 +855,21 @@ int circuit_finish_handshake(circuit_t *circ, char *reply) { hop != circ->cpath && hop->state == CPATH_STATE_OPEN; hop=hop->next) ; if(hop == circ->cpath) { /* got an extended when we're all done? */ - log(LOG_INFO,"circuit_finish_handshake(): got extended when circ already built? Weird."); + log_fn(LOG_INFO,"got extended when circ already built? Weird."); return 0; } } assert(hop->state == CPATH_STATE_AWAITING_KEYS); if(onion_skin_client_handshake(hop->handshake_state, reply, keys, 32) < 0) { - log(LOG_ERR,"circuit_finish_handshake(): onion_skin_client_handshake failed."); + log_fn(LOG_ERR,"onion_skin_client_handshake failed."); return -1; } crypto_dh_free(hop->handshake_state); /* don't need it anymore */ hop->handshake_state = NULL; - log(LOG_DEBUG,"circuit_finish_handshake(): hop %d init cipher forward %d, backward %d.", hop, *(int*)keys, *(int*)(keys+16)); + log_fn(LOG_DEBUG,"hop %d init cipher forward %d, backward %d.", (int)hop, *(int*)keys, *(int*)(keys+16)); if (!(hop->f_crypto = crypto_create_init_cipher(DEFAULT_CIPHER,keys,iv,1))) { log(LOG_ERR,"Cipher initialization failed."); @@ -883,7 +883,7 @@ int circuit_finish_handshake(circuit_t *circ, char *reply) { } hop->state = CPATH_STATE_OPEN; - log(LOG_DEBUG,"circuit_finish_handshake(): Completed."); + log_fn(LOG_DEBUG,"Completed."); return 0; } @@ -897,11 +897,11 @@ int circuit_truncated(circuit_t *circ, crypt_path_t *layer) { while(layer->next != circ->cpath) { /* we need to clear out layer->next */ victim = layer->next; - log(LOG_DEBUG, "circuit_truncated(): Killing a layer of the cpath."); + log_fn(LOG_DEBUG, "Killing a layer of the cpath."); for(stream = circ->p_streams; stream; stream=stream->next_stream) { if(stream->cpath_layer == victim) { - log(LOG_DEBUG, "circuit_truncated(): Marking stream %d for close.", *(int*)stream->stream_id); + log_fn(LOG_DEBUG, "Marking stream %d for close.", *(int*)stream->stream_id); stream->marked_for_close = 1; } } @@ -910,7 +910,7 @@ int circuit_truncated(circuit_t *circ, crypt_path_t *layer) { circuit_free_cpath_node(victim); } - log(LOG_DEBUG, "circuit_truncated(): Complete."); + log_fn(LOG_DEBUG, "Complete."); return 0; } diff --git a/src/or/command.c b/src/or/command.c index 54cfb11cb..ee14cce12 100644 --- a/src/or/command.c +++ b/src/or/command.c @@ -22,7 +22,7 @@ void command_time_process_cell(cell_t *cell, connection_t *conn, time_passed = tv_udiff(&start, &end) ; if (time_passed > 5000) { /* more than 5ms */ - log(LOG_INFO,"command_time_process_cell(): That call just took %d ms.",time_passed/1000); + log_fn(LOG_INFO,"That call just took %ld ms.",time_passed/1000); } *time += time_passed; } @@ -83,14 +83,14 @@ void command_process_create_cell(cell_t *cell, connection_t *conn) { circ = circuit_get_by_aci_conn(cell->aci, conn); if(circ) { - log(LOG_DEBUG,"command_process_create_cell(): received CREATE cell for known circ. Dropping."); + log_fn(LOG_DEBUG,"received CREATE cell for known circ. Dropping."); return; } circ = circuit_new(cell->aci, conn); circ->state = CIRCUIT_STATE_ONIONSKIN_PENDING; if(cell->length != DH_ONIONSKIN_LEN) { - log(LOG_DEBUG,"command_process_create_cell(): Bad cell length %d. Dropping.", cell->length); + log_fn(LOG_DEBUG,"Bad cell length %d. Dropping.", cell->length); circuit_close(circ); return; } @@ -99,10 +99,10 @@ void command_process_create_cell(cell_t *cell, connection_t *conn) { /* add it to the pending onions queue, and then return */ if(onion_pending_add(circ) < 0) { - log(LOG_DEBUG,"command_process_create_cell(): Failed to queue onionskin. Closing."); + log_fn(LOG_DEBUG,"Failed to queue onionskin. Closing."); circuit_close(circ); } - log(LOG_DEBUG,"command_process_create_cell(): success: queued onionskin."); + log_fn(LOG_DEBUG,"success: queued onionskin."); return; } @@ -113,26 +113,26 @@ void command_process_created_cell(cell_t *cell, connection_t *conn) { circ = circuit_get_by_aci_conn(cell->aci, conn); if(!circ) { - log(LOG_DEBUG,"command_process_created_cell(): received CREATED cell for unknown circ. Dropping."); + log_fn(LOG_DEBUG,"received CREATED cell for unknown circ. Dropping."); return; } if(circ->n_aci != cell->aci) { - log(LOG_DEBUG,"command_process_created_cell(): got created cell from OPward? Dropping."); + log_fn(LOG_DEBUG,"got created cell from OPward? Dropping."); return; } assert(cell->length == DH_KEY_LEN); if(circ->cpath) { /* we're the OP. Handshake this. */ - log(LOG_DEBUG,"command_process_created_cell(): at OP. Finishing handshake."); + log_fn(LOG_DEBUG,"at OP. Finishing handshake."); if(circuit_finish_handshake(circ, cell->payload) < 0) { - log(LOG_INFO,"command_process_created_cell(): circuit_finish_handshake failed."); + log_fn(LOG_INFO,"circuit_finish_handshake failed."); circuit_close(circ); return; } - log(LOG_DEBUG,"command_process_created_cell(): Moving to next skin."); + log_fn(LOG_DEBUG,"Moving to next skin."); if(circuit_send_next_onion_skin(circ) < 0) { - log(LOG_INFO,"command_process_created_cell(): circuit_send_next_onion_skin failed."); + log_fn(LOG_INFO,"circuit_send_next_onion_skin failed."); circuit_close(circ); return; } @@ -146,9 +146,9 @@ void command_process_created_cell(cell_t *cell, connection_t *conn) { newcell.length = RELAY_HEADER_SIZE + cell->length; memcpy(newcell.payload+RELAY_HEADER_SIZE, cell->payload, DH_KEY_LEN); - log(LOG_DEBUG,"command_process_created_cell(): Sending extended relay cell."); + log_fn(LOG_DEBUG,"Sending extended relay cell."); if(circuit_deliver_relay_cell(&newcell, circ, CELL_DIRECTION_IN, NULL) < 0) { - log(LOG_DEBUG,"command_process_created_cell(): failed to deliver extended cell. Closing."); + log_fn(LOG_DEBUG,"failed to deliver extended cell. Closing."); circuit_close(circ); return; } @@ -162,26 +162,26 @@ void command_process_relay_cell(cell_t *cell, connection_t *conn) { circ = circuit_get_by_aci_conn(cell->aci, conn); if(!circ) { - log(LOG_DEBUG,"command_process_relay_cell(): unknown circuit %d. Dropping.", cell->aci); + log_fn(LOG_DEBUG,"unknown circuit %d. Dropping.", cell->aci); return; } if(circ->state == CIRCUIT_STATE_ONIONSKIN_PENDING) { - log(LOG_DEBUG,"command_process_relay_cell(): circuit in create_wait. Dropping."); + log_fn(LOG_DEBUG,"circuit in create_wait. Dropping."); return; } if(cell->aci == circ->p_aci) { /* it's an outgoing cell */ cell->aci = circ->n_aci; /* switch it */ if(circuit_deliver_relay_cell(cell, circ, CELL_DIRECTION_OUT, conn->cpath_layer) < 0) { - log(LOG_INFO,"command_process_relay_cell(): circuit_deliver_relay_cell (forward) failed. Closing."); + log_fn(LOG_INFO,"circuit_deliver_relay_cell (forward) failed. Closing."); circuit_close(circ); return; } } else { /* it's an ingoing cell */ cell->aci = circ->p_aci; /* switch it */ if(circuit_deliver_relay_cell(cell, circ, CELL_DIRECTION_IN, NULL) < 0) { - log(LOG_DEBUG,"command_process_relay_cell(): circuit_deliver_relay_cell (backward) failed. Closing."); + log_fn(LOG_DEBUG,"circuit_deliver_relay_cell (backward) failed. Closing."); circuit_close(circ); return; } @@ -194,11 +194,11 @@ void command_process_destroy_cell(cell_t *cell, connection_t *conn) { circ = circuit_get_by_aci_conn(cell->aci, conn); if(!circ) { - log(LOG_DEBUG,"command_process_destroy_cell(): unknown circuit %d. Dropping.", cell->aci); + log_fn(LOG_DEBUG,"unknown circuit %d. Dropping.", cell->aci); return; } - log(LOG_DEBUG,"command_process_destroy_cell(): Received for aci %d.",cell->aci); + log_fn(LOG_DEBUG,"Received for aci %d.",cell->aci); if(circ->state == CIRCUIT_STATE_ONIONSKIN_PENDING) { onion_pending_remove(circ); } @@ -209,7 +209,7 @@ void command_process_destroy_cell(cell_t *cell, connection_t *conn) { circuit_close(circ); } else { /* the destroy came from ahead */ circ->n_conn = NULL; - log(LOG_DEBUG, "command_process_destroy_cell(): Delivering 'truncated' back."); + log_fn(LOG_DEBUG, "Delivering 'truncated' back."); connection_edge_send_command(NULL, circ, RELAY_COMMAND_TRUNCATED); } } diff --git a/src/or/config.c b/src/or/config.c index 8ef150b05..b5519c5f8 100644 --- a/src/or/config.c +++ b/src/or/config.c @@ -140,7 +140,7 @@ int config_compare(struct config_line *c, char *key, int type, void *arg) { return 0; /* it's a match. cast and assign. */ - log(LOG_DEBUG,"config_compare(): Recognized keyword '%s' as %s, using value '%s'.",c->key,key,c->value); + log_fn(LOG_DEBUG,"Recognized keyword '%s' as %s, using value '%s'.",c->key,key,c->value); switch(type) { case CONFIG_TYPE_INT: @@ -200,7 +200,7 @@ void config_assign(or_options_t *options, struct config_line *list) { ) { /* then we're ok. it matched something. */ } else { - log(LOG_WARNING,"config_assign(): Ignoring unknown keyword '%s'.",list->key); + log_fn(LOG_WARNING,"Ignoring unknown keyword '%s'.",list->key); } list = list->next; diff --git a/src/or/connection.c b/src/or/connection.c index bb7f5e8ec..db3751446 100644 --- a/src/or/connection.c +++ b/src/or/connection.c @@ -123,7 +123,7 @@ void connection_free(connection_t *conn) { crypto_free_pk_env(conn->pkey); if(conn->s > 0) { - log(LOG_INFO,"connection_free(): closing fd %d.",conn->s); + log_fn(LOG_INFO,"closing fd %d.",conn->s); close(conn->s); } if(conn->type == CONN_TYPE_OR) { @@ -140,7 +140,7 @@ int connection_create_listener(struct sockaddr_in *bindaddr, int type) { s = socket(PF_INET,SOCK_STREAM,IPPROTO_TCP); if (s < 0) { - log(LOG_ERR,"connection_create_listener(): Socket creation failed."); + log_fn(LOG_ERR,"Socket creation failed."); return -1; } @@ -161,18 +161,18 @@ int connection_create_listener(struct sockaddr_in *bindaddr, int type) { conn = connection_new(type); if(!conn) { - log(LOG_DEBUG,"connection_create_listener(): connection_new failed. Giving up."); + log_fn(LOG_DEBUG,"connection_new failed. Giving up."); return -1; } conn->s = s; if(connection_add(conn) < 0) { /* no space, forget it */ - log(LOG_DEBUG,"connection_create_listener(): connection_add failed. Giving up."); + log_fn(LOG_DEBUG,"connection_add failed. Giving up."); connection_free(conn); return -1; } - log(LOG_DEBUG,"connection_create_listener(): Listening on port %u.",ntohs(bindaddr->sin_port)); + log_fn(LOG_DEBUG,"Listening on port %u.",ntohs(bindaddr->sin_port)); conn->state = LISTENER_STATE_READY; connection_start_reading(conn); @@ -192,7 +192,7 @@ int connection_handle_listener_read(connection_t *conn, int new_type, int new_st if(errno==EAGAIN) return 0; /* he hung up before we could accept(). that's fine. */ /* else there was a real error. */ - log(LOG_ERR,"connection_handle_listener_read(): accept() failed. Closing."); + log_fn(LOG_ERR,"accept() failed. Closing."); return -1; } log(LOG_INFO,"Connection accepted on socket %d (child of fd %d).",news, conn->s); @@ -475,7 +475,7 @@ int connection_send_destroy(aci_t aci, connection_t *conn) { assert(conn); if(!connection_speaks_cells(conn)) { - log(LOG_INFO,"connection_send_destroy(): Aci %d: At an edge. Marking connection for close.", aci); + log_fn(LOG_INFO,"Aci %d: At an edge. Marking connection for close.", aci); conn->marked_for_close = 1; return 0; } @@ -483,7 +483,7 @@ int connection_send_destroy(aci_t aci, connection_t *conn) { memset(&cell, 0, sizeof(cell_t)); cell.aci = aci; cell.command = CELL_DESTROY; - log(LOG_INFO,"connection_send_destroy(): Sending destroy (aci %d).",aci); + log_fn(LOG_INFO,"Sending destroy (aci %d).",aci); return connection_write_cell_to_buf(&cell, conn); } @@ -548,7 +548,7 @@ int connection_process_inbuf(connection_t *conn) { case CONN_TYPE_DNSWORKER: return connection_dns_process_inbuf(conn); default: - log(LOG_DEBUG,"connection_process_inbuf() got unexpected conn->type."); + log_fn(LOG_DEBUG,"got unexpected conn->type."); return -1; } } @@ -584,11 +584,11 @@ repeat_connection_package_raw_inbuf: circ = circuit_get_by_conn(conn); if(!circ) { - log(LOG_DEBUG,"connection_package_raw_inbuf(): conn has no circuits!"); + log_fn(LOG_DEBUG,"conn has no circuits!"); return -1; } - log(LOG_DEBUG,"connection_package_raw_inbuf(): (%d) Packaging %d bytes (%d waiting).",conn->s,cell.length, conn->inbuf_datalen); + log_fn(LOG_DEBUG,"(%d) Packaging %d bytes (%d waiting).",conn->s,cell.length, conn->inbuf_datalen); cell.command = CELL_RELAY; @@ -599,7 +599,7 @@ repeat_connection_package_raw_inbuf: if(conn->type == CONN_TYPE_EXIT) { cell.aci = circ->p_aci; if(circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION_IN, NULL) < 0) { - log(LOG_DEBUG,"connection_package_raw_inbuf(): circuit_deliver_relay_cell (backward) failed. Closing."); + log_fn(LOG_DEBUG,"circuit_deliver_relay_cell (backward) failed. Closing."); circuit_close(circ); return 0; } @@ -609,7 +609,7 @@ repeat_connection_package_raw_inbuf: assert(conn->type == CONN_TYPE_AP); cell.aci = circ->n_aci; if(circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION_OUT, conn->cpath_layer) < 0) { - log(LOG_DEBUG,"connection_package_raw_inbuf(): circuit_deliver_relay_cell (forward) failed. Closing."); + log_fn(LOG_DEBUG,"circuit_deliver_relay_cell (forward) failed. Closing."); circuit_close(circ); return 0; } @@ -624,11 +624,10 @@ repeat_connection_package_raw_inbuf: assert(conn->package_window > 0); if(--conn->package_window <= 0) { /* is it 0 after decrement? */ connection_stop_reading(conn); - log(LOG_DEBUG,"connection_package_raw_inbuf(): conn->package_window reached 0."); + log_fn(LOG_DEBUG,"conn->package_window reached 0."); return 0; /* don't process the inbuf any more */ } - log(LOG_DEBUG,"connection_package_raw_inbuf(): conn->package_window is %d",conn->package_window); - + log_fn(LOG_DEBUG,"conn->package_window is %d",conn->package_window); /* handle more if there's more, or return 0 if there isn't */ goto repeat_connection_package_raw_inbuf; @@ -644,7 +643,7 @@ int connection_consider_sending_sendme(connection_t *conn, int edge_type) { circ = circuit_get_by_conn(conn); if(!circ) { /* this can legitimately happen if the destroy has already arrived and torn down the circuit */ - log(LOG_DEBUG,"connection_consider_sending_sendme(): No circuit associated with conn. Skipping."); + log_fn(LOG_DEBUG,"No circuit associated with conn. Skipping."); return 0; } @@ -660,10 +659,10 @@ int connection_consider_sending_sendme(connection_t *conn, int edge_type) { cell.aci = circ->n_aci; while(conn->deliver_window < STREAMWINDOW_START - STREAMWINDOW_INCREMENT) { - log(LOG_DEBUG,"connection_consider_sending_sendme(): Outbuf %d, Queueing stream sendme.", conn->outbuf_flushlen); + log_fn(LOG_DEBUG,"Outbuf %d, Queueing stream sendme.", conn->outbuf_flushlen); conn->deliver_window += STREAMWINDOW_INCREMENT; if(circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION(edge_type), conn->cpath_layer) < 0) { - log(LOG_DEBUG,"connection_consider_sending_sendme(): circuit_deliver_relay_cell failed. Closing."); + log_fn(LOG_DEBUG,"circuit_deliver_relay_cell failed. Closing."); circuit_close(circ); return 0; } @@ -676,7 +675,7 @@ int connection_finished_flushing(connection_t *conn) { assert(conn); -// log(LOG_DEBUG,"connection_finished_flushing() entered. Socket %u.", conn->s); +// log_fn(LOG_DEBUG,"entered. Socket %u.", conn->s); switch(conn->type) { case CONN_TYPE_OR: @@ -689,7 +688,7 @@ int connection_finished_flushing(connection_t *conn) { case CONN_TYPE_DNSWORKER: return connection_dns_finished_flushing(conn); default: - log(LOG_DEBUG,"connection_finished_flushing() got unexpected conn->type."); + log_fn(LOG_DEBUG,"got unexpected conn->type."); return -1; } } @@ -719,10 +718,10 @@ int connection_process_cell_from_inbuf(connection_t *conn) { #endif /* decrypt */ if(crypto_cipher_decrypt(conn->b_crypto,crypted,CELL_NETWORK_SIZE,outbuf)) { - log(LOG_ERR,"connection_process_cell_from_inbuf(): Decryption failed, dropping."); + log_fn(LOG_ERR,"Decryption failed, dropping."); return connection_process_inbuf(conn); /* process the remainder of the buffer */ } -// log(LOG_DEBUG,"connection_process_cell_from_inbuf(): Cell decrypted (%d bytes).",outlen); +// log_fn(LOG_DEBUG,"Cell decrypted (%d bytes).",outlen); #if 0 printf("Cell header plaintext: "); for(x=0;x<8;x++) { @@ -734,7 +733,7 @@ int connection_process_cell_from_inbuf(connection_t *conn) { /* retrieve cell info from outbuf (create the host-order struct from the network-order string) */ cell_unpack(&cell, outbuf); -// log(LOG_DEBUG,"connection_process_cell_from_inbuf(): Decrypted cell is of type %u (ACI %u).",cellp->command,cellp->aci); +// log_fn(LOG_DEBUG,"Decrypted cell is of type %u (ACI %u).",cellp->command,cellp->aci); command_process_cell(&cell, conn); return connection_process_inbuf(conn); /* process the remainder of the buffer */ diff --git a/src/or/connection_ap.c b/src/or/connection_ap.c index 5e48777de..478d51738 100644 --- a/src/or/connection_ap.c +++ b/src/or/connection_ap.c @@ -12,7 +12,7 @@ int ap_handshake_process_socks(connection_t *conn) { assert(conn); - log(LOG_DEBUG,"ap_handshake_process_socks() entered."); + log_fn(LOG_DEBUG,"entered."); if(!conn->socks_version) { /* try to pull it in */ @@ -22,38 +22,38 @@ int ap_handshake_process_socks(connection_t *conn) { if(connection_fetch_from_buf((char *)&socks4_info,sizeof(socks4_t),conn) < 0) return -1; - log(LOG_DEBUG,"ap_handshake_process_socks(): Successfully read socks info."); + log_fn(LOG_DEBUG,"Successfully read socks info."); if(socks4_info.version != 4) { - log(LOG_NOTICE,"ap_handshake_process_socks(): Unrecognized version %d.",socks4_info.version); + log_fn(LOG_NOTICE,"Unrecognized version %d.",socks4_info.version); ap_handshake_socks_reply(conn, SOCKS4_REQUEST_REJECT); return -1; } conn->socks_version = socks4_info.version; if(socks4_info.command != 1) { /* not a connect? we don't support it. */ - log(LOG_NOTICE,"ap_handshake_process_socks(): command %d not '1'.",socks4_info.command); + log_fn(LOG_NOTICE,"command %d not '1'.",socks4_info.command); ap_handshake_socks_reply(conn, SOCKS4_REQUEST_REJECT); return -1; } conn->dest_port = ntohs(*(uint16_t*)&socks4_info.destport); if(!conn->dest_port) { - log(LOG_NOTICE,"ap_handshake_process_socks(): Port is zero."); + log_fn(LOG_NOTICE,"Port is zero."); ap_handshake_socks_reply(conn, SOCKS4_REQUEST_REJECT); return -1; } - log(LOG_NOTICE,"ap_handshake_process_socks(): Dest port is %d.",conn->dest_port); + log_fn(LOG_NOTICE,"Dest port is %d.",conn->dest_port); if(socks4_info.destip[0] || socks4_info.destip[1] || socks4_info.destip[2] || !socks4_info.destip[3]) { /* not 0.0.0.x */ - log(LOG_NOTICE,"ap_handshake_process_socks(): destip not in form 0.0.0.x."); + log_fn(LOG_NOTICE,"destip not in form 0.0.0.x."); sprintf(tmpbuf, "%d.%d.%d.%d", socks4_info.destip[0], socks4_info.destip[1], socks4_info.destip[2], socks4_info.destip[3]); conn->dest_addr = strdup(tmpbuf); - log(LOG_DEBUG,"ap_handshake_process_socks(): Successfully read destip (%s)", conn->dest_addr); + log_fn(LOG_DEBUG,"Successfully read destip (%s)", conn->dest_addr); } } @@ -63,14 +63,14 @@ int ap_handshake_process_socks(connection_t *conn) { if(amt < 0) /* not there yet */ return 0; if(amt > 500) { - log(LOG_NOTICE,"ap_handshake_process_socks(): username too long."); + log_fn(LOG_NOTICE,"username too long."); ap_handshake_socks_reply(conn, SOCKS4_REQUEST_REJECT); return -1; } if(connection_fetch_from_buf(tmpbuf,amt,conn) < 0) return -1; conn->read_username = 1; - log(LOG_DEBUG,"ap_handshake_process_socks(): Successfully read username."); + log_fn(LOG_DEBUG,"Successfully read username."); } if(!conn->dest_addr) { /* no dest_addr found yet */ @@ -78,7 +78,7 @@ int ap_handshake_process_socks(connection_t *conn) { if(amt < 0) /* not there yet */ return 0; if(amt > 500) { - log(LOG_NOTICE,"ap_handshake_process_socks(): dest_addr too long."); + log_fn(LOG_NOTICE,"dest_addr too long."); ap_handshake_socks_reply(conn, SOCKS4_REQUEST_REJECT); return -1; } @@ -86,7 +86,7 @@ int ap_handshake_process_socks(connection_t *conn) { return -1; conn->dest_addr = strdup(tmpbuf); - log(LOG_NOTICE,"ap_handshake_process_socks(): successfully read dest addr '%s'", + log_fn(LOG_NOTICE,"successfully read dest addr '%s'", conn->dest_addr); } @@ -94,14 +94,14 @@ int ap_handshake_process_socks(connection_t *conn) { circ = circuit_get_newest_ap(); if(!circ) { - log(LOG_INFO,"ap_handshake_process_socks(): No circuit ready. Closing."); + log_fn(LOG_INFO,"No circuit ready. Closing."); return -1; } circ->dirty = 1; /* add it into the linked list of streams on this circuit */ - log(LOG_DEBUG,"ap_handshake_process_socks(): attaching new conn to circ. n_aci %d.", circ->n_aci); + log_fn(LOG_DEBUG,"attaching new conn to circ. n_aci %d.", circ->n_aci); conn->next_stream = circ->p_streams; circ->p_streams = conn; @@ -135,15 +135,15 @@ int ap_handshake_send_begin(connection_t *ap_conn, circuit_t *circ) { snprintf(cell.payload+RELAY_HEADER_SIZE+STREAM_ID_SIZE, CELL_PAYLOAD_SIZE-RELAY_HEADER_SIZE-STREAM_ID_SIZE, "%s:%d", ap_conn->dest_addr, ap_conn->dest_port) + 1 + STREAM_ID_SIZE + RELAY_HEADER_SIZE; - log(LOG_DEBUG,"ap_handshake_send_begin(): Sending relay cell (id %d) to begin stream %d.", *(int *)(cell.payload+1),*(int *)ap_conn->stream_id); + log_fn(LOG_DEBUG,"Sending relay cell (id %d) to begin stream %d.", *(int *)(cell.payload+1),*(int *)ap_conn->stream_id); if(circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION_OUT, ap_conn->cpath_layer) < 0) { - log(LOG_DEBUG,"ap_handshake_send_begin(): failed to deliver begin cell. Closing."); + log_fn(LOG_DEBUG,"failed to deliver begin cell. Closing."); return -1; } ap_conn->package_window = STREAMWINDOW_START; ap_conn->deliver_window = STREAMWINDOW_START; ap_conn->state = AP_CONN_STATE_OPEN; - log(LOG_INFO,"ap_handshake_send_begin(): Address/port sent, ap socket %d, n_aci %d",ap_conn->s,circ->n_aci); + log_fn(LOG_INFO,"Address/port sent, ap socket %d, n_aci %d",ap_conn->s,circ->n_aci); return 0; } @@ -163,7 +163,7 @@ int ap_handshake_socks_reply(connection_t *conn, char result) { } int connection_ap_create_listener(struct sockaddr_in *bindaddr) { - log(LOG_DEBUG,"connection_create_ap_listener starting"); + log_fn(LOG_DEBUG,"starting"); return connection_create_listener(bindaddr, CONN_TYPE_AP_LISTENER); } diff --git a/src/or/connection_edge.c b/src/or/connection_edge.c index 166ed4f83..6a6598477 100644 --- a/src/or/connection_edge.c +++ b/src/or/connection_edge.c @@ -32,13 +32,13 @@ int connection_edge_process_inbuf(connection_t *conn) { cell.aci = circ->n_aci; if (circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION(conn->type), conn->cpath_layer) < 0) { - log(LOG_DEBUG,"connection_edge_process_inbuf: circuit_deliver_relay_cell failed. Closing."); + log(LOG_DEBUG,"circuit_deliver_relay_cell failed. Closing."); circuit_close(circ); } return 0; #else /* eof reached, kill it. */ - log(LOG_DEBUG,"connection_edge_process_inbuf(): conn reached eof. Closing."); + log_fn(LOG_DEBUG,"conn reached eof. Closing."); return -1; #endif } @@ -53,7 +53,7 @@ int connection_edge_process_inbuf(connection_t *conn) { circuit_consider_stop_edge_reading(circuit_get_by_conn(conn), conn->type == CONN_TYPE_AP ? EDGE_AP : EDGE_EXIT, conn->cpath_layer); return 0; case EXIT_CONN_STATE_CONNECTING: - log(LOG_DEBUG,"connection_edge_process_inbuf(): text from server while in 'connecting' state at exit. Leaving it on buffer."); + log_fn(LOG_DEBUG,"text from server while in 'connecting' state at exit. Leaving it on buffer."); return 0; } @@ -65,7 +65,7 @@ int connection_edge_send_command(connection_t *fromconn, circuit_t *circ, int re int cell_direction; if(!circ) { - log(LOG_DEBUG,"connection_edge_send_command(): no circ. Closing."); + log_fn(LOG_DEBUG,"no circ. Closing."); return -1; } @@ -87,10 +87,10 @@ int connection_edge_send_command(connection_t *fromconn, circuit_t *circ, int re SET_CELL_STREAM_ID(cell, ZERO_STREAM); cell.length = RELAY_HEADER_SIZE; - log(LOG_INFO,"connection_edge_send_command(): delivering %d cell %s.", relay_command, cell_direction == CELL_DIRECTION_OUT ? "forward" : "backward"); + log_fn(LOG_INFO,"delivering %d cell %s.", relay_command, cell_direction == CELL_DIRECTION_OUT ? "forward" : "backward"); if(circuit_deliver_relay_cell(&cell, circ, cell_direction, fromconn ? fromconn->cpath_layer : NULL) < 0) { - log(LOG_DEBUG,"connection_edge_send_command(): circuit_deliver_relay_cell failed. Closing."); + log_fn(LOG_DEBUG,"circuit_deliver_relay_cell failed. Closing."); circuit_close(circ); return 0; } @@ -107,19 +107,19 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection assert(cell && circ); relay_command = CELL_RELAY_COMMAND(*cell); -// log(LOG_DEBUG,"connection_edge_process_relay_cell(): command %d stream %d", relay_command, stream_id); +// log_fn(LOG_DEBUG,"command %d stream %d", relay_command, stream_id); num_seen++; - log(LOG_DEBUG,"connection_edge_process_relay_cell(): Now seen %d relay cells here.", num_seen); + log_fn(LOG_DEBUG,"Now seen %d relay cells here.", num_seen); /* either conn is NULL, in which case we've got a control cell, or else * conn points to the recognized stream. */ if(conn && conn->state != AP_CONN_STATE_OPEN && conn->state != EXIT_CONN_STATE_OPEN) { if(conn->type == CONN_TYPE_EXIT && relay_command == RELAY_COMMAND_END) { - log(LOG_INFO,"connection_edge_process_relay_cell(): Exit got end before we're connected. Marking for close."); + log_fn(LOG_INFO,"Exit got end before we're connected. Marking for close."); conn->marked_for_close = 1; } else { - log(LOG_DEBUG,"connection_edge_process_relay_cell(): Got an unexpected relay cell, not in 'open' state. Dropping."); + log_fn(LOG_DEBUG,"Got an unexpected relay cell, not in 'open' state. Dropping."); } return 0; } @@ -127,32 +127,32 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection switch(relay_command) { case RELAY_COMMAND_BEGIN: if(edge_type == EDGE_AP) { - log(LOG_INFO,"connection_edge_process_relay_cell(): relay begin request unsupported. Dropping."); + log_fn(LOG_INFO,"relay begin request unsupported. Dropping."); return 0; } if(conn) { - log(LOG_INFO,"connection_edge_process_relay_cell(): begin cell for known stream. Dropping."); + log_fn(LOG_INFO,"begin cell for known stream. Dropping."); return 0; } return connection_exit_begin_conn(cell, circ); case RELAY_COMMAND_DATA: if((edge_type == EDGE_AP && --layer_hint->deliver_window < 0) || (edge_type == EDGE_EXIT && --circ->deliver_window < 0)) { - log(LOG_DEBUG,"connection_edge_process_relay_cell(): circ deliver_window below 0. Killing."); + log_fn(LOG_DEBUG,"circ deliver_window below 0. Killing."); return -1; /* XXX kill the whole circ? */ } - log(LOG_DEBUG,"connection_edge_process_relay_cell(): circ deliver_window now %d.", edge_type == EDGE_AP ? layer_hint->deliver_window : circ->deliver_window); + log_fn(LOG_DEBUG,"circ deliver_window now %d.", edge_type == EDGE_AP ? layer_hint->deliver_window : circ->deliver_window); if(circuit_consider_sending_sendme(circ, edge_type, layer_hint) < 0) return -1; if(!conn) { - log(LOG_DEBUG,"connection_edge_process_relay_cell(): relay cell dropped, unknown stream %d.",*(int*)conn->stream_id); + log_fn(LOG_DEBUG,"relay cell dropped, unknown stream %d.",*(int*)conn->stream_id); return 0; } if(--conn->deliver_window < 0) { /* is it below 0 after decrement? */ - log(LOG_DEBUG,"connection_edge_process_relay_cell(): conn deliver_window below 0. Killing."); + log_fn(LOG_DEBUG,"conn deliver_window below 0. Killing."); return -1; /* somebody's breaking protocol. kill the whole circuit. */ } @@ -166,10 +166,10 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection return 0; case RELAY_COMMAND_END: if(!conn) { - log(LOG_DEBUG,"connection_edge_process_relay_cell(): end cell dropped, unknown stream %d.",*(int*)conn->stream_id); + log_fn(LOG_DEBUG,"end cell dropped, unknown stream %d.",*(int*)conn->stream_id); return 0; } - log(LOG_DEBUG,"connection_edge_process_relay_cell(): end cell for stream %d. Removing stream.",*(int*)conn->stream_id); + log_fn(LOG_DEBUG,"end cell for stream %d. Removing stream.",*(int*)conn->stream_id); #ifdef HALF_OPEN conn->done_sending = 1; @@ -181,48 +181,48 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection break; case RELAY_COMMAND_EXTEND: if(conn) { - log(LOG_INFO,"connection_edge_process_relay_cell(): 'extend' for non-zero stream. Dropping."); + log_fn(LOG_INFO,"'extend' for non-zero stream. Dropping."); return 0; } return circuit_extend(cell, circ); case RELAY_COMMAND_EXTENDED: if(edge_type == EDGE_EXIT) { - log(LOG_INFO,"connection_edge_process_relay_cell(): 'extended' unsupported at exit. Dropping."); + log_fn(LOG_INFO,"'extended' unsupported at exit. Dropping."); return 0; } - log(LOG_DEBUG,"connection_edge_process_relay_cell(): Got an extended cell! Yay."); + log_fn(LOG_DEBUG,"Got an extended cell! Yay."); if(circuit_finish_handshake(circ, cell->payload+RELAY_HEADER_SIZE) < 0) { - log(LOG_INFO,"connection_edge_process_relay_cell(): circuit_finish_handshake failed."); + log_fn(LOG_INFO,"circuit_finish_handshake failed."); return -1; } return circuit_send_next_onion_skin(circ); case RELAY_COMMAND_TRUNCATE: if(edge_type == EDGE_AP) { - log(LOG_INFO,"connection_edge_process_relay_cell(): 'truncate' unsupported at AP. Dropping."); + log_fn(LOG_INFO,"'truncate' unsupported at AP. Dropping."); return 0; } if(circ->n_conn) { connection_send_destroy(circ->n_aci, circ->n_conn); circ->n_conn = NULL; } - log(LOG_DEBUG, "connection_edge_process_relay_cell(): Processed 'truncate', replying."); + log_fn(LOG_DEBUG, "Processed 'truncate', replying."); return connection_edge_send_command(NULL, circ, RELAY_COMMAND_TRUNCATED); case RELAY_COMMAND_TRUNCATED: if(edge_type == EDGE_EXIT) { - log(LOG_INFO,"connection_edge_process_relay_cell(): 'truncated' unsupported at exit. Dropping."); + log_fn(LOG_INFO,"'truncated' unsupported at exit. Dropping."); return 0; } return circuit_truncated(circ, layer_hint); case RELAY_COMMAND_CONNECTED: if(edge_type == EDGE_EXIT) { - log(LOG_INFO,"connection_edge_process_relay_cell(): 'connected' unsupported at exit. Dropping."); + log_fn(LOG_INFO,"'connected' unsupported at exit. Dropping."); return 0; } if(!conn) { - log(LOG_DEBUG,"connection_edge_process_relay_cell(): connected cell dropped, unknown stream %d.",*(int*)conn->stream_id); + log_fn(LOG_DEBUG,"connected cell dropped, unknown stream %d.",*(int*)conn->stream_id); break; } - log(LOG_DEBUG,"connection_edge_process_relay_cell(): Connected! Notifying application."); + log_fn(LOG_DEBUG,"Connected! Notifying application."); if(ap_handshake_socks_reply(conn, SOCKS4_REQUEST_GRANTED) < 0) { conn->marked_for_close = 1; } @@ -232,12 +232,12 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection if(edge_type == EDGE_AP) { assert(layer_hint); layer_hint->package_window += CIRCWINDOW_INCREMENT; - log(LOG_DEBUG,"connection_edge_process_relay_cell(): circ-level sendme at AP, packagewindow %d.", layer_hint->package_window); + log_fn(LOG_DEBUG,"circ-level sendme at AP, packagewindow %d.", layer_hint->package_window); circuit_resume_edge_reading(circ, EDGE_AP, layer_hint); } else { assert(!layer_hint); circ->package_window += CIRCWINDOW_INCREMENT; - log(LOG_DEBUG,"connection_edge_process_relay_cell(): circ-level sendme at exit, packagewindow %d.", circ->package_window); + log_fn(LOG_DEBUG,"circ-level sendme at exit, packagewindow %d.", circ->package_window); circuit_resume_edge_reading(circ, EDGE_EXIT, layer_hint); } return 0; @@ -248,7 +248,7 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection circuit_consider_stop_edge_reading(circ, edge_type, layer_hint); break; default: - log(LOG_DEBUG,"connection_edge_process_relay_cell(): unknown relay command %d.",relay_command); + log_fn(LOG_DEBUG,"unknown relay command %d.",relay_command); } return 0; } @@ -264,16 +264,16 @@ int connection_edge_finished_flushing(connection_t *conn) { if (getsockopt(conn->s, SOL_SOCKET, SO_ERROR, &e, &len) < 0) { /* not yet */ if(errno != EINPROGRESS){ /* yuck. kill it. */ - log(LOG_DEBUG,"connection_edge_finished_flushing(): in-progress exit connect failed. Removing."); + log_fn(LOG_DEBUG,"in-progress exit connect failed. Removing."); return -1; } else { - log(LOG_DEBUG,"connection_edge_finished_flushing(): in-progress exit connect still waiting."); + log_fn(LOG_DEBUG,"in-progress exit connect still waiting."); return 0; /* no change, see if next time is better */ } } /* the connect has finished. */ - log(LOG_DEBUG,"connection_edge_finished_flushing(): Exit connection to %s:%u established.", + log_fn(LOG_DEBUG,"Exit connection to %s:%u established.", conn->address,conn->port); conn->state = EXIT_CONN_STATE_OPEN; @@ -288,7 +288,7 @@ int connection_edge_finished_flushing(connection_t *conn) { connection_stop_writing(conn); return connection_consider_sending_sendme(conn, conn->type); default: - log(LOG_DEBUG,"Bug: connection_edge_finished_flushing() called in unexpected state."); + log_fn(LOG_DEBUG,"BUG: called in unexpected state."); return 0; } diff --git a/src/or/connection_exit.c b/src/or/connection_exit.c index 9bcda85dc..88f27d2cb 100644 --- a/src/or/connection_exit.c +++ b/src/or/connection_exit.c @@ -9,25 +9,25 @@ int connection_exit_begin_conn(cell_t *cell, circuit_t *circ) { char *colon; if(!memchr(cell->payload+RELAY_HEADER_SIZE+STREAM_ID_SIZE,0,cell->length-RELAY_HEADER_SIZE-STREAM_ID_SIZE)) { - log(LOG_WARNING,"connection_exit_begin_conn(): relay begin cell has no \\0. Dropping."); + log_fn(LOG_WARNING,"relay begin cell has no \\0. Dropping."); return 0; } colon = strchr(cell->payload+RELAY_HEADER_SIZE+STREAM_ID_SIZE, ':'); if(!colon) { - log(LOG_WARNING,"connection_exit_begin_conn(): relay begin cell has no colon. Dropping."); + log_fn(LOG_WARNING,"relay begin cell has no colon. Dropping."); return 0; } *colon = 0; if(!atoi(colon+1)) { /* bad port */ - log(LOG_DEBUG,"connection_exit_begin_conn(): relay begin cell has invalid port. Dropping."); + log_fn(LOG_DEBUG,"relay begin cell has invalid port. Dropping."); return 0; } - log(LOG_DEBUG,"connection_exit_begin_conn(): Creating new exit connection."); + log_fn(LOG_DEBUG,"Creating new exit connection."); n_stream = connection_new(CONN_TYPE_EXIT); if(!n_stream) { - log(LOG_DEBUG,"connection_exit_begin_conn(): connection_new failed. Dropping."); + log_fn(LOG_DEBUG,"connection_new failed. Dropping."); return 0; } @@ -41,7 +41,7 @@ int connection_exit_begin_conn(cell_t *cell, circuit_t *circ) { n_stream->package_window = STREAMWINDOW_START; n_stream->deliver_window = STREAMWINDOW_START; if(connection_add(n_stream) < 0) { /* no space, forget it */ - log(LOG_DEBUG,"connection_exit_begin_conn(): connection_add failed. Dropping."); + log_fn(LOG_DEBUG,"connection_add failed. Dropping."); connection_free(n_stream); return 0; } @@ -52,7 +52,7 @@ int connection_exit_begin_conn(cell_t *cell, circuit_t *circ) { /* send it off to the gethostbyname farm */ if(dns_resolve(n_stream) < 0) { - log(LOG_DEBUG,"connection_exit_begin_conn(): Couldn't queue resolve request."); + log_fn(LOG_DEBUG,"Couldn't queue resolve request."); connection_remove(n_stream); connection_free(n_stream); return 0; @@ -66,14 +66,14 @@ int connection_exit_connect(connection_t *conn) { struct sockaddr_in dest_addr; if(router_compare_to_exit_policy(conn) < 0) { - log(LOG_INFO,"connection_exit_connect(): %s:%d failed exit policy. Closing.", conn->address, conn->port); + log_fn(LOG_INFO,"%s:%d failed exit policy. Closing.", conn->address, conn->port); return -1; } /* all the necessary info is here. Start the connect() */ s=socket(PF_INET,SOCK_STREAM,IPPROTO_TCP); if (s < 0) { - log(LOG_ERR,"connection_exit_connect(): Error creating network socket."); + log_fn(LOG_ERR,"Error creating network socket."); return -1; } fcntl(s, F_SETFL, O_NONBLOCK); /* set s to non-blocking */ @@ -83,13 +83,13 @@ int connection_exit_connect(connection_t *conn) { dest_addr.sin_port = htons(conn->port); dest_addr.sin_addr.s_addr = htonl(conn->addr); - log(LOG_DEBUG,"connection_exit_connect(): Connecting to %s:%u.",conn->address,conn->port); + log_fn(LOG_DEBUG,"Connecting to %s:%u.",conn->address,conn->port); if(connect(s,(struct sockaddr *)&dest_addr,sizeof(dest_addr)) < 0) { if(errno != EINPROGRESS){ /* yuck. kill it. */ perror("connect"); - log(LOG_DEBUG,"connection_exit_connect(): Connect failed."); + log_fn(LOG_DEBUG,"Connect failed."); return -1; } else { /* it's in progress. set state appropriately and return. */ @@ -97,20 +97,20 @@ int connection_exit_connect(connection_t *conn) { connection_set_poll_socket(conn); conn->state = EXIT_CONN_STATE_CONNECTING; - log(LOG_DEBUG,"connection_exit_connect(): connect in progress, socket %d.",s); + log_fn(LOG_DEBUG,"connect in progress, socket %d.",s); connection_watch_events(conn, POLLOUT | POLLIN); return 0; } } /* it succeeded. we're connected. */ - log(LOG_DEBUG,"connection_exit_connect(): Connection to %s:%u established.",conn->address,conn->port); + log_fn(LOG_DEBUG,"Connection to %s:%u established.",conn->address,conn->port); conn->s = s; connection_set_poll_socket(conn); conn->state = EXIT_CONN_STATE_OPEN; if(connection_wants_to_flush(conn)) { /* in case there are any queued data cells */ - log(LOG_ERR,"connection_exit_connect(): tell roger: newly connected conn had data waiting!"); + log_fn(LOG_ERR,"tell roger: newly connected conn had data waiting!"); // connection_start_writing(conn); } // connection_process_inbuf(conn); diff --git a/src/or/connection_or.c b/src/or/connection_or.c index 8de0b2a2f..158425f2a 100644 --- a/src/or/connection_or.c +++ b/src/or/connection_or.c @@ -17,7 +17,7 @@ int connection_or_process_inbuf(connection_t *conn) { if(conn->inbuf_reached_eof) { /* eof reached, kill it. */ - log(LOG_DEBUG,"connection_or_process_inbuf(): conn reached eof. Closing."); + log_fn(LOG_DEBUG,"conn reached eof. Closing."); return -1; } @@ -33,7 +33,7 @@ int connection_or_process_inbuf(connection_t *conn) { case OR_CONN_STATE_OPEN: return connection_process_cell_from_inbuf(conn); default: - log(LOG_DEBUG,"connection_or_process_inbuf() called in state where I'm writing. Ignoring buf for now."); + log_fn(LOG_DEBUG,"called in state where I'm writing. Ignoring buf for now."); } return 0; @@ -51,7 +51,7 @@ int connection_or_finished_flushing(connection_t *conn) { if (getsockopt(conn->s, SOL_SOCKET, SO_ERROR, &e, &len) < 0) { /* not yet */ if(errno != EINPROGRESS){ /* yuck. kill it. */ - log(LOG_DEBUG,"connection_or_finished_flushing(): in-progress connect failed. Removing."); + log_fn(LOG_DEBUG,"in-progress connect failed. Removing."); return -1; } else { return 0; /* no change, see if next time is better */ @@ -59,7 +59,7 @@ int connection_or_finished_flushing(connection_t *conn) { } /* the connect has finished. */ - log(LOG_DEBUG,"connection_or_finished_flushing() : OR connection to router %s:%u established.", + log_fn(LOG_DEBUG,"OR connection to router %s:%u established.", conn->address,conn->port); if(options.OnionRouter) @@ -67,18 +67,18 @@ int connection_or_finished_flushing(connection_t *conn) { else return or_handshake_op_send_keys(conn); case OR_CONN_STATE_CLIENT_SENDING_AUTH: - log(LOG_DEBUG,"connection_or_finished_flushing(): client finished sending auth."); + log_fn(LOG_DEBUG,"client finished sending auth."); conn->state = OR_CONN_STATE_CLIENT_AUTH_WAIT; connection_watch_events(conn, POLLIN); return 0; case OR_CONN_STATE_CLIENT_SENDING_NONCE: - log(LOG_DEBUG,"connection_or_finished_flushing(): client finished sending nonce."); + log_fn(LOG_DEBUG,"client finished sending nonce."); conn_or_init_crypto(conn); connection_or_set_open(conn); return connection_process_inbuf(conn); /* in case there's anything waiting on it */ case OR_CONN_STATE_SERVER_SENDING_AUTH: - log(LOG_DEBUG,"connection_or_finished_flushing(): server finished sending auth."); + log_fn(LOG_DEBUG,"server finished sending auth."); conn->state = OR_CONN_STATE_SERVER_NONCE_WAIT; connection_watch_events(conn, POLLIN); return 0; @@ -87,7 +87,7 @@ int connection_or_finished_flushing(connection_t *conn) { connection_stop_writing(conn); return 0; default: - log(LOG_DEBUG,"Bug: connection_or_finished_flushing() called in unexpected state."); + log_fn(LOG_DEBUG,"BUG: called in unexpected state."); return 0; } diff --git a/src/or/directory.c b/src/or/directory.c index 34d9a1797..525decd87 100644 --- a/src/or/directory.c +++ b/src/or/directory.c @@ -31,7 +31,7 @@ void directory_initiate_fetch(routerinfo_t *router) { if(connection_get_by_type(CONN_TYPE_DIR)) /* there's already a fetch running */ return; - log(LOG_DEBUG,"directory_initiate_fetch(): initiating directory fetch"); + log_fn(LOG_DEBUG,"initiating directory fetch"); conn = connection_new(CONN_TYPE_DIR); if(!conn) @@ -46,13 +46,13 @@ void directory_initiate_fetch(routerinfo_t *router) { if (router->signing_pkey) conn->pkey = crypto_pk_dup_key(router->signing_pkey); else { - log(LOG_ERR, "No signing key known for directory %s; signature won't be checked", conn->address); + log_fn(LOG_ERR, "No signing key known for directory %s; signature won't be checked", conn->address); conn->pkey = NULL; } s=socket(PF_INET,SOCK_STREAM,IPPROTO_TCP); if(s < 0) { - log(LOG_ERR,"directory_initiate_fetch(): Error creating network socket."); + log_fn(LOG_ERR,"Error creating network socket."); connection_free(conn); return; } @@ -63,7 +63,7 @@ void directory_initiate_fetch(routerinfo_t *router) { router_addr.sin_port = htons(router->dir_port); router_addr.sin_addr.s_addr = htonl(router->addr); - log(LOG_DEBUG,"directory_initiate_fetch(): Trying to connect to %s:%u.",router->address,router->dir_port); + log_fn(LOG_DEBUG,"Trying to connect to %s:%u.",router->address,router->dir_port); if(connect(s,(struct sockaddr *)&router_addr,sizeof(router_addr)) < 0){ if(errno != EINPROGRESS){ @@ -80,7 +80,7 @@ void directory_initiate_fetch(routerinfo_t *router) { return; } - log(LOG_DEBUG,"directory_initiate_fetch(): connect in progress."); + log_fn(LOG_DEBUG,"connect in progress."); connection_watch_events(conn, POLLIN | POLLOUT); /* writable indicates finish, readable indicates broken link */ conn->state = DIR_CONN_STATE_CONNECTING; return; @@ -95,7 +95,7 @@ void directory_initiate_fetch(routerinfo_t *router) { return; } - log(LOG_DEBUG,"directory_initiate_fetch(): Connection to router %s:%u established.",router->address,router->dir_port); + log_fn(LOG_DEBUG,"Connection to router %s:%u established.",router->address,router->dir_port); if(directory_send_command(conn) < 0) { connection_remove(conn); @@ -108,7 +108,7 @@ int directory_send_command(connection_t *conn) { assert(conn && conn->type == CONN_TYPE_DIR); if(connection_write_to_buf(getstring, strlen(getstring), conn) < 0) { - log(LOG_DEBUG,"directory_send_command(): Couldn't write command to buffer."); + log_fn(LOG_DEBUG,"Couldn't write command to buffer."); return -1; } @@ -141,20 +141,19 @@ int connection_dir_process_inbuf(connection_t *conn) { if(conn->inbuf_reached_eof) { if(conn->state != DIR_CONN_STATE_READING) { - log(LOG_DEBUG,"connection_dir_process_inbuf(): conn reached eof, not reading. Closing."); + log_fn(LOG_DEBUG,"conn reached eof, not reading. Closing."); return -1; } /* eof reached, kill it, but first process the_directory and learn about new routers. */ -// log(LOG_DEBUG,"connection_dir_process_inbuf(): conn reached eof. Processing directory."); - log(LOG_DEBUG,"connection_dir_process_inbuf(): Received directory (size %d)\n%s", directorylen, the_directory); + log_fn(LOG_DEBUG,"Received directory (size %d)\n%s", directorylen, the_directory); if(directorylen == 0) { - log(LOG_DEBUG,"connection_dir_process_inbuf(): Empty directory. Ignoring."); + log_fn(LOG_DEBUG,"Empty directory. Ignoring."); return -1; } if(router_get_dir_from_string(the_directory, conn->pkey) < 0) { - log(LOG_DEBUG,"connection_dir_process_inbuf(): ...but parsing failed. Ignoring."); + log_fn(LOG_DEBUG,"...but parsing failed. Ignoring."); } else { - log(LOG_DEBUG,"connection_dir_process_inbuf(): and got a %s directory; updated routers.", + log_fn(LOG_DEBUG,"and got a %s directory; updated routers.", conn->pkey ? "authenticated" : "unauthenticated"); } @@ -170,7 +169,7 @@ int connection_dir_process_inbuf(connection_t *conn) { case DIR_CONN_STATE_READING: return directory_handle_reading(conn); default: - log(LOG_DEBUG,"connection_dir_process_inbuf(): Got data while writing; Ignoring."); + log_fn(LOG_DEBUG,"Got data while writing; Ignoring."); break; } @@ -183,7 +182,7 @@ int directory_handle_command(connection_t *conn) { assert(conn && conn->type == CONN_TYPE_DIR); if(conn->inbuf_datalen < strlen(getstring)) { /* entire response available? */ - log(LOG_DEBUG,"directory_handle_command(): Entire command not here yet. Waiting."); + log_fn(LOG_DEBUG,"Entire command not here yet. Waiting."); return 0; /* not yet */ } @@ -192,21 +191,21 @@ int directory_handle_command(connection_t *conn) { } if(strncasecmp(buf,getstring,strlen("GET / HTTP/"))) { - log(LOG_DEBUG,"directory_handle_command(): Command doesn't seem to be a get. Closing,"); + log_fn(LOG_DEBUG,"Command doesn't seem to be a get. Closing,"); return -1; } directory_rebuild(); /* rebuild it now, iff it's dirty */ if(directorylen == 0) { - log(LOG_DEBUG,"directory_handle_command(): My directory is empty. Closing."); + log_fn(LOG_DEBUG,"My directory is empty. Closing."); return -1; } - log(LOG_DEBUG,"directory_handle_command(): Dumping directory to client."); + log_fn(LOG_DEBUG,"Dumping directory to client."); if((connection_write_to_buf(answerstring, strlen(answerstring), conn) < 0) || (connection_write_to_buf(the_directory, directorylen, conn) < 0)) { - log(LOG_DEBUG,"directory_handle_command(): my outbuf is full. Oops."); + log_fn(LOG_DEBUG,"my outbuf is full. Oops."); return -1; } @@ -226,7 +225,7 @@ int directory_handle_reading(connection_t *conn) { return 0; headers = tor_malloc(amt+1); if(connection_fetch_from_buf(headers,amt,conn) < 0) { - log(LOG_DEBUG,"directory_handle_reading(): fetch_from_buf failed (reading headers)."); + log_fn(LOG_DEBUG,"fetch_from_buf failed (reading headers)."); return -1; } headers[amt] = 0; /* null terminate it, */ @@ -237,15 +236,15 @@ int directory_handle_reading(connection_t *conn) { amt = conn->inbuf_datalen; if(amt + directorylen >= MAX_DIR_SIZE) { - log(LOG_DEBUG,"directory_handle_reading(): Directory too large. Failing messily."); + log_fn(LOG_DEBUG,"Directory too large. Failing messily."); return -1; } - log(LOG_DEBUG,"directory_handle_reading(): Pulling %d bytes in at offset %d.", + log_fn(LOG_DEBUG,"Pulling %d bytes in at offset %d.", amt, directorylen); if(connection_fetch_from_buf(the_directory+directorylen,amt,conn) < 0) { - log(LOG_DEBUG,"directory_handle_reading(): fetch_from_buf failed (reading dir)."); + log_fn(LOG_DEBUG,"fetch_from_buf failed (reading dir)."); return -1; } @@ -266,7 +265,7 @@ int connection_dir_finished_flushing(connection_t *conn) { if (getsockopt(conn->s, SOL_SOCKET, SO_ERROR, &e, &len) < 0) { /* not yet */ if(errno != EINPROGRESS){ /* yuck. kill it. */ - log(LOG_DEBUG,"connection_dir_finished_flushing(): in-progress connect failed. Removing."); + log_fn(LOG_DEBUG,"in-progress connect failed. Removing."); router_forget_router(conn->addr, conn->port); /* don't try him again */ return -1; } else { @@ -275,22 +274,22 @@ int connection_dir_finished_flushing(connection_t *conn) { } /* the connect has finished. */ - log(LOG_DEBUG,"connection_dir_finished_flushing(): Dir connection to router %s:%u established.", + log_fn(LOG_DEBUG,"Dir connection to router %s:%u established.", conn->address,conn->port); return directory_send_command(conn); case DIR_CONN_STATE_SENDING_COMMAND: - log(LOG_DEBUG,"connection_dir_finished_flushing(): client finished sending command."); + log_fn(LOG_DEBUG,"client finished sending command."); directorylen = 0; reading_headers = 1; conn->state = DIR_CONN_STATE_READING; connection_watch_events(conn, POLLIN); return 0; case DIR_CONN_STATE_WRITING: - log(LOG_DEBUG,"connection_dir_finished_flushing(): Finished writing directory. Closing."); + log_fn(LOG_DEBUG,"Finished writing directory. Closing."); return -1; /* kill it */ default: - log(LOG_DEBUG,"Bug: connection_dir_finished_flushing() called in unexpected state."); + log_fn(LOG_DEBUG,"BUG: called in unexpected state."); return 0; } @@ -298,7 +297,7 @@ int connection_dir_finished_flushing(connection_t *conn) { } int connection_dir_create_listener(struct sockaddr_in *bindaddr) { - log(LOG_DEBUG,"connection_create_dir_listener starting"); + log_fn(LOG_DEBUG,"starting"); return connection_create_listener(bindaddr, CONN_TYPE_DIR_LISTENER); } diff --git a/src/or/main.c b/src/or/main.c index c231d57d6..181e7d898 100644 --- a/src/or/main.c +++ b/src/or/main.c @@ -753,7 +753,7 @@ dump_signed_directory_to_string_impl(char *s, int maxlen, directory_t *dir, i = strlen(s); cp = s+i; if (base64_encode(cp, maxlen-i, signature, 128) < 0) { - log(LOG_ERR,"dump_signed_directory_to_string(): couldn't base64-encode signature %d/%d"); + log_fn(LOG_ERR," couldn't base64-encode signature"); return -1; } diff --git a/src/or/routers.c b/src/or/routers.c index 0f6156cdf..06d7e2c79 100644 --- a/src/or/routers.c +++ b/src/or/routers.c @@ -218,7 +218,8 @@ int router_get_list_from_file(char *routerfile) string = tor_malloc(statbuf.st_size+1); if(read(fd,string,statbuf.st_size) != statbuf.st_size) { - log_fn(LOG_ERR,"Couldn't read all %d bytes of file '%s'.",statbuf.st_size,routerfile); + log_fn(LOG_ERR,"Couldn't read all %ld bytes of file '%s'.", + (long)statbuf.st_size,routerfile); free(string); close(fd); return -1; |