diff options
author | Roger Dingledine <arma@torproject.org> | 2004-02-28 07:01:22 +0000 |
---|---|---|
committer | Roger Dingledine <arma@torproject.org> | 2004-02-28 07:01:22 +0000 |
commit | dd632e697e6e7e96f755fab1a618e71fef169cdc (patch) | |
tree | 79b8f0d3823667921bf1ff064597d2632528e1ae | |
parent | a24b6e6d4fd9d65e9f0eef45f46720cd5007e175 (diff) | |
download | tor-dd632e697e6e7e96f755fab1a618e71fef169cdc.tar.gz tor-dd632e697e6e7e96f755fab1a618e71fef169cdc.zip |
clean up some log messages and severities
still plenty more left to clean
svn:r1158
-rw-r--r-- | src/or/buffers.c | 23 | ||||
-rw-r--r-- | src/or/circuit.c | 58 | ||||
-rw-r--r-- | src/or/command.c | 6 | ||||
-rw-r--r-- | src/or/config.c | 1 | ||||
-rw-r--r-- | src/or/connection.c | 15 | ||||
-rw-r--r-- | src/or/connection_edge.c | 23 |
6 files changed, 63 insertions, 63 deletions
diff --git a/src/or/buffers.c b/src/or/buffers.c index a87f807030..071edad89d 100644 --- a/src/or/buffers.c +++ b/src/or/buffers.c @@ -419,7 +419,6 @@ int fetch_from_buf_socks(buf_t *buf, socks_request_t *req) { if(req->socks_version != 5) { /* we need to negotiate a method */ unsigned char nummethods = (unsigned char)*(buf->mem+1); assert(!req->socks_version); - log_fn(LOG_DEBUG,"socks5: learning offered methods"); if(buf->datalen < 2+nummethods) return 0; if(!nummethods || !memchr(buf->mem+2, 0, nummethods)) { @@ -443,7 +442,7 @@ int fetch_from_buf_socks(buf_t *buf, socks_request_t *req) { if(buf->datalen < 8) /* basic info plus >=2 for addr plus 2 for port */ return 0; /* not yet */ if(*(buf->mem+1) != 1) { /* not a connect? we don't support it. */ - log_fn(LOG_WARN,"socks5: command %d not '1'.",*(buf->mem+1)); + log_fn(LOG_WARN,"socks5: command %d not '1'. Rejecting.",*(buf->mem+1)); return -1; } switch(*(buf->mem+3)) { /* address type */ @@ -455,7 +454,7 @@ int fetch_from_buf_socks(buf_t *buf, socks_request_t *req) { in.s_addr = htonl(destip); tmpbuf = inet_ntoa(in); if(strlen(tmpbuf)+1 > MAX_SOCKS_ADDR_LEN) { - log_fn(LOG_WARN,"socks5 IP takes %d bytes, which doesn't fit in %d", + log_fn(LOG_WARN,"socks5 IP takes %d bytes, which doesn't fit in %d. Rejecting.", (int)strlen(tmpbuf)+1,(int)MAX_SOCKS_ADDR_LEN); return -1; } @@ -469,7 +468,7 @@ int fetch_from_buf_socks(buf_t *buf, socks_request_t *req) { if(buf->datalen < 7+len) /* addr/port there? */ return 0; /* not yet */ if(len+1 > MAX_SOCKS_ADDR_LEN) { - log_fn(LOG_WARN,"socks5 hostname is %d bytes, which doesn't fit in %d", + log_fn(LOG_WARN,"socks5 hostname is %d bytes, which doesn't fit in %d. Rejecting.", len+1,MAX_SOCKS_ADDR_LEN); return -1; } @@ -479,7 +478,7 @@ int fetch_from_buf_socks(buf_t *buf, socks_request_t *req) { buf_remove_from_front(buf, 5+len+2); return 1; default: /* unsupported */ - log_fn(LOG_WARN,"socks5: unsupported address type %d",*(buf->mem+3)); + log_fn(LOG_WARN,"socks5: unsupported address type %d. Rejecting.",*(buf->mem+3)); return -1; } assert(0); @@ -490,14 +489,14 @@ int fetch_from_buf_socks(buf_t *buf, socks_request_t *req) { return 0; /* not yet */ if(*(buf->mem+1) != 1) { /* not a connect? we don't support it. */ - log_fn(LOG_WARN,"socks4: command %d not '1'.",*(buf->mem+1)); + log_fn(LOG_WARN,"socks4: command %d not '1'. Rejecting.",*(buf->mem+1)); return -1; } req->port = ntohs(*(uint16_t*)(buf->mem+2)); destip = ntohl(*(uint32_t*)(buf->mem+4)); if(!req->port || !destip) { - log_fn(LOG_WARN,"socks4: Port or DestIP is zero."); + log_fn(LOG_WARN,"socks4: Port or DestIP is zero. Rejecting."); return -1; } if(destip >> 8) { @@ -505,7 +504,7 @@ int fetch_from_buf_socks(buf_t *buf, socks_request_t *req) { in.s_addr = htonl(destip); tmpbuf = inet_ntoa(in); if(strlen(tmpbuf)+1 > MAX_SOCKS_ADDR_LEN) { - log_fn(LOG_WARN,"socks4 addr (%d bytes) too long.", + log_fn(LOG_WARN,"socks4 addr (%d bytes) too long. Rejecting.", (int)strlen(tmpbuf)); return -1; } @@ -515,7 +514,7 @@ int fetch_from_buf_socks(buf_t *buf, socks_request_t *req) { next = memchr(buf->mem+SOCKS4_NETWORK_LEN, 0, buf->datalen); if(!next) { - log_fn(LOG_DEBUG,"Username not here yet."); + log_fn(LOG_DEBUG,"socks4: Username not here yet."); return 0; } @@ -523,15 +522,15 @@ int fetch_from_buf_socks(buf_t *buf, socks_request_t *req) { if(socks4_prot == socks4a) { next = memchr(startaddr, 0, buf->mem+buf->datalen-startaddr); if(!next) { - log_fn(LOG_DEBUG,"Destaddr not here yet."); + log_fn(LOG_DEBUG,"socks4: Destaddr not here yet."); return 0; } if(MAX_SOCKS_ADDR_LEN <= next-startaddr) { - log_fn(LOG_WARN,"Destaddr too long."); + log_fn(LOG_WARN,"socks4: Destaddr too long. Rejecting."); return -1; } } - log_fn(LOG_DEBUG,"Everything is here. Success."); + log_fn(LOG_DEBUG,"socks4: Everything is here. Success."); strcpy(req->address, socks4_prot == socks4 ? tmpbuf : startaddr); /* XXX on very old netscapes (socks4) the next line triggers an * assert, because next-buf->mem+1 is greater than buf->datalen. diff --git a/src/or/circuit.c b/src/or/circuit.c index 13145c029c..f4d8bf8955 100644 --- a/src/or/circuit.c +++ b/src/or/circuit.c @@ -323,8 +323,8 @@ static void relay_set_digest(crypto_digest_env_t *digest, cell_t *cell) { crypto_digest_add_bytes(digest, cell->payload, CELL_PAYLOAD_SIZE); crypto_digest_get_digest(digest, integrity, 4); - log_fn(LOG_DEBUG,"Putting digest of %u %u %u %u into relay cell.", - integrity[0], integrity[1], integrity[2], integrity[3]); +// log_fn(LOG_DEBUG,"Putting digest of %u %u %u %u into relay cell.", +// integrity[0], integrity[1], integrity[2], integrity[3]); relay_header_unpack(&rh, cell->payload); memcpy(rh.integrity, integrity, 4); relay_header_pack(cell->payload, &rh); @@ -346,15 +346,15 @@ static int relay_digest_matches(crypto_digest_env_t *digest, cell_t *cell) { memset(rh.integrity, 0, 4); relay_header_pack(cell->payload, &rh); - log_fn(LOG_DEBUG,"Reading digest of %u %u %u %u from relay cell.", - received_integrity[0], received_integrity[1], - received_integrity[2], received_integrity[3]); +// log_fn(LOG_DEBUG,"Reading digest of %u %u %u %u from relay cell.", +// received_integrity[0], received_integrity[1], +// received_integrity[2], received_integrity[3]); crypto_digest_add_bytes(digest, cell->payload, CELL_PAYLOAD_SIZE); crypto_digest_get_digest(digest, calculated_integrity, 4); if(memcmp(received_integrity, calculated_integrity, 4)) { - log_fn(LOG_INFO,"Recognized=0 but bad digest. Not recognizing."); +// log_fn(LOG_INFO,"Recognized=0 but bad digest. Not recognizing."); // (%d vs %d).", received_integrity, calculated_integrity); /* restore digest to its old form */ crypto_digest_assign(digest, backup_digest); @@ -374,7 +374,7 @@ static int relay_crypt_one_payload(crypto_cipher_env_t *cipher, char *in, relay_header_t rh; relay_header_unpack(&rh, in); - log_fn(LOG_DEBUG,"before crypt: %d",rh.recognized); +// log_fn(LOG_DEBUG,"before crypt: %d",rh.recognized); if(( encrypt_mode && crypto_cipher_encrypt(cipher, in, CELL_PAYLOAD_SIZE, out)) || (!encrypt_mode && crypto_cipher_decrypt(cipher, in, CELL_PAYLOAD_SIZE, out))) { log_fn(LOG_WARN,"Error during crypt: %s", crypto_perror()); @@ -382,7 +382,7 @@ static int relay_crypt_one_payload(crypto_cipher_env_t *cipher, char *in, } memcpy(in,out,CELL_PAYLOAD_SIZE); relay_header_unpack(&rh, in); - log_fn(LOG_DEBUG,"after crypt: %d",rh.recognized); +// log_fn(LOG_DEBUG,"after crypt: %d",rh.recognized); return 0; } @@ -438,7 +438,7 @@ int circuit_receive_relay_cell(cell_t *cell, circuit_t *circ, } if(!conn) { - log_fn(LOG_WARN,"Didn't recognize cell, but circ stops here! Dropping."); + log_fn(LOG_WARN,"Didn't recognize cell, but circ stops here! Closing circ."); return -1; } @@ -462,7 +462,7 @@ static int relay_crypt(circuit_t *circ, cell_t *cell, char cell_direction, We'll want to do layered crypts. */ thishop = circ->cpath; if(thishop->state != CPATH_STATE_OPEN) { - log_fn(LOG_WARN,"Relay cell before first created cell?"); + log_fn(LOG_WARN,"Relay cell before first created cell? Closing."); return -1; } do { /* Remember: cpath is in forward order, that is, first hop first. */ @@ -483,12 +483,12 @@ static int relay_crypt(circuit_t *circ, cell_t *cell, char cell_direction, thishop = thishop->next; } while(thishop != circ->cpath && thishop->state == CPATH_STATE_OPEN); - log_fn(LOG_WARN,"in-cell at OP not recognized. Dropping."); - return 0; + log_fn(LOG_WARN,"in-cell at OP not recognized. Closing."); + return -1; } else { /* we're in the middle. Just one crypt. */ if(relay_crypt_one_payload(circ->p_crypto, cell->payload, 1) < 0) return -1; - log_fn(LOG_DEBUG,"Skipping recognized check, because we're not the OP."); +// log_fn(LOG_DEBUG,"Skipping recognized check, because we're not the OP."); } } else /* cell_direction == CELL_DIRECTION_OUT */ { /* we're in the middle. Just one crypt. */ @@ -510,10 +510,8 @@ static int relay_crypt(circuit_t *circ, cell_t *cell, char cell_direction, /* package a relay cell: - - if from AP: encrypt it to the right conn if 'recognized' doesn't - conflict, else insert dummies first as appropriate - - if from exit: encrypt it - - connection_or_write_cell_to_buf to the right conn + 1) encrypt it to the right conn + 2) connection_or_write_cell_to_buf to the right conn */ int circuit_package_relay_cell(cell_t *cell, circuit_t *circ, @@ -526,7 +524,7 @@ circuit_package_relay_cell(cell_t *cell, circuit_t *circ, if(cell_direction == CELL_DIRECTION_OUT) { conn = circ->n_conn; if(!conn) { - log_fn(LOG_INFO,"outgoing relay cell has n_conn==NULL. Dropping."); + log_fn(LOG_WARN,"outgoing relay cell has n_conn==NULL. Dropping."); return 0; /* just drop it */ } relay_set_digest(layer_hint->f_digest, cell); @@ -547,7 +545,7 @@ circuit_package_relay_cell(cell_t *cell, circuit_t *circ, } else { /* incoming cell */ conn = circ->p_conn; if(!conn) { - log_fn(LOG_INFO,"incoming relay cell has p_conn==NULL. Dropping."); + log_fn(LOG_WARN,"incoming relay cell has p_conn==NULL. Dropping."); return 0; /* just drop it */ } relay_set_digest(circ->p_digest, cell); @@ -580,7 +578,7 @@ relay_lookup_conn(circuit_t *circ, cell_t *cell, int cell_direction) log_fn(LOG_DEBUG,"found conn for stream %d.", rh.stream_id); return tmpconn; } - log_fn(LOG_DEBUG,"considered stream %d, not it.",tmpconn->stream_id); +// log_fn(LOG_DEBUG,"considered stream %d, not it.",tmpconn->stream_id); } return NULL; /* probably a begin relay cell */ } @@ -645,7 +643,7 @@ void circuit_consider_sending_sendme(circuit_t *circ, int edge_type, crypt_path_ circ->deliver_window += CIRCWINDOW_INCREMENT; if(connection_edge_send_command(NULL, circ, RELAY_COMMAND_SENDME, NULL, 0, layer_hint) < 0) { - log_fn(LOG_WARN,"connection_edge_send_command failed. Returning."); + log_fn(LOG_WARN,"connection_edge_send_command failed. Circuit's closed."); return; /* the circuit's closed, don't continue */ } } @@ -942,7 +940,7 @@ void circuit_n_conn_open(connection_t *or_conn) { log_fn(LOG_INFO,"send_next_onion_skin failed; circuit marked for closing."); circuit_close(circ); continue; - /* XXX could this be bad, eg if next_onion_skin failed because conn died? */ + /* XXX could this be bad, eg if next_onion_skin failed because conn died? */ } } } @@ -1038,11 +1036,11 @@ int circuit_extend(cell_t *cell, circuit_t *circ) { n_conn = connection_twin_get_by_addr_port(circ->n_addr,circ->n_port); if(!n_conn || n_conn->type != CONN_TYPE_OR) { - /* i've disabled making connections through OPs, but it's definitely - * possible here. I'm not sure if it would be a bug or a feature. -RD - */ - /* 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 + /* I've disabled making connections through OPs, but it's definitely + * possible here. I'm not sure if it would be a bug or a feature. + * + * 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. */ struct in_addr in; in.s_addr = htonl(circ->n_addr); @@ -1060,7 +1058,7 @@ int circuit_extend(cell_t *cell, circuit_t *circ) { circ_id_type = decide_circ_id_type(options.Nickname, n_conn->nickname); - log_fn(LOG_DEBUG,"circ_id_type = %u.",circ_id_type); +// log_fn(LOG_DEBUG,"circ_id_type = %u.",circ_id_type); circ->n_circ_id = get_unique_circ_id_by_conn(circ->n_conn, circ_id_type); if(!circ->n_circ_id) { log_fn(LOG_WARN,"failed to get unique circID."); @@ -1108,7 +1106,7 @@ int circuit_finish_handshake(circuit_t *circ, char *reply) { crypto_dh_free(hop->handshake_state); /* don't need it anymore */ hop->handshake_state = NULL; - log_fn(LOG_INFO,"hop init digest forward %u, backward %u.", + log_fn(LOG_DEBUG,"hop init digest forward %u, backward %u.", (unsigned)*(uint32_t*)keys, (unsigned)*(uint32_t*)(keys+20)); hop->f_digest = crypto_new_digest_env(CRYPTO_SHA1_DIGEST); crypto_digest_add_bytes(hop->f_digest, keys, 20); @@ -1130,7 +1128,7 @@ int circuit_finish_handshake(circuit_t *circ, char *reply) { hop->state = CPATH_STATE_OPEN; log_fn(LOG_INFO,"finished"); - circuit_log_path(LOG_WARN,circ); + circuit_log_path(LOG_INFO,circ); return 0; } diff --git a/src/or/command.c b/src/or/command.c index 0a3b91843f..cebf5cc26c 100644 --- a/src/or/command.c +++ b/src/or/command.c @@ -32,7 +32,7 @@ static void command_time_process_cell(cell_t *cell, connection_t *conn, tor_gettimeofday(&end); time_passed = tv_udiff(&start, &end) ; - if (time_passed > 5000) { /* more than 5ms */ + if (time_passed > 10000) { /* more than 10ms */ log_fn(LOG_INFO,"That call just took %ld ms.",time_passed/1000); } *time += time_passed; @@ -112,7 +112,7 @@ static void command_process_create_cell(cell_t *cell, connection_t *conn) { circuit_close(circ); return; } - log_fn(LOG_INFO,"success: handed off onionskin."); + log_fn(LOG_DEBUG,"success: handed off onionskin."); } static void command_process_created_cell(cell_t *cell, connection_t *conn) { @@ -145,7 +145,7 @@ static void command_process_created_cell(cell_t *cell, connection_t *conn) { return; } } else { /* pack it into an extended relay cell, and send it. */ - log_fn(LOG_INFO,"Converting created cell to extended relay cell, sending."); + log_fn(LOG_DEBUG,"Converting created cell to extended relay cell, sending."); connection_edge_send_command(NULL, circ, RELAY_COMMAND_EXTENDED, cell->payload, ONIONSKIN_REPLY_LEN, NULL); } diff --git a/src/or/config.c b/src/or/config.c index 0b75f74404..f540b1e55e 100644 --- a/src/or/config.c +++ b/src/or/config.c @@ -441,6 +441,7 @@ int getconfig(int argc, char **argv, or_options_t *options) { if(!cf) { if(using_default_torrc == 1) { log(LOG_WARN, "Configuration file '%s' not found. Using defaults.",fname); + /* XXX change this WARN to INFO once we start using this feature */ if(config_assign_default(options) < 0) return -1; } else { diff --git a/src/or/connection.c b/src/or/connection.c index ed96ed482e..3b1f6d9631 100644 --- a/src/or/connection.c +++ b/src/or/connection.c @@ -407,8 +407,8 @@ int connection_handle_read(connection_t *conn) { if(connection_read_to_buf(conn) < 0) { if(conn->type == CONN_TYPE_DIR && - (conn->state == DIR_CONN_STATE_CONNECTING_FETCH || - conn->state == DIR_CONN_STATE_CONNECTING_UPLOAD)) { + (conn->state == DIR_CONN_STATE_CONNECTING_FETCH || + conn->state == DIR_CONN_STATE_CONNECTING_UPLOAD)) { /* it's a directory server and connecting failed: forget about this router */ /* XXX I suspect pollerr may make Windows not get to this point. :( */ router_mark_as_down(conn->nickname); @@ -512,10 +512,7 @@ int connection_outbuf_too_full(connection_t *conn) { /* return -1 if you want to break the conn, else return 0 */ int connection_handle_write(connection_t *conn) { - if(connection_is_listener(conn)) { - log_fn(LOG_WARN,"Got a listener socket. Can't happen!"); - return -1; - } + assert(!connection_is_listener(conn)); conn->timestamp_lastwritten = time(NULL); @@ -631,7 +628,7 @@ connection_t *connection_twin_get_by_addr_port(uint32_t addr, uint16_t port) { /* first check if it's there exactly */ conn = connection_exact_get_by_addr_port(addr,port); if(conn && connection_state_is_open(conn)) { - log(LOG_INFO,"connection_twin_get_by_addr_port(): Found exact match."); + log(LOG_DEBUG,"connection_twin_get_by_addr_port(): Found exact match."); return conn; } @@ -647,7 +644,7 @@ connection_t *connection_twin_get_by_addr_port(uint32_t addr, uint16_t port) { assert(conn); if(connection_state_is_open(conn) && !crypto_pk_cmp_keys(conn->onion_pkey, router->onion_pkey)) { - log(LOG_INFO,"connection_twin_get_by_addr_port(): Found twin (%s).",conn->address); + log(LOG_DEBUG,"connection_twin_get_by_addr_port(): Found twin (%s).",conn->address); return conn; } } @@ -808,7 +805,7 @@ void assert_connection_ok(connection_t *conn, time_t now) { assert(conn); assert(conn->magic == CONNECTION_MAGIC); - return; + return; /* XXX !!! */ assert(conn->type >= _CONN_TYPE_MIN); assert(conn->type <= _CONN_TYPE_MAX); diff --git a/src/or/connection_edge.c b/src/or/connection_edge.c index ef07107c8c..2bba8f6ad2 100644 --- a/src/or/connection_edge.c +++ b/src/or/connection_edge.c @@ -145,7 +145,7 @@ int connection_edge_send_command(connection_t *fromconn, circuit_t *circ, int re int cell_direction; if(!circ) { - log_fn(LOG_WARN,"no circ. Closing."); + log_fn(LOG_WARN,"no circ. Closing conn."); assert(fromconn); connection_mark_for_close(fromconn, 0); return -1; @@ -212,15 +212,15 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection log_fn(LOG_WARN,"Got 'connected' while not in state connecting. Dropping."); return 0; } - log_fn(LOG_INFO,"Connected! Notifying application."); +// log_fn(LOG_INFO,"Connected! Notifying application."); conn->state = AP_CONN_STATE_OPEN; if (rh.length >= 4) { addr = ntohl(*(uint32_t*)(cell->payload + RELAY_HEADER_SIZE)); client_dns_set_entry(conn->socks_request->address, addr); } - log_fn(LOG_WARN,"'connected' received after %d seconds.", + log_fn(LOG_INFO,"'connected' received after %d seconds.", (int)(time(NULL) - conn->timestamp_lastread)); - circuit_log_path(LOG_WARN,circ); + circuit_log_path(LOG_INFO,circ); if(connection_ap_handshake_socks_reply(conn, NULL, 0, 1) < 0) { log_fn(LOG_INFO,"Writing to socks-speaking application failed. Closing."); connection_mark_for_close(conn, END_STREAM_REASON_MISC); @@ -357,8 +357,12 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection circuit_truncated(circ, layer_hint); return 0; case RELAY_COMMAND_CONNECTED: - log_fn(LOG_WARN,"'connected' unsupported while open. Closing."); - return -1; + if(conn) { + log_fn(LOG_WARN,"'connected' unsupported while open. Closing conn."); + return -1; + } + log_fn(LOG_INFO,"'connected' received, no conn attached anymore. Ignoring."); + return 0; case RELAY_COMMAND_SENDME: if(!conn) { if(edge_type == EDGE_AP) { @@ -562,7 +566,7 @@ void connection_ap_attach_pending(void) conn->state != AP_CONN_STATE_CIRCUIT_WAIT) continue; if(connection_ap_handshake_attach_circuit(conn) < 0) { - /* it will never work */ + /* -1 means it will never work */ /* Don't send end; there is no 'other end' of the stream */ connection_mark_for_close(conn,0); } @@ -661,7 +665,7 @@ static int connection_ap_handshake_attach_circuit_helper(connection_t *conn) { log_fn(LOG_INFO,"No safe circuit ready for edge connection; delaying."); addr = client_dns_lookup_entry(conn->socks_request->address); if(router_exit_policy_all_routers_reject(addr, conn->socks_request->port)) { - log_fn(LOG_WARN,"No node exists that will handle exit to %s:%d. Rejecting.", + log_fn(LOG_WARN,"No Tor server exists that allows exit to %s:%d. Rejecting.", conn->socks_request->address, conn->socks_request->port); return -1; } @@ -672,7 +676,7 @@ static int connection_ap_handshake_attach_circuit_helper(connection_t *conn) { connection_start_reading(conn); /* here, print the circ's path. so people can figure out which circs are sucking. */ - circuit_log_path(LOG_WARN,circ); + circuit_log_path(LOG_INFO,circ); if(!circ->timestamp_dirty) circ->timestamp_dirty = time(NULL); @@ -980,6 +984,7 @@ static uint32_t client_dns_lookup_entry(const char *address) return ent->addr; } } + static void client_dns_set_entry(const char *address, uint32_t val) { struct client_dns_entry *ent; |