Fix unicode errors in object controller logging
Change swift.proxy.server.Application.error_occurred() to decode message as utf-8 in same way that the exception_occurred() method was changed in [1]. This prevents a unicode error when logging error responses in swift.proxy.controllers.base.Controller._make_request() for paths that have non-ascii characters. Although the unicode error is currently caught by a surrounding except clause, the logging and error limiting treatment is different for ascii vs non-ascii paths. This patch makes them consistent. Fix the server type reported in _make_request() to be the correct server type, not always 'Container Server'. Fix path arg passed to _get_conn_response in swift.proxy.controllers.obj.BaseObjectController to be req.path rather than req. Add unit tests for error_occurred() being called with non-ascii paths and extend tests for exception_occurred() (see Related-Bug). [1] Change-Id: Icb7284eb5abc9869c1620ee6366817112d8e5587 Related-Bug: #1597210 Change-Id: I285499d164bff94835bdddb25d2af6d73114c281
This commit is contained in:
Alistair Coles
parent
7568ea5dd9
commit
ca2f6d13b6
@ -1545,10 +1545,11 @@ class Controller(object):
|
||||
self.app.error_occurred(
|
||||
node, _('ERROR %(status)d '
|
||||
'Trying to %(method)s %(path)s'
|
||||
'From Container Server') % {
|
||||
' From %(type)s Server') % {
|
||||
'status': resp.status,
|
||||
'method': method,
|
||||
'path': path})
|
||||
'path': path,
|
||||
'type': self.server_type})
|
||||
except (Exception, Timeout):
|
||||
self.app.exception_occurred(
|
||||
node, self.server_type,
|
||||
|
||||
@ -349,7 +349,7 @@ class BaseObjectController(Controller):
|
||||
for putter in putters:
|
||||
if putter.failed:
|
||||
continue
|
||||
pile.spawn(self._get_conn_response, putter, req,
|
||||
pile.spawn(self._get_conn_response, putter, req.path,
|
||||
self.app.logger.thread_locals, final_phase=final_phase)
|
||||
|
||||
def _handle_response(putter, response):
|
||||
|
||||
@ -509,7 +509,7 @@ class Application(object):
|
||||
"""
|
||||
self._incr_node_errors(node)
|
||||
self.logger.error(_('%(msg)s %(ip)s:%(port)s/%(device)s'),
|
||||
{'msg': msg, 'ip': node['ip'],
|
||||
{'msg': msg.decode('utf-8'), 'ip': node['ip'],
|
||||
'port': node['port'], 'device': node['device']})
|
||||
|
||||
def iter_nodes(self, ring, partition, node_iter=None):
|
||||
|
||||
@ -959,9 +959,9 @@ def fake_http_connect(*code_iter, **kwargs):
|
||||
self.body = self.body[amt:]
|
||||
return rv
|
||||
|
||||
def send(self, amt=None):
|
||||
def send(self, data=None):
|
||||
if self.give_send:
|
||||
self.give_send(self, amt)
|
||||
self.give_send(self, data)
|
||||
am_slow, value = self.get_slow()
|
||||
if am_slow:
|
||||
if self.received < 4:
|
||||
|
||||
@ -31,6 +31,7 @@ from six.moves import range
|
||||
|
||||
import swift
|
||||
from swift.common import utils, swob, exceptions
|
||||
from swift.common.exceptions import ChunkWriteTimeout
|
||||
from swift.common.header_key_dict import HeaderKeyDict
|
||||
from swift.proxy import server as proxy_server
|
||||
from swift.proxy.controllers import obj
|
||||
@ -856,19 +857,151 @@ class TestReplicatedObjController(BaseObjectControllerMixin,
|
||||
node_error_count(self.app, object_ring.devs[1]),
|
||||
self.app.error_suppression_limit + 1)
|
||||
|
||||
def test_PUT_connect_exception_with_unicode_path_and_locale(self):
|
||||
def test_PUT_connect_exception_with_unicode_path(self):
|
||||
expected = 201
|
||||
statuses = (
|
||||
Exception('Connection refused: Please insert ten dollars'),
|
||||
201, 201)
|
||||
201, 201, 201)
|
||||
|
||||
req = swob.Request.blank('/v1/AUTH_kilroy/%ED%88%8E/%E9%90%89',
|
||||
method='PUT',
|
||||
body='life is utf-gr8')
|
||||
self.app.logger.clear()
|
||||
with set_http_connect(*statuses):
|
||||
resp = req.get_response(self.app)
|
||||
|
||||
self.assertEqual(resp.status_int, expected)
|
||||
log_lines = self.app.logger.get_lines_for_level('error')
|
||||
self.assertFalse(log_lines[1:])
|
||||
self.assertIn('ERROR with Object server', log_lines[0])
|
||||
self.assertIn(req.swift_entity_path.decode('utf-8'), log_lines[0])
|
||||
self.assertIn('re: Expect: 100-continue', log_lines[0])
|
||||
|
||||
def test_PUT_get_expect_errors_with_unicode_path(self):
|
||||
def do_test(statuses):
|
||||
req = swob.Request.blank('/v1/AUTH_kilroy/%ED%88%8E/%E9%90%89',
|
||||
method='PUT',
|
||||
body='life is utf-gr8')
|
||||
self.app.logger.clear()
|
||||
with set_http_connect(*statuses):
|
||||
resp = req.get_response(self.app)
|
||||
|
||||
self.assertEqual(resp.status_int, 201)
|
||||
log_lines = self.app.logger.get_lines_for_level('error')
|
||||
self.assertFalse(log_lines[1:])
|
||||
return log_lines
|
||||
|
||||
log_lines = do_test((201, (507, None), 201, 201))
|
||||
self.assertIn('ERROR Insufficient Storage', log_lines[0])
|
||||
|
||||
log_lines = do_test((201, (503, None), 201, 201))
|
||||
self.assertIn('ERROR 503 Expect: 100-continue From Object Server',
|
||||
log_lines[0])
|
||||
|
||||
def test_PUT_send_exception_with_unicode_path(self):
|
||||
def do_test(exc):
|
||||
conns = set()
|
||||
|
||||
def capture_send(conn, data):
|
||||
conns.add(conn)
|
||||
if len(conns) == 2:
|
||||
raise exc
|
||||
|
||||
req = swob.Request.blank('/v1/AUTH_kilroy/%ED%88%8E/%E9%90%89',
|
||||
method='PUT',
|
||||
body='life is utf-gr8')
|
||||
self.app.logger.clear()
|
||||
with set_http_connect(201, 201, 201, give_send=capture_send):
|
||||
resp = req.get_response(self.app)
|
||||
|
||||
self.assertEqual(resp.status_int, 201)
|
||||
log_lines = self.app.logger.get_lines_for_level('error')
|
||||
self.assertFalse(log_lines[1:])
|
||||
self.assertIn('ERROR with Object server', log_lines[0])
|
||||
self.assertIn(req.swift_entity_path.decode('utf-8'), log_lines[0])
|
||||
self.assertIn('Trying to write to', log_lines[0])
|
||||
|
||||
do_test(Exception('Exception while sending data on connection'))
|
||||
do_test(ChunkWriteTimeout())
|
||||
|
||||
def test_PUT_final_response_errors_with_unicode_path(self):
|
||||
def do_test(statuses):
|
||||
req = swob.Request.blank('/v1/AUTH_kilroy/%ED%88%8E/%E9%90%89',
|
||||
method='PUT',
|
||||
body='life is utf-gr8')
|
||||
self.app.logger.clear()
|
||||
with set_http_connect(*statuses):
|
||||
resp = req.get_response(self.app)
|
||||
|
||||
self.assertEqual(resp.status_int, 201)
|
||||
log_lines = self.app.logger.get_lines_for_level('error')
|
||||
self.assertFalse(log_lines[1:])
|
||||
return req, log_lines
|
||||
|
||||
req, log_lines = do_test((201, (100, Exception('boom')), 201))
|
||||
self.assertIn('ERROR with Object server', log_lines[0])
|
||||
self.assertIn(req.path.decode('utf-8'), log_lines[0])
|
||||
self.assertIn('Trying to get final status of PUT', log_lines[0])
|
||||
|
||||
req, log_lines = do_test((201, (100, Timeout()), 201))
|
||||
self.assertIn('ERROR with Object server', log_lines[0])
|
||||
self.assertIn(req.path.decode('utf-8'), log_lines[0])
|
||||
self.assertIn('Trying to get final status of PUT', log_lines[0])
|
||||
|
||||
req, log_lines = do_test((201, (100, 507), 201))
|
||||
self.assertIn('ERROR Insufficient Storage', log_lines[0])
|
||||
|
||||
req, log_lines = do_test((201, (100, 500), 201))
|
||||
self.assertIn('ERROR 500 From Object Server', log_lines[0])
|
||||
self.assertIn(req.path.decode('utf-8'), log_lines[0])
|
||||
|
||||
def test_DELETE_errors(self):
|
||||
# verify logged errors with and without non-ascii characters in path
|
||||
def do_test(path, statuses):
|
||||
|
||||
req = swob.Request.blank('/v1' + path,
|
||||
method='DELETE',
|
||||
body='life is utf-gr8')
|
||||
self.app.logger.clear()
|
||||
with set_http_connect(*statuses):
|
||||
resp = req.get_response(self.app)
|
||||
|
||||
self.assertEqual(resp.status_int, 201)
|
||||
log_lines = self.app.logger.get_lines_for_level('error')
|
||||
self.assertFalse(log_lines[1:])
|
||||
return req, log_lines
|
||||
|
||||
req, log_lines = do_test('/AUTH_kilroy/ascii/ascii',
|
||||
(201, 500, 201, 201))
|
||||
self.assertIn('Trying to DELETE', log_lines[0])
|
||||
self.assertIn(req.swift_entity_path.decode('utf-8'), log_lines[0])
|
||||
self.assertIn(' From Object Server', log_lines[0])
|
||||
|
||||
req, log_lines = do_test('/AUTH_kilroy/%ED%88%8E/%E9%90%89',
|
||||
(201, 500, 201, 201))
|
||||
self.assertIn('Trying to DELETE', log_lines[0])
|
||||
self.assertIn(req.swift_entity_path.decode('utf-8'), log_lines[0])
|
||||
self.assertIn(' From Object Server', log_lines[0])
|
||||
|
||||
req, log_lines = do_test('/AUTH_kilroy/ascii/ascii',
|
||||
(201, 507, 201, 201))
|
||||
self.assertIn('ERROR Insufficient Storage', log_lines[0])
|
||||
|
||||
req, log_lines = do_test('/AUTH_kilroy/%ED%88%8E/%E9%90%89',
|
||||
(201, 507, 201, 201))
|
||||
self.assertIn('ERROR Insufficient Storage', log_lines[0])
|
||||
|
||||
req, log_lines = do_test('/AUTH_kilroy/ascii/ascii',
|
||||
(201, Exception(), 201, 201))
|
||||
self.assertIn('Trying to DELETE', log_lines[0])
|
||||
self.assertIn(req.swift_entity_path.decode('utf-8'), log_lines[0])
|
||||
self.assertIn('ERROR with Object server', log_lines[0])
|
||||
|
||||
req, log_lines = do_test('/AUTH_kilroy/%ED%88%8E/%E9%90%89',
|
||||
(201, Exception(), 201, 201))
|
||||
self.assertIn('Trying to DELETE', log_lines[0])
|
||||
self.assertIn(req.swift_entity_path.decode('utf-8'), log_lines[0])
|
||||
self.assertIn('ERROR with Object server', log_lines[0])
|
||||
|
||||
def test_PUT_error_during_transfer_data(self):
|
||||
class FakeReader(object):
|
||||
|
||||
@ -874,6 +874,60 @@ class TestProxyServer(unittest.TestCase):
|
||||
|
||||
self.assertEqual(controller.__name__, 'InfoController')
|
||||
|
||||
def test_exception_occurred(self):
|
||||
def do_test(additional_info):
|
||||
logger = debug_logger('test')
|
||||
app = proxy_server.Application({}, FakeMemcache(),
|
||||
account_ring=FakeRing(),
|
||||
container_ring=FakeRing(),
|
||||
logger=logger)
|
||||
node = app.container_ring.get_part_nodes(0)[0]
|
||||
node_key = app._error_limit_node_key(node)
|
||||
self.assertNotIn(node_key, app._error_limiting) # sanity
|
||||
try:
|
||||
raise Exception('kaboom1!')
|
||||
except Exception as err:
|
||||
app.exception_occurred(node, 'server-type', additional_info)
|
||||
|
||||
self.assertEqual(1, app._error_limiting[node_key]['errors'])
|
||||
line = logger.get_lines_for_level('error')[-1]
|
||||
self.assertIn('server-type server', line)
|
||||
self.assertIn(additional_info.decode('utf8'), line)
|
||||
self.assertIn(node['ip'], line)
|
||||
self.assertIn(str(node['port']), line)
|
||||
self.assertIn(node['device'], line)
|
||||
log_args, log_kwargs = logger.log_dict['error'][-1]
|
||||
self.assertTrue(log_kwargs['exc_info'])
|
||||
self.assertEqual(err, log_kwargs['exc_info'][1])
|
||||
|
||||
do_test('success')
|
||||
do_test('succès')
|
||||
do_test(u'success')
|
||||
|
||||
def test_error_occurred(self):
|
||||
def do_test(msg):
|
||||
logger = debug_logger('test')
|
||||
app = proxy_server.Application({}, FakeMemcache(),
|
||||
account_ring=FakeRing(),
|
||||
container_ring=FakeRing(),
|
||||
logger=logger)
|
||||
node = app.container_ring.get_part_nodes(0)[0]
|
||||
node_key = app._error_limit_node_key(node)
|
||||
self.assertNotIn(node_key, app._error_limiting) # sanity
|
||||
|
||||
app.error_occurred(node, msg)
|
||||
|
||||
self.assertEqual(1, app._error_limiting[node_key]['errors'])
|
||||
line = logger.get_lines_for_level('error')[-1]
|
||||
self.assertIn(msg.decode('utf8'), line)
|
||||
self.assertIn(node['ip'], line)
|
||||
self.assertIn(str(node['port']), line)
|
||||
self.assertIn(node['device'], line)
|
||||
|
||||
do_test('success')
|
||||
do_test('succès')
|
||||
do_test(u'success')
|
||||
|
||||
def test_error_limit_methods(self):
|
||||
logger = debug_logger('test')
|
||||
app = proxy_server.Application({}, FakeMemcache(),
|
||||
|
||||
Loading…
Reference in New Issue
Block a user