commit 726dc9acf599567bf2ed1786fc2af785f15cac25 Author: Andrea Shepard andrea@torproject.org Date: Sat Jun 25 05:20:46 2016 +0000

Remove old unparseable descriptor logging mechanism, add bump-to-head-of-queue for repeated unparseable descriptors, rename config variable --- src/or/config.c | 2 +- src/or/or.h | 6 +- src/or/routerparse.c | 231 ++++++++++++++++++++++++++------------------------- 3 files changed, 123 insertions(+), 116 deletions(-)

diff --git a/src/or/config.c b/src/or/config.c index 275be28..b00f8a9 100644 --- a/src/or/config.c +++ b/src/or/config.c @@ -212,7 +212,6 @@ static config_var_t option_vars_[] = { V(CountPrivateBandwidth, BOOL, "0"), V(DataDirectory, FILENAME, NULL), V(DataDirectoryGroupReadable, BOOL, "0"), - V(DetailedLogForUnparseableDescriptors, MEMUNIT, "0 bytes"), V(DisableNetwork, BOOL, "0"), V(DirAllowPrivateAddresses, BOOL, "0"), V(TestingAuthDirTimeToLearnReachability, INTERVAL, "30 minutes"), @@ -326,6 +325,7 @@ static config_var_t option_vars_[] = { VAR("MaxMemInQueues", MEMUNIT, MaxMemInQueues_raw, "0"), OBSOLETE("MaxOnionsPending"), V(MaxOnionQueueDelay, MSEC_INTERVAL, "1750 msec"), + V(MaxUnparseableDescSizeToLog, MEMUNIT, "10 MB"), V(MinMeasuredBWsForAuthToIgnoreAdvertised, INT, "500"), V(MyFamily, STRING, NULL), V(NewCircuitPeriod, INTERVAL, "30 seconds"), diff --git a/src/or/or.h b/src/or/or.h index 364699f..a1a0810 100644 --- a/src/or/or.h +++ b/src/or/or.h @@ -4499,10 +4499,10 @@ typedef struct { /** Autobool: Do we try to retain capabilities if we can? */ int KeepBindCapabilities;

- /** If > 0, maximum total size of unparseable descriptors to log - * during the lifetime of this Tor process. + /** Maximum total size of unparseable descriptors to log during the + * lifetime of this Tor process. */ - uint64_t DetailedLogForUnparseableDescriptors; + uint64_t MaxUnparseableDescSizeToLog; } or_options_t;

/** Persistent state for an onion router, as saved to disk. */ diff --git a/src/or/routerparse.c b/src/or/routerparse.c index 5ad6549..1d227fd 100644 --- a/src/or/routerparse.c +++ b/src/or/routerparse.c @@ -585,28 +585,40 @@ static int check_signature_token(const char *digest, #define DUMP_AREA(a,name) STMT_NIL #endif

-/** Last time we dumped a descriptor to disk. */ -static time_t last_desc_dumped = 0; +/* Dump mechanism for unparseable descriptors */ + /** List of dumped descriptors for FIFO cleanup purposes */ static smartlist_t *descs_dumped = NULL; /** Total size of dumped descriptors for FIFO cleanup */ static size_t len_descs_dumped = 0;

+/* + * One entry in the list of dumped descriptors; filename dumped to, length + * and SHA-256. + */ + typedef struct { char *filename; size_t len; - time_t timestamp; + uint8_t digest_sha256[DIGEST256_LEN]; } dumped_desc_t;

/** Dump desc FIFO/cleanup; take ownership of the given filename, add it to * the FIFO, and clean up the oldest entries to the extent they exceed the - * configured cap. */ + * configured cap. If any old entries with a matching hash existed, they + * just got overwritten right before this was called and we should adjust + * the total size counter without deleting them. + */ static void -dump_desc_fifo_add_and_clean(char *filename, size_t len, time_t now) +dump_desc_fifo_add_and_clean(char *filename, const uint8_t *digest_sha256, + size_t len) { dumped_desc_t *ent = NULL, *tmp; size_t max_len;

+ tor_assert(filename != NULL); + tor_assert(digest_sha256 != NULL); + if (descs_dumped == NULL) { /* We better have no length, then */ tor_assert(len_descs_dumped == 0); @@ -618,43 +630,45 @@ dump_desc_fifo_add_and_clean(char *filename, size_t len, time_t now) ent = tor_malloc_zero(sizeof(*ent)); ent->filename = filename; ent->len = len; - ent->timestamp = now; + memcpy(ent->digest_sha256, digest_sha256, DIGEST256_LEN);

/* Do we need to do some cleanup? */ - if (get_options()->DetailedLogForUnparseableDescriptors > 0) { - max_len = get_options()->DetailedLogForUnparseableDescriptors; - /* Iterate over the list until we've freed enough space */ - while (len_descs_dumped + len > max_len && - smartlist_len(descs_dumped) > 0) { - /* Get the oldest thing on the list */ - tmp = (dumped_desc_t *)(smartlist_get(descs_dumped, 0)); + max_len = get_options()->MaxUnparseableDescSizeToLog; + /* Iterate over the list until we've freed enough space */ + while (len_descs_dumped + len > max_len && + smartlist_len(descs_dumped) > 0) { + /* Get the oldest thing on the list */ + tmp = (dumped_desc_t *)(smartlist_get(descs_dumped, 0)); + + /* + * Check if it matches the filename we just added, so we don't delete + * something we just emitted if we get repeated identical descriptors. + */ + if (strcmp(tmp->filename, filename) != 0) { + /* Delete it and adjust the length counter */ + unlink(tmp->filename); + tor_assert(len_descs_dumped >= tmp->len); + len_descs_dumped -= tmp->len; + log_info(LD_DIR, + "Deleting old unparseable descriptor dump %s due to " + "space limits", + tmp->filename); + } else { /* - * Check if it matches the filename we just added, so we don't - * delete something we just emitted if we get repeated identical - * descriptors. + * Don't delete, but do adjust the counter since we will bump it + * later */ - if (strcmp(tmp->filename, filename) != 0) { - /* Delete it and adjust the length counter */ - unlink(tmp->filename); - tor_assert(len_descs_dumped >= tmp->len); - len_descs_dumped -= tmp->len; - log_info(LD_DIR, "Deleting old unparseable descriptor dump %s due to " - "space limits", tmp->filename); - } else { - /* - * Don't delete, but do adjust the counter since we will bump it - * later - */ - tor_assert(len_descs_dumped >= tmp->len); - len_descs_dumped -= tmp->len; - log_info(LD_DIR, "Replacing old descriptor dump %s with new identical" - " one", tmp->filename); - } - /* Free it and remove it from the list */ - smartlist_del_keeporder(descs_dumped, 0); - tor_free(tmp->filename); - tor_free(tmp); + tor_assert(len_descs_dumped >= tmp->len); + len_descs_dumped -= tmp->len; + log_info(LD_DIR, + "Replacing old descriptor dump %s with new identical one", + tmp->filename); } + + /* Free it and remove it from the list */ + smartlist_del_keeporder(descs_dumped, 0); + tor_free(tmp->filename); + tor_free(tmp); }

/* Append our entry to the end of the list and bump the counter */ @@ -662,6 +676,43 @@ dump_desc_fifo_add_and_clean(char *filename, size_t len, time_t now) len_descs_dumped += len; }

+/** Check if we already have a descriptor for this hash and move it to the + * head of the queue if so. Return 1 if one existed and 0 otherwise. + */ +static int +dump_desc_fifo_bump_hash(const uint8_t *digest_sha256) +{ + dumped_desc_t *match = NULL; + + tor_assert(digest_sha256); + + if (descs_dumped) { + /* Find a match if one exists */ + SMARTLIST_FOREACH_BEGIN(descs_dumped, dumped_desc_t *, ent) { + if (ent && + memcmp(ent->digest_sha256, digest_sha256, DIGEST256_LEN) == 0) { + /* + * Save a pointer to the match and remove it from its current + * position. + */ + match = ent; + SMARTLIST_DEL_CURRENT_KEEPORDER(descs_dumped, ent); + break; + } + } SMARTLIST_FOREACH_END(ent); + + if (match) { + /* Add it back at the end of the list */ + smartlist_add(descs_dumped, match); + + /* Indicate we found one */ + return 1; + } + } + + return 0; +} + /** Clean up on exit; just memory, leave the dumps behind */ static void @@ -688,28 +739,14 @@ dump_desc_fifo_cleanup(void) static void dump_desc(const char *desc, const char *type) { - time_t now = time(NULL); tor_assert(desc); tor_assert(type); - /* Are we dumping this one to a file? */ - int dumping_this_one; - /* - * Are we including the hash in the filename and using the - * FIFO mechanism? - */ - int dumping_by_hash; - /* Emit an "Unable to parse descriptor..." prefix? */ - int emit_prefix; size_t len; /* The SHA256 of the string */ uint8_t digest_sha256[DIGEST256_LEN]; char digest_sha256_hex[HEX_DIGEST256_LEN+1]; /* Filename to log it to */ char *debugfile, *debugfile_base; - /* Expected length of file */ - size_t filelen; - /* File content */ - char *content;

/* Get the hash for logging purposes anyway */ len = strlen(desc); @@ -724,76 +761,46 @@ dump_desc(const char *desc, const char *type) base16_encode(digest_sha256_hex, sizeof(digest_sha256_hex), (const char *)digest_sha256, sizeof(digest_sha256));

- if (get_options()->DetailedLogForUnparseableDescriptors > 0) { - /* Okay, we're logging to a fresh file named by hash for each one */ - dumping_by_hash = 1; - dumping_this_one = 1; - /* - * Detailed logging mechanism will mention type and hash in the main log; - * don't clutter up the files with anything but the exact dump. - */ - emit_prefix = 0; - tor_asprintf(&debugfile_base, "unparseable-desc.%s", digest_sha256_hex); - debugfile = get_datadir_fname(debugfile_base); - } else if (!last_desc_dumped || last_desc_dumped + 60 < now) { - /* Simple mechanism, check so we don't dump too often */ - dumping_by_hash = 0; - dumping_this_one = 1; - emit_prefix = 1; - debugfile_base = tor_strdup("unparseable-desc"); - debugfile = get_datadir_fname(debugfile_base); - } else { - /* No logging of the full descriptor this time */ - dumping_by_hash = 0; - dumping_this_one = 0; - emit_prefix = 1; - debugfile_base = NULL; - debugfile = NULL; - } - - if (dumping_this_one) { - if (emit_prefix) filelen = 50 + strlen(type) + len; - else filelen = len; - - /* Get content pointing at what we're writing */ - if (emit_prefix) { - content = tor_malloc_zero(filelen); - tor_snprintf(content, filelen, "Unable to parse descriptor of type " - "%s:\n%s", type, desc); - } else { - content = tor_strdup(desc); - } - - /* Write it, and tell the main log about it */ - write_str_to_file(debugfile, content, 1); - log_info(LD_DIR, - "Unable to parse descriptor of type %s with hash %s and length " - "%lu. See file %s in data directory for details.", - type, digest_sha256_hex, (unsigned long)len, debugfile_base); - - /* Free our in-memory copy if necessary */ - tor_free(content); - - last_desc_dumped = now; - - /* Give it to the FIFO and clean up as needed, if we're using one */ - if (dumping_by_hash) { - dump_desc_fifo_add_and_clean(debugfile, filelen, now); + /* + * We mention type and hash in the main log; don't clutter up the files + * with anything but the exact dump. + */ + tor_asprintf(&debugfile_base, "unparseable-desc.%s", digest_sha256_hex); + debugfile = get_datadir_fname(debugfile_base); + + if (len <= get_options()->MaxUnparseableDescSizeToLog) { + if (!dump_desc_fifo_bump_hash(digest_sha256)) { + /* Write it, and tell the main log about it */ + write_str_to_file(debugfile, desc, 1); + log_info(LD_DIR, + "Unable to parse descriptor of type %s with hash %s and " + "length %lu. See file %s in data directory for details.", + type, digest_sha256_hex, (unsigned long)len, debugfile_base); + + dump_desc_fifo_add_and_clean(debugfile, digest_sha256, len); /* Since we handed ownership over, don't free debugfile later */ debugfile = NULL; + } else { + /* We already had one with this hash dumped */ + log_info(LD_DIR, + "Unable to parse descriptor of type %s with hash %s and " + "length %lu. Descriptor not dumped because one with that hash " + "has already been dumped.", + type, digest_sha256_hex, (unsigned long)len); + /* We do have to free debugfile in this case */ } } else { /* Just log that it happened without dumping */ log_info(LD_DIR, "Unable to parse descriptor of type %s with hash %s and length " - "%lu. Descriptor not dumped since we just dumped one %u seconds " - "ago.", - type, digest_sha256_hex, (unsigned long)len, - (unsigned int)(now - last_desc_dumped)); + "%lu. Descriptor not dumped because it exceeds maximum log size " + "all by itself.", + type, digest_sha256_hex, (unsigned long)len); + /* We do have to free debugfile in this case */ }

- if (debugfile_base != NULL) tor_free(debugfile_base); - if (debugfile != NULL) tor_free(debugfile); + tor_free(debugfile_base); + tor_free(debugfile);

err: return;