diff options
Diffstat (limited to 'src')
-rw-r--r-- | src/or/buffers.c | 178 | ||||
-rw-r--r-- | src/or/circuitbuild.c | 230 | ||||
-rw-r--r-- | src/or/circuitlist.c | 31 | ||||
-rw-r--r-- | src/or/circuituse.c | 196 | ||||
-rw-r--r-- | src/or/command.c | 61 |
5 files changed, 368 insertions, 328 deletions
diff --git a/src/or/buffers.c b/src/or/buffers.c index 0a1c3de8d..71a018595 100644 --- a/src/or/buffers.c +++ b/src/or/buffers.c @@ -88,7 +88,7 @@ buf_normalize(buf_t *buf) } else { char *newmem, *oldmem; size_t sz = (buf->mem+buf->len)-buf->cur; - warn(LD_BUG, "Unexpected non-normalized buffer."); + log_warn(LD_BUG, "Unexpected non-normalized buffer."); newmem = GUARDED_MEM(tor_malloc(ALLOC_LEN(buf->len))); SET_GUARDS(newmem, buf->len); memcpy(newmem, buf->cur, sz); @@ -262,8 +262,8 @@ buf_ensure_capacity(buf_t *buf, size_t capacity) while (new_len < capacity) new_len *= 2; /* Resize the buffer. */ - debug(LD_MM,"Growing buffer from %d to %d bytes.", - (int)buf->len, (int)new_len); + log_debug(LD_MM,"Growing buffer from %d to %d bytes.", + (int)buf->len, (int)new_len); buf_resize(buf,new_len); return 0; } @@ -287,8 +287,8 @@ buf_shrink(buf_t *buf) if (new_len == buf->len) return; - debug(LD_MM,"Shrinking buffer from %d to %d bytes.", - (int)buf->len, (int)new_len); + log_debug(LD_MM,"Shrinking buffer from %d to %d bytes.", + (int)buf->len, (int)new_len); buf_resize(buf, new_len); } @@ -407,7 +407,7 @@ read_to_buf_impl(int s, size_t at_most, buf_t *buf, } return 0; /* would block. */ } else if (read_result == 0) { - debug(LD_NET,"Encountered eof"); + log_debug(LD_NET,"Encountered eof"); *reached_eof = 1; return 0; } else { /* we read some bytes */ @@ -415,8 +415,8 @@ read_to_buf_impl(int s, size_t at_most, buf_t *buf, buf_total_used += read_result; if (buf->datalen > buf->highwater) buf->highwater = buf->datalen; - debug(LD_NET,"Read %d bytes. %d on inbuf.",read_result, - (int)buf->datalen); + log_debug(LD_NET,"Read %d bytes. %d on inbuf.",read_result, + (int)buf->datalen); return read_result; } } @@ -481,9 +481,9 @@ read_to_buf_tls_impl(tor_tls_t *tls, size_t at_most, buf_t *buf, char *next) { int r; - debug(LD_NET,"before: %d on buf, %d pending, at_most %d.", - (int)buf_datalen(buf), (int)tor_tls_get_pending_bytes(tls), - (int)at_most); + log_debug(LD_NET,"before: %d on buf, %d pending, at_most %d.", + (int)buf_datalen(buf), (int)tor_tls_get_pending_bytes(tls), + (int)at_most); r = tor_tls_read(tls, next, at_most); if (r<0) return r; @@ -491,8 +491,8 @@ read_to_buf_tls_impl(tor_tls_t *tls, size_t at_most, buf_t *buf, char *next) buf_total_used += r; if (buf->datalen > buf->highwater) buf->highwater = buf->datalen; - debug(LD_NET,"Read %d bytes. %d on inbuf; %d pending",r, - (int)buf->datalen,(int)tor_tls_get_pending_bytes(tls)); + log_debug(LD_NET,"Read %d bytes. %d on inbuf; %d pending",r, + (int)buf->datalen,(int)tor_tls_get_pending_bytes(tls)); return r; } @@ -525,9 +525,9 @@ read_to_buf_tls(tor_tls_t *tls, size_t at_most, buf_t *buf) tor_assert(tls); assert_buf_ok(buf); - debug(LD_NET,"start: %d on buf, %d pending, at_most %d.", - (int)buf_datalen(buf), (int)tor_tls_get_pending_bytes(tls), - (int)at_most); + log_debug(LD_NET,"start: %d on buf, %d pending, at_most %d.", + (int)buf_datalen(buf), (int)tor_tls_get_pending_bytes(tls), + (int)at_most); if (buf_ensure_capacity(buf, at_most+buf->datalen)) return TOR_TLS_ERROR; @@ -575,7 +575,7 @@ flush_buf_impl(int s, buf_t *buf, size_t sz, size_t *buf_flushlen) if (!ERRNO_IS_EAGAIN(e)) { /* it's a real error */ return -1; } - debug(LD_NET,"write() would block, returning."); + log_debug(LD_NET,"write() would block, returning."); return 0; } else { *buf_flushlen -= write_result; @@ -612,8 +612,8 @@ flush_buf(int s, buf_t *buf, size_t sz, size_t *buf_flushlen) r = flush_buf_impl(s, buf, flushlen0, buf_flushlen); check(); - debug(LD_NET,"%d: flushed %d bytes, %d ready to flush, %d remain.", - s,r,(int)*buf_flushlen,(int)buf->datalen); + log_debug(LD_NET,"%d: flushed %d bytes, %d ready to flush, %d remain.", + s,r,(int)*buf_flushlen,(int)buf->datalen); if (r < 0 || (size_t)r < flushlen0) return r; /* Error, or can't flush any more now. */ flushed = r; @@ -622,8 +622,8 @@ flush_buf(int s, buf_t *buf, size_t sz, size_t *buf_flushlen) tor_assert(buf->cur == buf->mem); r = flush_buf_impl(s, buf, flushlen1, buf_flushlen); check(); - debug(LD_NET,"%d: flushed %d bytes, %d ready to flush, %d remain.", - s,r,(int)*buf_flushlen,(int)buf->datalen); + log_debug(LD_NET,"%d: flushed %d bytes, %d ready to flush, %d remain.", + s,r,(int)*buf_flushlen,(int)buf->datalen); if (r<0) return r; flushed += r; @@ -647,8 +647,8 @@ flush_buf_tls_impl(tor_tls_t *tls, buf_t *buf, size_t sz, size_t *buf_flushlen) } *buf_flushlen -= r; buf_remove_from_front(buf, r); - debug(LD_NET,"flushed %d bytes, %d ready to flush, %d remain.", - r,(int)*buf_flushlen,(int)buf->datalen); + log_debug(LD_NET,"flushed %d bytes, %d ready to flush, %d remain.", + r,(int)*buf_flushlen,(int)buf->datalen); return r; } @@ -709,8 +709,8 @@ write_to_buf(const char *string, size_t string_len, buf_t *buf) /* assert_buf_ok(buf); */ if (buf_ensure_capacity(buf, buf->datalen+string_len)) { - warn(LD_MM, "buflen too small, can't hold %d bytes.", - (int)(buf->datalen+string_len)); + log_warn(LD_MM, "buflen too small, can't hold %d bytes.", + (int)(buf->datalen+string_len)); return -1; } @@ -729,8 +729,8 @@ write_to_buf(const char *string, size_t string_len, buf_t *buf) } if (buf->datalen > buf->highwater) buf->highwater = buf->datalen; - debug(LD_NET,"added %d bytes to buf (now %d total).", - (int)string_len, (int)buf->datalen); + log_debug(LD_NET,"added %d bytes to buf (now %d total).", + (int)string_len, (int)buf->datalen); check(); return buf->datalen; } @@ -812,28 +812,28 @@ fetch_from_buf_http(buf_t *buf, buf_normalize(buf); if (buf_nul_terminate(buf)<0) { - warn(LD_BUG,"Couldn't nul-terminate buffer"); + log_warn(LD_BUG,"Couldn't nul-terminate buffer"); return -1; } headers = buf->cur; body = strstr(headers,"\r\n\r\n"); if (!body) { - debug(LD_HTTP,"headers not all here yet."); + log_debug(LD_HTTP,"headers not all here yet."); return 0; } body += 4; /* Skip the the CRLFCRLF */ headerlen = body-headers; /* includes the CRLFCRLF */ bodylen = buf->datalen - headerlen; - debug(LD_HTTP,"headerlen %d, bodylen %d.", (int)headerlen, (int)bodylen); + log_debug(LD_HTTP,"headerlen %d, bodylen %d.", (int)headerlen, (int)bodylen); if (max_headerlen <= headerlen) { - warn(LD_HTTP,"headerlen %d larger than %d. Failing.", - (int)headerlen, (int)max_headerlen-1); + log_warn(LD_HTTP,"headerlen %d larger than %d. Failing.", + (int)headerlen, (int)max_headerlen-1); return -1; } if (max_bodylen <= bodylen) { - warn(LD_HTTP,"bodylen %d larger than %d. Failing.", - (int)bodylen, (int)max_bodylen-1); + log_warn(LD_HTTP,"bodylen %d larger than %d. Failing.", + (int)bodylen, (int)max_bodylen-1); return -1; } @@ -843,22 +843,22 @@ fetch_from_buf_http(buf_t *buf, int i; i = atoi(p+strlen(CONTENT_LENGTH)); if (i < 0) { - warn(LD_PROTOCOL, "Content-Length is less than zero; it looks like " - "someone is trying to crash us."); + log_warn(LD_PROTOCOL, "Content-Length is less than zero; it looks like " + "someone is trying to crash us."); return -1; } contentlen = i; /* if content-length is malformed, then our body length is 0. fine. */ - debug(LD_HTTP,"Got a contentlen of %d.",(int)contentlen); + log_debug(LD_HTTP,"Got a contentlen of %d.",(int)contentlen); if (bodylen < contentlen) { if (!force_complete) { - debug(LD_HTTP,"body not all here yet."); + log_debug(LD_HTTP,"body not all here yet."); return 0; /* not all there yet */ } } if (bodylen > contentlen) { bodylen = contentlen; - debug(LD_HTTP,"bodylen reduced to %d.",(int)bodylen); + log_debug(LD_HTTP,"bodylen reduced to %d.",(int)bodylen); } } /* all happy. copy into the appropriate places, and return 1 */ @@ -929,8 +929,9 @@ fetch_from_buf_socks(buf_t *buf, socks_request_t *req, int log_sockstype) if (buf->datalen < 2u+nummethods) return 0; if (!nummethods || !memchr(buf->cur+2, 0, nummethods)) { - warn(LD_APP, - "socks5: offered methods don't include 'no auth'. Rejecting."); + log_warn(LD_APP, + "socks5: offered methods don't include 'no auth'. " + "Rejecting."); req->replylen = 2; /* 2 bytes of response */ req->reply[0] = 5; req->reply[1] = '\xFF'; /* reject all methods */ @@ -942,24 +943,24 @@ fetch_from_buf_socks(buf_t *buf, socks_request_t *req, int log_sockstype) req->reply[0] = 5; /* socks5 reply */ req->reply[1] = SOCKS5_SUCCEEDED; req->socks_version = 5; /* remember we've already negotiated auth */ - debug(LD_APP,"socks5: accepted method 0"); + log_debug(LD_APP,"socks5: accepted method 0"); return 0; } /* we know the method; read in the request */ - debug(LD_APP,"socks5: checking request"); + log_debug(LD_APP,"socks5: checking request"); if (buf->datalen < 8) /* basic info plus >=2 for addr plus 2 for port */ return 0; /* not yet */ req->command = (unsigned char) *(buf->cur+1); if (req->command != SOCKS_COMMAND_CONNECT && req->command != SOCKS_COMMAND_RESOLVE) { /* not a connect or resolve? we don't support it. */ - warn(LD_APP,"socks5: command %d not recognized. Rejecting.", - req->command); + log_warn(LD_APP,"socks5: command %d not recognized. Rejecting.", + req->command); return -1; } switch (*(buf->cur+3)) { /* address type */ case 1: /* IPv4 address */ - debug(LD_APP,"socks5: ipv4 address type"); + log_debug(LD_APP,"socks5: ipv4 address type"); if (buf->datalen < 10) /* ip/port there? */ return 0; /* not yet */ @@ -967,9 +968,10 @@ fetch_from_buf_socks(buf_t *buf, socks_request_t *req, int log_sockstype) in.s_addr = htonl(destip); tor_inet_ntoa(&in,tmpbuf,sizeof(tmpbuf)); if (strlen(tmpbuf)+1 > MAX_SOCKS_ADDR_LEN) { - warn(LD_APP, - "socks5 IP takes %d bytes, which doesn't fit in %d. Rejecting.", - (int)strlen(tmpbuf)+1,(int)MAX_SOCKS_ADDR_LEN); + log_warn(LD_APP, + "socks5 IP takes %d bytes, which doesn't fit in %d. " + "Rejecting.", + (int)strlen(tmpbuf)+1,(int)MAX_SOCKS_ADDR_LEN); return -1; } strlcpy(req->address,tmpbuf,sizeof(req->address)); @@ -977,23 +979,25 @@ fetch_from_buf_socks(buf_t *buf, socks_request_t *req, int log_sockstype) buf_remove_from_front(buf, 10); if (!address_is_in_virtual_range(req->address) && !have_warned_about_unsafe_socks) { - warn(LD_APP,"Your application (using socks5 on port %d) is giving " - "Tor only an IP address. Applications that do DNS resolves " - "themselves may leak information. Consider using Socks4A " - "(e.g. via privoxy or socat) instead. For more information, " - "please see http://wiki.noreply.org/noreply/TheOnionRouter/" - "TorFAQ#SOCKSAndDNS", req->port); + log_warn(LD_APP, + "Your application (using socks5 on port %d) is giving " + "Tor only an IP address. Applications that do DNS resolves " + "themselves may leak information. Consider using Socks4A " + "(e.g. via privoxy or socat) instead. For more information, " + "please see http://wiki.noreply.org/noreply/TheOnionRouter/" + "TorFAQ#SOCKSAndDNS", req->port); // have_warned_about_unsafe_socks = 1; // (for now, warn every time) } return 1; case 3: /* fqdn */ - debug(LD_APP,"socks5: fqdn address type"); + log_debug(LD_APP,"socks5: fqdn address type"); len = (unsigned char)*(buf->cur+4); if (buf->datalen < 7u+len) /* addr/port there? */ return 0; /* not yet */ if (len+1 > MAX_SOCKS_ADDR_LEN) { - warn(LD_APP, "socks5 hostname is %d bytes, which doesn't fit in " - "%d. Rejecting.", len+1,MAX_SOCKS_ADDR_LEN); + log_warn(LD_APP, + "socks5 hostname is %d bytes, which doesn't fit in " + "%d. Rejecting.", len+1,MAX_SOCKS_ADDR_LEN); return -1; } memcpy(req->address,buf->cur+5,len); @@ -1001,13 +1005,14 @@ fetch_from_buf_socks(buf_t *buf, socks_request_t *req, int log_sockstype) req->port = ntohs(get_uint16(buf->cur+5+len)); buf_remove_from_front(buf, 5+len+2); if (log_sockstype) - notice(LD_APP, "Your application (using socks5 on port %d) gave " - "Tor a hostname, which means Tor will do the DNS resolve " - "for you. This is good.", req->port); + log_notice(LD_APP, + "Your application (using socks5 on port %d) gave " + "Tor a hostname, which means Tor will do the DNS resolve " + "for you. This is good.", req->port); return 1; default: /* unsupported */ - warn(LD_APP,"socks5: unsupported address type %d. Rejecting.", - *(buf->cur+3)); + log_warn(LD_APP,"socks5: unsupported address type %d. Rejecting.", + *(buf->cur+3)); return -1; } tor_assert(0); @@ -1023,34 +1028,35 @@ fetch_from_buf_socks(buf_t *buf, socks_request_t *req, int log_sockstype) if (req->command != SOCKS_COMMAND_CONNECT && req->command != SOCKS_COMMAND_RESOLVE) { /* not a connect or resolve? we don't support it. */ - warn(LD_APP,"socks4: command %d not recognized. Rejecting.", - req->command); + log_warn(LD_APP,"socks4: command %d not recognized. Rejecting.", + req->command); return -1; } req->port = ntohs(*(uint16_t*)(buf->cur+2)); destip = ntohl(*(uint32_t*)(buf->mem+4)); if ((!req->port && req->command!=SOCKS_COMMAND_RESOLVE) || !destip) { - warn(LD_APP,"socks4: Port or DestIP is zero. Rejecting."); + log_warn(LD_APP,"socks4: Port or DestIP is zero. Rejecting."); return -1; } if (destip >> 8) { - debug(LD_APP,"socks4: destip not in form 0.0.0.x."); + log_debug(LD_APP,"socks4: destip not in form 0.0.0.x."); in.s_addr = htonl(destip); tor_inet_ntoa(&in,tmpbuf,sizeof(tmpbuf)); if (strlen(tmpbuf)+1 > MAX_SOCKS_ADDR_LEN) { - debug(LD_APP,"socks4 addr (%d bytes) too long. Rejecting.", - (int)strlen(tmpbuf)); + log_debug(LD_APP,"socks4 addr (%d bytes) too long. Rejecting.", + (int)strlen(tmpbuf)); return -1; } - debug(LD_APP,"socks4: successfully read destip (%s)",safe_str(tmpbuf)); + log_debug(LD_APP, + "socks4: successfully read destip (%s)",safe_str(tmpbuf)); socks4_prot = socks4; } next = memchr(buf->cur+SOCKS4_NETWORK_LEN, 0, buf->datalen-SOCKS4_NETWORK_LEN); if (!next) { - debug(LD_APP,"socks4: Username not here yet."); + log_debug(LD_APP,"socks4: Username not here yet."); return 0; } tor_assert(next < buf->cur+buf->datalen); @@ -1059,34 +1065,36 @@ fetch_from_buf_socks(buf_t *buf, socks_request_t *req, int log_sockstype) if (socks4_prot != socks4a && !address_is_in_virtual_range(tmpbuf) && !have_warned_about_unsafe_socks) { - warn(LD_APP,"Your application (using socks4 on port %d) is giving Tor " - "only an IP address. Applications that do DNS resolves " - "themselves may leak information. Consider using Socks4A (e.g. " - "via privoxy or socat) instead.", req->port); + log_warn(LD_APP, + "Your application (using socks4 on port %d) is giving Tor " + "only an IP address. Applications that do DNS resolves " + "themselves may leak information. Consider using Socks4A " + "(e.g. via privoxy or socat) instead.", req->port); // have_warned_about_unsafe_socks = 1; // (for now, warn every time) } if (socks4_prot == socks4a) { if (next+1 == buf->cur+buf->datalen) { - debug(LD_APP,"socks4: No part of destaddr here yet."); + log_debug(LD_APP,"socks4: No part of destaddr here yet."); return 0; } startaddr = next+1; next = memchr(startaddr, 0, buf->cur+buf->datalen-startaddr); if (!next) { - debug(LD_APP,"socks4: Destaddr not all here yet."); + log_debug(LD_APP,"socks4: Destaddr not all here yet."); return 0; } if (MAX_SOCKS_ADDR_LEN <= next-startaddr) { - warn(LD_APP,"socks4: Destaddr too long. Rejecting."); + log_warn(LD_APP,"socks4: Destaddr too long. Rejecting."); return -1; } tor_assert(next < buf->cur+buf->datalen); if (log_sockstype) - notice(LD_APP, "Your application (using socks4a on port %d) gave " - "Tor a hostname, which means Tor will do the DNS resolve " - "for you. This is good.", req->port); + log_notice(LD_APP, + "Your application (using socks4a on port %d) gave " + "Tor a hostname, which means Tor will do the DNS resolve " + "for you. This is good.", req->port); } - debug(LD_APP,"socks4: Everything is here. Success."); + log_debug(LD_APP,"socks4: Everything is here. Success."); strlcpy(req->address, startaddr ? startaddr : tmpbuf, sizeof(req->address)); /* next points to the final \0 on inbuf */ @@ -1125,9 +1133,9 @@ fetch_from_buf_socks(buf_t *buf, socks_request_t *req, int log_sockstype) req->replylen = strlen(req->reply)+1; /* fall through */ default: /* version is not socks4 or socks5 */ - warn(LD_APP, - "Socks version %d not recognized. (Tor is not an http proxy.)", - *(buf->cur)); + log_warn(LD_APP, + "Socks version %d not recognized. (Tor is not an http proxy.)", + *(buf->cur)); return -1; } } diff --git a/src/or/circuitbuild.c b/src/or/circuitbuild.c index c67d29d14..c007fe168 100644 --- a/src/or/circuitbuild.c +++ b/src/or/circuitbuild.c @@ -82,7 +82,7 @@ get_unique_circ_id_by_conn(connection_t *conn) /* Make sure we don't loop forever if all circ_id's are used. This * matters because it's an external DoS opportunity. */ - warn(LD_CIRC,"No unused circ IDs. Failing."); + log_warn(LD_CIRC,"No unused circ IDs. Failing."); return 0; } test_circ_id |= high_bit; @@ -275,7 +275,7 @@ again: r = onion_extend_cpath(circ->purpose, &circ->cpath, circ->build_state); // || !CIRCUIT_IS_ORIGIN(circ)) { // wtf? -rd if (r < 0) { - info(LD_CIRC,"Generating cpath hop failed."); + log_info(LD_CIRC,"Generating cpath hop failed."); return -1; } if (r == 0) @@ -348,8 +348,8 @@ circuit_handle_first_hop(circuit_t *circ) /* now see if we're already connected to the first OR in 'route' */ in.s_addr = htonl(firsthop->extend_info->addr); tor_inet_ntoa(&in, tmpbuf, sizeof(tmpbuf)); - debug(LD_CIRC,"Looking for firsthop '%s:%u'",tmpbuf, - firsthop->extend_info->port); + log_debug(LD_CIRC,"Looking for firsthop '%s:%u'",tmpbuf, + firsthop->extend_info->port); /* imprint the circuit with its future n_conn->id */ memcpy(circ->n_conn_id_digest, firsthop->extend_info->identity_digest, DIGEST_LEN); @@ -371,12 +371,12 @@ circuit_handle_first_hop(circuit_t *circ) firsthop->extend_info->port, firsthop->extend_info->identity_digest); if (!n_conn) { /* connect failed, forget the whole thing */ - info(LD_CIRC,"connect to firsthop failed. Closing."); + log_info(LD_CIRC,"connect to firsthop failed. Closing."); return -1; } } - debug(LD_CIRC,"connecting in progress (or finished). Good."); + log_debug(LD_CIRC,"connecting in progress (or finished). Good."); /* return success. The onion/circuit/etc will be taken care of * automatically (may already have been) whenever n_conn reaches * OR_CONN_STATE_OPEN. @@ -386,9 +386,9 @@ circuit_handle_first_hop(circuit_t *circ) circ->n_addr = n_conn->addr; circ->n_port = n_conn->port; circ->n_conn = n_conn; - debug(LD_CIRC,"Conn open. Delivering first onion skin."); + log_debug(LD_CIRC,"Conn open. Delivering first onion skin."); if (circuit_send_next_onion_skin(circ) < 0) { - info(LD_CIRC,"circuit_send_next_onion_skin failed."); + log_info(LD_CIRC,"circuit_send_next_onion_skin failed."); return -1; } } @@ -405,8 +405,8 @@ circuit_n_conn_done(connection_t *or_conn, int status) { extern smartlist_t *circuits_pending_or_conns; - debug(LD_CIRC,"or_conn to %s, status=%d", - or_conn->nickname ? or_conn->nickname : "NULL", status); + log_debug(LD_CIRC,"or_conn to %s, status=%d", + or_conn->nickname ? or_conn->nickname : "NULL", status); if (!circuits_pending_or_conns) return; @@ -422,19 +422,20 @@ circuit_n_conn_done(connection_t *or_conn, int status) !memcmp(or_conn->identity_digest, circ->n_conn_id_digest, DIGEST_LEN)) { if (!status) { /* or_conn failed; close circ */ - info(LD_CIRC,"or_conn failed. Closing circ."); + log_info(LD_CIRC,"or_conn failed. Closing circ."); circuit_mark_for_close(circ, END_CIRC_REASON_OR_IDENTITY); continue; } - debug(LD_CIRC,"Found circ %d, sending create cell.", circ->n_circ_id); + log_debug(LD_CIRC, + "Found circ %d, sending create cell.", circ->n_circ_id); /* circuit_deliver_create_cell will set n_circ_id and add us to * orconn_circuid_circuit_map, so we don't need to call * set_circid_orconn here. */ circ->n_conn = or_conn; if (CIRCUIT_IS_ORIGIN(circ)) { if (circuit_send_next_onion_skin(circ) < 0) { - info(LD_CIRC, - "send_next_onion_skin failed; circuit marked for closing."); + log_info(LD_CIRC, + "send_next_onion_skin failed; circuit marked for closing."); circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN); continue; /* XXX could this be bad, eg if next_onion_skin failed because conn @@ -475,10 +476,10 @@ circuit_deliver_create_cell(circuit_t *circ, uint8_t cell_type, char *payload) id = get_unique_circ_id_by_conn(circ->n_conn); if (!id) { - warn(LD_CIRC,"failed to get unique circID."); + log_warn(LD_CIRC,"failed to get unique circID."); return -1; } - debug(LD_CIRC,"Chosen circID %u.", id); + log_debug(LD_CIRC,"Chosen circID %u.", id); circuit_set_circid_orconn(circ, id, circ->n_conn, N_CONN_CHANGED); memset(&cell, 0, sizeof(cell_t)); @@ -557,7 +558,7 @@ circuit_send_next_onion_skin(circuit_t *circ) if (circ->cpath->state == CPATH_STATE_CLOSED) { int fast; uint8_t cell_type; - debug(LD_CIRC,"First skin; sending create cell."); + log_debug(LD_CIRC,"First skin; sending create cell."); router = router_get_by_digest(circ->n_conn->identity_digest); fast = should_use_create_fast_for_router(router); @@ -569,7 +570,7 @@ circuit_send_next_onion_skin(circuit_t *circ) if (onion_skin_create(circ->cpath->extend_info->onion_key, &(circ->cpath->dh_handshake_state), payload) < 0) { - warn(LD_CIRC,"onion_skin_create (first hop) failed."); + log_warn(LD_CIRC,"onion_skin_create (first hop) failed."); return - END_CIRC_REASON_INTERNAL; } } else { @@ -589,18 +590,18 @@ circuit_send_next_onion_skin(circuit_t *circ) circ->cpath->state = CPATH_STATE_AWAITING_KEYS; circuit_set_state(circ, CIRCUIT_STATE_BUILDING); - info(LD_CIRC,"First hop: finished sending %s cell to '%s'", - fast ? "CREATE_FAST" : "CREATE", - router ? router->nickname : "<unnamed>"); + log_info(LD_CIRC,"First hop: finished sending %s cell to '%s'", + fast ? "CREATE_FAST" : "CREATE", + router ? router->nickname : "<unnamed>"); } else { tor_assert(circ->cpath->state == CPATH_STATE_OPEN); tor_assert(circ->state == CIRCUIT_STATE_BUILDING); - debug(LD_CIRC,"starting to send subsequent skin."); + log_debug(LD_CIRC,"starting to send subsequent skin."); hop = onion_next_hop_in_cpath(circ->cpath); if (!hop) { /* done building the circuit. whew. */ circuit_set_state(circ, CIRCUIT_STATE_OPEN); - info(LD_CIRC,"circuit built!"); + log_info(LD_CIRC,"circuit built!"); circuit_reset_failure_count(0); if (!has_completed_circuit) { or_options_t *options = get_options(); @@ -628,11 +629,11 @@ circuit_send_next_onion_skin(circuit_t *circ) if (onion_skin_create(hop->extend_info->onion_key, &(hop->dh_handshake_state), onionskin) < 0) { - warn(LD_CIRC,"onion_skin_create failed."); + log_warn(LD_CIRC,"onion_skin_create failed."); return - END_CIRC_REASON_INTERNAL; } - debug(LD_CIRC,"Sending extend relay cell."); + log_debug(LD_CIRC,"Sending extend relay cell."); /* send it to hop->prev, because it will transfer * it to a create cell and then send to hop */ if (connection_edge_send_command(NULL, circ, RELAY_COMMAND_EXTEND, @@ -705,8 +706,8 @@ circuit_extend(cell_t *cell, circuit_t *circ) char tmpbuf[INET_NTOA_BUF_LEN]; in.s_addr = htonl(circ->n_addr); tor_inet_ntoa(&in,tmpbuf,sizeof(tmpbuf)); - info(LD_CIRC|LD_OR,"Next router (%s:%d) not connected. Connecting.", - tmpbuf, circ->n_port); + log_info(LD_CIRC|LD_OR,"Next router (%s:%d) not connected. Connecting.", + tmpbuf, circ->n_port); circ->onionskin = tor_malloc(ONIONSKIN_CHALLENGE_LEN); memcpy(circ->onionskin, onionskin, ONIONSKIN_CHALLENGE_LEN); @@ -722,11 +723,11 @@ circuit_extend(cell_t *cell, circuit_t *circ) /* we should try to open a connection */ n_conn = connection_or_connect(circ->n_addr, circ->n_port, id_digest); if (!n_conn) { - info(LD_CIRC,"Launching n_conn failed. Closing circuit."); + log_info(LD_CIRC,"Launching n_conn failed. Closing circuit."); circuit_mark_for_close(circ, END_CIRC_REASON_CONNECTFAILED); return 0; } - debug(LD_CIRC,"connecting in progress (or finished). Good."); + log_debug(LD_CIRC,"connecting in progress (or finished). Good."); } /* return success. The onion/circuit/etc will be taken care of * automatically (may already have been) whenever n_conn reaches @@ -741,7 +742,7 @@ circuit_extend(cell_t *cell, circuit_t *circ) circ->n_conn = n_conn; memcpy(circ->n_conn_id_digest, n_conn->identity_digest, DIGEST_LEN); - debug(LD_CIRC,"n_conn is %s:%u",n_conn->address,n_conn->port); + log_debug(LD_CIRC,"n_conn is %s:%u",n_conn->address,n_conn->port); if (circuit_deliver_create_cell(circ, CELL_CREATE, onionskin) < 0) return -1; @@ -776,12 +777,12 @@ circuit_init_cpath_crypto(crypt_path_t *cpath, char *key_data, int reverse) if (!(cpath->f_crypto = crypto_create_init_cipher(key_data+(2*DIGEST_LEN),1))) { - warn(LD_BUG,"Bug: forward cipher initialization failed."); + log_warn(LD_BUG,"Bug: forward cipher initialization failed."); return -1; } if (!(cpath->b_crypto = crypto_create_init_cipher(key_data+(2*DIGEST_LEN)+CIPHER_KEY_LEN,0))) { - warn(LD_BUG,"Bug: backward cipher initialization failed."); + log_warn(LD_BUG,"Bug: backward cipher initialization failed."); return -1; } @@ -819,7 +820,7 @@ circuit_finish_handshake(circuit_t *circ, uint8_t reply_type, char *reply) else { hop = onion_next_hop_in_cpath(circ->cpath); if (!hop) { /* got an extended when we're all done? */ - warn(LD_PROTOCOL,"got extended when circ already built? Closing."); + log_warn(LD_PROTOCOL,"got extended when circ already built? Closing."); return - END_CIRC_REASON_TORPROTOCOL; } } @@ -828,7 +829,7 @@ circuit_finish_handshake(circuit_t *circ, uint8_t reply_type, char *reply) if (reply_type == CELL_CREATED && hop->dh_handshake_state) { if (onion_skin_client_handshake(hop->dh_handshake_state, reply, keys, DIGEST_LEN*2+CIPHER_KEY_LEN*2) < 0) { - warn(LD_CIRC,"onion_skin_client_handshake failed."); + log_warn(LD_CIRC,"onion_skin_client_handshake failed."); return -END_CIRC_REASON_TORPROTOCOL; } /* Remember hash of g^xy */ @@ -836,12 +837,12 @@ circuit_finish_handshake(circuit_t *circ, uint8_t reply_type, char *reply) } else if (reply_type == CELL_CREATED_FAST && !hop->dh_handshake_state) { if (fast_client_handshake(hop->fast_handshake_state, reply, keys, DIGEST_LEN*2+CIPHER_KEY_LEN*2) < 0) { - warn(LD_CIRC,"fast_client_handshake failed."); + log_warn(LD_CIRC,"fast_client_handshake failed."); return -END_CIRC_REASON_TORPROTOCOL; } memcpy(hop->handshake_digest, reply+DIGEST_LEN, DIGEST_LEN); } else { - warn(LD_PROTOCOL,"CREATED cell type did not match CREATE cell type."); + log_warn(LD_PROTOCOL,"CREATED cell type did not match CREATE cell type."); return -END_CIRC_REASON_TORPROTOCOL; } @@ -856,8 +857,8 @@ circuit_finish_handshake(circuit_t *circ, uint8_t reply_type, char *reply) } hop->state = CPATH_STATE_OPEN; - info(LD_CIRC,"Finished building %scircuit hop:", - (reply_type == CELL_CREATED_FAST) ? "fast " : ""); + log_info(LD_CIRC,"Finished building %scircuit hop:", + (reply_type == CELL_CREATED_FAST) ? "fast " : ""); circuit_log_path(LOG_INFO,LD_CIRC,circ); control_event_circuit_status(circ, CIRC_EVENT_EXTENDED); @@ -891,12 +892,12 @@ circuit_truncated(circuit_t *circ, crypt_path_t *layer) while (layer->next != circ->cpath) { /* we need to clear out layer->next */ victim = layer->next; - debug(LD_CIRC, "Killing a layer of the cpath."); + log_debug(LD_CIRC, "Killing a layer of the cpath."); for (stream = circ->p_streams; stream; stream=stream->next_stream) { if (stream->cpath_layer == victim) { /* XXXX NM LD_CIRC? */ - info(LD_APP, "Marking stream %d for close.", stream->stream_id); + log_info(LD_APP, "Marking stream %d for close.", stream->stream_id); /* no need to send 'end' relay cells, * because the other side's already dead */ @@ -908,7 +909,7 @@ circuit_truncated(circuit_t *circ, crypt_path_t *layer) circuit_free_cpath_node(victim); } - info(LD_CIRC, "finished"); + log_info(LD_CIRC, "finished"); return 0; #endif } @@ -934,10 +935,11 @@ onionskin_answer(circuit_t *circ, uint8_t cell_type, char *payload, char *keys) memcpy(cell.payload, payload, cell_type == CELL_CREATED ? ONIONSKIN_REPLY_LEN : DIGEST_LEN*2); - debug(LD_CIRC,"init digest forward 0x%.8x, backward 0x%.8x.", - (unsigned int)*(uint32_t*)(keys), (unsigned int)*(uint32_t*)(keys+20)); + log_debug(LD_CIRC,"init digest forward 0x%.8x, backward 0x%.8x.", + (unsigned int)*(uint32_t*)(keys), + (unsigned int)*(uint32_t*)(keys+20)); if (circuit_init_cpath_crypto(tmp_cpath, keys, 0)<0) { - warn(LD_BUG,"Circuit initialization failed"); + log_warn(LD_BUG,"Circuit initialization failed"); tor_free(tmp_cpath); return -1; } @@ -954,7 +956,7 @@ onionskin_answer(circuit_t *circ, uint8_t cell_type, char *payload, char *keys) memcpy(circ->handshake_digest, cell.payload+DIGEST_LEN, DIGEST_LEN); connection_or_write_cell_to_buf(&cell, circ->p_conn); - debug(LD_CIRC,"Finished sending 'created' cell."); + log_debug(LD_CIRC,"Finished sending 'created' cell."); if (!is_local_IP(circ->p_conn->addr) && tor_tls_is_server(circ->p_conn->tls)) { @@ -993,21 +995,21 @@ new_route_len(double cw, uint8_t purpose, extend_info_t *exit, purpose != CIRCUIT_PURPOSE_S_ESTABLISH_INTRO) routelen++; #endif - debug(LD_CIRC,"Chosen route length %d (%d routers available).",routelen, - smartlist_len(routers)); + log_debug(LD_CIRC,"Chosen route length %d (%d routers available).",routelen, + smartlist_len(routers)); num_acceptable_routers = count_acceptable_routers(routers); if (num_acceptable_routers < 2) { - info(LD_CIRC, - "Not enough acceptable routers (%d). Discarding this circuit.", - num_acceptable_routers); + log_info(LD_CIRC, + "Not enough acceptable routers (%d). Discarding this circuit.", + num_acceptable_routers); return -1; } if (num_acceptable_routers < routelen) { - info(LD_CIRC,"Not enough routers: cutting routelen from %d to %d.", - routelen, num_acceptable_routers); + log_info(LD_CIRC,"Not enough routers: cutting routelen from %d to %d.", + routelen, num_acceptable_routers); routelen = num_acceptable_routers; } @@ -1201,10 +1203,10 @@ choose_good_exit_server_general(routerlist_t *dir, int need_uptime, ++n_best_support; } } - info(LD_CIRC, - "Found %d servers that might support %d/%d pending connections.", - n_best_support, best_support >= 0 ? best_support : 0, - n_pending_connections); + log_info(LD_CIRC, + "Found %d servers that might support %d/%d pending connections.", + n_best_support, best_support >= 0 ? best_support : 0, + n_pending_connections); preferredexits = smartlist_create(); add_nickname_list_to_smartlist(preferredexits,options->ExitNodes,1,1,1); @@ -1235,14 +1237,15 @@ choose_good_exit_server_general(routerlist_t *dir, int need_uptime, if (best_support == -1) { if (need_uptime || need_capacity) { - info(LD_CIRC, "We couldn't find any live%s%s routers; falling back " - "to list of all routers.", - need_capacity?", fast":"", - need_uptime?", stable":""); + log_info(LD_CIRC, + "We couldn't find any live%s%s routers; falling back " + "to list of all routers.", + need_capacity?", fast":"", + need_uptime?", stable":""); return choose_good_exit_server_general(dir, 0, 0); } - notice(LD_CIRC, "All routers are down or middleman -- choosing a " - "doomed exit at random."); + log_notice(LD_CIRC, "All routers are down or middleman -- choosing a " + "doomed exit at random."); } for (try = 0; try < 2; try++) { /* try once to pick only from routers that satisfy a needed port, @@ -1275,11 +1278,12 @@ choose_good_exit_server_general(routerlist_t *dir, int need_uptime, smartlist_free(sl); tor_free(n_supported); if (router) { - info(LD_CIRC, "Chose exit server '%s'", router->nickname); + log_info(LD_CIRC, "Chose exit server '%s'", router->nickname); return router; } if (options->StrictExitNodes) { - warn(LD_CIRC, "No exit routers seem to be running; can't choose an exit."); + log_warn(LD_CIRC, + "No exit routers seem to be running; can't choose an exit."); } return NULL; } @@ -1313,7 +1317,7 @@ choose_good_exit_server(uint8_t purpose, routerlist_t *dir, NULL, need_uptime, need_capacity, 0, options->_AllowUnverified & ALLOW_UNVERIFIED_RENDEZVOUS, 0); } - warn(LD_BUG,"Bug: unhandled purpose %d", purpose); + log_warn(LD_BUG,"Bug: unhandled purpose %d", purpose); tor_fragile_assert(); return NULL; } @@ -1335,14 +1339,14 @@ onion_pick_cpath_exit(circuit_t *circ, extend_info_t *exit) state->desired_path_len = r; if (exit) { /* the circuit-builder pre-requested one */ - info(LD_CIRC,"Using requested exit node '%s'", exit->nickname); + log_info(LD_CIRC,"Using requested exit node '%s'", exit->nickname); exit = extend_info_dup(exit); } else { /* we have to decide one */ routerinfo_t *router = choose_good_exit_server(circ->purpose, rl, state->need_uptime, state->need_capacity, state->is_internal); if (!router) { - warn(LD_CIRC,"failed to choose an exit server"); + log_warn(LD_CIRC,"failed to choose an exit server"); return -1; } exit = extend_info_from_router(router); @@ -1384,8 +1388,8 @@ circuit_extend_to_new_exit(circuit_t *circ, extend_info_t *info) circuit_append_new_exit(circ, info); circuit_set_state(circ, CIRCUIT_STATE_BUILDING); if (circuit_send_next_onion_skin(circ)<0) { - warn(LD_CIRC, "Couldn't extend circuit to new point '%s'.", - info->nickname); + log_warn(LD_CIRC, "Couldn't extend circuit to new point '%s'.", + info->nickname); circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN); return -1; } @@ -1461,7 +1465,7 @@ choose_good_middle_server(uint8_t purpose, tor_assert(_CIRCUIT_PURPOSE_MIN <= purpose && purpose <= _CIRCUIT_PURPOSE_MAX); - debug(LD_CIRC, "Contemplating intermediate hop: random choice."); + log_debug(LD_CIRC, "Contemplating intermediate hop: random choice."); excluded = smartlist_create(); if ((r = build_state_get_exit_router(state))) { smartlist_add(excluded, r); @@ -1574,13 +1578,13 @@ onion_extend_cpath(uint8_t purpose, crypt_path_t **head_ptr, } if (cur_len >= state->desired_path_len) { - debug(LD_CIRC, "Path is complete: %d steps long", - state->desired_path_len); + log_debug(LD_CIRC, "Path is complete: %d steps long", + state->desired_path_len); return 1; } - debug(LD_CIRC, "Path is %d long; we want %d", cur_len, - state->desired_path_len); + log_debug(LD_CIRC, "Path is %d long; we want %d", cur_len, + state->desired_path_len); if (cur_len == state->desired_path_len - 1) { /* Picking last node */ info = extend_info_dup(state->chosen_exit); @@ -1596,13 +1600,13 @@ onion_extend_cpath(uint8_t purpose, crypt_path_t **head_ptr, } if (!info) { - warn(LD_CIRC,"Failed to find node for hop %d of our path. Discarding " - "this circuit.", cur_len); + log_warn(LD_CIRC,"Failed to find node for hop %d of our path. Discarding " + "this circuit.", cur_len); return -1; } - debug(LD_CIRC,"Chose router %s for hop %d (exit is %s)", - info->nickname, cur_len+1, build_state_get_exit_nickname(state)); + log_debug(LD_CIRC,"Chose router %s for hop %d (exit is %s)", + info->nickname, cur_len+1, build_state_get_exit_nickname(state)); onion_append_hop(head_ptr, info); extend_info_free(info); @@ -1788,7 +1792,7 @@ add_an_entry_guard(routerinfo_t *chosen) again: if (--tries_left <= 0) { - warn(LD_CIRC, "Tried finding a new entry, but failed. Bad news. XXX."); + log_warn(LD_CIRC, "Tried finding a new entry, but failed. Bad news. XXX."); return NULL; } if (chosen) @@ -1805,7 +1809,7 @@ again: } entry = tor_malloc_zero(sizeof(entry_guard_t)); /* XXXX Downgrade this to info before release. NM */ - notice(LD_CIRC, "Chose '%s' as new entry guard.", router->nickname); + log_notice(LD_CIRC, "Chose '%s' as new entry guard.", router->nickname); strlcpy(entry->nickname, router->nickname, sizeof(entry->nickname)); memcpy(entry->identity, router->cache_info.identity_digest, DIGEST_LEN); if (chosen) @@ -1883,8 +1887,9 @@ remove_dead_entries(void) if (why) { base16_encode(dbuf, sizeof(dbuf), entry->identity, DIGEST_LEN); format_local_iso_time(tbuf, since); - warn(LD_CIRC, "Entry guard '%s' (%s) has been %s since %s; removing.", - entry->nickname, dbuf, why, tbuf); + log_warn(LD_CIRC, + "Entry guard '%s' (%s) has been %s since %s; removing.", + entry->nickname, dbuf, why, tbuf); tor_free(entry); smartlist_del_keeporder(entry_guards, i); log_entry_guards(LOG_INFO); @@ -1926,14 +1931,14 @@ entry_guards_set_status_from_directory(void) if (! entry->unlisted_since) { entry->unlisted_since = time(NULL); changed = 1; - warn(LD_CIRC,"Entry guard '%s' is not listed by directories.", - entry->nickname); + log_warn(LD_CIRC,"Entry guard '%s' is not listed by directories.", + entry->nickname); severity = LOG_WARN; } } else { if (entry->unlisted_since) { - warn(LD_CIRC,"Entry guard '%s' is listed again by directories.", - entry->nickname); + log_warn(LD_CIRC,"Entry guard '%s' is listed again by directories.", + entry->nickname); changed = 1; severity = LOG_WARN; } @@ -1941,24 +1946,25 @@ entry_guards_set_status_from_directory(void) if (! r->is_running) { if (! entry->down_since) { entry->down_since = now; - warn(LD_CIRC, "Entry guard '%s' is now down.", entry->nickname); + log_warn(LD_CIRC, "Entry guard '%s' is now down.", + entry->nickname); changed = 1; severity = LOG_WARN; } } else { if (entry->down_since) { - notice(LD_CIRC,"Entry guard '%s' is up in latest directories.", - entry->nickname); + log_notice(LD_CIRC,"Entry guard '%s' is up in latest directories.", + entry->nickname); changed = 1; } entry->down_since = 0; } } - info(LD_CIRC, "Summary: Entry '%s' is %s, %s, and %s.", - entry->nickname, - entry->down_since ? "down" : "up", - entry->unlisted_since ? "unlisted" : "listed", - entry_is_live(entry, 0, 1) ? "live" : "not live"); + log_info(LD_CIRC, "Summary: Entry '%s' is %s, %s, and %s.", + entry->nickname, + entry->down_since ? "down" : "up", + entry->unlisted_since ? "unlisted" : "listed", + entry_is_live(entry, 0, 1) ? "live" : "not live"); }); if (remove_dead_entries()) @@ -2010,27 +2016,27 @@ entry_guard_set_status(const char *digest, int succeeded) if (e == entry) break; }); - notice(LD_CIRC, - "Connected to new entry guard '%s'. Marking earlier " - "entry guards up. %d/%d entry guards usable/new.", - entry->nickname, - num_live_entry_guards(), smartlist_len(entry_guards)); + log_notice(LD_CIRC, + "Connected to new entry guard '%s'. Marking earlier " + "entry guards up. %d/%d entry guards usable/new.", + entry->nickname, + num_live_entry_guards(), smartlist_len(entry_guards)); log_entry_guards(LOG_INFO); changed = 1; } if (entry->down_since) { entry->down_since = 0; /*XXXX shouldn't be so loud. NM */ - notice(LD_CIRC, - "Connection to formerly down entry guard '%s' succeeded. " - "%d/%d entry guards usable/new.", entry->nickname, - num_live_entry_guards(), smartlist_len(entry_guards)); + log_notice(LD_CIRC, + "Connection to formerly down entry guard '%s' succeeded. " + "%d/%d entry guards usable/new.", entry->nickname, + num_live_entry_guards(), smartlist_len(entry_guards)); log_entry_guards(LOG_INFO); changed = 1; } } else { if (!entry->made_contact) { /* dump him */ - notice(LD_CIRC, + log_notice(LD_CIRC, "Connection to never-contacted entry guard '%s' failed. " "Removing from the list. %d/%d entry guards usable/new.", entry->nickname, @@ -2041,10 +2047,10 @@ entry_guard_set_status(const char *digest, int succeeded) changed = 1; } else if (!entry->down_since) { entry->down_since = time(NULL); - warn(LD_CIRC, "Connection to entry guard '%s' failed." - " %d/%d entry guards usable/new.", - entry->nickname, - num_live_entry_guards(), smartlist_len(entry_guards)); + log_warn(LD_CIRC, "Connection to entry guard '%s' failed." + " %d/%d entry guards usable/new.", + entry->nickname, + num_live_entry_guards(), smartlist_len(entry_guards)); log_entry_guards(LOG_INFO); changed = 1; } @@ -2064,7 +2070,7 @@ static int should_add_entry_nodes = 0; void entry_nodes_should_be_added(void) { - info(LD_CIRC, "New EntryNodes config option detected. Will use."); + log_info(LD_CIRC, "New EntryNodes config option detected. Will use."); should_add_entry_nodes = 1; } @@ -2081,7 +2087,7 @@ entry_guards_prepend_from_config(void) tor_assert(options->EntryNodes); if (options->StrictEntryNodes) { - info(LD_CIRC,"Clearing old entry guards"); + log_info(LD_CIRC,"Clearing old entry guards"); SMARTLIST_FOREACH(entry_guards, entry_guard_t *, e, tor_free(e)); smartlist_clear(entry_guards); entry_guards_changed(); @@ -2091,8 +2097,8 @@ entry_guards_prepend_from_config(void) 0, 1, 1); /* take a moment first to notice whether we got them all */ - info(LD_CIRC,"Adding configured EntryNodes '%s'.", - options->EntryNodes); + log_info(LD_CIRC,"Adding configured EntryNodes '%s'.", + options->EntryNodes); smartlist_split_string(tmp, options->EntryNodes, ",", SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 0); missed_some = smartlist_len(routers) != smartlist_len(tmp); diff --git a/src/or/circuitlist.c b/src/or/circuitlist.c index 9001b07d8..908038a99 100644 --- a/src/or/circuitlist.c +++ b/src/or/circuitlist.c @@ -218,7 +218,7 @@ circuit_state_to_string(int state) case CIRCUIT_STATE_OR_WAIT: return "connecting to server"; case CIRCUIT_STATE_OPEN: return "open"; default: - warn(LD_BUG, "Bug: unknown circuit state %d", state); + log_warn(LD_BUG, "Bug: unknown circuit state %d", state); tor_snprintf(buf, sizeof(buf), "unknown state [%d]", state); return buf; } @@ -408,11 +408,13 @@ circuit_get_by_circid_orconn_impl(uint16_t circ_id, connection_t *conn) circuit_t *circ; for (circ=global_circuitlist;circ;circ = circ->next) { if (circ->p_conn == conn && circ->p_circ_id == circ_id) { - warn(LD_BUG, "circuit matches p_conn, but not in hash table (Bug!)"); + log_warn(LD_BUG, + "circuit matches p_conn, but not in hash table (Bug!)"); return circ; } if (circ->n_conn == conn && circ->n_circ_id == circ_id) { - warn(LD_BUG, "circuit matches n_conn, but not in hash table (Bug!)"); + log_warn(LD_BUG, + "circuit matches n_conn, but not in hash table (Bug!)"); return circ; } } @@ -565,9 +567,10 @@ circuit_find_to_cannibalize(uint8_t purpose, extend_info_t *info, circuit_t *circ; circuit_t *best=NULL; - debug(LD_CIRC,"Hunting for a circ to cannibalize: purpose %d, uptime %d, " - "capacity %d, internal %d", - purpose, need_uptime, need_capacity, internal); + log_debug(LD_CIRC, + "Hunting for a circ to cannibalize: purpose %d, uptime %d, " + "capacity %d, internal %d", + purpose, need_uptime, need_capacity, internal); for (circ=global_circuitlist; circ; circ = circ->next) { if (CIRCUIT_IS_ORIGIN(circ) && @@ -666,9 +669,9 @@ _circuit_mark_for_close(circuit_t *circ, int reason, int line, } if (reason == END_CIRC_AT_ORIGIN) { if (!CIRCUIT_IS_ORIGIN(circ)) { - warn(LD_BUG, "Specified 'at-origin' non-reason for ending circuit, " - "but circuit was not at origin. (called %s:%d, purpose=%d)", - file, line, circ->purpose); + log_warn(LD_BUG, "Specified 'at-origin' non-reason for ending circuit, " + "but circuit was not at origin. (called %s:%d, purpose=%d)", + file, line, circ->purpose); } reason = END_CIRC_REASON_NONE; } else if (CIRCUIT_IS_ORIGIN(circ) && reason != END_CIRC_REASON_NONE) { @@ -677,7 +680,7 @@ _circuit_mark_for_close(circuit_t *circ, int reason, int line, reason = END_CIRC_REASON_NONE; } if (reason < _END_CIRC_REASON_MIN || reason > _END_CIRC_REASON_MAX) { - warn(LD_BUG, "Reason %d out of range at %s:%d", reason, file, line); + log_warn(LD_BUG, "Reason %d out of range at %s:%d", reason, file, line); reason = END_CIRC_REASON_NONE; } @@ -706,10 +709,10 @@ _circuit_mark_for_close(circuit_t *circ, int reason, int line, tor_assert(circ->state == CIRCUIT_STATE_OPEN); tor_assert(circ->build_state->chosen_exit); /* treat this like getting a nack from it */ - info(LD_REND, "Failed intro circ %s to %s (awaiting ack). " - "Removing from descriptor.", - safe_str(circ->rend_query), - safe_str(build_state_get_exit_nickname(circ->build_state))); + log_info(LD_REND, "Failed intro circ %s to %s (awaiting ack). " + "Removing from descriptor.", + safe_str(circ->rend_query), + safe_str(build_state_get_exit_nickname(circ->build_state))); rend_client_remove_intro_point(circ->build_state->chosen_exit, circ->rend_query); } diff --git a/src/or/circuituse.c b/src/or/circuituse.c index 9bb83e9d6..93563cfc5 100644 --- a/src/or/circuituse.c +++ b/src/or/circuituse.c @@ -83,7 +83,7 @@ circuit_is_acceptable(circuit_t *circ, connection_t *conn, if (purpose == CIRCUIT_PURPOSE_C_GENERAL) { if (!exitrouter) { - debug(LD_CIRC,"Not considering circuit with unknown router."); + log_debug(LD_CIRC,"Not considering circuit with unknown router."); return 0; /* this circuit is screwed and doesn't know it yet, * or is a rendezvous circuit. */ } @@ -254,14 +254,14 @@ circuit_expire_building(time_t now) } if (victim->n_conn) - info(LD_CIRC,"Abandoning circ %s:%d:%d (state %d:%s, purpose %d)", - victim->n_conn->address, victim->n_port, victim->n_circ_id, - victim->state, circuit_state_to_string(victim->state), - victim->purpose); + log_info(LD_CIRC,"Abandoning circ %s:%d:%d (state %d:%s, purpose %d)", + victim->n_conn->address, victim->n_port, victim->n_circ_id, + victim->state, circuit_state_to_string(victim->state), + victim->purpose); else - info(LD_CIRC,"Abandoning circ %d (state %d:%s, purpose %d)", - victim->n_circ_id, victim->state, - circuit_state_to_string(victim->state), victim->purpose); + log_info(LD_CIRC,"Abandoning circ %d (state %d:%s, purpose %d)", + victim->n_circ_id, victim->state, + circuit_state_to_string(victim->state), victim->purpose); circuit_log_path(LOG_INFO,LD_CIRC,victim); circuit_mark_for_close(victim, END_CIRC_AT_ORIGIN); @@ -281,11 +281,11 @@ circuit_remove_handled_ports(smartlist_t *needed_ports) port = smartlist_get(needed_ports, i); tor_assert(*port); if (circuit_stream_is_being_handled(NULL, *port, 2)) { -// debug(LD_CIRC,"Port %d is already being handled; removing.", port); +// log_debug(LD_CIRC,"Port %d is already being handled; removing.", port); smartlist_del(needed_ports, i--); tor_free(port); } else { - debug(LD_CIRC,"Port %d is not handled.", *port); + log_debug(LD_CIRC,"Port %d is not handled.", *port); } } } @@ -375,8 +375,9 @@ circuit_predict_and_launch_new(void) * and no circuit is currently available that can handle it. */ if (!circuit_all_predicted_ports_handled(now, &port_needs_uptime, &port_needs_capacity)) { - info(LD_CIRC,"Have %d clean circs (%d internal), need another exit circ.", - num, num_internal); + log_info(LD_CIRC, + "Have %d clean circs (%d internal), need another exit circ.", + num, num_internal); circuit_launch_by_router(CIRCUIT_PURPOSE_C_GENERAL, NULL, port_needs_uptime, port_needs_capacity, 0); return; @@ -384,9 +385,10 @@ circuit_predict_and_launch_new(void) /* Third, see if we need any more hidden service (server) circuits. */ if (num_rend_services() && num_uptime_internal < 3) { - info(LD_CIRC,"Have %d clean circs (%d internal), need another internal " - "circ for my hidden service.", - num, num_internal); + log_info(LD_CIRC, + "Have %d clean circs (%d internal), need another internal " + "circ for my hidden service.", + num, num_internal); circuit_launch_by_router(CIRCUIT_PURPOSE_C_GENERAL, NULL, 1, 1, 1); return; @@ -397,8 +399,10 @@ circuit_predict_and_launch_new(void) &hidserv_needs_capacity) && ((num_uptime_internal<2 && hidserv_needs_uptime) || num_internal<2)) { - info(LD_CIRC,"Have %d clean circs (%d uptime-internal, %d internal), need" - " another hidserv circ.", num, num_uptime_internal, num_internal); + log_info(LD_CIRC, + "Have %d clean circs (%d uptime-internal, %d internal), need" + " another hidserv circ.", + num, num_uptime_internal, num_internal); circuit_launch_by_router(CIRCUIT_PURPOSE_C_GENERAL, NULL, hidserv_needs_uptime, hidserv_needs_capacity, 1); return; @@ -499,7 +503,7 @@ circuit_detach_stream(circuit_t *circ, connection_t *conn) return; } - err(LD_BUG,"edge conn not in circuit's list?"); + log_err(LD_BUG,"edge conn not in circuit's list?"); tor_assert(0); /* should never get here */ } @@ -562,9 +566,9 @@ circuit_expire_old_circuits(void) circ->timestamp_dirty + get_options()->MaxCircuitDirtiness < now && CIRCUIT_IS_ORIGIN(circ) && !circ->p_streams /* nothing attached */ ) { - debug(LD_CIRC, "Closing n_circ_id %d (dirty %d secs ago, purp %d)", - circ->n_circ_id, (int)(now - circ->timestamp_dirty), - circ->purpose); + log_debug(LD_CIRC, "Closing n_circ_id %d (dirty %d secs ago, purp %d)", + circ->n_circ_id, (int)(now - circ->timestamp_dirty), + circ->purpose); /* (only general and purpose_c circs can get dirty) */ tor_assert(!circ->n_streams); tor_assert(circ->purpose <= CIRCUIT_PURPOSE_C_REND_JOINED); @@ -574,8 +578,9 @@ circuit_expire_old_circuits(void) circ->purpose == CIRCUIT_PURPOSE_C_GENERAL) { #define CIRCUIT_UNUSED_CIRC_TIMEOUT 3600 /* an hour */ if (circ->timestamp_created + CIRCUIT_UNUSED_CIRC_TIMEOUT < now) { - debug(LD_CIRC,"Closing circuit that has been unused for %d seconds.", - (int)(now - circ->timestamp_created)); + log_debug(LD_CIRC, + "Closing circuit that has been unused for %d seconds.", + (int)(now - circ->timestamp_created)); circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN); } } @@ -603,8 +608,9 @@ circuit_testing_failed(circuit_t *circ, int at_last_hop) circuit_launch_by_router(CIRCUIT_PURPOSE_TESTING, me, 0, 1, 1); else #endif - info(LD_GENERAL,"Our testing circuit (to see if your ORPort is reachable) " - "has failed. I'll try again later."); + log_info(LD_GENERAL, + "Our testing circuit (to see if your ORPort is reachable) " + "has failed. I'll try again later."); } /** The circuit <b>circ</b> has just become open. Take the next @@ -643,7 +649,7 @@ circuit_has_opened(circuit_t *circ) circuit_testing_opened(circ); break; default: - err(LD_BUG,"unhandled purpose %d",circ->purpose); + log_err(LD_BUG,"unhandled purpose %d",circ->purpose); tor_assert(0); } } @@ -676,9 +682,10 @@ circuit_build_failed(circuit_t *circ) n_conn = connection_or_get_by_identity_digest(circ->n_conn_id_digest); } if (n_conn) { - info(LD_OR, "Our circuit failed to get a response from the first hop " - "(%s:%d). I'm going to try to rotate to a better connection.", - n_conn->address, n_conn->port); + log_info(LD_OR, + "Our circuit failed to get a response from the first hop " + "(%s:%d). I'm going to try to rotate to a better connection.", + n_conn->address, n_conn->port); n_conn->is_obsolete = 1; entry_guard_set_status(n_conn->identity_digest, 0); } @@ -723,10 +730,11 @@ circuit_build_failed(circuit_t *circ) /* at Bob, connecting to rend point */ /* Don't increment failure count, since Alice may have picked * the rendezvous point maliciously */ - info(LD_REND, - "Couldn't connect to Alice's chosen rend point %s (%s hop failed).", - build_state_get_exit_nickname(circ->build_state), - failed_at_last_hop?"last":"non-last"); + log_info(LD_REND, + "Couldn't connect to Alice's chosen rend point %s " + "(%s hop failed).", + build_state_get_exit_nickname(circ->build_state), + failed_at_last_hop?"last":"non-last"); rend_service_relaunch_rendezvous(circ); break; default: @@ -776,8 +784,8 @@ circuit_launch_by_extend_info(uint8_t purpose, extend_info_t *extend_info, circuit_t *circ; if (!router_have_minimum_dir_info()) { - debug(LD_CIRC,"Haven't fetched enough directory info yet; canceling " - "circuit launch."); + log_debug(LD_CIRC,"Haven't fetched enough directory info yet; canceling " + "circuit launch."); return NULL; } @@ -787,8 +795,8 @@ circuit_launch_by_extend_info(uint8_t purpose, extend_info_t *extend_info, circ = circuit_find_to_cannibalize(CIRCUIT_PURPOSE_C_GENERAL, extend_info, need_uptime, need_capacity, internal); if (circ) { - info(LD_CIRC,"Cannibalizing circ '%s' for purpose %d", - build_state_get_exit_nickname(circ->build_state), purpose); + log_info(LD_CIRC,"Cannibalizing circ '%s' for purpose %d", + build_state_get_exit_nickname(circ->build_state), purpose); circ->purpose = purpose; /* reset the birth date of this circ, else expire_building * will see it and think it's been trying to build since it @@ -808,8 +816,9 @@ circuit_launch_by_extend_info(uint8_t purpose, extend_info_t *extend_info, return NULL; break; default: - warn(LD_BUG, "Bug: unexpected purpose %d when cannibalizing a circ.", - purpose); + log_warn(LD_BUG, + "Bug: unexpected purpose %d when cannibalizing a circ.", + purpose); tor_fragile_assert(); return NULL; } @@ -842,7 +851,7 @@ circuit_launch_by_nickname(uint8_t purpose, const char *exit_nickname, router = router_get_by_nickname(exit_nickname, 1); if (!router) { /*XXXXNM domain? */ - warn(LD_GENERAL, "No such OR as '%s'", exit_nickname); + log_warn(LD_GENERAL, "No such OR as '%s'", exit_nickname); return NULL; } } @@ -857,7 +866,7 @@ static void circuit_increment_failure_count(void) { ++n_circuit_failures; - debug(LD_CIRC,"n_circuit_failures now %d.",n_circuit_failures); + log_debug(LD_CIRC,"n_circuit_failures now %d.",n_circuit_failures); } /** Reset the failure count for opening general circuits. This means @@ -908,8 +917,9 @@ circuit_get_open_circ_or_launch(connection_t *conn, if (!router_have_minimum_dir_info()) { if (!connection_get_by_type(CONN_TYPE_DIR)) { - notice(LD_APP|LD_DIR,"Application request when we're believed to be " - "offline. Optimistically trying directory fetches again."); + log_notice(LD_APP|LD_DIR, + "Application request when we're believed to be " + "offline. Optimistically trying directory fetches again."); router_reset_status_download_failures(); router_reset_descriptor_download_failures(); update_networkstatus_downloads(time(NULL)); @@ -930,10 +940,10 @@ circuit_get_open_circ_or_launch(connection_t *conn, addr = ntohl(in.s_addr); if (router_exit_policy_all_routers_reject(addr, conn->socks_request->port, need_uptime)) { - notice(LD_APP, - "No Tor server exists that allows exit to %s:%d. Rejecting.", - safe_str(conn->socks_request->address), - conn->socks_request->port); + log_notice(LD_APP, + "No Tor server exists that allows exit to %s:%d. Rejecting.", + safe_str(conn->socks_request->address), + conn->socks_request->port); return -1; } } @@ -949,15 +959,15 @@ circuit_get_open_circ_or_launch(connection_t *conn, /* need to pick an intro point */ extend_info = rend_client_get_random_intro(conn->rend_query); if (!extend_info) { - info(LD_REND, - "No intro points for '%s': refetching service descriptor.", - safe_str(conn->rend_query)); + log_info(LD_REND, + "No intro points for '%s': refetching service descriptor.", + safe_str(conn->rend_query)); rend_client_refetch_renddesc(conn->rend_query); conn->state = AP_CONN_STATE_RENDDESC_WAIT; return 0; } - info(LD_REND,"Chose '%s' as intro point for '%s'.", - extend_info->nickname, safe_str(conn->rend_query)); + log_info(LD_REND,"Chose '%s' as intro point for '%s'.", + extend_info->nickname, safe_str(conn->rend_query)); } /* If we have specified a particular exit node for our @@ -968,8 +978,9 @@ circuit_get_open_circ_or_launch(connection_t *conn, routerinfo_t *r; if (!(r = router_get_by_nickname(conn->chosen_exit_name, 1))) { /*XXXX NM domain? */ - notice(LD_CIRC,"Requested exit point '%s' is not known. Closing.", - conn->chosen_exit_name); + log_notice(LD_CIRC, + "Requested exit point '%s' is not known. Closing.", + conn->chosen_exit_name); return -1; } extend_info = extend_info_from_router(r); @@ -1001,9 +1012,10 @@ circuit_get_open_circ_or_launch(connection_t *conn, } } if (!circ) - info(LD_APP, - "No safe circuit (purpose %d) ready for edge connection; delaying.", - desired_circuit_purpose); + log_info(LD_APP, + "No safe circuit (purpose %d) ready for edge " + "connection; delaying.", + desired_circuit_purpose); *circp = circ; return 0; } @@ -1016,8 +1028,8 @@ static void link_apconn_to_circ(connection_t *apconn, circuit_t *circ) { /* add it into the linked list of streams on this circuit */ - debug(LD_APP|LD_CIRC, "attaching new conn to circ. n_circ_id %d.", - circ->n_circ_id); + log_debug(LD_APP|LD_CIRC, "attaching new conn to circ. n_circ_id %d.", + circ->n_circ_id); /* reset it, so we can measure circ timeouts */ apconn->timestamp_lastread = time(NULL); apconn->next_stream = circ->p_streams; @@ -1139,10 +1151,10 @@ connection_ap_handshake_attach_circuit(connection_t *conn) conn_age = time(NULL) - conn->timestamp_created; if (conn_age > CONN_AP_MAX_ATTACH_DELAY) { - notice(LD_APP, - "Tried for %d seconds to get a connection to %s:%d. Giving up.", - conn_age, safe_str(conn->socks_request->address), - conn->socks_request->port); + log_notice(LD_APP, + "Tried for %d seconds to get a connection to %s:%d. Giving up.", + conn_age, safe_str(conn->socks_request->address), + conn->socks_request->port); return -1; } @@ -1152,13 +1164,15 @@ connection_ap_handshake_attach_circuit(connection_t *conn) if (conn->chosen_exit_name) { routerinfo_t *router = router_get_by_nickname(conn->chosen_exit_name, 1); if (!router) { - warn(LD_APP,"Requested exit point '%s' is not known. Closing.", - conn->chosen_exit_name); + log_warn(LD_APP, + "Requested exit point '%s' is not known. Closing.", + conn->chosen_exit_name); return -1; } if (!connection_ap_can_use_exit(conn, router)) { - warn(LD_APP,"Requested exit point '%s' would refuse request. Closing.", - conn->chosen_exit_name); + log_warn(LD_APP, + "Requested exit point '%s' would refuse request. Closing.", + conn->chosen_exit_name); return -1; } } @@ -1169,8 +1183,9 @@ connection_ap_handshake_attach_circuit(connection_t *conn) if (retval < 1) return retval; - debug(LD_APP|LD_CIRC,"Attaching apconn to circ %d (stream %d sec old).", - circ->n_circ_id, conn_age); + log_debug(LD_APP|LD_CIRC, + "Attaching apconn to circ %d (stream %d sec old).", + circ->n_circ_id, conn_age); /* here, print the circ's path. so people can figure out which circs are * sucking. */ circuit_log_path(LOG_INFO,LD_APP|LD_CIRC,circ); @@ -1192,9 +1207,10 @@ connection_ap_handshake_attach_circuit(connection_t *conn) if (retval > 0) { tor_assert(rendcirc); /* one is already established, attach */ - info(LD_REND, - "rend joined circ %d already here. attaching. (stream %d sec old)", - rendcirc->n_circ_id, conn_age); + log_info(LD_REND, + "rend joined circ %d already here. attaching. " + "(stream %d sec old)", + rendcirc->n_circ_id, conn_age); /* Mark rendezvous circuits as 'newly dirty' every time you use * them, since the process of rebuilding a rendezvous circ is so * expensive. There is a tradeoffs between linkability and @@ -1209,10 +1225,10 @@ connection_ap_handshake_attach_circuit(connection_t *conn) if (rendcirc && (rendcirc->purpose == CIRCUIT_PURPOSE_C_REND_READY_INTRO_ACKED)) { - info(LD_REND, - "pending-join circ %d already here, with intro ack. " - "Stalling. (stream %d sec old)", - rendcirc->n_circ_id, conn_age); + log_info(LD_REND, + "pending-join circ %d already here, with intro ack. " + "Stalling. (stream %d sec old)", + rendcirc->n_circ_id, conn_age); return 0; } @@ -1224,9 +1240,10 @@ connection_ap_handshake_attach_circuit(connection_t *conn) if (retval > 0) { /* one has already sent the intro. keep waiting. */ tor_assert(introcirc); - info(LD_REND, "Intro circ %d present and awaiting ack (rend %d). " - "Stalling. (stream %d sec old)", - introcirc->n_circ_id, rendcirc ? rendcirc->n_circ_id : 0, conn_age); + log_info(LD_REND, "Intro circ %d present and awaiting ack (rend %d). " + "Stalling. (stream %d sec old)", + introcirc->n_circ_id, rendcirc ? rendcirc->n_circ_id : 0, + conn_age); return 0; } @@ -1234,15 +1251,16 @@ connection_ap_handshake_attach_circuit(connection_t *conn) if (rendcirc && introcirc && rendcirc->purpose == CIRCUIT_PURPOSE_C_REND_READY) { - info(LD_REND,"ready rend circ %d already here (no intro-ack yet on " - "intro %d). (stream %d sec old)", - rendcirc->n_circ_id, introcirc->n_circ_id, conn_age); + log_info(LD_REND, + "ready rend circ %d already here (no intro-ack yet on " + "intro %d). (stream %d sec old)", + rendcirc->n_circ_id, introcirc->n_circ_id, conn_age); tor_assert(introcirc->purpose == CIRCUIT_PURPOSE_C_INTRODUCING); if (introcirc->state == CIRCUIT_STATE_OPEN) { - info(LD_REND,"found open intro circ %d (rend %d); sending " - "introduction. (stream %d sec old)", - introcirc->n_circ_id, rendcirc->n_circ_id, conn_age); + log_info(LD_REND,"found open intro circ %d (rend %d); sending " + "introduction. (stream %d sec old)", + introcirc->n_circ_id, rendcirc->n_circ_id, conn_age); if (rend_client_send_introduction(introcirc, rendcirc) < 0) { return -1; } @@ -1254,10 +1272,10 @@ connection_ap_handshake_attach_circuit(connection_t *conn) } } - info(LD_REND, "Intro (%d) and rend (%d) circs are not both ready. " - "Stalling conn. (%d sec old)", - introcirc ? introcirc->n_circ_id : 0, - rendcirc ? rendcirc->n_circ_id : 0, conn_age); + log_info(LD_REND, "Intro (%d) and rend (%d) circs are not both ready. " + "Stalling conn. (%d sec old)", + introcirc ? introcirc->n_circ_id : 0, + rendcirc ? rendcirc->n_circ_id : 0, conn_age); return 0; } } diff --git a/src/or/command.c b/src/or/command.c index 16a3efc1a..590f3e181 100644 --- a/src/or/command.c +++ b/src/or/command.c @@ -52,10 +52,10 @@ command_time_process_cell(cell_t *cell, connection_t *conn, int *time, time_passed = tv_udiff(&start, &end) ; if (time_passed > 10000) { /* more than 10ms */ - debug(LD_OR,"That call just took %ld ms.",time_passed/1000); + log_debug(LD_OR,"That call just took %ld ms.",time_passed/1000); } if (time_passed < 0) { - info(LD_GENERAL,"That call took us back in time!"); + log_info(LD_GENERAL,"That call took us back in time!"); time_passed = 0; } *time += time_passed; @@ -82,7 +82,8 @@ command_process_cell(cell_t *cell, connection_t *conn) if (now > current_second) { /* the second has rolled over */ /* print stats */ - info(LD_OR,"At end of second: %d creates (%d ms), %d createds (%d ms), " + log_info(LD_OR, + "At end of second: %d creates (%d ms), %d createds (%d ms), " "%d relays (%d ms), %d destroys (%d ms)", num_create, create_time/1000, num_created, created_time/1000, @@ -164,8 +165,9 @@ command_process_create_cell(cell_t *cell, connection_t *conn) int id_is_high; if (we_are_hibernating()) { - info(LD_OR,"Received create cell but we're shutting down. Sending back " - "destroy."); + log_info(LD_OR, + "Received create cell but we're shutting down. Sending back " + "destroy."); connection_or_send_destroy(cell->circ_id, conn, END_CIRC_REASON_HIBERNATING); return; @@ -179,14 +181,14 @@ command_process_create_cell(cell_t *cell, connection_t *conn) */ id_is_high = cell->circ_id & (1<<15); if (id_is_high && conn->circ_id_type == CIRC_ID_TYPE_HIGHER) { - info(LD_OR, "Got a high circuit ID from %s (%d); switching to " - "low circuit IDs.", - conn->nickname ? conn->nickname : "client", conn->s); + log_info(LD_OR, "Got a high circuit ID from %s (%d); switching to " + "low circuit IDs.", + conn->nickname ? conn->nickname : "client", conn->s); conn->circ_id_type = CIRC_ID_TYPE_LOWER; } else if (!id_is_high && conn->circ_id_type == CIRC_ID_TYPE_LOWER) { - info(LD_OR, "Got a low circuit ID from %s (%d); switching to " - "high circuit IDs.", - conn->nickname ? conn->nickname : "client", conn->s); + log_info(LD_OR, "Got a low circuit ID from %s (%d); switching to " + "high circuit IDs.", + conn->nickname ? conn->nickname : "client", conn->s); conn->circ_id_type = CIRC_ID_TYPE_HIGHER; } @@ -214,11 +216,11 @@ command_process_create_cell(cell_t *cell, connection_t *conn) /* hand it off to the cpuworkers, and then return */ if (assign_to_cpuworker(NULL, CPUWORKER_TASK_ONION, circ) < 0) { - warn(LD_GENERAL,"Failed to hand off onionskin. Closing."); + log_warn(LD_GENERAL,"Failed to hand off onionskin. Closing."); circuit_mark_for_close(circ, END_CIRC_REASON_INTERNAL); return; } - debug(LD_OR,"success: handed off onionskin."); + log_debug(LD_OR,"success: handed off onionskin."); } else { /* This is a CREATE_FAST cell; we can handle it immediately without using * a CPU worker.*/ @@ -226,12 +228,12 @@ command_process_create_cell(cell_t *cell, connection_t *conn) char reply[DIGEST_LEN*2]; tor_assert(cell->command == CELL_CREATE_FAST); if (fast_server_handshake(cell->payload, reply, keys, sizeof(keys))<0) { - warn(LD_OR,"Failed to generate key material. Closing."); + log_warn(LD_OR,"Failed to generate key material. Closing."); circuit_mark_for_close(circ, END_CIRC_REASON_INTERNAL); return; } if (onionskin_answer(circ, CELL_CREATED_FAST, reply, keys)<0) { - warn(LD_OR,"Failed to reply to CREATE_FAST cell. Closing."); + log_warn(LD_OR,"Failed to reply to CREATE_FAST cell. Closing."); circuit_mark_for_close(circ, END_CIRC_REASON_INTERNAL); return; } @@ -254,8 +256,9 @@ command_process_created_cell(cell_t *cell, connection_t *conn) circ = circuit_get_by_circid_orconn(cell->circ_id, conn); if (!circ) { - info(LD_OR,"(circID %d) unknown circ (probably got a destroy earlier). " - "Dropping.", cell->circ_id); + log_info(LD_OR, + "(circID %d) unknown circ (probably got a destroy earlier). " + "Dropping.", cell->circ_id); return; } @@ -267,21 +270,22 @@ command_process_created_cell(cell_t *cell, connection_t *conn) } if (CIRCUIT_IS_ORIGIN(circ)) { /* we're the OP. Handshake this. */ - debug(LD_OR,"at OP. Finishing handshake."); + log_debug(LD_OR,"at OP. Finishing handshake."); if (circuit_finish_handshake(circ, cell->command, cell->payload) < 0) { - warn(LD_OR,"circuit_finish_handshake failed."); + log_warn(LD_OR,"circuit_finish_handshake failed."); circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN); return; } - debug(LD_OR,"Moving to next skin."); + log_debug(LD_OR,"Moving to next skin."); if (circuit_send_next_onion_skin(circ) < 0) { - info(LD_OR,"circuit_send_next_onion_skin failed."); + log_info(LD_OR,"circuit_send_next_onion_skin failed."); /* XXX push this circuit_close lower */ circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN); return; } } else { /* pack it into an extended relay cell, and send it. */ - debug(LD_OR,"Converting created cell to extended relay cell, sending."); + log_debug(LD_OR, + "Converting created cell to extended relay cell, sending."); connection_edge_send_command(NULL, circ, RELAY_COMMAND_EXTENDED, cell->payload, ONIONSKIN_REPLY_LEN, NULL); } @@ -300,8 +304,9 @@ command_process_relay_cell(cell_t *cell, connection_t *conn) circ = circuit_get_by_circid_orconn(cell->circ_id, conn); if (!circ) { - debug(LD_OR,"unknown circuit %d on connection from %s:%d. Dropping.", - cell->circ_id, conn->address, conn->port); + log_debug(LD_OR, + "unknown circuit %d on connection from %s:%d. Dropping.", + cell->circ_id, conn->address, conn->port); return; } @@ -352,11 +357,11 @@ command_process_destroy_cell(cell_t *cell, connection_t *conn) circ = circuit_get_by_circid_orconn(cell->circ_id, conn); reason = (uint8_t)cell->payload[0]; if (!circ) { - info(LD_OR,"unknown circuit %d on connection from %s:%d. Dropping.", - cell->circ_id, conn->address, conn->port); + log_info(LD_OR,"unknown circuit %d on connection from %s:%d. Dropping.", + cell->circ_id, conn->address, conn->port); return; } - debug(LD_OR,"Received for circID %d.",cell->circ_id); + log_debug(LD_OR,"Received for circID %d.",cell->circ_id); if (cell->circ_id == circ->p_circ_id) { /* the destroy came from behind */ @@ -368,7 +373,7 @@ command_process_destroy_cell(cell_t *cell, connection_t *conn) circuit_mark_for_close(circ, reason); } else { char payload[1]; - debug(LD_OR, "Delivering 'truncated' back."); + log_debug(LD_OR, "Delivering 'truncated' back."); payload[0] = (char)reason; connection_edge_send_command(NULL, circ, RELAY_COMMAND_TRUNCATED, payload, sizeof(payload), NULL); |