mirror of
https://gitlab.torproject.org/tpo/core/tor.git
synced 2024-12-06 19:41:15 +01:00
Switch remaining files to new log interface.
svn:r5315
This commit is contained in:
@@ -87,6 +87,8 @@
|
||||
/** Generic edge-connection functionality. */
|
||||
#define LD_EDGE (1u<<16)
|
||||
#define LD_EXIT LD_EDGE
|
||||
/** Bandwidth accounting. */
|
||||
#define LD_ACCT (1u<<17)
|
||||
|
||||
typedef void (*log_callback)(int severity, unsigned int domain, const char *msg);
|
||||
|
||||
|
||||
+71
-63
@@ -4,6 +4,7 @@
|
||||
/* $Id$ */
|
||||
const char dirserv_c_id[] = "$Id$";
|
||||
|
||||
#define NEW_LOG_INTERFACE
|
||||
#include "or.h"
|
||||
|
||||
/**
|
||||
@@ -135,7 +136,7 @@ dirserv_add_own_fingerprint(const char *nickname, crypto_pk_env_t *pk)
|
||||
{
|
||||
char fp[FINGERPRINT_LEN+1];
|
||||
if (crypto_pk_get_fingerprint(pk, fp, 0)<0) {
|
||||
log_fn(LOG_ERR, "Error computing fingerprint");
|
||||
err(LD_BUG, "Error computing fingerprint");
|
||||
return -1;
|
||||
}
|
||||
if (!fingerprint_list)
|
||||
@@ -161,13 +162,13 @@ dirserv_parse_fingerprint_file(const char *fname)
|
||||
|
||||
cf = read_file_to_str(fname, 0);
|
||||
if (!cf) {
|
||||
log_fn(LOG_WARN, "Cannot open fingerprint file %s", fname);
|
||||
warn(LD_FS, "Cannot open fingerprint file %s", fname);
|
||||
return -1;
|
||||
}
|
||||
result = config_get_lines(cf, &front);
|
||||
tor_free(cf);
|
||||
if (result < 0) {
|
||||
log_fn(LOG_WARN, "Error reading from fingerprint file");
|
||||
warn(LD_CONFIG, "Error reading from fingerprint file");
|
||||
return -1;
|
||||
}
|
||||
|
||||
@@ -176,31 +177,34 @@ dirserv_parse_fingerprint_file(const char *fname)
|
||||
for (list=front; list; list=list->next) {
|
||||
nickname = list->key; fingerprint = list->value;
|
||||
if (strlen(nickname) > MAX_NICKNAME_LEN) {
|
||||
log(LOG_NOTICE, "Nickname '%s' too long in fingerprint file. Skipping.", nickname);
|
||||
notice(LD_CONFIG,
|
||||
"Nickname '%s' too long in fingerprint file. Skipping.", nickname);
|
||||
continue;
|
||||
}
|
||||
if (!is_legal_nickname(nickname) &&
|
||||
strcasecmp(nickname, "!reject") &&
|
||||
strcasecmp(nickname, "!invalid")) {
|
||||
log(LOG_NOTICE, "Invalid nickname '%s' in fingerprint file. Skipping.", nickname);
|
||||
notice(LD_CONFIG,
|
||||
"Invalid nickname '%s' in fingerprint file. Skipping.", nickname);
|
||||
continue;
|
||||
}
|
||||
if (strlen(fingerprint) != FINGERPRINT_LEN ||
|
||||
!crypto_pk_check_fingerprint_syntax(fingerprint)) {
|
||||
log_fn(LOG_NOTICE, "Invalid fingerprint (nickname '%s', fingerprint %s). Skipping.",
|
||||
notice(LD_CONFIG,
|
||||
"Invalid fingerprint (nickname '%s', fingerprint %s). Skipping.",
|
||||
nickname, fingerprint);
|
||||
continue;
|
||||
}
|
||||
if (0==strcasecmp(nickname, DEFAULT_CLIENT_NICKNAME)) {
|
||||
/* If you approved an OR called "client", then clients who use
|
||||
* the default nickname could all be rejected. That's no good. */
|
||||
log(LOG_NOTICE,
|
||||
notice(LD_CONFIG,
|
||||
"Authorizing a nickname '%s' would break many clients; skipping.",
|
||||
DEFAULT_CLIENT_NICKNAME);
|
||||
continue;
|
||||
}
|
||||
if (add_fingerprint_to_dir(nickname, fingerprint, fingerprint_list_new) != 0)
|
||||
log(LOG_NOTICE, "Duplicate nickname '%s'.", nickname);
|
||||
notice(LD_CONFIG, "Duplicate nickname '%s'.", nickname);
|
||||
}
|
||||
|
||||
config_free_lines(front);
|
||||
@@ -228,11 +232,11 @@ dirserv_router_get_status(const routerinfo_t *router, const char **msg)
|
||||
fingerprint_list = smartlist_create();
|
||||
|
||||
if (crypto_pk_get_fingerprint(router->identity_pkey, fp, 0)) {
|
||||
log_fn(LOG_WARN,"Error computing fingerprint");
|
||||
warn(LD_BUG,"Error computing fingerprint");
|
||||
return -1;
|
||||
}
|
||||
|
||||
log_fn(LOG_DEBUG, "%d fingerprints known.", smartlist_len(fingerprint_list));
|
||||
debug(LD_DIRSERV, "%d fingerprints known.", smartlist_len(fingerprint_list));
|
||||
SMARTLIST_FOREACH(fingerprint_list, fingerprint_entry_t *, ent,
|
||||
{
|
||||
if (!strcasecmp(fp,ent->fingerprint))
|
||||
@@ -260,32 +264,32 @@ dirserv_router_get_status(const routerinfo_t *router, const char **msg)
|
||||
router->addr, router->or_port, authdir_invalid_policy);
|
||||
|
||||
if (rej == ADDR_POLICY_PROBABLY_REJECTED || rej == ADDR_POLICY_REJECTED) {
|
||||
log_fn(LOG_INFO, "Rejecting '%s' because of address %s",
|
||||
router->nickname, router->address);
|
||||
info(LD_DIRSERV, "Rejecting '%s' because of address %s",
|
||||
router->nickname, router->address);
|
||||
if (msg)
|
||||
*msg = "Authdir is rejecting routers in this range.";
|
||||
return FP_REJECT;
|
||||
}
|
||||
if (inv == ADDR_POLICY_PROBABLY_REJECTED || inv == ADDR_POLICY_REJECTED) {
|
||||
log_fn(LOG_INFO, "Not marking '%s' valid because of address %s",
|
||||
router->nickname, router->address);
|
||||
info(LD_DIRSERV, "Not marking '%s' valid because of address %s",
|
||||
router->nickname, router->address);
|
||||
return FP_INVALID;
|
||||
}
|
||||
if (tor_version_as_new_as(router->platform,"0.1.0.2-rc"))
|
||||
return FP_VALID;
|
||||
else
|
||||
return FP_INVALID;
|
||||
log_fn(LOG_INFO,"No fingerprint found for '%s'",router->nickname);
|
||||
info(LD_DIRSERV,"No fingerprint found for '%s'",router->nickname);
|
||||
return 0;
|
||||
}
|
||||
if (0==strcasecmp(nn_ent->fingerprint, fp)) {
|
||||
log_fn(LOG_DEBUG,"Good fingerprint for '%s'",router->nickname);
|
||||
debug(LD_DIRSERV,"Good fingerprint for '%s'",router->nickname);
|
||||
return FP_NAMED; /* Right fingerprint. */
|
||||
} else {
|
||||
log_fn(LOG_WARN,"Mismatched fingerprint for '%s': expected '%s' got '%s'. ContactInfo '%s', platform '%s'.)",
|
||||
router->nickname, nn_ent->fingerprint, fp,
|
||||
router->contact_info ? router->contact_info : "",
|
||||
router->platform ? router->platform : "");
|
||||
warn(LD_DIRSERV,"Mismatched fingerprint for '%s': expected '%s' got '%s'. ContactInfo '%s', platform '%s'.)",
|
||||
router->nickname, nn_ent->fingerprint, fp,
|
||||
router->contact_info ? router->contact_info : "",
|
||||
router->platform ? router->platform : "");
|
||||
if (msg)
|
||||
*msg = "Rejected: There is already a verified server with this nickname and a different fingerprint.";
|
||||
return FP_REJECT; /* Wrong fingerprint. */
|
||||
@@ -342,13 +346,14 @@ dirserv_router_has_valid_address(routerinfo_t *ri)
|
||||
if (get_options()->DirAllowPrivateAddresses)
|
||||
return 0; /* whatever it is, we're fine with it */
|
||||
if (!tor_inet_aton(ri->address, &iaddr)) {
|
||||
log_fn(LOG_INFO,"Router '%s' published non-IP address '%s'. Refusing.",
|
||||
ri->nickname, ri->address);
|
||||
info(LD_DIRSERV,"Router '%s' published non-IP address '%s'. Refusing.",
|
||||
ri->nickname, ri->address);
|
||||
return -1;
|
||||
}
|
||||
if (is_internal_IP(ntohl(iaddr.s_addr))) {
|
||||
log_fn(LOG_INFO,"Router '%s' published internal IP address '%s'. Refusing.",
|
||||
ri->nickname, ri->address);
|
||||
info(LD_DIRSERV,
|
||||
"Router '%s' published internal IP address '%s'. Refusing.",
|
||||
ri->nickname, ri->address);
|
||||
return -1; /* it's a private IP, we should reject it */
|
||||
}
|
||||
return 0;
|
||||
@@ -373,7 +378,7 @@ authdir_wants_to_reject_router(routerinfo_t *ri,
|
||||
/* Is there too much clock skew? */
|
||||
now = time(NULL);
|
||||
if (ri->published_on > now+ROUTER_ALLOW_SKEW) {
|
||||
log_fn(LOG_NOTICE, "Publication time for nickname '%s' is too far (%d minutes) in the future; possible clock skew. Not adding (ContactInfo '%s', platform '%s').",
|
||||
notice(LD_DIRSERV, "Publication time for nickname '%s' is too far (%d minutes) in the future; possible clock skew. Not adding (ContactInfo '%s', platform '%s').",
|
||||
ri->nickname, (int)((ri->published_on-now)/60),
|
||||
ri->contact_info ? ri->contact_info : "",
|
||||
ri->platform ? ri->platform : "");
|
||||
@@ -381,7 +386,7 @@ authdir_wants_to_reject_router(routerinfo_t *ri,
|
||||
return -1;
|
||||
}
|
||||
if (ri->published_on < now-ROUTER_MAX_AGE) {
|
||||
log_fn(LOG_NOTICE, "Publication time for router with nickname '%s' is too far (%d minutes) in the past. Not adding (ContactInfo '%s', platform '%s').",
|
||||
notice(LD_DIRSERV, "Publication time for router with nickname '%s' is too far (%d minutes) in the past. Not adding (ContactInfo '%s', platform '%s').",
|
||||
ri->nickname, (int)((now-ri->published_on)/60),
|
||||
ri->contact_info ? ri->contact_info : "",
|
||||
ri->platform ? ri->platform : "");
|
||||
@@ -389,7 +394,7 @@ authdir_wants_to_reject_router(routerinfo_t *ri,
|
||||
return -1;
|
||||
}
|
||||
if (dirserv_router_has_valid_address(ri) < 0) {
|
||||
log_fn(LOG_NOTICE, "Router with nickname '%s' has invalid address '%s'. Not adding (ContactInfo '%s', platform '%s').",
|
||||
notice(LD_DIRSERV, "Router with nickname '%s' has invalid address '%s'. Not adding (ContactInfo '%s', platform '%s').",
|
||||
ri->nickname, ri->address,
|
||||
ri->contact_info ? ri->contact_info : "",
|
||||
ri->platform ? ri->platform : "");
|
||||
@@ -436,7 +441,7 @@ dirserv_add_descriptor(const char *desc, const char **msg)
|
||||
/* Check: is the descriptor syntactically valid? */
|
||||
ri = router_parse_entry_from_string(desc, NULL);
|
||||
if (!ri) {
|
||||
log(LOG_WARN, "Couldn't parse descriptor");
|
||||
warn(LD_DIRSERV, "Couldn't parse uploaded server descriptor");
|
||||
*msg = "Rejected: Couldn't parse server descriptor.";
|
||||
return -2;
|
||||
}
|
||||
@@ -447,9 +452,9 @@ dirserv_add_descriptor(const char *desc, const char **msg)
|
||||
ri_old = router_get_by_digest(ri->identity_digest);
|
||||
if (ri_old && ri_old->published_on < ri->published_on &&
|
||||
router_differences_are_cosmetic(ri_old, ri)) {
|
||||
log_fn(LOG_INFO,
|
||||
"Not replacing descriptor from '%s'; differences are cosmetic.",
|
||||
ri->nickname);
|
||||
info(LD_DIRSERV,
|
||||
"Not replacing descriptor from '%s'; differences are cosmetic.",
|
||||
ri->nickname);
|
||||
*msg = "Not replacing router descriptor; no information has changed since the last one with this identity.";
|
||||
return 0;
|
||||
}
|
||||
@@ -485,7 +490,7 @@ directory_remove_invalid(void)
|
||||
router_status_t r = dirserv_router_get_status(ent, &msg);
|
||||
switch (r) {
|
||||
case FP_REJECT:
|
||||
log(LOG_INFO, "Router '%s' is now rejected: %s",
|
||||
info(LD_DIRSERV, "Router '%s' is now rejected: %s",
|
||||
ent->nickname, msg?msg:"");
|
||||
routerlist_remove(rl, ent, i--);
|
||||
routerinfo_free(ent);
|
||||
@@ -493,14 +498,15 @@ directory_remove_invalid(void)
|
||||
break;
|
||||
case FP_NAMED:
|
||||
if (!ent->is_verified || !ent->is_named) {
|
||||
log(LOG_INFO, "Router '%s' is now verified and named.", ent->nickname);
|
||||
info(LD_DIRSERV,
|
||||
"Router '%s' is now verified and named.", ent->nickname);
|
||||
ent->is_verified = ent->is_named = 1;
|
||||
changed = 1;
|
||||
}
|
||||
break;
|
||||
case FP_VALID:
|
||||
if (!ent->is_verified || ent->is_named) {
|
||||
log(LOG_INFO, "Router '%s' is now verified.", ent->nickname);
|
||||
info(LD_DIRSERV, "Router '%s' is now verified.", ent->nickname);
|
||||
ent->is_verified = 1;
|
||||
ent->is_named = 0;
|
||||
changed = 1;
|
||||
@@ -508,7 +514,8 @@ directory_remove_invalid(void)
|
||||
break;
|
||||
case FP_INVALID:
|
||||
if (ent->is_verified || ent->is_named) {
|
||||
log(LOG_INFO, "Router '%s' is no longer verified.", ent->nickname);
|
||||
info(LD_DIRSERV,
|
||||
"Router '%s' is no longer verified.", ent->nickname);
|
||||
ent->is_verified = ent->is_named = 0;
|
||||
changed = 1;
|
||||
}
|
||||
@@ -745,7 +752,7 @@ dirserv_dump_directory_to_string(char **dir_out,
|
||||
|
||||
if (crypto_pk_write_public_key_to_string(private_key,&identity_pkey,
|
||||
&identity_pkey_len)<0) {
|
||||
log_fn(LOG_WARN,"write identity_pkey to string failed!");
|
||||
warn(LD_BUG,"write identity_pkey to string failed!");
|
||||
return -1;
|
||||
}
|
||||
|
||||
@@ -800,7 +807,7 @@ dirserv_dump_directory_to_string(char **dir_out,
|
||||
goto truncated;
|
||||
|
||||
if (router_get_dir_hash(buf,digest)) {
|
||||
log_fn(LOG_WARN,"couldn't compute digest");
|
||||
warn(LD_BUG,"couldn't compute digest");
|
||||
tor_free(buf);
|
||||
return -1;
|
||||
}
|
||||
@@ -812,7 +819,7 @@ dirserv_dump_directory_to_string(char **dir_out,
|
||||
*dir_out = buf;
|
||||
return 0;
|
||||
truncated:
|
||||
log_fn(LOG_WARN,"tried to exceed string length.");
|
||||
warn(LD_BUG,"tried to exceed string length.");
|
||||
tor_free(buf);
|
||||
return -1;
|
||||
}
|
||||
@@ -840,21 +847,21 @@ set_cached_dir(cached_dir_t *d, char *directory, time_t when)
|
||||
{
|
||||
time_t now = time(NULL);
|
||||
if (when<=d->published) {
|
||||
log_fn(LOG_INFO, "Ignoring old directory; not caching.");
|
||||
info(LD_DIRSERV, "Ignoring old directory; not caching.");
|
||||
tor_free(directory);
|
||||
} else if (when>=now+ROUTER_MAX_AGE) {
|
||||
log_fn(LOG_INFO, "Ignoring future directory; not caching.");
|
||||
info(LD_DIRSERV, "Ignoring future directory; not caching.");
|
||||
tor_free(directory);
|
||||
} else {
|
||||
/* if (when>d->published && when<now+ROUTER_MAX_AGE) */
|
||||
log_fn(LOG_DEBUG, "Caching directory.");
|
||||
debug(LD_DIRSERV, "Caching directory.");
|
||||
tor_free(d->dir);
|
||||
d->dir = directory;
|
||||
d->dir_len = strlen(directory);
|
||||
tor_free(d->dir_z);
|
||||
if (tor_gzip_compress(&(d->dir_z), &(d->dir_z_len), d->dir, d->dir_len,
|
||||
ZLIB_METHOD)) {
|
||||
log_fn(LOG_WARN,"Error compressing cached directory");
|
||||
warn(LD_BUG,"Error compressing cached directory");
|
||||
}
|
||||
d->published = when;
|
||||
}
|
||||
@@ -943,11 +950,11 @@ dirserv_pick_cached_dir_obj(cached_dir_t *cache_src,
|
||||
if (regenerate != NULL) {
|
||||
if (dirty && dirty + DIR_REGEN_SLACK_TIME < time(NULL)) {
|
||||
if (regenerate()) {
|
||||
log_fn(LOG_ERR, "Couldn't generate %s?", name);
|
||||
err(LD_BUG, "Couldn't generate %s?", name);
|
||||
exit(1);
|
||||
}
|
||||
} else {
|
||||
log_fn(LOG_INFO, "The %s is still clean; reusing.", name);
|
||||
info(LD_DIRSERV, "The %s is still clean; reusing.", name);
|
||||
}
|
||||
}
|
||||
return auth_src ? auth_src : cache_src;
|
||||
@@ -1011,13 +1018,13 @@ dirserv_regenerate_directory(void)
|
||||
|
||||
if (dirserv_dump_directory_to_string(&new_directory,
|
||||
get_identity_key())) {
|
||||
log(LOG_WARN, "Error creating directory.");
|
||||
warn(LD_BUG, "Error creating directory.");
|
||||
tor_free(new_directory);
|
||||
return -1;
|
||||
}
|
||||
set_cached_dir(&the_directory, new_directory, time(NULL));
|
||||
log_fn(LOG_INFO,"New directory (size %d) has been built.",(int)the_directory.dir_len);
|
||||
log_fn(LOG_DEBUG,"New directory (size %d):\n%s",(int)the_directory.dir_len,
|
||||
info(LD_DIRSERV,"New directory (size %d) has been built.",(int)the_directory.dir_len);
|
||||
debug(LD_DIRSERV,"New directory (size %d):\n%s",(int)the_directory.dir_len,
|
||||
the_directory.dir);
|
||||
|
||||
the_directory_is_dirty = 0;
|
||||
@@ -1051,7 +1058,7 @@ generate_runningrouters(void)
|
||||
}
|
||||
if (crypto_pk_write_public_key_to_string(private_key,&identity_pkey,
|
||||
&identity_pkey_len)<0) {
|
||||
log_fn(LOG_WARN,"write identity_pkey to string failed!");
|
||||
warn(LD_BUG,"write identity_pkey to string failed!");
|
||||
goto err;
|
||||
}
|
||||
format_iso_time(published, time(NULL));
|
||||
@@ -1068,7 +1075,7 @@ generate_runningrouters(void)
|
||||
tor_free(router_status);
|
||||
tor_free(identity_pkey);
|
||||
if (router_get_runningrouters_hash(s,digest)) {
|
||||
log_fn(LOG_WARN,"couldn't compute digest");
|
||||
warn(LD_BUG,"couldn't compute digest");
|
||||
goto err;
|
||||
}
|
||||
if (router_append_dirobj_signature(s, len, digest, private_key)<0)
|
||||
@@ -1162,7 +1169,7 @@ generate_v2_networkstatus(void)
|
||||
const char *contact;
|
||||
|
||||
if (resolve_my_address(options, &addr, &hostname)<0) {
|
||||
log_fn(LOG_WARN, "Couldn't resolve my hostname");
|
||||
warn(LD_NET, "Couldn't resolve my hostname");
|
||||
goto done;
|
||||
}
|
||||
in.s_addr = htonl(addr);
|
||||
@@ -1175,12 +1182,12 @@ generate_v2_networkstatus(void)
|
||||
|
||||
if (crypto_pk_write_public_key_to_string(private_key, &identity_pkey,
|
||||
&identity_pkey_len)<0) {
|
||||
log_fn(LOG_WARN,"Writing public key to string failed.");
|
||||
warn(LD_BUG,"Writing public key to string failed.");
|
||||
goto done;
|
||||
}
|
||||
|
||||
if (crypto_pk_get_fingerprint(private_key, fingerprint, 0)<0) {
|
||||
log_fn(LOG_ERR, "Error computing fingerprint");
|
||||
err(LD_BUG, "Error computing fingerprint");
|
||||
goto done;
|
||||
}
|
||||
|
||||
@@ -1254,25 +1261,25 @@ generate_v2_networkstatus(void)
|
||||
f_stable?" Stable":"",
|
||||
f_running?" Running":"",
|
||||
f_valid?" Valid":"")<0) {
|
||||
log_fn(LOG_WARN, "Unable to print router status.");
|
||||
warn(LD_BUG, "Unable to print router status.");
|
||||
goto done;
|
||||
}
|
||||
}
|
||||
outp += strlen(outp);
|
||||
});
|
||||
|
||||
if (tor_snprintf(outp, endp-outp, "directory-signature %s\n",
|
||||
get_options()->Nickname)<0) {
|
||||
log_fn(LOG_WARN, "Unable to write signature line.");
|
||||
warn(LD_BUG, "Unable to write signature line.");
|
||||
goto done;
|
||||
}
|
||||
|
||||
if (router_get_networkstatus_v2_hash(status, digest)<0) {
|
||||
log_fn(LOG_WARN, "Unable to hash network status");
|
||||
warn(LD_BUG, "Unable to hash network status");
|
||||
goto done;
|
||||
}
|
||||
|
||||
if (router_append_dirobj_signature(outp,endp-outp,digest,private_key)<0) {
|
||||
log_fn(LOG_WARN, "Unable to sign router status.");
|
||||
warn(LD_BUG, "Unable to sign router status.");
|
||||
goto done;
|
||||
}
|
||||
|
||||
@@ -1320,7 +1327,7 @@ dirserv_get_networkstatus_v2(smartlist_t *result,
|
||||
if (d)
|
||||
smartlist_add(result, d);
|
||||
else
|
||||
log_fn(LOG_WARN,"Unable to generate an authoritative network status.");
|
||||
warn(LD_BUG,"Unable to generate an authoritative network status.");
|
||||
}
|
||||
} else if (!strcmp(key, "all")) {
|
||||
digestmap_iter_t *iter = digestmap_iter_init(cached_v2_networkstatus);
|
||||
@@ -1332,7 +1339,8 @@ dirserv_get_networkstatus_v2(smartlist_t *result,
|
||||
iter = digestmap_iter_next(cached_v2_networkstatus, iter);
|
||||
}
|
||||
if (smartlist_len(result) == 0)
|
||||
log_fn(LOG_WARN, "Client requested 'all' network status objects; we have none.");
|
||||
warn(LD_DIRSERV,
|
||||
"Client requested 'all' network status objects; we have none.");
|
||||
} else if (!strcmpstart(key, "fp/")) {
|
||||
smartlist_t *digests = smartlist_create();
|
||||
dir_split_resource_into_fingerprints(key+3, digests, NULL, 1);
|
||||
@@ -1351,7 +1359,7 @@ dirserv_get_networkstatus_v2(smartlist_t *result,
|
||||
} else {
|
||||
char hexbuf[HEX_DIGEST_LEN+1];
|
||||
base16_encode(hexbuf, sizeof(hexbuf), cp, DIGEST_LEN);
|
||||
log_fn(LOG_INFO, "Don't know about any network status with fingerprint '%s'", hexbuf);
|
||||
info(LD_DIRSERV, "Don't know about any network status with fingerprint '%s'", hexbuf);
|
||||
}
|
||||
tor_free(cp);
|
||||
});
|
||||
@@ -1460,11 +1468,11 @@ dirserv_orconn_tls_done(const char *address,
|
||||
if (!ri->is_verified) {
|
||||
/* We have a router at the same address! */
|
||||
if (strcasecmp(ri->nickname, nickname_rcvd)) {
|
||||
log_fn(LOG_NOTICE, "Dropping descriptor: nickname '%s' does not match nickname '%s' in cert from %s:%d",
|
||||
notice(LD_DIRSERV, "Dropping descriptor: nickname '%s' does not match nickname '%s' in cert from %s:%d",
|
||||
ri->nickname, nickname_rcvd, address, or_port);
|
||||
drop = 1;
|
||||
} else if (memcmp(ri->identity_digest, digest_rcvd, DIGEST_LEN)) {
|
||||
log_fn(LOG_NOTICE, "Dropping descriptor: identity key does not match key in cert from %s:%d",
|
||||
notice(LD_DIRSERV, "Dropping descriptor: identity key does not match key in cert from %s:%d",
|
||||
address, or_port);
|
||||
drop = 1;
|
||||
}
|
||||
@@ -1474,7 +1482,7 @@ dirserv_orconn_tls_done(const char *address,
|
||||
routerinfo_free(ri);
|
||||
directory_set_dirty();
|
||||
} else { /* correct nickname and digest. mark this router reachable! */
|
||||
log_fn(LOG_INFO,"Found router %s to be reachable. Yay.", ri->nickname);
|
||||
info(LD_DIRSERV,"Found router %s to be reachable. Yay.", ri->nickname);
|
||||
ri->last_reachable = time(NULL);
|
||||
ri->num_unreachable_notifications = 0;
|
||||
}
|
||||
|
||||
+44
-40
@@ -17,6 +17,7 @@ const char dns_c_id[] = "$Id$";
|
||||
* them becomes more commonly available.
|
||||
*/
|
||||
|
||||
#define NEW_LOG_INTERFACE
|
||||
#include "or.h"
|
||||
#include "tree.h"
|
||||
|
||||
@@ -149,14 +150,14 @@ purge_expired_resolves(uint32_t now)
|
||||
*/
|
||||
while (oldest_cached_resolve && (oldest_cached_resolve->expire < now)) {
|
||||
resolve = oldest_cached_resolve;
|
||||
log(LOG_DEBUG,"Forgetting old cached resolve (address %s, expires %lu)",
|
||||
debug(LD_EXIT,"Forgetting old cached resolve (address %s, expires %lu)",
|
||||
safe_str(resolve->address), (unsigned long)resolve->expire);
|
||||
if (resolve->state == CACHE_STATE_PENDING) {
|
||||
log_fn(LOG_WARN,"Bug: Expiring a dns resolve ('%s') that's still pending. Forgot to cull it?", safe_str(resolve->address));
|
||||
debug(LD_EXIT,"Bug: Expiring a dns resolve ('%s') that's still pending. Forgot to cull it?", safe_str(resolve->address));
|
||||
tor_fragile_assert();
|
||||
}
|
||||
if (resolve->pending_connections) {
|
||||
log_fn(LOG_WARN, "Closing pending connections on expiring DNS resolve!");
|
||||
debug(LD_EXIT, "Closing pending connections on expiring DNS resolve!");
|
||||
tor_fragile_assert();
|
||||
while (resolve->pending_connections) {
|
||||
pend = resolve->pending_connections;
|
||||
@@ -283,19 +284,19 @@ dns_resolve(connection_t *exitconn)
|
||||
pending_connection->conn = exitconn;
|
||||
pending_connection->next = resolve->pending_connections;
|
||||
resolve->pending_connections = pending_connection;
|
||||
log_fn(LOG_DEBUG,"Connection (fd %d) waiting for pending DNS resolve of '%s'",
|
||||
debug(LD_EXIT,"Connection (fd %d) waiting for pending DNS resolve of '%s'",
|
||||
exitconn->s, safe_str(exitconn->address));
|
||||
exitconn->state = EXIT_CONN_STATE_RESOLVING;
|
||||
return 0;
|
||||
case CACHE_STATE_VALID:
|
||||
exitconn->addr = resolve->addr;
|
||||
log_fn(LOG_DEBUG,"Connection (fd %d) found cached answer for '%s'",
|
||||
debug(LD_EXIT,"Connection (fd %d) found cached answer for '%s'",
|
||||
exitconn->s, safe_str(exitconn->address));
|
||||
if (exitconn->purpose == EXIT_PURPOSE_RESOLVE)
|
||||
send_resolved_cell(exitconn, RESOLVED_TYPE_IPV4);
|
||||
return 1;
|
||||
case CACHE_STATE_FAILED:
|
||||
log_fn(LOG_DEBUG,"Connection (fd %d) found cached error for '%s'",
|
||||
debug(LD_EXIT,"Connection (fd %d) found cached error for '%s'",
|
||||
exitconn->s, safe_str(exitconn->address));
|
||||
if (exitconn->purpose == EXIT_PURPOSE_RESOLVE)
|
||||
send_resolved_cell(exitconn, RESOLVED_TYPE_ERROR);
|
||||
@@ -344,14 +345,15 @@ assign_to_dnsworker(connection_t *exitconn)
|
||||
dnsconn = connection_get_by_type_state(CONN_TYPE_DNSWORKER, DNSWORKER_STATE_IDLE);
|
||||
|
||||
if (!dnsconn) {
|
||||
log_fn(LOG_WARN,"no idle dns workers. Failing.");
|
||||
warn(LD_EXIT,"no idle dns workers. Failing.");
|
||||
if (exitconn->purpose == EXIT_PURPOSE_RESOLVE)
|
||||
send_resolved_cell(exitconn, RESOLVED_TYPE_ERROR_TRANSIENT);
|
||||
goto err;
|
||||
}
|
||||
|
||||
log_fn(LOG_DEBUG, "Connection (fd %d) needs to resolve '%s'; assigning to DNSWorker (fd %d)",
|
||||
exitconn->s, safe_str(exitconn->address), dnsconn->s);
|
||||
debug(LD_EXIT,
|
||||
"Connection (fd %d) needs to resolve '%s'; assigning to DNSWorker (fd %d)",
|
||||
exitconn->s, safe_str(exitconn->address), dnsconn->s);
|
||||
|
||||
tor_free(dnsconn->address);
|
||||
dnsconn->address = tor_strdup(exitconn->address);
|
||||
@@ -384,7 +386,8 @@ connection_dns_remove(connection_t *conn)
|
||||
|
||||
resolve = SPLAY_FIND(cache_tree, &cache_root, &search);
|
||||
if (!resolve) {
|
||||
log_fn(LOG_NOTICE,"Address '%s' is not pending. Dropping.", safe_str(conn->address));
|
||||
/* XXXX RD This *is* a bug, right? -NM */
|
||||
notice(LD_BUG,"Address '%s' is not pending. Dropping.", safe_str(conn->address));
|
||||
return;
|
||||
}
|
||||
|
||||
@@ -396,7 +399,7 @@ connection_dns_remove(connection_t *conn)
|
||||
if (pend->conn == conn) {
|
||||
resolve->pending_connections = pend->next;
|
||||
tor_free(pend);
|
||||
log_fn(LOG_DEBUG, "First connection (fd %d) no longer waiting for resolve of '%s'",
|
||||
debug(LD_EXIT, "First connection (fd %d) no longer waiting for resolve of '%s'",
|
||||
conn->s, safe_str(conn->address));
|
||||
return;
|
||||
} else {
|
||||
@@ -405,7 +408,7 @@ connection_dns_remove(connection_t *conn)
|
||||
victim = pend->next;
|
||||
pend->next = victim->next;
|
||||
tor_free(victim);
|
||||
log_fn(LOG_DEBUG, "Connection (fd %d) no longer waiting for resolve of '%s'",
|
||||
debug(LD_EXIT, "Connection (fd %d) no longer waiting for resolve of '%s'",
|
||||
conn->s, safe_str(conn->address));
|
||||
return; /* more are pending */
|
||||
}
|
||||
@@ -467,13 +470,14 @@ dns_cancel_pending_resolve(char *address)
|
||||
|
||||
resolve = SPLAY_FIND(cache_tree, &cache_root, &search);
|
||||
if (!resolve) {
|
||||
log_fn(LOG_NOTICE,"Address '%s' is not pending. Dropping.", safe_str(address));
|
||||
/* XXXX RD This *is* a bug, right? -NM */
|
||||
notice(LD_BUG,"Address '%s' is not pending. Dropping.", safe_str(address));
|
||||
return;
|
||||
}
|
||||
|
||||
if (!resolve->pending_connections) {
|
||||
/* XXX this should never trigger, but sometimes it does */
|
||||
log_fn(LOG_WARN,"Bug: Address '%s' is pending but has no pending connections!",
|
||||
warn(LD_BUG,"Bug: Address '%s' is pending but has no pending connections!",
|
||||
safe_str(address));
|
||||
tor_fragile_assert();
|
||||
return;
|
||||
@@ -481,8 +485,8 @@ dns_cancel_pending_resolve(char *address)
|
||||
tor_assert(resolve->pending_connections);
|
||||
|
||||
/* mark all pending connections to fail */
|
||||
log_fn(LOG_DEBUG, "Failing all connections waiting on DNS resolve of '%s'",
|
||||
safe_str(address));
|
||||
debug(LD_EXIT, "Failing all connections waiting on DNS resolve of '%s'",
|
||||
safe_str(address));
|
||||
while (resolve->pending_connections) {
|
||||
pend = resolve->pending_connections;
|
||||
pend->conn->state = EXIT_CONN_STATE_RESOLVEFAILED;
|
||||
@@ -551,8 +555,8 @@ dns_found_answer(char *address, uint32_t addr, char outcome)
|
||||
|
||||
resolve = SPLAY_FIND(cache_tree, &cache_root, &search);
|
||||
if (!resolve) {
|
||||
log_fn(LOG_INFO,"Resolved unasked address '%s'; caching anyway.",
|
||||
safe_str(address));
|
||||
info(LD_EXIT,"Resolved unasked address '%s'; caching anyway.",
|
||||
safe_str(address));
|
||||
resolve = tor_malloc_zero(sizeof(cached_resolve_t));
|
||||
resolve->state = (outcome == DNS_RESOLVE_SUCCEEDED) ?
|
||||
CACHE_STATE_VALID : CACHE_STATE_FAILED;
|
||||
@@ -565,7 +569,7 @@ dns_found_answer(char *address, uint32_t addr, char outcome)
|
||||
if (resolve->state != CACHE_STATE_PENDING) {
|
||||
/* XXXX Maybe update addr? or check addr for consistency? Or let
|
||||
* VALID replace FAILED? */
|
||||
log_fn(LOG_NOTICE, "Resolved '%s' which was already resolved; ignoring",
|
||||
notice(LD_EXIT, "Resolved '%s' which was already resolved; ignoring",
|
||||
safe_str(address));
|
||||
tor_assert(resolve->pending_connections == NULL);
|
||||
return;
|
||||
@@ -656,7 +660,7 @@ connection_dns_finished_flushing(connection_t *conn)
|
||||
int
|
||||
connection_dns_reached_eof(connection_t *conn)
|
||||
{
|
||||
log_fn(LOG_WARN,"Read eof. Worker died unexpectedly.");
|
||||
warn(LD_EXIT,"Read eof. Worker died unexpectedly.");
|
||||
if (conn->state == DNSWORKER_STATE_BUSY) {
|
||||
/* don't cancel the resolve here -- it would be cancelled in
|
||||
* connection_about_to_close_connection(), since conn is still
|
||||
@@ -682,8 +686,8 @@ connection_dns_process_inbuf(connection_t *conn)
|
||||
tor_assert(conn->type == CONN_TYPE_DNSWORKER);
|
||||
|
||||
if (conn->state != DNSWORKER_STATE_BUSY && buf_datalen(conn->inbuf)) {
|
||||
log_fn(LOG_WARN,"Bug: read data (%d bytes) from an idle dns worker (fd %d, address '%s'). Please report.",
|
||||
(int)buf_datalen(conn->inbuf), conn->s, safe_str(conn->address));
|
||||
warn(LD_BUG,"Bug: read data (%d bytes) from an idle dns worker (fd %d, address '%s'). Please report.",
|
||||
(int)buf_datalen(conn->inbuf), conn->s, safe_str(conn->address));
|
||||
tor_fragile_assert();
|
||||
|
||||
/* Pull it off the buffer anyway, or it will just stay there.
|
||||
@@ -692,7 +696,7 @@ connection_dns_process_inbuf(connection_t *conn)
|
||||
while (buf_datalen(conn->inbuf)) {
|
||||
connection_fetch_from_buf(&success,1,conn);
|
||||
connection_fetch_from_buf((char *)&addr,sizeof(uint32_t),conn);
|
||||
log_fn(LOG_WARN,"Discarding idle dns answer (success %d, addr %d.)",
|
||||
warn(LD_EXIT,"Discarding idle dns answer (success %d, addr %d.)",
|
||||
success, addr); // XXX safe_str
|
||||
}
|
||||
return 0;
|
||||
@@ -705,8 +709,8 @@ connection_dns_process_inbuf(connection_t *conn)
|
||||
connection_fetch_from_buf(&success,1,conn);
|
||||
connection_fetch_from_buf((char *)&addr,sizeof(uint32_t),conn);
|
||||
|
||||
log_fn(LOG_DEBUG, "DNSWorker (fd %d) returned answer for '%s'",
|
||||
conn->s, safe_str(conn->address));
|
||||
debug(LD_EXIT, "DNSWorker (fd %d) returned answer for '%s'",
|
||||
conn->s, safe_str(conn->address));
|
||||
|
||||
tor_assert(success >= DNS_RESOLVE_FAILED_TRANSIENT);
|
||||
tor_assert(success <= DNS_RESOLVE_SUCCEEDED);
|
||||
@@ -784,17 +788,17 @@ dnsworker_main(void *data)
|
||||
|
||||
if ((r = recv(fd, &address_len, 1, 0)) != 1) {
|
||||
if (r == 0) {
|
||||
log_fn(LOG_INFO,"DNS worker exiting because Tor process closed connection (either pruned idle dnsworker or died).");
|
||||
info(LD_EXIT,"DNS worker exiting because Tor process closed connection (either pruned idle dnsworker or died).");
|
||||
} else {
|
||||
log_fn(LOG_INFO,"DNS worker exiting because of error on connection to Tor process.");
|
||||
log_fn(LOG_INFO,"(Error on %d was %s)", fd, tor_socket_strerror(tor_socket_errno(fd)));
|
||||
info(LD_EXIT,"DNS worker exiting because of error on connection to Tor process.");
|
||||
info(LD_EXIT,"(Error on %d was %s)", fd, tor_socket_strerror(tor_socket_errno(fd)));
|
||||
}
|
||||
tor_close_socket(fd);
|
||||
spawn_exit();
|
||||
}
|
||||
|
||||
if (address_len && read_all(fd, address, address_len, 1) != address_len) {
|
||||
log_fn(LOG_ERR,"read hostname failed. Child exiting.");
|
||||
err(LD_BUG,"read hostname failed. Child exiting.");
|
||||
tor_close_socket(fd);
|
||||
spawn_exit();
|
||||
}
|
||||
@@ -807,21 +811,21 @@ dnsworker_main(void *data)
|
||||
switch (result) {
|
||||
case 1:
|
||||
/* XXX result can never be 1, because we set it to -1 above on error */
|
||||
log_fn(LOG_INFO,"Could not resolve dest addr %s (transient).",safe_str(address));
|
||||
info(LD_NET,"Could not resolve dest addr %s (transient).",safe_str(address));
|
||||
answer[0] = DNS_RESOLVE_FAILED_TRANSIENT;
|
||||
break;
|
||||
case -1:
|
||||
log_fn(LOG_INFO,"Could not resolve dest addr %s (permanent).",safe_str(address));
|
||||
info(LD_NET,"Could not resolve dest addr %s (permanent).",safe_str(address));
|
||||
answer[0] = DNS_RESOLVE_FAILED_PERMANENT;
|
||||
break;
|
||||
case 0:
|
||||
log_fn(LOG_INFO,"Resolved address '%s'.",safe_str(address));
|
||||
info(LD_NET,"Resolved address '%s'.",safe_str(address));
|
||||
answer[0] = DNS_RESOLVE_SUCCEEDED;
|
||||
break;
|
||||
}
|
||||
set_uint32(answer+1, ip);
|
||||
if (write_all(fd, answer, 5, 1) != 5) {
|
||||
log_fn(LOG_ERR,"writing answer failed. Child exiting.");
|
||||
err(LD_NET,"writing answer failed. Child exiting.");
|
||||
tor_close_socket(fd);
|
||||
spawn_exit();
|
||||
}
|
||||
@@ -841,7 +845,7 @@ spawn_dnsworker(void)
|
||||
|
||||
fdarray = tor_malloc(sizeof(int)*2);
|
||||
if ((err = tor_socketpair(AF_UNIX, SOCK_STREAM, 0, fdarray)) < 0) {
|
||||
log(LOG_WARN, "Couldn't construct socketpair: %s", tor_socket_strerror(-err));
|
||||
warn(LD_NET, "Couldn't construct socketpair: %s", tor_socket_strerror(-err));
|
||||
tor_free(fdarray);
|
||||
return -1;
|
||||
}
|
||||
@@ -850,7 +854,7 @@ spawn_dnsworker(void)
|
||||
|
||||
fd = fdarray[0]; /* We copy this out here, since dnsworker_main may free fdarray */
|
||||
spawn_func(dnsworker_main, (void*)fdarray);
|
||||
log_fn(LOG_DEBUG,"just spawned a worker.");
|
||||
debug(LD_EXIT,"just spawned a worker.");
|
||||
#ifndef TOR_IS_MULTITHREADED
|
||||
tor_close_socket(fdarray[1]); /* we don't need the worker's side of the pipe */
|
||||
tor_free(fdarray);
|
||||
@@ -865,7 +869,7 @@ spawn_dnsworker(void)
|
||||
conn->address = tor_strdup("<unused>");
|
||||
|
||||
if (connection_add(conn) < 0) { /* no space, forget it */
|
||||
log_fn(LOG_WARN,"connection_add failed. Giving up.");
|
||||
warn(LD_NET,"connection_add failed. Giving up.");
|
||||
connection_free(conn); /* this closes fd */
|
||||
return -1;
|
||||
}
|
||||
@@ -903,8 +907,8 @@ spawn_enough_dnsworkers(void)
|
||||
DNSWORKER_STATE_BUSY);
|
||||
tor_assert(dnsconn);
|
||||
|
||||
log_fn(LOG_WARN, "%d DNS workers are spawned; all are busy. Killing one.",
|
||||
MAX_DNSWORKERS);
|
||||
warn(LD_EXIT, "%d DNS workers are spawned; all are busy. Killing one.",
|
||||
MAX_DNSWORKERS);
|
||||
|
||||
connection_mark_for_close(dnsconn);
|
||||
num_dnsworkers_busy--;
|
||||
@@ -918,7 +922,7 @@ spawn_enough_dnsworkers(void)
|
||||
|
||||
while (num_dnsworkers < num_dnsworkers_needed) {
|
||||
if (spawn_dnsworker() < 0) {
|
||||
log_fn(LOG_WARN,"Spawn failed. Will try again later.");
|
||||
warn(LD_EXIT,"Spawn failed. Will try again later.");
|
||||
return -1;
|
||||
}
|
||||
num_dnsworkers++;
|
||||
@@ -927,7 +931,7 @@ spawn_enough_dnsworkers(void)
|
||||
while (num_dnsworkers > num_dnsworkers_busy+MAX_IDLE_DNSWORKERS) {
|
||||
/* too many idle? */
|
||||
/* cull excess workers */
|
||||
log_fn(LOG_INFO,"%d of %d dnsworkers are idle. Killing one.",
|
||||
info(LD_EXIT,"%d of %d dnsworkers are idle. Killing one.",
|
||||
num_dnsworkers-num_dnsworkers_busy, num_dnsworkers);
|
||||
dnsconn = connection_get_by_type_state(CONN_TYPE_DNSWORKER, DNSWORKER_STATE_IDLE);
|
||||
tor_assert(dnsconn);
|
||||
|
||||
+38
-37
@@ -22,6 +22,7 @@ hibernating, phase 2:
|
||||
- close all OR/AP/exit conns)
|
||||
*/
|
||||
|
||||
#define NEW_LOG_INTERFACE
|
||||
#include "or.h"
|
||||
|
||||
#define HIBERNATE_STATE_LIVE 1
|
||||
@@ -128,7 +129,7 @@ accounting_parse_options(or_options_t *options, int validate_only)
|
||||
smartlist_split_string(items, v, NULL,
|
||||
SPLIT_SKIP_SPACE|SPLIT_IGNORE_BLANK,0);
|
||||
if (smartlist_len(items)<2) {
|
||||
log_fn(LOG_WARN, "Too few arguments to AccountingStart");
|
||||
warn(LD_CONFIG, "Too few arguments to AccountingStart");
|
||||
goto err;
|
||||
}
|
||||
s = smartlist_get(items,0);
|
||||
@@ -139,7 +140,7 @@ accounting_parse_options(or_options_t *options, int validate_only)
|
||||
} else if (0==strcasecmp(s, "day")) {
|
||||
unit = UNIT_DAY;
|
||||
} else {
|
||||
log_fn(LOG_WARN, "Unrecognized accounting unit '%s': only 'month', 'week', and 'day' are supported.", s);
|
||||
warn(LD_CONFIG, "Unrecognized accounting unit '%s': only 'month', 'week', and 'day' are supported.", s);
|
||||
goto err;
|
||||
}
|
||||
|
||||
@@ -147,14 +148,14 @@ accounting_parse_options(or_options_t *options, int validate_only)
|
||||
case UNIT_WEEK:
|
||||
d = tor_parse_long(smartlist_get(items,1), 10, 1, 7, &ok, NULL);
|
||||
if (!ok) {
|
||||
log_fn(LOG_WARN, "Weekly accounting must start begin on a day between 1(Monday) and 7 (Sunday)");
|
||||
warn(LD_CONFIG, "Weekly accounting must start begin on a day between 1(Monday) and 7 (Sunday)");
|
||||
goto err;
|
||||
}
|
||||
break;
|
||||
case UNIT_MONTH:
|
||||
d = tor_parse_long(smartlist_get(items,1), 10, 1, 28, &ok, NULL);
|
||||
if (!ok) {
|
||||
log_fn(LOG_WARN, "Monthly accounting must start begin on a day between 1 and 28");
|
||||
warn(LD_CONFIG, "Monthly accounting must start begin on a day between 1 and 28");
|
||||
goto err;
|
||||
}
|
||||
break;
|
||||
@@ -167,27 +168,27 @@ accounting_parse_options(or_options_t *options, int validate_only)
|
||||
|
||||
idx = unit==UNIT_DAY?1:2;
|
||||
if (smartlist_len(items) != (idx+1)) {
|
||||
log_fn(LOG_WARN, "Accounting unit '%s' requires %d arguments",
|
||||
warn(LD_CONFIG,"Accounting unit '%s' requires %d arguments",
|
||||
s, idx+1);
|
||||
goto err;
|
||||
}
|
||||
s = smartlist_get(items, idx);
|
||||
h = tor_parse_long(s, 10, 0, 23, &ok, &cp);
|
||||
if (!ok) {
|
||||
log_fn(LOG_WARN, "Accounting start time not parseable: bad hour.");
|
||||
warn(LD_CONFIG,"Accounting start time not parseable: bad hour.");
|
||||
goto err;
|
||||
}
|
||||
if (!cp || *cp!=':') {
|
||||
log_fn(LOG_WARN,"Accounting start time not parseable: not in HH:MM format");
|
||||
warn(LD_CONFIG,"Accounting start time not parseable: not in HH:MM format");
|
||||
goto err;
|
||||
}
|
||||
m = tor_parse_long(cp+1, 10, 0, 59, &ok, &cp);
|
||||
if (!ok) {
|
||||
log_fn(LOG_WARN, "Accounting start time not parseable: bad minute");
|
||||
warn(LD_CONFIG, "Accounting start time not parseable: bad minute");
|
||||
goto err;
|
||||
}
|
||||
if (!cp || *cp!='\0') {
|
||||
log_fn(LOG_WARN,"Accounting start time not parseable: not in HH:MM format");
|
||||
warn(LD_CONFIG,"Accounting start time not parseable: not in HH:MM format");
|
||||
goto err;
|
||||
}
|
||||
|
||||
@@ -321,15 +322,15 @@ configure_accounting(time_t now)
|
||||
start_of_accounting_period_after(interval_start_time) <= now) {
|
||||
/* We didn't have recorded usage, or we don't have recorded usage
|
||||
* for this interval. Start a new interval. */
|
||||
log_fn(LOG_INFO, "Starting new accounting interval.");
|
||||
info(LD_ACCT, "Starting new accounting interval.");
|
||||
reset_accounting(now);
|
||||
} else if (interval_start_time ==
|
||||
start_of_accounting_period_containing(interval_start_time)) {
|
||||
log_fn(LOG_INFO, "Continuing accounting interval.");
|
||||
info(LD_ACCT, "Continuing accounting interval.");
|
||||
/* We are in the interval we thought we were in. Do nothing.*/
|
||||
interval_end_time = start_of_accounting_period_after(interval_start_time);
|
||||
} else {
|
||||
log_fn(LOG_WARN, "Mismatched accounting interval; starting a fresh one.");
|
||||
warn(LD_ACCT, "Mismatched accounting interval; starting a fresh one.");
|
||||
reset_accounting(now);
|
||||
}
|
||||
accounting_set_wakeup_time();
|
||||
@@ -370,7 +371,7 @@ update_expected_bandwidth(void)
|
||||
static void
|
||||
reset_accounting(time_t now)
|
||||
{
|
||||
log_fn(LOG_INFO, "Starting new accounting interval.");
|
||||
info(LD_ACCT, "Starting new accounting interval.");
|
||||
update_expected_bandwidth();
|
||||
interval_start_time = start_of_accounting_period_containing(now);
|
||||
interval_end_time = start_of_accounting_period_after(interval_start_time);
|
||||
@@ -413,7 +414,7 @@ accounting_run_housekeeping(time_t now)
|
||||
}
|
||||
if (time_to_record_bandwidth_usage(now)) {
|
||||
if (accounting_record_bandwidth_usage(now)) {
|
||||
log_fn(LOG_ERR, "Couldn't record bandwidth usage to disk; exiting.");
|
||||
err(LD_FS, "Couldn't record bandwidth usage to disk; exiting.");
|
||||
/* This can fail when we're out of fd's, causing a crash.
|
||||
* The current answer is to reserve 32 more than we need, in
|
||||
* set_max_file_descriptors(). */
|
||||
@@ -436,7 +437,7 @@ accounting_set_wakeup_time(void)
|
||||
|
||||
if (! identity_key_is_set()) {
|
||||
if (init_keys() < 0) {
|
||||
log_fn(LOG_ERR, "Error initializing keys");
|
||||
err(LD_BUG, "Error initializing keys");
|
||||
tor_assert(0);
|
||||
}
|
||||
}
|
||||
@@ -458,7 +459,7 @@ accounting_set_wakeup_time(void)
|
||||
time_to_exhaust_bw = 24*60*60;
|
||||
interval_wakeup_time = interval_start_time;
|
||||
|
||||
log_fn(LOG_NOTICE, "Configured hibernation. This interval begins at %s "
|
||||
notice(LD_ACCT, "Configured hibernation. This interval begins at %s "
|
||||
"and ends at %s. We have no prior estimate for bandwidth, so "
|
||||
"we will start out awake and hibernate when we exhaust our quota.",
|
||||
buf1, buf2);
|
||||
@@ -500,7 +501,7 @@ accounting_set_wakeup_time(void)
|
||||
down_time<interval_end_time?down_time:interval_end_time);
|
||||
format_local_iso_time(buf4, interval_end_time);
|
||||
|
||||
log_fn(LOG_NOTICE, "Configured hibernation. This interval began at %s; "
|
||||
notice(LD_ACCT, "Configured hibernation. This interval began at %s; "
|
||||
"the scheduled wake-up time %s %s; "
|
||||
"we expect%s to exhaust our quota for this interval around %s; "
|
||||
"the next interval begins at %s (all times local)",
|
||||
@@ -566,45 +567,45 @@ read_bandwidth_usage(void)
|
||||
|
||||
if (smartlist_len(elts)<1 ||
|
||||
atoi(smartlist_get(elts,0)) != BW_ACCOUNTING_VERSION) {
|
||||
log_fn(LOG_WARN, "Unrecognized bw_accounting file version: %s",
|
||||
warn(LD_ACCT, "Unrecognized bw_accounting file version: %s",
|
||||
(const char*)smartlist_get(elts,0));
|
||||
goto err;
|
||||
}
|
||||
if (smartlist_len(elts) < 7) {
|
||||
log_fn(LOG_WARN, "Corrupted bw_accounting file: %d lines",
|
||||
warn(LD_ACCT, "Corrupted bw_accounting file: %d lines",
|
||||
smartlist_len(elts));
|
||||
goto err;
|
||||
}
|
||||
if (parse_iso_time(smartlist_get(elts,1), &t1)) {
|
||||
log_fn(LOG_WARN, "Error parsing bandwidth usage start time.");
|
||||
warn(LD_ACCT, "Error parsing bandwidth usage start time.");
|
||||
goto err;
|
||||
}
|
||||
if (parse_iso_time(smartlist_get(elts,2), &t2)) {
|
||||
log_fn(LOG_WARN, "Error parsing bandwidth usage last-written time");
|
||||
warn(LD_ACCT, "Error parsing bandwidth usage last-written time");
|
||||
goto err;
|
||||
}
|
||||
n_read = tor_parse_uint64(smartlist_get(elts,3), 10, 0, UINT64_MAX,
|
||||
&ok, NULL);
|
||||
if (!ok) {
|
||||
log_fn(LOG_WARN, "Error parsing number of bytes read");
|
||||
warn(LD_ACCT, "Error parsing number of bytes read");
|
||||
goto err;
|
||||
}
|
||||
n_written = tor_parse_uint64(smartlist_get(elts,4), 10, 0, UINT64_MAX,
|
||||
&ok, NULL);
|
||||
if (!ok) {
|
||||
log_fn(LOG_WARN, "Error parsing number of bytes read");
|
||||
warn(LD_ACCT, "Error parsing number of bytes read");
|
||||
goto err;
|
||||
}
|
||||
n_seconds = (uint32_t)tor_parse_ulong(smartlist_get(elts,5), 10,0,ULONG_MAX,
|
||||
&ok, NULL);
|
||||
if (!ok) {
|
||||
log_fn(LOG_WARN, "Error parsing number of seconds live");
|
||||
warn(LD_ACCT, "Error parsing number of seconds live");
|
||||
goto err;
|
||||
}
|
||||
expected_bw =(uint32_t)tor_parse_ulong(smartlist_get(elts,6), 10,0,ULONG_MAX,
|
||||
&ok, NULL);
|
||||
if (!ok) {
|
||||
log_fn(LOG_WARN, "Error parsing expected bandwidth");
|
||||
warn(LD_ACCT, "Error parsing expected bandwidth");
|
||||
goto err;
|
||||
}
|
||||
|
||||
@@ -614,7 +615,7 @@ read_bandwidth_usage(void)
|
||||
interval_start_time = t1;
|
||||
expected_bandwidth_usage = expected_bw;
|
||||
|
||||
log_fn(LOG_INFO, "Successfully read bandwidth accounting file written at %s for interval starting at %s. We have been active for %lu seconds in this interval. At the start of the interval, we expected to use about %lu KB per second. ("U64_FORMAT" bytes read so far, "U64_FORMAT" bytes written so far)",
|
||||
info(LD_ACCT, "Successfully read bandwidth accounting file written at %s for interval starting at %s. We have been active for %lu seconds in this interval. At the start of the interval, we expected to use about %lu KB per second. ("U64_FORMAT" bytes read so far, "U64_FORMAT" bytes written so far)",
|
||||
(char*)smartlist_get(elts,2),
|
||||
(char*)smartlist_get(elts,1),
|
||||
(unsigned long)n_seconds_active_in_interval,
|
||||
@@ -666,7 +667,7 @@ hibernate_begin(int new_state, time_t now)
|
||||
|
||||
if (new_state == HIBERNATE_STATE_EXITING &&
|
||||
hibernate_state != HIBERNATE_STATE_LIVE) {
|
||||
log(LOG_NOTICE,"Sigint received %s; exiting now.",
|
||||
notice(LD_GENERAL,"Sigint received %s; exiting now.",
|
||||
hibernate_state == HIBERNATE_STATE_EXITING ?
|
||||
"a second time" : "while hibernating");
|
||||
tor_cleanup();
|
||||
@@ -677,7 +678,7 @@ hibernate_begin(int new_state, time_t now)
|
||||
while ((conn = connection_get_by_type(CONN_TYPE_OR_LISTENER)) ||
|
||||
(conn = connection_get_by_type(CONN_TYPE_AP_LISTENER)) ||
|
||||
(conn = connection_get_by_type(CONN_TYPE_DIR_LISTENER))) {
|
||||
log_fn(LOG_INFO,"Closing listener type %d", conn->type);
|
||||
info(LD_NET,"Closing listener type %d", conn->type);
|
||||
connection_mark_for_close(conn);
|
||||
}
|
||||
|
||||
@@ -685,7 +686,7 @@ hibernate_begin(int new_state, time_t now)
|
||||
/* XXX upload rendezvous service descriptors with no intro points */
|
||||
|
||||
if (new_state == HIBERNATE_STATE_EXITING) {
|
||||
log(LOG_NOTICE,"Interrupt: will shut down in %d seconds. Interrupt again to exit now.", options->ShutdownWaitLength);
|
||||
notice(LD_GENERAL,"Interrupt: will shut down in %d seconds. Interrupt again to exit now.", options->ShutdownWaitLength);
|
||||
hibernate_end_time = time(NULL) + options->ShutdownWaitLength;
|
||||
} else { /* soft limit reached */
|
||||
hibernate_end_time = interval_end_time;
|
||||
@@ -703,7 +704,7 @@ hibernate_end(int new_state)
|
||||
hibernate_state == HIBERNATE_STATE_DORMANT);
|
||||
|
||||
/* listeners will be relaunched in run_scheduled_events() in main.c */
|
||||
log_fn(LOG_NOTICE,"Hibernation period ended. Resuming normal activity.");
|
||||
notice(LD_ACCT,"Hibernation period ended. Resuming normal activity.");
|
||||
|
||||
hibernate_state = new_state;
|
||||
hibernate_end_time = 0; /* no longer hibernating */
|
||||
@@ -738,7 +739,7 @@ hibernate_go_dormant(time_t now)
|
||||
else
|
||||
hibernate_begin(HIBERNATE_STATE_DORMANT, now);
|
||||
|
||||
log_fn(LOG_NOTICE,"Going dormant. Blowing away remaining connections.");
|
||||
notice(LD_ACCT,"Going dormant. Blowing away remaining connections.");
|
||||
|
||||
/* Close all OR/AP/exit conns. Leave dir conns because we still want
|
||||
* to be able to upload server descriptors so people know we're still
|
||||
@@ -751,7 +752,7 @@ hibernate_go_dormant(time_t now)
|
||||
if (CONN_IS_EDGE(conn))
|
||||
connection_edge_end(conn, END_STREAM_REASON_HIBERNATING,
|
||||
conn->cpath_layer);
|
||||
log_fn(LOG_INFO,"Closing conn type %d", conn->type);
|
||||
info(LD_NET,"Closing conn type %d", conn->type);
|
||||
if (conn->type == CONN_TYPE_AP) /* send socks failure if needed */
|
||||
connection_mark_unattached_ap(conn, END_STREAM_REASON_HIBERNATING);
|
||||
else
|
||||
@@ -780,10 +781,10 @@ hibernate_end_time_elapsed(time_t now)
|
||||
format_iso_time(buf,interval_wakeup_time);
|
||||
if (hibernate_state != HIBERNATE_STATE_DORMANT) {
|
||||
/* We weren't sleeping before; we should sleep now. */
|
||||
log_fn(LOG_NOTICE, "Accounting period ended. Commencing hibernation until %s GMT",buf);
|
||||
notice(LD_ACCT, "Accounting period ended. Commencing hibernation until %s GMT",buf);
|
||||
hibernate_go_dormant(now);
|
||||
} else {
|
||||
log_fn(LOG_NOTICE, "Accounting period ended. This period, we will hibernate until %s GMT",buf);
|
||||
notice(LD_ACCT, "Accounting period ended. This period, we will hibernate until %s GMT",buf);
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -802,7 +803,7 @@ consider_hibernation(time_t now)
|
||||
if (hibernate_state == HIBERNATE_STATE_EXITING) {
|
||||
tor_assert(hibernate_end_time);
|
||||
if (hibernate_end_time <= now) {
|
||||
log(LOG_NOTICE,"Clean shutdown finished. Exiting.");
|
||||
notice(LD_GENERAL, "Clean shutdown finished. Exiting.");
|
||||
tor_cleanup();
|
||||
exit(0);
|
||||
}
|
||||
@@ -825,11 +826,11 @@ consider_hibernation(time_t now)
|
||||
* go dormant. */
|
||||
if (hibernate_state == HIBERNATE_STATE_LIVE) {
|
||||
if (hibernate_soft_limit_reached()) {
|
||||
log_fn(LOG_NOTICE,"Bandwidth soft limit reached; commencing hibernation.");
|
||||
notice(LD_ACCT,"Bandwidth soft limit reached; commencing hibernation.");
|
||||
hibernate_begin(HIBERNATE_STATE_LOWBANDWIDTH, now);
|
||||
} else if (accounting_enabled && now < interval_wakeup_time) {
|
||||
format_iso_time(buf,interval_wakeup_time);
|
||||
log_fn(LOG_NOTICE, "Commencing hibernation. We will wake up at %s GMT",buf);
|
||||
notice(LD_ACCT,"Commencing hibernation. We will wake up at %s GMT",buf);
|
||||
hibernate_go_dormant(now);
|
||||
}
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user