commit 7d535ea9d3a0b2706392425c13feac760dfccdee Author: teor <teor2345@gmail.com> Date: Fri Jun 16 09:48:18 2017 +1000 Add extra logging during compression and decompression This helps diagnose failures. Part of #22502. --- src/common/compress.c | 13 ++++++++++++- src/or/directory.c | 49 ++++++++++++++++++++++++++++++++----------------- 2 files changed, 44 insertions(+), 18 deletions(-) diff --git a/src/common/compress.c b/src/common/compress.c index ee9de6a..e65894d 100644 --- a/src/common/compress.c +++ b/src/common/compress.c @@ -102,8 +102,13 @@ tor_compress_impl(int compress, stream = tor_compress_new(compress, method, compression_level); - if (stream == NULL) + if (stream == NULL) { + log_warn(LD_GENERAL, "NULL stream while %scompressing", + compress?"":"de"); + log_debug(LD_GENERAL, "method: %d level: %d at len: %zd", + method, compression_level, in_len); return -1; + } size_t in_len_orig = in_len; size_t out_remaining, out_alloc; @@ -137,6 +142,12 @@ tor_compress_impl(int compress, break; case TOR_COMPRESS_OK: if (compress || complete_only) { + log_fn(protocol_warn_level, LD_PROTOCOL, + "Unexpected %s while %scompressing", + complete_only?"end of input":"result", + compress?"":"de"); + log_debug(LD_GENERAL, "method: %d level: %d at len: %zd", + method, compression_level, in_len); goto err; } else { if (in_len != 0) { diff --git a/src/or/directory.c b/src/or/directory.c index acd694f..ecd9811 100644 --- a/src/or/directory.c +++ b/src/or/directory.c @@ -2327,30 +2327,40 @@ connection_dir_client_reached_eof(dir_connection_t *conn) plausible = body_is_plausible(body, body_len, conn->base_.purpose); if (compression != NO_METHOD || !plausible) { + int severity = LOG_DEBUG; char *new_body = NULL; size_t new_len = 0; + const char *description1, *description2; + int want_to_try_both = 0; + int tried_both = 0; compress_method_t guessed = detect_compression_method(body, body_len); - if (compression == UNKNOWN_METHOD || guessed != compression) { - /* Tell the user if we don't believe what we're told about compression.*/ - const char *description1, *description2; - description1 = compression_method_get_human_name(compression); + description1 = compression_method_get_human_name(compression); - if (BUG(description1 == NULL)) - description1 = compression_method_get_human_name(UNKNOWN_METHOD); + if (BUG(description1 == NULL)) + description1 = compression_method_get_human_name(UNKNOWN_METHOD); - if (guessed == UNKNOWN_METHOD && !plausible) - description2 = "confusing binary junk"; - else - description2 = compression_method_get_human_name(guessed); + if (guessed == UNKNOWN_METHOD && !plausible) + description2 = "confusing binary junk"; + else + description2 = compression_method_get_human_name(guessed); - log_info(LD_HTTP, "HTTP body from server '%s:%d' was labeled as %s, " - "but it seems to be %s.%s", - conn->base_.address, conn->base_.port, description1, - description2, - (compression>0 && guessed>0)?" Trying both.":""); + /* Tell the user if we don't believe what we're told about compression.*/ + want_to_try_both = (compression == UNKNOWN_METHOD || + guessed != compression); + if (want_to_try_both) { + severity = LOG_INFO; } + tor_log(severity, LD_HTTP, + "HTTP body from server '%s:%d' was labeled as %s, " + "%s it seems to be %s.%s", + conn->base_.address, conn->base_.port, description1, + guessed != compression?"but":"and", + description2, + (compression>0 && guessed>0 && want_to_try_both)? + " Trying both.":""); + /* Try declared compression first if we can. * tor_compress_supports_method() also returns true for NO_METHOD. * Ensure that the server is not sending us data compressed using a @@ -2376,14 +2386,19 @@ connection_dir_client_reached_eof(dir_connection_t *conn) } if (!new_body && tor_compress_supports_method(guessed) && - compression != guessed) + compression != guessed) { tor_uncompress(&new_body, &new_len, body, body_len, guessed, !allow_partial, LOG_PROTOCOL_WARN); + tried_both = 1; + } /* If we're pretty sure that we have a compressed directory, and * we didn't manage to uncompress it, then warn and bail. */ if (!plausible && !new_body) { log_fn(LOG_PROTOCOL_WARN, LD_HTTP, - "Unable to decompress HTTP body (server '%s:%d').", + "Unable to decompress HTTP body (tried %s%s%s, server '%s:%d').", + description1, + tried_both?" and ":"", + tried_both?description2:"", conn->base_.address, conn->base_.port); rv = -1; goto done;