enhance swiftclient logging

* log to debug for successes and info for errors
* remove dead code, neither body or raw_body are sent in kwargs
* include resp.reason and response headers in logging
* remove trailing \n in logging. users who want them can set logging.basicConfig(format=FORMAT)
* add --info option to swift cli

Change-Id: If07af46cb377f3f3d70f6c4284037241d360a8b7

3 files changed, 77 insertions, 14 deletions

diff --git a/bin/swift b/bin/swift
index 10bceca..2abb65a 100755
--- a/bin/swift
+++ b/bin/swift
@@ -1266,7 +1266,7 @@ if __name__ == '__main__':
     parser = OptionParser(version='%%prog %s' % version,
                           usage='''
 usage: %%prog [--version] [--help] [--snet] [--verbose]
-             [--debug] [--quiet] [--auth <auth_url>]
+             [--debug] [--info] [--quiet] [--auth <auth_url>]
              [--auth-version <auth_version>] [--user <username>]
              [--key <api_key>] [--retries <num_retries>]
              [--os-username <auth-user-name>] [--os-password <auth-password>]
@@ -1311,8 +1311,11 @@ Examples:
     parser.add_option('-v', '--verbose', action='count', dest='verbose',
                       default=1, help='Print more info')
     parser.add_option('--debug', action='store_true', dest='debug',
-                      default=False, help='Show the curl commands of all http '
-                      'queries.')
+                      default=False, help='Show the curl commands and results '
+                      'of all http queries regardless of result status.')
+    parser.add_option('--info', action='store_true', dest='info',
+                      default=False, help='Show the curl commands and results '
+                      ' of all http queries which return an error.')
     parser.add_option('-q', '--quiet', action='store_const', dest='verbose',
                       const=0, default=1, help='Suppress status output')
     parser.add_option('-A', '--auth', dest='auth',
@@ -1434,9 +1437,12 @@ Examples:
 
     signal.signal(signal.SIGINT, immediate_exit)
 
-    if options.debug:
+    if options.debug or options.info:
         logger = logging.getLogger("swiftclient")
-        logging.basicConfig(level=logging.DEBUG)
+        if options.debug:
+            logging.basicConfig(level=logging.DEBUG)
+        elif options.info:
+            logging.basicConfig(level=logging.INFO)
 
     had_error = False
 
diff --git a/swiftclient/client.py b/swiftclient/client.py
index a95ce70..3bbbc54 100644
--- a/swiftclient/client.py
+++ b/swiftclient/client.py
@@ -54,9 +54,10 @@ logger.addHandler(NullHandler())
 
 
 def http_log(args, kwargs, resp, body):
-    if not logger.isEnabledFor(logging.DEBUG):
+    if not logger.isEnabledFor(logging.INFO):
         return
 
+    # create and log equivalent curl command
     string_parts = ['curl -i']
     for element in args:
         if element == 'HEAD':
@@ -65,21 +66,22 @@ def http_log(args, kwargs, resp, body):
             string_parts.append(' -X %s' % element)
         else:
             string_parts.append(' %s' % element)
-
     if 'headers' in kwargs:
         for element in kwargs['headers']:
             header = ' -H "%s: %s"' % (element, kwargs['headers'][element])
             string_parts.append(header)
 
-    logger.debug("REQ: %s\n" % "".join(string_parts))
-    if 'raw_body' in kwargs:
-        logger.debug("REQ BODY (RAW): %s\n" % (kwargs['raw_body']))
-    if 'body' in kwargs:
-        logger.debug("REQ BODY: %s\n" % (kwargs['body']))
+    # log response as debug if good, or info if error
+    if resp.status < 300:
+        log_method = logger.debug
+    else:
+        log_method = logger.info
 
-    logger.debug("RESP STATUS: %s\n", resp.status)
+    log_method("REQ: %s" % "".join(string_parts))
+    log_method("RESP STATUS: %s %s" % (resp.status, resp.reason))
+    log_method("RESP HEADERS: %s", resp.getheaders())
     if body:
-        logger.debug("RESP BODY: %s\n", body)
+        log_method("RESP BODY: %s", body)
 
 
 def quote(value, safe='/'):
diff --git a/tests/test_swiftclient.py b/tests/test_swiftclient.py
index 6cf3c11..e827a2a 100644
--- a/tests/test_swiftclient.py
+++ b/tests/test_swiftclient.py
@@ -16,6 +16,7 @@
 # TODO: More tests
 import mock
 import httplib
+import logging
 import socket
 import StringIO
 import testtools
@@ -159,6 +160,7 @@ class MockHttpTest(testtools.TestCase):
 class MockHttpResponse():
     def __init__(self):
         self.status = 200
+        self.reason = "OK"
         self.buffer = []
 
     def read(self):
@@ -167,6 +169,9 @@ class MockHttpResponse():
     def getheader(self, name, default):
         return ""
 
+    def getheaders(self):
+        return {"key1": "value1", "key2": "value2"}
+
     def fake_response(self):
         return MockHttpResponse()
 
@@ -838,6 +843,9 @@ class TestConnection(MockHttpTest):
             def getheader(self, *args, **kwargs):
                 return 'header'
 
+            def getheaders(self):
+                return {"key1": "value1", "key2": "value2"}
+
             def read(self, *args, **kwargs):
                 return ''
 
@@ -883,5 +891,52 @@ class TestConnection(MockHttpTest):
             c.http_connection = orig_conn
 
 
+class TestLogging(MockHttpTest):
+    """
+    Make sure all the lines in http_log are covered.
+    """
+
+    def setUp(self):
+        super(TestLogging, self).setUp()
+        self.swiftclient_logger = logging.getLogger("swiftclient")
+        self.log_level = self.swiftclient_logger.getEffectiveLevel()
+        self.swiftclient_logger.setLevel(logging.INFO)
+
+    def tearDown(self):
+        self.swiftclient_logger.setLevel(self.log_level)
+        super(TestLogging, self).tearDown()
+
+    def test_put_ok(self):
+        c.http_connection = self.fake_http_connection(200)
+        args = ('http://www.test.com', 'asdf', 'asdf', 'asdf', 'asdf')
+        value = c.put_object(*args)
+        self.assertTrue(isinstance(value, basestring))
+
+    def test_head_error(self):
+        c.http_connection = self.fake_http_connection(500)
+        self.assertRaises(c.ClientException, c.head_object,
+                          'http://www.test.com', 'asdf', 'asdf', 'asdf')
+
+    def test_get_error(self):
+        body = 'c' * 65
+        conn = self.fake_http_connection(
+            404, body=body)('http://www.test.com/')
+        request_args = {}
+
+        def fake_request(method, url, body=None, headers=None):
+            request_args['method'] = method
+            request_args['url'] = url
+            request_args['body'] = body
+            request_args['headers'] = headers
+            return
+        conn[1].request = fake_request
+        headers = {'Range': 'bytes=1-2'}
+        self.assertRaises(
+            c.ClientException,
+            c.get_object,
+            'url_is_irrelevant', 'TOKEN', 'container', 'object',
+            http_conn=conn, headers=headers)
+
+
 if __name__ == '__main__':
     testtools.main()