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

more log conversions.

Browse Source 
whee.


svn:r6003
This commit is contained in:
Roger Dingledine 2006-02-13 09:02:35 +00:00
parent 36484f873a
commit d113b75da6
6 changed files with 486 additions and 438 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

306
src/or/config.c
View File

@ -466,8 +466,8 @@ set_options(or_options_t *new_val)
return -1; return -1;
} }
if (options_act(old_options) < 0) { /* acting on the options failed. die. */ if (options_act(old_options) < 0) { /* acting on the options failed. die. */
err(LD_CONFIG, log_err(LD_CONFIG,
"Acting on config options left us in a broken state. Dying."); "Acting on config options left us in a broken state. Dying.");
exit(1); exit(1);
} }
if (old_options) if (old_options)
@ -561,8 +561,8 @@ options_act_reversible(or_options_t *old_options)
/* Ensure data directory is private; create if possible. */ /* Ensure data directory is private; create if possible. */
if (check_private_dir(options->DataDirectory, CPD_CREATE)<0) { if (check_private_dir(options->DataDirectory, CPD_CREATE)<0) {
err(LD_FS, "Couldn't access/create private data directory \"%s\"", log_err(LD_FS, "Couldn't access/create private data directory \"%s\"",
options->DataDirectory); options->DataDirectory);
/* No need to roll back, since you can't change the value. */ /* No need to roll back, since you can't change the value. */
goto done; goto done;
} }
@ -579,7 +579,7 @@ options_act_reversible(or_options_t *old_options)
set_conn_limit = 1; set_conn_limit = 1;
if (retry_all_listeners(0, replaced_listeners, new_listeners) < 0) { if (retry_all_listeners(0, replaced_listeners, new_listeners) < 0) {
err(LD_CONFIG, "Failed to bind one of the listener ports."); log_err(LD_CONFIG, "Failed to bind one of the listener ports.");
goto rollback; goto rollback;
} }
@ -597,8 +597,8 @@ options_act_reversible(or_options_t *old_options)
} }
SMARTLIST_FOREACH(replaced_listeners, connection_t *, conn, SMARTLIST_FOREACH(replaced_listeners, connection_t *, conn,
{ {
notice(LD_NET, "Closing old %s on %s:%d", log_notice(LD_NET, "Closing old %s on %s:%d",
conn_type_to_string(conn->type), conn->address, conn->port); conn_type_to_string(conn->type), conn->address, conn->port);
connection_close_immediate(conn); connection_close_immediate(conn);
connection_mark_for_close(conn); connection_mark_for_close(conn);
}); });
@ -617,8 +617,8 @@ options_act_reversible(or_options_t *old_options)
SMARTLIST_FOREACH(new_listeners, connection_t *, conn, SMARTLIST_FOREACH(new_listeners, connection_t *, conn,
{ {
notice(LD_NET, "Closing %s on %s:%d", log_notice(LD_NET, "Closing %s on %s:%d",
conn_type_to_string(conn->type), conn->address, conn->port); conn_type_to_string(conn->type), conn->address, conn->port);
connection_close_immediate(conn); connection_close_immediate(conn);
connection_mark_for_close(conn); connection_mark_for_close(conn);
}); });
@ -651,7 +651,7 @@ options_act(or_options_t *old_options)
if (options->DirServers) { if (options->DirServers) {
for (cl = options->DirServers; cl; cl = cl->next) { for (cl = options->DirServers; cl; cl = cl->next) {
if (parse_dir_server_line(cl->value, 0)<0) { if (parse_dir_server_line(cl->value, 0)<0) {
err(LD_BUG, log_err(LD_BUG,
"Bug: Previously validated DirServer line could not be added!"); "Bug: Previously validated DirServer line could not be added!");
return -1; return -1;
} }
@ -661,8 +661,8 @@ options_act(or_options_t *old_options)
} }
if (running_tor && rend_config_services(options, 0)<0) { if (running_tor && rend_config_services(options, 0)<0) {
err(LD_BUG, log_err(LD_BUG,
"Bug: Previously validated hidden services line could not be added!"); "Bug: Previously validated hidden services line could not be added!");
return -1; return -1;
} }
@ -671,8 +671,8 @@ options_act(or_options_t *old_options)
fn = tor_malloc(len); fn = tor_malloc(len);
tor_snprintf(fn, len, "%s/cached-status", options->DataDirectory); tor_snprintf(fn, len, "%s/cached-status", options->DataDirectory);
if (check_private_dir(fn, CPD_CREATE) != 0) { if (check_private_dir(fn, CPD_CREATE) != 0) {
err(LD_CONFIG, log_err(LD_CONFIG,
"Couldn't access/create private data directory \"%s\"", fn); "Couldn't access/create private data directory \"%s\"", fn);
tor_free(fn); tor_free(fn);
return -1; return -1;
} }
@ -722,13 +722,13 @@ options_act(or_options_t *old_options)
/* reload keys as needed for rendezvous services. */ /* reload keys as needed for rendezvous services. */
if (rend_service_load_keys()<0) { if (rend_service_load_keys()<0) {
err(LD_GENERAL,"Error loading rendezvous service keys"); log_err(LD_GENERAL,"Error loading rendezvous service keys");
return -1; return -1;
} }
/* Set up accounting */ /* Set up accounting */
if (accounting_parse_options(options, 0)<0) { if (accounting_parse_options(options, 0)<0) {
err(LD_CONFIG,"Error in accounting options"); log_err(LD_CONFIG,"Error in accounting options");
return -1; return -1;
} }
if (accounting_is_enabled(options)) if (accounting_is_enabled(options))
@ -740,17 +740,19 @@ options_act(or_options_t *old_options)
/* Check for transitions that need action. */ /* Check for transitions that need action. */
if (old_options) { if (old_options) {
if (options->UseEntryGuards && !old_options->UseEntryGuards) { if (options->UseEntryGuards && !old_options->UseEntryGuards) {
info(LD_CIRC,"Switching to entry guards; abandoning previous circuits"); log_info(LD_CIRC,
"Switching to entry guards; abandoning previous circuits");
circuit_mark_all_unused_circs(); circuit_mark_all_unused_circs();
circuit_expire_all_dirty_circs(); circuit_expire_all_dirty_circs();
} }
if (options_transition_affects_workers(old_options, options)) { if (options_transition_affects_workers(old_options, options)) {
info(LD_GENERAL,"Worker-related options changed. Rotating workers."); log_info(LD_GENERAL,
"Worker-related options changed. Rotating workers.");
if (server_mode(options) && !server_mode(old_options)) { if (server_mode(options) && !server_mode(old_options)) {
extern int has_completed_circuit; extern int has_completed_circuit;
if (init_keys() < 0) { if (init_keys() < 0) {
err(LD_GENERAL,"Error initializing keys; exiting"); log_err(LD_GENERAL,"Error initializing keys; exiting");
return -1; return -1;
} }
server_has_changed_ip(); server_has_changed_ip();
@ -799,10 +801,11 @@ expand_abbrev(config_format_t *fmt, const char *option, int command_line,
if (!strcasecmp(option,fmt->abbrevs[i].abbreviated) && if (!strcasecmp(option,fmt->abbrevs[i].abbreviated) &&
(command_line || !fmt->abbrevs[i].commandline_only)) { (command_line || !fmt->abbrevs[i].commandline_only)) {
if (warn_obsolete && fmt->abbrevs[i].warn) { if (warn_obsolete && fmt->abbrevs[i].warn) {
warn(LD_CONFIG, log_warn(LD_CONFIG,
"The configuration option '%s' is deprecated; use '%s' instead.", "The configuration option '%s' is deprecated; "
fmt->abbrevs[i].abbreviated, "use '%s' instead.",
fmt->abbrevs[i].full); fmt->abbrevs[i].abbreviated,
fmt->abbrevs[i].full);
} }
return fmt->abbrevs[i].full; return fmt->abbrevs[i].full;
} }
@ -834,8 +837,8 @@ config_get_commandlines(int argc, char **argv, config_line_t **result)
continue; continue;
} }
if (i == argc-1) { if (i == argc-1) {
warn(LD_CONFIG,"Command-line option '%s' with no value. Failing.", log_warn(LD_CONFIG,"Command-line option '%s' with no value. Failing.",
argv[i]); argv[i]);
config_free_lines(front); config_free_lines(front);
return -1; return -1;
} }
@ -961,9 +964,9 @@ config_find_option(config_format_t *fmt, const char *key)
/* If none, check for an abbreviated match */ /* If none, check for an abbreviated match */
for (i=0; fmt->vars[i].name; ++i) { for (i=0; fmt->vars[i].name; ++i) {
if (!strncasecmp(key, fmt->vars[i].name, keylen)) { if (!strncasecmp(key, fmt->vars[i].name, keylen)) {
warn(LD_CONFIG, "The abbreviation '%s' is deprecated. " log_warn(LD_CONFIG, "The abbreviation '%s' is deprecated. "
"Please use '%s' instead", "Please use '%s' instead",
key, fmt->vars[i].name); key, fmt->vars[i].name);
return &fmt->vars[i]; return &fmt->vars[i];
} }
} }
@ -1070,10 +1073,10 @@ config_assign_value(config_format_t *fmt, or_options_t *options,
break; break;
case CONFIG_TYPE_OBSOLETE: case CONFIG_TYPE_OBSOLETE:
warn(LD_CONFIG, "Skipping obsolete configuration option '%s'", c->key); log_warn(LD_CONFIG, "Skipping obsolete configuration option '%s'", c->key);
break; break;
case CONFIG_TYPE_LINELIST_V: case CONFIG_TYPE_LINELIST_V:
warn(LD_CONFIG, "Can't provide value for virtual option '%s'", c->key); log_warn(LD_CONFIG, "Can't provide value for virtual option '%s'", c->key);
return -1; return -1;
default: default:
tor_assert(0); tor_assert(0);
@ -1103,11 +1106,12 @@ config_assign_line(config_format_t *fmt, or_options_t *options,
if (!var) { if (!var) {
if (fmt->extra) { if (fmt->extra) {
void *lvalue = STRUCT_VAR_P(options, fmt->extra->var_offset); void *lvalue = STRUCT_VAR_P(options, fmt->extra->var_offset);
info(LD_CONFIG, "Found unrecognized option '%s'; saving it.", c->key); log_info(LD_CONFIG,
"Found unrecognized option '%s'; saving it.", c->key);
config_line_append((config_line_t**)lvalue, c->key, c->value); config_line_append((config_line_t**)lvalue, c->key, c->value);
return 0; return 0;
} else { } else {
warn(LD_CONFIG, "Unknown option '%s'. Failing.", c->key); log_warn(LD_CONFIG, "Unknown option '%s'. Failing.", c->key);
return -1; return -1;
} }
} }
@ -1199,11 +1203,11 @@ get_assigned_option(config_format_t *fmt, or_options_t *options,
var = config_find_option(fmt, key); var = config_find_option(fmt, key);
if (!var) { if (!var) {
warn(LD_CONFIG, "Unknown option '%s'. Failing.", key); log_warn(LD_CONFIG, "Unknown option '%s'. Failing.", key);
return NULL; return NULL;
} else if (var->type == CONFIG_TYPE_LINELIST_S) { } else if (var->type == CONFIG_TYPE_LINELIST_S) {
warn(LD_CONFIG, log_warn(LD_CONFIG,
"Can't return context-sensitive '%s' on its own", key); "Can't return context-sensitive '%s' on its own", key);
return NULL; return NULL;
} }
value = STRUCT_VAR_P(options, var->var_offset); value = STRUCT_VAR_P(options, var->var_offset);
@ -1263,16 +1267,17 @@ get_assigned_option(config_format_t *fmt, or_options_t *options,
result->value = tor_strdup(""); result->value = tor_strdup("");
break; break;
case CONFIG_TYPE_OBSOLETE: case CONFIG_TYPE_OBSOLETE:
warn(LD_CONFIG, log_warn(LD_CONFIG,
"You asked me for the value of an obsolete config option '%s'.", "You asked me for the value of an obsolete config option '%s'.",
key); key);
tor_free(result->key); tor_free(result->key);
tor_free(result); tor_free(result);
return NULL; return NULL;
default: default:
tor_free(result->key); tor_free(result->key);
tor_free(result); tor_free(result);
warn(LD_BUG,"Bug: unknown type %d for known key '%s'", var->type, key); log_warn(LD_BUG,"Bug: unknown type %d for known key '%s'",
var->type, key);
return NULL; return NULL;
} }
@ -1506,10 +1511,10 @@ resolve_my_address(or_options_t *options, uint32_t *addr_out,
explicit_ip = 0; /* it's implicit */ explicit_ip = 0; /* it's implicit */
if (gethostname(hostname, sizeof(hostname)) < 0) { if (gethostname(hostname, sizeof(hostname)) < 0) {
warn(LD_NET,"Error obtaining local hostname"); log_warn(LD_NET,"Error obtaining local hostname");
return -1; return -1;
} }
debug(LD_CONFIG,"Guessed local host name as '%s'",hostname); log_debug(LD_CONFIG,"Guessed local host name as '%s'",hostname);
} }
/* now we know hostname. resolve it and keep only the IP */ /* now we know hostname. resolve it and keep only the IP */
@ -1519,8 +1524,8 @@ resolve_my_address(or_options_t *options, uint32_t *addr_out,
explicit_ip = 0; explicit_ip = 0;
rent = (struct hostent *)gethostbyname(hostname); rent = (struct hostent *)gethostbyname(hostname);
if (!rent) { if (!rent) {
warn(LD_CONFIG,"Could not resolve local Address '%s'. Failing.", log_warn(LD_CONFIG,"Could not resolve local Address '%s'. Failing.",
hostname); hostname);
return -1; return -1;
} }
tor_assert(rent->h_length == 4); tor_assert(rent->h_length == 4);
@ -1533,26 +1538,26 @@ resolve_my_address(or_options_t *options, uint32_t *addr_out,
if (!options->DirServers) { if (!options->DirServers) {
/* if they are using the default dirservers, disallow internal IPs /* if they are using the default dirservers, disallow internal IPs
* always. */ * always. */
warn(LD_CONFIG,"Address '%s' resolves to private IP '%s'. " log_warn(LD_CONFIG,"Address '%s' resolves to private IP '%s'. "
"Tor servers that use the default DirServers must have public " "Tor servers that use the default DirServers must have public "
"IP addresses.", "IP addresses.",
hostname, tmpbuf); hostname, tmpbuf);
return -1; return -1;
} }
if (!explicit_ip) { if (!explicit_ip) {
/* even if they've set their own dirservers, require an explicit IP if /* even if they've set their own dirservers, require an explicit IP if
* they're using an internal address. */ * they're using an internal address. */
warn(LD_CONFIG,"Address '%s' resolves to private IP '%s'. Please " log_warn(LD_CONFIG,"Address '%s' resolves to private IP '%s'. Please "
"set the Address config option to be the IP you want to use.", "set the Address config option to be the IP you want to use.",
hostname, tmpbuf); hostname, tmpbuf);
return -1; return -1;
} }
} }
debug(LD_CONFIG, "Resolved Address to '%s'.", tmpbuf); log_debug(LD_CONFIG, "Resolved Address to '%s'.", tmpbuf);
*addr_out = ntohl(in.s_addr); *addr_out = ntohl(in.s_addr);
if (old_addr && old_addr != *addr_out) { if (old_addr && old_addr != *addr_out) {
notice(LD_NET, "Your IP seems to have changed. Updating."); log_notice(LD_NET, "Your IP seems to have changed. Updating.");
server_has_changed_ip(); server_has_changed_ip();
} }
old_addr = *addr_out; old_addr = *addr_out;
@ -1570,7 +1575,7 @@ get_default_nickname(void)
char *cp, *out, *outp; char *cp, *out, *outp;
if (gethostname(localhostname, sizeof(localhostname)) < 0) { if (gethostname(localhostname, sizeof(localhostname)) < 0) {
warn(LD_NET,"Error obtaining local hostname"); log_warn(LD_NET,"Error obtaining local hostname");
return NULL; return NULL;
} }
@ -1672,8 +1677,8 @@ options_dup(config_format_t *fmt, or_options_t *old)
line = get_assigned_option(fmt, old, fmt->vars[i].name); line = get_assigned_option(fmt, old, fmt->vars[i].name);
if (line) { if (line) {
if (config_assign(fmt, newopts, line, 0, 0) < 0) { if (config_assign(fmt, newopts, line, 0, 0) < 0) {
warn(LD_BUG, "Bug: config_get_assigned_option() generated " log_warn(LD_BUG, "Bug: config_get_assigned_option() generated "
"something we couldn't config_assign()."); "something we couldn't config_assign().");
tor_assert(0); tor_assert(0);
} }
} }
@ -1756,7 +1761,7 @@ config_dump(config_format_t *fmt, void *options, int minimal)
char *tmp; char *tmp;
tmp = tor_malloc(len); tmp = tor_malloc(len);
if (tor_snprintf(tmp, len, "%s %s\n", line->key, line->value)<0) { if (tor_snprintf(tmp, len, "%s %s\n", line->key, line->value)<0) {
err(LD_BUG,"Internal error writing option value"); log_err(LD_BUG,"Internal error writing option value");
tor_assert(0); tor_assert(0);
} }
smartlist_add(elements, tmp); smartlist_add(elements, tmp);
@ -1771,7 +1776,7 @@ config_dump(config_format_t *fmt, void *options, int minimal)
char *tmp; char *tmp;
tmp = tor_malloc(len); tmp = tor_malloc(len);
if (tor_snprintf(tmp, len, "%s %s\n", line->key, line->value)<0) { if (tor_snprintf(tmp, len, "%s %s\n", line->key, line->value)<0) {
err(LD_BUG,"Internal error writing option value"); log_err(LD_BUG,"Internal error writing option value");
tor_assert(0); tor_assert(0);
} }
smartlist_add(elements, tmp); smartlist_add(elements, tmp);
@ -1831,7 +1836,7 @@ parse_reachable_addresses(void)
if (config_parse_addr_policy(options->ReachableAddresses, if (config_parse_addr_policy(options->ReachableAddresses,
&reachable_addr_policy, &reachable_addr_policy,
ADDR_POLICY_ACCEPT)) { ADDR_POLICY_ACCEPT)) {
warn(LD_CONFIG, "Error in ReachableAddresses entry; ignoring."); log_warn(LD_CONFIG, "Error in ReachableAddresses entry; ignoring.");
return; return;
} }
} }
@ -1861,7 +1866,7 @@ fascist_firewall_allows_address(uint32_t addr, uint16_t port)
case ADDR_POLICY_REJECTED: case ADDR_POLICY_REJECTED:
return 0; return 0;
default: default:
warn(LD_BUG, "Unexpected result: %d", (int)p); log_warn(LD_BUG, "Unexpected result: %d", (int)p);
return 0; return 0;
} }
} }
@ -1927,7 +1932,7 @@ options_validate(or_options_t *old_options, or_options_t *options,
if (!is_internal_IP(addr, 1) && if (!is_internal_IP(addr, 1) &&
(!old_options || !config_lines_eq(old_options->SocksListenAddress, (!old_options || !config_lines_eq(old_options->SocksListenAddress,
options->SocksListenAddress))) { options->SocksListenAddress))) {
warn(LD_CONFIG, log_warn(LD_CONFIG,
"You specified a public address '%s' for a SOCKS listener. Other " "You specified a public address '%s' for a SOCKS listener. Other "
"people on the Internet might find your computer and use it as " "people on the Internet might find your computer and use it as "
"an open SOCKS proxy. Please don't allow this unless you have " "an open SOCKS proxy. Please don't allow this unless you have "
@ -1944,7 +1949,8 @@ options_validate(or_options_t *old_options, or_options_t *options,
if (server_mode(options)) { if (server_mode(options)) {
if (!(options->Nickname = get_default_nickname())) if (!(options->Nickname = get_default_nickname()))
return -1; return -1;
notice(LD_CONFIG, "Choosing default nickname '%s'", options->Nickname); log_notice(LD_CONFIG, "Choosing default nickname '%s'",
options->Nickname);
} }
} else { } else {
if (!is_legal_nickname(options->Nickname)) { if (!is_legal_nickname(options->Nickname)) {
@ -2021,8 +2027,8 @@ options_validate(or_options_t *old_options, or_options_t *options,
options->RecommendedServerVersions = options->RecommendedServerVersions =
config_lines_dup(options->RecommendedVersions); config_lines_dup(options->RecommendedVersions);
if (options->UseEntryGuards) { if (options->UseEntryGuards) {
notice(LD_CONFIG, "Authoritative directory servers can't set " log_notice(LD_CONFIG, "Authoritative directory servers can't set "
"UseEntryGuards. Disabling."); "UseEntryGuards. Disabling.");
options->UseEntryGuards = 0; options->UseEntryGuards = 0;
} }
} }
@ -2344,38 +2350,39 @@ options_transition_allowed(or_options_t *old, or_options_t *new_val)
return 0; return 0;
if (!opt_streq(old->PidFile, new_val->PidFile)) { if (!opt_streq(old->PidFile, new_val->PidFile)) {
warn(LD_CONFIG,"PidFile is not allowed to change. Failing."); log_warn(LD_CONFIG,"PidFile is not allowed to change. Failing.");
return -1; return -1;
} }
if (old->RunAsDaemon != new_val->RunAsDaemon) { if (old->RunAsDaemon != new_val->RunAsDaemon) {
warn(LD_CONFIG,"While Tor is running, changing RunAsDaemon is not allowed." log_warn(LD_CONFIG,
" Failing."); "While Tor is running, changing RunAsDaemon is not allowed."
" Failing.");
return -1; return -1;
} }
if (strcmp(old->DataDirectory,new_val->DataDirectory)!=0) { if (strcmp(old->DataDirectory,new_val->DataDirectory)!=0) {
warn(LD_CONFIG,"While Tor is running, changing DataDirectory " log_warn(LD_CONFIG,"While Tor is running, changing DataDirectory "
"(\"%s\"->\"%s\") is not allowed. Failing.", "(\"%s\"->\"%s\") is not allowed. Failing.",
old->DataDirectory, new_val->DataDirectory); old->DataDirectory, new_val->DataDirectory);
return -1; return -1;
} }
if (!opt_streq(old->User, new_val->User)) { if (!opt_streq(old->User, new_val->User)) {
warn(LD_CONFIG,"While Tor is running, changing User is not allowed. " log_warn(LD_CONFIG,"While Tor is running, changing User is not allowed. "
"Failing."); "Failing.");
return -1; return -1;
} }
if (!opt_streq(old->Group, new_val->Group)) { if (!opt_streq(old->Group, new_val->Group)) {
warn(LD_CONFIG,"While Tor is running, changing Group is not allowed. " log_warn(LD_CONFIG,"While Tor is running, changing Group is not allowed. "
"Failing."); "Failing.");
return -1; return -1;
} }
if (old->HardwareAccel != new_val->HardwareAccel) { if (old->HardwareAccel != new_val->HardwareAccel) {
warn(LD_CONFIG,"While Tor is running, changing HardwareAccel is not " log_warn(LD_CONFIG,"While Tor is running, changing HardwareAccel is not "
"allowed. Failing."); "allowed. Failing.");
return -1; return -1;
} }
@ -2449,9 +2456,10 @@ get_windows_conf_root(void)
&idl))) { &idl))) {
GetCurrentDirectory(MAX_PATH, path); GetCurrentDirectory(MAX_PATH, path);
is_set = 1; is_set = 1;
warn(LD_CONFIG, "I couldn't find your application data folder: are you " log_warn(LD_CONFIG,
"running an ancient version of Windows 95? Defaulting to \"%s\"", "I couldn't find your application data folder: are you "
path); "running an ancient version of Windows 95? Defaulting to \"%s\"",
path);
return path; return path;
} }
/* Convert the path from an "ID List" (whatever that is!) to a path. */ /* Convert the path from an "ID List" (whatever that is!) to a path. */
@ -2501,7 +2509,7 @@ check_nickname_list(const char *lst, const char *name)
SMARTLIST_FOREACH(sl, const char *, s, SMARTLIST_FOREACH(sl, const char *, s,
{ {
if (!is_legal_nickname_or_hexdigest(s)) { if (!is_legal_nickname_or_hexdigest(s)) {
warn(LD_CONFIG, "Invalid nickname '%s' in %s line", s, name); log_warn(LD_CONFIG, "Invalid nickname '%s' in %s line", s, name);
r = -1; r = -1;
} }
}); });
@ -2679,18 +2687,20 @@ config_register_addressmaps(or_options_t *options)
from = smartlist_get(elts,0); from = smartlist_get(elts,0);
to = smartlist_get(elts,1); to = smartlist_get(elts,1);
if (!is_plausible_address(from)) { if (!is_plausible_address(from)) {
warn(LD_CONFIG,"Skipping invalid argument '%s' to MapAddress",from); log_warn(LD_CONFIG,
"Skipping invalid argument '%s' to MapAddress", from);
} else if (!is_plausible_address(to)) { } else if (!is_plausible_address(to)) {
warn(LD_CONFIG,"Skipping invalid argument '%s' to MapAddress",to); log_warn(LD_CONFIG,
"Skipping invalid argument '%s' to MapAddress", to);
} else { } else {
addressmap_register(from, tor_strdup(to), 0); addressmap_register(from, tor_strdup(to), 0);
if (smartlist_len(elts)>2) { if (smartlist_len(elts)>2) {
warn(LD_CONFIG,"Ignoring extra arguments to MapAddress."); log_warn(LD_CONFIG,"Ignoring extra arguments to MapAddress.");
} }
} }
} else { } else {
warn(LD_CONFIG,"MapAddress '%s' has too few arguments. Ignoring.", log_warn(LD_CONFIG,"MapAddress '%s' has too few arguments. Ignoring.",
opt->value); opt->value);
} }
SMARTLIST_FOREACH(elts, char*, cp, tor_free(cp)); SMARTLIST_FOREACH(elts, char*, cp, tor_free(cp));
smartlist_clear(elts); smartlist_clear(elts);
@ -2717,8 +2727,8 @@ parse_log_severity_range(const char *range, int *min_out, int *max_out)
char *tmp_sev = tor_strndup(range, cp - range); char *tmp_sev = tor_strndup(range, cp - range);
levelMin = parse_log_level(tmp_sev); levelMin = parse_log_level(tmp_sev);
if (levelMin < 0) { if (levelMin < 0) {
warn(LD_CONFIG, "Unrecognized log severity '%s': must be one of " log_warn(LD_CONFIG, "Unrecognized log severity '%s': must be one of "
"err|warn|notice|info|debug", tmp_sev); "err|warn|notice|info|debug", tmp_sev);
tor_free(tmp_sev); tor_free(tmp_sev);
return -1; return -1;
} }
@ -2729,16 +2739,16 @@ parse_log_severity_range(const char *range, int *min_out, int *max_out)
} else { } else {
levelMax = parse_log_level(cp+1); levelMax = parse_log_level(cp+1);
if (levelMax < 0) { if (levelMax < 0) {
warn(LD_CONFIG, "Unrecognized log severity '%s': must be one of " log_warn(LD_CONFIG, "Unrecognized log severity '%s': must be one of "
"err|warn|notice|info|debug", cp+1); "err|warn|notice|info|debug", cp+1);
return -1; return -1;
} }
} }
} else { } else {
levelMin = parse_log_level(range); levelMin = parse_log_level(range);
if (levelMin < 0) { if (levelMin < 0) {
warn(LD_CONFIG, "Unrecognized log severity '%s': must be one of " log_warn(LD_CONFIG, "Unrecognized log severity '%s': must be one of "
"err|warn|notice|info|debug", range); "err|warn|notice|info|debug", range);
return -1; return -1;
} }
levelMax = LOG_ERR; levelMax = LOG_ERR;
@ -2775,8 +2785,8 @@ convert_log_option(or_options_t *options, config_line_t *level_opt,
if (file_opt && !strcasecmp(file_opt->key, "LogFile")) { if (file_opt && !strcasecmp(file_opt->key, "LogFile")) {
if (add_single_log_option(options, levelMin, levelMax, "file", if (add_single_log_option(options, levelMin, levelMax, "file",
file_opt->value) < 0) { file_opt->value) < 0) {
warn(LD_FS, "Cannot write to LogFile \"%s\": %s.", file_opt->value, log_warn(LD_FS, "Cannot write to LogFile \"%s\": %s.", file_opt->value,
strerror(errno)); strerror(errno));
return -1; return -1;
} }
} else if (file_opt && !strcasecmp(file_opt->key, "SysLog")) { } else if (file_opt && !strcasecmp(file_opt->key, "SysLog")) {
@ -2807,7 +2817,7 @@ options_init_logs(or_options_t *options, int validate_only)
smartlist_split_string(elts, opt->value, NULL, smartlist_split_string(elts, opt->value, NULL,
SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 3); SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 3);
if (smartlist_len(elts) == 0) { if (smartlist_len(elts) == 0) {
warn(LD_CONFIG, "Bad syntax on Log option 'Log %s'", opt->value); log_warn(LD_CONFIG, "Bad syntax on Log option 'Log %s'", opt->value);
ok = 0; goto cleanup; ok = 0; goto cleanup;
} }
if (parse_log_severity_range(smartlist_get(elts,0), &levelMin, if (parse_log_severity_range(smartlist_get(elts,0), &levelMin,
@ -2817,8 +2827,8 @@ options_init_logs(or_options_t *options, int validate_only)
if (smartlist_len(elts) < 2) { /* only loglevels were provided */ if (smartlist_len(elts) < 2) { /* only loglevels were provided */
if (!validate_only) { if (!validate_only) {
if (daemon) { if (daemon) {
warn(LD_CONFIG, log_warn(LD_CONFIG,
"Can't log to stdout with RunAsDaemon set; skipping stdout"); "Can't log to stdout with RunAsDaemon set; skipping stdout");
} else { } else {
add_stream_log(levelMin, levelMax, "<stdout>", stdout); add_stream_log(levelMin, levelMax, "<stdout>", stdout);
} }
@ -2827,24 +2837,24 @@ options_init_logs(or_options_t *options, int validate_only)
} }
if (!strcasecmp(smartlist_get(elts,1), "file")) { if (!strcasecmp(smartlist_get(elts,1), "file")) {
if (smartlist_len(elts) != 3) { if (smartlist_len(elts) != 3) {
warn(LD_CONFIG, "Bad syntax on Log option 'Log %s'", opt->value); log_warn(LD_CONFIG, "Bad syntax on Log option 'Log %s'", opt->value);
ok = 0; goto cleanup; ok = 0; goto cleanup;
} }
if (!validate_only) { if (!validate_only) {
if (add_file_log(levelMin, levelMax, smartlist_get(elts, 2)) < 0) { if (add_file_log(levelMin, levelMax, smartlist_get(elts, 2)) < 0) {
warn(LD_CONFIG, "Couldn't open file for 'Log %s'", opt->value); log_warn(LD_CONFIG, "Couldn't open file for 'Log %s'", opt->value);
ok = 0; ok = 0;
} }
} }
goto cleanup; goto cleanup;
} }
if (smartlist_len(elts) != 2) { if (smartlist_len(elts) != 2) {
warn(LD_CONFIG, "Bad syntax on Log option 'Log %s'", opt->value); log_warn(LD_CONFIG, "Bad syntax on Log option 'Log %s'", opt->value);
ok = 0; goto cleanup; ok = 0; goto cleanup;
} }
if (!strcasecmp(smartlist_get(elts,1), "stdout")) { if (!strcasecmp(smartlist_get(elts,1), "stdout")) {
if (daemon) { if (daemon) {
warn(LD_CONFIG, "Can't log to stdout with RunAsDaemon set."); log_warn(LD_CONFIG, "Can't log to stdout with RunAsDaemon set.");
ok = 0; goto cleanup; ok = 0; goto cleanup;
} }
if (!validate_only) { if (!validate_only) {
@ -2852,7 +2862,7 @@ options_init_logs(or_options_t *options, int validate_only)
} }
} else if (!strcasecmp(smartlist_get(elts,1), "stderr")) { } else if (!strcasecmp(smartlist_get(elts,1), "stderr")) {
if (daemon) { if (daemon) {
warn(LD_CONFIG, "Can't log to stdout with RunAsDaemon set."); log_warn(LD_CONFIG, "Can't log to stdout with RunAsDaemon set.");
ok = 0; goto cleanup; ok = 0; goto cleanup;
} }
if (!validate_only) { if (!validate_only) {
@ -2863,15 +2873,15 @@ options_init_logs(or_options_t *options, int validate_only)
if (!validate_only) if (!validate_only)
add_syslog_log(levelMin, levelMax); add_syslog_log(levelMin, levelMax);
#else #else
warn(LD_CONFIG, "Syslog is not supported in this compilation."); log_warn(LD_CONFIG, "Syslog is not supported in this compilation.");
#endif #endif
} else { } else {
warn(LD_CONFIG, "Unrecognized log type %s", log_warn(LD_CONFIG, "Unrecognized log type %s",
(const char*)smartlist_get(elts,1)); (const char*)smartlist_get(elts,1));
if (strchr(smartlist_get(elts,1), '/') || if (strchr(smartlist_get(elts,1), '/') ||
strchr(smartlist_get(elts,1), '\\')) { strchr(smartlist_get(elts,1), '\\')) {
warn(LD_CONFIG, "Did you mean to say 'Log file %s' ?", log_warn(LD_CONFIG, "Did you mean to say 'Log file %s' ?",
(const char *)smartlist_get(elts,1)); (const char *)smartlist_get(elts,1));
} }
ok = 0; goto cleanup; ok = 0; goto cleanup;
} }
@ -2900,7 +2910,7 @@ add_single_log_option(or_options_t *options, int minSeverity, int maxSeverity,
maxSeverity == LOG_ERR ? "" : "-", maxSeverity == LOG_ERR ? "" : "-",
maxSeverity == LOG_ERR ? "" : log_level_to_string(maxSeverity), maxSeverity == LOG_ERR ? "" : log_level_to_string(maxSeverity),
type, fname?" ":"", fname?fname:"")<0) { type, fname?" ":"", fname?fname:"")<0) {
warn(LD_BUG, "Normalized log option too long."); log_warn(LD_BUG, "Normalized log option too long.");
tor_free(buf); tor_free(buf);
return -1; return -1;
} }
@ -2940,8 +2950,8 @@ normalize_log_options(or_options_t *options)
while (opt) { while (opt) {
if (!strcasecmp(opt->key, "LogLevel")) { if (!strcasecmp(opt->key, "LogLevel")) {
warn(LD_CONFIG, "Two LogLevel options in a row without " log_warn(LD_CONFIG, "Two LogLevel options in a row without "
"intervening LogFile or SysLog"); "intervening LogFile or SysLog");
opt = opt->next; opt = opt->next;
} else { } else {
tor_assert(!strcasecmp(opt->key, "LogFile") || tor_assert(!strcasecmp(opt->key, "LogFile") ||
@ -3011,7 +3021,7 @@ config_expand_exit_policy_aliases(smartlist_t *entries, int assume_action)
action = ""; action = "";
cp = v; cp = v;
} else { } else {
warn(LD_CONFIG,"Policy '%s' didn't start with accept or reject.", v); log_warn(LD_CONFIG,"Policy '%s' didn't start with accept or reject.", v);
tor_free(pre); tor_free(pre);
return -1; return -1;
} }
@ -3039,7 +3049,7 @@ config_expand_exit_policy_aliases(smartlist_t *entries, int assume_action)
} }
post = smartlist_join_strings(entries,",",0,NULL); post = smartlist_join_strings(entries,",",0,NULL);
if (expanded_any) if (expanded_any)
info(LD_CONFIG, "Expanded '%s' to '%s'", pre, post); log_info(LD_CONFIG, "Expanded '%s' to '%s'", pre, post);
tor_free(pre); tor_free(pre);
tor_free(post); tor_free(post);
return expanded_any; return expanded_any;
@ -3181,16 +3191,16 @@ config_parse_addr_policy(config_line_t *cfg,
} }
SMARTLIST_FOREACH(entries, const char *, ent, SMARTLIST_FOREACH(entries, const char *, ent,
{ {
debug(LD_CONFIG,"Adding new entry '%s'",ent); log_debug(LD_CONFIG,"Adding new entry '%s'",ent);
*nextp = router_parse_addr_policy_from_string(ent, assume_action); *nextp = router_parse_addr_policy_from_string(ent, assume_action);
if (*nextp) { if (*nextp) {
if (addr_mask_get_bits((*nextp)->msk)<0) { if (addr_mask_get_bits((*nextp)->msk)<0) {
warn(LD_CONFIG, "Address policy element '%s' can't be expressed " log_warn(LD_CONFIG, "Address policy element '%s' can't be expressed "
"as a bit prefix.", ent); "as a bit prefix.", ent);
} }
nextp = &((*nextp)->next); nextp = &((*nextp)->next);
} else { } else {
warn(LD_CONFIG,"Malformed policy '%s'.", ent); log_warn(LD_CONFIG,"Malformed policy '%s'.", ent);
r = -1; r = -1;
} }
}); });
@ -3308,12 +3318,12 @@ parse_redirect_line(smartlist_t *result, config_line_t *line)
smartlist_split_string(elements, line->value, NULL, smartlist_split_string(elements, line->value, NULL,
SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 0); SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 0);
if (smartlist_len(elements) != 2) { if (smartlist_len(elements) != 2) {
warn(LD_CONFIG, "Wrong number of elements in RedirectExit line"); log_warn(LD_CONFIG, "Wrong number of elements in RedirectExit line");
goto err; goto err;
} }
if (parse_addr_and_port_range(smartlist_get(elements,0),&r->addr,&r->mask, if (parse_addr_and_port_range(smartlist_get(elements,0),&r->addr,&r->mask,
&r->port_min,&r->port_max)) { &r->port_min,&r->port_max)) {
warn(LD_CONFIG, "Error parsing source address in RedirectExit line"); log_warn(LD_CONFIG, "Error parsing source address in RedirectExit line");
goto err; goto err;
} }
if (0==strcasecmp(smartlist_get(elements,1), "pass")) { if (0==strcasecmp(smartlist_get(elements,1), "pass")) {
@ -3321,7 +3331,7 @@ parse_redirect_line(smartlist_t *result, config_line_t *line)
} else { } else {
if (parse_addr_port(smartlist_get(elements,1),NULL,&r->addr_dest, if (parse_addr_port(smartlist_get(elements,1),NULL,&r->addr_dest,
&r->port_dest)) { &r->port_dest)) {
warn(LD_CONFIG, "Error parsing dest address in RedirectExit line"); log_warn(LD_CONFIG, "Error parsing dest address in RedirectExit line");
goto err; goto err;
} }
r->is_redirect = 1; r->is_redirect = 1;
@ -3362,7 +3372,7 @@ parse_dir_server_line(const char *line, int validate_only)
smartlist_split_string(items, line, NULL, smartlist_split_string(items, line, NULL,
SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, -1); SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, -1);
if (smartlist_len(items) < 2) { if (smartlist_len(items) < 2) {
warn(LD_CONFIG, "Too few arguments to DirServer line."); log_warn(LD_CONFIG, "Too few arguments to DirServer line.");
goto err; goto err;
} }
@ -3380,33 +3390,33 @@ parse_dir_server_line(const char *line, int validate_only)
} }
if (smartlist_len(items) < 2) { if (smartlist_len(items) < 2) {
warn(LD_CONFIG, "Too few arguments to DirServer line."); log_warn(LD_CONFIG, "Too few arguments to DirServer line.");
goto err; goto err;
} }
addrport = smartlist_get(items, 0); addrport = smartlist_get(items, 0);
if (parse_addr_port(addrport, &address, NULL, &port)<0) { if (parse_addr_port(addrport, &address, NULL, &port)<0) {
warn(LD_CONFIG, "Error parsing DirServer address '%s'", addrport); log_warn(LD_CONFIG, "Error parsing DirServer address '%s'", addrport);
goto err; goto err;
} }
if (!port) { if (!port) {
warn(LD_CONFIG, "Missing port in DirServer address '%s'",addrport); log_warn(LD_CONFIG, "Missing port in DirServer address '%s'",addrport);
goto err; goto err;
} }
smartlist_del_keeporder(items, 0); smartlist_del_keeporder(items, 0);
fingerprint = smartlist_join_strings(items, "", 0, NULL); fingerprint = smartlist_join_strings(items, "", 0, NULL);
if (strlen(fingerprint) != HEX_DIGEST_LEN) { if (strlen(fingerprint) != HEX_DIGEST_LEN) {
warn(LD_CONFIG, "Key digest for DirServer is wrong length."); log_warn(LD_CONFIG, "Key digest for DirServer is wrong length.");
goto err; goto err;
} }
if (base16_decode(digest, DIGEST_LEN, fingerprint, HEX_DIGEST_LEN)<0) { if (base16_decode(digest, DIGEST_LEN, fingerprint, HEX_DIGEST_LEN)<0) {
warn(LD_CONFIG, "Unable to decode DirServer key digest."); log_warn(LD_CONFIG, "Unable to decode DirServer key digest.");
goto err; goto err;
} }
if (!validate_only) { if (!validate_only) {
debug(LD_DIR, "Trusted dirserver at %s:%d (%s)", address, (int)port, log_debug(LD_DIR, "Trusted dirserver at %s:%d (%s)", address, (int)port,
(char*)smartlist_get(items,1)); (char*)smartlist_get(items,1));
add_trusted_dir_server(nickname, address, port, digest, supports_v1); add_trusted_dir_server(nickname, address, port, digest, supports_v1);
} }
@ -3447,15 +3457,16 @@ normalize_data_directory(or_options_t *options)
if (strncmp(d,"~/",2) == 0) { if (strncmp(d,"~/",2) == 0) {
char *fn = expand_filename(d); char *fn = expand_filename(d);
if (!fn) { if (!fn) {
err(LD_CONFIG,"Failed to expand filename \"%s\".", d); log_err(LD_CONFIG,"Failed to expand filename \"%s\".", d);
return -1; return -1;
} }
if (!options->DataDirectory && !strcmp(fn,"/.tor")) { if (!options->DataDirectory && !strcmp(fn,"/.tor")) {
/* If our homedir is /, we probably don't want to use it. */ /* If our homedir is /, we probably don't want to use it. */
/* XXXX Default to /var/lib/tor? */ /* XXXX Default to /var/lib/tor? */
warn(LD_CONFIG, "Default DataDirectory is \"~/.tor\". This expands to " log_warn(LD_CONFIG,
"\"%s\", which is probably not what you want. Using \"%s/tor\" " "Default DataDirectory is \"~/.tor\". This expands to "
"instead", fn, LOCALSTATEDIR); "\"%s\", which is probably not what you want. Using \"%s/tor\" "
"instead", fn, LOCALSTATEDIR);
tor_free(fn); tor_free(fn);
fn = tor_strdup(LOCALSTATEDIR"/tor"); fn = tor_strdup(LOCALSTATEDIR"/tor");
@ -3476,7 +3487,7 @@ validate_data_directory(or_options_t *options)
return -1; return -1;
tor_assert(options->DataDirectory); tor_assert(options->DataDirectory);
if (strlen(options->DataDirectory) > (512-128)) { if (strlen(options->DataDirectory) > (512-128)) {
err(LD_CONFIG, "DataDirectory is too long."); log_err(LD_CONFIG, "DataDirectory is too long.");
return -1; return -1;
} }
return 0; return 0;
@ -3514,13 +3525,14 @@ write_configuration_file(const char *fname, or_options_t *options)
case FN_NOENT: case FN_NOENT:
break; break;
default: default:
warn(LD_CONFIG,"Config file \"%s\" is not a file? Failing.", fname); log_warn(LD_CONFIG,
"Config file \"%s\" is not a file? Failing.", fname);
return -1; return -1;
} }
} }
if (!(new_conf = options_dump(options, 1))) { if (!(new_conf = options_dump(options, 1))) {
warn(LD_BUG, "Couldn't get configuration string"); log_warn(LD_BUG, "Couldn't get configuration string");
goto err; goto err;
} }
@ -3537,7 +3549,7 @@ write_configuration_file(const char *fname, or_options_t *options)
fn_tmp = tor_malloc(fn_tmp_len); fn_tmp = tor_malloc(fn_tmp_len);
while (1) { while (1) {
if (tor_snprintf(fn_tmp, fn_tmp_len, "%s.orig.%d", fname, i)<0) { if (tor_snprintf(fn_tmp, fn_tmp_len, "%s.orig.%d", fname, i)<0) {
warn(LD_BUG, "tor_snprintf failed inexplicably"); log_warn(LD_BUG, "tor_snprintf failed inexplicably");
tor_free(fn_tmp); tor_free(fn_tmp);
goto err; goto err;
} }
@ -3545,7 +3557,7 @@ write_configuration_file(const char *fname, or_options_t *options)
break; break;
++i; ++i;
} }
notice(LD_CONFIG, "Renaming old configuration file to \"%s\"", fn_tmp); log_notice(LD_CONFIG, "Renaming old configuration file to \"%s\"", fn_tmp);
rename(fname, fn_tmp); rename(fname, fn_tmp);
tor_free(fn_tmp); tor_free(fn_tmp);
} }
@ -3651,7 +3663,7 @@ config_parse_units(const char *val, struct unit_table_t *u, int *ok)
return v; return v;
} }
} }
warn(LD_CONFIG, "Unknown unit '%s'.", cp); log_warn(LD_CONFIG, "Unknown unit '%s'.", cp);
*ok = 0; *ok = 0;
return 0; return 0;
} }
@ -3678,7 +3690,7 @@ config_parse_interval(const char *s, int *ok)
if (!ok) if (!ok)
return -1; return -1;
if (r > INT_MAX) { if (r > INT_MAX) {
warn(LD_CONFIG, "Interval '%s' is too long", s); log_warn(LD_CONFIG, "Interval '%s' is too long", s);
*ok = 0; *ok = 0;
return -1; return -1;
} }
@ -3808,12 +3820,12 @@ or_state_validate(or_state_t *old_state, or_state_t *state, int from_setconf)
const char *err; const char *err;
tor_version_t v; tor_version_t v;
if (entry_guards_parse_state(state, 0, &err)<0) { if (entry_guards_parse_state(state, 0, &err)<0) {
warn(LD_GENERAL, "Unable to parse entry nodes: %s", err); log_warn(LD_GENERAL, "Unable to parse entry nodes: %s", err);
return -1; return -1;
} }
if (state->TorVersion && tor_version_parse(state->TorVersion, &v)) { if (state->TorVersion && tor_version_parse(state->TorVersion, &v)) {
warn(LD_GENERAL, "Can't parse Tor version '%s' from your state file. " log_warn(LD_GENERAL, "Can't parse Tor version '%s' from your state file. "
"Proceeding anyway.", state->TorVersion); "Proceeding anyway.", state->TorVersion);
} }
return 0; return 0;
} }
@ -3828,9 +3840,9 @@ or_state_set(or_state_t *new_state)
config_free(&state_format, global_state); config_free(&state_format, global_state);
global_state = new_state; global_state = new_state;
if (entry_guards_parse_state(global_state, 1, &err)<0) if (entry_guards_parse_state(global_state, 1, &err)<0)
warn(LD_GENERAL,"Unparseable helper nodes state: %s",err); log_warn(LD_GENERAL,"Unparseable helper nodes state: %s",err);
if (rep_hist_load_state(global_state, &err)<0) if (rep_hist_load_state(global_state, &err)<0)
warn(LD_GENERAL,"Unparseable bandwidth history state: %s",err); log_warn(LD_GENERAL,"Unparseable bandwidth history state: %s",err);
} }
/* DOCDOC */ /* DOCDOC */
@ -3845,14 +3857,14 @@ or_state_load(void)
switch (file_status(fname)) { switch (file_status(fname)) {
case FN_FILE: case FN_FILE:
if (!(contents = read_file_to_str(fname, 0))) { if (!(contents = read_file_to_str(fname, 0))) {
warn(LD_FS, "Unable to read state file \"%s\"", fname); log_warn(LD_FS, "Unable to read state file \"%s\"", fname);
goto done; goto done;
} }
break; break;
case FN_NOENT: case FN_NOENT:
break; break;
default: default:
warn(LD_GENERAL,"State file \"%s\" is not a file? Failing.", fname); log_warn(LD_GENERAL,"State file \"%s\" is not a file? Failing.", fname);
goto done; goto done;
} }
new_state = tor_malloc_zero(sizeof(or_state_t)); new_state = tor_malloc_zero(sizeof(or_state_t));
@ -3873,9 +3885,9 @@ or_state_load(void)
goto done; goto done;
if (contents) if (contents)
info(LD_GENERAL, "Loaded state from \"%s\"", fname); log_info(LD_GENERAL, "Loaded state from \"%s\"", fname);
else else
info(LD_GENERAL, "Initialized state"); log_info(LD_GENERAL, "Initialized state");
or_state_set(new_state); or_state_set(new_state);
new_state = NULL; new_state = NULL;
if (!contents) { if (!contents) {
@ -3924,12 +3936,12 @@ or_state_save(void)
tor_free(state); tor_free(state);
fname = get_or_state_fname(); fname = get_or_state_fname();
if (write_str_to_file(fname, contents, 0)<0) { if (write_str_to_file(fname, contents, 0)<0) {
warn(LD_FS, "Unable to write state to file \"%s\"", fname); log_warn(LD_FS, "Unable to write state to file \"%s\"", fname);
tor_free(fname); tor_free(fname);
tor_free(contents); tor_free(contents);
return -1; return -1;
} }
info(LD_GENERAL, "Saved state to \"%s\"", fname); log_info(LD_GENERAL, "Saved state to \"%s\"", fname);
tor_free(fname); tor_free(fname);
tor_free(contents); tor_free(contents);

175
src/or/connection.c
View File

@ -51,7 +51,7 @@ conn_type_to_string(int type)
case CONN_TYPE_CONTROL_LISTENER: return "Control listener"; case CONN_TYPE_CONTROL_LISTENER: return "Control listener";
case CONN_TYPE_CONTROL: return "Control"; case CONN_TYPE_CONTROL: return "Control";
default: default:
warn(LD_BUG, "Bug: unknown connection type %d", type); log_warn(LD_BUG, "Bug: unknown connection type %d", type);
tor_snprintf(buf, sizeof(buf), "unknown [%d]", type); tor_snprintf(buf, sizeof(buf), "unknown [%d]", type);
return buf; return buf;
} }
@ -134,7 +134,7 @@ conn_state_to_string(int type, int state)
break; break;
} }
warn(LD_BUG, "Bug: unknown connection state %d (type %d)", state, type); log_warn(LD_BUG, "Bug: unknown connection state %d (type %d)", state, type);
tor_snprintf(buf, sizeof(buf), tor_snprintf(buf, sizeof(buf),
"unknown state [%d] on unknown [%s] connection", "unknown state [%d] on unknown [%s] connection",
state, conn_type_to_string(type)); state, conn_type_to_string(type));
@ -191,12 +191,12 @@ connection_unregister(connection_t *conn)
{ {
if (conn->read_event) { if (conn->read_event) {
if (event_del(conn->read_event)) if (event_del(conn->read_event))
warn(LD_BUG, "Error removing read event for %d", conn->s); log_warn(LD_BUG, "Error removing read event for %d", conn->s);
tor_free(conn->read_event); tor_free(conn->read_event);
} }
if (conn->write_event) { if (conn->write_event) {
if (event_del(conn->write_event)) if (event_del(conn->write_event))
warn(LD_BUG, "Error removing write event for %d", conn->s); log_warn(LD_BUG, "Error removing write event for %d", conn->s);
tor_free(conn->write_event); tor_free(conn->write_event);
} }
} }
@ -234,13 +234,13 @@ _connection_free(connection_t *conn)
tor_free(conn->requested_resource); tor_free(conn->requested_resource);
if (conn->s >= 0) { if (conn->s >= 0) {
debug(LD_NET,"closing fd %d.",conn->s); log_debug(LD_NET,"closing fd %d.",conn->s);
tor_close_socket(conn->s); tor_close_socket(conn->s);
} }
if (conn->type == CONN_TYPE_OR && if (conn->type == CONN_TYPE_OR &&
!tor_digest_is_zero(conn->identity_digest)) { !tor_digest_is_zero(conn->identity_digest)) {
warn(LD_BUG, "called on OR conn with non-zeroed identity_digest"); log_warn(LD_BUG, "called on OR conn with non-zeroed identity_digest");
connection_or_remove_from_identity_map(conn); connection_or_remove_from_identity_map(conn);
} }
@ -324,9 +324,9 @@ connection_about_to_close_connection(connection_t *conn)
if (CONN_IS_EDGE(conn)) { if (CONN_IS_EDGE(conn)) {
if (!conn->has_sent_end) { if (!conn->has_sent_end) {
warn(LD_BUG, "Harmless bug: Edge connection (marked at %s:%d) " log_warn(LD_BUG, "Harmless bug: Edge connection (marked at %s:%d) "
"hasn't sent end yet?", "hasn't sent end yet?",
conn->marked_for_close_file, conn->marked_for_close); conn->marked_for_close_file, conn->marked_for_close);
tor_fragile_assert(); tor_fragile_assert();
} }
} }
@ -371,9 +371,9 @@ connection_about_to_close_connection(connection_t *conn)
if (conn->socks_request->has_finished == 0) { if (conn->socks_request->has_finished == 0) {
/* since conn gets removed right after this function finishes, /* since conn gets removed right after this function finishes,
* there's no point trying to send back a reply at this point. */ * there's no point trying to send back a reply at this point. */
warn(LD_BUG,"Bug: Closing stream (marked at %s:%d) without sending" log_warn(LD_BUG,"Bug: Closing stream (marked at %s:%d) without sending"
" back a socks reply.", " back a socks reply.",
conn->marked_for_close_file, conn->marked_for_close); conn->marked_for_close_file, conn->marked_for_close);
} else { } else {
control_event_stream_status(conn, STREAM_EVENT_CLOSED); control_event_stream_status(conn, STREAM_EVENT_CLOSED);
} }
@ -403,15 +403,15 @@ connection_close_immediate(connection_t *conn)
{ {
assert_connection_ok(conn,0); assert_connection_ok(conn,0);
if (conn->s < 0) { if (conn->s < 0) {
err(LD_BUG,"Bug: Attempt to close already-closed connection."); log_err(LD_BUG,"Bug: Attempt to close already-closed connection.");
tor_fragile_assert(); tor_fragile_assert();
return; return;
} }
if (conn->outbuf_flushlen) { if (conn->outbuf_flushlen) {
info(LD_NET,"fd %d, type %s, state %s, %d bytes on outbuf.", log_info(LD_NET,"fd %d, type %s, state %s, %d bytes on outbuf.",
conn->s, conn_type_to_string(conn->type), conn->s, conn_type_to_string(conn->type),
conn_state_to_string(conn->type, conn->state), conn_state_to_string(conn->type, conn->state),
(int)conn->outbuf_flushlen); (int)conn->outbuf_flushlen);
} }
connection_unregister(conn); connection_unregister(conn);
@ -515,7 +515,8 @@ connection_create_listener(const char *listenaddress, uint16_t listenport,
memset(&listenaddr,0,sizeof(struct sockaddr_in)); memset(&listenaddr,0,sizeof(struct sockaddr_in));
if (parse_addr_port(listenaddress, &address, &addr, &usePort)<0) { if (parse_addr_port(listenaddress, &address, &addr, &usePort)<0) {
warn(LD_CONFIG, "Error parsing/resolving ListenAddress %s",listenaddress); log_warn(LD_CONFIG,
"Error parsing/resolving ListenAddress %s", listenaddress);
return NULL; return NULL;
} }
@ -525,15 +526,15 @@ connection_create_listener(const char *listenaddress, uint16_t listenport,
listenaddr.sin_family = AF_INET; listenaddr.sin_family = AF_INET;
listenaddr.sin_port = htons((uint16_t) usePort); listenaddr.sin_port = htons((uint16_t) usePort);
notice(LD_NET, "Opening %s on %s:%d", log_notice(LD_NET, "Opening %s on %s:%d",
conn_type_to_string(type), address, usePort); conn_type_to_string(type), address, usePort);
s = socket(PF_INET,SOCK_STREAM,IPPROTO_TCP); s = socket(PF_INET,SOCK_STREAM,IPPROTO_TCP);
if (s < 0) { if (s < 0) {
warn(LD_NET,"Socket creation failed."); log_warn(LD_NET,"Socket creation failed.");
goto err; goto err;
} else if (!SOCKET_IS_POLLABLE(s)) { } else if (!SOCKET_IS_POLLABLE(s)) {
warn(LD_NET,"Too many connections; can't create pollable listener."); log_warn(LD_NET,"Too many connections; can't create pollable listener.");
tor_close_socket(s); tor_close_socket(s);
goto err; goto err;
} }
@ -551,14 +552,14 @@ connection_create_listener(const char *listenaddress, uint16_t listenport,
int e = tor_socket_errno(s); int e = tor_socket_errno(s);
if (ERRNO_IS_EADDRINUSE(e)) if (ERRNO_IS_EADDRINUSE(e))
helpfulhint = ". Is Tor already running?"; helpfulhint = ". Is Tor already running?";
warn(LD_NET, "Could not bind to %s:%u: %s%s", address, usePort, log_warn(LD_NET, "Could not bind to %s:%u: %s%s", address, usePort,
tor_socket_strerror(e), helpfulhint); tor_socket_strerror(e), helpfulhint);
goto err; goto err;
} }
if (listen(s,SOMAXCONN) < 0) { if (listen(s,SOMAXCONN) < 0) {
warn(LD_NET, "Could not listen on %s:%u: %s", address, usePort, log_warn(LD_NET, "Could not listen on %s:%u: %s", address, usePort,
tor_socket_strerror(tor_socket_errno(s))); tor_socket_strerror(tor_socket_errno(s)));
goto err; goto err;
} }
@ -571,12 +572,13 @@ connection_create_listener(const char *listenaddress, uint16_t listenport,
conn->port = usePort; conn->port = usePort;
if (connection_add(conn) < 0) { /* no space, forget it */ if (connection_add(conn) < 0) { /* no space, forget it */
warn(LD_NET,"connection_add failed. Giving up."); log_warn(LD_NET,"connection_add failed. Giving up.");
connection_free(conn); connection_free(conn);
goto err; goto err;
} }
debug(LD_NET,"%s listening on port %u.",conn_type_to_string(type), usePort); log_debug(LD_NET,"%s listening on port %u.",
conn_type_to_string(type), usePort);
conn->state = LISTENER_STATE_READY; conn->state = LISTENER_STATE_READY;
connection_start_reading(conn); connection_start_reading(conn);
@ -637,7 +639,7 @@ connection_handle_listener_read(connection_t *conn, int new_type)
int e; int e;
if (news>=0) { if (news>=0) {
/* Too many conns to poll. */ /* Too many conns to poll. */
warn(LD_NET,"Too many connections; couldn't accept connection."); log_warn(LD_NET,"Too many connections; couldn't accept connection.");
tor_close_socket(news); tor_close_socket(news);
return 0; return 0;
} }
@ -645,31 +647,33 @@ connection_handle_listener_read(connection_t *conn, int new_type)
if (ERRNO_IS_ACCEPT_EAGAIN(e)) { if (ERRNO_IS_ACCEPT_EAGAIN(e)) {
return 0; /* he hung up before we could accept(). that's fine. */ return 0; /* he hung up before we could accept(). that's fine. */
} else if (ERRNO_IS_ACCEPT_RESOURCE_LIMIT(e)) { } else if (ERRNO_IS_ACCEPT_RESOURCE_LIMIT(e)) {
notice(LD_NET,"accept failed: %s. Dropping incoming connection.", log_notice(LD_NET,"accept failed: %s. Dropping incoming connection.",
tor_socket_strerror(e)); tor_socket_strerror(e));
return 0; return 0;
} }
/* else there was a real error. */ /* else there was a real error. */
warn(LD_NET,"accept() failed: %s. Closing listener.", log_warn(LD_NET,"accept() failed: %s. Closing listener.",
tor_socket_strerror(e)); tor_socket_strerror(e));
connection_mark_for_close(conn); connection_mark_for_close(conn);
return -1; return -1;
} }
debug(LD_NET,"Connection accepted on socket %d (child of fd %d).", log_debug(LD_NET,
news,conn->s); "Connection accepted on socket %d (child of fd %d).",
news,conn->s);
set_socket_nonblocking(news); set_socket_nonblocking(news);
if (check_sockaddr_in((struct sockaddr*)addrbuf, remotelen, LOG_INFO)<0) { if (check_sockaddr_in((struct sockaddr*)addrbuf, remotelen, LOG_INFO)<0) {
info(LD_NET, "accept() returned a strange address; trying getsockname()."); log_info(LD_NET,
"accept() returned a strange address; trying getsockname().");
remotelen=256; remotelen=256;
memset(addrbuf, 0, sizeof(addrbuf)); memset(addrbuf, 0, sizeof(addrbuf));
if (getsockname(news, (struct sockaddr*)addrbuf, &remotelen)<0) { if (getsockname(news, (struct sockaddr*)addrbuf, &remotelen)<0) {
warn(LD_NET, "getsockname() failed."); log_warn(LD_NET, "getsockname() failed.");
} else { } else {
if (check_sockaddr_in((struct sockaddr*)addrbuf, remotelen, if (check_sockaddr_in((struct sockaddr*)addrbuf, remotelen,
LOG_WARN) < 0) { LOG_WARN) < 0) {
warn(LD_NET,"Something's wrong with this conn. Closing it."); log_warn(LD_NET,"Something's wrong with this conn. Closing it.");
tor_close_socket(news); tor_close_socket(news);
return 0; return 0;
} }
@ -682,8 +686,8 @@ connection_handle_listener_read(connection_t *conn, int new_type)
/* check sockspolicy to see if we should accept it */ /* check sockspolicy to see if we should accept it */
if (socks_policy_permits_address(ntohl(remote.sin_addr.s_addr)) == 0) { if (socks_policy_permits_address(ntohl(remote.sin_addr.s_addr)) == 0) {
tor_inet_ntoa(&remote.sin_addr, tmpbuf, sizeof(tmpbuf)); tor_inet_ntoa(&remote.sin_addr, tmpbuf, sizeof(tmpbuf));
notice(LD_APP,"Denying socks connection from untrusted address %s.", log_notice(LD_APP,"Denying socks connection from untrusted address %s.",
tmpbuf); tmpbuf);
tor_close_socket(news); tor_close_socket(news);
return 0; return 0;
} }
@ -692,8 +696,8 @@ connection_handle_listener_read(connection_t *conn, int new_type)
/* check dirpolicy to see if we should accept it */ /* check dirpolicy to see if we should accept it */
if (dir_policy_permits_address(ntohl(remote.sin_addr.s_addr)) == 0) { if (dir_policy_permits_address(ntohl(remote.sin_addr.s_addr)) == 0) {
tor_inet_ntoa(&remote.sin_addr, tmpbuf, sizeof(tmpbuf)); tor_inet_ntoa(&remote.sin_addr, tmpbuf, sizeof(tmpbuf));
notice(LD_DIRSERV,"Denying dir connection from address %s.", log_notice(LD_DIRSERV,"Denying dir connection from address %s.",
tmpbuf); tmpbuf);
tor_close_socket(news); tor_close_socket(news);
return 0; return 0;
} }
@ -762,13 +766,13 @@ connection_connect(connection_t *conn, char *address,
s = socket(PF_INET,SOCK_STREAM,IPPROTO_TCP); s = socket(PF_INET,SOCK_STREAM,IPPROTO_TCP);
if (s < 0) { if (s < 0) {
warn(LD_NET,"Error creating network socket: %s", log_warn(LD_NET,"Error creating network socket: %s",
tor_socket_strerror(tor_socket_errno(-1))); tor_socket_strerror(tor_socket_errno(-1)));
return -1; return -1;
} else if (!SOCKET_IS_POLLABLE(s)) { } else if (!SOCKET_IS_POLLABLE(s)) {
warn(LD_NET, log_warn(LD_NET,
"Too many connections; can't create pollable connection to %s", "Too many connections; can't create pollable connection to %s",
safe_str(address)); safe_str(address));
tor_close_socket(s); tor_close_socket(s);
return -1; return -1;
} }
@ -780,12 +784,12 @@ connection_connect(connection_t *conn, char *address,
ext_addr.sin_family = AF_INET; ext_addr.sin_family = AF_INET;
ext_addr.sin_port = 0; ext_addr.sin_port = 0;
if (!tor_inet_aton(options->OutboundBindAddress, &ext_addr.sin_addr)) { if (!tor_inet_aton(options->OutboundBindAddress, &ext_addr.sin_addr)) {
warn(LD_CONFIG,"Outbound bind address '%s' didn't parse. Ignoring.", log_warn(LD_CONFIG,"Outbound bind address '%s' didn't parse. Ignoring.",
options->OutboundBindAddress); options->OutboundBindAddress);
} else { } else {
if (bind(s, (struct sockaddr*)&ext_addr, sizeof(ext_addr)) < 0) { if (bind(s, (struct sockaddr*)&ext_addr, sizeof(ext_addr)) < 0) {
warn(LD_NET,"Error binding network socket: %s", log_warn(LD_NET,"Error binding network socket: %s",
tor_socket_strerror(tor_socket_errno(s))); tor_socket_strerror(tor_socket_errno(s)));
return -1; return -1;
} }
} }
@ -798,14 +802,15 @@ connection_connect(connection_t *conn, char *address,
dest_addr.sin_port = htons(port); dest_addr.sin_port = htons(port);
dest_addr.sin_addr.s_addr = htonl(addr); dest_addr.sin_addr.s_addr = htonl(addr);
debug(LD_NET,"Connecting to %s:%u.",safe_str(address),port); log_debug(LD_NET,"Connecting to %s:%u.",safe_str(address),port);
if (connect(s,(struct sockaddr *)&dest_addr,sizeof(dest_addr)) < 0) { if (connect(s,(struct sockaddr *)&dest_addr,sizeof(dest_addr)) < 0) {
int e = tor_socket_errno(s); int e = tor_socket_errno(s);
if (!ERRNO_IS_CONN_EINPROGRESS(e)) { if (!ERRNO_IS_CONN_EINPROGRESS(e)) {
/* yuck. kill it. */ /* yuck. kill it. */
info(LD_NET,"connect() to %s:%u failed: %s",safe_str(address),port, log_info(LD_NET,
tor_socket_strerror(e)); "connect() to %s:%u failed: %s",safe_str(address),port,
tor_socket_strerror(e));
tor_close_socket(s); tor_close_socket(s);
return -1; return -1;
} else { } else {
@ -905,8 +910,8 @@ retry_listeners(int type, config_line_t *cfg,
}); });
if (! line) { if (! line) {
/* This one isn't configured. Close it. */ /* This one isn't configured. Close it. */
notice(LD_NET, "Closing %s on %s:%d", log_notice(LD_NET, "Closing %s on %s:%d",
conn_type_to_string(type), conn->address, conn->port); conn_type_to_string(type), conn->address, conn->port);
if (replaced_conns) { if (replaced_conns) {
smartlist_add(replaced_conns, conn); smartlist_add(replaced_conns, conn);
} else { } else {
@ -915,8 +920,8 @@ retry_listeners(int type, config_line_t *cfg,
} }
} else { } else {
/* It's configured; we don't need to launch it. */ /* It's configured; we don't need to launch it. */
// debug(LD_NET, "Already have %s on %s:%d", // log_debug(LD_NET, "Already have %s on %s:%d",
// conn_type_to_string(type), conn->address, conn->port); // conn_type_to_string(type), conn->address, conn->port);
smartlist_remove(launch, line); smartlist_remove(launch, line);
if (free_launch_elts) if (free_launch_elts)
config_free_lines(line); config_free_lines(line);
@ -1101,11 +1106,11 @@ connection_bucket_refill(struct timeval *now)
/* refill the global buckets */ /* refill the global buckets */
if (global_read_bucket < (int)options->BandwidthBurst) { if (global_read_bucket < (int)options->BandwidthBurst) {
global_read_bucket += (int)options->BandwidthRate; global_read_bucket += (int)options->BandwidthRate;
debug(LD_NET,"global_read_bucket now %d.", global_read_bucket); log_debug(LD_NET,"global_read_bucket now %d.", global_read_bucket);
} }
if (global_write_bucket < (int)options->BandwidthBurst) { if (global_write_bucket < (int)options->BandwidthBurst) {
global_write_bucket += (int)options->BandwidthRate; global_write_bucket += (int)options->BandwidthRate;
debug(LD_NET,"global_write_bucket now %d.", global_write_bucket); log_debug(LD_NET,"global_write_bucket now %d.", global_write_bucket);
} }
/* refill the per-connection buckets */ /* refill the per-connection buckets */
@ -1267,23 +1272,24 @@ connection_read_to_buf(connection_t *conn, int *max_to_read)
return connection_tls_continue_handshake(conn); return connection_tls_continue_handshake(conn);
} }
debug(LD_NET,"%d: starting, inbuf_datalen %d (%d pending in tls object)." log_debug(LD_NET,
" at_most %d.", "%d: starting, inbuf_datalen %d (%d pending in tls object)."
conn->s,(int)buf_datalen(conn->inbuf), " at_most %d.",
tor_tls_get_pending_bytes(conn->tls), at_most); conn->s,(int)buf_datalen(conn->inbuf),
tor_tls_get_pending_bytes(conn->tls), at_most);
/* else open, or closing */ /* else open, or closing */
result = read_to_buf_tls(conn->tls, at_most, conn->inbuf); result = read_to_buf_tls(conn->tls, at_most, conn->inbuf);
switch (result) { switch (result) {
case TOR_TLS_CLOSE: case TOR_TLS_CLOSE:
info(LD_NET,"TLS connection closed on read. Closing. " log_info(LD_NET,"TLS connection closed on read. Closing. "
"(Nickname %s, address %s", "(Nickname %s, address %s",
conn->nickname ? conn->nickname : "not set", conn->address); conn->nickname ? conn->nickname : "not set", conn->address);
return -1; return -1;
case TOR_TLS_ERROR: case TOR_TLS_ERROR:
info(LD_NET,"tls error. breaking (nickname %s, address %s).", log_info(LD_NET,"tls error. breaking (nickname %s, address %s).",
conn->nickname ? conn->nickname : "not set", conn->address); conn->nickname ? conn->nickname : "not set", conn->address);
return -1; return -1;
case TOR_TLS_WANTWRITE: case TOR_TLS_WANTWRITE:
connection_start_writing(conn); connection_start_writing(conn);
@ -1302,7 +1308,7 @@ connection_read_to_buf(connection_t *conn, int *max_to_read)
* believing that SSL bytes are the same as TCP bytes anyway. */ * believing that SSL bytes are the same as TCP bytes anyway. */
int r2 = read_to_buf_tls(conn->tls, pending, conn->inbuf); int r2 = read_to_buf_tls(conn->tls, pending, conn->inbuf);
if (r2<0) { if (r2<0) {
warn(LD_BUG, "Bug: apparently, reading pending bytes can fail."); log_warn(LD_BUG, "Bug: apparently, reading pending bytes can fail.");
return -1; return -1;
} else { } else {
result += r2; result += r2;
@ -1402,7 +1408,8 @@ connection_handle_write(connection_t *conn)
/* Sometimes, "writable" means "connected". */ /* Sometimes, "writable" means "connected". */
if (connection_state_is_connecting(conn)) { if (connection_state_is_connecting(conn)) {
if (getsockopt(conn->s, SOL_SOCKET, SO_ERROR, (void*)&e, &len) < 0) { if (getsockopt(conn->s, SOL_SOCKET, SO_ERROR, (void*)&e, &len) < 0) {
warn(LD_BUG,"getsockopt() syscall failed?! Please report to tor-ops."); log_warn(LD_BUG,
"getsockopt() syscall failed?! Please report to tor-ops.");
if (CONN_IS_EDGE(conn)) if (CONN_IS_EDGE(conn))
connection_edge_end_errno(conn, conn->cpath_layer); connection_edge_end_errno(conn, conn->cpath_layer);
connection_mark_for_close(conn); connection_mark_for_close(conn);
@ -1411,7 +1418,7 @@ connection_handle_write(connection_t *conn)
if (e) { if (e) {
/* some sort of error, but maybe just inprogress still */ /* some sort of error, but maybe just inprogress still */
if (!ERRNO_IS_CONN_EINPROGRESS(e)) { if (!ERRNO_IS_CONN_EINPROGRESS(e)) {
info(LD_NET,"in-progress connect failed. Removing."); log_info(LD_NET,"in-progress connect failed. Removing.");
if (CONN_IS_EDGE(conn)) if (CONN_IS_EDGE(conn))
connection_edge_end_errno(conn, conn->cpath_layer); connection_edge_end_errno(conn, conn->cpath_layer);
@ -1453,19 +1460,19 @@ connection_handle_write(connection_t *conn)
switch (result) { switch (result) {
case TOR_TLS_ERROR: case TOR_TLS_ERROR:
case TOR_TLS_CLOSE: case TOR_TLS_CLOSE:
info(LD_NET,result==TOR_TLS_ERROR? log_info(LD_NET,result==TOR_TLS_ERROR?
"tls error. breaking.":"TLS connection closed on flush"); "tls error. breaking.":"TLS connection closed on flush");
/* Don't flush; connection is dead. */ /* Don't flush; connection is dead. */
connection_close_immediate(conn); connection_close_immediate(conn);
connection_mark_for_close(conn); connection_mark_for_close(conn);
return -1; return -1;
case TOR_TLS_WANTWRITE: case TOR_TLS_WANTWRITE:
debug(LD_NET,"wanted write."); log_debug(LD_NET,"wanted write.");
/* we're already writing */ /* we're already writing */
return 0; return 0;
case TOR_TLS_WANTREAD: case TOR_TLS_WANTREAD:
/* Make sure to avoid a loop if the receive buckets are empty. */ /* Make sure to avoid a loop if the receive buckets are empty. */
debug(LD_NET,"wanted read."); log_debug(LD_NET,"wanted read.");
if (!connection_is_reading(conn)) { if (!connection_is_reading(conn)) {
connection_stop_writing(conn); connection_stop_writing(conn);
conn->wants_to_write = 1; conn->wants_to_write = 1;
@ -1565,11 +1572,13 @@ connection_write_to_buf(const char *string, size_t len, connection_t *conn)
if (CONN_IS_EDGE(conn)) { if (CONN_IS_EDGE(conn)) {
/* if it failed, it means we have our package/delivery windows set /* if it failed, it means we have our package/delivery windows set
wrong compared to our max outbuf size. close the whole circuit. */ wrong compared to our max outbuf size. close the whole circuit. */
warn(LD_NET,"write_to_buf failed. Closing circuit (fd %d).", conn->s); log_warn(LD_NET,
"write_to_buf failed. Closing circuit (fd %d).", conn->s);
circuit_mark_for_close(circuit_get_by_edge_conn(conn), circuit_mark_for_close(circuit_get_by_edge_conn(conn),
END_CIRC_REASON_INTERNAL); END_CIRC_REASON_INTERNAL);
} else { } else {
warn(LD_NET,"write_to_buf failed. Closing connection (fd %d).", conn->s); log_warn(LD_NET,
"write_to_buf failed. Closing connection (fd %d).", conn->s);
connection_mark_for_close(conn); connection_mark_for_close(conn);
} }
return; return;
@ -1849,7 +1858,7 @@ client_check_address_changed(int sock)
if (getsockname(sock, (struct sockaddr*)&out_addr, &out_addr_len)<0) { if (getsockname(sock, (struct sockaddr*)&out_addr, &out_addr_len)<0) {
int e = tor_socket_errno(sock); int e = tor_socket_errno(sock);
warn(LD_NET, "getsockname() failed: %s", tor_socket_strerror(e)); log_warn(LD_NET, "getsockname() failed: %s", tor_socket_strerror(e));
return; return;
} }
@ -1908,7 +1917,7 @@ connection_process_inbuf(connection_t *conn, int package_partial)
case CONN_TYPE_CONTROL: case CONN_TYPE_CONTROL:
return connection_control_process_inbuf(conn); return connection_control_process_inbuf(conn);
default: default:
err(LD_BUG,"Bug: got unexpected conn type %d.", conn->type); log_err(LD_BUG,"Bug: got unexpected conn type %d.", conn->type);
tor_fragile_assert(); tor_fragile_assert();
return -1; return -1;
} }
@ -1942,7 +1951,7 @@ connection_finished_flushing(connection_t *conn)
case CONN_TYPE_CONTROL: case CONN_TYPE_CONTROL:
return connection_control_finished_flushing(conn); return connection_control_finished_flushing(conn);
default: default:
err(LD_BUG,"Bug: got unexpected conn type %d.", conn->type); log_err(LD_BUG,"Bug: got unexpected conn type %d.", conn->type);
tor_fragile_assert(); tor_fragile_assert();
return -1; return -1;
} }
@ -1967,7 +1976,7 @@ connection_finished_connecting(connection_t *conn)
case CONN_TYPE_DIR: case CONN_TYPE_DIR:
return connection_dir_finished_connecting(conn); return connection_dir_finished_connecting(conn);
default: default:
err(LD_BUG,"Bug: got unexpected conn type %d.", conn->type); log_err(LD_BUG,"Bug: got unexpected conn type %d.", conn->type);
tor_fragile_assert(); tor_fragile_assert();
return -1; return -1;
} }
@ -1992,7 +2001,7 @@ connection_reached_eof(connection_t *conn)
case CONN_TYPE_CONTROL: case CONN_TYPE_CONTROL:
return connection_control_reached_eof(conn); return connection_control_reached_eof(conn);
default: default:
err(LD_BUG,"Bug: got unexpected conn type %d.", conn->type); log_err(LD_BUG,"Bug: got unexpected conn type %d.", conn->type);
tor_fragile_assert(); tor_fragile_assert();
return -1; return -1;
} }

225
src/or/connection_edge.c
View File

@ -41,8 +41,9 @@ _connection_mark_unattached_ap(connection_t *conn, int endreason,
connection_edge_end_reason_socks5_response(endreason); connection_edge_end_reason_socks5_response(endreason);
if (endreason == END_STREAM_REASON_ALREADY_SOCKS_REPLIED) if (endreason == END_STREAM_REASON_ALREADY_SOCKS_REPLIED)
warn(LD_BUG,"Bug: stream (marked at %s:%d) sending two socks replies?", log_warn(LD_BUG,
file, line); "Bug: stream (marked at %s:%d) sending two socks replies?",
file, line);
if (conn->socks_request->command == SOCKS_COMMAND_CONNECT) if (conn->socks_request->command == SOCKS_COMMAND_CONNECT)
connection_ap_handshake_socks_reply(conn, NULL, 0, socksreason); connection_ap_handshake_socks_reply(conn, NULL, 0, socksreason);
@ -78,7 +79,7 @@ connection_edge_reached_eof(connection_t *conn)
/* it still has stuff to process. don't let it die yet. */ /* it still has stuff to process. don't let it die yet. */
return 0; return 0;
} }
info(LD_EDGE,"conn (fd %d) reached eof. Closing.", conn->s); log_info(LD_EDGE,"conn (fd %d) reached eof. Closing.", conn->s);
if (!conn->marked_for_close) { if (!conn->marked_for_close) {
/* only mark it if not already marked. it's possible to /* only mark it if not already marked. it's possible to
* get the 'end' right around when the client hangs up on us. */ * get the 'end' right around when the client hangs up on us. */
@ -127,11 +128,12 @@ connection_edge_process_inbuf(connection_t *conn, int package_partial)
case AP_CONN_STATE_CONNECT_WAIT: case AP_CONN_STATE_CONNECT_WAIT:
case AP_CONN_STATE_RESOLVE_WAIT: case AP_CONN_STATE_RESOLVE_WAIT:
case AP_CONN_STATE_CONTROLLER_WAIT: case AP_CONN_STATE_CONTROLLER_WAIT:
info(LD_EDGE,"data from edge while in '%s' state. Leaving it on buffer.", log_info(LD_EDGE,
conn_state_to_string(conn->type, conn->state)); "data from edge while in '%s' state. Leaving it on buffer.",
conn_state_to_string(conn->type, conn->state));
return 0; return 0;
} }
warn(LD_BUG,"Bug: Got unexpected state %d. Closing.",conn->state); log_warn(LD_BUG,"Bug: Got unexpected state %d. Closing.",conn->state);
tor_fragile_assert(); tor_fragile_assert();
connection_edge_end(conn, END_STREAM_REASON_INTERNAL, conn->cpath_layer); connection_edge_end(conn, END_STREAM_REASON_INTERNAL, conn->cpath_layer);
connection_mark_for_close(conn); connection_mark_for_close(conn);
@ -147,8 +149,8 @@ connection_edge_destroy(uint16_t circ_id, connection_t *conn)
tor_assert(CONN_IS_EDGE(conn)); tor_assert(CONN_IS_EDGE(conn));
if (!conn->marked_for_close) { if (!conn->marked_for_close) {
info(LD_EDGE, log_info(LD_EDGE,
"CircID %d: At an edge. Marking connection for close.", circ_id); "CircID %d: At an edge. Marking connection for close.", circ_id);
if (conn->type == CONN_TYPE_AP) { if (conn->type == CONN_TYPE_AP) {
connection_mark_unattached_ap(conn, END_STREAM_REASON_DESTROY); connection_mark_unattached_ap(conn, END_STREAM_REASON_DESTROY);
} else { } else {
@ -178,16 +180,16 @@ connection_edge_end(connection_t *conn, char reason, crypt_path_t *cpath_layer)
circuit_t *circ; circuit_t *circ;
if (conn->has_sent_end) { if (conn->has_sent_end) {
warn(LD_BUG,"Harmless bug: Calling connection_edge_end (reason %d) " log_warn(LD_BUG,"Harmless bug: Calling connection_edge_end (reason %d) "
"on an already ended stream?", reason); "on an already ended stream?", reason);
tor_fragile_assert(); tor_fragile_assert();
return -1; return -1;
} }
if (conn->marked_for_close) { if (conn->marked_for_close) {
warn(LD_BUG, log_warn(LD_BUG,
"Bug: called on conn that's already marked for close at %s:%d.", "Bug: called on conn that's already marked for close at %s:%d.",
conn->marked_for_close_file, conn->marked_for_close); conn->marked_for_close_file, conn->marked_for_close);
return 0; return 0;
} }
@ -202,11 +204,11 @@ connection_edge_end(connection_t *conn, char reason, crypt_path_t *cpath_layer)
circ = circuit_get_by_edge_conn(conn); circ = circuit_get_by_edge_conn(conn);
if (circ && !circ->marked_for_close) { if (circ && !circ->marked_for_close) {
debug(LD_EDGE,"Marking conn (fd %d) and sending end.",conn->s); log_debug(LD_EDGE,"Marking conn (fd %d) and sending end.",conn->s);
connection_edge_send_command(conn, circ, RELAY_COMMAND_END, connection_edge_send_command(conn, circ, RELAY_COMMAND_END,
payload, payload_len, cpath_layer); payload, payload_len, cpath_layer);
} else { } else {
debug(LD_EDGE,"Marking conn (fd %d); no circ to send end.",conn->s); log_debug(LD_EDGE,"Marking conn (fd %d); no circ to send end.",conn->s);
} }
conn->has_sent_end = 1; conn->has_sent_end = 1;
@ -256,7 +258,7 @@ connection_edge_finished_flushing(connection_t *conn)
connection_stop_writing(conn); connection_stop_writing(conn);
return 0; return 0;
default: default:
warn(LD_BUG,"BUG: called in unexpected state %d.", conn->state); log_warn(LD_BUG,"BUG: called in unexpected state %d.", conn->state);
tor_fragile_assert(); tor_fragile_assert();
return -1; return -1;
} }
@ -278,8 +280,8 @@ connection_edge_finished_connecting(connection_t *conn)
in.s_addr = htonl(conn->addr); in.s_addr = htonl(conn->addr);
tor_inet_ntoa(&in,valbuf,sizeof(valbuf)); tor_inet_ntoa(&in,valbuf,sizeof(valbuf));
info(LD_EXIT,"Exit connection to %s:%u (%s) established.", log_info(LD_EXIT,"Exit connection to %s:%u (%s) established.",
safe_str(conn->address),conn->port,safe_str(valbuf)); safe_str(conn->address),conn->port,safe_str(valbuf));
conn->state = EXIT_CONN_STATE_OPEN; conn->state = EXIT_CONN_STATE_OPEN;
connection_watch_events(conn, EV_READ); /* stop writing, continue reading */ connection_watch_events(conn, EV_READ); /* stop writing, continue reading */
@ -334,7 +336,7 @@ connection_ap_expire_beginning(void)
continue; continue;
if (conn->state == AP_CONN_STATE_CONTROLLER_WAIT) { if (conn->state == AP_CONN_STATE_CONTROLLER_WAIT) {
if (now - conn->timestamp_lastread >= 120) { if (now - conn->timestamp_lastread >= 120) {
notice(LD_APP, "Closing unattached stream."); log_notice(LD_APP, "Closing unattached stream.");
connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT); connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT);
} }
continue; continue;
@ -347,17 +349,18 @@ connection_ap_expire_beginning(void)
continue; continue;
circ = circuit_get_by_edge_conn(conn); circ = circuit_get_by_edge_conn(conn);
if (!circ) { /* it's vanished? */ if (!circ) { /* it's vanished? */
info(LD_APP,"Conn is waiting (address %s), but lost its circ.", log_info(LD_APP,"Conn is waiting (address %s), but lost its circ.",
safe_str(conn->socks_request->address)); safe_str(conn->socks_request->address));
connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT); connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT);
continue; continue;
} }
if (circ->purpose == CIRCUIT_PURPOSE_C_REND_JOINED) { if (circ->purpose == CIRCUIT_PURPOSE_C_REND_JOINED) {
if (now - conn->timestamp_lastread > 45) { if (now - conn->timestamp_lastread > 45) {
notice(LD_REND, "Rend stream is %d seconds late. Giving up on address" log_notice(LD_REND,
" '%s.onion'.", "Rend stream is %d seconds late. Giving up on address"
(int)(now - conn->timestamp_lastread), " '%s.onion'.",
safe_str(conn->socks_request->address)); (int)(now - conn->timestamp_lastread),
safe_str(conn->socks_request->address));
connection_edge_end(conn, END_STREAM_REASON_TIMEOUT, connection_edge_end(conn, END_STREAM_REASON_TIMEOUT,
conn->cpath_layer); conn->cpath_layer);
connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT); connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT);
@ -366,11 +369,12 @@ connection_ap_expire_beginning(void)
} }
tor_assert(circ->purpose == CIRCUIT_PURPOSE_C_GENERAL); tor_assert(circ->purpose == CIRCUIT_PURPOSE_C_GENERAL);
nickname = build_state_get_exit_nickname(circ->build_state); nickname = build_state_get_exit_nickname(circ->build_state);
notice(LD_APP,"We tried for %d seconds to connect to '%s' using exit '%s'." log_notice(LD_APP,
" Retrying on a new circuit.", "We tried for %d seconds to connect to '%s' using exit '%s'."
(int)(now - conn->timestamp_lastread), " Retrying on a new circuit.",
safe_str(conn->socks_request->address), (int)(now - conn->timestamp_lastread),
nickname ? nickname : "*unnamed*"); safe_str(conn->socks_request->address),
nickname ? nickname : "*unnamed*");
/* send an end down the circuit */ /* send an end down the circuit */
connection_edge_end(conn, END_STREAM_REASON_TIMEOUT, conn->cpath_layer); connection_edge_end(conn, END_STREAM_REASON_TIMEOUT, conn->cpath_layer);
/* un-mark it as ending, since we're going to reuse it */ /* un-mark it as ending, since we're going to reuse it */
@ -594,13 +598,13 @@ addressmap_rewrite(char *address, size_t maxlen)
if (!ent || !ent->new_address) if (!ent || !ent->new_address)
return; /* done, no rewrite needed */ return; /* done, no rewrite needed */
info(LD_APP, "Addressmap: rewriting '%s' to '%s'", log_info(LD_APP, "Addressmap: rewriting '%s' to '%s'",
safe_str(address), safe_str(ent->new_address)); safe_str(address), safe_str(ent->new_address));
strlcpy(address, ent->new_address, maxlen); strlcpy(address, ent->new_address, maxlen);
} }
warn(LD_CONFIG, log_warn(LD_CONFIG,
"Loop detected: we've rewritten '%s' 16 times! Using it as-is.", "Loop detected: we've rewritten '%s' 16 times! Using it as-is.",
safe_str(address)); safe_str(address));
/* it's fine to rewrite a rewrite, but don't loop forever */ /* it's fine to rewrite a rewrite, but don't loop forever */
} }
@ -642,8 +646,8 @@ addressmap_register(const char *address, char *new_address, time_t expires)
strmap_set(addressmap, address, ent); strmap_set(addressmap, address, ent);
} else if (ent->new_address) { /* we need to clean up the old mapping. */ } else if (ent->new_address) { /* we need to clean up the old mapping. */
if (expires > 1) { if (expires > 1) {
info(LD_APP,"Temporary addressmap ('%s' to '%s') not performed, " log_info(LD_APP,"Temporary addressmap ('%s' to '%s') not performed, "
"since it's already mapped to '%s'", "since it's already mapped to '%s'",
safe_str(address), safe_str(new_address), safe_str(ent->new_address)); safe_str(address), safe_str(new_address), safe_str(ent->new_address));
tor_free(new_address); tor_free(new_address);
return; return;
@ -661,8 +665,8 @@ addressmap_register(const char *address, char *new_address, time_t expires)
ent->expires = expires==2 ? 1 : expires; ent->expires = expires==2 ? 1 : expires;
ent->num_resolve_failures = 0; ent->num_resolve_failures = 0;
info(LD_CONFIG, "Addressmap: (re)mapped '%s' to '%s'", log_info(LD_CONFIG, "Addressmap: (re)mapped '%s' to '%s'",
safe_str(address), safe_str(ent->new_address)); safe_str(address), safe_str(ent->new_address));
control_event_address_mapped(address, ent->new_address, expires); control_event_address_mapped(address, ent->new_address, expires);
} }
@ -680,8 +684,8 @@ client_dns_incr_failures(const char *address)
strmap_set(addressmap,address,ent); strmap_set(addressmap,address,ent);
} }
++ent->num_resolve_failures; ++ent->num_resolve_failures;
info(LD_APP, "Address %s now has %d resolve failures.", log_info(LD_APP, "Address %s now has %d resolve failures.",
safe_str(address), ent->num_resolve_failures); safe_str(address), ent->num_resolve_failures);
return ent->num_resolve_failures; return ent->num_resolve_failures;
} }
@ -807,7 +811,7 @@ addressmap_get_virtual_address(int type)
} }
return tor_strdup(buf); return tor_strdup(buf);
} else { } else {
warn(LD_BUG, "Called with unsupported address type (%d)", type); log_warn(LD_BUG, "Called with unsupported address type (%d)", type);
return NULL; return NULL;
} }
} }
@ -846,10 +850,11 @@ addressmap_register_virtual_address(int type, char *new_address)
tor_free(new_address); tor_free(new_address);
return tor_strdup(*addrp); return tor_strdup(*addrp);
} else } else
warn(LD_BUG, "Internal confusion: I thought that '%s' was mapped to " log_warn(LD_BUG,
"by '%s', but '%s' really maps to '%s'. This is a harmless bug.", "Internal confusion: I thought that '%s' was mapped to by "
safe_str(new_address), safe_str(*addrp), safe_str(*addrp), "'%s', but '%s' really maps to '%s'. This is a harmless bug.",
ent?safe_str(ent->new_address):"(nothing)"); safe_str(new_address), safe_str(*addrp), safe_str(*addrp),
ent?safe_str(ent->new_address):"(nothing)");
} }
tor_free(*addrp); tor_free(*addrp);
@ -940,8 +945,8 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn)
hostname_type_t addresstype; hostname_type_t addresstype;
tor_strlower(socks->address); /* normalize it */ tor_strlower(socks->address); /* normalize it */
debug(LD_APP,"Client asked for %s:%d", safe_str(socks->address), log_debug(LD_APP,"Client asked for %s:%d", safe_str(socks->address),
socks->port); socks->port);
/* For address map controls, remap the address */ /* For address map controls, remap the address */
addressmap_rewrite(socks->address, sizeof(socks->address)); addressmap_rewrite(socks->address, sizeof(socks->address));
@ -952,8 +957,8 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn)
* the address through Tor; that's likely to fail, and may leak * the address through Tor; that's likely to fail, and may leak
* information. * information.
*/ */
warn(LD_APP,"Missing mapping for virtual address '%s'. Refusing.", log_warn(LD_APP,"Missing mapping for virtual address '%s'. Refusing.",
socks->address); /* don't safe_str() this yet. */ socks->address); /* don't safe_str() this yet. */
connection_mark_unattached_ap(conn, END_STREAM_REASON_INTERNAL); connection_mark_unattached_ap(conn, END_STREAM_REASON_INTERNAL);
return -1; return -1;
} }
@ -964,7 +969,7 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn)
addresstype = parse_extended_hostname(socks->address); addresstype = parse_extended_hostname(socks->address);
if (addresstype == BAD_HOSTNAME) { if (addresstype == BAD_HOSTNAME) {
warn(LD_APP, "Invalid hostname %s; rejecting", socks->address); log_warn(LD_APP, "Invalid hostname %s; rejecting", socks->address);
connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
return -1; return -1;
} }
@ -978,8 +983,8 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn)
conn->chosen_exit_name = tor_strdup(s+1); conn->chosen_exit_name = tor_strdup(s+1);
*s = 0; *s = 0;
} else { } else {
warn(LD_APP,"Malformed exit address '%s.exit'. Refusing.", log_warn(LD_APP,"Malformed exit address '%s.exit'. Refusing.",
safe_str(socks->address)); safe_str(socks->address));
connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
return -1; return -1;
} }
@ -994,9 +999,9 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn)
in.s_addr = htonl(r->addr); in.s_addr = htonl(r->addr);
strlcpy(socks->address, inet_ntoa(in), sizeof(socks->address)); strlcpy(socks->address, inet_ntoa(in), sizeof(socks->address));
} else { } else {
warn(LD_APP, log_warn(LD_APP,
"Unrecognized server in exit address '%s.exit'. Refusing.", "Unrecognized server in exit address '%s.exit'. Refusing.",
safe_str(socks->address)); safe_str(socks->address));
connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
return -1; return -1;
} }
@ -1007,8 +1012,9 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn)
/* not a hidden-service request (i.e. normal or .exit) */ /* not a hidden-service request (i.e. normal or .exit) */
if (address_is_invalid_destination(socks->address)) { if (address_is_invalid_destination(socks->address)) {
warn(LD_APP,"Destination '%s' seems to be an invalid hostname. Failing.", log_warn(LD_APP,
safe_str(socks->address)); "Destination '%s' seems to be an invalid hostname. Failing.",
safe_str(socks->address));
connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
return -1; return -1;
} }
@ -1018,7 +1024,7 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn)
struct in_addr in; struct in_addr in;
/* Reply to resolves immediately if we can. */ /* Reply to resolves immediately if we can. */
if (strlen(socks->address) > RELAY_PAYLOAD_SIZE) { if (strlen(socks->address) > RELAY_PAYLOAD_SIZE) {
warn(LD_APP,"Address to be resolved is too large. Failing."); log_warn(LD_APP,"Address to be resolved is too large. Failing.");
connection_ap_handshake_socks_resolved(conn,RESOLVED_TYPE_ERROR, connection_ap_handshake_socks_resolved(conn,RESOLVED_TYPE_ERROR,
0,NULL,-1); 0,NULL,-1);
connection_mark_unattached_ap(conn, connection_mark_unattached_ap(conn,
@ -1036,7 +1042,7 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn)
rep_hist_note_used_resolve(time(NULL)); /* help predict this next time */ rep_hist_note_used_resolve(time(NULL)); /* help predict this next time */
} else { /* socks->command == SOCKS_COMMAND_CONNECT */ } else { /* socks->command == SOCKS_COMMAND_CONNECT */
if (socks->port == 0) { if (socks->port == 0) {
notice(LD_APP,"Application asked to connect to port 0. Refusing."); log_notice(LD_APP,"Application asked to connect to port 0. Refusing.");
connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
return -1; return -1;
} }
@ -1046,8 +1052,9 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn)
routerinfo_t *r = routerinfo_t *r =
router_find_exact_exit_enclave(socks->address, socks->port); router_find_exact_exit_enclave(socks->address, socks->port);
if (r) { if (r) {
info(LD_APP,"Redirecting address %s to exit at enclave router %s", log_info(LD_APP,
safe_str(socks->address), r->nickname); "Redirecting address %s to exit at enclave router %s",
safe_str(socks->address), r->nickname);
/* use the hex digest, not nickname, in case there are two /* use the hex digest, not nickname, in case there are two
routers with this nickname */ routers with this nickname */
conn->chosen_exit_name = conn->chosen_exit_name =
@ -1072,7 +1079,8 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn)
if (socks->command == SOCKS_COMMAND_RESOLVE) { if (socks->command == SOCKS_COMMAND_RESOLVE) {
/* if it's a resolve request, fail it right now, rather than /* if it's a resolve request, fail it right now, rather than
* building all the circuits and then realizing it won't work. */ * building all the circuits and then realizing it won't work. */
warn(LD_APP,"Resolve requests to hidden services not allowed. Failing."); log_warn(LD_APP,
"Resolve requests to hidden services not allowed. Failing.");
connection_ap_handshake_socks_resolved(conn,RESOLVED_TYPE_ERROR, connection_ap_handshake_socks_resolved(conn,RESOLVED_TYPE_ERROR,
0,NULL,-1); 0,NULL,-1);
connection_mark_unattached_ap(conn, connection_mark_unattached_ap(conn,
@ -1081,34 +1089,34 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn)
} }
strlcpy(conn->rend_query, socks->address, sizeof(conn->rend_query)); strlcpy(conn->rend_query, socks->address, sizeof(conn->rend_query));
info(LD_REND,"Got a hidden service request for ID '%s'", log_info(LD_REND,"Got a hidden service request for ID '%s'",
safe_str(conn->rend_query)); safe_str(conn->rend_query));
/* see if we already have it cached */ /* see if we already have it cached */
r = rend_cache_lookup_entry(conn->rend_query, -1, &entry); r = rend_cache_lookup_entry(conn->rend_query, -1, &entry);
if (r<0) { if (r<0) {
warn(LD_BUG,"Bug: Invalid service name '%s'", log_warn(LD_BUG,"Bug: Invalid service name '%s'",
safe_str(conn->rend_query)); safe_str(conn->rend_query));
connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
return -1; return -1;
} }
if (r==0) { if (r==0) {
conn->state = AP_CONN_STATE_RENDDESC_WAIT; conn->state = AP_CONN_STATE_RENDDESC_WAIT;
info(LD_REND, "Unknown descriptor %s. Fetching.", log_info(LD_REND, "Unknown descriptor %s. Fetching.",
safe_str(conn->rend_query)); safe_str(conn->rend_query));
rend_client_refetch_renddesc(conn->rend_query); rend_client_refetch_renddesc(conn->rend_query);
} else { /* r > 0 */ } else { /* r > 0 */
#define NUM_SECONDS_BEFORE_REFETCH (60*15) #define NUM_SECONDS_BEFORE_REFETCH (60*15)
if (time(NULL) - entry->received < NUM_SECONDS_BEFORE_REFETCH) { if (time(NULL) - entry->received < NUM_SECONDS_BEFORE_REFETCH) {
conn->state = AP_CONN_STATE_CIRCUIT_WAIT; conn->state = AP_CONN_STATE_CIRCUIT_WAIT;
info(LD_REND, "Descriptor is here and fresh enough. Great."); log_info(LD_REND, "Descriptor is here and fresh enough. Great.");
if (connection_ap_handshake_attach_circuit(conn) < 0) { if (connection_ap_handshake_attach_circuit(conn) < 0) {
connection_mark_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH); connection_mark_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
return -1; return -1;
} }
} else { } else {
conn->state = AP_CONN_STATE_RENDDESC_WAIT; conn->state = AP_CONN_STATE_RENDDESC_WAIT;
info(LD_REND, "Stale descriptor %s. Refetching.", log_info(LD_REND, "Stale descriptor %s. Refetching.",
safe_str(conn->rend_query)); safe_str(conn->rend_query));
rend_client_refetch_renddesc(conn->rend_query); rend_client_refetch_renddesc(conn->rend_query);
} }
} }
@ -1140,7 +1148,7 @@ connection_ap_handshake_process_socks(connection_t *conn)
tor_assert(conn->socks_request); tor_assert(conn->socks_request);
socks = conn->socks_request; socks = conn->socks_request;
debug(LD_APP,"entered."); log_debug(LD_APP,"entered.");
sockshere = fetch_from_buf_socks(conn->inbuf, socks, options->TestSocks); sockshere = fetch_from_buf_socks(conn->inbuf, socks, options->TestSocks);
if (sockshere == 0) { if (sockshere == 0) {
@ -1149,16 +1157,16 @@ connection_ap_handshake_process_socks(connection_t *conn)
/* zero it out so we can do another round of negotiation */ /* zero it out so we can do another round of negotiation */
socks->replylen = 0; socks->replylen = 0;
} else { } else {
debug(LD_APP,"socks handshake not all here yet."); log_debug(LD_APP,"socks handshake not all here yet.");
} }
return 0; return 0;
} else if (sockshere == -1) { } else if (sockshere == -1) {
if (socks->replylen) { /* we should send reply back */ if (socks->replylen) { /* we should send reply back */
debug(LD_APP,"reply is already set for us. Using it."); log_debug(LD_APP,"reply is already set for us. Using it.");
connection_ap_handshake_socks_reply(conn, socks->reply, socks->replylen, connection_ap_handshake_socks_reply(conn, socks->reply, socks->replylen,
SOCKS5_GENERAL_ERROR); SOCKS5_GENERAL_ERROR);
} else { } else {
warn(LD_APP,"Fetching socks handshake failed. Closing."); log_warn(LD_APP,"Fetching socks handshake failed. Closing.");
connection_ap_handshake_socks_reply(conn, NULL, 0, SOCKS5_GENERAL_ERROR); connection_ap_handshake_socks_reply(conn, NULL, 0, SOCKS5_GENERAL_ERROR);
} }
connection_mark_unattached_ap(conn, connection_mark_unattached_ap(conn,
@ -1192,7 +1200,7 @@ again:
test_stream_id = circ->next_stream_id++; test_stream_id = circ->next_stream_id++;
if (++attempts > 1<<16) { if (++attempts > 1<<16) {
/* Make sure we don't loop forever if all stream_id's are used. */ /* Make sure we don't loop forever if all stream_id's are used. */
warn(LD_APP,"No unused stream IDs. Failing."); log_warn(LD_APP,"No unused stream IDs. Failing.");
return 0; return 0;
} }
if (test_stream_id == 0) if (test_stream_id == 0)
@ -1231,7 +1239,8 @@ connection_ap_handshake_send_begin(connection_t *ap_conn, circuit_t *circ)
ap_conn->socks_request->port); ap_conn->socks_request->port);
payload_len = strlen(payload)+1; payload_len = strlen(payload)+1;
debug(LD_APP,"Sending relay cell to begin stream %d.",ap_conn->stream_id); log_debug(LD_APP,
"Sending relay cell to begin stream %d.", ap_conn->stream_id);
if (connection_edge_send_command(ap_conn, circ, RELAY_COMMAND_BEGIN, if (connection_edge_send_command(ap_conn, circ, RELAY_COMMAND_BEGIN,
payload, payload_len, payload, payload_len,
@ -1241,8 +1250,8 @@ connection_ap_handshake_send_begin(connection_t *ap_conn, circuit_t *circ)
ap_conn->package_window = STREAMWINDOW_START; ap_conn->package_window = STREAMWINDOW_START;
ap_conn->deliver_window = STREAMWINDOW_START; ap_conn->deliver_window = STREAMWINDOW_START;
ap_conn->state = AP_CONN_STATE_CONNECT_WAIT; ap_conn->state = AP_CONN_STATE_CONNECT_WAIT;
info(LD_APP,"Address/port sent, ap socket %d, n_circ_id %d", log_info(LD_APP,"Address/port sent, ap socket %d, n_circ_id %d",
ap_conn->s, circ->n_circ_id); ap_conn->s, circ->n_circ_id);
control_event_stream_status(ap_conn, STREAM_EVENT_SENT_CONNECT); control_event_stream_status(ap_conn, STREAM_EVENT_SENT_CONNECT);
return 0; return 0;
} }
@ -1275,15 +1284,16 @@ connection_ap_handshake_send_resolve(connection_t *ap_conn, circuit_t *circ)
payload_len = strlen(string_addr)+1; payload_len = strlen(string_addr)+1;
tor_assert(payload_len <= RELAY_PAYLOAD_SIZE); tor_assert(payload_len <= RELAY_PAYLOAD_SIZE);
debug(LD_APP,"Sending relay cell to begin stream %d.",ap_conn->stream_id); log_debug(LD_APP,
"Sending relay cell to begin stream %d.", ap_conn->stream_id);
if (connection_edge_send_command(ap_conn, circ, RELAY_COMMAND_RESOLVE, if (connection_edge_send_command(ap_conn, circ, RELAY_COMMAND_RESOLVE,
string_addr, payload_len, ap_conn->cpath_layer) < 0) string_addr, payload_len, ap_conn->cpath_layer) < 0)
return -1; /* circuit is closed, don't continue */ return -1; /* circuit is closed, don't continue */
ap_conn->state = AP_CONN_STATE_RESOLVE_WAIT; ap_conn->state = AP_CONN_STATE_RESOLVE_WAIT;
info(LD_APP,"Address sent for resolve, ap socket %d, n_circ_id %d", log_info(LD_APP,"Address sent for resolve, ap socket %d, n_circ_id %d",
ap_conn->s, circ->n_circ_id); ap_conn->s, circ->n_circ_id);
control_event_stream_status(ap_conn, STREAM_EVENT_SENT_RESOLVE); control_event_stream_status(ap_conn, STREAM_EVENT_SENT_RESOLVE);
return 0; return 0;
} }
@ -1301,11 +1311,12 @@ connection_ap_make_bridge(char *address, uint16_t port)
connection_t *conn; connection_t *conn;
int err; int err;
info(LD_APP,"Making AP bridge to %s:%d ...",safe_str(address),port); log_info(LD_APP,"Making AP bridge to %s:%d ...",safe_str(address),port);
if ((err = tor_socketpair(AF_UNIX, SOCK_STREAM, 0, fd)) < 0) { if ((err = tor_socketpair(AF_UNIX, SOCK_STREAM, 0, fd)) < 0) {
warn(LD_NET,"Couldn't construct socketpair (%s). Network down? Delaying.", log_warn(LD_NET,
tor_socket_strerror(-err)); "Couldn't construct socketpair (%s). Network down? Delaying.",
tor_socket_strerror(-err));
return -1; return -1;
} }
@ -1345,7 +1356,7 @@ connection_ap_make_bridge(char *address, uint16_t port)
return -1; return -1;
} }
info(LD_APP,"... AP bridge created and connected."); log_info(LD_APP,"... AP bridge created and connected.");
return fd[1]; return fd[1];
} }
@ -1432,8 +1443,8 @@ connection_ap_handshake_socks_reply(connection_t *conn, char *reply,
status==SOCKS5_SUCCEEDED ? STREAM_EVENT_SUCCEEDED : STREAM_EVENT_FAILED); status==SOCKS5_SUCCEEDED ? STREAM_EVENT_SUCCEEDED : STREAM_EVENT_FAILED);
if (conn->socks_request->has_finished) { if (conn->socks_request->has_finished) {
warn(LD_BUG, "Harmless bug: duplicate calls to " log_warn(LD_BUG, "Harmless bug: duplicate calls to "
"connection_ap_handshake_socks_reply."); "connection_ap_handshake_socks_reply.");
return; return;
} }
if (replylen) { /* we already have a reply in mind */ if (replylen) { /* we already have a reply in mind */
@ -1495,21 +1506,21 @@ connection_exit_begin_conn(cell_t *cell, circuit_t *circ)
*/ */
if (!memchr(cell->payload+RELAY_HEADER_SIZE, 0, rh.length)) { if (!memchr(cell->payload+RELAY_HEADER_SIZE, 0, rh.length)) {
warn(LD_PROTOCOL,"relay begin cell has no \\0. Dropping."); log_warn(LD_PROTOCOL,"relay begin cell has no \\0. Dropping.");
return 0; return 0;
} }
if (parse_addr_port(cell->payload+RELAY_HEADER_SIZE,&address,NULL,&port)<0) { if (parse_addr_port(cell->payload+RELAY_HEADER_SIZE,&address,NULL,&port)<0) {
warn(LD_PROTOCOL,"Unable to parse addr:port in relay begin cell. " log_warn(LD_PROTOCOL,"Unable to parse addr:port in relay begin cell. "
"Dropping."); "Dropping.");
return 0; return 0;
} }
if (port==0) { if (port==0) {
warn(LD_PROTOCOL,"Missing port in relay begin cell. Dropping."); log_warn(LD_PROTOCOL,"Missing port in relay begin cell. Dropping.");
tor_free(address); tor_free(address);
return 0; return 0;
} }
debug(LD_EXIT,"Creating new exit connection."); log_debug(LD_EXIT,"Creating new exit connection.");
n_stream = connection_new(CONN_TYPE_EXIT); n_stream = connection_new(CONN_TYPE_EXIT);
n_stream->purpose = EXIT_PURPOSE_CONNECT; n_stream->purpose = EXIT_PURPOSE_CONNECT;
@ -1520,7 +1531,7 @@ connection_exit_begin_conn(cell_t *cell, circuit_t *circ)
n_stream->deliver_window = STREAMWINDOW_START; n_stream->deliver_window = STREAMWINDOW_START;
if (circ->purpose == CIRCUIT_PURPOSE_S_REND_JOINED) { if (circ->purpose == CIRCUIT_PURPOSE_S_REND_JOINED) {
debug(LD_REND,"begin is for rendezvous. configuring stream."); log_debug(LD_REND,"begin is for rendezvous. configuring stream.");
n_stream->address = tor_strdup("(rendezvous)"); n_stream->address = tor_strdup("(rendezvous)");
n_stream->state = EXIT_CONN_STATE_CONNECTING; n_stream->state = EXIT_CONN_STATE_CONNECTING;
strlcpy(n_stream->rend_query, circ->rend_query, strlcpy(n_stream->rend_query, circ->rend_query,
@ -1528,7 +1539,8 @@ connection_exit_begin_conn(cell_t *cell, circuit_t *circ)
tor_assert(connection_edge_is_rendezvous_stream(n_stream)); tor_assert(connection_edge_is_rendezvous_stream(n_stream));
assert_circuit_ok(circ); assert_circuit_ok(circ);
if (rend_service_set_connection_addr_port(n_stream, circ) < 0) { if (rend_service_set_connection_addr_port(n_stream, circ) < 0) {
info(LD_REND,"Didn't find rendezvous service (port %d)",n_stream->port); log_info(LD_REND,"Didn't find rendezvous service (port %d)",
n_stream->port);
connection_edge_end(n_stream, END_STREAM_REASON_EXITPOLICY, connection_edge_end(n_stream, END_STREAM_REASON_EXITPOLICY,
n_stream->cpath_layer); n_stream->cpath_layer);
connection_free(n_stream); connection_free(n_stream);
@ -1538,7 +1550,7 @@ connection_exit_begin_conn(cell_t *cell, circuit_t *circ)
return 0; return 0;
} }
assert_circuit_ok(circ); assert_circuit_ok(circ);
debug(LD_REND,"Finished assigning addr/port"); log_debug(LD_REND,"Finished assigning addr/port");
n_stream->cpath_layer = circ->cpath->prev; /* link it */ n_stream->cpath_layer = circ->cpath->prev; /* link it */
/* add it into the linked list of n_streams on this circuit */ /* add it into the linked list of n_streams on this circuit */
@ -1651,8 +1663,8 @@ connection_exit_connect(connection_t *conn)
if (!connection_edge_is_rendezvous_stream(conn) && if (!connection_edge_is_rendezvous_stream(conn) &&
router_compare_to_my_exit_policy(conn)) { router_compare_to_my_exit_policy(conn)) {
info(LD_EXIT,"%s:%d failed exit policy. Closing.", log_info(LD_EXIT,"%s:%d failed exit policy. Closing.",
safe_str(conn->address), conn->port); safe_str(conn->address), conn->port);
connection_edge_end(conn, END_STREAM_REASON_EXITPOLICY, conn->cpath_layer); connection_edge_end(conn, END_STREAM_REASON_EXITPOLICY, conn->cpath_layer);
circuit_detach_stream(circuit_get_by_edge_conn(conn), conn); circuit_detach_stream(circuit_get_by_edge_conn(conn), conn);
connection_free(conn); connection_free(conn);
@ -1673,15 +1685,16 @@ connection_exit_connect(connection_t *conn)
port = r->port_dest; port = r->port_dest;
in.s_addr = htonl(addr); in.s_addr = htonl(addr);
tor_inet_ntoa(&in, tmpbuf, sizeof(tmpbuf)); tor_inet_ntoa(&in, tmpbuf, sizeof(tmpbuf));
debug(LD_EXIT, "Redirecting connection from %s:%d to %s:%d", log_debug(LD_EXIT, "Redirecting connection from %s:%d to %s:%d",
safe_str(conn->address), conn->port, safe_str(tmpbuf), port); safe_str(conn->address), conn->port,
safe_str(tmpbuf), port);
} }
break; break;
} }
}); });
} }
debug(LD_EXIT,"about to try connecting"); log_debug(LD_EXIT,"about to try connecting");
switch (connection_connect(conn, conn->address, addr, port)) { switch (connection_connect(conn, conn->address, addr, port)) {
case -1: case -1:
connection_edge_end_errno(conn, conn->cpath_layer); connection_edge_end_errno(conn, conn->cpath_layer);
@ -1701,7 +1714,7 @@ connection_exit_connect(connection_t *conn)
conn->state = EXIT_CONN_STATE_OPEN; conn->state = EXIT_CONN_STATE_OPEN;
if (connection_wants_to_flush(conn)) { if (connection_wants_to_flush(conn)) {
/* in case there are any queued data cells */ /* in case there are any queued data cells */
warn(LD_BUG,"Bug: newly connected conn had data waiting!"); log_warn(LD_BUG,"Bug: newly connected conn had data waiting!");
// connection_start_writing(conn); // connection_start_writing(conn);
} }
connection_watch_events(conn, EV_READ); connection_watch_events(conn, EV_READ);
@ -1761,8 +1774,8 @@ connection_ap_can_use_exit(connection_t *conn, routerinfo_t *exit)
if (conn->chosen_exit_name) { if (conn->chosen_exit_name) {
if (router_get_by_nickname(conn->chosen_exit_name, 1) != exit) { if (router_get_by_nickname(conn->chosen_exit_name, 1) != exit) {
/* doesn't match */ /* doesn't match */
debug(LD_APP,"Requested node '%s', considering node '%s'. No.", log_debug(LD_APP,"Requested node '%s', considering node '%s'. No.",
conn->chosen_exit_name, exit->nickname); conn->chosen_exit_name, exit->nickname);
return 0; return 0;
} }
} }
@ -1827,7 +1840,7 @@ socks_policy_permits_address(uint32_t addr)
return 0; return 0;
else if (a==ADDR_POLICY_ACCEPTED) else if (a==ADDR_POLICY_ACCEPTED)
return 1; return 1;
warn(LD_BUG, "Bug: Got unexpected 'maybe' answer from socks policy"); log_warn(LD_BUG, "Bug: Got unexpected 'maybe' answer from socks policy");
return 0; return 0;
} }

79
src/or/connection_or.c
View File

@ -137,7 +137,7 @@ cell_unpack(cell_t *dest, const char *src)
int int
connection_or_reached_eof(connection_t *conn) connection_or_reached_eof(connection_t *conn)
{ {
info(LD_OR,"OR connection reached EOF. Closing."); log_info(LD_OR,"OR connection reached EOF. Closing.");
connection_mark_for_close(conn); connection_mark_for_close(conn);
return 0; return 0;
} }
@ -160,28 +160,29 @@ connection_or_read_proxy_response(connection_t *conn)
&headers, MAX_HEADERS_SIZE, &headers, MAX_HEADERS_SIZE,
NULL, NULL, 10000, 0)) { NULL, NULL, 10000, 0)) {
case -1: /* overflow */ case -1: /* overflow */
warn(LD_PROTOCOL,"Your https proxy sent back an oversized response. " log_warn(LD_PROTOCOL,
"Closing."); "Your https proxy sent back an oversized response. Closing.");
return -1; return -1;
case 0: case 0:
info(LD_OR,"https proxy response not all here yet. Waiting."); log_info(LD_OR,"https proxy response not all here yet. Waiting.");
return 0; return 0;
/* case 1, fall through */ /* case 1, fall through */
} }
if (parse_http_response(headers, &status_code, &date_header, if (parse_http_response(headers, &status_code, &date_header,
&compression, &reason) < 0) { &compression, &reason) < 0) {
warn(LD_OR,"Unparseable headers from proxy (connecting to '%s'). Closing.", log_warn(LD_OR,
conn->address); "Unparseable headers from proxy (connecting to '%s'). Closing.",
conn->address);
tor_free(headers); tor_free(headers);
return -1; return -1;
} }
if (!reason) reason = tor_strdup("[no reason given]"); if (!reason) reason = tor_strdup("[no reason given]");
if (status_code == 200) { if (status_code == 200) {
info(LD_OR, log_info(LD_OR,
"HTTPS connect to '%s' successful! (200 \"%s\") Starting TLS.", "HTTPS connect to '%s' successful! (200 \"%s\") Starting TLS.",
conn->address, reason); conn->address, reason);
tor_free(reason); tor_free(reason);
if (connection_tls_start_handshake(conn, 0) < 0) { if (connection_tls_start_handshake(conn, 0) < 0) {
/* TLS handshaking error of some kind. */ /* TLS handshaking error of some kind. */
@ -192,10 +193,10 @@ connection_or_read_proxy_response(connection_t *conn)
return 0; return 0;
} }
/* else, bad news on the status code */ /* else, bad news on the status code */
warn(LD_OR, log_warn(LD_OR,
"The https proxy sent back an unexpected status code %d (\"%s\"). " "The https proxy sent back an unexpected status code %d (\"%s\"). "
"Closing.", "Closing.",
status_code, reason); status_code, reason);
tor_free(reason); tor_free(reason);
connection_mark_for_close(conn); connection_mark_for_close(conn);
return -1; return -1;
@ -240,7 +241,7 @@ connection_or_finished_flushing(connection_t *conn)
switch (conn->state) { switch (conn->state) {
case OR_CONN_STATE_PROXY_FLUSHING: case OR_CONN_STATE_PROXY_FLUSHING:
debug(LD_OR,"finished sending CONNECT to proxy."); log_debug(LD_OR,"finished sending CONNECT to proxy.");
conn->state = OR_CONN_STATE_PROXY_READING; conn->state = OR_CONN_STATE_PROXY_READING;
connection_stop_writing(conn); connection_stop_writing(conn);
break; break;
@ -248,7 +249,7 @@ connection_or_finished_flushing(connection_t *conn)
connection_stop_writing(conn); connection_stop_writing(conn);
break; break;
default: default:
err(LD_BUG,"BUG: called in unexpected state %d.", conn->state); log_err(LD_BUG,"BUG: called in unexpected state %d.", conn->state);
tor_fragile_assert(); tor_fragile_assert();
return -1; return -1;
} }
@ -264,8 +265,8 @@ connection_or_finished_connecting(connection_t *conn)
tor_assert(conn->type == CONN_TYPE_OR); tor_assert(conn->type == CONN_TYPE_OR);
tor_assert(conn->state == OR_CONN_STATE_CONNECTING); tor_assert(conn->state == OR_CONN_STATE_CONNECTING);
debug(LD_OR,"OR connect() to router at %s:%u finished.", log_debug(LD_OR,"OR connect() to router at %s:%u finished.",
conn->address,conn->port); conn->address,conn->port);
if (get_options()->HttpsProxy) { if (get_options()->HttpsProxy) {
char buf[1024]; char buf[1024];
@ -280,7 +281,7 @@ connection_or_finished_connecting(connection_t *conn)
if (authenticator) { if (authenticator) {
base64_authenticator = alloc_http_authenticator(authenticator); base64_authenticator = alloc_http_authenticator(authenticator);
if (!base64_authenticator) if (!base64_authenticator)
warn(LD_OR, "Encoding https authenticator failed"); log_warn(LD_OR, "Encoding https authenticator failed");
} }
if (base64_authenticator) { if (base64_authenticator) {
tor_snprintf(buf, sizeof(buf), "CONNECT %s:%d HTTP/1.1\r\n" tor_snprintf(buf, sizeof(buf), "CONNECT %s:%d HTTP/1.1\r\n"
@ -428,7 +429,7 @@ connection_or_connect(uint32_t addr, uint16_t port, const char *id_digest)
if (server_mode(options) && (me=router_get_my_routerinfo()) && if (server_mode(options) && (me=router_get_my_routerinfo()) &&
router_digest_is_me(id_digest)) { router_digest_is_me(id_digest)) {
info(LD_PROTOCOL,"Client asked me to connect to myself. Refusing."); log_info(LD_PROTOCOL,"Client asked me to connect to myself. Refusing.");
return NULL; return NULL;
} }
@ -486,11 +487,11 @@ connection_tls_start_handshake(connection_t *conn, int receiving)
conn->state = OR_CONN_STATE_HANDSHAKING; conn->state = OR_CONN_STATE_HANDSHAKING;
conn->tls = tor_tls_new(conn->s, receiving, 0); conn->tls = tor_tls_new(conn->s, receiving, 0);
if (!conn->tls) { if (!conn->tls) {
warn(LD_BUG,"tor_tls_new failed. Closing."); log_warn(LD_BUG,"tor_tls_new failed. Closing.");
return -1; return -1;
} }
connection_start_reading(conn); connection_start_reading(conn);
debug(LD_OR,"starting TLS handshake on fd %d", conn->s); log_debug(LD_OR,"starting TLS handshake on fd %d", conn->s);
if (connection_tls_continue_handshake(conn) < 0) { if (connection_tls_continue_handshake(conn) < 0) {
return -1; return -1;
} }
@ -509,16 +510,16 @@ connection_tls_continue_handshake(connection_t *conn)
switch (tor_tls_handshake(conn->tls)) { switch (tor_tls_handshake(conn->tls)) {
case TOR_TLS_ERROR: case TOR_TLS_ERROR:
case TOR_TLS_CLOSE: case TOR_TLS_CLOSE:
info(LD_OR,"tls error. breaking connection."); log_info(LD_OR,"tls error. breaking connection.");
return -1; return -1;
case TOR_TLS_DONE: case TOR_TLS_DONE:
return connection_tls_finish_handshake(conn); return connection_tls_finish_handshake(conn);
case TOR_TLS_WANTWRITE: case TOR_TLS_WANTWRITE:
connection_start_writing(conn); connection_start_writing(conn);
debug(LD_OR,"wanted write"); log_debug(LD_OR,"wanted write");
return 0; return 0;
case TOR_TLS_WANTREAD: /* handshaking conns are *always* reading */ case TOR_TLS_WANTREAD: /* handshaking conns are *always* reading */
debug(LD_OR,"wanted read"); log_debug(LD_OR,"wanted read");
return 0; return 0;
} }
return 0; return 0;
@ -570,7 +571,7 @@ connection_or_check_valid_handshake(connection_t *conn, char *digest_rcvd)
check_no_tls_errors(); check_no_tls_errors();
if (! tor_tls_peer_has_cert(conn->tls)) { if (! tor_tls_peer_has_cert(conn->tls)) {
info(LD_PROTOCOL,"Peer didn't send a cert! Closing."); log_info(LD_PROTOCOL,"Peer didn't send a cert! Closing.");
return -1; return -1;
} }
check_no_tls_errors(); check_no_tls_errors();
@ -581,8 +582,8 @@ connection_or_check_valid_handshake(connection_t *conn, char *digest_rcvd)
return -1; return -1;
} }
check_no_tls_errors(); check_no_tls_errors();
debug(LD_OR, "Other side (%s:%d) claims to be router '%s'", log_debug(LD_OR, "Other side (%s:%d) claims to be router '%s'",
conn->address, conn->port, nickname); conn->address, conn->port, nickname);
if (tor_tls_verify(severity, conn->tls, &identity_rcvd) < 0) { if (tor_tls_verify(severity, conn->tls, &identity_rcvd) < 0) {
log_fn(severity,LD_OR,"Other side, which claims to be router '%s' (%s:%d)," log_fn(severity,LD_OR,"Other side, which claims to be router '%s' (%s:%d),"
@ -591,7 +592,7 @@ connection_or_check_valid_handshake(connection_t *conn, char *digest_rcvd)
return -1; return -1;
} }
check_no_tls_errors(); check_no_tls_errors();
debug(LD_OR,"The router's cert is valid."); log_debug(LD_OR,"The router's cert is valid.");
crypto_pk_get_digest(identity_rcvd, digest_rcvd); crypto_pk_get_digest(identity_rcvd, digest_rcvd);
if (crypto_pk_cmp_keys(get_identity_key(), identity_rcvd)<0) { if (crypto_pk_cmp_keys(get_identity_key(), identity_rcvd)<0) {
@ -661,7 +662,7 @@ connection_tls_finish_handshake(connection_t *conn)
char digest_rcvd[DIGEST_LEN]; char digest_rcvd[DIGEST_LEN];
int started_here = connection_or_nonopen_was_started_here(conn); int started_here = connection_or_nonopen_was_started_here(conn);
debug(LD_OR,"tls handshake done. verifying."); log_debug(LD_OR,"tls handshake done. verifying.");
if (connection_or_check_valid_handshake(conn, digest_rcvd) < 0) if (connection_or_check_valid_handshake(conn, digest_rcvd) < 0)
return -1; return -1;
@ -669,8 +670,9 @@ connection_tls_finish_handshake(connection_t *conn)
#if 0 #if 0
connection_t *c; connection_t *c;
if ((c=connection_or_get_by_identity_digest(digest_rcvd))) { if ((c=connection_or_get_by_identity_digest(digest_rcvd))) {
debug(LD_OR,"Router '%s' is already connected on fd %d. Dropping fd %d.", log_debug(LD_OR,
c->nickname, c->s, conn->s); "Router '%s' is already connected on fd %d. Dropping fd %d.",
c->nickname, c->s, conn->s);
return -1; return -1;
} }
#endif #endif
@ -730,9 +732,9 @@ connection_or_write_cell_to_buf(const cell_t *cell, connection_t *conn)
if (connection_handle_write(conn) < 0) { if (connection_handle_write(conn) < 0) {
if (!conn->marked_for_close) { if (!conn->marked_for_close) {
/* this connection is broken. remove it. */ /* this connection is broken. remove it. */
warn(LD_BUG, log_warn(LD_BUG,
"Bug: unhandled error on write for OR conn (fd %d); removing", "Bug: unhandled error on write for OR conn (fd %d); removing",
conn->s); conn->s);
tor_fragile_assert(); tor_fragile_assert();
conn->has_sent_end = 1; /* don't cry wolf about duplicate close */ conn->has_sent_end = 1; /* don't cry wolf about duplicate close */
/* XXX do we need a close-immediate here, so we don't try to flush? */ /* XXX do we need a close-immediate here, so we don't try to flush? */
@ -761,9 +763,10 @@ connection_or_process_cells_from_inbuf(connection_t *conn)
cell_t cell; cell_t cell;
loop: loop:
debug(LD_OR,"%d: starting, inbuf_datalen %d (%d pending in tls object).", log_debug(LD_OR,
conn->s,(int)buf_datalen(conn->inbuf), "%d: starting, inbuf_datalen %d (%d pending in tls object).",
tor_tls_get_pending_bytes(conn->tls)); conn->s,(int)buf_datalen(conn->inbuf),
tor_tls_get_pending_bytes(conn->tls));
if (buf_datalen(conn->inbuf) < CELL_NETWORK_SIZE) /* whole response if (buf_datalen(conn->inbuf) < CELL_NETWORK_SIZE) /* whole response
available? */ available? */
return 0; /* not yet */ return 0; /* not yet */
@ -797,7 +800,7 @@ connection_or_send_destroy(uint16_t circ_id, connection_t *conn, int reason)
cell.circ_id = circ_id; cell.circ_id = circ_id;
cell.command = CELL_DESTROY; cell.command = CELL_DESTROY;
cell.payload[0] = (uint8_t) reason; cell.payload[0] = (uint8_t) reason;
debug(LD_OR,"Sending destroy (circID %d).", circ_id); log_debug(LD_OR,"Sending destroy (circID %d).", circ_id);
connection_or_write_cell_to_buf(&cell, conn); connection_or_write_cell_to_buf(&cell, conn);
return 0; return 0;
} }

75
src/or/control.c
View File

@ -700,7 +700,7 @@ control_setconf_helper(connection_t *conn, uint32_t len, char *body,
*outp = '\0'; *outp = '\0';
if (config_get_lines(config, &lines) < 0) { if (config_get_lines(config, &lines) < 0) {
warn(LD_CONTROL,"Controller gave us config lines we can't parse."); log_warn(LD_CONTROL,"Controller gave us config lines we can't parse.");
connection_write_str_to_buf("551 Couldn't parse configuration\r\n", connection_write_str_to_buf("551 Couldn't parse configuration\r\n",
conn); conn);
tor_free(config); tor_free(config);
@ -709,7 +709,7 @@ control_setconf_helper(connection_t *conn, uint32_t len, char *body,
tor_free(config); tor_free(config);
} else { } else {
if (config_get_lines(body, &lines) < 0) { if (config_get_lines(body, &lines) < 0) {
warn(LD_CONTROL,"Controller gave us config lines we can't parse."); log_warn(LD_CONTROL,"Controller gave us config lines we can't parse.");
send_control0_error(conn, ERR_SYNTAX, "Couldn't parse configuration"); send_control0_error(conn, ERR_SYNTAX, "Couldn't parse configuration");
return 0; return 0;
} }
@ -718,7 +718,8 @@ control_setconf_helper(connection_t *conn, uint32_t len, char *body,
if ((r=options_trial_assign(lines, use_defaults, clear_first)) < 0) { if ((r=options_trial_assign(lines, use_defaults, clear_first)) < 0) {
int v0_err; int v0_err;
const char *msg; const char *msg;
warn(LD_CONTROL,"Controller gave us config lines that didn't validate."); log_warn(LD_CONTROL,
"Controller gave us config lines that didn't validate.");
switch (r) { switch (r) {
case -1: case -1:
v0_err = ERR_UNRECOGNIZED_CONFIG_KEY; v0_err = ERR_UNRECOGNIZED_CONFIG_KEY;
@ -1024,7 +1025,8 @@ handle_control_authenticate(connection_t *conn, uint32_t len, const char *body)
char expected[S2K_SPECIFIER_LEN+DIGEST_LEN]; char expected[S2K_SPECIFIER_LEN+DIGEST_LEN];
char received[DIGEST_LEN]; char received[DIGEST_LEN];
if (decode_hashed_password(expected, options->HashedControlPassword)<0) { if (decode_hashed_password(expected, options->HashedControlPassword)<0) {
warn(LD_CONTROL,"Couldn't decode HashedControlPassword: invalid base16"); log_warn(LD_CONTROL,
"Couldn't decode HashedControlPassword: invalid base16");
goto err; goto err;
} }
secret_to_key(received,DIGEST_LEN,password,password_len,expected); secret_to_key(received,DIGEST_LEN,password,password_len,expected);
@ -1052,7 +1054,7 @@ handle_control_authenticate(connection_t *conn, uint32_t len, const char *body)
} }
return 0; return 0;
ok: ok:
info(LD_CONTROL, "Authenticated control connection (%d)", conn->s); log_info(LD_CONTROL, "Authenticated control connection (%d)", conn->s);
send_control_done(conn); send_control_done(conn);
if (STATE_IS_V0(conn->state)) if (STATE_IS_V0(conn->state))
conn->state = CONTROL_CONN_STATE_OPEN_V0; conn->state = CONTROL_CONN_STATE_OPEN_V0;
@ -1168,18 +1170,20 @@ handle_control_mapaddress(connection_t *conn, uint32_t len, const char *body)
const char *from = smartlist_get(elts,0); const char *from = smartlist_get(elts,0);
const char *to = smartlist_get(elts,1); const char *to = smartlist_get(elts,1);
if (!is_plausible_address(from)) { if (!is_plausible_address(from)) {
warn(LD_CONTROL,"Skipping invalid argument '%s' in MapAddress msg", log_warn(LD_CONTROL,
"Skipping invalid argument '%s' in MapAddress msg",
from); from);
} else if (!is_plausible_address(to)) { } else if (!is_plausible_address(to)) {
warn(LD_CONTROL,"Skipping invalid argument '%s' in MapAddress msg",to); log_warn(LD_CONTROL,
"Skipping invalid argument '%s' in MapAddress msg", to);
} else if (!strcmp(from, ".") || !strcmp(from, "0.0.0.0")) { } else if (!strcmp(from, ".") || !strcmp(from, "0.0.0.0")) {
const char *address = addressmap_register_virtual_address( const char *address = addressmap_register_virtual_address(
!strcmp(from,".") ? RESOLVED_TYPE_HOSTNAME : RESOLVED_TYPE_IPV4, !strcmp(from,".") ? RESOLVED_TYPE_HOSTNAME : RESOLVED_TYPE_IPV4,
tor_strdup(to)); tor_strdup(to));
if (!address) { if (!address) {
warn(LD_CONTROL, log_warn(LD_CONTROL,
"Unable to allocate address for '%s' in MapAddress msg", "Unable to allocate address for '%s' in MapAddress msg",
safe_str(line)); safe_str(line));
} else { } else {
size_t anslen = strlen(address)+strlen(to)+8; size_t anslen = strlen(address)+strlen(to)+8;
char *ans = tor_malloc(anslen); char *ans = tor_malloc(anslen);
@ -1201,7 +1205,8 @@ handle_control_mapaddress(connection_t *conn, uint32_t len, const char *body)
} }
} }
} else { } else {
warn(LD_CONTROL, "Skipping MapAddress line with wrong number of items."); log_warn(LD_CONTROL,
"Skipping MapAddress line with wrong number of items.");
} }
SMARTLIST_FOREACH(elts, char *, cp, tor_free(cp)); SMARTLIST_FOREACH(elts, char *, cp, tor_free(cp));
smartlist_clear(elts); smartlist_clear(elts);
@ -1375,8 +1380,8 @@ handle_getinfo_helper(const char *question, char **answer)
case AP_CONN_STATE_OPEN: case AP_CONN_STATE_OPEN:
state = "SUCCEEDED"; break; state = "SUCCEEDED"; break;
default: default:
warn(LD_BUG, "Asked for stream in unknown state %d", log_warn(LD_BUG, "Asked for stream in unknown state %d",
conns[i]->state); conns[i]->state);
continue; continue;
} }
circ = circuit_get_by_edge_conn(conns[i]); circ = circuit_get_by_edge_conn(conns[i]);
@ -1645,8 +1650,8 @@ handle_control_extendcircuit(connection_t *conn, uint32_t len,
if (circ->state == CIRCUIT_STATE_OPEN) { if (circ->state == CIRCUIT_STATE_OPEN) {
circuit_set_state(circ, CIRCUIT_STATE_BUILDING); circuit_set_state(circ, CIRCUIT_STATE_BUILDING);
if (circuit_send_next_onion_skin(circ) < 0) { if (circuit_send_next_onion_skin(circ) < 0) {
info(LD_CONTROL, log_info(LD_CONTROL,
"send_next_onion_skin failed; circuit marked for closing."); "send_next_onion_skin failed; circuit marked for closing.");
circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN); circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN);
if (v0) if (v0)
send_control0_error(conn, ERR_INTERNAL, "couldn't send onion skin"); send_control0_error(conn, ERR_INTERNAL, "couldn't send onion skin");
@ -1977,8 +1982,8 @@ handle_control_closecircuit(connection_t *conn, uint32_t len,
if (!strcasecmp(smartlist_get(args, i), "IfUnused")) if (!strcasecmp(smartlist_get(args, i), "IfUnused"))
safe = 1; safe = 1;
else else
info(LD_CONTROL, "Skipping unknown option %s", log_info(LD_CONTROL, "Skipping unknown option %s",
(char*)smartlist_get(args,i)); (char*)smartlist_get(args,i));
} }
} }
SMARTLIST_FOREACH(args, char *, cp, tor_free(cp)); SMARTLIST_FOREACH(args, char *, cp, tor_free(cp));
@ -2006,7 +2011,7 @@ handle_control_fragments(connection_t *conn, uint16_t command_type,
{ {
if (command_type == CONTROL0_CMD_FRAGMENTHEADER) { if (command_type == CONTROL0_CMD_FRAGMENTHEADER) {
if (conn->incoming_cmd) { if (conn->incoming_cmd) {
warn(LD_CONTROL, "Dropping incomplete fragmented command"); log_warn(LD_CONTROL, "Dropping incomplete fragmented command");
tor_free(conn->incoming_cmd); tor_free(conn->incoming_cmd);
} }
if (body_len < 6) { if (body_len < 6) {
@ -2058,7 +2063,7 @@ connection_control_reached_eof(connection_t *conn)
tor_assert(conn); tor_assert(conn);
tor_assert(conn->type == CONN_TYPE_CONTROL); tor_assert(conn->type == CONN_TYPE_CONTROL);
info(LD_CONTROL,"Control connection reached EOF. Closing."); log_info(LD_CONTROL,"Control connection reached EOF. Closing.");
connection_mark_for_close(conn); connection_mark_for_close(conn);
return 0; return 0;
} }
@ -2223,13 +2228,14 @@ connection_control_process_inbuf_v0(connection_t *conn)
{ {
case -2: case -2:
tor_free(body); tor_free(body);
info(LD_CONTROL, "Detected v1 control protocol on connection (fd %d)", log_info(LD_CONTROL,
conn->s); "Detected v1 control protocol on connection (fd %d)",
conn->s);
conn->state = CONTROL_CONN_STATE_NEEDAUTH_V1; conn->state = CONTROL_CONN_STATE_NEEDAUTH_V1;
return connection_control_process_inbuf_v1(conn); return connection_control_process_inbuf_v1(conn);
case -1: case -1:
tor_free(body); tor_free(body);
warn(LD_CONTROL, "Error in control command. Failing."); log_warn(LD_CONTROL, "Error in control command. Failing.");
return -1; return -1;
case 0: case 0:
/* Control command not all here yet. Wait. */ /* Control command not all here yet. Wait. */
@ -2245,8 +2251,8 @@ connection_control_process_inbuf_v0(connection_t *conn)
* commands will be considered. */ * commands will be considered. */
if (conn->state == CONTROL_CONN_STATE_NEEDAUTH_V0 && if (conn->state == CONTROL_CONN_STATE_NEEDAUTH_V0 &&
command_type != CONTROL0_CMD_AUTHENTICATE) { command_type != CONTROL0_CMD_AUTHENTICATE) {
info(LD_CONTROL, "Rejecting '%s' command; authentication needed.", log_info(LD_CONTROL, "Rejecting '%s' command; authentication needed.",
control_cmd_to_string(command_type)); control_cmd_to_string(command_type));
send_control0_error(conn, ERR_UNAUTHORIZED, "Authentication required"); send_control0_error(conn, ERR_UNAUTHORIZED, "Authentication required");
tor_free(body); tor_free(body);
goto again; goto again;
@ -2265,7 +2271,7 @@ connection_control_process_inbuf_v0(connection_t *conn)
body = conn->incoming_cmd; body = conn->incoming_cmd;
conn->incoming_cmd = NULL; conn->incoming_cmd = NULL;
} else if (conn->incoming_cmd) { } else if (conn->incoming_cmd) {
warn(LD_CONTROL, "Dropping incomplete fragmented command"); log_warn(LD_CONTROL, "Dropping incomplete fragmented command");
tor_free(conn->incoming_cmd); tor_free(conn->incoming_cmd);
} }
@ -2333,18 +2339,19 @@ connection_control_process_inbuf_v0(connection_t *conn)
case CONTROL0_CMD_CONFVALUE: case CONTROL0_CMD_CONFVALUE:
case CONTROL0_CMD_EVENT: case CONTROL0_CMD_EVENT:
case CONTROL0_CMD_INFOVALUE: case CONTROL0_CMD_INFOVALUE:
warn(LD_CONTROL, "Received client-only '%s' command; ignoring.", log_warn(LD_CONTROL, "Received client-only '%s' command; ignoring.",
control_cmd_to_string(command_type)); control_cmd_to_string(command_type));
send_control0_error(conn, ERR_UNRECOGNIZED_TYPE, send_control0_error(conn, ERR_UNRECOGNIZED_TYPE,
"Command type only valid from server to tor client"); "Command type only valid from server to tor client");
break; break;
case CONTROL0_CMD_FRAGMENTHEADER: case CONTROL0_CMD_FRAGMENTHEADER:
case CONTROL0_CMD_FRAGMENT: case CONTROL0_CMD_FRAGMENT:
warn(LD_CONTROL, "Recieved command fragment out of order; ignoring."); log_warn(LD_CONTROL,
"Recieved command fragment out of order; ignoring.");
send_control0_error(conn, ERR_SYNTAX, "Bad fragmentation on command."); send_control0_error(conn, ERR_SYNTAX, "Bad fragmentation on command.");
default: default:
warn(LD_CONTROL, "Received unrecognized command type %d; ignoring.", log_warn(LD_CONTROL, "Received unrecognized command type %d; ignoring.",
(int)command_type); (int)command_type);
send_control0_error(conn, ERR_UNRECOGNIZED_TYPE, send_control0_error(conn, ERR_UNRECOGNIZED_TYPE,
"Unrecognized command type"); "Unrecognized command type");
break; break;
@ -2399,7 +2406,7 @@ control_event_circuit_status(circuit_t *circ, circuit_status_event_t tp)
case CIRC_EVENT_FAILED: status = "FAILED"; break; case CIRC_EVENT_FAILED: status = "FAILED"; break;
case CIRC_EVENT_CLOSED: status = "CLOSED"; break; case CIRC_EVENT_CLOSED: status = "CLOSED"; break;
default: default:
warn(LD_BUG, "Unrecognized status code %d", (int)tp); log_warn(LD_BUG, "Unrecognized status code %d", (int)tp);
return 0; return 0;
} }
send_control1_event(EVENT_CIRCUIT_STATUS, send_control1_event(EVENT_CIRCUIT_STATUS,
@ -2472,7 +2479,7 @@ control_event_stream_status(connection_t *conn, stream_status_event_t tp)
case STREAM_EVENT_NEW_RESOLVE: status = "NEWRESOLVE"; break; case STREAM_EVENT_NEW_RESOLVE: status = "NEWRESOLVE"; break;
case STREAM_EVENT_FAILED_RETRIABLE: status = "DETACHED"; break; case STREAM_EVENT_FAILED_RETRIABLE: status = "DETACHED"; break;
default: default:
warn(LD_BUG, "Unrecognized status code %d", (int)tp); log_warn(LD_BUG, "Unrecognized status code %d", (int)tp);
return 0; return 0;
} }
circ = circuit_get_by_edge_conn(conn); circ = circuit_get_by_edge_conn(conn);
@ -2514,7 +2521,7 @@ control_event_or_conn_status(connection_t *conn,or_conn_status_event_t tp)
case OR_CONN_EVENT_FAILED: status = "FAILED"; break; case OR_CONN_EVENT_FAILED: status = "FAILED"; break;
case OR_CONN_EVENT_CLOSED: status = "CLOSED"; break; case OR_CONN_EVENT_CLOSED: status = "CLOSED"; break;
default: default:
warn(LD_BUG, "Unrecognized status code %d", (int)tp); log_warn(LD_BUG, "Unrecognized status code %d", (int)tp);
return 0; return 0;
} }
send_control1_event(EVENT_OR_CONN_STATUS, send_control1_event(EVENT_OR_CONN_STATUS,
@ -2731,7 +2738,7 @@ init_cookie_authentication(int enabled)
authentication_cookie_is_set = 1; authentication_cookie_is_set = 1;
if (write_bytes_to_file(fname, authentication_cookie, if (write_bytes_to_file(fname, authentication_cookie,
AUTHENTICATION_COOKIE_LEN, 1)) { AUTHENTICATION_COOKIE_LEN, 1)) {
warn(LD_FS,"Error writing authentication cookie."); log_warn(LD_FS,"Error writing authentication cookie.");
return -1; return -1;
} }

64
src/or/cpuworker.c
View File

@ -85,7 +85,8 @@ tag_unpack(const char *tag, uint32_t *addr, uint16_t *port, uint16_t *circ_id)
in.s_addr = htonl(*addr); in.s_addr = htonl(*addr);
tor_inet_ntoa(&in, addrbuf, sizeof(addrbuf)); tor_inet_ntoa(&in, addrbuf, sizeof(addrbuf));
debug(LD_OR,"onion was from %s:%d, circ_id %d.", addrbuf, *port, *circ_id); log_debug(LD_OR,
"onion was from %s:%d, circ_id %d.", addrbuf, *port, *circ_id);
} }
/** Called when the onion key has changed and we need to spawn new /** Called when the onion key has changed and we need to spawn new
@ -111,12 +112,12 @@ cpuworkers_rotate(void)
int int
connection_cpu_reached_eof(connection_t *conn) connection_cpu_reached_eof(connection_t *conn)
{ {
warn(LD_GENERAL,"Read eof. Worker died unexpectedly."); log_warn(LD_GENERAL,"Read eof. Worker died unexpectedly.");
if (conn->state != CPUWORKER_STATE_IDLE) { if (conn->state != CPUWORKER_STATE_IDLE) {
/* the circ associated with this cpuworker will have to wait until /* the circ associated with this cpuworker will have to wait until
* it gets culled in run_connection_housekeeping(), since we have * it gets culled in run_connection_housekeeping(), since we have
* no way to find out which circ it was. */ * no way to find out which circ it was. */
warn(LD_GENERAL,"...and it left a circuit queued; abandoning circ."); log_warn(LD_GENERAL,"...and it left a circuit queued; abandoning circ.");
num_cpuworkers_busy--; num_cpuworkers_busy--;
} }
num_cpuworkers--; num_cpuworkers--;
@ -166,8 +167,9 @@ connection_cpu_process_inbuf(connection_t *conn)
circ = circuit_get_by_circid_orconn(circ_id, p_conn); circ = circuit_get_by_circid_orconn(circ_id, p_conn);
if (success == 0) { if (success == 0) {
debug(LD_OR, log_debug(LD_OR,
"decoding onionskin failed. (Old key or bad software.) Closing."); "decoding onionskin failed. "
"(Old key or bad software.) Closing.");
if (circ) if (circ)
circuit_mark_for_close(circ, END_CIRC_REASON_TORPROTOCOL); circuit_mark_for_close(circ, END_CIRC_REASON_TORPROTOCOL);
goto done_processing; goto done_processing;
@ -178,17 +180,17 @@ connection_cpu_process_inbuf(connection_t *conn)
* why our tag doesn't include a pointer to the circ, because we'd * why our tag doesn't include a pointer to the circ, because we'd
* never know if it's still valid. * never know if it's still valid.
*/ */
debug(LD_OR,"processed onion for a circ that's gone. Dropping."); log_debug(LD_OR,"processed onion for a circ that's gone. Dropping.");
goto done_processing; goto done_processing;
} }
tor_assert(circ->p_conn); tor_assert(circ->p_conn);
if (onionskin_answer(circ, CELL_CREATED, buf+TAG_LEN, if (onionskin_answer(circ, CELL_CREATED, buf+TAG_LEN,
buf+TAG_LEN+ONIONSKIN_REPLY_LEN) < 0) { buf+TAG_LEN+ONIONSKIN_REPLY_LEN) < 0) {
warn(LD_OR,"onionskin_answer failed. Closing."); log_warn(LD_OR,"onionskin_answer failed. Closing.");
circuit_mark_for_close(circ, END_CIRC_REASON_INTERNAL); circuit_mark_for_close(circ, END_CIRC_REASON_INTERNAL);
goto done_processing; goto done_processing;
} }
debug(LD_OR,"onionskin_answer succeeded. Yay."); log_debug(LD_OR,"onionskin_answer succeeded. Yay.");
} else { } else {
tor_assert(0); /* don't ask me to do handshakes yet */ tor_assert(0); /* don't ask me to do handshakes yet */
} }
@ -254,26 +256,28 @@ cpuworker_main(void *data)
if ((r = recv(fd, &question_type, 1, 0)) != 1) { if ((r = recv(fd, &question_type, 1, 0)) != 1) {
// log_fn(LOG_ERR,"read type failed. Exiting."); // log_fn(LOG_ERR,"read type failed. Exiting.");
if (r == 0) { if (r == 0) {
info(LD_OR,"CPU worker exiting because Tor process closed connection " log_info(LD_OR,
"(either rotated keys or died)."); "CPU worker exiting because Tor process closed connection "
"(either rotated keys or died).");
} else { } else {
info(LD_OR,"CPU worker editing because of error on connection to Tor " log_info(LD_OR,
"process."); "CPU worker editing because of error on connection to Tor "
info(LD_OR,"(Error on %d was %s)", "process.");
fd, tor_socket_strerror(tor_socket_errno(fd))); log_info(LD_OR,"(Error on %d was %s)",
fd, tor_socket_strerror(tor_socket_errno(fd)));
} }
goto end; goto end;
} }
tor_assert(question_type == CPUWORKER_TASK_ONION); tor_assert(question_type == CPUWORKER_TASK_ONION);
if (read_all(fd, tag, TAG_LEN, 1) != TAG_LEN) { if (read_all(fd, tag, TAG_LEN, 1) != TAG_LEN) {
err(LD_BUG,"read tag failed. Exiting."); log_err(LD_BUG,"read tag failed. Exiting.");
goto end; goto end;
} }
if (read_all(fd, question, ONIONSKIN_CHALLENGE_LEN, 1) != if (read_all(fd, question, ONIONSKIN_CHALLENGE_LEN, 1) !=
ONIONSKIN_CHALLENGE_LEN) { ONIONSKIN_CHALLENGE_LEN) {
err(LD_BUG,"read question failed. Exiting."); log_err(LD_BUG,"read question failed. Exiting.");
goto end; goto end;
} }
@ -281,21 +285,21 @@ cpuworker_main(void *data)
if (onion_skin_server_handshake(question, onion_key, last_onion_key, if (onion_skin_server_handshake(question, onion_key, last_onion_key,
reply_to_proxy, keys, CPATH_KEY_MATERIAL_LEN) < 0) { reply_to_proxy, keys, CPATH_KEY_MATERIAL_LEN) < 0) {
/* failure */ /* failure */
debug(LD_OR,"onion_skin_server_handshake failed."); log_debug(LD_OR,"onion_skin_server_handshake failed.");
memset(buf,0,LEN_ONION_RESPONSE); /* send all zeros for failure */ memset(buf,0,LEN_ONION_RESPONSE); /* send all zeros for failure */
} else { } else {
/* success */ /* success */
debug(LD_OR,"onion_skin_server_handshake succeeded."); log_debug(LD_OR,"onion_skin_server_handshake succeeded.");
buf[0] = 1; /* 1 means success */ buf[0] = 1; /* 1 means success */
memcpy(buf+1,tag,TAG_LEN); memcpy(buf+1,tag,TAG_LEN);
memcpy(buf+1+TAG_LEN,reply_to_proxy,ONIONSKIN_REPLY_LEN); memcpy(buf+1+TAG_LEN,reply_to_proxy,ONIONSKIN_REPLY_LEN);
memcpy(buf+1+TAG_LEN+ONIONSKIN_REPLY_LEN,keys,CPATH_KEY_MATERIAL_LEN); memcpy(buf+1+TAG_LEN+ONIONSKIN_REPLY_LEN,keys,CPATH_KEY_MATERIAL_LEN);
} }
if (write_all(fd, buf, LEN_ONION_RESPONSE, 1) != LEN_ONION_RESPONSE) { if (write_all(fd, buf, LEN_ONION_RESPONSE, 1) != LEN_ONION_RESPONSE) {
err(LD_BUG,"writing response buf failed. Exiting."); log_err(LD_BUG,"writing response buf failed. Exiting.");
goto end; goto end;
} }
debug(LD_OR,"finished writing response."); log_debug(LD_OR,"finished writing response.");
} }
} }
end: end:
@ -321,15 +325,15 @@ spawn_cpuworker(void)
fdarray = tor_malloc(sizeof(int)*2); fdarray = tor_malloc(sizeof(int)*2);
if ((err = tor_socketpair(AF_UNIX, SOCK_STREAM, 0, fdarray)) < 0) { if ((err = tor_socketpair(AF_UNIX, SOCK_STREAM, 0, fdarray)) < 0) {
warn(LD_NET, "Couldn't construct socketpair: %s", log_warn(LD_NET, "Couldn't construct socketpair: %s",
tor_socket_strerror(-err)); tor_socket_strerror(-err));
tor_free(fdarray); tor_free(fdarray);
return -1; return -1;
} }
fd = fdarray[0]; fd = fdarray[0];
spawn_func(cpuworker_main, (void*)fdarray); spawn_func(cpuworker_main, (void*)fdarray);
debug(LD_OR,"just spawned a cpu worker."); log_debug(LD_OR,"just spawned a cpu worker.");
#ifndef TOR_IS_MULTITHREADED #ifndef TOR_IS_MULTITHREADED
tor_close_socket(fdarray[1]); /* don't need the worker's side of the pipe */ tor_close_socket(fdarray[1]); /* don't need the worker's side of the pipe */
tor_free(fdarray); tor_free(fdarray);
@ -344,7 +348,7 @@ spawn_cpuworker(void)
conn->address = tor_strdup("localhost"); conn->address = tor_strdup("localhost");
if (connection_add(conn) < 0) { /* no space, forget it */ if (connection_add(conn) < 0) { /* no space, forget it */
warn(LD_NET,"connection_add failed. Giving up."); log_warn(LD_NET,"connection_add failed. Giving up.");
connection_free(conn); /* this closes fd */ connection_free(conn); /* this closes fd */
return -1; return -1;
} }
@ -370,7 +374,7 @@ spawn_enough_cpuworkers(void)
while (num_cpuworkers < num_cpuworkers_needed) { while (num_cpuworkers < num_cpuworkers_needed) {
if (spawn_cpuworker() < 0) { if (spawn_cpuworker() < 0) {
warn(LD_GENERAL,"Spawn failed. Will try again later."); log_warn(LD_GENERAL,"Spawn failed. Will try again later.");
return; return;
} }
num_cpuworkers++; num_cpuworkers++;
@ -391,7 +395,7 @@ process_pending_task(connection_t *cpuworker)
if (!circ) if (!circ)
return; return;
if (assign_to_cpuworker(cpuworker, CPUWORKER_TASK_ONION, circ) < 0) if (assign_to_cpuworker(cpuworker, CPUWORKER_TASK_ONION, circ) < 0)
warn(LD_OR,"assign_to_cpuworker failed. Ignoring."); log_warn(LD_OR,"assign_to_cpuworker failed. Ignoring.");
} }
#define CPUWORKER_BUSY_TIMEOUT 3600 /* seconds */ #define CPUWORKER_BUSY_TIMEOUT 3600 /* seconds */
@ -415,8 +419,8 @@ cull_wedged_cpuworkers(void)
conn->type == CONN_TYPE_CPUWORKER && conn->type == CONN_TYPE_CPUWORKER &&
conn->state == CPUWORKER_STATE_BUSY_ONION && conn->state == CPUWORKER_STATE_BUSY_ONION &&
conn->timestamp_lastwritten + CPUWORKER_BUSY_TIMEOUT < now) { conn->timestamp_lastwritten + CPUWORKER_BUSY_TIMEOUT < now) {
notice(LD_BUG, log_notice(LD_BUG,
"Bug: closing wedged cpuworker. Can somebody find the bug?"); "Bug: closing wedged cpuworker. Can somebody find the bug?");
num_cpuworkers_busy--; num_cpuworkers_busy--;
num_cpuworkers--; num_cpuworkers--;
connection_mark_for_close(conn); connection_mark_for_close(conn);
@ -447,7 +451,7 @@ assign_to_cpuworker(connection_t *cpuworker, uint8_t question_type,
tor_assert(circ->onionskin); tor_assert(circ->onionskin);
if (num_cpuworkers_busy == num_cpuworkers) { if (num_cpuworkers_busy == num_cpuworkers) {
debug(LD_OR,"No idle cpuworkers. Queuing."); log_debug(LD_OR,"No idle cpuworkers. Queuing.");
if (onion_pending_add(circ) < 0) if (onion_pending_add(circ) < 0)
return -1; return -1;
return 0; return 0;
@ -460,7 +464,7 @@ assign_to_cpuworker(connection_t *cpuworker, uint8_t question_type,
tor_assert(cpuworker); tor_assert(cpuworker);
if (!circ->p_conn) { if (!circ->p_conn) {
info(LD_OR,"circ->p_conn gone. Failing circ."); log_info(LD_OR,"circ->p_conn gone. Failing circ.");
return -1; return -1;
} }
tag_pack(tag, circ->p_conn->addr, circ->p_conn->port, circ->p_circ_id); tag_pack(tag, circ->p_conn->addr, circ->p_conn->port, circ->p_circ_id);