Fix how bytes transferred are logged

swift/proxy/server.py

@@ -385,7 +385,8 @@ class Controller(object):
                     source.read()
                     continue
             if req.method == 'GET' and source.status in (200, 206):
-
+                res = Response(request=req, conditional_response=True)
+                res.bytes_transferred = 0
                 def file_iter():
                     try:
                         while True:
@@ -394,9 +395,9 @@ class Controller(object):
                             if not chunk:
                                 break
                             yield chunk
-                            req.sent_size += len(chunk)
+                            res.bytes_transferred += len(chunk)
                     except GeneratorExit:
-                        req.client_disconnect = True
+                        res.client_disconnect = True
                         self.app.logger.info(
                             'Client disconnected on read transaction %s' %
                             self.trans_id)
@@ -404,9 +405,7 @@ class Controller(object):
                         self.exception_occurred(node, 'Object',
                             'Trying to read during GET of %s' % req.path)
                         raise
-
+                res.app_iter = file_iter()
-                res = Response(app_iter=file_iter(), request=req,
-                               conditional_response=True)
                 update_headers(res, source.getheaders())
                 res.status = source.status
                 res.content_length = source.getheader('Content-Length')
@@ -622,7 +621,7 @@ class ObjectController(Controller):
                 (len(conns), len(nodes) / 2 + 1, self.trans_id))
             return HTTPServiceUnavailable(request=req)
         try:
-            req.creation_size = 0
+            req.bytes_transferred = 0
             while True:
                 with ChunkReadTimeout(self.app.client_timeout):
                     try:
@@ -633,9 +632,8 @@ class ObjectController(Controller):
                         else:
                             break
                 len_chunk = len(chunk)
-                req.creation_size += len_chunk
+                req.bytes_transferred += len_chunk
-                if req.creation_size > MAX_FILE_SIZE:
+                if req.bytes_transferred > MAX_FILE_SIZE:
-                    req.creation_size = 0
                     return HTTPRequestEntityTooLarge(request=req)
                 for conn in conns:
                     try:
@@ -655,10 +653,12 @@ class ObjectController(Controller):
                 'ERROR Client read timeout (%ss)' % err.seconds)
             return HTTPRequestTimeout(request=req)
         except:
+            req.client_disconnect = True
             self.app.logger.exception(
                 'ERROR Exception causing client disconnect')
             return Response(status='499 Client Disconnect')
-        if req.content_length and req.creation_size < req.content_length:
+        if req.content_length and req.bytes_transferred < req.content_length:
+            req.client_disconnect = True
             self.app.logger.info(
                 'Client disconnected without sending enough data %s' %
                 self.trans_id)
@@ -1027,8 +1027,7 @@ class BaseApplication(object):
         pass
 
     def update_request(self, req):
-        req.creation_size = '-'
+        req.bytes_transferred = '-'
-        req.sent_size = 0
         req.client_disconnect = False
         req.headers['x-cf-trans-id'] = 'tx' + str(uuid.uuid4())
         if 'x-storage-token' in req.headers and \
@@ -1099,9 +1098,6 @@ class Application(BaseApplication):
     def posthooklogger(self, env, req):
         response = req.response
         trans_time = '%.4f' % (time.time() - req.start_time)
-        if not response.content_length and response.app_iter and \
-                    hasattr(response.app_iter, '__len__'):
-            response.content_length = sum(map(len, response.app_iter))
         the_request = quote(unquote(req.path))
         if req.query_string:
             the_request = the_request + '?' + req.query_string
@@ -1110,20 +1106,14 @@ class Application(BaseApplication):
         if not client and 'x-forwarded-for' in req.headers:
             # remote user for other lbs
             client = req.headers['x-forwarded-for'].split(',')[0].strip()
-        raw_in = req.content_length or 0
-        if req.creation_size != '-':
-            raw_in = req.creation_size
-        raw_out = 0
-        if req.method != 'HEAD':
-            if response.content_length:
-                raw_out = response.content_length
-            if req.sent_size or req.client_disconnect:
-                raw_out = req.sent_size
         logged_headers = None
         if self.log_headers:
             logged_headers = '\n'.join('%s: %s' % (k, v)
                 for k, v in req.headers.items())
-        status_int = req.client_disconnect and 499 or response.status_int
+        status_int = response.status_int
+        if getattr(req, 'client_disconnect', False) or \
+                getattr(response, 'client_disconnect', False):
+            status_int = 499
         self.logger.info(' '.join(quote(str(x)) for x in (
                 client or '-',
                 req.remote_addr or '-',
@@ -1135,8 +1125,8 @@ class Application(BaseApplication):
                 req.referer or '-',
                 req.user_agent or '-',
                 req.headers.get('x-auth-token', '-'),
-                raw_in or '-',
+                getattr(req, 'bytes_transferred', 0) or '-',
-                raw_out or '-',
+                getattr(response, 'bytes_transferred', 0) or '-',
                 req.headers.get('etag', '-'),
                 req.headers.get('x-cf-trans-id', '-'),
                 logged_headers or '-',

test/unit/proxy/test_server.py

@@ -50,7 +50,7 @@ logging.getLogger().addHandler(logging.StreamHandler(sys.stdout))
 
 def fake_http_connect(*code_iter, **kwargs):
     class FakeConn(object):
-        def __init__(self, status, etag=None):
+        def __init__(self, status, etag=None, body=''):
             self.status = status
             self.reason = 'Fake'
             self.host = '1.2.3.4'
@@ -58,6 +58,7 @@ def fake_http_connect(*code_iter, **kwargs):
             self.sent = 0
             self.received = 0
             self.etag = etag
+            self.body = body
         def getresponse(self):
             if 'raise_exc' in kwargs:
                 raise Exception('test')
@@ -65,7 +66,7 @@ def fake_http_connect(*code_iter, **kwargs):
         def getexpect(self):
             return FakeConn(100)
         def getheaders(self):
-            headers = {'content-length': 0,
+            headers = {'content-length': len(self.body),
                        'content-type': 'x-application/test',
                        'x-timestamp': '1',
                        'x-object-meta-test': 'testing',
@@ -87,7 +88,9 @@ def fake_http_connect(*code_iter, **kwargs):
                     self.sent += 1
                     sleep(0.1)
                     return ' '
-            return ''
+            rv = self.body[:amt]
+            self.body = self.body[amt:]
+            return rv
         def send(self, amt=None):
             if 'slow' in kwargs:
                 if self.received < 4:
@@ -111,7 +114,7 @@ def fake_http_connect(*code_iter, **kwargs):
         etag = etag_iter.next()
         if status == -1:
             raise HTTPException()
-        return FakeConn(status, etag)
+        return FakeConn(status, etag, body=kwargs.get('body', ''))
     return connect
 
 
@@ -1458,6 +1461,72 @@ class TestObjectController(unittest.TestCase):
             resp = controller.PUT(req)
             self.assertEquals(resp.status_int, 422)
 
+    def test_request_bytes_transferred_attr(self):
+        with save_globals():
+            proxy_server.http_connect = \
+                fake_http_connect(200, 200, 201, 201, 201)
+            controller = proxy_server.ObjectController(self.app, 'account',
+                            'container', 'object')
+            req = Request.blank('/a/c/o', environ={'REQUEST_METHOD': 'PUT'},
+                                headers={'Content-Length': '10'},
+                                body='1234567890')
+            req.account = 'a'
+            res = controller.PUT(req)
+            self.assert_(hasattr(req, 'bytes_transferred'))
+            self.assertEquals(req.bytes_transferred, 10)
+
+    def test_response_bytes_transferred_attr(self):
+        with save_globals():
+            proxy_server.http_connect = \
+                fake_http_connect(200, body='1234567890')
+            controller = proxy_server.ObjectController(self.app, 'account',
+                            'container', 'object')
+            req = Request.blank('/a/c/o')
+            req.account = 'a'
+            res = controller.GET(req)
+            res.body
+            self.assert_(hasattr(res, 'bytes_transferred'))
+            self.assertEquals(res.bytes_transferred, 10)
+
+    def test_request_client_disconnect_attr(self):
+        with save_globals():
+            proxy_server.http_connect = \
+                fake_http_connect(200, 200, 201, 201, 201)
+            controller = proxy_server.ObjectController(self.app, 'account',
+                            'container', 'object')
+            req = Request.blank('/a/c/o', environ={'REQUEST_METHOD': 'PUT'},
+                                headers={'Content-Length': '10'},
+                                body='12345')
+            req.account = 'a'
+            res = controller.PUT(req)
+            self.assertEquals(req.bytes_transferred, 5)
+            self.assert_(hasattr(req, 'client_disconnect'))
+            self.assert_(req.client_disconnect)
+
+    def test_response_client_disconnect_attr(self):
+        with save_globals():
+            proxy_server.http_connect = \
+                fake_http_connect(200, body='1234567890')
+            controller = proxy_server.ObjectController(self.app, 'account',
+                            'container', 'object')
+            req = Request.blank('/a/c/o')
+            req.account = 'a'
+            orig_object_chunk_size = self.app.object_chunk_size
+            try:
+                self.app.object_chunk_size = 5
+                res = controller.GET(req)
+                ix = 0
+                for v in res.app_iter:
+                    ix += 1
+                    if ix > 1:
+                        break
+                res.app_iter.close()
+                self.assertEquals(res.bytes_transferred, 5)
+                self.assert_(hasattr(res, 'client_disconnect'))
+                self.assert_(res.client_disconnect)
+            finally: 
+                self.app.object_chunk_size = orig_object_chunk_size
+
 
 class TestContainerController(unittest.TestCase):
     "Test swift.proxy_server.ContainerController"
@@ -1646,6 +1715,41 @@ class TestContainerController(unittest.TestCase):
             # 200: Account check, 404x3: Container check
             self.assert_status_map(controller.DELETE, (200, 404, 404, 404), 404)
 
+    def test_response_bytes_transferred_attr(self):
+        with save_globals():
+            proxy_server.http_connect = fake_http_connect(200, 200, body='{}')
+            controller = proxy_server.ContainerController(self.app, 'account',
+                                                          'container')
+            req = Request.blank('/a/c?format=json')
+            req.account = 'a'
+            res = controller.GET(req)
+            res.body
+            self.assert_(hasattr(res, 'bytes_transferred'))
+            self.assertEquals(res.bytes_transferred, 2)
+
+    def test_response_client_disconnect_attr(self):
+        with save_globals():
+            proxy_server.http_connect = fake_http_connect(200, 200, body='{}')
+            controller = proxy_server.ContainerController(self.app, 'account',
+                                                          'container')
+            req = Request.blank('/a/c?format=json')
+            req.account = 'a'
+            orig_object_chunk_size = self.app.object_chunk_size
+            try:
+                self.app.object_chunk_size = 1
+                res = controller.GET(req)
+                ix = 0
+                for v in res.app_iter:
+                    ix += 1
+                    if ix > 1:
+                        break
+                res.app_iter.close()
+                self.assertEquals(res.bytes_transferred, 1)
+                self.assert_(hasattr(res, 'client_disconnect'))
+                self.assert_(res.client_disconnect)
+            finally: 
+                self.app.object_chunk_size = orig_object_chunk_size
+
 
 class TestAccountController(unittest.TestCase):
 
@@ -1728,6 +1832,39 @@ class TestAccountController(unittest.TestCase):
         resp = controller.HEAD(req)
         self.assertEquals(resp.status_int, 503)
 
+    def test_response_bytes_transferred_attr(self):
+        with save_globals():
+            proxy_server.http_connect = fake_http_connect(200, 200, body='{}')
+            controller = proxy_server.AccountController(self.app, 'account')
+            req = Request.blank('/a?format=json')
+            req.account = 'a'
+            res = controller.GET(req)
+            res.body
+            self.assert_(hasattr(res, 'bytes_transferred'))
+            self.assertEquals(res.bytes_transferred, 2)
+
+    def test_response_client_disconnect_attr(self):
+        with save_globals():
+            proxy_server.http_connect = fake_http_connect(200, 200, body='{}')
+            controller = proxy_server.AccountController(self.app, 'account')
+            req = Request.blank('/a?format=json')
+            req.account = 'a'
+            orig_object_chunk_size = self.app.object_chunk_size
+            try:
+                self.app.object_chunk_size = 1
+                res = controller.GET(req)
+                ix = 0
+                for v in res.app_iter:
+                    ix += 1
+                    if ix > 1:
+                        break
+                res.app_iter.close()
+                self.assertEquals(res.bytes_transferred, 1)
+                self.assert_(hasattr(res, 'client_disconnect'))
+                self.assert_(res.client_disconnect)
+            finally: 
+                self.app.object_chunk_size = orig_object_chunk_size
+
 
 if __name__ == '__main__':
     unittest.main()