From 7d535ea9d3a0b2706392425c13feac760dfccdee Mon Sep 17 00:00:00 2001
From: teor <teor2345@gmail.com>
Date: Fri, 16 Jun 2017 09:48:18 +1000
Subject: [PATCH] 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 ee9de6a768..e65894d9d2 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 acd694ffee..ecd98119fe 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;