mirrors/tor
1
0
Fork 0
mirror of https://gitlab.torproject.org/tpo/core/tor.git synced 2025-02-25 07:07:52 +01:00
Code Issues Projects Releases Wiki Activity

convert some more source files to the new log convention

Browse source 
svn:r6002
This commit is contained in:
Roger Dingledine 2006-02-13 08:28:42 +00:00
parent 7d80921afa
commit 36484f873a
5 changed files with 368 additions and 328 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

178
src/or/buffers.c
View file

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

230
src/or/circuitbuild.c
View file

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

31
src/or/circuitlist.c
View file

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

196
src/or/circuituse.c
View file

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

61
src/or/command.c
View file

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