commit 99b87d7ca48c5ed80aec5f24902843f72975bfea Author: Nick Mathewson <nickm@torproject.org> Date: Wed Apr 3 13:53:06 2019 -0400 Even more diagnostic messages for bug 28223. Try to figure out _where exactly_ we are first encountering NULs in microdescriptors, and what we are doing when that happens. --- changes/diagnostic_28223_redux | 4 ++++ src/feature/dirparse/microdesc_parse.c | 17 ++++++++++++++++- src/feature/nodelist/microdesc.c | 21 +++++++++++++++++++++ 3 files changed, 41 insertions(+), 1 deletion(-) diff --git a/changes/diagnostic_28223_redux b/changes/diagnostic_28223_redux new file mode 100644 index 000000000..0d7499832 --- /dev/null +++ b/changes/diagnostic_28223_redux @@ -0,0 +1,4 @@ + o Minor features (diagnostic): + - Add more diagnostic log messages in an attempt to solve + the issue of NUL bytes appearing in a microdescriptor cache. + Related to ticket 28223. diff --git a/src/feature/dirparse/microdesc_parse.c b/src/feature/dirparse/microdesc_parse.c index 5a75af399..1e26901ce 100644 --- a/src/feature/dirparse/microdesc_parse.c +++ b/src/feature/dirparse/microdesc_parse.c @@ -159,7 +159,22 @@ microdescs_parse_from_string(const char *s, const char *eos, if (tokenize_string(area, s, start_of_next_microdesc, tokens, microdesc_token_table, flags)) { - log_warn(LD_DIR, "Unparseable microdescriptor"); + const char *location; + switch (where) { + case SAVED_NOWHERE: + location = "download or generated string"; + break; + case SAVED_IN_CACHE: + location = "cache"; + break; + case SAVED_IN_JOURNAL: + location = "journal"; + break; + default: + location = "unknown location"; + break; + } + log_warn(LD_DIR, "Unparseable microdescriptor found in %s", location); goto next; } diff --git a/src/feature/nodelist/microdesc.c b/src/feature/nodelist/microdesc.c index dafaabb5e..af4f608d2 100644 --- a/src/feature/nodelist/microdesc.c +++ b/src/feature/nodelist/microdesc.c @@ -221,6 +221,13 @@ dump_microdescriptor(int fd, microdesc_t *md, size_t *annotation_len_out) } md->off = tor_fd_getpos(fd); + const char *nulpos = memchr(md->body, 0, md->bodylen); + if (BUG(nulpos)) { + log_warn(LD_BUG, "About to dump a NUL into a microdescriptor file. " + "offset %"PRId64", bodylen %zu, nul position %zu", + (int64_t)md->off, md->bodylen, + (size_t)(nulpos - md->body)); + } written = write_all_to_fd(fd, md->body, md->bodylen); if (written != (ssize_t)md->bodylen) { written = written < 0 ? 0 : written; @@ -480,6 +487,17 @@ microdesc_cache_clear(microdesc_cache_t *cache) cache->bytes_dropped = 0; } +static void +warn_if_nul_found(const char *inp, size_t len, const char *description) +{ + const char *nul_found = memchr(inp, 0, len); + if (BUG(nul_found)) { + log_warn(LD_BUG, "Found unexpected NUL while reading %s, at " + "position %zu/%zu.", + description, (nul_found - inp), len); + } +} + /** Reload the contents of <b>cache</b> from disk. If it is empty, load it * for the first time. Return 0 on success, -1 on failure. */ int @@ -497,6 +515,7 @@ microdesc_cache_reload(microdesc_cache_t *cache) mm = cache->cache_content = tor_mmap_file(cache->cache_fname); if (mm) { + warn_if_nul_found(mm->data, mm->size, "microdesc cache"); added = microdescs_add_to_cache(cache, mm->data, mm->data+mm->size, SAVED_IN_CACHE, 0, -1, NULL); if (added) { @@ -509,6 +528,8 @@ microdesc_cache_reload(microdesc_cache_t *cache) RFTS_IGNORE_MISSING, &st); if (journal_content) { cache->journal_len = (size_t) st.st_size; + warn_if_nul_found(journal_content, cache->journal_len, + "microdesc journal"); added = microdescs_add_to_cache(cache, journal_content, journal_content+st.st_size, SAVED_IN_JOURNAL, 0, -1, NULL);