From 0504fffb058103754be864006aa6fe49c4c2a883 Mon Sep 17 00:00:00 2001 From: John Dickinson Date: Thu, 11 Aug 2011 14:36:02 -0500 Subject: [PATCH 1/2] added client_ip to all proxy log lines not otherwise containing it --- swift/common/utils.py | 23 +++++++++++++++++++---- swift/proxy/server.py | 3 +++ test/unit/common/test_utils.py | 26 ++++++++++++++++++++++++-- 3 files changed, 46 insertions(+), 6 deletions(-) diff --git a/swift/common/utils.py b/swift/common/utils.py index 03c430d73f..58e3167190 100644 --- a/swift/common/utils.py +++ b/swift/common/utils.py @@ -294,10 +294,12 @@ class LoggerFileObject(object): class LogAdapter(logging.LoggerAdapter, object): """ A Logger like object which performs some reformatting on calls to - :meth:`exception`. Can be used to store a threadlocal transaction id. + :meth:`exception`. Can be used to store a threadlocal transaction id and + client ip. """ _txn_id = threading.local() + _client_ip = threading.local() def __init__(self, logger, server): logging.LoggerAdapter.__init__(self, logger, {}) @@ -313,6 +315,15 @@ class LogAdapter(logging.LoggerAdapter, object): def txn_id(self, value): self._txn_id.value = value + @property + def client_ip(self): + if hasattr(self._client_ip, 'value'): + return self._client_ip.value + + @client_ip.setter + def client_ip(self, value): + self._client_ip.value = value + def getEffectiveLevel(self): return self.logger.getEffectiveLevel() @@ -320,7 +331,8 @@ class LogAdapter(logging.LoggerAdapter, object): """ Add extra info to message """ - kwargs['extra'] = {'server': self.server, 'txn_id': self.txn_id} + kwargs['extra'] = {'server': self.server, 'txn_id': self.txn_id, + 'client_ip': self.client_ip} return msg, kwargs def notice(self, msg, *args, **kwargs): @@ -365,7 +377,7 @@ class LogAdapter(logging.LoggerAdapter, object): call('%s: %s' % (msg, emsg), *args, **kwargs) -class TxnFormatter(logging.Formatter): +class SwiftLogFormatter(logging.Formatter): """ Custom logging.Formatter will append txn_id to a log message if the record has one and the message does not. @@ -376,6 +388,9 @@ class TxnFormatter(logging.Formatter): if (record.txn_id and record.levelno != logging.INFO and record.txn_id not in msg): msg = "%s (txn: %s)" % (msg, record.txn_id) + if (record.client_ip and record.levelno != logging.INFO and + record.client_ip not in msg): + msg = "%s (client_ip: %s)" % (msg, record.client_ip) return msg @@ -406,7 +421,7 @@ def get_logger(conf, name=None, log_to_console=False, log_route=None, logger = logging.getLogger(log_route) logger.propagate = False # all new handlers will get the same formatter - formatter = TxnFormatter(fmt) + formatter = SwiftLogFormatter(fmt) # get_logger will only ever add one SysLog Handler to a logger if not hasattr(get_logger, 'handler4logger'): diff --git a/swift/proxy/server.py b/swift/proxy/server.py index 44e8b8e6bb..4477f90aac 100644 --- a/swift/proxy/server.py +++ b/swift/proxy/server.py @@ -289,6 +289,7 @@ class Controller(object): :param node: dictionary of node to handle errors for :param msg: error message + :param req: request that triggered the error """ self.error_increment(node) self.app.logger.error(_('%(msg)s %(ip)s:%(port)s'), @@ -301,6 +302,7 @@ class Controller(object): :param node: dictionary of node to log the error for :param typ: server type :param additional_info: additional information to log + :param req: request that triggered the exception """ self.app.logger.exception( _('ERROR with %(type)s server %(ip)s:%(port)s/%(device)s re: ' @@ -1645,6 +1647,7 @@ class BaseApplication(object): controller = controller(self, **path_parts) controller.trans_id = req.headers.get('x-trans-id', '-') self.logger.txn_id = req.headers.get('x-trans-id', None) + self.logger.client_ip = get_remote_client(req) try: handler = getattr(controller, req.method) if not getattr(handler, 'publicly_accessible'): diff --git a/test/unit/common/test_utils.py b/test/unit/common/test_utils.py index aeaf49092e..05707158a1 100644 --- a/test/unit/common/test_utils.py +++ b/test/unit/common/test_utils.py @@ -409,12 +409,12 @@ class TestUtils(unittest.TestCase): logger.logger.removeHandler(handler) reset_loggers() - def test_txn_formatter(self): + def test_swift_log_formatter(self): # setup stream logging sio = StringIO() logger = utils.get_logger(None) handler = logging.StreamHandler(sio) - handler.setFormatter(utils.TxnFormatter()) + handler.setFormatter(utils.SwiftLogFormatter()) logger.logger.addHandler(handler) def strip_value(sio): @@ -443,6 +443,28 @@ class TestUtils(unittest.TestCase): self.assertEquals(logger.txn_id, '12345') logger.warn('test 12345 test') self.assertEquals(strip_value(sio), 'test 12345 test\n') + + # test client_ip + self.assertFalse(logger.client_ip) + logger.error('my error message') + log_msg = strip_value(sio) + self.assert_('my error message' in log_msg) + self.assert_('client_ip' not in log_msg) + logger.client_ip = '1.2.3.4' + logger.error('test') + log_msg = strip_value(sio) + self.assert_('client_ip' in log_msg) + self.assert_('1.2.3.4' in log_msg) + # test no client_ip on info message + self.assertEquals(logger.client_ip, '1.2.3.4') + logger.info('test') + log_msg = strip_value(sio) + self.assert_('client_ip' not in log_msg) + self.assert_('1.2.3.4' not in log_msg) + # test client_ip (and txn) already in message + self.assertEquals(logger.client_ip, '1.2.3.4') + logger.warn('test 1.2.3.4 test 12345') + self.assertEquals(strip_value(sio), 'test 1.2.3.4 test 12345\n') finally: logger.logger.removeHandler(handler) reset_loggers() From 33ecfc3a43d26c20dca22000f04b9e89032927df Mon Sep 17 00:00:00 2001 From: John Dickinson Date: Fri, 12 Aug 2011 08:33:42 -0500 Subject: [PATCH 2/2] removed extraneous docstring lines --- swift/proxy/server.py | 2 -- 1 file changed, 2 deletions(-) diff --git a/swift/proxy/server.py b/swift/proxy/server.py index 4477f90aac..9e922c6375 100644 --- a/swift/proxy/server.py +++ b/swift/proxy/server.py @@ -289,7 +289,6 @@ class Controller(object): :param node: dictionary of node to handle errors for :param msg: error message - :param req: request that triggered the error """ self.error_increment(node) self.app.logger.error(_('%(msg)s %(ip)s:%(port)s'), @@ -302,7 +301,6 @@ class Controller(object): :param node: dictionary of node to log the error for :param typ: server type :param additional_info: additional information to log - :param req: request that triggered the exception """ self.app.logger.exception( _('ERROR with %(type)s server %(ip)s:%(port)s/%(device)s re: '