Fix how bytes transferred are logged

This commit is contained in:
gholt 2010-08-09 20:52:16 +00:00 committed by Tarmac
commit 40779d8d21
2 changed files with 159 additions and 32 deletions

View File

@ -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 = Response(app_iter=file_iter(), request=req,
conditional_response=True)
res.app_iter = file_iter()
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
if req.creation_size > MAX_FILE_SIZE:
req.creation_size = 0
req.bytes_transferred += len_chunk
if req.bytes_transferred > MAX_FILE_SIZE:
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.sent_size = 0
req.bytes_transferred = '-'
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 '-',
raw_out or '-',
getattr(req, 'bytes_transferred', 0) or '-',
getattr(response, 'bytes_transferred', 0) or '-',
req.headers.get('etag', '-'),
req.headers.get('x-cf-trans-id', '-'),
logged_headers or '-',

View File

@ -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()