diff options
| -rw-r--r-- | src/or/config.c | 306 | ||||
| -rw-r--r-- | src/or/connection.c | 175 | ||||
| -rw-r--r-- | src/or/connection_edge.c | 225 | ||||
| -rw-r--r-- | src/or/connection_or.c | 79 | ||||
| -rw-r--r-- | src/or/control.c | 75 | ||||
| -rw-r--r-- | src/or/cpuworker.c | 64 |
6 files changed, 486 insertions, 438 deletions
diff --git a/src/or/config.c b/src/or/config.c index 669c47bbd..60ec0c021 100644 --- a/src/or/config.c +++ b/src/or/config.c @@ -466,8 +466,8 @@ set_options(or_options_t *new_val) return -1; } if (options_act(old_options) < 0) { /* acting on the options failed. die. */ - err(LD_CONFIG, - "Acting on config options left us in a broken state. Dying."); + log_err(LD_CONFIG, + "Acting on config options left us in a broken state. Dying."); exit(1); } if (old_options) @@ -561,8 +561,8 @@ options_act_reversible(or_options_t *old_options) /* Ensure data directory is private; create if possible. */ if (check_private_dir(options->DataDirectory, CPD_CREATE)<0) { - err(LD_FS, "Couldn't access/create private data directory \"%s\"", - options->DataDirectory); + log_err(LD_FS, "Couldn't access/create private data directory \"%s\"", + options->DataDirectory); /* No need to roll back, since you can't change the value. */ goto done; } @@ -579,7 +579,7 @@ options_act_reversible(or_options_t *old_options) set_conn_limit = 1; 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; } @@ -597,8 +597,8 @@ options_act_reversible(or_options_t *old_options) } SMARTLIST_FOREACH(replaced_listeners, connection_t *, conn, { - notice(LD_NET, "Closing old %s on %s:%d", - conn_type_to_string(conn->type), conn->address, conn->port); + log_notice(LD_NET, "Closing old %s on %s:%d", + conn_type_to_string(conn->type), conn->address, conn->port); connection_close_immediate(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, { - notice(LD_NET, "Closing %s on %s:%d", - conn_type_to_string(conn->type), conn->address, conn->port); + log_notice(LD_NET, "Closing %s on %s:%d", + conn_type_to_string(conn->type), conn->address, conn->port); connection_close_immediate(conn); connection_mark_for_close(conn); }); @@ -651,7 +651,7 @@ options_act(or_options_t *old_options) if (options->DirServers) { for (cl = options->DirServers; cl; cl = cl->next) { 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!"); return -1; } @@ -661,8 +661,8 @@ options_act(or_options_t *old_options) } if (running_tor && rend_config_services(options, 0)<0) { - err(LD_BUG, - "Bug: Previously validated hidden services line could not be added!"); + log_err(LD_BUG, + "Bug: Previously validated hidden services line could not be added!"); return -1; } @@ -671,8 +671,8 @@ options_act(or_options_t *old_options) fn = tor_malloc(len); tor_snprintf(fn, len, "%s/cached-status", options->DataDirectory); if (check_private_dir(fn, CPD_CREATE) != 0) { - err(LD_CONFIG, - "Couldn't access/create private data directory \"%s\"", fn); + log_err(LD_CONFIG, + "Couldn't access/create private data directory \"%s\"", fn); tor_free(fn); return -1; } @@ -722,13 +722,13 @@ options_act(or_options_t *old_options) /* reload keys as needed for rendezvous services. */ 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; } /* Set up accounting */ if (accounting_parse_options(options, 0)<0) { - err(LD_CONFIG,"Error in accounting options"); + log_err(LD_CONFIG,"Error in accounting options"); return -1; } if (accounting_is_enabled(options)) @@ -740,17 +740,19 @@ options_act(or_options_t *old_options) /* Check for transitions that need action. */ if (old_options) { 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_expire_all_dirty_circs(); } 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)) { extern int has_completed_circuit; if (init_keys() < 0) { - err(LD_GENERAL,"Error initializing keys; exiting"); + log_err(LD_GENERAL,"Error initializing keys; exiting"); return -1; } 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) && (command_line || !fmt->abbrevs[i].commandline_only)) { if (warn_obsolete && fmt->abbrevs[i].warn) { - warn(LD_CONFIG, - "The configuration option '%s' is deprecated; use '%s' instead.", - fmt->abbrevs[i].abbreviated, - fmt->abbrevs[i].full); + log_warn(LD_CONFIG, + "The configuration option '%s' is deprecated; " + "use '%s' instead.", + fmt->abbrevs[i].abbreviated, + 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; } if (i == argc-1) { - warn(LD_CONFIG,"Command-line option '%s' with no value. Failing.", - argv[i]); + log_warn(LD_CONFIG,"Command-line option '%s' with no value. Failing.", + argv[i]); config_free_lines(front); return -1; } @@ -961,9 +964,9 @@ config_find_option(config_format_t *fmt, const char *key) /* If none, check for an abbreviated match */ for (i=0; fmt->vars[i].name; ++i) { if (!strncasecmp(key, fmt->vars[i].name, keylen)) { - warn(LD_CONFIG, "The abbreviation '%s' is deprecated. " - "Please use '%s' instead", - key, fmt->vars[i].name); + log_warn(LD_CONFIG, "The abbreviation '%s' is deprecated. " + "Please use '%s' instead", + key, fmt->vars[i].name); return &fmt->vars[i]; } } @@ -1070,10 +1073,10 @@ config_assign_value(config_format_t *fmt, or_options_t *options, break; 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; 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; default: tor_assert(0); @@ -1103,11 +1106,12 @@ config_assign_line(config_format_t *fmt, or_options_t *options, if (!var) { if (fmt->extra) { 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); return 0; } else { - warn(LD_CONFIG, "Unknown option '%s'. Failing.", c->key); + log_warn(LD_CONFIG, "Unknown option '%s'. Failing.", c->key); return -1; } } @@ -1199,11 +1203,11 @@ get_assigned_option(config_format_t *fmt, or_options_t *options, var = config_find_option(fmt, key); if (!var) { - warn(LD_CONFIG, "Unknown option '%s'. Failing.", key); + log_warn(LD_CONFIG, "Unknown option '%s'. Failing.", key); return NULL; } else if (var->type == CONFIG_TYPE_LINELIST_S) { - warn(LD_CONFIG, - "Can't return context-sensitive '%s' on its own", key); + log_warn(LD_CONFIG, + "Can't return context-sensitive '%s' on its own", key); return NULL; } 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(""); break; case CONFIG_TYPE_OBSOLETE: - warn(LD_CONFIG, - "You asked me for the value of an obsolete config option '%s'.", - key); + log_warn(LD_CONFIG, + "You asked me for the value of an obsolete config option '%s'.", + key); tor_free(result->key); tor_free(result); return NULL; default: tor_free(result->key); 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; } @@ -1506,10 +1511,10 @@ resolve_my_address(or_options_t *options, uint32_t *addr_out, explicit_ip = 0; /* it's implicit */ if (gethostname(hostname, sizeof(hostname)) < 0) { - warn(LD_NET,"Error obtaining local hostname"); + log_warn(LD_NET,"Error obtaining local hostname"); 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 */ @@ -1519,8 +1524,8 @@ resolve_my_address(or_options_t *options, uint32_t *addr_out, explicit_ip = 0; rent = (struct hostent *)gethostbyname(hostname); if (!rent) { - warn(LD_CONFIG,"Could not resolve local Address '%s'. Failing.", - hostname); + log_warn(LD_CONFIG,"Could not resolve local Address '%s'. Failing.", + hostname); return -1; } 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 they are using the default dirservers, disallow internal IPs * always. */ - warn(LD_CONFIG,"Address '%s' resolves to private IP '%s'. " - "Tor servers that use the default DirServers must have public " - "IP addresses.", - hostname, tmpbuf); + log_warn(LD_CONFIG,"Address '%s' resolves to private IP '%s'. " + "Tor servers that use the default DirServers must have public " + "IP addresses.", + hostname, tmpbuf); return -1; } if (!explicit_ip) { /* even if they've set their own dirservers, require an explicit IP if * they're using an internal address. */ - warn(LD_CONFIG,"Address '%s' resolves to private IP '%s'. Please " - "set the Address config option to be the IP you want to use.", - hostname, tmpbuf); + 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.", + hostname, tmpbuf); 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); 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(); } old_addr = *addr_out; @@ -1570,7 +1575,7 @@ get_default_nickname(void) char *cp, *out, *outp; if (gethostname(localhostname, sizeof(localhostname)) < 0) { - warn(LD_NET,"Error obtaining local hostname"); + log_warn(LD_NET,"Error obtaining local hostname"); 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); if (line) { if (config_assign(fmt, newopts, line, 0, 0) < 0) { - warn(LD_BUG, "Bug: config_get_assigned_option() generated " - "something we couldn't config_assign()."); + log_warn(LD_BUG, "Bug: config_get_assigned_option() generated " + "something we couldn't config_assign()."); tor_assert(0); } } @@ -1756,7 +1761,7 @@ config_dump(config_format_t *fmt, void *options, int minimal) char *tmp; tmp = tor_malloc(len); 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); } smartlist_add(elements, tmp); @@ -1771,7 +1776,7 @@ config_dump(config_format_t *fmt, void *options, int minimal) char *tmp; tmp = tor_malloc(len); 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); } smartlist_add(elements, tmp); @@ -1831,7 +1836,7 @@ parse_reachable_addresses(void) if (config_parse_addr_policy(options->ReachableAddresses, &reachable_addr_policy, ADDR_POLICY_ACCEPT)) { - warn(LD_CONFIG, "Error in ReachableAddresses entry; ignoring."); + log_warn(LD_CONFIG, "Error in ReachableAddresses entry; ignoring."); return; } } @@ -1861,7 +1866,7 @@ fascist_firewall_allows_address(uint32_t addr, uint16_t port) case ADDR_POLICY_REJECTED: return 0; default: - warn(LD_BUG, "Unexpected result: %d", (int)p); + log_warn(LD_BUG, "Unexpected result: %d", (int)p); return 0; } } @@ -1927,7 +1932,7 @@ options_validate(or_options_t *old_options, or_options_t *options, if (!is_internal_IP(addr, 1) && (!old_options || !config_lines_eq(old_options->SocksListenAddress, options->SocksListenAddress))) { - warn(LD_CONFIG, + log_warn(LD_CONFIG, "You specified a public address '%s' for a SOCKS listener. Other " "people on the Internet might find your computer and use it as " "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 (!(options->Nickname = get_default_nickname())) return -1; - notice(LD_CONFIG, "Choosing default nickname '%s'", options->Nickname); + log_notice(LD_CONFIG, "Choosing default nickname '%s'", + options->Nickname); } } else { if (!is_legal_nickname(options->Nickname)) { @@ -2021,8 +2027,8 @@ options_validate(or_options_t *old_options, or_options_t *options, options->RecommendedServerVersions = config_lines_dup(options->RecommendedVersions); if (options->UseEntryGuards) { - notice(LD_CONFIG, "Authoritative directory servers can't set " - "UseEntryGuards. Disabling."); + log_notice(LD_CONFIG, "Authoritative directory servers can't set " + "UseEntryGuards. Disabling."); options->UseEntryGuards = 0; } } @@ -2344,38 +2350,39 @@ options_transition_allowed(or_options_t *old, or_options_t *new_val) return 0; 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; } if (old->RunAsDaemon != new_val->RunAsDaemon) { - warn(LD_CONFIG,"While Tor is running, changing RunAsDaemon is not allowed." - " Failing."); + log_warn(LD_CONFIG, + "While Tor is running, changing RunAsDaemon is not allowed." + " Failing."); return -1; } if (strcmp(old->DataDirectory,new_val->DataDirectory)!=0) { - warn(LD_CONFIG,"While Tor is running, changing DataDirectory " - "(\"%s\"->\"%s\") is not allowed. Failing.", - old->DataDirectory, new_val->DataDirectory); + log_warn(LD_CONFIG,"While Tor is running, changing DataDirectory " + "(\"%s\"->\"%s\") is not allowed. Failing.", + old->DataDirectory, new_val->DataDirectory); return -1; } if (!opt_streq(old->User, new_val->User)) { - warn(LD_CONFIG,"While Tor is running, changing User is not allowed. " - "Failing."); + log_warn(LD_CONFIG,"While Tor is running, changing User is not allowed. " + "Failing."); return -1; } if (!opt_streq(old->Group, new_val->Group)) { - warn(LD_CONFIG,"While Tor is running, changing Group is not allowed. " - "Failing."); + log_warn(LD_CONFIG,"While Tor is running, changing Group is not allowed. " + "Failing."); return -1; } if (old->HardwareAccel != new_val->HardwareAccel) { - warn(LD_CONFIG,"While Tor is running, changing HardwareAccel is not " - "allowed. Failing."); + log_warn(LD_CONFIG,"While Tor is running, changing HardwareAccel is not " + "allowed. Failing."); return -1; } @@ -2449,9 +2456,10 @@ get_windows_conf_root(void) &idl))) { GetCurrentDirectory(MAX_PATH, path); is_set = 1; - warn(LD_CONFIG, "I couldn't find your application data folder: are you " - "running an ancient version of Windows 95? Defaulting to \"%s\"", - path); + log_warn(LD_CONFIG, + "I couldn't find your application data folder: are you " + "running an ancient version of Windows 95? Defaulting to \"%s\"", + path); return 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, { 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; } }); @@ -2679,18 +2687,20 @@ config_register_addressmaps(or_options_t *options) from = smartlist_get(elts,0); to = smartlist_get(elts,1); 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)) { - warn(LD_CONFIG,"Skipping invalid argument '%s' to MapAddress",to); + log_warn(LD_CONFIG, + "Skipping invalid argument '%s' to MapAddress", to); } else { addressmap_register(from, tor_strdup(to), 0); if (smartlist_len(elts)>2) { - warn(LD_CONFIG,"Ignoring extra arguments to MapAddress."); + log_warn(LD_CONFIG,"Ignoring extra arguments to MapAddress."); } } } else { - warn(LD_CONFIG,"MapAddress '%s' has too few arguments. Ignoring.", - opt->value); + log_warn(LD_CONFIG,"MapAddress '%s' has too few arguments. Ignoring.", + opt->value); } SMARTLIST_FOREACH(elts, char*, cp, tor_free(cp)); 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); levelMin = parse_log_level(tmp_sev); if (levelMin < 0) { - warn(LD_CONFIG, "Unrecognized log severity '%s': must be one of " - "err|warn|notice|info|debug", tmp_sev); + log_warn(LD_CONFIG, "Unrecognized log severity '%s': must be one of " + "err|warn|notice|info|debug", tmp_sev); tor_free(tmp_sev); return -1; } @@ -2729,16 +2739,16 @@ parse_log_severity_range(const char *range, int *min_out, int *max_out) } else { levelMax = parse_log_level(cp+1); if (levelMax < 0) { - warn(LD_CONFIG, "Unrecognized log severity '%s': must be one of " - "err|warn|notice|info|debug", cp+1); + log_warn(LD_CONFIG, "Unrecognized log severity '%s': must be one of " + "err|warn|notice|info|debug", cp+1); return -1; } } } else { levelMin = parse_log_level(range); if (levelMin < 0) { - warn(LD_CONFIG, "Unrecognized log severity '%s': must be one of " - "err|warn|notice|info|debug", range); + log_warn(LD_CONFIG, "Unrecognized log severity '%s': must be one of " + "err|warn|notice|info|debug", range); return -1; } 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 (add_single_log_option(options, levelMin, levelMax, "file", file_opt->value) < 0) { - warn(LD_FS, "Cannot write to LogFile \"%s\": %s.", file_opt->value, - strerror(errno)); + log_warn(LD_FS, "Cannot write to LogFile \"%s\": %s.", file_opt->value, + strerror(errno)); return -1; } } 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, SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 3); 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; } 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 (!validate_only) { if (daemon) { - warn(LD_CONFIG, - "Can't log to stdout with RunAsDaemon set; skipping stdout"); + log_warn(LD_CONFIG, + "Can't log to stdout with RunAsDaemon set; skipping stdout"); } else { 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 (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; } if (!validate_only) { 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; } } goto cleanup; } 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; } if (!strcasecmp(smartlist_get(elts,1), "stdout")) { 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; } 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")) { 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; } if (!validate_only) { @@ -2863,15 +2873,15 @@ options_init_logs(or_options_t *options, int validate_only) if (!validate_only) add_syslog_log(levelMin, levelMax); #else - warn(LD_CONFIG, "Syslog is not supported in this compilation."); + log_warn(LD_CONFIG, "Syslog is not supported in this compilation."); #endif } else { - warn(LD_CONFIG, "Unrecognized log type %s", - (const char*)smartlist_get(elts,1)); + log_warn(LD_CONFIG, "Unrecognized log type %s", + (const char*)smartlist_get(elts,1)); if (strchr(smartlist_get(elts,1), '/') || strchr(smartlist_get(elts,1), '\\')) { - warn(LD_CONFIG, "Did you mean to say 'Log file %s' ?", - (const char *)smartlist_get(elts,1)); + log_warn(LD_CONFIG, "Did you mean to say 'Log file %s' ?", + (const char *)smartlist_get(elts,1)); } 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 ? "" : log_level_to_string(maxSeverity), 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); return -1; } @@ -2940,8 +2950,8 @@ normalize_log_options(or_options_t *options) while (opt) { if (!strcasecmp(opt->key, "LogLevel")) { - warn(LD_CONFIG, "Two LogLevel options in a row without " - "intervening LogFile or SysLog"); + log_warn(LD_CONFIG, "Two LogLevel options in a row without " + "intervening LogFile or SysLog"); opt = opt->next; } else { tor_assert(!strcasecmp(opt->key, "LogFile") || @@ -3011,7 +3021,7 @@ config_expand_exit_policy_aliases(smartlist_t *entries, int assume_action) action = ""; cp = v; } 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); return -1; } @@ -3039,7 +3049,7 @@ config_expand_exit_policy_aliases(smartlist_t *entries, int assume_action) } post = smartlist_join_strings(entries,",",0,NULL); 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(post); return expanded_any; @@ -3181,16 +3191,16 @@ config_parse_addr_policy(config_line_t *cfg, } 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); if (*nextp) { if (addr_mask_get_bits((*nextp)->msk)<0) { - warn(LD_CONFIG, "Address policy element '%s' can't be expressed " - "as a bit prefix.", ent); + log_warn(LD_CONFIG, "Address policy element '%s' can't be expressed " + "as a bit prefix.", ent); } nextp = &((*nextp)->next); } else { - warn(LD_CONFIG,"Malformed policy '%s'.", ent); + log_warn(LD_CONFIG,"Malformed policy '%s'.", ent); r = -1; } }); @@ -3308,12 +3318,12 @@ parse_redirect_line(smartlist_t *result, config_line_t *line) smartlist_split_string(elements, line->value, NULL, SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, 0); 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; } if (parse_addr_and_port_range(smartlist_get(elements,0),&r->addr,&r->mask, &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; } if (0==strcasecmp(smartlist_get(elements,1), "pass")) { @@ -3321,7 +3331,7 @@ parse_redirect_line(smartlist_t *result, config_line_t *line) } else { if (parse_addr_port(smartlist_get(elements,1),NULL,&r->addr_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; } r->is_redirect = 1; @@ -3362,7 +3372,7 @@ parse_dir_server_line(const char *line, int validate_only) smartlist_split_string(items, line, NULL, SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK, -1); 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; } @@ -3380,33 +3390,33 @@ parse_dir_server_line(const char *line, int validate_only) } 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; } addrport = smartlist_get(items, 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; } 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; } smartlist_del_keeporder(items, 0); fingerprint = smartlist_join_strings(items, "", 0, NULL); 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; } 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; } if (!validate_only) { - debug(LD_DIR, "Trusted dirserver at %s:%d (%s)", address, (int)port, - (char*)smartlist_get(items,1)); + log_debug(LD_DIR, "Trusted dirserver at %s:%d (%s)", address, (int)port, + (char*)smartlist_get(items,1)); 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) { char *fn = expand_filename(d); if (!fn) { - err(LD_CONFIG,"Failed to expand filename \"%s\".", d); + log_err(LD_CONFIG,"Failed to expand filename \"%s\".", d); return -1; } if (!options->DataDirectory && !strcmp(fn,"/.tor")) { /* If our homedir is /, we probably don't want to use it. */ /* XXXX Default to /var/lib/tor? */ - warn(LD_CONFIG, "Default DataDirectory is \"~/.tor\". This expands to " - "\"%s\", which is probably not what you want. Using \"%s/tor\" " - "instead", fn, LOCALSTATEDIR); + log_warn(LD_CONFIG, + "Default DataDirectory is \"~/.tor\". This expands to " + "\"%s\", which is probably not what you want. Using \"%s/tor\" " + "instead", fn, LOCALSTATEDIR); tor_free(fn); fn = tor_strdup(LOCALSTATEDIR"/tor"); @@ -3476,7 +3487,7 @@ validate_data_directory(or_options_t *options) return -1; tor_assert(options->DataDirectory); if (strlen(options->DataDirectory) > (512-128)) { - err(LD_CONFIG, "DataDirectory is too long."); + log_err(LD_CONFIG, "DataDirectory is too long."); return -1; } return 0; @@ -3514,13 +3525,14 @@ write_configuration_file(const char *fname, or_options_t *options) case FN_NOENT: break; 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; } } 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; } @@ -3537,7 +3549,7 @@ write_configuration_file(const char *fname, or_options_t *options) fn_tmp = tor_malloc(fn_tmp_len); while (1) { 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); goto err; } @@ -3545,7 +3557,7 @@ write_configuration_file(const char *fname, or_options_t *options) break; ++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); tor_free(fn_tmp); } @@ -3651,7 +3663,7 @@ config_parse_units(const char *val, struct unit_table_t *u, int *ok) return v; } } - warn(LD_CONFIG, "Unknown unit '%s'.", cp); + log_warn(LD_CONFIG, "Unknown unit '%s'.", cp); *ok = 0; return 0; } @@ -3678,7 +3690,7 @@ config_parse_interval(const char *s, int *ok) if (!ok) return -1; 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; return -1; } @@ -3808,12 +3820,12 @@ or_state_validate(or_state_t *old_state, or_state_t *state, int from_setconf) const char *err; tor_version_t v; 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; } if (state->TorVersion && tor_version_parse(state->TorVersion, &v)) { - warn(LD_GENERAL, "Can't parse Tor version '%s' from your state file. " - "Proceeding anyway.", state->TorVersion); + log_warn(LD_GENERAL, "Can't parse Tor version '%s' from your state file. " + "Proceeding anyway.", state->TorVersion); } return 0; } @@ -3828,9 +3840,9 @@ or_state_set(or_state_t *new_state) config_free(&state_format, global_state); global_state = new_state; 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) - warn(LD_GENERAL,"Unparseable bandwidth history state: %s",err); + log_warn(LD_GENERAL,"Unparseable bandwidth history state: %s",err); } /* DOCDOC */ @@ -3845,14 +3857,14 @@ or_state_load(void) switch (file_status(fname)) { case FN_FILE: 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; } break; case FN_NOENT: break; 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; } new_state = tor_malloc_zero(sizeof(or_state_t)); @@ -3873,9 +3885,9 @@ or_state_load(void) goto done; if (contents) - info(LD_GENERAL, "Loaded state from \"%s\"", fname); + log_info(LD_GENERAL, "Loaded state from \"%s\"", fname); else - info(LD_GENERAL, "Initialized state"); + log_info(LD_GENERAL, "Initialized state"); or_state_set(new_state); new_state = NULL; if (!contents) { @@ -3924,12 +3936,12 @@ or_state_save(void) tor_free(state); fname = get_or_state_fname(); 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(contents); return -1; } - info(LD_GENERAL, "Saved state to \"%s\"", fname); + log_info(LD_GENERAL, "Saved state to \"%s\"", fname); tor_free(fname); tor_free(contents); diff --git a/src/or/connection.c b/src/or/connection.c index fde66b858..9386a8301 100644 --- a/src/or/connection.c +++ b/src/or/connection.c @@ -51,7 +51,7 @@ conn_type_to_string(int type) case CONN_TYPE_CONTROL_LISTENER: return "Control listener"; case CONN_TYPE_CONTROL: return "Control"; 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); return buf; } @@ -134,7 +134,7 @@ conn_state_to_string(int type, int state) 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), "unknown state [%d] on unknown [%s] connection", state, conn_type_to_string(type)); @@ -191,12 +191,12 @@ connection_unregister(connection_t *conn) { if (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); } if (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); } } @@ -234,13 +234,13 @@ _connection_free(connection_t *conn) tor_free(conn->requested_resource); 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); } if (conn->type == CONN_TYPE_OR && !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); } @@ -324,9 +324,9 @@ connection_about_to_close_connection(connection_t *conn) if (CONN_IS_EDGE(conn)) { if (!conn->has_sent_end) { - warn(LD_BUG, "Harmless bug: Edge connection (marked at %s:%d) " - "hasn't sent end yet?", - conn->marked_for_close_file, conn->marked_for_close); + log_warn(LD_BUG, "Harmless bug: Edge connection (marked at %s:%d) " + "hasn't sent end yet?", + conn->marked_for_close_file, conn->marked_for_close); tor_fragile_assert(); } } @@ -371,9 +371,9 @@ connection_about_to_close_connection(connection_t *conn) if (conn->socks_request->has_finished == 0) { /* since conn gets removed right after this function finishes, * 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" - " back a socks reply.", - conn->marked_for_close_file, conn->marked_for_close); + log_warn(LD_BUG,"Bug: Closing stream (marked at %s:%d) without sending" + " back a socks reply.", + conn->marked_for_close_file, conn->marked_for_close); } else { control_event_stream_status(conn, STREAM_EVENT_CLOSED); } @@ -403,15 +403,15 @@ connection_close_immediate(connection_t *conn) { assert_connection_ok(conn,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(); return; } if (conn->outbuf_flushlen) { - info(LD_NET,"fd %d, type %s, state %s, %d bytes on outbuf.", - conn->s, conn_type_to_string(conn->type), - conn_state_to_string(conn->type, conn->state), - (int)conn->outbuf_flushlen); + log_info(LD_NET,"fd %d, type %s, state %s, %d bytes on outbuf.", + conn->s, conn_type_to_string(conn->type), + conn_state_to_string(conn->type, conn->state), + (int)conn->outbuf_flushlen); } connection_unregister(conn); @@ -515,7 +515,8 @@ connection_create_listener(const char *listenaddress, uint16_t listenport, memset(&listenaddr,0,sizeof(struct sockaddr_in)); 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; } @@ -525,15 +526,15 @@ connection_create_listener(const char *listenaddress, uint16_t listenport, listenaddr.sin_family = AF_INET; listenaddr.sin_port = htons((uint16_t) usePort); - notice(LD_NET, "Opening %s on %s:%d", - conn_type_to_string(type), address, usePort); + log_notice(LD_NET, "Opening %s on %s:%d", + conn_type_to_string(type), address, usePort); s = socket(PF_INET,SOCK_STREAM,IPPROTO_TCP); if (s < 0) { - warn(LD_NET,"Socket creation failed."); + log_warn(LD_NET,"Socket creation failed."); goto err; } 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); goto err; } @@ -551,14 +552,14 @@ connection_create_listener(const char *listenaddress, uint16_t listenport, int e = tor_socket_errno(s); if (ERRNO_IS_EADDRINUSE(e)) helpfulhint = ". Is Tor already running?"; - warn(LD_NET, "Could not bind to %s:%u: %s%s", address, usePort, - tor_socket_strerror(e), helpfulhint); + log_warn(LD_NET, "Could not bind to %s:%u: %s%s", address, usePort, + tor_socket_strerror(e), helpfulhint); goto err; } if (listen(s,SOMAXCONN) < 0) { - warn(LD_NET, "Could not listen on %s:%u: %s", address, usePort, - tor_socket_strerror(tor_socket_errno(s))); + log_warn(LD_NET, "Could not listen on %s:%u: %s", address, usePort, + tor_socket_strerror(tor_socket_errno(s))); goto err; } @@ -571,12 +572,13 @@ connection_create_listener(const char *listenaddress, uint16_t listenport, conn->port = usePort; 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); 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; connection_start_reading(conn); @@ -637,7 +639,7 @@ connection_handle_listener_read(connection_t *conn, int new_type) int e; if (news>=0) { /* 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); return 0; } @@ -645,31 +647,33 @@ connection_handle_listener_read(connection_t *conn, int new_type) if (ERRNO_IS_ACCEPT_EAGAIN(e)) { return 0; /* he hung up before we could accept(). that's fine. */ } else if (ERRNO_IS_ACCEPT_RESOURCE_LIMIT(e)) { - notice(LD_NET,"accept failed: %s. Dropping incoming connection.", - tor_socket_strerror(e)); + log_notice(LD_NET,"accept failed: %s. Dropping incoming connection.", + tor_socket_strerror(e)); return 0; } /* else there was a real error. */ - warn(LD_NET,"accept() failed: %s. Closing listener.", - tor_socket_strerror(e)); + log_warn(LD_NET,"accept() failed: %s. Closing listener.", + tor_socket_strerror(e)); connection_mark_for_close(conn); return -1; } - debug(LD_NET,"Connection accepted on socket %d (child of fd %d).", - news,conn->s); + log_debug(LD_NET, + "Connection accepted on socket %d (child of fd %d).", + news,conn->s); set_socket_nonblocking(news); 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; memset(addrbuf, 0, sizeof(addrbuf)); if (getsockname(news, (struct sockaddr*)addrbuf, &remotelen)<0) { - warn(LD_NET, "getsockname() failed."); + log_warn(LD_NET, "getsockname() failed."); } else { if (check_sockaddr_in((struct sockaddr*)addrbuf, remotelen, 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); 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 */ if (socks_policy_permits_address(ntohl(remote.sin_addr.s_addr)) == 0) { tor_inet_ntoa(&remote.sin_addr, tmpbuf, sizeof(tmpbuf)); - notice(LD_APP,"Denying socks connection from untrusted address %s.", - tmpbuf); + log_notice(LD_APP,"Denying socks connection from untrusted address %s.", + tmpbuf); tor_close_socket(news); 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 */ if (dir_policy_permits_address(ntohl(remote.sin_addr.s_addr)) == 0) { tor_inet_ntoa(&remote.sin_addr, tmpbuf, sizeof(tmpbuf)); - notice(LD_DIRSERV,"Denying dir connection from address %s.", - tmpbuf); + log_notice(LD_DIRSERV,"Denying dir connection from address %s.", + tmpbuf); tor_close_socket(news); return 0; } @@ -762,13 +766,13 @@ connection_connect(connection_t *conn, char *address, s = socket(PF_INET,SOCK_STREAM,IPPROTO_TCP); if (s < 0) { - warn(LD_NET,"Error creating network socket: %s", - tor_socket_strerror(tor_socket_errno(-1))); + log_warn(LD_NET,"Error creating network socket: %s", + tor_socket_strerror(tor_socket_errno(-1))); return -1; } else if (!SOCKET_IS_POLLABLE(s)) { - warn(LD_NET, - "Too many connections; can't create pollable connection to %s", - safe_str(address)); + log_warn(LD_NET, + "Too many connections; can't create pollable connection to %s", + safe_str(address)); tor_close_socket(s); return -1; } @@ -780,12 +784,12 @@ connection_connect(connection_t *conn, char *address, ext_addr.sin_family = AF_INET; ext_addr.sin_port = 0; if (!tor_inet_aton(options->OutboundBindAddress, &ext_addr.sin_addr)) { - warn(LD_CONFIG,"Outbound bind address '%s' didn't parse. Ignoring.", - options->OutboundBindAddress); + log_warn(LD_CONFIG,"Outbound bind address '%s' didn't parse. Ignoring.", + options->OutboundBindAddress); } else { if (bind(s, (struct sockaddr*)&ext_addr, sizeof(ext_addr)) < 0) { - warn(LD_NET,"Error binding network socket: %s", - tor_socket_strerror(tor_socket_errno(s))); + log_warn(LD_NET,"Error binding network socket: %s", + tor_socket_strerror(tor_socket_errno(s))); return -1; } } @@ -798,14 +802,15 @@ connection_connect(connection_t *conn, char *address, dest_addr.sin_port = htons(port); 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) { int e = tor_socket_errno(s); if (!ERRNO_IS_CONN_EINPROGRESS(e)) { /* yuck. kill it. */ - info(LD_NET,"connect() to %s:%u failed: %s",safe_str(address),port, - tor_socket_strerror(e)); + log_info(LD_NET, + "connect() to %s:%u failed: %s",safe_str(address),port, + tor_socket_strerror(e)); tor_close_socket(s); return -1; } else { @@ -905,8 +910,8 @@ retry_listeners(int type, config_line_t *cfg, }); if (! line) { /* This one isn't configured. Close it. */ - notice(LD_NET, "Closing %s on %s:%d", - conn_type_to_string(type), conn->address, conn->port); + log_notice(LD_NET, "Closing %s on %s:%d", + conn_type_to_string(type), conn->address, conn->port); if (replaced_conns) { smartlist_add(replaced_conns, conn); } else { @@ -915,8 +920,8 @@ retry_listeners(int type, config_line_t *cfg, } } else { /* It's configured; we don't need to launch it. */ -// debug(LD_NET, "Already have %s on %s:%d", -// conn_type_to_string(type), conn->address, conn->port); +// log_debug(LD_NET, "Already have %s on %s:%d", +// conn_type_to_string(type), conn->address, conn->port); smartlist_remove(launch, line); if (free_launch_elts) config_free_lines(line); @@ -1101,11 +1106,11 @@ connection_bucket_refill(struct timeval *now) /* refill the global buckets */ if (global_read_bucket < (int)options->BandwidthBurst) { 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) { 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 */ @@ -1267,23 +1272,24 @@ connection_read_to_buf(connection_t *conn, int *max_to_read) return connection_tls_continue_handshake(conn); } - debug(LD_NET,"%d: starting, inbuf_datalen %d (%d pending in tls object)." - " at_most %d.", - conn->s,(int)buf_datalen(conn->inbuf), - tor_tls_get_pending_bytes(conn->tls), at_most); + log_debug(LD_NET, + "%d: starting, inbuf_datalen %d (%d pending in tls object)." + " at_most %d.", + conn->s,(int)buf_datalen(conn->inbuf), + tor_tls_get_pending_bytes(conn->tls), at_most); /* else open, or closing */ result = read_to_buf_tls(conn->tls, at_most, conn->inbuf); switch (result) { case TOR_TLS_CLOSE: - info(LD_NET,"TLS connection closed on read. Closing. " - "(Nickname %s, address %s", - conn->nickname ? conn->nickname : "not set", conn->address); + log_info(LD_NET,"TLS connection closed on read. Closing. " + "(Nickname %s, address %s", + conn->nickname ? conn->nickname : "not set", conn->address); return -1; case TOR_TLS_ERROR: - info(LD_NET,"tls error. breaking (nickname %s, address %s).", - conn->nickname ? conn->nickname : "not set", conn->address); + log_info(LD_NET,"tls error. breaking (nickname %s, address %s).", + conn->nickname ? conn->nickname : "not set", conn->address); return -1; case TOR_TLS_WANTWRITE: 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. */ int r2 = read_to_buf_tls(conn->tls, pending, conn->inbuf); 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; } else { result += r2; @@ -1402,7 +1408,8 @@ connection_handle_write(connection_t *conn) /* Sometimes, "writable" means "connected". */ if (connection_state_is_connecting(conn)) { 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)) connection_edge_end_errno(conn, conn->cpath_layer); connection_mark_for_close(conn); @@ -1411,7 +1418,7 @@ connection_handle_write(connection_t *conn) if (e) { /* some sort of error, but maybe just inprogress still */ 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)) connection_edge_end_errno(conn, conn->cpath_layer); @@ -1453,19 +1460,19 @@ connection_handle_write(connection_t *conn) switch (result) { case TOR_TLS_ERROR: case TOR_TLS_CLOSE: - info(LD_NET,result==TOR_TLS_ERROR? - "tls error. breaking.":"TLS connection closed on flush"); + log_info(LD_NET,result==TOR_TLS_ERROR? + "tls error. breaking.":"TLS connection closed on flush"); /* Don't flush; connection is dead. */ connection_close_immediate(conn); connection_mark_for_close(conn); return -1; case TOR_TLS_WANTWRITE: - debug(LD_NET,"wanted write."); + log_debug(LD_NET,"wanted write."); /* we're already writing */ return 0; case TOR_TLS_WANTREAD: /* 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)) { connection_stop_writing(conn); 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 it failed, it means we have our package/delivery windows set 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), END_CIRC_REASON_INTERNAL); } 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); } return; @@ -1849,7 +1858,7 @@ client_check_address_changed(int sock) if (getsockname(sock, (struct sockaddr*)&out_addr, &out_addr_len)<0) { 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; } @@ -1908,7 +1917,7 @@ connection_process_inbuf(connection_t *conn, int package_partial) case CONN_TYPE_CONTROL: return connection_control_process_inbuf(conn); 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(); return -1; } @@ -1942,7 +1951,7 @@ connection_finished_flushing(connection_t *conn) case CONN_TYPE_CONTROL: return connection_control_finished_flushing(conn); 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(); return -1; } @@ -1967,7 +1976,7 @@ connection_finished_connecting(connection_t *conn) case CONN_TYPE_DIR: return connection_dir_finished_connecting(conn); 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(); return -1; } @@ -1992,7 +2001,7 @@ connection_reached_eof(connection_t *conn) case CONN_TYPE_CONTROL: return connection_control_reached_eof(conn); 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(); return -1; } diff --git a/src/or/connection_edge.c b/src/or/connection_edge.c index a38984ab7..f3d6fffd1 100644 --- a/src/or/connection_edge.c +++ b/src/or/connection_edge.c @@ -41,8 +41,9 @@ _connection_mark_unattached_ap(connection_t *conn, int endreason, connection_edge_end_reason_socks5_response(endreason); if (endreason == END_STREAM_REASON_ALREADY_SOCKS_REPLIED) - warn(LD_BUG,"Bug: stream (marked at %s:%d) sending two socks replies?", - file, line); + log_warn(LD_BUG, + "Bug: stream (marked at %s:%d) sending two socks replies?", + file, line); if (conn->socks_request->command == SOCKS_COMMAND_CONNECT) 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. */ 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) { /* only mark it if not already marked. it's possible to * 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_RESOLVE_WAIT: case AP_CONN_STATE_CONTROLLER_WAIT: - info(LD_EDGE,"data from edge while in '%s' state. Leaving it on buffer.", - conn_state_to_string(conn->type, conn->state)); + log_info(LD_EDGE, + "data from edge while in '%s' state. Leaving it on buffer.", + conn_state_to_string(conn->type, conn->state)); 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(); connection_edge_end(conn, END_STREAM_REASON_INTERNAL, conn->cpath_layer); 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)); if (!conn->marked_for_close) { - info(LD_EDGE, - "CircID %d: At an edge. Marking connection for close.", circ_id); + log_info(LD_EDGE, + "CircID %d: At an edge. Marking connection for close.", circ_id); if (conn->type == CONN_TYPE_AP) { connection_mark_unattached_ap(conn, END_STREAM_REASON_DESTROY); } else { @@ -178,16 +180,16 @@ connection_edge_end(connection_t *conn, char reason, crypt_path_t *cpath_layer) circuit_t *circ; if (conn->has_sent_end) { - warn(LD_BUG,"Harmless bug: Calling connection_edge_end (reason %d) " - "on an already ended stream?", reason); + log_warn(LD_BUG,"Harmless bug: Calling connection_edge_end (reason %d) " + "on an already ended stream?", reason); tor_fragile_assert(); return -1; } if (conn->marked_for_close) { - warn(LD_BUG, - "Bug: called on conn that's already marked for close at %s:%d.", - conn->marked_for_close_file, conn->marked_for_close); + log_warn(LD_BUG, + "Bug: called on conn that's already marked for close at %s:%d.", + conn->marked_for_close_file, conn->marked_for_close); 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); 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, payload, payload_len, cpath_layer); } 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; @@ -256,7 +258,7 @@ connection_edge_finished_flushing(connection_t *conn) connection_stop_writing(conn); return 0; 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(); return -1; } @@ -278,8 +280,8 @@ connection_edge_finished_connecting(connection_t *conn) in.s_addr = htonl(conn->addr); tor_inet_ntoa(&in,valbuf,sizeof(valbuf)); - info(LD_EXIT,"Exit connection to %s:%u (%s) established.", - safe_str(conn->address),conn->port,safe_str(valbuf)); + log_info(LD_EXIT,"Exit connection to %s:%u (%s) established.", + safe_str(conn->address),conn->port,safe_str(valbuf)); conn->state = EXIT_CONN_STATE_OPEN; connection_watch_events(conn, EV_READ); /* stop writing, continue reading */ @@ -334,7 +336,7 @@ connection_ap_expire_beginning(void) continue; if (conn->state == AP_CONN_STATE_CONTROLLER_WAIT) { 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); } continue; @@ -347,17 +349,18 @@ connection_ap_expire_beginning(void) continue; circ = circuit_get_by_edge_conn(conn); if (!circ) { /* it's vanished? */ - info(LD_APP,"Conn is waiting (address %s), but lost its circ.", - safe_str(conn->socks_request->address)); + log_info(LD_APP,"Conn is waiting (address %s), but lost its circ.", + safe_str(conn->socks_request->address)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT); continue; } if (circ->purpose == CIRCUIT_PURPOSE_C_REND_JOINED) { if (now - conn->timestamp_lastread > 45) { - notice(LD_REND, "Rend stream is %d seconds late. Giving up on address" - " '%s.onion'.", - (int)(now - conn->timestamp_lastread), - safe_str(conn->socks_request->address)); + log_notice(LD_REND, + "Rend stream is %d seconds late. Giving up on address" + " '%s.onion'.", + (int)(now - conn->timestamp_lastread), + safe_str(conn->socks_request->address)); connection_edge_end(conn, END_STREAM_REASON_TIMEOUT, conn->cpath_layer); 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); nickname = build_state_get_exit_nickname(circ->build_state); - notice(LD_APP,"We tried for %d seconds to connect to '%s' using exit '%s'." - " Retrying on a new circuit.", - (int)(now - conn->timestamp_lastread), - safe_str(conn->socks_request->address), - nickname ? nickname : "*unnamed*"); + log_notice(LD_APP, + "We tried for %d seconds to connect to '%s' using exit '%s'." + " Retrying on a new circuit.", + (int)(now - conn->timestamp_lastread), + safe_str(conn->socks_request->address), + nickname ? nickname : "*unnamed*"); /* send an end down the circuit */ connection_edge_end(conn, END_STREAM_REASON_TIMEOUT, conn->cpath_layer); /* 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) return; /* done, no rewrite needed */ - info(LD_APP, "Addressmap: rewriting '%s' to '%s'", - safe_str(address), safe_str(ent->new_address)); + log_info(LD_APP, "Addressmap: rewriting '%s' to '%s'", + safe_str(address), safe_str(ent->new_address)); strlcpy(address, ent->new_address, maxlen); } - warn(LD_CONFIG, - "Loop detected: we've rewritten '%s' 16 times! Using it as-is.", - safe_str(address)); + log_warn(LD_CONFIG, + "Loop detected: we've rewritten '%s' 16 times! Using it as-is.", + safe_str(address)); /* 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); } else if (ent->new_address) { /* we need to clean up the old mapping. */ if (expires > 1) { - info(LD_APP,"Temporary addressmap ('%s' to '%s') not performed, " - "since it's already mapped to '%s'", + log_info(LD_APP,"Temporary addressmap ('%s' to '%s') not performed, " + "since it's already mapped to '%s'", safe_str(address), safe_str(new_address), safe_str(ent->new_address)); tor_free(new_address); return; @@ -661,8 +665,8 @@ addressmap_register(const char *address, char *new_address, time_t expires) ent->expires = expires==2 ? 1 : expires; ent->num_resolve_failures = 0; - info(LD_CONFIG, "Addressmap: (re)mapped '%s' to '%s'", - safe_str(address), safe_str(ent->new_address)); + log_info(LD_CONFIG, "Addressmap: (re)mapped '%s' to '%s'", + safe_str(address), safe_str(ent->new_address)); 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); } ++ent->num_resolve_failures; - info(LD_APP, "Address %s now has %d resolve failures.", - safe_str(address), ent->num_resolve_failures); + log_info(LD_APP, "Address %s now has %d resolve failures.", + safe_str(address), ent->num_resolve_failures); return ent->num_resolve_failures; } @@ -807,7 +811,7 @@ addressmap_get_virtual_address(int type) } return tor_strdup(buf); } else { - warn(LD_BUG, "Called with unsupported address type (%d)", type); + log_warn(LD_BUG, "Called with unsupported address type (%d)", type); return NULL; } } @@ -846,10 +850,11 @@ addressmap_register_virtual_address(int type, char *new_address) tor_free(new_address); return tor_strdup(*addrp); } else - warn(LD_BUG, "Internal confusion: I thought that '%s' was mapped to " - "by '%s', but '%s' really maps to '%s'. This is a harmless bug.", - safe_str(new_address), safe_str(*addrp), safe_str(*addrp), - ent?safe_str(ent->new_address):"(nothing)"); + log_warn(LD_BUG, + "Internal confusion: I thought that '%s' was mapped to by " + "'%s', but '%s' really maps to '%s'. This is a harmless bug.", + safe_str(new_address), safe_str(*addrp), safe_str(*addrp), + ent?safe_str(ent->new_address):"(nothing)"); } tor_free(*addrp); @@ -940,8 +945,8 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn) hostname_type_t addresstype; tor_strlower(socks->address); /* normalize it */ - debug(LD_APP,"Client asked for %s:%d", safe_str(socks->address), - socks->port); + log_debug(LD_APP,"Client asked for %s:%d", safe_str(socks->address), + socks->port); /* For address map controls, remap the 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 * information. */ - warn(LD_APP,"Missing mapping for virtual address '%s'. Refusing.", - socks->address); /* don't safe_str() this yet. */ + log_warn(LD_APP,"Missing mapping for virtual address '%s'. Refusing.", + socks->address); /* don't safe_str() this yet. */ connection_mark_unattached_ap(conn, END_STREAM_REASON_INTERNAL); return -1; } @@ -964,7 +969,7 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn) addresstype = parse_extended_hostname(socks->address); 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); return -1; } @@ -978,8 +983,8 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn) conn->chosen_exit_name = tor_strdup(s+1); *s = 0; } else { - warn(LD_APP,"Malformed exit address '%s.exit'. Refusing.", - safe_str(socks->address)); + log_warn(LD_APP,"Malformed exit address '%s.exit'. Refusing.", + safe_str(socks->address)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); return -1; } @@ -994,9 +999,9 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn) in.s_addr = htonl(r->addr); strlcpy(socks->address, inet_ntoa(in), sizeof(socks->address)); } else { - warn(LD_APP, - "Unrecognized server in exit address '%s.exit'. Refusing.", - safe_str(socks->address)); + log_warn(LD_APP, + "Unrecognized server in exit address '%s.exit'. Refusing.", + safe_str(socks->address)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); 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) */ if (address_is_invalid_destination(socks->address)) { - warn(LD_APP,"Destination '%s' seems to be an invalid hostname. Failing.", - safe_str(socks->address)); + log_warn(LD_APP, + "Destination '%s' seems to be an invalid hostname. Failing.", + safe_str(socks->address)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); return -1; } @@ -1018,7 +1024,7 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn) struct in_addr in; /* Reply to resolves immediately if we can. */ 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, 0,NULL,-1); 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 */ } else { /* socks->command == SOCKS_COMMAND_CONNECT */ 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); return -1; } @@ -1046,8 +1052,9 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn) routerinfo_t *r = router_find_exact_exit_enclave(socks->address, socks->port); if (r) { - info(LD_APP,"Redirecting address %s to exit at enclave router %s", - safe_str(socks->address), r->nickname); + log_info(LD_APP, + "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 routers with this nickname */ conn->chosen_exit_name = @@ -1072,7 +1079,8 @@ connection_ap_handshake_rewrite_and_attach(connection_t *conn) if (socks->command == SOCKS_COMMAND_RESOLVE) { /* if it's a resolve request, fail it right now, rather than * 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, 0,NULL,-1); 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)); - info(LD_REND,"Got a hidden service request for ID '%s'", - safe_str(conn->rend_query)); + log_info(LD_REND,"Got a hidden service request for ID '%s'", + safe_str(conn->rend_query)); /* see if we already have it cached */ r = rend_cache_lookup_entry(conn->rend_query, -1, &entry); if (r<0) { - warn(LD_BUG,"Bug: Invalid service name '%s'", - safe_str(conn->rend_query)); + log_warn(LD_BUG,"Bug: Invalid service name '%s'", + safe_str(conn->rend_query)); connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL); return -1; } if (r==0) { conn->state = AP_CONN_STATE_RENDDESC_WAIT; - info(LD_REND, "Unknown descriptor %s. Fetching.", - safe_str(conn->rend_query)); + log_info(LD_REND, "Unknown descriptor %s. Fetching.", + safe_str(conn->rend_query)); rend_client_refetch_renddesc(conn->rend_query); } else { /* r > 0 */ #define NUM_SECONDS_BEFORE_REFETCH (60*15) if (time(NULL) - entry->received < NUM_SECONDS_BEFORE_REFETCH) { 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) { connection_mark_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH); return -1; } } else { conn->state = AP_CONN_STATE_RENDDESC_WAIT; - info(LD_REND, "Stale descriptor %s. Refetching.", - safe_str(conn->rend_query)); + log_info(LD_REND, "Stale descriptor %s. Refetching.", + safe_str(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); socks = conn->socks_request; - debug(LD_APP,"entered."); + log_debug(LD_APP,"entered."); sockshere = fetch_from_buf_socks(conn->inbuf, socks, options->TestSocks); 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 */ socks->replylen = 0; } else { - debug(LD_APP,"socks handshake not all here yet."); + log_debug(LD_APP,"socks handshake not all here yet."); } return 0; } else if (sockshere == -1) { 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, SOCKS5_GENERAL_ERROR); } 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_mark_unattached_ap(conn, @@ -1192,7 +1200,7 @@ again: test_stream_id = circ->next_stream_id++; if (++attempts > 1<<16) { /* 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; } 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); 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, 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->deliver_window = STREAMWINDOW_START; ap_conn->state = AP_CONN_STATE_CONNECT_WAIT; - info(LD_APP,"Address/port sent, ap socket %d, n_circ_id %d", - ap_conn->s, circ->n_circ_id); + log_info(LD_APP,"Address/port sent, ap socket %d, n_circ_id %d", + ap_conn->s, circ->n_circ_id); control_event_stream_status(ap_conn, STREAM_EVENT_SENT_CONNECT); return 0; } @@ -1275,15 +1284,16 @@ connection_ap_handshake_send_resolve(connection_t *ap_conn, circuit_t *circ) payload_len = strlen(string_addr)+1; 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, string_addr, payload_len, ap_conn->cpath_layer) < 0) return -1; /* circuit is closed, don't continue */ ap_conn->state = AP_CONN_STATE_RESOLVE_WAIT; - info(LD_APP,"Address sent for resolve, ap socket %d, n_circ_id %d", - ap_conn->s, circ->n_circ_id); + log_info(LD_APP,"Address sent for resolve, ap socket %d, n_circ_id %d", + ap_conn->s, circ->n_circ_id); control_event_stream_status(ap_conn, STREAM_EVENT_SENT_RESOLVE); return 0; } @@ -1301,11 +1311,12 @@ connection_ap_make_bridge(char *address, uint16_t port) connection_t *conn; 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) { - warn(LD_NET,"Couldn't construct socketpair (%s). Network down? Delaying.", - tor_socket_strerror(-err)); + log_warn(LD_NET, + "Couldn't construct socketpair (%s). Network down? Delaying.", + tor_socket_strerror(-err)); return -1; } @@ -1345,7 +1356,7 @@ connection_ap_make_bridge(char *address, uint16_t port) return -1; } - info(LD_APP,"... AP bridge created and connected."); + log_info(LD_APP,"... AP bridge created and connected."); 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); if (conn->socks_request->has_finished) { - warn(LD_BUG, "Harmless bug: duplicate calls to " - "connection_ap_handshake_socks_reply."); + log_warn(LD_BUG, "Harmless bug: duplicate calls to " + "connection_ap_handshake_socks_reply."); return; } 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)) { - warn(LD_PROTOCOL,"relay begin cell has no \\0. Dropping."); + log_warn(LD_PROTOCOL,"relay begin cell has no \\0. Dropping."); return 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. " - "Dropping."); + log_warn(LD_PROTOCOL,"Unable to parse addr:port in relay begin cell. " + "Dropping."); return 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); 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->purpose = EXIT_PURPOSE_CONNECT; @@ -1520,7 +1531,7 @@ connection_exit_begin_conn(cell_t *cell, circuit_t *circ) n_stream->deliver_window = STREAMWINDOW_START; 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->state = EXIT_CONN_STATE_CONNECTING; 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)); assert_circuit_ok(circ); 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, n_stream->cpath_layer); connection_free(n_stream); @@ -1538,7 +1550,7 @@ connection_exit_begin_conn(cell_t *cell, circuit_t *circ) return 0; } 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 */ /* 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) && router_compare_to_my_exit_policy(conn)) { - info(LD_EXIT,"%s:%d failed exit policy. Closing.", - safe_str(conn->address), conn->port); + log_info(LD_EXIT,"%s:%d failed exit policy. Closing.", + safe_str(conn->address), conn->port); connection_edge_end(conn, END_STREAM_REASON_EXITPOLICY, conn->cpath_layer); circuit_detach_stream(circuit_get_by_edge_conn(conn), conn); connection_free(conn); @@ -1673,15 +1685,16 @@ connection_exit_connect(connection_t *conn) port = r->port_dest; in.s_addr = htonl(addr); tor_inet_ntoa(&in, tmpbuf, sizeof(tmpbuf)); - debug(LD_EXIT, "Redirecting connection from %s:%d to %s:%d", - safe_str(conn->address), conn->port, safe_str(tmpbuf), port); + log_debug(LD_EXIT, "Redirecting connection from %s:%d to %s:%d", + safe_str(conn->address), conn->port, + safe_str(tmpbuf), port); } break; } }); } - debug(LD_EXIT,"about to try connecting"); + log_debug(LD_EXIT,"about to try connecting"); switch (connection_connect(conn, conn->address, addr, port)) { case -1: connection_edge_end_errno(conn, conn->cpath_layer); @@ -1701,7 +1714,7 @@ connection_exit_connect(connection_t *conn) conn->state = EXIT_CONN_STATE_OPEN; if (connection_wants_to_flush(conn)) { /* 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_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 (router_get_by_nickname(conn->chosen_exit_name, 1) != exit) { /* doesn't match */ - debug(LD_APP,"Requested node '%s', considering node '%s'. No.", - conn->chosen_exit_name, exit->nickname); + log_debug(LD_APP,"Requested node '%s', considering node '%s'. No.", + conn->chosen_exit_name, exit->nickname); return 0; } } @@ -1827,7 +1840,7 @@ socks_policy_permits_address(uint32_t addr) return 0; else if (a==ADDR_POLICY_ACCEPTED) 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; } diff --git a/src/or/connection_or.c b/src/or/connection_or.c index a58abc587..07b43dfbc 100644 --- a/src/or/connection_or.c +++ b/src/or/connection_or.c @@ -137,7 +137,7 @@ cell_unpack(cell_t *dest, const char *src) int 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); return 0; } @@ -160,28 +160,29 @@ connection_or_read_proxy_response(connection_t *conn) &headers, MAX_HEADERS_SIZE, NULL, NULL, 10000, 0)) { case -1: /* overflow */ - warn(LD_PROTOCOL,"Your https proxy sent back an oversized response. " - "Closing."); + log_warn(LD_PROTOCOL, + "Your https proxy sent back an oversized response. Closing."); return -1; 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; /* case 1, fall through */ } if (parse_http_response(headers, &status_code, &date_header, &compression, &reason) < 0) { - warn(LD_OR,"Unparseable headers from proxy (connecting to '%s'). Closing.", - conn->address); + log_warn(LD_OR, + "Unparseable headers from proxy (connecting to '%s'). Closing.", + conn->address); tor_free(headers); return -1; } if (!reason) reason = tor_strdup("[no reason given]"); if (status_code == 200) { - info(LD_OR, - "HTTPS connect to '%s' successful! (200 \"%s\") Starting TLS.", - conn->address, reason); + log_info(LD_OR, + "HTTPS connect to '%s' successful! (200 \"%s\") Starting TLS.", + conn->address, reason); tor_free(reason); if (connection_tls_start_handshake(conn, 0) < 0) { /* TLS handshaking error of some kind. */ @@ -192,10 +193,10 @@ connection_or_read_proxy_response(connection_t *conn) return 0; } /* else, bad news on the status code */ - warn(LD_OR, - "The https proxy sent back an unexpected status code %d (\"%s\"). " - "Closing.", - status_code, reason); + log_warn(LD_OR, + "The https proxy sent back an unexpected status code %d (\"%s\"). " + "Closing.", + status_code, reason); tor_free(reason); connection_mark_for_close(conn); return -1; @@ -240,7 +241,7 @@ connection_or_finished_flushing(connection_t *conn) switch (conn->state) { 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; connection_stop_writing(conn); break; @@ -248,7 +249,7 @@ connection_or_finished_flushing(connection_t *conn) connection_stop_writing(conn); break; 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(); return -1; } @@ -264,8 +265,8 @@ connection_or_finished_connecting(connection_t *conn) tor_assert(conn->type == CONN_TYPE_OR); tor_assert(conn->state == OR_CONN_STATE_CONNECTING); - debug(LD_OR,"OR connect() to router at %s:%u finished.", - conn->address,conn->port); + log_debug(LD_OR,"OR connect() to router at %s:%u finished.", + conn->address,conn->port); if (get_options()->HttpsProxy) { char buf[1024]; @@ -280,7 +281,7 @@ connection_or_finished_connecting(connection_t *conn) if (authenticator) { base64_authenticator = alloc_http_authenticator(authenticator); if (!base64_authenticator) - warn(LD_OR, "Encoding https authenticator failed"); + log_warn(LD_OR, "Encoding https authenticator failed"); } if (base64_authenticator) { 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()) && 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; } @@ -486,11 +487,11 @@ connection_tls_start_handshake(connection_t *conn, int receiving) conn->state = OR_CONN_STATE_HANDSHAKING; conn->tls = tor_tls_new(conn->s, receiving, 0); if (!conn->tls) { - warn(LD_BUG,"tor_tls_new failed. Closing."); + log_warn(LD_BUG,"tor_tls_new failed. Closing."); return -1; } 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) { return -1; } @@ -509,16 +510,16 @@ connection_tls_continue_handshake(connection_t *conn) switch (tor_tls_handshake(conn->tls)) { case TOR_TLS_ERROR: case TOR_TLS_CLOSE: - info(LD_OR,"tls error. breaking connection."); + log_info(LD_OR,"tls error. breaking connection."); return -1; case TOR_TLS_DONE: return connection_tls_finish_handshake(conn); case TOR_TLS_WANTWRITE: connection_start_writing(conn); - debug(LD_OR,"wanted write"); + log_debug(LD_OR,"wanted write"); return 0; case TOR_TLS_WANTREAD: /* handshaking conns are *always* reading */ - debug(LD_OR,"wanted read"); + log_debug(LD_OR,"wanted read"); return 0; } return 0; @@ -570,7 +571,7 @@ connection_or_check_valid_handshake(connection_t *conn, char *digest_rcvd) check_no_tls_errors(); 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; } check_no_tls_errors(); @@ -581,8 +582,8 @@ connection_or_check_valid_handshake(connection_t *conn, char *digest_rcvd) return -1; } check_no_tls_errors(); - debug(LD_OR, "Other side (%s:%d) claims to be router '%s'", - conn->address, conn->port, nickname); + log_debug(LD_OR, "Other side (%s:%d) claims to be router '%s'", + conn->address, conn->port, nickname); 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)," @@ -591,7 +592,7 @@ connection_or_check_valid_handshake(connection_t *conn, char *digest_rcvd) return -1; } 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); 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]; 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) return -1; @@ -669,8 +670,9 @@ connection_tls_finish_handshake(connection_t *conn) #if 0 connection_t *c; if ((c=connection_or_get_by_identity_digest(digest_rcvd))) { - debug(LD_OR,"Router '%s' is already connected on fd %d. Dropping fd %d.", - c->nickname, c->s, conn->s); + log_debug(LD_OR, + "Router '%s' is already connected on fd %d. Dropping fd %d.", + c->nickname, c->s, conn->s); return -1; } #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 (!conn->marked_for_close) { /* this connection is broken. remove it. */ - warn(LD_BUG, - "Bug: unhandled error on write for OR conn (fd %d); removing", - conn->s); + log_warn(LD_BUG, + "Bug: unhandled error on write for OR conn (fd %d); removing", + conn->s); tor_fragile_assert(); 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? */ @@ -761,9 +763,10 @@ connection_or_process_cells_from_inbuf(connection_t *conn) cell_t cell; loop: - debug(LD_OR,"%d: starting, inbuf_datalen %d (%d pending in tls object).", - conn->s,(int)buf_datalen(conn->inbuf), - tor_tls_get_pending_bytes(conn->tls)); + log_debug(LD_OR, + "%d: starting, inbuf_datalen %d (%d pending in tls object).", + conn->s,(int)buf_datalen(conn->inbuf), + tor_tls_get_pending_bytes(conn->tls)); if (buf_datalen(conn->inbuf) < CELL_NETWORK_SIZE) /* whole response available? */ 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.command = CELL_DESTROY; 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); return 0; } diff --git a/src/or/control.c b/src/or/control.c index 287550549..392a1061d 100644 --- a/src/or/control.c +++ b/src/or/control.c @@ -700,7 +700,7 @@ control_setconf_helper(connection_t *conn, uint32_t len, char *body, *outp = '\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", conn); tor_free(config); @@ -709,7 +709,7 @@ control_setconf_helper(connection_t *conn, uint32_t len, char *body, tor_free(config); } else { 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"); 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) { int v0_err; 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) { case -1: 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 received[DIGEST_LEN]; 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; } 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; ok: - info(LD_CONTROL, "Authenticated control connection (%d)", conn->s); + log_info(LD_CONTROL, "Authenticated control connection (%d)", conn->s); send_control_done(conn); if (STATE_IS_V0(conn->state)) 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 *to = smartlist_get(elts,1); 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); } 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")) { const char *address = addressmap_register_virtual_address( !strcmp(from,".") ? RESOLVED_TYPE_HOSTNAME : RESOLVED_TYPE_IPV4, tor_strdup(to)); if (!address) { - warn(LD_CONTROL, - "Unable to allocate address for '%s' in MapAddress msg", - safe_str(line)); + log_warn(LD_CONTROL, + "Unable to allocate address for '%s' in MapAddress msg", + safe_str(line)); } else { size_t anslen = strlen(address)+strlen(to)+8; char *ans = tor_malloc(anslen); @@ -1201,7 +1205,8 @@ handle_control_mapaddress(connection_t *conn, uint32_t len, const char *body) } } } 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_clear(elts); @@ -1375,8 +1380,8 @@ handle_getinfo_helper(const char *question, char **answer) case AP_CONN_STATE_OPEN: state = "SUCCEEDED"; break; default: - warn(LD_BUG, "Asked for stream in unknown state %d", - conns[i]->state); + log_warn(LD_BUG, "Asked for stream in unknown state %d", + conns[i]->state); continue; } 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) { circuit_set_state(circ, CIRCUIT_STATE_BUILDING); if (circuit_send_next_onion_skin(circ) < 0) { - info(LD_CONTROL, - "send_next_onion_skin failed; circuit marked for closing."); + log_info(LD_CONTROL, + "send_next_onion_skin failed; circuit marked for closing."); circuit_mark_for_close(circ, END_CIRC_AT_ORIGIN); if (v0) 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")) safe = 1; else - info(LD_CONTROL, "Skipping unknown option %s", - (char*)smartlist_get(args,i)); + log_info(LD_CONTROL, "Skipping unknown option %s", + (char*)smartlist_get(args,i)); } } 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 (conn->incoming_cmd) { - warn(LD_CONTROL, "Dropping incomplete fragmented command"); + log_warn(LD_CONTROL, "Dropping incomplete fragmented command"); tor_free(conn->incoming_cmd); } if (body_len < 6) { @@ -2058,7 +2063,7 @@ connection_control_reached_eof(connection_t *conn) tor_assert(conn); 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); return 0; } @@ -2223,13 +2228,14 @@ connection_control_process_inbuf_v0(connection_t *conn) { case -2: tor_free(body); - info(LD_CONTROL, "Detected v1 control protocol on connection (fd %d)", - conn->s); + log_info(LD_CONTROL, + "Detected v1 control protocol on connection (fd %d)", + conn->s); conn->state = CONTROL_CONN_STATE_NEEDAUTH_V1; return connection_control_process_inbuf_v1(conn); case -1: tor_free(body); - warn(LD_CONTROL, "Error in control command. Failing."); + log_warn(LD_CONTROL, "Error in control command. Failing."); return -1; case 0: /* Control command not all here yet. Wait. */ @@ -2245,8 +2251,8 @@ connection_control_process_inbuf_v0(connection_t *conn) * commands will be considered. */ if (conn->state == CONTROL_CONN_STATE_NEEDAUTH_V0 && command_type != CONTROL0_CMD_AUTHENTICATE) { - info(LD_CONTROL, "Rejecting '%s' command; authentication needed.", - control_cmd_to_string(command_type)); + log_info(LD_CONTROL, "Rejecting '%s' command; authentication needed.", + control_cmd_to_string(command_type)); send_control0_error(conn, ERR_UNAUTHORIZED, "Authentication required"); tor_free(body); goto again; @@ -2265,7 +2271,7 @@ connection_control_process_inbuf_v0(connection_t *conn) body = conn->incoming_cmd; conn->incoming_cmd = NULL; } 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); } @@ -2333,18 +2339,19 @@ connection_control_process_inbuf_v0(connection_t *conn) case CONTROL0_CMD_CONFVALUE: case CONTROL0_CMD_EVENT: case CONTROL0_CMD_INFOVALUE: - warn(LD_CONTROL, "Received client-only '%s' command; ignoring.", - control_cmd_to_string(command_type)); + log_warn(LD_CONTROL, "Received client-only '%s' command; ignoring.", + control_cmd_to_string(command_type)); send_control0_error(conn, ERR_UNRECOGNIZED_TYPE, "Command type only valid from server to tor client"); break; case CONTROL0_CMD_FRAGMENTHEADER: 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."); default: - warn(LD_CONTROL, "Received unrecognized command type %d; ignoring.", - (int)command_type); + log_warn(LD_CONTROL, "Received unrecognized command type %d; ignoring.", + (int)command_type); send_control0_error(conn, ERR_UNRECOGNIZED_TYPE, "Unrecognized command type"); 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_CLOSED: status = "CLOSED"; break; default: - warn(LD_BUG, "Unrecognized status code %d", (int)tp); + log_warn(LD_BUG, "Unrecognized status code %d", (int)tp); return 0; } 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_FAILED_RETRIABLE: status = "DETACHED"; break; default: - warn(LD_BUG, "Unrecognized status code %d", (int)tp); + log_warn(LD_BUG, "Unrecognized status code %d", (int)tp); return 0; } 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_CLOSED: status = "CLOSED"; break; default: - warn(LD_BUG, "Unrecognized status code %d", (int)tp); + log_warn(LD_BUG, "Unrecognized status code %d", (int)tp); return 0; } send_control1_event(EVENT_OR_CONN_STATUS, @@ -2731,7 +2738,7 @@ init_cookie_authentication(int enabled) authentication_cookie_is_set = 1; if (write_bytes_to_file(fname, authentication_cookie, AUTHENTICATION_COOKIE_LEN, 1)) { - warn(LD_FS,"Error writing authentication cookie."); + log_warn(LD_FS,"Error writing authentication cookie."); return -1; } diff --git a/src/or/cpuworker.c b/src/or/cpuworker.c index 69d391955..9cc8dc47d 100644 --- a/src/or/cpuworker.c +++ b/src/or/cpuworker.c @@ -85,7 +85,8 @@ tag_unpack(const char *tag, uint32_t *addr, uint16_t *port, uint16_t *circ_id) in.s_addr = htonl(*addr); 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 @@ -111,12 +112,12 @@ cpuworkers_rotate(void) int 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) { /* the circ associated with this cpuworker will have to wait until * it gets culled in run_connection_housekeeping(), since we have * 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--; @@ -166,8 +167,9 @@ connection_cpu_process_inbuf(connection_t *conn) circ = circuit_get_by_circid_orconn(circ_id, p_conn); if (success == 0) { - debug(LD_OR, - "decoding onionskin failed. (Old key or bad software.) Closing."); + log_debug(LD_OR, + "decoding onionskin failed. " + "(Old key or bad software.) Closing."); if (circ) circuit_mark_for_close(circ, END_CIRC_REASON_TORPROTOCOL); 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 * 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; } tor_assert(circ->p_conn); if (onionskin_answer(circ, CELL_CREATED, buf+TAG_LEN, 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); goto done_processing; } - debug(LD_OR,"onionskin_answer succeeded. Yay."); + log_debug(LD_OR,"onionskin_answer succeeded. Yay."); } else { 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) { // log_fn(LOG_ERR,"read type failed. Exiting."); if (r == 0) { - info(LD_OR,"CPU worker exiting because Tor process closed connection " - "(either rotated keys or died)."); + log_info(LD_OR, + "CPU worker exiting because Tor process closed connection " + "(either rotated keys or died)."); } else { - info(LD_OR,"CPU worker editing because of error on connection to Tor " - "process."); - info(LD_OR,"(Error on %d was %s)", - fd, tor_socket_strerror(tor_socket_errno(fd))); + log_info(LD_OR, + "CPU worker editing because of error on connection to Tor " + "process."); + log_info(LD_OR,"(Error on %d was %s)", + fd, tor_socket_strerror(tor_socket_errno(fd))); } goto end; } tor_assert(question_type == CPUWORKER_TASK_ONION); 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; } if (read_all(fd, question, ONIONSKIN_CHALLENGE_LEN, 1) != ONIONSKIN_CHALLENGE_LEN) { - err(LD_BUG,"read question failed. Exiting."); + log_err(LD_BUG,"read question failed. Exiting."); goto end; } @@ -281,21 +285,21 @@ cpuworker_main(void *data) if (onion_skin_server_handshake(question, onion_key, last_onion_key, reply_to_proxy, keys, CPATH_KEY_MATERIAL_LEN) < 0) { /* 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 */ } else { /* success */ - debug(LD_OR,"onion_skin_server_handshake succeeded."); + log_debug(LD_OR,"onion_skin_server_handshake succeeded."); buf[0] = 1; /* 1 means success */ memcpy(buf+1,tag,TAG_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); } 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; } - debug(LD_OR,"finished writing response."); + log_debug(LD_OR,"finished writing response."); } } end: @@ -321,15 +325,15 @@ spawn_cpuworker(void) fdarray = tor_malloc(sizeof(int)*2); if ((err = tor_socketpair(AF_UNIX, SOCK_STREAM, 0, fdarray)) < 0) { - warn(LD_NET, "Couldn't construct socketpair: %s", - tor_socket_strerror(-err)); + log_warn(LD_NET, "Couldn't construct socketpair: %s", + tor_socket_strerror(-err)); tor_free(fdarray); return -1; } fd = fdarray[0]; 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 tor_close_socket(fdarray[1]); /* don't need the worker's side of the pipe */ tor_free(fdarray); @@ -344,7 +348,7 @@ spawn_cpuworker(void) conn->address = tor_strdup("localhost"); 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 */ return -1; } @@ -370,7 +374,7 @@ spawn_enough_cpuworkers(void) while (num_cpuworkers < num_cpuworkers_needed) { if (spawn_cpuworker() < 0) { - warn(LD_GENERAL,"Spawn failed. Will try again later."); + log_warn(LD_GENERAL,"Spawn failed. Will try again later."); return; } num_cpuworkers++; @@ -391,7 +395,7 @@ process_pending_task(connection_t *cpuworker) if (!circ) return; 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 */ @@ -415,8 +419,8 @@ cull_wedged_cpuworkers(void) conn->type == CONN_TYPE_CPUWORKER && conn->state == CPUWORKER_STATE_BUSY_ONION && conn->timestamp_lastwritten + CPUWORKER_BUSY_TIMEOUT < now) { - notice(LD_BUG, - "Bug: closing wedged cpuworker. Can somebody find the bug?"); + log_notice(LD_BUG, + "Bug: closing wedged cpuworker. Can somebody find the bug?"); num_cpuworkers_busy--; num_cpuworkers--; connection_mark_for_close(conn); @@ -447,7 +451,7 @@ assign_to_cpuworker(connection_t *cpuworker, uint8_t question_type, tor_assert(circ->onionskin); 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) return -1; return 0; @@ -460,7 +464,7 @@ assign_to_cpuworker(connection_t *cpuworker, uint8_t question_type, tor_assert(cpuworker); 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; } tag_pack(tag, circ->p_conn->addr, circ->p_conn->port, circ->p_circ_id); |