diff --git a/bin/swift-bench b/bin/swift-bench index 3c167ee06f..0554782a06 100755 --- a/bin/swift-bench +++ b/bin/swift-bench @@ -22,7 +22,7 @@ import uuid from optparse import OptionParser from swift.common.bench import BenchController -from swift.common.utils import readconf, LogAdapter, NamedFormatter +from swift.common.utils import readconf, LogAdapter # The defaults should be sufficient to run swift-bench on a SAIO CONF_DEFAULTS = { @@ -125,9 +125,9 @@ if __name__ == '__main__': options.log_level.lower(), logging.INFO)) loghandler = logging.StreamHandler() logger.addHandler(loghandler) - logger = LogAdapter(logger) - logformat = NamedFormatter('swift-bench', logger, - fmt='%(server)s %(asctime)s %(levelname)s %(message)s') + logger = LogAdapter(logger, 'swift-bench') + logformat = logging.Formatter('%(server)s %(asctime)s %(levelname)s ' + '%(message)s') loghandler.setFormatter(logformat) controller = BenchController(logger, options) diff --git a/doc/source/overview_stats.rst b/doc/source/overview_stats.rst index 40a5dd01af..6364de4611 100644 --- a/doc/source/overview_stats.rst +++ b/doc/source/overview_stats.rst @@ -15,10 +15,9 @@ Access logs *********** Access logs are the proxy server logs. Rackspace uses syslog-ng to redirect -proxy log messages with the syslog priority LOG_NOTICE to an hourly log -file. For example, a proxy request that is made on August 4, 2010 at 12:37 gets -logged in a file named 2010080412. This allows easy log rotation and easy -per-hour log processing. +the proxy log output to an hourly log file. For example, a proxy request that +is made on August 4, 2010 at 12:37 gets logged in a file named 2010080412. +This allows easy log rotation and easy per-hour log processing. ****************** Account stats logs @@ -100,11 +99,11 @@ Running the stats system on SAIO destination df_local1 { file("/var/log/swift/proxy.log" owner() group()); }; destination df_local1_err { file("/var/log/swift/proxy.error" owner() group()); }; destination df_local1_hourly { file("/var/log/swift/hourly/$YEAR$MONTH$DAY$HOUR" owner() group()); }; - filter f_local1 { facility(local1) and level(notice); }; + filter f_local1 { facility(local1) and level(info); }; - filter f_local1_err { facility(local1) and not level(notice); }; + filter f_local1_err { facility(local1) and not level(info); }; - # local1.notice -/var/log/swift/proxy.log + # local1.info -/var/log/swift/proxy.log # write to local file and to remove log server log { source(s_all); @@ -182,4 +181,4 @@ earlier. This file will have one entry per account per hour for each account with activity in that hour. One .csv file should be produced per hour. Note that the stats will be delayed by at least two hours by default. This can be changed with the new_log_cutoff variable in the config file. See -`log-processing.conf-sample` for more details. +`log-processing.conf-sample` for more details. \ No newline at end of file diff --git a/swift/common/utils.py b/swift/common/utils.py index 595ad3ac03..3ba291e266 100644 --- a/swift/common/utils.py +++ b/swift/common/utils.py @@ -289,7 +289,8 @@ class LoggerFileObject(object): return self -class LogAdapter(object): +# double inhereitence to support property with setter +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. @@ -297,11 +298,10 @@ class LogAdapter(object): _txn_id = threading.local() - def __init__(self, logger): - self.logger = logger - for proxied_method in ('debug', 'log', 'warn', 'warning', 'error', - 'critical', 'info'): - setattr(self, proxied_method, getattr(logger, proxied_method)) + def __init__(self, logger, server): + logging.LoggerAdapter.__init__(self, logger, {}) + self.server = server + setattr(self, 'warn', self.warning) @property def txn_id(self): @@ -315,24 +315,34 @@ class LogAdapter(object): def getEffectiveLevel(self): return self.logger.getEffectiveLevel() - def notice(self, msg, *args): + def process(self, msg, kwargs): + """ + Add extra info to message + """ + kwargs['extra'] = {'server': self.server, 'txn_id': self.txn_id} + return msg, kwargs + + def notice(self, msg, *args, **kwargs): """ Convenience function for syslog priority LOG_NOTICE. The python logging lvl is set to 25, just above info. SysLogHandler is monkey patched to map this log lvl to the LOG_NOTICE syslog priority. """ - self.logger.log(NOTICE, msg, *args) + self.log(NOTICE, msg, *args, **kwargs) - def exception(self, msg, *args): + def _exception(self, msg, *args, **kwargs): + logging.LoggerAdapter.exception(self, msg, *args, **kwargs) + + def exception(self, msg, *args, **kwargs): _junk, exc, _junk = sys.exc_info() - call = self.logger.error + call = self.error emsg = '' if isinstance(exc, OSError): if exc.errno in (errno.EIO, errno.ENOSPC): emsg = str(exc) else: - call = self.logger.exception + call = self._exception elif isinstance(exc, socket.error): if exc.errno == errno.ECONNREFUSED: emsg = _('Connection refused') @@ -341,7 +351,7 @@ class LogAdapter(object): elif exc.errno == errno.ETIMEDOUT: emsg = _('Connection timeout') else: - call = self.logger.exception + call = self._exception elif isinstance(exc, eventlet.Timeout): emsg = exc.__class__.__name__ if hasattr(exc, 'seconds'): @@ -350,53 +360,25 @@ class LogAdapter(object): if exc.msg: emsg += ' %s' % exc.msg else: - call = self.logger.exception - call('%s: %s' % (msg, emsg), *args) + call = self._exception + call('%s: %s' % (msg, emsg), *args, **kwargs) -class NamedFormatter(logging.Formatter): +class TxnFormatter(logging.Formatter): """ - NamedFormatter is used to add additional information to log messages. - Normally it will simply add the server name as an attribute on the - LogRecord and the default format string will include it at the - begining of the log message. Additionally, if the transaction id is - available and not already included in the message, NamedFormatter will - add it. - - NamedFormatter may be initialized with a format string which makes use - of the standard LogRecord attributes. In addition the format string - may include the following mapping key: - - +----------------+---------------------------------------------+ - | Format | Description | - +================+=============================================+ - | %(server)s | Name of the swift server doing logging | - +----------------+---------------------------------------------+ - - :param server: the swift server name, a string. - :param logger: a Logger or :class:`LogAdapter` instance, additional - context may be pulled from attributes on this logger if - available. - :param fmt: the format string used to construct the message, if none is - supplied it defaults to ``"%(server)s %(message)s"`` + Custom logging.Formatter will append txn_id to a log message if the record + has one and the message does not. """ - - def __init__(self, server, logger, - fmt="%(server)s %(message)s"): - logging.Formatter.__init__(self, fmt) - self.server = server - self.logger = logger - def format(self, record): - record.server = self.server msg = logging.Formatter.format(self, record) - if self.logger.txn_id and (record.levelno != logging.INFO or - self.logger.txn_id not in msg): - msg = "%s (txn: %s)" % (msg, self.logger.txn_id) + if (record.txn_id and record.levelno != logging.INFO and + record.txn_id not in msg): + msg = "%s (txn: %s)" % (msg, record.txn_id) return msg -def get_logger(conf, name=None, log_to_console=False, log_route=None): +def get_logger(conf, name=None, log_to_console=False, log_route=None, + fmt="%(server)s %(message)s"): """ Get the current system logger using config settings. @@ -412,48 +394,46 @@ def get_logger(conf, name=None, log_to_console=False, log_route=None): """ if not conf: conf = {} - if not hasattr(get_logger, 'root_logger_configured'): - get_logger.root_logger_configured = True - get_logger(conf, name, log_to_console, log_route='root') if name is None: name = conf.get('log_name', 'swift') if not log_route: log_route = name - if log_route == 'root': - logger = logging.getLogger() - else: - logger = logging.getLogger(log_route) - logger.propagate = False - if not hasattr(get_logger, 'handler4facility'): - get_logger.handler4facility = {} - facility = getattr(SysLogHandler, conf.get('log_facility', 'LOG_LOCAL0'), - SysLogHandler.LOG_LOCAL0) - if facility in get_logger.handler4facility: - logger.removeHandler(get_logger.handler4facility[facility]) - get_logger.handler4facility[facility].close() - del get_logger.handler4facility[facility] - if log_to_console: - # check if a previous call to get_logger already added a console logger - if hasattr(get_logger, 'console') and get_logger.console: - logger.removeHandler(get_logger.console) - get_logger.console = logging.StreamHandler(sys.__stderr__) - logger.addHandler(get_logger.console) - get_logger.handler4facility[facility] = \ - SysLogHandler(address='/dev/log', facility=facility) + logger = logging.getLogger(log_route) + logger.propagate = False + # all swift new handlers will get the same formatter + formatter = TxnFormatter(fmt) + + # a single swift logger will only get one SysLog Handler if not hasattr(get_logger, 'handler4logger'): get_logger.handler4logger = {} if logger in get_logger.handler4logger: logger.removeHandler(get_logger.handler4logger[logger]) - get_logger.handler4logger[logger] = \ - get_logger.handler4facility[facility] - logger.addHandler(get_logger.handler4facility[facility]) + + # facility for this logger will be set by last call wins + facility = getattr(SysLogHandler, conf.get('log_facility', 'LOG_LOCAL0'), + SysLogHandler.LOG_LOCAL0) + handler = SysLogHandler(address='/dev/log', facility=facility) + handler.setFormatter(formatter) + logger.addHandler(handler) + get_logger.handler4logger[logger] = handler + + # setup console logging + if log_to_console or hasattr(get_logger, 'console_handler4logger'): + # remove pre-existing console handler for this logger + if not hasattr(get_logger, 'console_handler4logger'): + get_logger.console_handler4logger = {} + if logger in get_logger.console_handler4logger: + logger.removeHandler(get_logger.console_handler4logger[logger]) + + console_handler = logging.StreamHandler(sys.__stderr__) + console_handler.setFormatter(formatter) + logger.addHandler(console_handler) + get_logger.console_handler4logger[logger] = console_handler + + # set the level for the logger logger.setLevel( getattr(logging, conf.get('log_level', 'INFO').upper(), logging.INFO)) - adapted_logger = LogAdapter(logger) - formatter = NamedFormatter(name, adapted_logger) - get_logger.handler4facility[facility].setFormatter(formatter) - if hasattr(get_logger, 'console'): - get_logger.console.setFormatter(formatter) + adapted_logger = LogAdapter(logger, name) return adapted_logger @@ -486,8 +466,9 @@ def capture_stdio(logger, **kwargs): # collect stdio file desc not in use for logging stdio_fds = [0, 1, 2] - if hasattr(get_logger, 'console'): - stdio_fds.remove(get_logger.console.stream.fileno()) + for _junk, handler in getattr(get_logger, + 'console_handler4logger', {}).items(): + stdio_fds.remove(handler.stream.fileno()) with open(os.devnull, 'r+b') as nullfile: # close stdio (excludes fds open for logging) diff --git a/swift/proxy/server.py b/swift/proxy/server.py index c4d8178c61..b2b41d6434 100644 --- a/swift/proxy/server.py +++ b/swift/proxy/server.py @@ -1606,22 +1606,20 @@ class BaseApplication(object): def __init__(self, conf, memcache=None, logger=None, account_ring=None, container_ring=None, object_ring=None): - if logger is None: - self.logger = get_logger(conf) - else: - self.logger = logger if conf is None: conf = {} - if 'access_log_name' in conf or 'access_log_facility' in conf: - access_log_conf = { - 'log_name': conf.get('access_log_name', conf.get('log_name', - 'proxy-server')), - 'log_facility': conf.get('access_log_facility', - conf.get('log_facility', 'LOG_LOCAL0')), - } - self.access_logger = get_logger(access_log_conf) + if logger is None: + self.logger = get_logger(conf) + access_log_conf = {} + for key in ('log_facility', 'log_name', 'log_level'): + value = conf.get('access_' + key, conf.get(key, None)) + if value: + access_log_conf[key] = value + self.access_logger = get_logger(access_log_conf, + log_route='proxy-access') else: - self.access_logger = self.logger + self.logger = self.access_logger = logger + swift_dir = conf.get('swift_dir', '/etc/swift') self.node_timeout = int(conf.get('node_timeout', 10)) self.conn_timeout = float(conf.get('conn_timeout', 0.5)) diff --git a/test/unit/common/test_utils.py b/test/unit/common/test_utils.py index d709c65d3e..959caa8919 100644 --- a/test/unit/common/test_utils.py +++ b/test/unit/common/test_utils.py @@ -19,6 +19,7 @@ from __future__ import with_statement import logging import mimetools import os +import errno import socket import sys import time @@ -31,6 +32,8 @@ from tempfile import NamedTemporaryFile from eventlet import sleep +from swift.common.exceptions import TimeoutError, MessageTimeout, \ + ConnectionTimeout from swift.common import utils @@ -76,6 +79,17 @@ class MockSys(): __stderr__ = sys.__stderr__ +def reset_loggers(): + if hasattr(utils.get_logger, 'handler4logger'): + for logger, handler in utils.get_logger.handler4logger.items(): + logger.removeHandler(handler) + delattr(utils.get_logger, 'handler4logger') + if hasattr(utils.get_logger, 'console_handler4logger'): + for logger, h in utils.get_logger.console_handler4logger.items(): + logger.removeHandler(h) + delattr(utils.get_logger, 'console_handler4logger') + + class TestUtils(unittest.TestCase): """ Tests for swift.common.utils """ @@ -308,10 +322,131 @@ Error: unable to locate %s self.assertEquals(sio.getvalue(), 'test1\ntest3\ntest4\n') # make sure notice lvl logs by default - logger.notice('test7') - self.assertEquals(sio.getvalue(), - 'test1\ntest3\ntest4\ntest6\n') + logger.notice('test6') + def test_clean_logger_exception(self): + # setup stream logging + sio = StringIO() + logger = utils.get_logger(None) + handler = logging.StreamHandler(sio) + logger.logger.addHandler(handler) + + def strip_value(sio): + v = sio.getvalue() + sio.truncate(0) + return v + + def log_exception(exc): + try: + raise exc + except (Exception, TimeoutError): + logger.exception('blah') + try: + # establish base case + self.assertEquals(strip_value(sio), '') + logger.info('test') + self.assertEquals(strip_value(sio), 'test\n') + self.assertEquals(strip_value(sio), '') + logger.info('test') + logger.info('test') + self.assertEquals(strip_value(sio), 'test\ntest\n') + self.assertEquals(strip_value(sio), '') + + # test OSError + for en in (errno.EIO, errno.ENOSPC): + log_exception(OSError(en, 'my %s error message' % en)) + log_msg = strip_value(sio) + self.assert_('Traceback' not in log_msg) + self.assert_('my %s error message' % en in log_msg) + # unfiltered + log_exception(OSError()) + self.assert_('Traceback' in strip_value(sio)) + + # test socket.error + log_exception(socket.error(errno.ECONNREFUSED, + 'my error message')) + log_msg = strip_value(sio) + self.assert_('Traceback' not in log_msg) + self.assert_('errno.ECONNREFUSED message test' not in log_msg) + self.assert_('Connection refused' in log_msg) + log_exception(socket.error(errno.EHOSTUNREACH, + 'my error message')) + log_msg = strip_value(sio) + self.assert_('Traceback' not in log_msg) + self.assert_('my error message' not in log_msg) + self.assert_('Host unreachable' in log_msg) + log_exception(socket.error(errno.ETIMEDOUT, 'my error message')) + log_msg = strip_value(sio) + self.assert_('Traceback' not in log_msg) + self.assert_('my error message' not in log_msg) + self.assert_('Connection timeout' in log_msg) + # unfiltered + log_exception(socket.error(0, 'my error message')) + log_msg = strip_value(sio) + self.assert_('Traceback' in log_msg) + self.assert_('my error message' in log_msg) + + # test eventlet.Timeout + log_exception(ConnectionTimeout(42, 'my error message')) + log_msg = strip_value(sio) + self.assert_('Traceback' not in log_msg) + self.assert_('ConnectionTimeout' in log_msg) + self.assert_('(42s)' in log_msg) + self.assert_('my error message' not in log_msg) + log_exception(MessageTimeout(42, 'my error message')) + log_msg = strip_value(sio) + self.assert_('Traceback' not in log_msg) + self.assert_('MessageTimeout' in log_msg) + self.assert_('(42s)' in log_msg) + self.assert_('my error message' in log_msg) + + # test unhandled + log_exception(Exception('my error message')) + log_msg = strip_value(sio) + self.assert_('Traceback' in log_msg) + self.assert_('my error message' in log_msg) + + finally: + logger.logger.removeHandler(handler) + reset_loggers() + + def test_txn_formatter(self): + # setup stream logging + sio = StringIO() + logger = utils.get_logger(None) + handler = logging.StreamHandler(sio) + handler.setFormatter(utils.TxnFormatter()) + logger.logger.addHandler(handler) + + def strip_value(sio): + v = sio.getvalue() + sio.truncate(0) + return v + + try: + self.assertFalse(logger.txn_id) + logger.error('my error message') + log_msg = strip_value(sio) + self.assert_('my error message' in log_msg) + self.assert_('txn' not in log_msg) + logger.txn_id = '12345' + logger.error('test') + log_msg = strip_value(sio) + self.assert_('txn' in log_msg) + self.assert_('12345' in log_msg) + # test no txn on info message + self.assertEquals(logger.txn_id, '12345') + logger.info('test') + log_msg = strip_value(sio) + self.assert_('txn' not in log_msg) + self.assert_('12345' not in log_msg) + # test txn already in message + self.assertEquals(logger.txn_id, '12345') + logger.warn('test 12345 test') + self.assertEquals(strip_value(sio), 'test 12345 test\n') + finally: + logger.logger.removeHandler(handler) + reset_loggers() def test_storage_directory(self): self.assertEquals(utils.storage_directory('objects', '1', 'ABCDEF'), @@ -397,56 +532,71 @@ log_name = yarr''' logger = utils.get_logger(None, 'dummy') # mock utils system modules - utils.sys = MockSys() - utils.os = MockOs() + _orig_sys = utils.sys + _orig_os = utils.os + try: + utils.sys = MockSys() + utils.os = MockOs() - # basic test - utils.capture_stdio(logger) - self.assert_(utils.sys.excepthook is not None) - self.assertEquals(utils.os.closed_fds, [0, 1, 2]) - self.assert_(utils.sys.stdout is not None) - self.assert_(utils.sys.stderr is not None) + # basic test + utils.capture_stdio(logger) + self.assert_(utils.sys.excepthook is not None) + self.assertEquals(utils.os.closed_fds, [0, 1, 2]) + self.assert_(utils.sys.stdout is not None) + self.assert_(utils.sys.stderr is not None) - # reset; test same args, but exc when trying to close stdio - utils.os = MockOs(raise_funcs=('dup2',)) - utils.sys = MockSys() + # reset; test same args, but exc when trying to close stdio + utils.os = MockOs(raise_funcs=('dup2',)) + utils.sys = MockSys() - # test unable to close stdio - utils.capture_stdio(logger) - self.assert_(utils.sys.excepthook is not None) - self.assertEquals(utils.os.closed_fds, []) - self.assert_(utils.sys.stdout is not None) - self.assert_(utils.sys.stderr is not None) + # test unable to close stdio + utils.capture_stdio(logger) + self.assert_(utils.sys.excepthook is not None) + self.assertEquals(utils.os.closed_fds, []) + self.assert_(utils.sys.stdout is not None) + self.assert_(utils.sys.stderr is not None) - # reset; test some other args - logger = utils.get_logger(None, log_to_console=True) - utils.os = MockOs() - utils.sys = MockSys() + # reset; test some other args + logger = utils.get_logger(None, log_to_console=True) + utils.os = MockOs() + utils.sys = MockSys() - # test console log - utils.capture_stdio(logger, capture_stdout=False, - capture_stderr=False) - self.assert_(utils.sys.excepthook is not None) - # when logging to console, stderr remains open - self.assertEquals(utils.os.closed_fds, [0, 1]) - logger.logger.removeHandler(utils.get_logger.console) - # stdio not captured - self.assertFalse(hasattr(utils.sys, 'stdout')) - self.assertFalse(hasattr(utils.sys, 'stderr')) + # test console log + utils.capture_stdio(logger, capture_stdout=False, + capture_stderr=False) + self.assert_(utils.sys.excepthook is not None) + # when logging to console, stderr remains open + self.assertEquals(utils.os.closed_fds, [0, 1]) + reset_loggers() + + # stdio not captured + self.assertFalse(hasattr(utils.sys, 'stdout')) + self.assertFalse(hasattr(utils.sys, 'stderr')) + reset_loggers() + finally: + utils.sys = _orig_sys + utils.os = _orig_os def test_get_logger_console(self): - reload(utils) # reset get_logger attrs + reset_loggers() logger = utils.get_logger(None) - self.assertFalse(hasattr(utils.get_logger, 'console')) + console_handlers = [h for h in logger.logger.handlers if + isinstance(h, logging.StreamHandler)] + self.assertFalse(console_handlers) logger = utils.get_logger(None, log_to_console=True) - self.assert_(hasattr(utils.get_logger, 'console')) - self.assert_(isinstance(utils.get_logger.console, - logging.StreamHandler)) + console_handlers = [h for h in logger.logger.handlers if + isinstance(h, logging.StreamHandler)] + self.assert_(console_handlers) # make sure you can't have two console handlers - old_handler = utils.get_logger.console + self.assertEquals(len(console_handlers), 1) + old_handler = console_handlers[0] logger = utils.get_logger(None, log_to_console=True) - self.assertNotEquals(utils.get_logger.console, old_handler) - logger.logger.removeHandler(utils.get_logger.console) + console_handlers = [h for h in logger.logger.handlers if + isinstance(h, logging.StreamHandler)] + self.assertEquals(len(console_handlers), 1) + new_handler = console_handlers[0] + self.assertNotEquals(new_handler, old_handler) + reset_loggers() def test_ratelimit_sleep(self): running_time = 0 diff --git a/test/unit/proxy/test_server.py b/test/unit/proxy/test_server.py index 9e49b09e74..71b61e1e2c 100644 --- a/test/unit/proxy/test_server.py +++ b/test/unit/proxy/test_server.py @@ -16,6 +16,7 @@ from __future__ import with_statement import cPickle as pickle import logging +from logging.handlers import SysLogHandler import os import sys import unittest @@ -465,8 +466,138 @@ class TestController(unittest.TestCase): test(404, 507, 503) test(503, 503, 503) + class TestProxyServer(unittest.TestCase): + def test_access_log(self): + + class MyApp(proxy_server.Application): + + def handle_request(self, req): + resp = Response(request=req) + req.response = resp + req.start_time = time() + return resp + + def start_response(*args): + pass + + class MockLogger(): + + def __init__(self): + self.buffer = StringIO() + + def info(self, msg, args=None): + if args: + msg = msg % args + self.buffer.write(msg) + + def strip_value(self): + rv = self.buffer.getvalue() + self.buffer.truncate(0) + return rv + + class SnarfStream(object): + # i can't seem to subclass cStringIO + + def __init__(self, *args, **kwargs): + self.sio = StringIO() + + def strip_value(self): + rv = self.getvalue().strip() + self.truncate(0) + return rv + + def __getattr__(self, name): + try: + return object.__getattr__(self, name) + except AttributeError: + try: + return getattr(self.sio, name) + except AttributeError: + return self.__getattribute__(name) + + snarf = SnarfStream() + _orig_get_logger = proxy_server.get_logger + + def mock_get_logger(*args, **kwargs): + if kwargs.get('log_route') != 'proxy-access': + return _orig_get_logger(*args, **kwargs) + kwargs['log_route'] = 'snarf' + logger = _orig_get_logger(*args, **kwargs) + if [h for h in logger.logger.handlers if + isinstance(h, logging.StreamHandler) and h.stream is snarf]: + # snarf handler already setup! + return logger + formatter = logger.logger.handlers[0].formatter + formatter._fmt += ' %(levelname)s' + snarf_handler = logging.StreamHandler(snarf) + snarf_handler.setFormatter(formatter) + logger.logger.addHandler(snarf_handler) + return logger + + def test_conf(conf): + app = MyApp(conf, memcache=FakeMemcache(), account_ring=FakeRing(), + container_ring=FakeRing(), object_ring=FakeRing()) + req = Request.blank('') + app(req.environ, start_response) + + try: + proxy_server.get_logger = mock_get_logger + test_conf({}) + line = snarf.strip_value() + print line + self.assert_(line.startswith('swift')) + self.assert_(line.endswith('INFO')) + test_conf({'log_name': 'snarf-test'}) + line = snarf.strip_value() + print line + self.assert_(line.startswith('snarf-test')) + self.assert_(line.endswith('INFO')) + test_conf({'log_name': 'snarf-test', 'log_level': 'ERROR'}) + line = snarf.strip_value() + print line + self.assertFalse(line) + test_conf({'log_name': 'snarf-test', 'log_level': 'ERROR', + 'access_log_name': 'access-test', + 'access_log_level': 'INFO'}) + line = snarf.strip_value() + print line + self.assert_(line.startswith('access-test')) + self.assert_(line.endswith('INFO')) + + # test facility + def get_facility(logger): + h = [h for h in logger.logger.handlers if + isinstance(h, SysLogHandler)][0] + return h.facility + + conf = {'log_facility': 'LOG_LOCAL0'} + app = MyApp(conf, memcache=FakeMemcache(), account_ring=FakeRing(), + container_ring=FakeRing(), object_ring=FakeRing()) + self.assertEquals(get_facility(app.logger), + SysLogHandler.LOG_LOCAL0) + self.assertEquals(get_facility(app.access_logger), + SysLogHandler.LOG_LOCAL0) + conf = {'log_facility': 'LOG_LOCAL0', + 'access_log_facility': 'LOG_LOCAL1'} + app = MyApp(conf, memcache=FakeMemcache(), account_ring=FakeRing(), + container_ring=FakeRing(), object_ring=FakeRing()) + self.assertEquals(get_facility(app.logger), + SysLogHandler.LOG_LOCAL0) + self.assertEquals(get_facility(app.access_logger), + SysLogHandler.LOG_LOCAL1) + conf = {'access_log_facility': 'LOG_LOCAL1'} + app = MyApp(conf, memcache=FakeMemcache(), account_ring=FakeRing(), + container_ring=FakeRing(), object_ring=FakeRing()) + self.assertEquals(get_facility(app.logger), + SysLogHandler.LOG_LOCAL0) + self.assertEquals(get_facility(app.access_logger), + SysLogHandler.LOG_LOCAL1) + + finally: + proxy_server.get_logger = _orig_get_logger + def test_unhandled_exception(self): class MyApp(proxy_server.Application): @@ -1805,8 +1936,7 @@ class TestObjectController(unittest.TestCase): def info(self, msg): self.msg = msg - orig_logger = prosrv.logger - orig_access_logger = prosrv.access_logger + orig_logger, orig_access_logger = prosrv.logger, prosrv.access_logger prosrv.logger = prosrv.access_logger = Logger() sock = connect_tcp(('localhost', prolis.getsockname()[1])) fd = sock.makefile() @@ -1823,12 +1953,8 @@ class TestObjectController(unittest.TestCase): prosrv.logger.msg) exp = 'host1' self.assertEquals(prosrv.logger.msg[:len(exp)], exp) - prosrv.access_logger = orig_access_logger - prosrv.logger = orig_logger # Turn on header logging. - orig_logger = prosrv.logger - orig_access_logger = prosrv.access_logger prosrv.logger = prosrv.access_logger = Logger() prosrv.log_headers = True sock = connect_tcp(('localhost', prolis.getsockname()[1])) @@ -1843,8 +1969,7 @@ class TestObjectController(unittest.TestCase): self.assert_('Goofy-Header%3A%20True' in prosrv.logger.msg, prosrv.logger.msg) prosrv.log_headers = False - prosrv.access_logger = orig_access_logger - prosrv.logger = orig_logger + prosrv.logger, prosrv.access_logger = orig_logger, orig_access_logger def test_chunked_put_utf8_all_the_way_down(self): # Test UTF-8 Unicode all the way through the system