From 8699af83c9ee1cbc5691ed12a6f57fa1134aab41 Mon Sep 17 00:00:00 2001 From: Alistair Coles Date: Fri, 4 Oct 2024 11:55:55 +0100 Subject: [PATCH] Remove statds from the logs module We would like to remove any Statsd related code from logs.py. That requires that SwiftLogAdapter no longer provides a StatsdClient interface by default. However, for backwards compatibility the main utils.get_logger/get_prefixed_logger entrypoints must provide a SwiftLogAdapter that does have a StatdsClient interface. The new utils._patch_statsd_methods helper function is therefore used to retrospectively patch a SwiftLogAdapter instance with the StatsdClient interface when necessary. The _patch_statsd_helper is used in get_logger, and again when we clone a logger in get_prefixed_logger. Co-Authored-By: Shreeya Deshpande Change-Id: I44694b92264066ca427bb96456d6f944e09b31c0 --- swift/cli/relinker.py | 4 +- swift/common/utils/__init__.py | 140 ++++++++- swift/common/utils/logs.py | 117 +++----- test/debug_logger.py | 6 +- .../common/middleware/test_proxy_logging.py | 4 +- test/unit/common/test_statsd_client.py | 36 --- test/unit/common/test_utils.py | 283 +++++++++++++++++- test/unit/common/utils/test_logs.py | 157 +++++----- test/unit/proxy/test_server.py | 28 +- 9 files changed, 553 insertions(+), 222 deletions(-) diff --git a/swift/cli/relinker.py b/swift/cli/relinker.py index e47334091f..4424422c15 100644 --- a/swift/cli/relinker.py +++ b/swift/cli/relinker.py @@ -30,10 +30,10 @@ from swift.common.exceptions import LockTimeout from swift.common.storage_policy import POLICIES from swift.common.utils import replace_partition_in_path, config_true_value, \ audit_location_generator, get_logger, readconf, drop_privileges, \ - RateLimitedIterator, distribute_evenly, \ + RateLimitedIterator, distribute_evenly, get_prefixed_logger, \ non_negative_float, non_negative_int, config_auto_int_value, \ dump_recon_cache, get_partition_from_path, get_hub -from swift.common.utils.logs import SwiftLogAdapter, get_prefixed_logger +from swift.common.utils.logs import SwiftLogAdapter from swift.obj import diskfile from swift.common.recon import RECON_RELINKER_FILE, DEFAULT_RECON_CACHE_PATH diff --git a/swift/common/utils/__init__.py b/swift/common/utils/__init__.py index 8f1e070c4e..c6c3229244 100644 --- a/swift/common/utils/__init__.py +++ b/swift/common/utils/__init__.py @@ -87,8 +87,8 @@ from .base import ( # noqa from swift.common.utils.logs import ( # noqa SysLogHandler, # t.u.helpers.setup_servers monkey patch is sketch logging_monkey_patch, - get_logger, - get_prefixed_logger, + get_swift_logger, + get_prefixed_swift_logger, LogLevelFilter, NullLogger, capture_stdio, @@ -157,7 +157,7 @@ from swift.common.utils.ipaddrs import ( # noqa parse_socket_string, whataremyips, ) -from swift.common.statsd_client import StatsdClient # noqa +from swift.common.statsd_client import StatsdClient, get_statsd_client import logging EUCLEAN = getattr(errno, 'EUCLEAN', 117) # otherwise not present on osx @@ -205,6 +205,140 @@ DEFAULT_LOCK_TIMEOUT = 10 DEFAULT_DRAIN_LIMIT = 65536 +def _patch_statsd_methods(target, statsd_client_source): + """ + Note: this function is only used to create backwards compatible + legacy "hybrid" loggers that also have a StatsdClient interface. + It should not otherwise be used to patch arbitrary objects to + have a StatsdClient interface. + + Patch the ``target`` object with methods that present an interface to a + ``StatsdClient`` instance that is an attribute ``statsd_client`` of + ``statsd_client_source``. + + Note: ``statsd_client_source`` is an object that *has a* ``StatsdClient`` + and not an object that *is a* ``StatsdClient`` instance, because the + actual ``StatsdClient`` instance may change. The patched target + therefore forwards its methods to whatever instance of ``StatsdClient`` + the ``statsd_client_source`` currently has. + + :param target: an object that will be patched to present an interface to a + ``StatsdClient``. + :param statsd_client_source: an object that must have an attribute + ``statsd_client`` that must be an instance of a ``StatsdClient``. + This is typically a core ``logging.Logger`` that has been patched with + a ``StatsdClient`` by ``get_logger()``. + """ + try: + if not isinstance(statsd_client_source.statsd_client, StatsdClient): + raise ValueError() + except (AttributeError, ValueError): + raise ValueError( + 'statsd_client_source must have a statsd_client attribute') + + def set_statsd_prefix(prefix): + """ + This method is deprecated. Callers should use the + ``statsd_tail_prefix`` argument of ``get_logger`` when instantiating a + logger. + + The StatsD client prefix defaults to the "name" of the logger. This + method may override that default with a specific value. Currently used + in the proxy-server to differentiate the Account, Container, and Object + controllers. + """ + warnings.warn( + 'set_statsd_prefix() is deprecated; use the ' + '``statsd_tail_prefix`` argument to ``get_logger`` instead.', + DeprecationWarning, stacklevel=2 + ) + if getattr(statsd_client_source, 'statsd_client'): + statsd_client_source.statsd_client._set_prefix(prefix) + + def statsd_delegate(statsd_func_name): + """ + Factory to create methods which delegate to methods on + ``statsd_client_source.statsd_client`` (an instance of StatsdClient). + The created methods conditionally delegate to a method whose name is + given in 'statsd_func_name'. The created delegate methods are a no-op + when StatsD logging is not configured. + + :param statsd_func_name: the name of a method on ``StatsdClient``. + """ + func = getattr(StatsdClient, statsd_func_name) + + @functools.wraps(func) + def wrapped(*a, **kw): + if getattr(statsd_client_source, 'statsd_client'): + func = getattr(statsd_client_source.statsd_client, + statsd_func_name) + return func(*a, **kw) + return wrapped + + target.update_stats = statsd_delegate('update_stats') + target.increment = statsd_delegate('increment') + target.decrement = statsd_delegate('decrement') + target.timing = statsd_delegate('timing') + target.timing_since = statsd_delegate('timing_since') + target.transfer_rate = statsd_delegate('transfer_rate') + target.set_statsd_prefix = set_statsd_prefix + target.statsd_client_source = statsd_client_source + + +def get_logger(conf, name=None, log_to_console=False, log_route=None, + fmt="%(server)s: %(message)s", statsd_tail_prefix=None): + """ + Returns a ``SwiftLogAdapter`` that has been patched to also provide an + interface to a ``StatsdClient``. + + :param conf: Configuration dict to read settings from + :param name: This value is used to populate the ``server`` field in the log + format, as the prefix for statsd messages, and as the default + value for ``log_route``; defaults to the ``log_name`` value in + ``conf``, if it exists, or to 'swift'. + :param log_to_console: Add handler which writes to console on stderr. + :param log_route: Route for the logging, not emitted to the log, just used + to separate logging configurations; defaults to the value + of ``name`` or whatever ``name`` defaults to. This value + is used as the name attribute of the + ``SwiftLogAdapter`` that is returned. + :param fmt: Override log format. + :param statsd_tail_prefix: tail prefix to pass to ``StatsdClient``; if None + then the tail prefix defaults to the value of ``name``. + :return: an instance of ``SwiftLogAdapter``. + """ + conf = conf or {} + swift_logger = get_swift_logger( + conf, name, log_to_console, log_route, fmt) + name = conf.get('log_name', 'swift') if name is None else name + tail_prefix = name if statsd_tail_prefix is None else statsd_tail_prefix + statsd_client = get_statsd_client(conf, tail_prefix, swift_logger.logger) + swift_logger.logger.statsd_client = statsd_client + _patch_statsd_methods(swift_logger, swift_logger.logger) + return swift_logger + + +def get_prefixed_logger(swift_logger, prefix): + """ + Return a clone of the given ``swift_logger`` with a new prefix string + that replaces the prefix string of the given ``swift_logger`` + + If the given ``swift_logger`` has been patched with an interface to a + ``StatsdClient`` instance then the returned ``SwiftLogAdapter`` will also + be patched with an interface to the same ``StatsdClient`` instance. + + :param swift_logger: an instance of ``SwiftLogAdapter``. + :param prefix: a string prefix. + :returns: a new instance of ``SwiftLogAdapter``. + """ + new_logger = get_prefixed_swift_logger(swift_logger, prefix=prefix) + if hasattr(swift_logger, 'statsd_client_source'): + if getattr(swift_logger.statsd_client_source, 'statsd_client'): + _patch_statsd_methods( + new_logger, swift_logger.statsd_client_source) + return new_logger + + class InvalidHashPathConfigError(ValueError): def __str__(self): diff --git a/swift/common/utils/logs.py b/swift/common/utils/logs.py index 01a02648d0..e35dbce7aa 100644 --- a/swift/common/utils/logs.py +++ b/swift/common/utils/logs.py @@ -24,9 +24,7 @@ import socket import stat import string import sys -import functools import time -import warnings import fcntl import eventlet import six @@ -35,7 +33,6 @@ import datetime from swift.common.utils.base import md5, quote, split_path from swift.common.utils.timestamp import UTC from swift.common.utils.config import config_true_value -from swift.common import statsd_client # common.utils imports a fully qualified common.exceptions so that # common.exceptions can import common.utils with out a circular import error # (if we only make reference to attributes of a module w/i our function/method @@ -175,13 +172,13 @@ class PipeMutex(object): def __del__(self): # We need this so we don't leak file descriptors. Otherwise, if you - # call get_logger() and don't explicitly dispose of it by calling + # call get_swift_logger() and don't explicitly dispose of it by calling # logger.logger.handlers[0].lock.close() [1], the pipe file # descriptors are leaked. # # This only really comes up in tests. Swift processes tend to call - # get_logger() once and then hang on to it until they exit, but the - # test suite calls get_logger() a lot. + # get_swift_logger() once and then hang on to it until they exit, + # but the test suite calls get_swift_logger() a lot. # # [1] and that's a completely ridiculous thing to expect callers to # do, so nobody does it and that's okay. @@ -294,6 +291,7 @@ class SwiftLogAdapter(logging.LoggerAdapter, object): @property def name(self): + # py3 does this for us already; add it for py2 return self.logger.name @property @@ -389,52 +387,6 @@ class SwiftLogAdapter(logging.LoggerAdapter, object): call = self._exception call('%s: %s' % (msg, emsg), *args, **kwargs) - def set_statsd_prefix(self, prefix): - """ - This method is deprecated. Callers should use the - ``statsd_tail_prefix`` argument of ``get_logger`` when instantiating a - logger. - - The StatsD client prefix defaults to the "name" of the logger. This - method may override that default with a specific value. Currently used - in the proxy-server to differentiate the Account, Container, and Object - controllers. - """ - warnings.warn( - 'set_statsd_prefix() is deprecated; use the ' - '``statsd_tail_prefix`` argument to ``get_logger`` instead.', - DeprecationWarning, stacklevel=2 - ) - if self.logger.statsd_client: - self.logger.statsd_client._set_prefix(prefix) - - def statsd_delegate(statsd_func_name): - """ - Factory to create methods which delegate to methods on - self.logger.statsd_client (an instance of StatsdClient). The - created methods conditionally delegate to a method whose name is given - in 'statsd_func_name'. The created delegate methods are a no-op when - StatsD logging is not configured. - - :param statsd_func_name: the name of a method on StatsdClient. - """ - func = getattr(statsd_client.StatsdClient, statsd_func_name) - - @functools.wraps(func) - def wrapped(self, *a, **kw): - if getattr(self.logger, 'statsd_client'): - func = getattr(self.logger.statsd_client, statsd_func_name) - return func(*a, **kw) - - return wrapped - - update_stats = statsd_delegate('update_stats') - increment = statsd_delegate('increment') - decrement = statsd_delegate('decrement') - timing = statsd_delegate('timing') - timing_since = statsd_delegate('timing_since') - transfer_rate = statsd_delegate('transfer_rate') - class SwiftLogFormatter(logging.Formatter): """ @@ -588,8 +540,8 @@ class LogLevelFilter(object): return 1 -def get_logger(conf, name=None, log_to_console=False, log_route=None, - fmt="%(server)s: %(message)s", statsd_tail_prefix=None): +def get_swift_logger(conf, name=None, log_to_console=False, log_route=None, + fmt="%(server)s: %(message)s"): """ Get the current system logger using config settings. @@ -604,10 +556,10 @@ def get_logger(conf, name=None, log_to_console=False, log_route=None, log_address = /dev/log :param conf: Configuration dict to read settings from - :param name: This value is used to populate the ``server`` field in the log - format, as the prefix for statsd messages, and as the default - value for ``log_route``; defaults to the ``log_name`` value in - ``conf``, if it exists, or to 'swift'. + :param name: This value is used to populate the ``server`` field in + the log format, as the default value for ``log_route``; + defaults to the ``log_name`` value in ``conf``, if it exists, + or to 'swift'. :param log_to_console: Add handler which writes to console on stderr :param log_route: Route for the logging, not emitted to the log, just used to separate logging configurations; defaults to the value @@ -615,13 +567,11 @@ def get_logger(conf, name=None, log_to_console=False, log_route=None, is used as the name attribute of the ``logging.LogAdapter`` that is returned. :param fmt: Override log format - :param statsd_tail_prefix: tail prefix to pass to statsd client; if None - then the tail prefix defaults to the value of ``name``. - :return: an instance of ``LogAdapter`` + :return: an instance of ``SwiftLogAdapter`` """ # note: log_name is typically specified in conf (i.e. defined by # operators), whereas log_route is typically hard-coded in callers of - # get_logger (i.e. defined by developers) + # get_swift_logger (i.e. defined by developers) if not conf: conf = {} if name is None: @@ -634,11 +584,11 @@ def get_logger(conf, name=None, log_to_console=False, log_route=None, formatter = SwiftLogFormatter( fmt=fmt, max_line_length=int(conf.get('log_max_line_length', 0))) - # get_logger will only ever add one SysLog Handler to a logger - if not hasattr(get_logger, 'handler4logger'): - get_logger.handler4logger = {} - if logger in get_logger.handler4logger: - logger.removeHandler(get_logger.handler4logger[logger]) + # get_swift_logger will only ever add one SysLog Handler to a logger + if not hasattr(get_swift_logger, 'handler4logger'): + get_swift_logger.handler4logger = {} + if logger in get_swift_logger.handler4logger: + logger.removeHandler(get_swift_logger.handler4logger[logger]) # facility for this logger will be set by last call wins facility = getattr(SysLogHandler, conf.get('log_facility', 'LOG_LOCAL0'), @@ -667,31 +617,26 @@ def get_logger(conf, name=None, log_to_console=False, log_route=None, handler = ThreadSafeSysLogHandler(facility=facility) handler.setFormatter(formatter) logger.addHandler(handler) - get_logger.handler4logger[logger] = handler + get_swift_logger.handler4logger[logger] = handler # setup console logging - if log_to_console or hasattr(get_logger, 'console_handler4logger'): + if log_to_console or hasattr(get_swift_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]) + if not hasattr(get_swift_logger, 'console_handler4logger'): + get_swift_logger.console_handler4logger = {} + if logger in get_swift_logger.console_handler4logger: + logger.removeHandler( + get_swift_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 + get_swift_logger.console_handler4logger[logger] = console_handler # set the level for the logger logger.setLevel( getattr(logging, conf.get('log_level', 'INFO').upper(), logging.INFO)) - # Setup logger with a StatsD client if so configured - if statsd_tail_prefix is None: - statsd_tail_prefix = name - logger.statsd_client = statsd_client.get_statsd_client( - conf, statsd_tail_prefix, logger) - adapted_logger = SwiftLogAdapter(logger, name) other_handlers = conf.get('log_custom_handlers', None) if other_handlers: @@ -713,7 +658,15 @@ def get_logger(conf, name=None, log_to_console=False, log_route=None, return adapted_logger -def get_prefixed_logger(swift_logger, prefix): +def get_prefixed_swift_logger(swift_logger, prefix): + """ + Return a clone of the given ``swift_logger`` with a new prefix string + that replaces the prefix string of the given ``swift_logger``. + + :param swift_logger: an instance of ``SwiftLogAdapter``. + :param prefix: a string prefix. + :returns: a new instance of ``SwiftLogAdapter``. + """ return SwiftLogAdapter( swift_logger.logger, swift_logger.server, prefix=prefix) @@ -760,7 +713,7 @@ def capture_stdio(logger, **kwargs): # collect stdio file desc not in use for logging stdio_files = [sys.stdin, sys.stdout, sys.stderr] console_fds = [h.stream.fileno() for _junk, h in getattr( - get_logger, 'console_handler4logger', {}).items()] + get_swift_logger, 'console_handler4logger', {}).items()] stdio_files = [f for f in stdio_files if f.fileno() not in console_fds] with open(os.devnull, 'r+b') as nullfile: diff --git a/test/debug_logger.py b/test/debug_logger.py index 43f47064c7..71b23b744b 100644 --- a/test/debug_logger.py +++ b/test/debug_logger.py @@ -272,7 +272,9 @@ class DebugLogAdapter(utils.logs.SwiftLogAdapter): def debug_logger(name='test'): """get a named adapted debug logger""" - return DebugLogAdapter(DebugLogger(), name) + adapted_logger = DebugLogAdapter(DebugLogger(), name) + utils._patch_statsd_methods(adapted_logger, adapted_logger.logger) + return adapted_logger class ForwardingLogHandler(logging.NullHandler): @@ -327,7 +329,7 @@ def capture_logger(conf, *args, **kwargs): """ with mock.patch('swift.common.utils.logs.SwiftLogAdapter', CaptureLogAdapter): - log_adapter = utils.logs.get_logger(conf, *args, **kwargs) + log_adapter = utils.get_logger(conf, *args, **kwargs) log_adapter.start_capture() try: yield log_adapter diff --git a/test/unit/common/middleware/test_proxy_logging.py b/test/unit/common/middleware/test_proxy_logging.py index 7b2b2cb5c3..ac40a2fc59 100644 --- a/test/unit/common/middleware/test_proxy_logging.py +++ b/test/unit/common/middleware/test_proxy_logging.py @@ -23,7 +23,7 @@ from logging.handlers import SysLogHandler import six from six.moves.urllib.parse import unquote -from swift.common.utils import get_logger, split_path +from swift.common.utils import get_swift_logger, split_path from swift.common.statsd_client import StatsdClient from swift.common.middleware import proxy_logging from swift.common.registry import register_sensitive_header, \ @@ -969,7 +969,7 @@ class TestProxyLogging(unittest.TestCase): FakeApp(), {'log_headers': 'yes', 'access_log_facility': 'LOG_LOCAL7'}) - handler = get_logger.handler4logger[app.access_logger.logger] + handler = get_swift_logger.handler4logger[app.access_logger.logger] self.assertEqual(SysLogHandler.LOG_LOCAL7, handler.facility) def test_filter(self): diff --git a/test/unit/common/test_statsd_client.py b/test/unit/common/test_statsd_client.py index 457a455960..73ea86d41f 100644 --- a/test/unit/common/test_statsd_client.py +++ b/test/unit/common/test_statsd_client.py @@ -819,39 +819,3 @@ class TestModuleFunctions(unittest.TestCase): self.assertEqual(self.logger, client.logger) warn_lines = self.logger.get_lines_for_level('warning') self.assertEqual([], warn_lines) - - -class TestSwiftLogAdapterDelegation(unittest.TestCase): - - def setUp(self): - self.logger = utils.get_logger({'log_statsd_host': 'some.host.com'}, - 'some-name', log_route='some-route') - self.mock_socket = MockUdpSocket() - self.logger.logger.statsd_client._open_socket = \ - lambda *_: self.mock_socket - self.address = ('some.host.com', 8125) - - def test_setup(self): - self.logger.increment('foo') - self.assertEqual(self.mock_socket.sent, - [(b'some-name.foo:1|c', self.address)]) - - def test_get_prefix_logger(self): - prefixed_logger = utils.get_prefixed_logger(self.logger, 'my-prefix') - prefixed_logger.increment('bar') - self.assertEqual(self.mock_socket.sent, - [(b'some-name.bar:1|c', self.address)]) - - def test_adapted_logger(self): - adapted_logger = utils.logs.SwiftLogAdapter( - self.logger.logger, 'my-adapter') - adapted_logger.increment('buz') - self.assertEqual(self.mock_socket.sent, - [(b'some-name.buz:1|c', self.address)]) - - def test_wrapped_adapter(self): - wrapped_adapter = utils.logs.SwiftLogAdapter( - self.logger, 'wrapped-adapter') - with self.assertRaises(AttributeError) as ctx: - wrapped_adapter.increment('baz') - self.assertIn("has no attribute 'statsd_client'", str(ctx.exception)) diff --git a/test/unit/common/test_utils.py b/test/unit/common/test_utils.py index 8e946f5056..a9f7118b92 100644 --- a/test/unit/common/test_utils.py +++ b/test/unit/common/test_utils.py @@ -16,10 +16,11 @@ """Tests for swift.common.utils""" from __future__ import print_function +import argparse import hashlib import itertools -from test.debug_logger import debug_logger +from test.debug_logger import debug_logger, FakeStatsdClient from test.unit import temptree, make_timestamp_iter, with_tempdir, \ mock_timestamp_now, FakeIterable @@ -7367,3 +7368,283 @@ class TestContextPool(unittest.TestCase): self.assertEqual(pool.running(), size) pool.close() self.assertEqual(pool.running(), 0) + + +class TestLoggerStatsdClientDelegation(unittest.TestCase): + def setUp(self): + self.logger_name = 'server' + + def tearDown(self): + # Avoid test coupling by removing any StatsdClient instance + # that may have been patched on to a Logger. + core_logger = logging.getLogger(self.logger_name) + if hasattr(core_logger, 'statsd_client'): + del core_logger.statsd_client + + def test_patch_statsd_methods(self): + client = FakeStatsdClient('host.com', 1234) + source = argparse.Namespace() + source.statsd_client = client + + target = argparse.Namespace() + utils._patch_statsd_methods(target, source) + target.increment('a') + target.decrement('b') + target.update_stats('c', 4) + target.timing('d', 23.4) + target.timing_since('e', 23.4) + target.transfer_rate('f', 56.7, 1234.5) + exp = { + 'decrement': [(('b',), {})], + 'increment': [(('a',), {})], + 'timing': [(('d', 23.4), {}), + (('f', 45929.52612393682, None), {})], + 'timing_since': [(('e', 23.4), {})], + 'transfer_rate': [(('f', 56.7, 1234.5), {})], + 'update_stats': [(('a', 1, None), {}), + (('b', -1, None), {}), + (('c', 4), {})] + } + self.assertEqual(exp, client.calls) + + def test_patch_statsd_methods_source_is_none(self): + with self.assertRaises(ValueError) as cm: + utils._patch_statsd_methods(object, None) + self.assertEqual( + 'statsd_client_source must have a statsd_client attribute', + str(cm.exception)) + + def test_patch_statsd_methods_source_no_statsd_client(self): + source = argparse.Namespace() + with self.assertRaises(ValueError) as cm: + utils._patch_statsd_methods(object, source) + self.assertEqual( + 'statsd_client_source must have a statsd_client attribute', + str(cm.exception)) + + def test_patch_statsd_methods_source_statsd_client_is_none(self): + source = argparse.Namespace() + source.statsd_client = None + with self.assertRaises(ValueError) as cm: + utils._patch_statsd_methods(object, source) + self.assertEqual( + 'statsd_client_source must have a statsd_client attribute', + str(cm.exception)) + + def test_patch_statsd_methods_client_deleted_from_source(self): + client = FakeStatsdClient('host.com', 1234) + source = argparse.Namespace() + source.statsd_client = client + target = argparse.Namespace() + utils._patch_statsd_methods(target, source) + target.increment('a') + exp = { + 'increment': [(('a',), {})], + 'update_stats': [(('a', 1, None), {})], + } + self.assertEqual(exp, client.calls) + + # if the statsd_client is deleted you will blow up... + del source.statsd_client + try: + target.increment('b') + except AttributeError as err: + self.assertEqual( + str(err), + "'Namespace' object has no attribute 'statsd_client'") + + def test_get_logger_provides_a_swift_log_adapter(self): + orig_get_swift_logger = utils.logs.get_swift_logger + calls = [] + + def fake_get_swift_logger(*args, **kwargs): + result = orig_get_swift_logger(*args, **kwargs) + calls.append((args, kwargs, result)) + return result + + conf = {} + fmt = 'test %(message)s' + with mock.patch( + 'swift.common.utils.get_swift_logger', fake_get_swift_logger): + logger = utils.get_logger( + conf, name=self.logger_name, log_to_console=True, + log_route='test', fmt=fmt) + self.assertEqual(1, len(calls)) + self.assertEqual( + ((conf, self.logger_name, True, 'test', fmt), {}), + calls[0][:2]) + self.assertIs(calls[0][2], logger) + + def test_get_logger_provides_statsd_client(self): + with mock.patch( + 'swift.common.statsd_client.StatsdClient', FakeStatsdClient): + swift_logger = utils.get_logger(None, name=self.logger_name) + self.assertTrue(hasattr(swift_logger.logger, 'statsd_client')) + self.assertIsInstance(swift_logger.logger.statsd_client, + FakeStatsdClient) + swift_logger.increment('a') + swift_logger.decrement('b') + swift_logger.update_stats('c', 4) + swift_logger.timing('d', 23.4) + swift_logger.timing_since('e', 23.4) + swift_logger.transfer_rate('f', 56.7, 1234.5) + exp = { + 'decrement': [(('b',), {})], + 'increment': [(('a',), {})], + 'timing': [(('d', 23.4), {}), + (('f', 45929.52612393682, None), {})], + 'timing_since': [(('e', 23.4), {})], + 'transfer_rate': [(('f', 56.7, 1234.5), {})], + 'update_stats': [(('a', 1, None), {}), + (('b', -1, None), {}), + (('c', 4), {})] + } + self.assertTrue(hasattr(swift_logger.logger, 'statsd_client')) + client = swift_logger.logger.statsd_client + self.assertEqual(exp, client.calls) + + def test_get_logger_statsd_client_prefix(self): + def call_get_logger(conf, name, statsd_tail_prefix): + with mock.patch('swift.common.statsd_client.StatsdClient', + FakeStatsdClient): + swift_logger = utils.get_logger( + conf, name=name, statsd_tail_prefix=statsd_tail_prefix) + self.assertTrue(hasattr(swift_logger.logger, 'statsd_client')) + self.assertIsInstance(swift_logger.logger.statsd_client, + FakeStatsdClient) + return swift_logger.logger.statsd_client + + # tail prefix defaults to swift + statsd_client = call_get_logger(None, None, None) + self.assertEqual('swift.', statsd_client._prefix) + + # tail prefix defaults to conf log_name + conf = {'log_name': 'bar'} + statsd_client = call_get_logger(conf, None, None) + self.assertEqual('bar.', statsd_client._prefix) + + # tail prefix defaults to name arg which overrides conf log_name + statsd_client = call_get_logger(conf, '', None) + self.assertEqual('', statsd_client._prefix) + + # tail prefix defaults to name arg which overrides conf log_name + statsd_client = call_get_logger(conf, 'baz', None) + self.assertEqual('baz.', statsd_client._prefix) + + # tail prefix set to statsd_tail_prefix arg which overrides name arg + statsd_client = call_get_logger(conf, 'baz', '') + self.assertEqual('', statsd_client._prefix) + + # tail prefix set to statsd_tail_prefix arg which overrides name arg + statsd_client = call_get_logger(conf, 'baz', 'boo') + self.assertEqual('boo.', statsd_client._prefix) + + # base prefix is configured, tail prefix defaults to swift + conf = {'log_statsd_metric_prefix': 'foo'} + statsd_client = call_get_logger(conf, None, None) + self.assertEqual('foo.swift.', statsd_client._prefix) + + # base prefix is configured, tail prefix defaults to conf log_name + conf = {'log_statsd_metric_prefix': 'foo', 'log_name': 'bar'} + statsd_client = call_get_logger(conf, None, None) + self.assertEqual('foo.bar.', statsd_client._prefix) + + # base prefix is configured, tail prefix defaults to name arg + statsd_client = call_get_logger(conf, 'baz', None) + self.assertEqual('foo.baz.', statsd_client._prefix) + + # base prefix is configured, tail prefix set to statsd_tail_prefix arg + statsd_client = call_get_logger(conf, None, '') + self.assertEqual('foo.', statsd_client._prefix) + + # base prefix is configured, tail prefix set to statsd_tail_prefix arg + statsd_client = call_get_logger(conf, 'baz', 'boo') + self.assertEqual('foo.boo.', statsd_client._prefix) + + def test_get_logger_replaces_statsd_client(self): + # Each call to get_logger creates a *new* StatsdClient instance and + # sets it as an attribute of the potentially *shared* Logger instance. + # This is a questionable pattern but the test at least reminds us. + orig_logger = utils.get_logger( + {'log_statsd_port': 1234}, + name=self.logger_name, + statsd_tail_prefix='orig') + self.assertTrue(hasattr(orig_logger.logger, 'statsd_client')) + orig_client = orig_logger.logger.statsd_client + self.assertEqual('orig.', orig_client._prefix) + self.assertEqual(1234, orig_client._port) + + new_adapted_logger = utils.get_logger( + {'log_statsd_port': 5678}, + name=self.logger_name, + statsd_tail_prefix='new') + self.assertTrue(hasattr(new_adapted_logger.logger, 'statsd_client')) + new_client = new_adapted_logger.logger.statsd_client + # same core Logger... + self.assertIs(orig_logger.logger, new_adapted_logger.logger) + # ... different StatsdClient ! + self.assertIsNot(new_client, orig_client) + self.assertIs(new_client, orig_logger.logger.statsd_client) + self.assertEqual('new.', new_client._prefix) + self.assertEqual(5678, new_client._port) + + def test_get_prefixed_logger_calls_get_prefixed_swift_logger(self): + orig_get_prefixed_swift_logger = utils.logs.get_prefixed_swift_logger + base_logger = utils.logs.get_swift_logger(None) + calls = [] + + def fake_get_prefixed_swift_logger(*args, **kwargs): + result = orig_get_prefixed_swift_logger(*args, **kwargs) + calls.append((args, kwargs, result)) + return result + + with mock.patch( + 'swift.common.utils.get_prefixed_swift_logger', + fake_get_prefixed_swift_logger): + logger = utils.get_prefixed_logger(base_logger, 'boo') + self.assertEqual(1, len(calls)) + self.assertEqual(((base_logger,), {'prefix': 'boo'}), calls[0][:2]) + self.assertEqual(calls[0][2], logger) + self.assertEqual('boo', logger.prefix) + + def test_get_prefixed_logger_adopts_statsd_client(self): + # verify that get_prefixed_logger installs an interface to any existing + # StatsdClient that the source logger has + with mock.patch( + 'swift.common.statsd_client.StatsdClient', FakeStatsdClient): + adapted_logger = utils.get_logger(None, name=self.logger_name) + self.assertTrue(hasattr(adapted_logger.logger, 'statsd_client')) + self.assertIsInstance(adapted_logger.logger.statsd_client, + FakeStatsdClient) + + prefixed_logger = utils.get_prefixed_logger(adapted_logger, 'test') + self.assertTrue(hasattr(prefixed_logger.logger, 'statsd_client')) + self.assertIs(prefixed_logger.logger.statsd_client, + adapted_logger.logger.statsd_client) + + prefixed_logger.increment('foo') + prefixed_logger.decrement('boo') + + exp = { + 'increment': [(('foo',), {})], + 'decrement': [(('boo',), {})], + 'update_stats': [(('foo', 1, None), {}), + (('boo', -1, None), {})] + } + self.assertEqual(exp, prefixed_logger.logger.statsd_client.calls) + self.assertEqual(exp, adapted_logger.logger.statsd_client.calls) + + def test_get_prefixed_logger_no_statsd_client(self): + # verify get_prefixed_logger can be used to mutate the prefix of a + # SwiftLogAdapter that does *not* have a StatsdClient interface + adapted_logger = utils.logs.get_swift_logger( + None, name=self.logger_name) + self.assertFalse( + hasattr(adapted_logger.logger, 'statsd_client')) + self.assertFalse(hasattr(adapted_logger, 'statsd_client_source')) + self.assertFalse(hasattr(adapted_logger, 'increment')) + + prefixed_logger = utils.get_prefixed_logger(adapted_logger, 'test') + self.assertFalse(hasattr(prefixed_logger, 'statsd_client_source')) + self.assertFalse(hasattr(prefixed_logger.logger, 'statsd_client')) + self.assertFalse(hasattr(prefixed_logger, 'increment')) diff --git a/test/unit/common/utils/test_logs.py b/test/unit/common/utils/test_logs.py index 7d9c082904..e20b5e54bf 100644 --- a/test/unit/common/utils/test_logs.py +++ b/test/unit/common/utils/test_logs.py @@ -36,8 +36,7 @@ from six.moves import http_client from test.unit import with_tempdir from test.unit import quiet_eventlet_exceptions from test.unit.common.test_utils import MockOs, MockSys -from swift.common.exceptions import Timeout, \ - MessageTimeout, ConnectionTimeout +from swift.common.exceptions import Timeout, MessageTimeout, ConnectionTimeout if six.PY2: import eventlet.green.httplib as green_http_client @@ -48,23 +47,24 @@ from swift.common import utils from swift.common.swob import Request, Response from swift.common.utils.logs import SwiftLogFormatter, SwiftLogAdapter, \ - get_prefixed_logger + get_swift_logger, get_prefixed_swift_logger def reset_loggers(): - if hasattr(utils.get_logger, 'handler4logger'): - for logger, handler in utils.get_logger.handler4logger.items(): + if hasattr(get_swift_logger, 'handler4logger'): + for logger, handler in get_swift_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(): + delattr(get_swift_logger, 'handler4logger') + if hasattr(get_swift_logger, 'console_handler4logger'): + for logger, h in \ + get_swift_logger.console_handler4logger.items(): logger.removeHandler(h) - delattr(utils.get_logger, 'console_handler4logger') - # Reset the LogAdapter class thread local state. Use get_logger() here - # to fetch a LogAdapter instance because the items from - # get_logger.handler4logger above are the underlying logger instances, - # not the LogAdapter. - utils.get_logger(None).thread_locals = (None, None) + delattr(get_swift_logger, 'console_handler4logger') + # Reset the LogAdapter class thread local state. Use get_swift_logger() + # here to fetch a LogAdapter instance because the items from + # get_swift_logger.handler4logger above are the underlying logger + # instances not the LogAdapter. + get_swift_logger(None).thread_locals = (None, None) def reset_logger_state(f): @@ -192,22 +192,22 @@ class TestUtilsLogs(unittest.TestCase): logger.removeHandler(handler) - def test_get_logger(self): + def test_get_swift_logger(self): sio = StringIO() logger = logging.getLogger('server') logger.addHandler(logging.StreamHandler(sio)) - logger = utils.get_logger(None, 'server', log_route='server') + logger = get_swift_logger(None, 'server', log_route='server') logger.warning('test1') self.assertEqual(sio.getvalue(), 'test1\n') logger.debug('test2') self.assertEqual(sio.getvalue(), 'test1\n') - logger = utils.get_logger({'log_level': 'DEBUG'}, 'server', + logger = get_swift_logger({'log_level': 'DEBUG'}, 'server', log_route='server') logger.debug('test3') self.assertEqual(sio.getvalue(), 'test1\ntest3\n') # Doesn't really test that the log facility is truly being used all the # way to syslog; but exercises the code. - logger = utils.get_logger({'log_facility': 'LOG_LOCAL3'}, 'server', + logger = get_swift_logger({'log_facility': 'LOG_LOCAL3'}, 'server', log_route='server') logger.warning('test4') self.assertEqual(sio.getvalue(), @@ -221,7 +221,7 @@ class TestUtilsLogs(unittest.TestCase): self.assertEqual(sio.getvalue(), 'test1\ntest3\ntest4\ntest6\n') - def test_get_logger_name_and_route(self): + def test_get_swift_logger_name_and_route(self): @contextlib.contextmanager def add_log_handler(logger): # install a handler to capture log messages formatted as per swift @@ -234,7 +234,7 @@ class TestUtilsLogs(unittest.TestCase): yield sio logger.logger.removeHandler(handler) - logger = utils.get_logger({}, name='name', log_route='route') + logger = utils.get_swift_logger({}, name='name', log_route='route') # log_route becomes the LogAdapter.name and logging.Logger.name self.assertEqual('route', logger.name) self.assertEqual('route', logger.logger.name) @@ -245,36 +245,37 @@ class TestUtilsLogs(unittest.TestCase): logger.info('testing') self.assertEqual('name: testing\n', sio.getvalue()) - logger = utils.get_logger({'log_name': 'conf-name'}, name='name', - log_route='route') + logger = utils.get_swift_logger({'log_name': 'conf-name'}, + name='name', log_route='route') self.assertEqual('route', logger.name) self.assertEqual('name', logger.server) with add_log_handler(logger) as sio: logger.info('testing') self.assertEqual('name: testing\n', sio.getvalue()) - logger = utils.get_logger({'log_name': 'conf-name'}, log_route='route') + logger = utils.get_swift_logger({'log_name': 'conf-name'}, + log_route='route') self.assertEqual('route', logger.name) self.assertEqual('conf-name', logger.server) with add_log_handler(logger) as sio: logger.info('testing') self.assertEqual('conf-name: testing\n', sio.getvalue()) - logger = utils.get_logger({'log_name': 'conf-name'}) + logger = utils.get_swift_logger({'log_name': 'conf-name'}) self.assertEqual('conf-name', logger.name) self.assertEqual('conf-name', logger.server) with add_log_handler(logger) as sio: logger.info('testing') self.assertEqual('conf-name: testing\n', sio.getvalue()) - logger = utils.get_logger({}) + logger = utils.get_swift_logger({}) self.assertEqual('swift', logger.name) self.assertEqual('swift', logger.server) with add_log_handler(logger) as sio: logger.info('testing') self.assertEqual('swift: testing\n', sio.getvalue()) - logger = utils.get_logger({}, log_route='route') + logger = utils.get_swift_logger({}, log_route='route') self.assertEqual('route', logger.name) self.assertEqual('swift', logger.server) with add_log_handler(logger) as sio: @@ -282,20 +283,16 @@ class TestUtilsLogs(unittest.TestCase): self.assertEqual('swift: testing\n', sio.getvalue()) # same log_route, different names... - logger1 = utils.get_logger({'log_statsd_host': '1.2.3.4'}, - name='name1', log_route='route') - logger2 = utils.get_logger({'log_statsd_host': '1.2.3.5'}, - name='name2', log_route='route') + logger1 = utils.get_swift_logger({'log_statsd_host': '1.2.3.4'}, + name='name1', log_route='route') + logger2 = utils.get_swift_logger({'log_statsd_host': '1.2.3.5'}, + name='name2', log_route='route') self.assertEqual('route', logger1.name) self.assertEqual('route', logger1.logger.name) self.assertEqual('name1', logger1.server) - # oh dear, the statsd client on the common logging.Logger instance got - # mutated when logger2 was created - self.assertEqual('name2.', logger1.logger.statsd_client._prefix) self.assertEqual('route', logger2.name) self.assertEqual('route', logger2.logger.name) self.assertEqual('name2', logger2.server) - self.assertEqual('name2.', logger2.logger.statsd_client._prefix) self.assertIs(logger2.logger, logger1.logger) with add_log_handler(logger1) as sio: logger1.info('testing') @@ -305,18 +302,16 @@ class TestUtilsLogs(unittest.TestCase): self.assertEqual('name2: testing\n', sio.getvalue()) # different log_route, different names... - logger1 = utils.get_logger({'log_statsd_host': '1.2.3.4'}, - name='name1', log_route='route1') - logger2 = utils.get_logger({'log_statsd_host': '1.2.3.5'}, - name='name2', log_route='route2') + logger1 = utils.get_swift_logger({'log_statsd_host': '1.2.3.4'}, + name='name1', log_route='route1') + logger2 = utils.get_swift_logger({'log_statsd_host': '1.2.3.5'}, + name='name2', log_route='route2') self.assertEqual('route1', logger1.name) self.assertEqual('route1', logger1.logger.name) self.assertEqual('name1', logger1.server) - self.assertEqual('name1.', logger1.logger.statsd_client._prefix) self.assertEqual('route2', logger2.name) self.assertEqual('route2', logger2.logger.name) self.assertEqual('name2', logger2.server) - self.assertEqual('name2.', logger2.logger.statsd_client._prefix) self.assertIsNot(logger2.logger, logger1.logger) with add_log_handler(logger1) as sio: logger1.info('testing') @@ -326,7 +321,7 @@ class TestUtilsLogs(unittest.TestCase): self.assertEqual('name2: testing\n', sio.getvalue()) @with_tempdir - def test_get_logger_sysloghandler_plumbing(self, tempdir): + def test_get_swift_logger_sysloghandler_plumbing(self, tempdir): orig_sysloghandler = utils.logs.ThreadSafeSysLogHandler syslog_handler_args = [] @@ -348,7 +343,7 @@ class TestUtilsLogs(unittest.TestCase): syslog_handler_catcher), \ mock.patch.object(socket, 'getaddrinfo', fake_getaddrinfo): # default log_address - utils.get_logger({ + get_swift_logger({ 'log_facility': 'LOG_LOCAL3', }, 'server', log_route='server') expected_args = [((), {'address': '/dev/log', @@ -365,7 +360,7 @@ class TestUtilsLogs(unittest.TestCase): # custom log_address - file doesn't exist: fallback to UDP log_address = os.path.join(tempdir, 'foo') syslog_handler_args = [] - utils.get_logger({ + get_swift_logger({ 'log_facility': 'LOG_LOCAL3', 'log_address': log_address, }, 'server', log_route='server') @@ -378,7 +373,7 @@ class TestUtilsLogs(unittest.TestCase): with open(log_address, 'w'): pass syslog_handler_args = [] - utils.get_logger({ + get_swift_logger({ 'log_facility': 'LOG_LOCAL3', 'log_address': log_address, }, 'server', log_route='server') @@ -394,7 +389,7 @@ class TestUtilsLogs(unittest.TestCase): sock.settimeout(5) sock.bind(log_address) syslog_handler_args = [] - utils.get_logger({ + get_swift_logger({ 'log_facility': 'LOG_LOCAL3', 'log_address': log_address, }, 'server', log_route='server') @@ -406,7 +401,7 @@ class TestUtilsLogs(unittest.TestCase): # Using UDP with default port syslog_handler_args = [] - utils.get_logger({ + get_swift_logger({ 'log_udp_host': 'syslog.funtimes.com', }, 'server', log_route='server') self.assertEqual([ @@ -417,7 +412,7 @@ class TestUtilsLogs(unittest.TestCase): # Using UDP with non-default port syslog_handler_args = [] - utils.get_logger({ + get_swift_logger({ 'log_udp_host': 'syslog.funtimes.com', 'log_udp_port': '2123', }, 'server', log_route='server') @@ -429,13 +424,13 @@ class TestUtilsLogs(unittest.TestCase): with mock.patch.object(utils.logs, 'ThreadSafeSysLogHandler', side_effect=OSError(errno.EPERM, 'oops')): with self.assertRaises(OSError) as cm: - utils.get_logger({ + get_swift_logger({ 'log_facility': 'LOG_LOCAL3', 'log_address': 'log_address', }, 'server', log_route='server') self.assertEqual(errno.EPERM, cm.exception.errno) - def test_get_logger_custom_log_handlers(self): + def test_get_swift_logger_custom_log_handlers(self): def custom_log_handler(conf, name, log_to_console, log_route, fmt, logger, adapted_logger): adapted_logger.server = adapted_logger.server.upper() @@ -449,7 +444,7 @@ class TestUtilsLogs(unittest.TestCase): # sanity check... conf = {} - adapted_logger = utils.get_logger( + adapted_logger = get_swift_logger( conf, 'my_server', log_route='my_logger_name') adapted_logger.warning('test') self.assertEqual(sio.getvalue(), @@ -461,7 +456,7 @@ class TestUtilsLogs(unittest.TestCase): patch_target = 'test.unit.common.utils.custom_log_handler' conf = {'log_custom_handlers': patch_target} with mock.patch(patch_target, custom_log_handler, create=True): - adapted_logger = utils.get_logger( + adapted_logger = get_swift_logger( conf, 'my_server', log_route='my_logger_name') adapted_logger.warning('test') self.assertEqual(sio.getvalue(), @@ -471,7 +466,7 @@ class TestUtilsLogs(unittest.TestCase): def test_clean_logger_exception(self): # setup stream logging sio = StringIO() - logger = utils.get_logger(None) + logger = get_swift_logger(None) handler = logging.StreamHandler(sio) logger.logger.addHandler(handler) @@ -610,7 +605,7 @@ class TestUtilsLogs(unittest.TestCase): def test_swift_log_formatter_max_line_length(self): # setup stream logging sio = StringIO() - logger = utils.get_logger(None) + logger = get_swift_logger(None) handler = logging.StreamHandler(sio) formatter = utils.SwiftLogFormatter(max_line_length=10) handler.setFormatter(formatter) @@ -666,7 +661,7 @@ class TestUtilsLogs(unittest.TestCase): def test_swift_log_formatter(self): # setup stream logging sio = StringIO() - logger = utils.get_logger(None) + logger = get_swift_logger(None) handler = logging.StreamHandler(sio) handler.setFormatter(utils.SwiftLogFormatter()) logger.logger.addHandler(handler) @@ -728,13 +723,13 @@ class TestUtilsLogs(unittest.TestCase): logger.logger.removeHandler(handler) @reset_logger_state - def test_get_prefixed_logger(self): + def test_get_prefixed_swift_logger(self): # setup stream logging sio = StringIO() - base_logger = utils.get_logger(None) + base_logger = get_swift_logger(None) handler = logging.StreamHandler(sio) base_logger.logger.addHandler(handler) - logger = get_prefixed_logger(base_logger, 'some prefix: ') + logger = get_prefixed_swift_logger(base_logger, 'some prefix: ') def strip_value(sio): sio.seek(0) @@ -759,13 +754,13 @@ class TestUtilsLogs(unittest.TestCase): base_logger.logger.removeHandler(handler) @reset_logger_state - def test_get_prefixed_logger_exception_method(self): + def test_get_prefixed_swift_logger_exception_method(self): # setup stream logging sio = StringIO() - base_logger = utils.get_logger(None) + base_logger = get_swift_logger(None) handler = logging.StreamHandler(sio) base_logger.logger.addHandler(handler) - logger = get_prefixed_logger(base_logger, 'some prefix: ') + logger = get_prefixed_swift_logger(base_logger, 'some prefix: ') def strip_value(sio): sio.seek(0) @@ -816,13 +811,13 @@ class TestUtilsLogs(unittest.TestCase): base_logger.logger.removeHandler(handler) @reset_logger_state - def test_get_prefixed_logger_non_string_values(self): + def test_get_prefixed_swift_logger_non_string_values(self): # setup stream logging sio = StringIO() - base_logger = utils.get_logger(None) + base_logger = get_swift_logger(None) handler = logging.StreamHandler(sio) base_logger.logger.addHandler(handler) - logger = get_prefixed_logger(base_logger, 'some prefix: ') + logger = get_prefixed_swift_logger(base_logger, 'some prefix: ') exc = Exception('blah') def strip_value(sio): @@ -832,21 +827,21 @@ class TestUtilsLogs(unittest.TestCase): return v try: - logger = get_prefixed_logger(logger, 'abc') + logger = get_prefixed_swift_logger(logger, 'abc') self.assertEqual('abc', logger.prefix) logger.info('test') self.assertEqual(strip_value(sio), 'abctest\n') logger.info(exc) self.assertEqual(strip_value(sio), 'abcblah\n') - logger = get_prefixed_logger(logger, '') + logger = get_prefixed_swift_logger(logger, '') self.assertEqual('', logger.prefix) logger.info('test') self.assertEqual(strip_value(sio), 'test\n') logger.info(exc) self.assertEqual(strip_value(sio), 'blah\n') - logger = get_prefixed_logger(logger, 0) + logger = get_prefixed_swift_logger(logger, 0) self.assertEqual(0, logger.prefix) logger.info('test') self.assertEqual(strip_value(sio), '0test\n') @@ -856,14 +851,14 @@ class TestUtilsLogs(unittest.TestCase): logger.logger.removeHandler(handler) @reset_logger_state - def test_get_prefixed_logger_replaces_prefix(self): + def test_get_prefixed_swift_logger_replaces_prefix(self): # setup stream logging sio = StringIO() - base_logger = utils.get_logger(None) + base_logger = get_swift_logger(None) handler = logging.StreamHandler(sio) base_logger.logger.addHandler(handler) - logger1 = get_prefixed_logger(base_logger, 'one: ') - logger2 = get_prefixed_logger(logger1, 'two: ') + logger1 = get_prefixed_swift_logger(base_logger, 'one: ') + logger2 = get_prefixed_swift_logger(logger1, 'two: ') def strip_value(sio): sio.seek(0) @@ -886,17 +881,17 @@ class TestUtilsLogs(unittest.TestCase): finally: base_logger.logger.removeHandler(handler) - def test_get_prefixed_logger_isolation(self): + def test_get_prefixed_swift_logger_isolation(self): # verify that the new instance's attributes are copied by value # from the old (except prefix), but the thread_locals are still shared - adapted_logger = utils.get_logger(None, name='server') + adapted_logger = get_swift_logger(None, name='server') adapted_logger.thread_locals = ('id', 'ip') - adapted_logger = get_prefixed_logger(adapted_logger, 'foo') + adapted_logger = get_prefixed_swift_logger(adapted_logger, 'foo') self.assertEqual(adapted_logger.server, 'server') self.assertEqual(adapted_logger.thread_locals, ('id', 'ip')) self.assertEqual(adapted_logger.prefix, 'foo') - cloned_adapted_logger = get_prefixed_logger( + cloned_adapted_logger = get_prefixed_swift_logger( adapted_logger, 'boo') self.assertEqual(cloned_adapted_logger.server, 'server') self.assertEqual(cloned_adapted_logger.thread_locals, ('id', 'ip')) @@ -907,7 +902,7 @@ class TestUtilsLogs(unittest.TestCase): self.assertEqual(adapted_logger.prefix, 'foo') self.assertIs(adapted_logger.logger, cloned_adapted_logger.logger) - cloned_adapted_logger = get_prefixed_logger( + cloned_adapted_logger = get_prefixed_swift_logger( adapted_logger, adapted_logger.prefix + 'bar') adapted_logger.server = 'waiter' self.assertEqual(adapted_logger.server, 'waiter') @@ -923,7 +918,7 @@ class TestUtilsLogs(unittest.TestCase): @reset_logger_state def test_capture_stdio(self): # stubs - logger = utils.logs.get_logger(None, 'dummy') + logger = get_swift_logger(None, 'dummy') # mock utils system modules mock_os = MockOs() @@ -958,7 +953,7 @@ class TestUtilsLogs(unittest.TestCase): mock_sys = MockSys() with mock.patch.object(utils.logs, 'os', mock_os), \ mock.patch.object(utils.logs, 'sys', mock_sys): - logger = utils.get_logger(None, log_to_console=True) + logger = get_swift_logger(None, log_to_console=True) # test console log utils.logs.capture_stdio(logger, capture_stdout=False, @@ -976,19 +971,19 @@ class TestUtilsLogs(unittest.TestCase): utils.logs.LoggerFileObject)) @reset_logger_state - def test_get_logger_console(self): - logger = utils.get_logger(None) + def test_get_swift_logger_console(self): + logger = get_swift_logger(None) 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) + logger = get_swift_logger(None, log_to_console=True) console_handlers = [h for h in logger.logger.handlers if isinstance(h, logging.StreamHandler)] self.assertTrue(console_handlers) # make sure you can't have two console handlers self.assertEqual(len(console_handlers), 1) old_handler = console_handlers[0] - logger = utils.get_logger(None, log_to_console=True) + logger = get_swift_logger(None, log_to_console=True) console_handlers = [h for h in logger.logger.handlers if isinstance(h, logging.StreamHandler)] self.assertEqual(len(console_handlers), 1) diff --git a/test/unit/proxy/test_server.py b/test/unit/proxy/test_server.py index 220ca4888b..13d2ce3f1e 100644 --- a/test/unit/proxy/test_server.py +++ b/test/unit/proxy/test_server.py @@ -53,7 +53,7 @@ from six.moves import range from six.moves.urllib.parse import quote, parse_qsl from test import listen_zero -from test.debug_logger import debug_logger +from test.debug_logger import debug_logger, FakeStatsdClient from test.unit import ( connect_tcp, readuntil2crlfs, fake_http_connect, FakeRing, FakeMemcache, patch_policies, write_fake_ring, mocked_http_conn, @@ -2295,16 +2295,17 @@ class TestProxyServerConfigLoading(unittest.TestCase): use = egg:swift#proxy """ % self.tempdir conf_path = self._write_conf(dedent(conf_sections)) - with mock.patch('swift.common.statsd_client.StatsdClient') \ - as mock_statsd: + with mock.patch('swift.common.statsd_client.StatsdClient', + FakeStatsdClient): app = loadapp(conf_path, allow_modify_pipeline=False) # logger name is hard-wired 'proxy-server' self.assertEqual('proxy-server', app.logger.name) self.assertEqual('swift', app.logger.server) - mock_statsd.assert_called_once_with( - 'example.com', 8125, base_prefix='', tail_prefix='proxy-server', - default_sample_rate=1.0, sample_rate_factor=1.0, - logger=app.logger.logger) + self.assertIsInstance(app.logger.logger.statsd_client, StatsdClient) + self.assertEqual(app.logger.logger.statsd_client._host, 'example.com') + self.assertEqual(app.logger.logger.statsd_client._port, 8125) + self.assertEqual(app.logger.logger.statsd_client._prefix, + 'proxy-server.') conf_sections = """ [DEFAULT] @@ -2320,18 +2321,19 @@ class TestProxyServerConfigLoading(unittest.TestCase): """ % self.tempdir conf_path = self._write_conf(dedent(conf_sections)) - with mock.patch('swift.common.statsd_client.StatsdClient') \ - as mock_statsd: + with mock.patch('swift.common.statsd_client.StatsdClient', + FakeStatsdClient): app = loadapp(conf_path, allow_modify_pipeline=False) # logger name is hard-wired 'proxy-server' self.assertEqual('proxy-server', app.logger.name) # server is defined by log_name option self.assertEqual('test-name', app.logger.server) # statsd tail prefix is hard-wired 'proxy-server' - mock_statsd.assert_called_once_with( - 'example.com', 8125, base_prefix='', tail_prefix='proxy-server', - default_sample_rate=1.0, sample_rate_factor=1.0, - logger=app.logger.logger) + self.assertIsInstance(app.logger.logger.statsd_client, StatsdClient) + self.assertEqual(app.logger.logger.statsd_client._host, 'example.com') + self.assertEqual(app.logger.logger.statsd_client._port, 8125) + self.assertEqual(app.logger.logger.statsd_client._prefix, + 'proxy-server.') class TestProxyServerConfigStringLoading(TestProxyServerConfigLoading):