Fix logging of the gzipped body

Change-Id: I6d7ccbf4ef9b46e890ecec58842c5cdd2804c7a9
Closes-bug: 1670620

4 files changed, 73 insertions, 5 deletions

diff --git a/swiftclient/client.py b/swiftclient/client.py
index 21cbe27..80b6eda 100644
--- a/swiftclient/client.py
+++ b/swiftclient/client.py
@@ -32,7 +32,8 @@ import six
 from swiftclient import version as swiftclient_version
 from swiftclient.exceptions import ClientException
 from swiftclient.utils import (
-    iter_wrapper, LengthWrapper, ReadableToIterable, parse_api_response)
+    iter_wrapper, LengthWrapper, ReadableToIterable, parse_api_response,
+    get_body)
 
 # Default is 100, increase to 256
 http_client._MAXHEADERS = 256
@@ -165,7 +166,9 @@ def http_log(args, kwargs, resp, body):
     log_method("RESP STATUS: %s %s", resp.status, resp.reason)
     log_method("RESP HEADERS: %s", scrub_headers(resp.getheaders()))
     if body:
-        log_method("RESP BODY: %s", body)
+        resp_headers = resp_header_dict(resp)
+        nbody = get_body(resp_headers, body)
+        log_method("RESP BODY: %s", nbody)
 
 
 def parse_header_string(data):
diff --git a/swiftclient/utils.py b/swiftclient/utils.py
index 9f8af1f..47856c2 100644
--- a/swiftclient/utils.py
+++ b/swiftclient/utils.py
@@ -143,11 +143,16 @@ def generate_temp_url(path, seconds, key, method, absolute=False,
         return temp_url
 
 
-def parse_api_response(headers, body):
+def get_body(headers, body):
     if headers.get('content-encoding') == 'gzip':
         with gzip.GzipFile(fileobj=six.BytesIO(body), mode='r') as gz:
-            body = gz.read()
+            nbody = gz.read()
+        return nbody
+    return body
+
 
+def parse_api_response(headers, body):
+    body = get_body(headers, body)
     charset = 'utf-8'
     # Swift *should* be speaking UTF-8, but check content-type just in case
     content_type = headers.get('content-type', '')
diff --git a/tests/unit/test_swiftclient.py b/tests/unit/test_swiftclient.py
index 3a24b00..d4a704e 100644
--- a/tests/unit/test_swiftclient.py
+++ b/tests/unit/test_swiftclient.py
@@ -13,6 +13,7 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
+import gzip
 import logging
 import mock
 import six
@@ -82,7 +83,7 @@ class TestClientException(unittest.TestCase):
 
 
 class MockHttpResponse(object):
-    def __init__(self, status=0, headers=None, verify=False):
+    def __init__(self, status=0, headers=None, verify=False, need_items=None):
         self.status = status
         self.status_code = status
         self.reason = "OK"
@@ -91,6 +92,7 @@ class MockHttpResponse(object):
         self.verify = verify
         self.md5sum = md5()
         self.headers = {'etag': '"%s"' % EMPTY_ETAG}
+        self.need_items = need_items
         if headers:
             self.headers.update(headers)
         self.closed = False
@@ -117,6 +119,8 @@ class MockHttpResponse(object):
         return self.headers.get(name, default)
 
     def getheaders(self):
+        if self.need_items:
+            return dict(self.headers).items()
         return dict(self.headers)
 
     def fake_response(self):
@@ -2607,6 +2611,44 @@ class TestLogging(MockHttpTest):
             self.assertNotIn(unicode_token_value, output)
             self.assertNotIn(set_cookie_value, output)
 
+    def test_logging_body(self):
+        with mock.patch('swiftclient.client.logger.debug') as mock_log:
+            token_value = 'tkee96b40a8ca44fc5ad72ec5a7c90d9b'
+            token_encoded = token_value.encode('utf8')
+            unicode_token_value = (u'\u5929\u7a7a\u4e2d\u7684\u4e4c\u4e91'
+                                   u'\u5929\u7a7a\u4e2d\u7684\u4e4c\u4e91'
+                                   u'\u5929\u7a7a\u4e2d\u7684\u4e4c')
+            unicode_token_encoded = unicode_token_value.encode('utf8')
+            set_cookie_value = 'X-Auth-Token=%s' % token_value
+            set_cookie_encoded = set_cookie_value.encode('utf8')
+            buf = six.BytesIO()
+            gz = gzip.GzipFile(fileobj=buf, mode='w')
+            gz.write(u'{"test": "\u2603"}'.encode('utf8'))
+            gz.close()
+            c.http_log(
+                ['GET'],
+                {'headers': {
+                    'X-Auth-Token': token_encoded,
+                    'X-Storage-Token': unicode_token_encoded
+                }},
+                MockHttpResponse(
+                    status=200,
+                    headers={
+                        'X-Auth-Token': token_encoded,
+                        'X-Storage-Token': unicode_token_encoded,
+                        'content-encoding': 'gzip',
+                        'Etag': b'mock_etag',
+                        'Set-Cookie': set_cookie_encoded
+                    },
+                    need_items=True,
+                ),
+                buf.getvalue(),
+            )
+            self.assertEqual(
+                mock.call(
+                    'RESP BODY: %s', u'{"test": "\u2603"}'.encode('utf8')),
+                mock_log.mock_calls[3])
+
     def test_show_token(self):
         with mock.patch('swiftclient.client.logger.debug') as mock_log:
             token_value = 'tkee96b40a8ca44fc5ad72ec5a7c90d9b'
diff --git a/tests/unit/test_utils.py b/tests/unit/test_utils.py
index cbea8d8..c5961e8 100644
--- a/tests/unit/test_utils.py
+++ b/tests/unit/test_utils.py
@@ -507,3 +507,21 @@ class TestApiResponeParser(unittest.TestCase):
             {'content-encoding': 'gzip'},
             buf.getvalue())
         self.assertEqual({'test': u'\u2603'}, result)
+
+
+class TestGetBody(unittest.TestCase):
+
+    def test_not_gzipped(self):
+        result = u.parse_api_response(
+            {}, u'{"test": "\\u2603"}'.encode('utf8'))
+        self.assertEqual({'test': u'\u2603'}, result)
+
+    def test_gzipped_body(self):
+        buf = six.BytesIO()
+        gz = gzip.GzipFile(fileobj=buf, mode='w')
+        gz.write(u'{"test": "\u2603"}'.encode('utf8'))
+        gz.close()
+        result = u.parse_api_response(
+            {'content-encoding': 'gzip'},
+            buf.getvalue())
+        self.assertEqual({'test': u'\u2603'}, result)