Reload log_config_append config on SIGHUP
On SIGHUP the mutate_hook will be called. Call fileConfig to reconfigure logging if log-config-append changes or the timestamp of the file it points to changes. Implements: bp mutable-logging Change-Id: I8ca8e6b4e9218f3a2edaf9ecf53653d829bc0c12
This commit is contained in:
Alexis Lee
parent
fc490c03b7
commit
8fde280b86
@ -49,6 +49,7 @@ logging_cli_opts = [
|
||||
cfg.StrOpt('log-config-append',
|
||||
metavar='PATH',
|
||||
deprecated_name='log-config',
|
||||
mutable=True,
|
||||
help='The name of a logging configuration file. This file '
|
||||
'is appended to any existing logging configuration '
|
||||
'files. For details about logging configuration files, '
|
||||
|
||||
@ -212,9 +212,20 @@ class LogConfigError(Exception):
|
||||
|
||||
def _load_log_config(log_config_append):
|
||||
try:
|
||||
logging.config.fileConfig(log_config_append,
|
||||
disable_existing_loggers=False)
|
||||
except (moves.configparser.Error, KeyError) as exc:
|
||||
if not hasattr(_load_log_config, "old_time"):
|
||||
_load_log_config.old_time = 0
|
||||
new_time = os.path.getmtime(log_config_append)
|
||||
if _load_log_config.old_time != new_time:
|
||||
# Reset all existing loggers before reloading config as fileConfig
|
||||
# does not reset non-child loggers.
|
||||
for logger in _iter_loggers():
|
||||
logger.level = logging.NOTSET
|
||||
logger.handlers = []
|
||||
logger.propagate = 1
|
||||
logging.config.fileConfig(log_config_append,
|
||||
disable_existing_loggers=False)
|
||||
_load_log_config.old_time = new_time
|
||||
except (moves.configparser.Error, KeyError, os.error) as exc:
|
||||
raise LogConfigError(log_config_append, six.text_type(exc))
|
||||
|
||||
|
||||
@ -226,6 +237,11 @@ def _mutate_hook(conf, fresh):
|
||||
if (None, 'debug') in fresh:
|
||||
_refresh_root_level(conf.debug, conf.verbose)
|
||||
|
||||
if (None, 'log-config-append') in fresh:
|
||||
_load_log_config.old_time = 0
|
||||
if conf.log_config_append:
|
||||
_load_log_config(conf.log_config_append)
|
||||
|
||||
|
||||
def register_options(conf):
|
||||
"""Register the command line and configuration options used by oslo.log."""
|
||||
|
||||
@ -16,6 +16,7 @@
|
||||
# License for the specific language governing permissions and limitations
|
||||
# under the License.
|
||||
|
||||
from contextlib import contextmanager
|
||||
import copy
|
||||
import datetime
|
||||
import logging
|
||||
@ -48,6 +49,20 @@ from oslo_log import handlers
|
||||
from oslo_log import log
|
||||
|
||||
|
||||
MIN_LOG_INI = b"""[loggers]
|
||||
keys=root
|
||||
|
||||
[formatters]
|
||||
keys=
|
||||
|
||||
[handlers]
|
||||
keys=
|
||||
|
||||
[logger_root]
|
||||
handlers=
|
||||
"""
|
||||
|
||||
|
||||
def _fake_context():
|
||||
ctxt = context.RequestContext(1, 1, overwrite=True)
|
||||
ctxt.user = 'myuser'
|
||||
@ -967,32 +982,254 @@ class FastWatchedFileHandlerTestCase(BaseTestCase):
|
||||
self.assertTrue(os.path.exists(log_path))
|
||||
|
||||
|
||||
class ConfigTestCase(test_base.BaseTestCase):
|
||||
def test_mutate(self):
|
||||
conf = cfg.CONF
|
||||
old_config = ("[DEFAULT]\n"
|
||||
"debug = false\n")
|
||||
new_config = ("[DEFAULT]\n"
|
||||
"debug = true\n")
|
||||
paths = self.create_tempfiles([('old', old_config),
|
||||
('new', new_config)])
|
||||
log.register_options(conf)
|
||||
conf(['--config-file', paths[0]])
|
||||
class MutateTestCase(BaseTestCase):
|
||||
def setup_confs(self, *confs):
|
||||
paths = self.create_tempfiles(
|
||||
('conf_%d' % i, conf) for i, conf in enumerate(confs))
|
||||
self.CONF(['--config-file', paths[0]])
|
||||
return paths
|
||||
|
||||
def test_debug(self):
|
||||
paths = self.setup_confs(
|
||||
"[DEFAULT]\ndebug = false\n",
|
||||
"[DEFAULT]\ndebug = true\n")
|
||||
log_root = log.getLogger(None).logger
|
||||
|
||||
log._setup_logging_from_conf(conf, 'test', 'test')
|
||||
self.assertEqual(conf.debug, False)
|
||||
|
||||
self.assertEqual(conf.verbose, True)
|
||||
log._setup_logging_from_conf(self.CONF, 'test', 'test')
|
||||
self.assertEqual(self.CONF.debug, False)
|
||||
self.assertEqual(self.CONF.verbose, True)
|
||||
self.assertEqual(log.INFO, log_root.getEffectiveLevel())
|
||||
|
||||
shutil.copy(paths[1], paths[0])
|
||||
conf.mutate_config_files()
|
||||
self.CONF.mutate_config_files()
|
||||
|
||||
self.assertEqual(conf.debug, True)
|
||||
self.assertEqual(conf.verbose, True)
|
||||
self.assertEqual(self.CONF.debug, True)
|
||||
self.assertEqual(self.CONF.verbose, True)
|
||||
self.assertEqual(log.DEBUG, log_root.getEffectiveLevel())
|
||||
|
||||
@mock.patch.object(logging.config, "fileConfig")
|
||||
def test_log_config_append(self, mock_fileConfig):
|
||||
logini = self.create_tempfiles([('log.ini', MIN_LOG_INI)])[0]
|
||||
paths = self.setup_confs(
|
||||
"[DEFAULT]\nlog_config_append = no_exist\n",
|
||||
"[DEFAULT]\nlog_config_append = %s\n" % logini)
|
||||
self.assertRaises(log.LogConfigError, log.setup, self.CONF, '')
|
||||
self.assertFalse(mock_fileConfig.called)
|
||||
|
||||
shutil.copy(paths[1], paths[0])
|
||||
self.CONF.mutate_config_files()
|
||||
|
||||
mock_fileConfig.assert_called_once_with(
|
||||
logini, disable_existing_loggers=False)
|
||||
|
||||
@mock.patch.object(logging.config, "fileConfig")
|
||||
def test_log_config_append_no_touch(self, mock_fileConfig):
|
||||
logini = self.create_tempfiles([('log.ini', MIN_LOG_INI)])[0]
|
||||
self.setup_confs("[DEFAULT]\nlog_config_append = %s\n" % logini)
|
||||
log.setup(self.CONF, '')
|
||||
mock_fileConfig.assert_called_once_with(
|
||||
logini, disable_existing_loggers=False)
|
||||
mock_fileConfig.reset_mock()
|
||||
|
||||
self.CONF.mutate_config_files()
|
||||
|
||||
self.assertFalse(mock_fileConfig.called)
|
||||
|
||||
@mock.patch.object(logging.config, "fileConfig")
|
||||
def test_log_config_append_touch(self, mock_fileConfig):
|
||||
logini = self.create_tempfiles([('log.ini', MIN_LOG_INI)])[0]
|
||||
self.setup_confs("[DEFAULT]\nlog_config_append = %s\n" % logini)
|
||||
log.setup(self.CONF, '')
|
||||
mock_fileConfig.assert_called_once_with(
|
||||
logini, disable_existing_loggers=False)
|
||||
mock_fileConfig.reset_mock()
|
||||
|
||||
# No thread sync going on here, just ensure the mtimes are different
|
||||
time.sleep(0.1)
|
||||
os.utime(logini, None)
|
||||
self.CONF.mutate_config_files()
|
||||
|
||||
mock_fileConfig.assert_called_once_with(
|
||||
logini, disable_existing_loggers=False)
|
||||
|
||||
def mk_log_config(self, data):
|
||||
"""Turns a dictConfig-like structure into one suitable for fileConfig.
|
||||
|
||||
The schema is not validated as this is a test helper not production
|
||||
code. Garbage in, garbage out. Particularly, don't try to use filters,
|
||||
fileConfig doesn't support them.
|
||||
|
||||
Handler args must be passed like 'args': (1, 2). dictConfig passes
|
||||
keys by keyword name and fileConfig passes them by position so
|
||||
accepting the dictConfig form makes it nigh impossible to produce the
|
||||
fileConfig form.
|
||||
|
||||
I traverse dicts by sorted keys for output stability but it doesn't
|
||||
matter if defaulted keys are out of order.
|
||||
"""
|
||||
lines = []
|
||||
for section in ['formatters', 'handlers', 'loggers']:
|
||||
items = data.get(section, {})
|
||||
keys = sorted(items)
|
||||
skeys = ",".join(keys)
|
||||
if section == 'loggers' and 'root' in data:
|
||||
skeys = ("root," + skeys) if skeys else "root"
|
||||
lines.extend(["[%s]" % section,
|
||||
"keys=%s" % skeys])
|
||||
for key in keys:
|
||||
lines.extend(["",
|
||||
"[%s_%s]" % (section[:-1], key)])
|
||||
item = items[key]
|
||||
lines.extend("%s=%s" % (k, item[k]) for k in sorted(item))
|
||||
if section == 'handlers':
|
||||
if 'args' not in item:
|
||||
lines.append("args=()")
|
||||
elif section == 'loggers':
|
||||
lines.append("qualname=%s" % key)
|
||||
if 'handlers' not in item:
|
||||
lines.append("handlers=")
|
||||
lines.append("")
|
||||
root = data.get('root', {})
|
||||
if root:
|
||||
lines.extend(["[logger_root]"])
|
||||
lines.extend("%s=%s" % (k, root[k]) for k in sorted(root))
|
||||
if 'handlers' not in root:
|
||||
lines.append("handlers=")
|
||||
return "\n".join(lines)
|
||||
|
||||
def test_mk_log_config_full(self):
|
||||
data = {'loggers': {'aaa': {'level': 'INFO'},
|
||||
'bbb': {'level': 'WARN',
|
||||
'propagate': False}},
|
||||
'handlers': {'aaa': {'level': 'INFO'},
|
||||
'bbb': {'level': 'WARN',
|
||||
'propagate': False,
|
||||
'args': (1, 2)}},
|
||||
'formatters': {'aaa': {'level': 'INFO'},
|
||||
'bbb': {'level': 'WARN',
|
||||
'propagate': False}},
|
||||
'root': {'level': 'INFO',
|
||||
'handlers': 'aaa'},
|
||||
}
|
||||
full = """[formatters]
|
||||
keys=aaa,bbb
|
||||
|
||||
[formatter_aaa]
|
||||
level=INFO
|
||||
|
||||
[formatter_bbb]
|
||||
level=WARN
|
||||
propagate=False
|
||||
|
||||
[handlers]
|
||||
keys=aaa,bbb
|
||||
|
||||
[handler_aaa]
|
||||
level=INFO
|
||||
args=()
|
||||
|
||||
[handler_bbb]
|
||||
args=(1, 2)
|
||||
level=WARN
|
||||
propagate=False
|
||||
|
||||
[loggers]
|
||||
keys=root,aaa,bbb
|
||||
|
||||
[logger_aaa]
|
||||
level=INFO
|
||||
qualname=aaa
|
||||
handlers=
|
||||
|
||||
[logger_bbb]
|
||||
level=WARN
|
||||
propagate=False
|
||||
qualname=bbb
|
||||
handlers=
|
||||
|
||||
[logger_root]
|
||||
handlers=aaa
|
||||
level=INFO"""
|
||||
self.assertEqual(full, self.mk_log_config(data))
|
||||
|
||||
def test_mk_log_config_empty(self):
|
||||
"""Ensure mk_log_config tolerates missing bits"""
|
||||
empty = """[formatters]
|
||||
keys=
|
||||
|
||||
[handlers]
|
||||
keys=
|
||||
|
||||
[loggers]
|
||||
keys=
|
||||
"""
|
||||
self.assertEqual(empty, self.mk_log_config({}))
|
||||
|
||||
@contextmanager
|
||||
def mutate_conf(self, conf1, conf2):
|
||||
loginis = self.create_tempfiles([
|
||||
('log1.ini', self.mk_log_config(conf1)),
|
||||
('log2.ini', self.mk_log_config(conf2))])
|
||||
confs = self.setup_confs(
|
||||
"[DEFAULT]\nlog_config_append = %s\n" % loginis[0],
|
||||
"[DEFAULT]\nlog_config_append = %s\n" % loginis[1])
|
||||
log.setup(self.CONF, '')
|
||||
|
||||
yield loginis, confs
|
||||
shutil.copy(confs[1], confs[0])
|
||||
self.CONF.mutate_config_files()
|
||||
|
||||
@mock.patch.object(logging.config, "fileConfig")
|
||||
def test_log_config_append_change_file(self, mock_fileConfig):
|
||||
with self.mutate_conf({}, {}) as (loginis, confs):
|
||||
mock_fileConfig.assert_called_once_with(
|
||||
loginis[0], disable_existing_loggers=False)
|
||||
mock_fileConfig.reset_mock()
|
||||
|
||||
mock_fileConfig.assert_called_once_with(
|
||||
loginis[1], disable_existing_loggers=False)
|
||||
|
||||
def set_root_stream(self):
|
||||
root = logging.getLogger()
|
||||
self.assertEqual(1, len(root.handlers))
|
||||
handler = root.handlers[0]
|
||||
handler.stream = six.StringIO()
|
||||
return handler.stream
|
||||
|
||||
def test_remove_handler(self):
|
||||
fake_handler = {'class': 'logging.StreamHandler',
|
||||
'args': ()}
|
||||
conf1 = {'root': {'handlers': 'fake'},
|
||||
'handlers': {'fake': fake_handler}}
|
||||
conf2 = {'root': {'handlers': ''}}
|
||||
with self.mutate_conf(conf1, conf2) as (loginis, confs):
|
||||
stream = self.set_root_stream()
|
||||
root = logging.getLogger()
|
||||
root.error("boo")
|
||||
self.assertEqual("boo\n", stream.getvalue())
|
||||
stream.truncate(0)
|
||||
root.error("boo")
|
||||
self.assertEqual("", stream.getvalue())
|
||||
|
||||
def test_remove_logger(self):
|
||||
fake_handler = {'class': 'logging.StreamHandler'}
|
||||
fake_logger = {'level': 'WARN'}
|
||||
conf1 = {'root': {'handlers': 'fake'},
|
||||
'handlers': {'fake': fake_handler},
|
||||
'loggers': {'a.a': fake_logger}}
|
||||
conf2 = {'root': {'handlers': 'fake'},
|
||||
'handlers': {'fake': fake_handler}}
|
||||
stream = six.StringIO()
|
||||
with self.mutate_conf(conf1, conf2) as (loginis, confs):
|
||||
stream = self.set_root_stream()
|
||||
log = logging.getLogger("a.a")
|
||||
log.info("info")
|
||||
log.warn("warn")
|
||||
self.assertEqual("warn\n", stream.getvalue())
|
||||
stream = self.set_root_stream()
|
||||
log.info("info")
|
||||
log.warn("warn")
|
||||
self.assertEqual("info\nwarn\n", stream.getvalue())
|
||||
|
||||
|
||||
class LogConfigOptsTestCase(BaseTestCase):
|
||||
|
||||
@ -1103,22 +1340,9 @@ class LogConfigOptsTestCase(BaseTestCase):
|
||||
|
||||
class LogConfigTestCase(BaseTestCase):
|
||||
|
||||
minimal_config = b"""[loggers]
|
||||
keys=root
|
||||
|
||||
[formatters]
|
||||
keys=
|
||||
|
||||
[handlers]
|
||||
keys=
|
||||
|
||||
[logger_root]
|
||||
handlers=
|
||||
"""
|
||||
|
||||
def setUp(self):
|
||||
super(LogConfigTestCase, self).setUp()
|
||||
names = self.create_tempfiles([('logging', self.minimal_config)])
|
||||
names = self.create_tempfiles([('logging', MIN_LOG_INI)])
|
||||
self.log_config_append = names[0]
|
||||
|
||||
def test_log_config_append_ok(self):
|
||||
@ -1133,7 +1357,7 @@ handlers=
|
||||
'test_log_config_append')
|
||||
|
||||
def test_log_config_append_invalid(self):
|
||||
names = self.create_tempfiles([('logging', self.minimal_config[5:])])
|
||||
names = self.create_tempfiles([('logging', MIN_LOG_INI[5:])])
|
||||
self.log_config_append = names[0]
|
||||
self.config(log_config_append=self.log_config_append)
|
||||
self.assertRaises(log.LogConfigError, log.setup,
|
||||
|
||||
@ -0,0 +1,5 @@
|
||||
---
|
||||
features:
|
||||
- The log_config_append configuration option is now mutable and the logging
|
||||
settings it controls are reconfigured when the configuration file is reread.
|
||||
This can be used to, for example, change logger or handler levels.
|
||||
Loading…
Reference in New Issue
Block a user