From eda7d5fe3c9527ae20850b38f8b626782dd5efec Mon Sep 17 00:00:00 2001 From: Alistair Coles Date: Fri, 4 Feb 2022 10:58:46 +0000 Subject: [PATCH] Deprecate LogAdapter.set_statsd_prefix Previously, the set_statsd_prefix method was used to mutate a logger's StatsdClient tail prefix after a logger was instantiated. This pattern had led to unexpected mutations (see Related-Change). The tail_prefix can now be passed as an argument to get_logger(), and is then forwarded to the StatsdClient constructor, for a more explicit assignment pattern. The set_statsd_prefix method is left in place for backwards compatibility. A DeprecationWarning will be raised if it is used to mutate the StatsdClient tail prefix. Change-Id: I7692860e3b741e1bc10626e26bb7b27399c325ab Related-Change: I0522b1953722ca96021a0002cf93432b973ce626 --- doc/source/admin/objectstorage-monitoring.rst | 8 --- swift/common/middleware/proxy_logging.py | 4 +- swift/common/middleware/tempauth.py | 9 +-- swift/common/utils.py | 55 ++++++++++++++++--- swift/proxy/server.py | 4 +- .../common/middleware/test_proxy_logging.py | 22 +++++++- test/unit/common/middleware/test_tempauth.py | 30 +++++++++- test/unit/common/test_utils.py | 53 +++++++++++++++++- test/unit/proxy/test_server.py | 28 +++++++--- 9 files changed, 177 insertions(+), 36 deletions(-) diff --git a/doc/source/admin/objectstorage-monitoring.rst b/doc/source/admin/objectstorage-monitoring.rst index cc3b31fa4e..86e81711b8 100644 --- a/doc/source/admin/objectstorage-monitoring.rst +++ b/doc/source/admin/objectstorage-monitoring.rst @@ -145,14 +145,6 @@ require accuracy (``sample_rate=1``) while others may not. Then the LogAdapter object returned by ``get_logger()``, usually stored in ``self.logger``, has these new methods: -- ``set_statsd_prefix(self, prefix)`` Sets the client library stat - prefix value which gets prefixed to every meter. The default prefix - is the ``name`` of the logger such as ``object-server``, - ``container-auditor``, and so on. This is currently used to turn - ``proxy-server`` into one of ``proxy-server.Account``, - ``proxy-server.Container``, or ``proxy-server.Object`` as soon as the - Controller object is determined and instantiated for the request. - - ``update_stats(self, metric, amount, sample_rate=1)`` Increments the supplied meter by the given amount. This is used when you need to add or subtract more that one from a counter, like incrementing diff --git a/swift/common/middleware/proxy_logging.py b/swift/common/middleware/proxy_logging.py index fc43ec7b30..74245a0a18 100644 --- a/swift/common/middleware/proxy_logging.py +++ b/swift/common/middleware/proxy_logging.py @@ -133,8 +133,8 @@ class ProxyLoggingMiddleware(object): access_log_conf[key] = value self.access_logger = logger or get_logger( access_log_conf, - log_route=conf.get('access_log_route', 'proxy-access')) - self.access_logger.set_statsd_prefix('proxy-server') + log_route=conf.get('access_log_route', 'proxy-access'), + statsd_tail_prefix='proxy-server') self.reveal_sensitive_prefix = int( conf.get('reveal_sensitive_prefix', 16)) self.check_log_msg_template_validity() diff --git a/swift/common/middleware/tempauth.py b/swift/common/middleware/tempauth.py index c7242faa55..151a754acd 100644 --- a/swift/common/middleware/tempauth.py +++ b/swift/common/middleware/tempauth.py @@ -209,13 +209,14 @@ class TempAuth(object): def __init__(self, app, conf): self.app = app self.conf = conf - self.logger = get_logger(conf, log_route='tempauth') - self.log_headers = config_true_value(conf.get('log_headers', 'f')) self.reseller_prefixes, self.account_rules = \ config_read_reseller_options(conf, dict(require_group='')) self.reseller_prefix = self.reseller_prefixes[0] - self.logger.set_statsd_prefix('tempauth.%s' % ( - self.reseller_prefix if self.reseller_prefix else 'NONE',)) + statsd_tail_prefix = 'tempauth.%s' % ( + self.reseller_prefix if self.reseller_prefix else 'NONE',) + self.logger = get_logger(conf, log_route='tempauth', + statsd_tail_prefix=statsd_tail_prefix) + self.log_headers = config_true_value(conf.get('log_headers', 'f')) self.auth_prefix = conf.get('auth_prefix', '/auth/') if not self.auth_prefix or not self.auth_prefix.strip('/'): self.logger.warning('Rewriting invalid auth prefix "%s" to ' diff --git a/swift/common/utils.py b/swift/common/utils.py index ad11b1091c..53c62548b4 100644 --- a/swift/common/utils.py +++ b/swift/common/utils.py @@ -1880,7 +1880,7 @@ class StatsdClient(object): self._host = host self._port = port self._base_prefix = base_prefix - self.set_prefix(tail_prefix) + self._set_prefix(tail_prefix) self._default_sample_rate = default_sample_rate self._sample_rate_factor = sample_rate_factor self.random = random @@ -1921,16 +1921,45 @@ class StatsdClient(object): else: self._target = (host, port) - def set_prefix(self, new_prefix): - if new_prefix and self._base_prefix: - self._prefix = '.'.join([self._base_prefix, new_prefix, '']) - elif new_prefix: - self._prefix = new_prefix + '.' + def _set_prefix(self, tail_prefix): + """ + Modifies the prefix that is added to metric names. The resulting prefix + is the concatenation of the component parts `base_prefix` and + `tail_prefix`. Only truthy components are included. Each included + component is followed by a period, e.g.:: + + .. + . + . + + + Note: this method is expected to be called from the constructor only, + but exists to provide backwards compatible functionality for the + deprecated set_prefix() method. + + :param tail_prefix: The new value of tail_prefix + """ + if tail_prefix and self._base_prefix: + self._prefix = '.'.join([self._base_prefix, tail_prefix, '']) + elif tail_prefix: + self._prefix = tail_prefix + '.' elif self._base_prefix: self._prefix = self._base_prefix + '.' else: self._prefix = '' + def set_prefix(self, tail_prefix): + """ + This method is deprecated; use the ``tail_prefix`` argument of the + constructor when instantiating the class instead. + """ + warnings.warn( + 'set_prefix() is deprecated; use the ``tail_prefix`` argument of ' + 'the constructor when instantiating the class instead.', + DeprecationWarning + ) + self._set_prefix(tail_prefix) + def _send(self, m_name, m_value, m_type, sample_rate): if sample_rate is None: sample_rate = self._default_sample_rate @@ -2015,7 +2044,7 @@ def timing_stats(**dec_kwargs): class SwiftLoggerAdapter(logging.LoggerAdapter): """ A logging.LoggerAdapter subclass that also passes through StatsD method - calls. Adds an optional metric_prefix to statsd metric names. + calls. Like logging.LoggerAdapter, you have to subclass this and override the process() method to accomplish anything useful. @@ -2229,6 +2258,10 @@ class LogAdapter(logging.LoggerAdapter, object): 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 @@ -2334,7 +2367,7 @@ class LogLevelFilter(object): def get_logger(conf, name=None, log_to_console=False, log_route=None, - fmt="%(server)s: %(message)s"): + fmt="%(server)s: %(message)s", statsd_tail_prefix=None): """ Get the current system logger using config settings. @@ -2365,6 +2398,8 @@ 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`` """ # note: log_name is typically specified in conf (i.e. defined by @@ -2443,8 +2478,10 @@ def get_logger(conf, name=None, log_to_console=False, log_route=None, 'log_statsd_default_sample_rate', 1)) sample_rate_factor = float(conf.get( 'log_statsd_sample_rate_factor', 1)) + if statsd_tail_prefix is None: + statsd_tail_prefix = name statsd_client = StatsdClient(statsd_host, statsd_port, base_prefix, - name, default_sample_rate, + statsd_tail_prefix, default_sample_rate, sample_rate_factor, logger=logger) logger.statsd_client = statsd_client else: diff --git a/swift/proxy/server.py b/swift/proxy/server.py index 4b8d1f2402..259450fea6 100644 --- a/swift/proxy/server.py +++ b/swift/proxy/server.py @@ -196,10 +196,10 @@ class Application(object): if conf is None: conf = {} if logger is None: - self.logger = get_logger(conf, log_route='proxy-server') + self.logger = get_logger(conf, log_route='proxy-server', + statsd_tail_prefix='proxy-server') else: self.logger = logger - self.logger.set_statsd_prefix('proxy-server') self._error_limiting = {} swift_dir = conf.get('swift_dir', '/etc/swift') diff --git a/test/unit/common/middleware/test_proxy_logging.py b/test/unit/common/middleware/test_proxy_logging.py index 7e444610c3..f1b9d32593 100644 --- a/test/unit/common/middleware/test_proxy_logging.py +++ b/test/unit/common/middleware/test_proxy_logging.py @@ -21,7 +21,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_logger, split_path, StatsdClient from swift.common.middleware import proxy_logging from swift.common.swob import Request, Response from swift.common import constraints @@ -149,6 +149,26 @@ class TestProxyLogging(unittest.TestCase): self.assertEqual(got_metrics_values_and_kwargs, exp_metrics_values_and_kwargs) + def test_logger_statsd_prefix(self): + app = proxy_logging.ProxyLoggingMiddleware( + FakeApp(), {'log_statsd_host': 'example.com'}) + self.assertIsNotNone(app.access_logger.logger.statsd_client) + self.assertIsInstance(app.access_logger.logger.statsd_client, + StatsdClient) + self.assertEqual('proxy-server.', + app.access_logger.logger.statsd_client._prefix) + + app = proxy_logging.ProxyLoggingMiddleware( + FakeApp(), {'log_statsd_metric_prefix': 'foo', # set base prefix + 'access_log_name': 'bar', # not used as tail prefix + 'log_name': 'baz', # not used as tail prefix + 'log_statsd_host': 'example.com'}) + self.assertIsNotNone(app.access_logger.logger.statsd_client) + self.assertIsInstance(app.access_logger.logger.statsd_client, + StatsdClient) + self.assertEqual('foo.proxy-server.', + app.access_logger.logger.statsd_client._prefix) + def test_log_request_statsd_invalid_stats_types(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) app.access_logger = debug_logger() diff --git a/test/unit/common/middleware/test_tempauth.py b/test/unit/common/middleware/test_tempauth.py index b7ec9e9a94..a9820de8e6 100644 --- a/test/unit/common/middleware/test_tempauth.py +++ b/test/unit/common/middleware/test_tempauth.py @@ -24,7 +24,7 @@ from six.moves.urllib.parse import quote, urlparse from swift.common.middleware import tempauth as auth from swift.common.middleware.acl import format_acl from swift.common.swob import Request, Response -from swift.common.utils import split_path +from swift.common.utils import split_path, StatsdClient from test.unit import FakeMemcache NO_CONTENT_RESP = (('204 No Content', {}, ''),) # mock server response @@ -97,6 +97,34 @@ class TestAuth(unittest.TestCase): req.environ['swift.cache'] = FakeMemcache() return req + def test_statsd_prefix(self): + app = FakeApp() + ath = auth.filter_factory({'log_statsd_host': 'example.com'})(app) + self.assertIsNotNone(ath.logger.logger.statsd_client) + self.assertIsInstance(ath.logger.logger.statsd_client, + StatsdClient) + self.assertEqual('tempauth.AUTH_.', + ath.logger.logger.statsd_client._prefix) + + ath = auth.filter_factory({'log_statsd_metric_prefix': 'foo', + 'log_name': 'bar', + 'log_statsd_host': 'example.com'})(app) + self.assertIsNotNone(ath.logger.logger.statsd_client) + self.assertIsInstance(ath.logger.logger.statsd_client, + StatsdClient) + self.assertEqual('foo.tempauth.AUTH_.', + ath.logger.logger.statsd_client._prefix) + + ath = auth.filter_factory({'log_statsd_metric_prefix': 'foo', + 'log_name': 'bar', + 'log_statsd_host': 'example.com', + 'reseller_prefix': 'TEST'})(app) + self.assertIsNotNone(ath.logger.logger.statsd_client) + self.assertIsInstance(ath.logger.logger.statsd_client, + StatsdClient) + self.assertEqual('foo.tempauth.TEST_.', + ath.logger.logger.statsd_client._prefix) + def test_reseller_prefix_init(self): app = FakeApp() ath = auth.filter_factory({})(app) diff --git a/test/unit/common/test_utils.py b/test/unit/common/test_utils.py index 2b4b616b70..2893c2bac8 100644 --- a/test/unit/common/test_utils.py +++ b/test/unit/common/test_utils.py @@ -5344,6 +5344,16 @@ class TestStatsdLogging(unittest.TestCase): self.assertEqual(logger.logger.statsd_client._prefix, 'some-name.') self.assertEqual(logger.logger.statsd_client._default_sample_rate, 1) + logger2 = utils.get_logger( + {'log_statsd_host': 'some.host.com'}, + 'other-name', log_route='some-route', + statsd_tail_prefix='some-name.more-specific') + self.assertEqual(logger.logger.statsd_client._prefix, + 'some-name.more-specific.') + self.assertEqual(logger2.logger.statsd_client._prefix, + 'some-name.more-specific.') + + # note: set_statsd_prefix is deprecated logger2 = utils.get_logger({'log_statsd_host': 'some.host.com'}, 'other-name', log_route='some-route') logger.set_statsd_prefix('some-name.more-specific') @@ -5356,15 +5366,23 @@ class TestStatsdLogging(unittest.TestCase): self.assertEqual(logger2.logger.statsd_client._prefix, '') def test_get_logger_statsd_client_non_defaults(self): - logger = utils.get_logger({ + conf = { 'log_statsd_host': 'another.host.com', 'log_statsd_port': '9876', 'log_statsd_default_sample_rate': '0.75', 'log_statsd_sample_rate_factor': '0.81', 'log_statsd_metric_prefix': 'tomato.sauce', - }, 'some-name', log_route='some-route') + } + logger = utils.get_logger(conf, 'some-name', log_route='some-route') self.assertEqual(logger.logger.statsd_client._prefix, 'tomato.sauce.some-name.') + + logger = utils.get_logger(conf, 'other-name', log_route='some-route', + statsd_tail_prefix='some-name.more-specific') + self.assertEqual(logger.logger.statsd_client._prefix, + 'tomato.sauce.some-name.more-specific.') + + # note: set_statsd_prefix is deprecated logger.set_statsd_prefix('some-name.more-specific') self.assertEqual(logger.logger.statsd_client._prefix, 'tomato.sauce.some-name.more-specific.') @@ -5377,6 +5395,37 @@ class TestStatsdLogging(unittest.TestCase): self.assertEqual(logger.logger.statsd_client._sample_rate_factor, 0.81) + def test_statsd_set_prefix_deprecation(self): + conf = {'log_statsd_host': 'another.host.com'} + + with warnings.catch_warnings(record=True) as cm: + warnings.resetwarnings() + warnings.simplefilter('always', DeprecationWarning) + logger = utils.get_logger( + conf, 'some-name', log_route='some-route') + logger.logger.statsd_client.set_prefix('some-name.more-specific') + msgs = [str(warning.message) + for warning in cm + if str(warning.message).startswith('set_prefix')] + self.assertEqual( + ['set_prefix() is deprecated; use the ``tail_prefix`` argument of ' + 'the constructor when instantiating the class instead.'], + msgs) + + with warnings.catch_warnings(record=True) as cm: + warnings.resetwarnings() + warnings.simplefilter('always', DeprecationWarning) + logger = utils.get_logger( + conf, 'some-name', log_route='some-route') + logger.set_statsd_prefix('some-name.more-specific') + msgs = [str(warning.message) + for warning in cm + if str(warning.message).startswith('set_prefix')] + self.assertEqual( + ['set_prefix() is deprecated; use the ``tail_prefix`` argument of ' + 'the constructor when instantiating the class instead.'], + msgs) + def test_ipv4_or_ipv6_hostname_defaults_to_ipv4(self): def stub_getaddrinfo_both_ipv4_and_ipv6(host, port, family, *rest): if family == socket.AF_INET: diff --git a/test/unit/proxy/test_server.py b/test/unit/proxy/test_server.py index c9a95886f5..4249c41c21 100644 --- a/test/unit/proxy/test_server.py +++ b/test/unit/proxy/test_server.py @@ -69,7 +69,7 @@ from swift.common.exceptions import ChunkReadTimeout, DiskFileNotExist, \ APIVersionError, ChunkReadError from swift.common import utils, constraints, registry from swift.common.utils import hash_path, storage_directory, \ - parse_content_type, parse_mime_headers, \ + parse_content_type, parse_mime_headers, StatsdClient, \ iter_multipart_mime_documents, public, mkdirs, NullLogger, md5 from swift.common.wsgi import loadapp, ConfigString, SwiftHttpProtocol from swift.proxy.controllers import base as proxy_base @@ -1336,11 +1336,25 @@ class TestProxyServer(unittest.TestCase): path_parts.get('disallowed_sections')) def test_statsd_prefix(self): - app = proxy_server.Application({}, logger=debug_logger(), + app = proxy_server.Application({'log_statsd_host': 'example.com'}, account_ring=FakeRing(), container_ring=FakeRing()) - self.assertEqual([(('proxy-server',), {})], - app.logger.log_dict['set_statsd_prefix']) + self.assertIsNotNone(app.logger.logger.statsd_client) + self.assertIsInstance(app.logger.logger.statsd_client, + StatsdClient) + self.assertEqual('proxy-server.', + app.logger.logger.statsd_client._prefix) + + app = proxy_server.Application({'log_statsd_metric_prefix': 'foo', + 'log_name': 'bar', + 'log_statsd_host': 'example.com'}, + account_ring=FakeRing(), + container_ring=FakeRing()) + self.assertIsNotNone(app.logger.logger.statsd_client) + self.assertIsInstance(app.logger.logger.statsd_client, + StatsdClient) + self.assertEqual('foo.proxy-server.', + app.logger.logger.statsd_client._prefix) @patch_policies([ @@ -2147,7 +2161,7 @@ class TestProxyServerConfigLoading(unittest.TestCase): self.assertEqual('proxy-server', app.logger.name) self.assertEqual('swift', app.logger.server) mock_statsd.assert_called_once_with( - 'example.com', 8125, '', 'swift', 1.0, 1.0, + 'example.com', 8125, '', 'proxy-server', 1.0, 1.0, logger=app.logger.logger) conf_sections = """ @@ -2170,9 +2184,9 @@ class TestProxyServerConfigLoading(unittest.TestCase): self.assertEqual('proxy-server', app.logger.name) # server is defined by log_name option self.assertEqual('test-name', app.logger.server) - # statsd prefix is defined by log_name option + # statsd tail prefix is hard-wired 'proxy-server' mock_statsd.assert_called_once_with( - 'example.com', 8125, '', 'test-name', 1.0, 1.0, + 'example.com', 8125, '', 'proxy-server', 1.0, 1.0, logger=app.logger.logger)