nihilist/tor
1
0
Fork 0
mirror of https://gitlab.torproject.org/tpo/core/tor.git synced 2024-11-10 21:23:58 +01:00
Code Issues Packages Projects Releases Wiki Activity

Update more files to new log stuff.

Browse Source 
svn:r5286
This commit is contained in:
Nick Mathewson 2005-10-18 22:56:40 +00:00
parent 55f2ab9cc3
commit 1bd3f6cc9a
8 changed files with 211 additions and 183 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

16
src/common/log.h
View File

@ -51,16 +51,32 @@
#endif #endif
/* Logging domains */ /* Logging domains */
/** Catch-all for miscellaneous events and internal errors and fatal
* errors. */
#define LD_GENERAL 0 #define LD_GENERAL 0
/** The cryptography subsytem */
#define LD_CRYPTO 1 #define LD_CRYPTO 1
/** Networking */
#define LD_NET 2 #define LD_NET 2
/** Parsing and acting on our configuration */
#define LD_CONFIG 3 #define LD_CONFIG 3
/** Reading and writing from the filesystem */
#define LD_FS 4 #define LD_FS 4
/** Other servers' (non)compliance with the Tor protocol */
#define LD_PROTOCOL 5 #define LD_PROTOCOL 5
/** Memory management */
#define LD_MM 6 #define LD_MM 6
/** HTTP implementation */
#define LD_HTTP 7 #define LD_HTTP 7
/** Application (socks) requests */
#define LD_APP 8 #define LD_APP 8
/** Communication via the controller protocol */
#define LD_CONTROL 9 #define LD_CONTROL 9
/** Building, using, and managing circuits */
#define LD_CIRC 10
/** Hidden services */
#define LD_REND 11
typedef void (*log_callback)(int severity, int domain, const char *msg); typedef void (*log_callback)(int severity, int domain, const char *msg);

18
src/or/circuitlist.c
View File

@ -10,6 +10,7 @@ const char circuitlist_c_id[] = "$Id$";
* \brief Manage the global circuit list. * \brief Manage the global circuit list.
**/ **/
#define NEW_LOG_INTERFACE
#include "or.h" #include "or.h"
/* Define RB_AUGMENT to avoid warnings about if statements with emtpy bodies. /* Define RB_AUGMENT to avoid warnings about if statements with emtpy bodies.
@ -187,7 +188,7 @@ circuit_state_to_string(int state)
case CIRCUIT_STATE_OR_WAIT: return "connecting to firsthop"; case CIRCUIT_STATE_OR_WAIT: return "connecting to firsthop";
case CIRCUIT_STATE_OPEN: return "open"; case CIRCUIT_STATE_OPEN: return "open";
default: default:
log_fn(LOG_WARN, "Bug: unknown circuit state %d", state); warn(LD_GENERAL, "Bug: unknown circuit state %d", state);
tor_snprintf(buf, sizeof(buf), "unknown state [%d]", state); tor_snprintf(buf, sizeof(buf), "unknown state [%d]", state);
return buf; return buf;
} }
@ -374,11 +375,11 @@ circuit_get_by_circid_orconn(uint16_t circ_id, connection_t *conn)
continue; continue;
if (circ->p_conn == conn && circ->p_circ_id == circ_id) { if (circ->p_conn == conn && circ->p_circ_id == circ_id) {
log_fn(LOG_WARN, "circuit matches p_conn, but not in tree (Bug!)"); warn(LD_GENERAL, "circuit matches p_conn, but not in tree (Bug!)");
return circ; return circ;
} }
if (circ->n_conn == conn && circ->n_circ_id == circ_id) { if (circ->n_conn == conn && circ->n_circ_id == circ_id) {
log_fn(LOG_WARN, "circuit matches n_conn, but not in tree (Bug!)"); warn(LD_GENERAL, "circuit matches n_conn, but not in tree (Bug!)");
return circ; return circ;
} }
} }
@ -401,7 +402,7 @@ circuit_get_by_edge_conn(connection_t *conn)
/* return NULL; */ /* return NULL; */
circ = circuit_get_by_conn(conn); circ = circuit_get_by_conn(conn);
if (circ) { if (circ) {
log_fn(LOG_WARN, "BUG: conn->on_circuit==NULL, but there was in fact a circuit there."); warn(LD_GENERAL, "BUG: conn->on_circuit==NULL, but there was in fact a circuit there.");
} }
return circ; return circ;
} }
@ -534,7 +535,7 @@ circuit_get_clean_open(uint8_t purpose, int need_uptime,
circuit_t *circ; circuit_t *circ;
circuit_t *best=NULL; circuit_t *best=NULL;
log_fn(LOG_DEBUG,"Hunting for a circ to cannibalize: purpose %d, uptime %d, capacity %d, internal %d", purpose, need_uptime, need_capacity, internal); 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) { for (circ=global_circuitlist; circ; circ = circ->next) {
if (CIRCUIT_IS_ORIGIN(circ) && if (CIRCUIT_IS_ORIGIN(circ) &&
@ -613,7 +614,8 @@ _circuit_mark_for_close(circuit_t *circ, int line, const char *file)
tor_assert(file); tor_assert(file);
if (circ->marked_for_close) { if (circ->marked_for_close) {
log(LOG_WARN,"Duplicate call to circuit_mark_for_close at %s:%d" log(LOG_WARN,LD_GENERAL,
"Duplicate call to circuit_mark_for_close at %s:%d"
" (first at %s:%d)", file, line, " (first at %s:%d)", file, line,
circ->marked_for_close_file, circ->marked_for_close); circ->marked_for_close_file, circ->marked_for_close);
return; return;
@ -640,7 +642,7 @@ _circuit_mark_for_close(circuit_t *circ, int line, const char *file)
tor_assert(circ->state == CIRCUIT_STATE_OPEN); tor_assert(circ->state == CIRCUIT_STATE_OPEN);
tor_assert(circ->build_state->chosen_exit); tor_assert(circ->build_state->chosen_exit);
/* treat this like getting a nack from it */ /* treat this like getting a nack from it */
log_fn(LOG_INFO,"Failed intro circ %s to %s (awaiting ack). Removing from descriptor.", info(LD_REND,"Failed intro circ %s to %s (awaiting ack). Removing from descriptor.",
safe_str(circ->rend_query), safe_str(circ->rend_query),
safe_str(build_state_get_exit_nickname(circ->build_state))); safe_str(build_state_get_exit_nickname(circ->build_state)));
rend_client_remove_intro_point(circ->build_state->chosen_exit, rend_client_remove_intro_point(circ->build_state->chosen_exit,
@ -701,7 +703,7 @@ assert_cpath_layer_ok(const crypt_path_t *cp)
/* tor_assert(cp->dh_handshake_state); */ /* tor_assert(cp->dh_handshake_state); */
break; break;
default: default:
log_fn(LOG_ERR,"Unexpected state %d",cp->state); err("Unexpected state %d",cp->state);
tor_assert(0); tor_assert(0);
} }
tor_assert(cp->package_window >= 0); tor_assert(cp->package_window >= 0);

20
src/or/onion.c
View File

@ -11,6 +11,7 @@ const char onion_c_id[] = "$Id$";
* parsing and creation. * parsing and creation.
**/ **/
#define NEW_LOG_INTERFACE
#include "or.h" #include "or.h"
/** Type for a linked list of circuits that are waiting for a free CPU worker /** Type for a linked list of circuits that are waiting for a free CPU worker
@ -56,7 +57,7 @@ onion_pending_add(circuit_t *circ)
tor_assert(!ol_tail->next); tor_assert(!ol_tail->next);
if (ol_length >= get_options()->MaxOnionsPending) { if (ol_length >= get_options()->MaxOnionsPending) {
log_fn(LOG_NOTICE,"Already have %d onions queued. Closing.", ol_length); notice(LD_GENERAL,"Already have %d onions queued. Closing.", ol_length);
tor_free(tmp); tor_free(tmp);
return -1; return -1;
} }
@ -68,7 +69,7 @@ onion_pending_add(circuit_t *circ)
/* cull elderly requests. */ /* cull elderly requests. */
circ = ol_list->circ; circ = ol_list->circ;
onion_pending_remove(ol_list->circ); onion_pending_remove(ol_list->circ);
log_fn(LOG_INFO,"Circuit create request is too old; cancelling due to overload."); info(LD_CIRC,"Circuit create request is too old; cancelling due to overload.");
circuit_mark_for_close(circ); circuit_mark_for_close(circ);
} }
return 0; return 0;
@ -116,7 +117,8 @@ onion_pending_remove(circuit_t *circ)
} else { /* we need to hunt through the rest of the list */ } else { /* we need to hunt through the rest of the list */
for ( ;tmpo->next && tmpo->next->circ != circ; tmpo=tmpo->next) ; for ( ;tmpo->next && tmpo->next->circ != circ; tmpo=tmpo->next) ;
if (!tmpo->next) { if (!tmpo->next) {
log_fn(LOG_DEBUG,"circ (p_circ_id %d) not in list, probably at cpuworker.",circ->p_circ_id); /* XX is there a better category here? */
debug(LD_GENERAL,"circ (p_circ_id %d) not in list, probably at cpuworker.",circ->p_circ_id);
return; return;
} }
/* now we know tmpo->next->circ == circ */ /* now we know tmpo->next->circ == circ */
@ -236,17 +238,17 @@ onion_skin_server_handshake(const char *onion_skin, /* ONIONSKIN_CHALLENGE_LEN b
break; break;
} }
if (len<0) { if (len<0) {
log_fn(LOG_INFO, "Couldn't decrypt onionskin: client may be using old onion key"); info(LD_PROTOCOL, "Couldn't decrypt onionskin: client may be using old onion key");
goto err; goto err;
} else if (len != DH_KEY_LEN) { } else if (len != DH_KEY_LEN) {
log_fn(LOG_WARN, "Unexpected onionskin length after decryption: %d", warn(LD_PROTOCOL, "Unexpected onionskin length after decryption: %d",
len); len);
goto err; goto err;
} }
dh = crypto_dh_new(); dh = crypto_dh_new();
if (crypto_dh_get_public(dh, handshake_reply_out, DH_KEY_LEN)) { if (crypto_dh_get_public(dh, handshake_reply_out, DH_KEY_LEN)) {
log_fn(LOG_INFO, "crypto_dh_get_public failed."); info(LD_GENERAL, "crypto_dh_get_public failed.");
goto err; goto err;
} }
@ -262,7 +264,7 @@ onion_skin_server_handshake(const char *onion_skin, /* ONIONSKIN_CHALLENGE_LEN b
len = crypto_dh_compute_secret(dh, challenge, DH_KEY_LEN, len = crypto_dh_compute_secret(dh, challenge, DH_KEY_LEN,
key_material, DIGEST_LEN+key_out_len); key_material, DIGEST_LEN+key_out_len);
if (len < 0) { if (len < 0) {
log_fn(LOG_INFO, "crypto_dh_compute_secret failed."); info(LD_GENERAL, "crypto_dh_compute_secret failed.");
goto err; goto err;
} }
@ -327,7 +329,7 @@ onion_skin_client_handshake(crypto_dh_env_t *handshake_state,
if (memcmp(key_material, handshake_reply+DH_KEY_LEN, 20)) { if (memcmp(key_material, handshake_reply+DH_KEY_LEN, 20)) {
/* H(K) does *not* match. Something fishy. */ /* H(K) does *not* match. Something fishy. */
tor_free(key_material); tor_free(key_material);
log_fn(LOG_WARN,"Digest DOES NOT MATCH on onion handshake. Bug or attack."); warn(LD_PROTOCOL,"Digest DOES NOT MATCH on onion handshake. Bug or attack.");
return -1; return -1;
} }
@ -393,7 +395,7 @@ fast_client_handshake(const char *handshake_state, /* DIGEST_LEN bytes */
if (memcmp(digest, handshake_reply_out+DIGEST_LEN, DIGEST_LEN)) { if (memcmp(digest, handshake_reply_out+DIGEST_LEN, DIGEST_LEN)) {
/* H(K) does *not* match. Something fishy. */ /* H(K) does *not* match. Something fishy. */
log_fn(LOG_WARN,"Digest DOES NOT MATCH on fast handshake. Bug or attack."); warn(LD_PROTOCOL,"Digest DOES NOT MATCH on fast handshake. Bug or attack.");
return -1; return -1;
} }

76
src/or/rendclient.c
View File

@ -8,6 +8,7 @@ const char rendclient_c_id[] = "$Id$";
* \brief Client code to access location-hidden services. * \brief Client code to access location-hidden services.
**/ **/
#define NEW_LOG_INTERFACE
#include "or.h" #include "or.h"
/** Called when we've established a circuit to an introduction point: /** Called when we've established a circuit to an introduction point:
@ -19,7 +20,7 @@ rend_client_introcirc_has_opened(circuit_t *circ)
tor_assert(CIRCUIT_IS_ORIGIN(circ)); tor_assert(CIRCUIT_IS_ORIGIN(circ));
tor_assert(circ->cpath); tor_assert(circ->cpath);
log_fn(LOG_INFO,"introcirc is open"); info(LD_REND,"introcirc is open");
connection_ap_attach_pending(); connection_ap_attach_pending();
} }
@ -30,10 +31,10 @@ static int
rend_client_send_establish_rendezvous(circuit_t *circ) rend_client_send_establish_rendezvous(circuit_t *circ)
{ {
tor_assert(circ->purpose == CIRCUIT_PURPOSE_C_ESTABLISH_REND); tor_assert(circ->purpose == CIRCUIT_PURPOSE_C_ESTABLISH_REND);
log_fn(LOG_INFO, "Sending an ESTABLISH_RENDEZVOUS cell"); info(LD_REND, "Sending an ESTABLISH_RENDEZVOUS cell");
if (crypto_rand(circ->rend_cookie, REND_COOKIE_LEN) < 0) { if (crypto_rand(circ->rend_cookie, REND_COOKIE_LEN) < 0) {
log_fn(LOG_WARN, "Internal error: Couldn't produce random cookie."); warn(LD_GENERAL, "Internal error: Couldn't produce random cookie.");
circuit_mark_for_close(circ); circuit_mark_for_close(circ);
return -1; return -1;
} }
@ -42,7 +43,7 @@ rend_client_send_establish_rendezvous(circuit_t *circ)
circ->rend_cookie, REND_COOKIE_LEN, circ->rend_cookie, REND_COOKIE_LEN,
circ->cpath->prev)<0) { circ->cpath->prev)<0) {
/* circ is already marked for close */ /* circ is already marked for close */
log_fn(LOG_WARN, "Couldn't send ESTABLISH_RENDEZVOUS cell"); warn(LD_GENERAL, "Couldn't send ESTABLISH_RENDEZVOUS cell");
return -1; return -1;
} }
@ -68,14 +69,14 @@ rend_client_send_introduction(circuit_t *introcirc, circuit_t *rendcirc)
tor_assert(!rend_cmp_service_ids(introcirc->rend_query, rendcirc->rend_query)); tor_assert(!rend_cmp_service_ids(introcirc->rend_query, rendcirc->rend_query));
if (rend_cache_lookup_entry(introcirc->rend_query, -1, &entry) < 1) { if (rend_cache_lookup_entry(introcirc->rend_query, -1, &entry) < 1) {
log_fn(LOG_WARN,"query '%s' didn't have valid rend desc in cache. Failing.", warn(LD_REND,"query '%s' didn't have valid rend desc in cache. Failing.",
safe_str(introcirc->rend_query)); safe_str(introcirc->rend_query));
goto err; goto err;
} }
/* first 20 bytes of payload are the hash of bob's pk */ /* first 20 bytes of payload are the hash of bob's pk */
if (crypto_pk_get_digest(entry->parsed->pk, payload)<0) { if (crypto_pk_get_digest(entry->parsed->pk, payload)<0) {
log_fn(LOG_WARN, "Internal error: couldn't hash public key."); warn(LD_GENERAL, "Internal error: couldn't hash public key.");
goto err; goto err;
} }
@ -86,11 +87,11 @@ rend_client_send_introduction(circuit_t *introcirc, circuit_t *rendcirc)
tor_malloc_zero(sizeof(crypt_path_t)); tor_malloc_zero(sizeof(crypt_path_t));
cpath->magic = CRYPT_PATH_MAGIC; cpath->magic = CRYPT_PATH_MAGIC;
if (!(cpath->dh_handshake_state = crypto_dh_new())) { if (!(cpath->dh_handshake_state = crypto_dh_new())) {
log_fn(LOG_WARN, "Internal error: couldn't allocate DH."); warn(LD_GENERAL, "Internal error: couldn't allocate DH.");
goto err; goto err;
} }
if (crypto_dh_generate_public(cpath->dh_handshake_state)<0) { if (crypto_dh_generate_public(cpath->dh_handshake_state)<0) {
log_fn(LOG_WARN, "Internal error: couldn't generate g^x."); warn(LD_GENERAL, "Internal error: couldn't generate g^x.");
goto err; goto err;
} }
} }
@ -119,7 +120,7 @@ rend_client_send_introduction(circuit_t *introcirc, circuit_t *rendcirc)
if (crypto_dh_get_public(cpath->dh_handshake_state, tmp+dh_offset, if (crypto_dh_get_public(cpath->dh_handshake_state, tmp+dh_offset,
DH_KEY_LEN)<0) { DH_KEY_LEN)<0) {
log_fn(LOG_WARN, "Internal error: couldn't extract g^x."); warn(LD_GENERAL, "Internal error: couldn't extract g^x.");
goto err; goto err;
} }
@ -129,7 +130,7 @@ rend_client_send_introduction(circuit_t *introcirc, circuit_t *rendcirc)
dh_offset+DH_KEY_LEN, dh_offset+DH_KEY_LEN,
PK_PKCS1_OAEP_PADDING, 0); PK_PKCS1_OAEP_PADDING, 0);
if (r<0) { if (r<0) {
log_fn(LOG_WARN,"Internal error: hybrid pk encrypt failed."); warn(LD_GENERAL,"Internal error: hybrid pk encrypt failed.");
goto err; goto err;
} }
@ -141,7 +142,7 @@ rend_client_send_introduction(circuit_t *introcirc, circuit_t *rendcirc)
payload, payload_len, payload, payload_len,
introcirc->cpath->prev)<0) { introcirc->cpath->prev)<0) {
/* introcirc is already marked for close. leave rendcirc alone. */ /* introcirc is already marked for close. leave rendcirc alone. */
log_fn(LOG_WARN, "Couldn't send INTRODUCE1 cell"); warn(LD_GENERAL, "Couldn't send INTRODUCE1 cell");
return -1; return -1;
} }
@ -163,7 +164,7 @@ rend_client_rendcirc_has_opened(circuit_t *circ)
tor_assert(circ->purpose == CIRCUIT_PURPOSE_C_ESTABLISH_REND); tor_assert(circ->purpose == CIRCUIT_PURPOSE_C_ESTABLISH_REND);
tor_assert(CIRCUIT_IS_ORIGIN(circ)); tor_assert(CIRCUIT_IS_ORIGIN(circ));
log_fn(LOG_INFO,"rendcirc is open"); info(LD_REND,"rendcirc is open");
/* generate a rendezvous cookie, store it in circ */ /* generate a rendezvous cookie, store it in circ */
if (rend_client_send_establish_rendezvous(circ) < 0) { if (rend_client_send_establish_rendezvous(circ) < 0) {
@ -180,7 +181,7 @@ rend_client_introduction_acked(circuit_t *circ,
circuit_t *rendcirc; circuit_t *rendcirc;
if (circ->purpose != CIRCUIT_PURPOSE_C_INTRODUCE_ACK_WAIT) { if (circ->purpose != CIRCUIT_PURPOSE_C_INTRODUCE_ACK_WAIT) {
log_fn(LOG_WARN, "Received REND_INTRODUCE_ACK on unexpected circuit %d.", warn(LD_PROTOCOL, "Received REND_INTRODUCE_ACK on unexpected circuit %d.",
circ->n_circ_id); circ->n_circ_id);
circuit_mark_for_close(circ); circuit_mark_for_close(circ);
return -1; return -1;
@ -194,13 +195,13 @@ rend_client_introduction_acked(circuit_t *circ,
/* Locate the rend circ which is waiting to hear about this ack, /* Locate the rend circ which is waiting to hear about this ack,
* and tell it. * and tell it.
*/ */
log_fn(LOG_INFO,"Received ack. Telling rend circ..."); info(LD_REND,"Received ack. Telling rend circ...");
rendcirc = circuit_get_by_rend_query_and_purpose( rendcirc = circuit_get_by_rend_query_and_purpose(
circ->rend_query, CIRCUIT_PURPOSE_C_REND_READY); circ->rend_query, CIRCUIT_PURPOSE_C_REND_READY);
if (rendcirc) { /* remember the ack */ if (rendcirc) { /* remember the ack */
rendcirc->purpose = CIRCUIT_PURPOSE_C_REND_READY_INTRO_ACKED; rendcirc->purpose = CIRCUIT_PURPOSE_C_REND_READY_INTRO_ACKED;
} else { } else {
log_fn(LOG_INFO,"...Found no rend circ. Dropping on the floor."); info(LD_REND,"...Found no rend circ. Dropping on the floor.");
} }
/* close the circuit: we won't need it anymore. */ /* close the circuit: we won't need it anymore. */
circ->purpose = CIRCUIT_PURPOSE_C_INTRODUCE_ACKED; circ->purpose = CIRCUIT_PURPOSE_C_INTRODUCE_ACKED;
@ -220,15 +221,16 @@ rend_client_introduction_acked(circuit_t *circ,
int result; int result;
info = rend_client_get_random_intro(circ->rend_query); info = rend_client_get_random_intro(circ->rend_query);
if (!info) { if (!info) {
log_fn(LOG_WARN, "No introduction points left for %s. Closing.", warn(LD_REND, "No introduction points left for %s. Closing.",
safe_str(circ->rend_query)); safe_str(circ->rend_query));
circuit_mark_for_close(circ); circuit_mark_for_close(circ);
return -1; return -1;
} }
log_fn(LOG_INFO,"Got nack for %s from %s. Re-extending circ %d, this time to %s.", info(LD_REND,
safe_str(circ->rend_query), "Got nack for %s from %s. Re-extending circ %d, this time to %s.",
circ->build_state->chosen_exit->nickname, circ->n_circ_id, safe_str(circ->rend_query),
info->nickname); circ->build_state->chosen_exit->nickname, circ->n_circ_id,
info->nickname);
result = circuit_extend_to_new_exit(circ, info); result = circuit_extend_to_new_exit(circ, info);
extend_info_free(info); extend_info_free(info);
return result; return result;
@ -245,7 +247,7 @@ void
rend_client_refetch_renddesc(const char *query) rend_client_refetch_renddesc(const char *query)
{ {
if (connection_get_by_type_state_rendquery(CONN_TYPE_DIR, 0, query)) { if (connection_get_by_type_state_rendquery(CONN_TYPE_DIR, 0, query)) {
log_fn(LOG_INFO,"Would fetch a new renddesc here (for %s), but one is already in progress.", safe_str(query)); info(LD_REND,"Would fetch a new renddesc here (for %s), but one is already in progress.", safe_str(query));
} else { } else {
/* not one already; initiate a dir rend desc lookup */ /* not one already; initiate a dir rend desc lookup */
directory_get_from_dirserver(DIR_PURPOSE_FETCH_RENDDESC, query, 1); directory_get_from_dirserver(DIR_PURPOSE_FETCH_RENDDESC, query, 1);
@ -267,11 +269,11 @@ rend_client_remove_intro_point(extend_info_t *failed_intro, const char *query)
r = rend_cache_lookup_entry(query, -1, &ent); r = rend_cache_lookup_entry(query, -1, &ent);
if (r<0) { if (r<0) {
log_fn(LOG_WARN, "Bug: malformed service ID '%s'.", safe_str(query)); warn(LD_GENERAL, "Bug: malformed service ID '%s'.", safe_str(query));
return -1; return -1;
} }
if (r==0) { if (r==0) {
log_fn(LOG_INFO, "Unknown service %s. Re-fetching descriptor.", info(LD_REND, "Unknown service %s. Re-fetching descriptor.",
safe_str(query)); safe_str(query));
rend_client_refetch_renddesc(query); rend_client_refetch_renddesc(query);
return 0; return 0;
@ -306,7 +308,7 @@ rend_client_remove_intro_point(extend_info_t *failed_intro, const char *query)
} }
if (!ent->parsed->n_intro_points) { if (!ent->parsed->n_intro_points) {
log_fn(LOG_INFO,"No more intro points remain for %s. Re-fetching descriptor.", info(LD_REND,"No more intro points remain for %s. Re-fetching descriptor.",
safe_str(query)); safe_str(query));
rend_client_refetch_renddesc(query); rend_client_refetch_renddesc(query);
@ -318,8 +320,8 @@ rend_client_remove_intro_point(extend_info_t *failed_intro, const char *query)
return 0; return 0;
} }
log_fn(LOG_INFO,"%d options left for %s.", info(LD_REND,"%d options left for %s.",
ent->parsed->n_intro_points, safe_str(query)); ent->parsed->n_intro_points, safe_str(query));
return 1; return 1;
} }
@ -331,11 +333,11 @@ rend_client_rendezvous_acked(circuit_t *circ, const char *request, size_t reques
{ {
/* we just got an ack for our establish-rendezvous. switch purposes. */ /* we just got an ack for our establish-rendezvous. switch purposes. */
if (circ->purpose != CIRCUIT_PURPOSE_C_ESTABLISH_REND) { if (circ->purpose != CIRCUIT_PURPOSE_C_ESTABLISH_REND) {
log_fn(LOG_WARN,"Got a rendezvous ack when we weren't expecting one. Closing circ."); warn(LD_PROTOCOL,"Got a rendezvous ack when we weren't expecting one. Closing circ.");
circuit_mark_for_close(circ); circuit_mark_for_close(circ);
return -1; return -1;
} }
log_fn(LOG_INFO,"Got rendezvous ack. This circuit is now ready for rendezvous."); info(LD_REND,"Got rendezvous ack. This circuit is now ready for rendezvous.");
circ->purpose = CIRCUIT_PURPOSE_C_REND_READY; circ->purpose = CIRCUIT_PURPOSE_C_REND_READY;
return 0; return 0;
} }
@ -350,13 +352,13 @@ rend_client_receive_rendezvous(circuit_t *circ, const char *request, size_t requ
if ((circ->purpose != CIRCUIT_PURPOSE_C_REND_READY && if ((circ->purpose != CIRCUIT_PURPOSE_C_REND_READY &&
circ->purpose != CIRCUIT_PURPOSE_C_REND_READY_INTRO_ACKED) circ->purpose != CIRCUIT_PURPOSE_C_REND_READY_INTRO_ACKED)
|| !circ->build_state->pending_final_cpath) { || !circ->build_state->pending_final_cpath) {
log_fn(LOG_WARN,"Got rendezvous2 cell from hidden service, but not expecting it. Closing."); warn(LD_PROTOCOL,"Got rendezvous2 cell from hidden service, but not expecting it. Closing.");
circuit_mark_for_close(circ); circuit_mark_for_close(circ);
return -1; return -1;
} }
if (request_len != DH_KEY_LEN+DIGEST_LEN) { if (request_len != DH_KEY_LEN+DIGEST_LEN) {
log_fn(LOG_WARN,"Incorrect length (%d) on RENDEZVOUS2 cell.",(int)request_len); warn(LD_PROTOCOL,"Incorrect length (%d) on RENDEZVOUS2 cell.",(int)request_len);
goto err; goto err;
} }
@ -367,7 +369,7 @@ rend_client_receive_rendezvous(circuit_t *circ, const char *request, size_t requ
tor_assert(hop->dh_handshake_state); tor_assert(hop->dh_handshake_state);
if (crypto_dh_compute_secret(hop->dh_handshake_state, request, DH_KEY_LEN, if (crypto_dh_compute_secret(hop->dh_handshake_state, request, DH_KEY_LEN,
keys, DIGEST_LEN+CPATH_KEY_MATERIAL_LEN)<0) { keys, DIGEST_LEN+CPATH_KEY_MATERIAL_LEN)<0) {
log_fn(LOG_WARN, "Couldn't complete DH handshake."); warn(LD_GENERAL, "Couldn't complete DH handshake.");
goto err; goto err;
} }
/* ... and set up cpath. */ /* ... and set up cpath. */
@ -376,7 +378,7 @@ rend_client_receive_rendezvous(circuit_t *circ, const char *request, size_t requ
/* Check whether the digest is right... */ /* Check whether the digest is right... */
if (memcmp(keys, request+DH_KEY_LEN, DIGEST_LEN)) { if (memcmp(keys, request+DH_KEY_LEN, DIGEST_LEN)) {
log_fn(LOG_WARN, "Incorrect digest of key material."); warn(LD_PROTOCOL, "Incorrect digest of key material.");
goto err; goto err;
} }
@ -418,7 +420,7 @@ rend_client_desc_here(const char *query)
entry->parsed->n_intro_points > 0) { entry->parsed->n_intro_points > 0) {
/* either this fetch worked, or it failed but there was a /* either this fetch worked, or it failed but there was a
* valid entry from before which we should reuse */ * valid entry from before which we should reuse */
log_fn(LOG_INFO,"Rend desc is usable. Launching circuits."); info(LD_REND,"Rend desc is usable. Launching circuits.");
conn->state = AP_CONN_STATE_CIRCUIT_WAIT; conn->state = AP_CONN_STATE_CIRCUIT_WAIT;
/* restart their timeout values, so they get a fair shake at /* restart their timeout values, so they get a fair shake at
@ -429,12 +431,12 @@ rend_client_desc_here(const char *query)
if (connection_ap_handshake_attach_circuit(conn) < 0) { if (connection_ap_handshake_attach_circuit(conn) < 0) {
/* it will never work */ /* it will never work */
log_fn(LOG_WARN,"Rendezvous attempt failed. Closing."); warn(LD_REND,"Rendezvous attempt failed. Closing.");
connection_mark_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH); connection_mark_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
} }
tor_assert(conn->state != AP_CONN_STATE_RENDDESC_WAIT); /* avoid loop */ tor_assert(conn->state != AP_CONN_STATE_RENDDESC_WAIT); /* avoid loop */
} else { /* 404, or fetch didn't get that far */ } else { /* 404, or fetch didn't get that far */
log_fn(LOG_NOTICE,"Closing stream for '%s.onion': hidden service is unavailable (try again later).", safe_str(query)); notice(LD_REND,"Closing stream for '%s.onion': hidden service is unavailable (try again later).", safe_str(query));
connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT); connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT);
} }
} }
@ -451,7 +453,7 @@ rend_client_get_random_intro(const char *query)
rend_cache_entry_t *entry; rend_cache_entry_t *entry;
if (rend_cache_lookup_entry(query, -1, &entry) < 1) { if (rend_cache_lookup_entry(query, -1, &entry) < 1) {
log_fn(LOG_WARN,"Query '%s' didn't have valid rend desc in cache. Failing.", warn(LD_REND,"Query '%s' didn't have valid rend desc in cache. Failing.",
safe_str(query)); safe_str(query));
return NULL; return NULL;
} }
@ -469,7 +471,7 @@ rend_client_get_random_intro(const char *query)
char *choice = entry->parsed->intro_points[i]; char *choice = entry->parsed->intro_points[i];
routerinfo_t *router = router_get_by_nickname(choice, 0); routerinfo_t *router = router_get_by_nickname(choice, 0);
if (!router) { if (!router) {
log_fn(LOG_INFO, "Unknown router with nickname '%s'; trying another.",choice); info(LD_REND, "Unknown router with nickname '%s'; trying another.",choice);
tor_free(choice); tor_free(choice);
entry->parsed->intro_points[i] = entry->parsed->intro_points[i] =
entry->parsed->intro_points[--entry->parsed->n_intro_points]; entry->parsed->intro_points[--entry->parsed->n_intro_points];

23
src/or/rendcommon.c
View File

@ -9,6 +9,7 @@ const char rendcommon_c_id[] = "$Id$";
* introducers, services, clients, and rendezvous points. * introducers, services, clients, and rendezvous points.
**/ **/
#define NEW_LOG_INTERFACE
#include "or.h" #include "or.h"
/** Return 0 if one and two are the same service ids, else -1 or 1 */ /** Return 0 if one and two are the same service ids, else -1 or 1 */
@ -178,7 +179,7 @@ rend_parse_service_descriptor(const char *str, size_t len)
cp += 8+DIGEST_LEN; cp += 8+DIGEST_LEN;
if (end-cp < klen) goto truncated; if (end-cp < klen) goto truncated;
if (!(info->onion_key = crypto_pk_asn1_decode(cp,klen))) { if (!(info->onion_key = crypto_pk_asn1_decode(cp,klen))) {
log_fn(LOG_WARN, "Internal error decoding onion key for intro point."); warn(LD_PROTOCOL, "Internal error decoding onion key for intro point.");
goto error; goto error;
} }
cp += klen; cp += klen;
@ -188,7 +189,7 @@ rend_parse_service_descriptor(const char *str, size_t len)
tor_assert(end-cp >= 0); tor_assert(end-cp >= 0);
if ((size_t)(end-cp) < keylen) goto truncated; if ((size_t)(end-cp) < keylen) goto truncated;
if ((size_t)(end-cp) > keylen) { if ((size_t)(end-cp) > keylen) {
log_fn(LOG_WARN, "Signature is %d bytes too long on service descriptor.", warn(LD_PROTOCOL, "Signature is %d bytes too long on service descriptor.",
(int)((size_t)(end-cp) - keylen)); (int)((size_t)(end-cp) - keylen));
goto error; goto error;
} }
@ -196,13 +197,13 @@ rend_parse_service_descriptor(const char *str, size_t len)
(char*)str,cp-str, /* data */ (char*)str,cp-str, /* data */
(char*)cp,end-cp /* signature*/ (char*)cp,end-cp /* signature*/
)<0) { )<0) {
log_fn(LOG_WARN, "Bad signature on service descriptor."); warn(LD_PROTOCOL, "Bad signature on service descriptor.");
goto error; goto error;
} }
return result; return result;
truncated: truncated:
log_fn(LOG_WARN, "Truncated service descriptor."); warn(LD_PROTOCOL, "Truncated service descriptor.");
error: error:
rend_service_descriptor_free(result); rend_service_descriptor_free(result);
return NULL; return NULL;
@ -361,35 +362,35 @@ rend_cache_store(const char *desc, size_t desc_len)
tor_assert(rend_cache); tor_assert(rend_cache);
parsed = rend_parse_service_descriptor(desc,desc_len); parsed = rend_parse_service_descriptor(desc,desc_len);
if (!parsed) { if (!parsed) {
log_fn(LOG_WARN,"Couldn't parse service descriptor."); warn(LD_PROTOCOL,"Couldn't parse service descriptor.");
return -1; return -1;
} }
if (rend_get_service_id(parsed->pk, query)<0) { if (rend_get_service_id(parsed->pk, query)<0) {
log_fn(LOG_WARN,"Couldn't compute service ID."); warn(LD_GENERAL,"Couldn't compute service ID.");
rend_service_descriptor_free(parsed); rend_service_descriptor_free(parsed);
return -1; return -1;
} }
tor_snprintf(key, sizeof(key), "%c%s", parsed->version?'1':'0', query); tor_snprintf(key, sizeof(key), "%c%s", parsed->version?'1':'0', query);
now = time(NULL); now = time(NULL);
if (parsed->timestamp < now-REND_CACHE_MAX_AGE-REND_CACHE_MAX_SKEW) { if (parsed->timestamp < now-REND_CACHE_MAX_AGE-REND_CACHE_MAX_SKEW) {
log_fn(LOG_WARN,"Service descriptor %s is too old.", safe_str(query)); warn(LD_REND,"Service descriptor %s is too old.", safe_str(query));
rend_service_descriptor_free(parsed); rend_service_descriptor_free(parsed);
return -1; return -1;
} }
if (parsed->timestamp > now+REND_CACHE_MAX_SKEW) { if (parsed->timestamp > now+REND_CACHE_MAX_SKEW) {
log_fn(LOG_WARN,"Service descriptor %s is too far in the future.", warn(LD_REND,"Service descriptor %s is too far in the future.",
safe_str(query)); safe_str(query));
rend_service_descriptor_free(parsed); rend_service_descriptor_free(parsed);
return -1; return -1;
} }
e = (rend_cache_entry_t*) strmap_get_lc(rend_cache, key); e = (rend_cache_entry_t*) strmap_get_lc(rend_cache, key);
if (e && e->parsed->timestamp > parsed->timestamp) { if (e && e->parsed->timestamp > parsed->timestamp) {
log_fn(LOG_INFO,"We already have a newer service descriptor %s with the same ID and version.", safe_str(query)); info(LD_REND,"We already have a newer service descriptor %s with the same ID and version.", safe_str(query));
rend_service_descriptor_free(parsed); rend_service_descriptor_free(parsed);
return 0; return 0;
} }
if (e && e->len == desc_len && !memcmp(desc,e->desc,desc_len)) { if (e && e->len == desc_len && !memcmp(desc,e->desc,desc_len)) {
log_fn(LOG_INFO,"We already have this service descriptor %s.", safe_str(query)); info(LD_REND,"We already have this service descriptor %s.", safe_str(query));
e->received = time(NULL); e->received = time(NULL);
rend_service_descriptor_free(parsed); rend_service_descriptor_free(parsed);
return 0; return 0;
@ -407,7 +408,7 @@ rend_cache_store(const char *desc, size_t desc_len)
e->desc = tor_malloc(desc_len); e->desc = tor_malloc(desc_len);
memcpy(e->desc, desc, desc_len); memcpy(e->desc, desc, desc_len);
log_fn(LOG_DEBUG,"Successfully stored rend desc '%s', len %d.", debug(LD_REND,"Successfully stored rend desc '%s', len %d.",
safe_str(query), (int)desc_len); safe_str(query), (int)desc_len);
return 1; return 1;
} }

97
src/or/rendmid.c
View File

@ -8,6 +8,7 @@ const char rendmid_c_id[] = "$Id$";
* \brief Implement introductions points and rendezvous points. * \brief Implement introductions points and rendezvous points.
**/ **/
#define NEW_LOG_INTERFACE
#include "or.h" #include "or.h"
/** Respond to an ESTABLISH_INTRO cell by checking the signed data and /** Respond to an ESTABLISH_INTRO cell by checking the signed data and
@ -24,11 +25,11 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, size_t request_le
circuit_t *c; circuit_t *c;
char serviceid[REND_SERVICE_ID_LEN+1]; char serviceid[REND_SERVICE_ID_LEN+1];
log_fn(LOG_INFO, info(LD_REND,
"Received an ESTABLISH_INTRO request on circuit %d", circ->p_circ_id); "Received an ESTABLISH_INTRO request on circuit %d", circ->p_circ_id);
if (circ->purpose != CIRCUIT_PURPOSE_OR || circ->n_conn) { if (circ->purpose != CIRCUIT_PURPOSE_OR || circ->n_conn) {
log_fn(LOG_WARN, "Rejecting ESTABLISH_INTRO on non-OR or non-edge circuit."); warn(LD_PROTOCOL, "Rejecting ESTABLISH_INTRO on non-OR or non-edge circuit.");
goto err; goto err;
} }
if (request_len < 2+DIGEST_LEN) if (request_len < 2+DIGEST_LEN)
@ -41,7 +42,7 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, size_t request_le
goto truncated; goto truncated;
pk = crypto_pk_asn1_decode(request+2, asn1len); pk = crypto_pk_asn1_decode(request+2, asn1len);
if (!pk) { if (!pk) {
log_fn(LOG_WARN, "Couldn't decode public key."); warn(LD_PROTOCOL, "Couldn't decode public key.");
goto err; goto err;
} }
@ -49,24 +50,24 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, size_t request_le
memcpy(buf, circ->handshake_digest, DIGEST_LEN); memcpy(buf, circ->handshake_digest, DIGEST_LEN);
memcpy(buf+DIGEST_LEN, "INTRODUCE", 9); memcpy(buf+DIGEST_LEN, "INTRODUCE", 9);
if (crypto_digest(expected_digest, buf, DIGEST_LEN+9) < 0) { if (crypto_digest(expected_digest, buf, DIGEST_LEN+9) < 0) {
log_fn(LOG_WARN, "Internal error computing digest."); warn(LD_GENERAL, "Internal error computing digest.");
goto err; goto err;
} }
if (memcmp(expected_digest, request+2+asn1len, DIGEST_LEN)) { if (memcmp(expected_digest, request+2+asn1len, DIGEST_LEN)) {
log_fn(LOG_WARN, "Hash of session info was not as expected."); warn(LD_PROTOCOL, "Hash of session info was not as expected.");
goto err; goto err;
} }
/* Rest of body: signature of previous data */ /* Rest of body: signature of previous data */
if (crypto_pk_public_checksig_digest(pk, request, 2+asn1len+DIGEST_LEN, if (crypto_pk_public_checksig_digest(pk, request, 2+asn1len+DIGEST_LEN,
request+2+DIGEST_LEN+asn1len, request+2+DIGEST_LEN+asn1len,
request_len-(2+DIGEST_LEN+asn1len))<0) { request_len-(2+DIGEST_LEN+asn1len))<0) {
log_fn(LOG_WARN, "Incorrect signature on ESTABLISH_INTRO cell; rejecting."); warn(LD_PROTOCOL, "Incorrect signature on ESTABLISH_INTRO cell; rejecting.");
goto err; goto err;
} }
/* The request is valid. First, compute the hash of Bob's PK.*/ /* The request is valid. First, compute the hash of Bob's PK.*/
if (crypto_pk_get_digest(pk, pk_digest)<0) { if (crypto_pk_get_digest(pk, pk_digest)<0) {
log_fn(LOG_WARN, "Internal error: couldn't hash public key."); warn(LD_GENERAL, "Internal error: couldn't hash public key.");
goto err; goto err;
} }
@ -79,7 +80,7 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, size_t request_le
c = NULL; c = NULL;
while ((c = circuit_get_next_by_pk_and_purpose( while ((c = circuit_get_next_by_pk_and_purpose(
c,pk_digest,CIRCUIT_PURPOSE_INTRO_POINT))) { c,pk_digest,CIRCUIT_PURPOSE_INTRO_POINT))) {
log_fn(LOG_INFO, "Replacing old circuit %d for service %s", info(LD_REND, "Replacing old circuit %d for service %s",
c->p_circ_id, safe_str(serviceid)); c->p_circ_id, safe_str(serviceid));
circuit_mark_for_close(c); circuit_mark_for_close(c);
} }
@ -88,7 +89,7 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, size_t request_le
if (connection_edge_send_command(NULL,circ, if (connection_edge_send_command(NULL,circ,
RELAY_COMMAND_INTRO_ESTABLISHED, RELAY_COMMAND_INTRO_ESTABLISHED,
"", 0, NULL)<0) { "", 0, NULL)<0) {
log_fn(LOG_INFO, "Couldn't send INTRO_ESTABLISHED cell."); info(LD_GENERAL, "Couldn't send INTRO_ESTABLISHED cell.");
goto err; goto err;
} }
@ -96,13 +97,13 @@ rend_mid_establish_intro(circuit_t *circ, const char *request, size_t request_le
circ->purpose = CIRCUIT_PURPOSE_INTRO_POINT; circ->purpose = CIRCUIT_PURPOSE_INTRO_POINT;
memcpy(circ->rend_pk_digest, pk_digest, DIGEST_LEN); memcpy(circ->rend_pk_digest, pk_digest, DIGEST_LEN);
log_fn(LOG_INFO, info(LD_REND,
"Established introduction point on circuit %d for service %s", "Established introduction point on circuit %d for service %s",
circ->p_circ_id, safe_str(serviceid)); circ->p_circ_id, safe_str(serviceid));
return 0; return 0;
truncated: truncated:
log_fn(LOG_WARN, "Rejecting truncated ESTABLISH_INTRO cell."); warn(LD_PROTOCOL, "Rejecting truncated ESTABLISH_INTRO cell.");
err: err:
if (pk) crypto_free_pk_env(pk); if (pk) crypto_free_pk_env(pk);
circuit_mark_for_close(circ); circuit_mark_for_close(circ);
@ -121,7 +122,7 @@ rend_mid_introduce(circuit_t *circ, const char *request, size_t request_len)
char nak_body[1]; char nak_body[1];
if (circ->purpose != CIRCUIT_PURPOSE_OR || circ->n_conn) { if (circ->purpose != CIRCUIT_PURPOSE_OR || circ->n_conn) {
log_fn(LOG_WARN, "Rejecting INTRODUCE1 on non-OR or non-edge circuit %d.", warn(LD_PROTOCOL, "Rejecting INTRODUCE1 on non-OR or non-edge circuit %d.",
circ->p_circ_id); circ->p_circ_id);
goto err; goto err;
} }
@ -129,9 +130,9 @@ rend_mid_introduce(circuit_t *circ, const char *request, size_t request_len)
/* change to MAX_HEX_NICKNAME_LEN once 0.0.9.x is obsolete */ /* change to MAX_HEX_NICKNAME_LEN once 0.0.9.x is obsolete */
if (request_len < (DIGEST_LEN+(MAX_NICKNAME_LEN+1)+REND_COOKIE_LEN+ if (request_len < (DIGEST_LEN+(MAX_NICKNAME_LEN+1)+REND_COOKIE_LEN+
DH_KEY_LEN+CIPHER_KEY_LEN+PKCS1_OAEP_PADDING_OVERHEAD)) { DH_KEY_LEN+CIPHER_KEY_LEN+PKCS1_OAEP_PADDING_OVERHEAD)) {
log_fn(LOG_WARN, warn(LD_PROTOCOL,
"Impossibly short INTRODUCE1 cell on circuit %d; responding with nack.", "Impossibly short INTRODUCE1 cell on circuit %d; responding with nack.",
circ->p_circ_id); circ->p_circ_id);
goto err; goto err;
} }
@ -141,27 +142,28 @@ rend_mid_introduce(circuit_t *circ, const char *request, size_t request_len)
intro_circ = circuit_get_next_by_pk_and_purpose( intro_circ = circuit_get_next_by_pk_and_purpose(
NULL, request, CIRCUIT_PURPOSE_INTRO_POINT); NULL, request, CIRCUIT_PURPOSE_INTRO_POINT);
if (!intro_circ) { if (!intro_circ) {
log_fn(LOG_INFO, info(LD_REND,
"No intro circ found for INTRODUCE1 cell (%s) from circuit %d; responding with nack.", "No intro circ found for INTRODUCE1 cell (%s) from circuit %d; responding with nack.",
safe_str(serviceid), circ->p_circ_id); safe_str(serviceid), circ->p_circ_id);
goto err; goto err;
} }
log_fn(LOG_INFO, info(LD_REND,
"Sending introduction request for service %s from circ %d to circ %d", "Sending introduction request for service %s from circ %d to circ %d",
safe_str(serviceid), circ->p_circ_id, intro_circ->p_circ_id); safe_str(serviceid), circ->p_circ_id, intro_circ->p_circ_id);
/* Great. Now we just relay the cell down the circuit. */ /* Great. Now we just relay the cell down the circuit. */
if (connection_edge_send_command(NULL, intro_circ, if (connection_edge_send_command(NULL, intro_circ,
RELAY_COMMAND_INTRODUCE2, RELAY_COMMAND_INTRODUCE2,
request, request_len, NULL)) { request, request_len, NULL)) {
log_fn(LOG_WARN, "Unable to send INTRODUCE2 cell to Tor client."); warn(LD_GENERAL,
"Unable to send INTRODUCE2 cell to Tor client.");
goto err; goto err;
} }
/* And sent an ack down Alice's circuit. Empty body means succeeded. */ /* And sent an ack down Alice's circuit. Empty body means succeeded. */
if (connection_edge_send_command(NULL,circ,RELAY_COMMAND_INTRODUCE_ACK, if (connection_edge_send_command(NULL,circ,RELAY_COMMAND_INTRODUCE_ACK,
NULL,0,NULL)) { NULL,0,NULL)) {
log_fn(LOG_WARN, "Unable to send INTRODUCE_ACK cell to Tor client."); warn(LD_GENERAL, "Unable to send INTRODUCE_ACK cell to Tor client.");
circuit_mark_for_close(circ); circuit_mark_for_close(circ);
return -1; return -1;
} }
@ -172,7 +174,7 @@ rend_mid_introduce(circuit_t *circ, const char *request, size_t request_len)
nak_body[0] = 1; nak_body[0] = 1;
if (connection_edge_send_command(NULL,circ,RELAY_COMMAND_INTRODUCE_ACK, if (connection_edge_send_command(NULL,circ,RELAY_COMMAND_INTRODUCE_ACK,
nak_body, 1, NULL)) { nak_body, 1, NULL)) {
log_fn(LOG_WARN, "Unable to send NAK to Tor client."); warn(LD_GENERAL, "Unable to send NAK to Tor client.");
circuit_mark_for_close(circ); /* Is this right? */ circuit_mark_for_close(circ); /* Is this right? */
} }
return -1; return -1;
@ -187,17 +189,17 @@ rend_mid_establish_rendezvous(circuit_t *circ, const char *request, size_t reque
char hexid[9]; char hexid[9];
if (circ->purpose != CIRCUIT_PURPOSE_OR || circ->n_conn) { if (circ->purpose != CIRCUIT_PURPOSE_OR || circ->n_conn) {
log_fn(LOG_WARN, "Tried to establish rendezvous on non-OR or non-edge circuit."); warn(LD_PROTOCOL, "Tried to establish rendezvous on non-OR or non-edge circuit.");
goto err; goto err;
} }
if (request_len != REND_COOKIE_LEN) { if (request_len != REND_COOKIE_LEN) {
log_fn(LOG_WARN, "Invalid length on ESTABLISH_RENDEZVOUS."); warn(LD_PROTOCOL, "Invalid length on ESTABLISH_RENDEZVOUS.");
goto err; goto err;
} }
if (circuit_get_rendezvous(request)) { if (circuit_get_rendezvous(request)) {
log_fn(LOG_WARN, "Duplicate rendezvous cookie in ESTABLISH_RENDEZVOUS."); warn(LD_PROTOCOL, "Duplicate rendezvous cookie in ESTABLISH_RENDEZVOUS.");
goto err; goto err;
} }
@ -205,7 +207,7 @@ rend_mid_establish_rendezvous(circuit_t *circ, const char *request, size_t reque
if (connection_edge_send_command(NULL,circ, if (connection_edge_send_command(NULL,circ,
RELAY_COMMAND_RENDEZVOUS_ESTABLISHED, RELAY_COMMAND_RENDEZVOUS_ESTABLISHED,
"", 0, NULL)<0) { "", 0, NULL)<0) {
log_fn(LOG_WARN, "Couldn't send RENDEZVOUS_ESTABLISHED cell."); warn(LD_PROTOCOL, "Couldn't send RENDEZVOUS_ESTABLISHED cell.");
goto err; goto err;
} }
@ -214,7 +216,7 @@ rend_mid_establish_rendezvous(circuit_t *circ, const char *request, size_t reque
base16_encode(hexid,9,request,4); base16_encode(hexid,9,request,4);
log_fn(LOG_INFO, "Established rendezvous point on circuit %d for cookie %s", info(LD_REND, "Established rendezvous point on circuit %d for cookie %s",
circ->p_circ_id, hexid); circ->p_circ_id, hexid);
return 0; return 0;
@ -236,29 +238,29 @@ rend_mid_rendezvous(circuit_t *circ, const char *request, size_t request_len)
base16_encode(hexid,9,request,request_len<4?request_len:4); base16_encode(hexid,9,request,request_len<4?request_len:4);
if (request_len>=4) { if (request_len>=4) {
log_fn(LOG_INFO, "Got request for rendezvous from circuit %d to cookie %s.", info(LD_REND, "Got request for rendezvous from circuit %d to cookie %s.",
circ->p_circ_id, hexid); circ->p_circ_id, hexid);
} }
if (circ->purpose != CIRCUIT_PURPOSE_OR || circ->n_conn) { if (circ->purpose != CIRCUIT_PURPOSE_OR || circ->n_conn) {
log_fn(LOG_WARN, info(LD_REND,
"Tried to complete rendezvous on non-OR or non-edge circuit %d.", "Tried to complete rendezvous on non-OR or non-edge circuit %d.",
circ->p_circ_id); circ->p_circ_id);
goto err; goto err;
} }
if (request_len != REND_COOKIE_LEN+DH_KEY_LEN+DIGEST_LEN) { if (request_len != REND_COOKIE_LEN+DH_KEY_LEN+DIGEST_LEN) {
log_fn(LOG_WARN, warn(LD_PROTOCOL,
"Rejecting RENDEZVOUS1 cell with bad length (%d) on circuit %d.", "Rejecting RENDEZVOUS1 cell with bad length (%d) on circuit %d.",
(int)request_len, circ->p_circ_id); (int)request_len, circ->p_circ_id);
goto err; goto err;
} }
rend_circ = circuit_get_rendezvous(request); rend_circ = circuit_get_rendezvous(request);
if (!rend_circ) { if (!rend_circ) {
log_fn(LOG_INFO, warn(LD_PROTOCOL,
"Rejecting RENDEZVOUS1 cell with unrecognized rendezvous cookie %s.", "Rejecting RENDEZVOUS1 cell with unrecognized rendezvous cookie %s.",
hexid); hexid);
goto err; goto err;
} }
@ -267,15 +269,16 @@ rend_mid_rendezvous(circuit_t *circ, const char *request, size_t request_len)
RELAY_COMMAND_RENDEZVOUS2, RELAY_COMMAND_RENDEZVOUS2,
request+REND_COOKIE_LEN, request+REND_COOKIE_LEN,
request_len-REND_COOKIE_LEN, NULL)) { request_len-REND_COOKIE_LEN, NULL)) {
log_fn(LOG_WARN, "Unable to send RENDEZVOUS2 cell to OP on circuit %d.", warn(LD_GENERAL,
rend_circ->p_circ_id); "Unable to send RENDEZVOUS2 cell to OP on circuit %d.",
rend_circ->p_circ_id);
goto err; goto err;
} }
/* Join the circuits. */ /* Join the circuits. */
log_fn(LOG_INFO, info(LD_REND,
"Completing rendezvous: circuit %d joins circuit %d (cookie %s)", "Completing rendezvous: circuit %d joins circuit %d (cookie %s)",
circ->p_circ_id, rend_circ->p_circ_id, hexid); circ->p_circ_id, rend_circ->p_circ_id, hexid);
circ->purpose = CIRCUIT_PURPOSE_REND_ESTABLISHED; circ->purpose = CIRCUIT_PURPOSE_REND_ESTABLISHED;
rend_circ->purpose = CIRCUIT_PURPOSE_REND_ESTABLISHED; rend_circ->purpose = CIRCUIT_PURPOSE_REND_ESTABLISHED;

135
src/or/rendservice.c
View File

@ -8,6 +8,7 @@ const char rendservice_c_id[] = "$Id$";
* \brief The hidden-service side of rendezvous functionality. * \brief The hidden-service side of rendezvous functionality.
**/ **/
#define NEW_LOG_INTERFACE
#include "or.h" #include "or.h"
static circuit_t *find_intro_circuit(routerinfo_t *router, const char *pk_digest); static circuit_t *find_intro_circuit(routerinfo_t *router, const char *pk_digest);
@ -119,18 +120,18 @@ add_service(rend_service_t *service)
service->intro_exclude_nodes = tor_strdup(""); service->intro_exclude_nodes = tor_strdup("");
if (!smartlist_len(service->ports)) { if (!smartlist_len(service->ports)) {
log_fn(LOG_WARN, "Hidden service with no ports configured; ignoring."); warn(LD_CONFIG, "Hidden service with no ports configured; ignoring.");
rend_service_free(service); rend_service_free(service);
} else { } else {
smartlist_set_capacity(service->ports, -1); smartlist_set_capacity(service->ports, -1);
smartlist_add(rend_service_list, service); smartlist_add(rend_service_list, service);
log_fn(LOG_DEBUG,"Configuring service with directory \"%s\"",service->directory); debug(LD_REND,"Configuring service with directory \"%s\"",service->directory);
for (i = 0; i < smartlist_len(service->ports); ++i) { for (i = 0; i < smartlist_len(service->ports); ++i) {
char addrbuf[INET_NTOA_BUF_LEN]; char addrbuf[INET_NTOA_BUF_LEN];
p = smartlist_get(service->ports, i); p = smartlist_get(service->ports, i);
addr.s_addr = htonl(p->real_addr); addr.s_addr = htonl(p->real_addr);
tor_inet_ntoa(&addr, addrbuf, sizeof(addrbuf)); tor_inet_ntoa(&addr, addrbuf, sizeof(addrbuf));
log_fn(LOG_DEBUG,"Service maps port %d to %s:%d", debug(LD_REND,"Service maps port %d to %s:%d",
p->virtual_port, addrbuf, p->real_port); p->virtual_port, addrbuf, p->real_port);
} }
} }
@ -157,13 +158,13 @@ parse_port_config(const char *string)
sl = smartlist_create(); sl = smartlist_create();
smartlist_split_string(sl, string, " ", SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 0); smartlist_split_string(sl, string, " ", SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 0);
if (smartlist_len(sl) < 1 || smartlist_len(sl) > 2) { if (smartlist_len(sl) < 1 || smartlist_len(sl) > 2) {
log_fn(LOG_WARN, "Bad syntax in hidden service port configuration."); warn(LD_CONFIG, "Bad syntax in hidden service port configuration.");
goto err; goto err;
} }
virtport = atoi(smartlist_get(sl,0)); virtport = atoi(smartlist_get(sl,0));
if (virtport < 1 || virtport > 65535) { if (virtport < 1 || virtport > 65535) {
log_fn(LOG_WARN, "Missing or invalid port in hidden service port configuration."); warn(LD_CONFIG, "Missing or invalid port in hidden service port configuration.");
goto err; goto err;
} }
@ -175,7 +176,7 @@ parse_port_config(const char *string)
addrport = smartlist_get(sl,1); addrport = smartlist_get(sl,1);
if (strchr(addrport, ':') || strchr(addrport, '.')) { if (strchr(addrport, ':') || strchr(addrport, '.')) {
if (parse_addr_port(addrport, NULL, &addr, &p)<0) { if (parse_addr_port(addrport, NULL, &addr, &p)<0) {
log_fn(LOG_WARN,"Unparseable address in hidden service port configuration."); warn(LD_CONFIG,"Unparseable address in hidden service port configuration.");
goto err; goto err;
} }
realport = p?p:virtport; realport = p?p:virtport;
@ -231,7 +232,7 @@ rend_config_services(or_options_t *options, int validate_only)
continue; continue;
} }
if (!service) { if (!service) {
log_fn(LOG_WARN, "HiddenServicePort with no preceding HiddenServiceDir directive."); warn(LD_CONFIG, "HiddenServicePort with no preceding HiddenServiceDir directive.");
rend_service_free(service); rend_service_free(service);
return -1; return -1;
} }
@ -244,14 +245,14 @@ rend_config_services(or_options_t *options, int validate_only)
smartlist_add(service->ports, portcfg); smartlist_add(service->ports, portcfg);
} else if (!strcasecmp(line->key, "HiddenServiceNodes")) { } else if (!strcasecmp(line->key, "HiddenServiceNodes")) {
if (service->intro_prefer_nodes) { if (service->intro_prefer_nodes) {
log_fn(LOG_WARN, "Got multiple HiddenServiceNodes lines for a single service."); warn(LD_CONFIG, "Got multiple HiddenServiceNodes lines for a single service.");
return -1; return -1;
} }
service->intro_prefer_nodes = tor_strdup(line->value); service->intro_prefer_nodes = tor_strdup(line->value);
} else { } else {
tor_assert(!strcasecmp(line->key, "HiddenServiceExcludeNodes")); tor_assert(!strcasecmp(line->key, "HiddenServiceExcludeNodes"));
if (service->intro_exclude_nodes) { if (service->intro_exclude_nodes) {
log_fn(LOG_WARN, "Got multiple HiddenServiceExcludedNodes lines for a single service."); warn(LD_CONFIG, "Got multiple HiddenServiceExcludedNodes lines for a single service.");
return -1; return -1;
} }
service->intro_exclude_nodes = tor_strdup(line->value); service->intro_exclude_nodes = tor_strdup(line->value);
@ -294,7 +295,7 @@ rend_service_update_descriptor(rend_service_t *service)
for (i=0; i < n; ++i) { for (i=0; i < n; ++i) {
router = router_get_by_nickname(smartlist_get(service->intro_nodes, i),1); router = router_get_by_nickname(smartlist_get(service->intro_nodes, i),1);
if (!router) { if (!router) {
log_fn(LOG_INFO,"Router '%s' not found. Skipping.", info(LD_REND,"Router '%s' not found. Skipping.",
(char*)smartlist_get(service->intro_nodes, i)); (char*)smartlist_get(service->intro_nodes, i));
continue; continue;
} }
@ -324,7 +325,7 @@ rend_service_load_keys(void)
s = smartlist_get(rend_service_list,i); s = smartlist_get(rend_service_list,i);
if (s->private_key) if (s->private_key)
continue; continue;
log_fn(LOG_INFO, "Loading hidden-service keys from \"%s\"", s->directory); info(LD_REND, "Loading hidden-service keys from \"%s\"", s->directory);
/* Check/create directory */ /* Check/create directory */
if (check_private_dir(s->directory, CPD_CREATE) < 0) if (check_private_dir(s->directory, CPD_CREATE) < 0)
@ -333,7 +334,7 @@ rend_service_load_keys(void)
/* Load key */ /* Load key */
if (strlcpy(fname,s->directory,sizeof(fname)) >= sizeof(fname) || if (strlcpy(fname,s->directory,sizeof(fname)) >= sizeof(fname) ||
strlcat(fname,"/private_key",sizeof(fname)) >= sizeof(fname)) { strlcat(fname,"/private_key",sizeof(fname)) >= sizeof(fname)) {
log_fn(LOG_WARN, "Directory name too long: \"%s\".", s->directory); warn(LD_CONFIG, "Directory name too long: \"%s\".", s->directory);
return -1; return -1;
} }
s->private_key = init_key_from_file(fname); s->private_key = init_key_from_file(fname);
@ -342,16 +343,16 @@ rend_service_load_keys(void)
/* Create service file */ /* Create service file */
if (rend_get_service_id(s->private_key, s->service_id)<0) { if (rend_get_service_id(s->private_key, s->service_id)<0) {
log_fn(LOG_WARN, "Internal error: couldn't encode service ID."); warn(LD_GENERAL, "Internal error: couldn't encode service ID.");
return -1; return -1;
} }
if (crypto_pk_get_digest(s->private_key, s->pk_digest)<0) { if (crypto_pk_get_digest(s->private_key, s->pk_digest)<0) {
log_fn(LOG_WARN, "Couldn't compute hash of public key."); warn(LD_GENERAL, "Bug: Couldn't compute hash of public key.");
return -1; return -1;
} }
if (strlcpy(fname,s->directory,sizeof(fname)) >= sizeof(fname) || if (strlcpy(fname,s->directory,sizeof(fname)) >= sizeof(fname) ||
strlcat(fname,"/hostname",sizeof(fname)) >= sizeof(fname)) { strlcat(fname,"/hostname",sizeof(fname)) >= sizeof(fname)) {
log_fn(LOG_WARN, "Directory name too long: \"%s\".", s->directory); warn(LD_CONFIG, "Directory name too long: \"%s\".", s->directory);
return -1; return -1;
} }
tor_snprintf(buf, sizeof(buf),"%s.onion\n", s->service_id); tor_snprintf(buf, sizeof(buf),"%s.onion\n", s->service_id);
@ -415,11 +416,11 @@ rend_service_introduce(circuit_t *circuit, const char *request, size_t request_l
base32_encode(serviceid, REND_SERVICE_ID_LEN+1, base32_encode(serviceid, REND_SERVICE_ID_LEN+1,
circuit->rend_pk_digest,10); circuit->rend_pk_digest,10);
log_fn(LOG_INFO, "Received INTRODUCE2 cell for service %s on circ %d.", info(LD_REND, "Received INTRODUCE2 cell for service %s on circ %d.",
serviceid, circuit->n_circ_id); serviceid, circuit->n_circ_id);
if (circuit->purpose != CIRCUIT_PURPOSE_S_INTRO) { if (circuit->purpose != CIRCUIT_PURPOSE_S_INTRO) {
log_fn(LOG_WARN, "Got an INTRODUCE2 over a non-introduction circuit %d.", warn(LD_PROTOCOL, "Got an INTRODUCE2 over a non-introduction circuit %d.",
circuit->n_circ_id); circuit->n_circ_id);
return -1; return -1;
} }
@ -427,7 +428,7 @@ rend_service_introduce(circuit_t *circuit, const char *request, size_t request_l
/* min key length plus digest length plus nickname length */ /* min key length plus digest length plus nickname length */
if (request_len < DIGEST_LEN+REND_COOKIE_LEN+(MAX_NICKNAME_LEN+1)+ if (request_len < DIGEST_LEN+REND_COOKIE_LEN+(MAX_NICKNAME_LEN+1)+
DH_KEY_LEN+42) { DH_KEY_LEN+42) {
log_fn(LOG_WARN, "Got a truncated INTRODUCE2 cell on circ %d.", warn(LD_PROTOCOL, "Got a truncated INTRODUCE2 cell on circ %d.",
circuit->n_circ_id); circuit->n_circ_id);
return -1; return -1;
} }
@ -435,20 +436,20 @@ rend_service_introduce(circuit_t *circuit, const char *request, size_t request_l
/* first DIGEST_LEN bytes of request is service pk digest */ /* first DIGEST_LEN bytes of request is service pk digest */
service = rend_service_get_by_pk_digest(request); service = rend_service_get_by_pk_digest(request);
if (!service) { if (!service) {
log_fn(LOG_WARN, "Got an INTRODUCE2 cell for an unrecognized service %s.", warn(LD_REND, "Got an INTRODUCE2 cell for an unrecognized service %s.",
serviceid); serviceid);
return -1; return -1;
} }
if (memcmp(circuit->rend_pk_digest, request, DIGEST_LEN)) { if (memcmp(circuit->rend_pk_digest, request, DIGEST_LEN)) {
base32_encode(serviceid, REND_SERVICE_ID_LEN+1, request, 10); base32_encode(serviceid, REND_SERVICE_ID_LEN+1, request, 10);
log_fn(LOG_WARN, "Got an INTRODUCE2 cell for the wrong service (%s).", warn(LD_REND, "Got an INTRODUCE2 cell for the wrong service (%s).",
serviceid); serviceid);
return -1; return -1;
} }
keylen = crypto_pk_keysize(service->private_key); keylen = crypto_pk_keysize(service->private_key);
if (request_len < keylen+DIGEST_LEN) { if (request_len < keylen+DIGEST_LEN) {
log_fn(LOG_WARN, "PK-encrypted portion of INTRODUCE2 cell was truncated."); warn(LD_PROTOCOL, "PK-encrypted portion of INTRODUCE2 cell was truncated.");
return -1; return -1;
} }
/* Next N bytes is encrypted with service key */ /* Next N bytes is encrypted with service key */
@ -456,7 +457,7 @@ rend_service_introduce(circuit_t *circuit, const char *request, size_t request_l
service->private_key,buf,request+DIGEST_LEN,request_len-DIGEST_LEN, service->private_key,buf,request+DIGEST_LEN,request_len-DIGEST_LEN,
PK_PKCS1_OAEP_PADDING,1); PK_PKCS1_OAEP_PADDING,1);
if (r<0) { if (r<0) {
log_fn(LOG_WARN, "Couldn't decrypt INTRODUCE2 cell."); warn(LD_PROTOCOL, "Couldn't decrypt INTRODUCE2 cell.");
return -1; return -1;
} }
len = r; len = r;
@ -473,12 +474,12 @@ rend_service_introduce(circuit_t *circuit, const char *request, size_t request_l
klen = ntohs(get_uint16(buf+7+DIGEST_LEN)); klen = ntohs(get_uint16(buf+7+DIGEST_LEN));
if ((int)len != 7+DIGEST_LEN+2+klen+20+128) { if ((int)len != 7+DIGEST_LEN+2+klen+20+128) {
log_fn(LOG_WARN, "Bad length %u for version 2 INTRODUCE2 cell.", (int)len); warn(LD_PROTOCOL, "Bad length %u for version 2 INTRODUCE2 cell.", (int)len);
goto err; goto err;
} }
extend_info->onion_key = crypto_pk_asn1_decode(buf+7+DIGEST_LEN+2, klen); extend_info->onion_key = crypto_pk_asn1_decode(buf+7+DIGEST_LEN+2, klen);
if (!extend_info->onion_key) { if (!extend_info->onion_key) {
log_fn(LOG_WARN, "Error decoding onion key in version 2 INTRODUCE2 cell."); warn(LD_PROTOCOL, "Error decoding onion key in version 2 INTRODUCE2 cell.");
goto err; goto err;
} }
ptr = buf+7+DIGEST_LEN+2+klen; ptr = buf+7+DIGEST_LEN+2+klen;
@ -500,12 +501,12 @@ rend_service_introduce(circuit_t *circuit, const char *request, size_t request_l
/* XXX when 0.1.0.x is obsolete, change this to reject version < 2. */ /* XXX when 0.1.0.x is obsolete, change this to reject version < 2. */
ptr=memchr(rp_nickname,0,nickname_field_len); ptr=memchr(rp_nickname,0,nickname_field_len);
if (!ptr || ptr == rp_nickname) { if (!ptr || ptr == rp_nickname) {
log_fn(LOG_WARN, "Couldn't find a null-padded nickname in INTRODUCE2 cell."); warn(LD_PROTOCOL, "Couldn't find a null-padded nickname in INTRODUCE2 cell.");
return -1; return -1;
} }
if ((version == 0 && !is_legal_nickname(rp_nickname)) || if ((version == 0 && !is_legal_nickname(rp_nickname)) ||
(version == 1 && !is_legal_nickname_or_hexdigest(rp_nickname))) { (version == 1 && !is_legal_nickname_or_hexdigest(rp_nickname))) {
log_fn(LOG_WARN, "Bad nickname in INTRODUCE2 cell."); warn(LD_PROTOCOL, "Bad nickname in INTRODUCE2 cell.");
return -1; return -1;
} }
/* Okay, now we know that a nickname is at the start of the buffer. */ /* Okay, now we know that a nickname is at the start of the buffer. */
@ -514,7 +515,7 @@ rend_service_introduce(circuit_t *circuit, const char *request, size_t request_l
len -= rp_nickname - buf; /* also remove header space used by version, if any */ len -= rp_nickname - buf; /* also remove header space used by version, if any */
router = router_get_by_nickname(rp_nickname, 0); router = router_get_by_nickname(rp_nickname, 0);
if (!router) { if (!router) {
log_fn(LOG_INFO, "Couldn't find router '%s' named in rendezvous cell.", info(LD_REND, "Couldn't find router '%s' named in rendezvous cell.",
rp_nickname); rp_nickname);
goto err; goto err;
} }
@ -523,7 +524,7 @@ rend_service_introduce(circuit_t *circuit, const char *request, size_t request_l
} }
if (len != REND_COOKIE_LEN+DH_KEY_LEN) { if (len != REND_COOKIE_LEN+DH_KEY_LEN) {
log_fn(LOG_WARN, "Bad length %u for INTRODUCE2 cell.", (int)len); warn(LD_PROTOCOL, "Bad length %u for INTRODUCE2 cell.", (int)len);
return -1; return -1;
} }
@ -533,12 +534,12 @@ rend_service_introduce(circuit_t *circuit, const char *request, size_t request_l
/* Try DH handshake... */ /* Try DH handshake... */
dh = crypto_dh_new(); dh = crypto_dh_new();
if (!dh || crypto_dh_generate_public(dh)<0) { if (!dh || crypto_dh_generate_public(dh)<0) {
log_fn(LOG_WARN, "Internal error: couldn't build DH state or generate public key."); warn(LD_GENERAL,"Internal error: couldn't build DH state or generate public key.");
goto err; goto err;
} }
if (crypto_dh_compute_secret(dh, ptr+REND_COOKIE_LEN, DH_KEY_LEN, keys, if (crypto_dh_compute_secret(dh, ptr+REND_COOKIE_LEN, DH_KEY_LEN, keys,
DIGEST_LEN+CPATH_KEY_MATERIAL_LEN)<0) { DIGEST_LEN+CPATH_KEY_MATERIAL_LEN)<0) {
log_fn(LOG_WARN, "Internal error: couldn't complete DH handshake"); warn(LD_GENERAL, "Internal error: couldn't complete DH handshake");
goto err; goto err;
} }
@ -557,13 +558,13 @@ rend_service_introduce(circuit_t *circuit, const char *request, size_t request_l
break; break;
} }
if (!launched) { /* give up */ if (!launched) { /* give up */
log_fn(LOG_WARN,"Giving up launching first hop of circuit to rendezvous point '%s' for service %s.", warn(LD_REND,"Giving up launching first hop of circuit to rendezvous point '%s' for service %s.",
extend_info->nickname, serviceid); extend_info->nickname, serviceid);
goto err; goto err;
} }
log_fn(LOG_INFO, info(LD_REND,
"Accepted intro; launching circuit to '%s' (cookie %s) for service %s.", "Accepted intro; launching circuit to '%s' (cookie %s) for service %s.",
extend_info->nickname, hexcookie, serviceid); extend_info->nickname, hexcookie, serviceid);
tor_assert(launched->build_state); tor_assert(launched->build_state);
/* Fill in the circuit's state. */ /* Fill in the circuit's state. */
memcpy(launched->rend_pk_digest, circuit->rend_pk_digest, memcpy(launched->rend_pk_digest, circuit->rend_pk_digest,
@ -605,7 +606,7 @@ rend_service_relaunch_rendezvous(circuit_t *oldcirc)
if (!oldcirc->build_state || if (!oldcirc->build_state ||
oldcirc->build_state->failure_count > MAX_REND_FAILURES || oldcirc->build_state->failure_count > MAX_REND_FAILURES ||
oldcirc->build_state->expiry_time < time(NULL)) { oldcirc->build_state->expiry_time < time(NULL)) {
log_fn(LOG_INFO,"Attempt to build circuit to %s for rendezvous has failed too many times or expired; giving up.", info(LD_REND,"Attempt to build circuit to %s for rendezvous has failed too many times or expired; giving up.",
oldcirc->build_state ? oldcirc->build_state->chosen_exit->nickname : oldcirc->build_state ? oldcirc->build_state->chosen_exit->nickname :
"*unknown*"); "*unknown*");
return; return;
@ -615,17 +616,17 @@ rend_service_relaunch_rendezvous(circuit_t *oldcirc)
tor_assert(oldstate); tor_assert(oldstate);
if (oldstate->pending_final_cpath == NULL) { if (oldstate->pending_final_cpath == NULL) {
log_fn(LOG_INFO,"Skipping relaunch of circ that failed on its first hop. Initiator will retry."); info(LD_REND,"Skipping relaunch of circ that failed on its first hop. Initiator will retry.");
return; return;
} }
log_fn(LOG_INFO,"Reattempting rendezvous circuit to %s", info(LD_REND,"Reattempting rendezvous circuit to %s",
oldstate->chosen_exit->nickname); oldstate->chosen_exit->nickname);
newcirc = circuit_launch_by_extend_info(CIRCUIT_PURPOSE_S_CONNECT_REND, newcirc = circuit_launch_by_extend_info(CIRCUIT_PURPOSE_S_CONNECT_REND,
oldstate->chosen_exit, 0, 1, 1); oldstate->chosen_exit, 0, 1, 1);
if (!newcirc) { if (!newcirc) {
log_fn(LOG_WARN,"Couldn't relaunch rendezvous circuit to %s.", warn(LD_REND,"Couldn't relaunch rendezvous circuit to %s.",
oldstate->chosen_exit->nickname); oldstate->chosen_exit->nickname);
return; return;
} }
@ -649,7 +650,7 @@ rend_service_launch_establish_intro(rend_service_t *service, const char *nicknam
{ {
circuit_t *launched; circuit_t *launched;
log_fn(LOG_INFO, "Launching circuit to introduction point %s for service %s", info(LD_REND, "Launching circuit to introduction point %s for service %s",
nickname, service->service_id); nickname, service->service_id);
rep_hist_note_used_hidserv(time(NULL), 1, 0); rep_hist_note_used_hidserv(time(NULL), 1, 0);
@ -657,7 +658,7 @@ rend_service_launch_establish_intro(rend_service_t *service, const char *nicknam
++service->n_intro_circuits_launched; ++service->n_intro_circuits_launched;
launched = circuit_launch_by_nickname(CIRCUIT_PURPOSE_S_ESTABLISH_INTRO, nickname, 1, 0, 1); launched = circuit_launch_by_nickname(CIRCUIT_PURPOSE_S_ESTABLISH_INTRO, nickname, 1, 0, 1);
if (!launched) { if (!launched) {
log_fn(LOG_INFO, "Can't launch circuit to establish introduction at '%s'.", info(LD_REND, "Can't launch circuit to establish introduction at '%s'.",
nickname); nickname);
return -1; return -1;
} }
@ -692,14 +693,14 @@ rend_service_intro_has_opened(circuit_t *circuit)
service = rend_service_get_by_pk_digest(circuit->rend_pk_digest); service = rend_service_get_by_pk_digest(circuit->rend_pk_digest);
if (!service) { if (!service) {
log_fn(LOG_WARN, "Unrecognized service ID %s on introduction circuit %d.", warn(LD_REND, "Unrecognized service ID %s on introduction circuit %d.",
serviceid, circuit->n_circ_id); serviceid, circuit->n_circ_id);
goto err; goto err;
} }
log_fn(LOG_INFO, info(LD_REND,
"Established circuit %d as introduction point for service %s", "Established circuit %d as introduction point for service %s",
circuit->n_circ_id, serviceid); circuit->n_circ_id, serviceid);
/* Build the payload for a RELAY_ESTABLISH_INTRO cell. */ /* Build the payload for a RELAY_ESTABLISH_INTRO cell. */
len = crypto_pk_asn1_encode(service->private_key, buf+2, len = crypto_pk_asn1_encode(service->private_key, buf+2,
@ -713,16 +714,16 @@ rend_service_intro_has_opened(circuit_t *circuit)
len += 20; len += 20;
r = crypto_pk_private_sign_digest(service->private_key, buf+len, buf, len); r = crypto_pk_private_sign_digest(service->private_key, buf+len, buf, len);
if (r<0) { if (r<0) {
log_fn(LOG_WARN, "Internal error: couldn't sign introduction request."); warn(LD_GENERAL, "Internal error: couldn't sign introduction request.");
goto err; goto err;
} }
len += r; len += r;
if (connection_edge_send_command(NULL, circuit,RELAY_COMMAND_ESTABLISH_INTRO, if (connection_edge_send_command(NULL, circuit,RELAY_COMMAND_ESTABLISH_INTRO,
buf, len, circuit->cpath->prev)<0) { buf, len, circuit->cpath->prev)<0) {
log_fn(LOG_INFO, info(LD_GENERAL,
"Couldn't send introduction request for service %s on circuit %d", "Couldn't send introduction request for service %s on circuit %d",
serviceid, circuit->n_circ_id); serviceid, circuit->n_circ_id);
goto err; goto err;
} }
@ -740,12 +741,12 @@ rend_service_intro_established(circuit_t *circuit, const char *request, size_t r
rend_service_t *service; rend_service_t *service;
if (circuit->purpose != CIRCUIT_PURPOSE_S_ESTABLISH_INTRO) { if (circuit->purpose != CIRCUIT_PURPOSE_S_ESTABLISH_INTRO) {
log_fn(LOG_WARN, "received INTRO_ESTABLISHED cell on non-intro circuit."); warn(LD_PROTOCOL, "received INTRO_ESTABLISHED cell on non-intro circuit.");
goto err; goto err;
} }
service = rend_service_get_by_pk_digest(circuit->rend_pk_digest); service = rend_service_get_by_pk_digest(circuit->rend_pk_digest);
if (!service) { if (!service) {
log_fn(LOG_WARN, "Unknown service on introduction circuit %d.", warn(LD_REND, "Unknown service on introduction circuit %d.",
circuit->n_circ_id); circuit->n_circ_id);
goto err; goto err;
} }
@ -780,13 +781,13 @@ rend_service_rendezvous_has_opened(circuit_t *circuit)
base32_encode(serviceid, REND_SERVICE_ID_LEN+1, base32_encode(serviceid, REND_SERVICE_ID_LEN+1,
circuit->rend_pk_digest,10); circuit->rend_pk_digest,10);
log_fn(LOG_INFO, info(LD_REND,
"Done building circuit %d to rendezvous with cookie %s for service %s", "Done building circuit %d to rendezvous with cookie %s for service %s",
circuit->n_circ_id, hexcookie, serviceid); circuit->n_circ_id, hexcookie, serviceid);
service = rend_service_get_by_pk_digest(circuit->rend_pk_digest); service = rend_service_get_by_pk_digest(circuit->rend_pk_digest);
if (!service) { if (!service) {
log_fn(LOG_WARN, "Internal error: unrecognized service ID on introduction circuit."); warn(LD_GENERAL, "Internal error: unrecognized service ID on introduction circuit.");
goto err; goto err;
} }
@ -794,7 +795,7 @@ rend_service_rendezvous_has_opened(circuit_t *circuit)
memcpy(buf, circuit->rend_cookie, REND_COOKIE_LEN); memcpy(buf, circuit->rend_cookie, REND_COOKIE_LEN);
if (crypto_dh_get_public(hop->dh_handshake_state, if (crypto_dh_get_public(hop->dh_handshake_state,
buf+REND_COOKIE_LEN, DH_KEY_LEN)<0) { buf+REND_COOKIE_LEN, DH_KEY_LEN)<0) {
log_fn(LOG_WARN,"Couldn't get DH public key."); warn(LD_GENERAL,"Couldn't get DH public key.");
goto err; goto err;
} }
memcpy(buf+REND_COOKIE_LEN+DH_KEY_LEN, hop->handshake_digest, memcpy(buf+REND_COOKIE_LEN+DH_KEY_LEN, hop->handshake_digest,
@ -804,7 +805,7 @@ rend_service_rendezvous_has_opened(circuit_t *circuit)
if (connection_edge_send_command(NULL, circuit, RELAY_COMMAND_RENDEZVOUS1, if (connection_edge_send_command(NULL, circuit, RELAY_COMMAND_RENDEZVOUS1,
buf, REND_COOKIE_LEN+DH_KEY_LEN+DIGEST_LEN, buf, REND_COOKIE_LEN+DH_KEY_LEN+DIGEST_LEN,
circuit->cpath->prev)<0) { circuit->cpath->prev)<0) {
log_fn(LOG_WARN, "Couldn't send RENDEZVOUS1 cell."); warn(LD_GENERAL, "Couldn't send RENDEZVOUS1 cell.");
goto err; goto err;
} }
@ -880,7 +881,7 @@ upload_service_descriptor(rend_service_t *service, int version)
version, version,
service->private_key, service->private_key,
&desc, &desc_len)<0) { &desc, &desc_len)<0) {
log_fn(LOG_WARN, "Internal error: couldn't encode service descriptor; not uploading."); warn(LD_GENERAL, "Internal error: couldn't encode service descriptor; not uploading.");
return; return;
} }
@ -936,7 +937,7 @@ rend_services_introduce(void)
intro = smartlist_get(service->intro_nodes, j); intro = smartlist_get(service->intro_nodes, j);
router = router_get_by_nickname(intro, 0); router = router_get_by_nickname(intro, 0);
if (!router || !find_intro_circuit(router,service->pk_digest)) { if (!router || !find_intro_circuit(router,service->pk_digest)) {
log_fn(LOG_INFO,"Giving up on %s as intro point for %s.", info(LD_REND,"Giving up on %s as intro point for %s.",
intro, service->service_id); intro, service->service_id);
tor_free(intro); tor_free(intro);
smartlist_del(service->intro_nodes,j--); smartlist_del(service->intro_nodes,j--);
@ -968,7 +969,7 @@ rend_services_introduce(void)
service->intro_exclude_nodes, exclude_routers, 1, 0, service->intro_exclude_nodes, exclude_routers, 1, 0,
get_options()->_AllowUnverified & ALLOW_UNVERIFIED_INTRODUCTION, 0); get_options()->_AllowUnverified & ALLOW_UNVERIFIED_INTRODUCTION, 0);
if (!router) { if (!router) {
log_fn(LOG_WARN, "Could only establish %d introduction points for %s.", warn(LD_REND, "Could only establish %d introduction points for %s.",
smartlist_len(service->intro_nodes), service->service_id); smartlist_len(service->intro_nodes), service->service_id);
break; break;
} }
@ -980,8 +981,8 @@ rend_services_introduce(void)
smartlist_add(intro_routers, router); smartlist_add(intro_routers, router);
smartlist_add(exclude_routers, router); smartlist_add(exclude_routers, router);
smartlist_add(service->intro_nodes, hex_digest); smartlist_add(service->intro_nodes, hex_digest);
log_fn(LOG_INFO,"Picked router %s as an intro point for %s.", router->nickname, info(LD_REND, "Picked router %s as an intro point for %s.",
service->service_id); router->nickname, service->service_id);
} }
/* Reset exclude_routers, for the next time around the loop. */ /* Reset exclude_routers, for the next time around the loop. */
@ -996,7 +997,7 @@ rend_services_introduce(void)
intro = smartlist_get(service->intro_nodes, j); intro = smartlist_get(service->intro_nodes, j);
r = rend_service_launch_establish_intro(service, intro); r = rend_service_launch_establish_intro(service, intro);
if (r<0) { if (r<0) {
log_fn(LOG_WARN, "Error launching circuit to node %s for service %s.", warn(LD_REND, "Error launching circuit to node %s for service %s.",
intro, service->service_id); intro, service->service_id);
} }
} }
@ -1053,20 +1054,20 @@ rend_service_dump_stats(int severity)
for (i=0; i < smartlist_len(rend_service_list); ++i) { for (i=0; i < smartlist_len(rend_service_list); ++i) {
service = smartlist_get(rend_service_list, i); service = smartlist_get(rend_service_list, i);
log(severity, "Service configured in \"%s\":", service->directory); log(severity, LD_GENERAL, "Service configured in \"%s\":", service->directory);
for (j=0; j < smartlist_len(service->intro_nodes); ++j) { for (j=0; j < smartlist_len(service->intro_nodes); ++j) {
nickname = smartlist_get(service->intro_nodes, j); nickname = smartlist_get(service->intro_nodes, j);
router = router_get_by_nickname(smartlist_get(service->intro_nodes,j),1); router = router_get_by_nickname(smartlist_get(service->intro_nodes,j),1);
if (!router) { if (!router) {
log(severity, " Intro point at %s: unrecognized router",nickname); log(severity, LD_GENERAL, " Intro point at %s: unrecognized router",nickname);
continue; continue;
} }
circ = find_intro_circuit(router, service->pk_digest); circ = find_intro_circuit(router, service->pk_digest);
if (!circ) { if (!circ) {
log(severity, " Intro point at %s: no circuit",nickname); log(severity, LD_GENERAL, " Intro point at %s: no circuit",nickname);
continue; continue;
} }
log(severity, " Intro point at %s: circuit is %s",nickname, log(severity, LD_GENERAL, " Intro point at %s: circuit is %s",nickname,
circuit_state_to_string(circ->state)); circuit_state_to_string(circ->state));
} }
} }
@ -1086,12 +1087,12 @@ rend_service_set_connection_addr_port(connection_t *conn, circuit_t *circ)
char serviceid[REND_SERVICE_ID_LEN+1]; char serviceid[REND_SERVICE_ID_LEN+1];
tor_assert(circ->purpose == CIRCUIT_PURPOSE_S_REND_JOINED); tor_assert(circ->purpose == CIRCUIT_PURPOSE_S_REND_JOINED);
log_fn(LOG_DEBUG,"beginning to hunt for addr/port"); debug(LD_REND,"beginning to hunt for addr/port");
base32_encode(serviceid, REND_SERVICE_ID_LEN+1, base32_encode(serviceid, REND_SERVICE_ID_LEN+1,
circ->rend_pk_digest,10); circ->rend_pk_digest,10);
service = rend_service_get_by_pk_digest(circ->rend_pk_digest); service = rend_service_get_by_pk_digest(circ->rend_pk_digest);
if (!service) { if (!service) {
log_fn(LOG_WARN, "Couldn't find any service associated with pk %s on rendezvous circuit %d; closing.", warn(LD_REND, "Couldn't find any service associated with pk %s on rendezvous circuit %d; closing.",
serviceid, circ->n_circ_id); serviceid, circ->n_circ_id);
return -1; return -1;
} }
@ -1103,7 +1104,7 @@ rend_service_set_connection_addr_port(connection_t *conn, circuit_t *circ)
return 0; return 0;
} }
} }
log_fn(LOG_INFO, "No virtual port mapping exists for port %d on service %s", info(LD_REND, "No virtual port mapping exists for port %d on service %s",
conn->port,serviceid); conn->port,serviceid);
return -1; return -1;
} }

9
src/or/rephist.c
View File

@ -10,6 +10,7 @@ const char rephist_c_id[] = "$Id$";
* been using, which ports we tend to want, and so on. * been using, which ports we tend to want, and so on.
**/ **/
#define NEW_LOG_INTERFACE
#include "or.h" #include "or.h"
static void bw_arrays_init(void); static void bw_arrays_init(void);
@ -289,7 +290,7 @@ rep_hist_dump_stats(time_t now, int severity)
rep_history_clean(now - get_options()->RephistTrackTime); rep_history_clean(now - get_options()->RephistTrackTime);
log(severity, "--------------- Dumping history information:"); log(severity, LD_GENERAL, "--------------- Dumping history information:");
for (orhist_it = digestmap_iter_init(history_map); !digestmap_iter_done(orhist_it); for (orhist_it = digestmap_iter_init(history_map); !digestmap_iter_done(orhist_it);
orhist_it = digestmap_iter_next(history_map,orhist_it)) { orhist_it = digestmap_iter_next(history_map,orhist_it)) {
@ -309,7 +310,7 @@ rep_hist_dump_stats(time_t now, int severity)
} else { } else {
uptime=1.0; uptime=1.0;
} }
log(severity, log(severity, LD_GENERAL,
"OR %s [%s]: %ld/%ld good connections; uptime %ld/%ld sec (%.2f%%)", "OR %s [%s]: %ld/%ld good connections; uptime %ld/%ld sec (%.2f%%)",
name1, hexdigest1, name1, hexdigest1,
or_history->n_conn_ok, or_history->n_conn_fail+or_history->n_conn_ok, or_history->n_conn_ok, or_history->n_conn_fail+or_history->n_conn_ok,
@ -337,7 +338,7 @@ rep_hist_dump_stats(time_t now, int severity)
else else
len += ret; len += ret;
} }
log(severity, "%s", buffer); log(severity, LD_GENERAL, "%s", buffer);
} }
} }
} }
@ -715,7 +716,7 @@ rep_hist_get_predicted_ports(time_t now)
tmp_time = smartlist_get(predicted_ports_times, i); tmp_time = smartlist_get(predicted_ports_times, i);
if (*tmp_time + PREDICTED_CIRCS_RELEVANCE_TIME < now) { if (*tmp_time + PREDICTED_CIRCS_RELEVANCE_TIME < now) {
tmp_port = smartlist_get(predicted_ports_list, i); tmp_port = smartlist_get(predicted_ports_list, i);
log_fn(LOG_DEBUG, "Expiring predicted port %d", *tmp_port); debug(LD_CIRC, "Expiring predicted port %d", *tmp_port);
smartlist_del(predicted_ports_list, i); smartlist_del(predicted_ports_list, i);
smartlist_del(predicted_ports_times, i); smartlist_del(predicted_ports_times, i);
rephist_total_alloc -= sizeof(uint16_t)+sizeof(time_t); rephist_total_alloc -= sizeof(uint16_t)+sizeof(time_t);