Bug 1044751 - Add command line options for configuring log level of formatters in mozlog.structured.;r=jgraham

This commit is contained in:
Chris Manchester 2014-08-05 22:54:12 -04:00
parent c312284088
commit 1118dd9934
3 changed files with 139 additions and 22 deletions

View File

@ -5,6 +5,7 @@
import sys
import optparse
from collections import defaultdict
from structuredlog import StructuredLogger, set_default_logger
import handlers
import formatters
@ -18,6 +19,16 @@ log_formatters = {
'tbpl': (formatters.TbplFormatter, "TBPL style log format"),
}
def level_filter_wrapper(formatter, level):
return handlers.LogLevelFilter(formatter, level)
fmt_options = {
# <option name>: (<wrapper function>, description, <applicable formatters>)
'level': (level_filter_wrapper,
"A least log level to subscribe to for the given formatter (debug, info, error, etc.)",
["mach", "tbpl"]),
}
def log_file(name):
if name == "-":
@ -50,7 +61,10 @@ def add_logging_group(parser):
for name, (cls, help_str) in log_formatters.iteritems():
group.add_option("--log-" + name, action="append", type="str",
help=help_str)
for optname, (cls, help_str, formatters) in fmt_options.iteritems():
for fmt in formatters:
group.add_option("--log-%s-%s" % (fmt, optname), action="store",
type="str", help=help_str)
parser.add_option_group(group)
else:
group = parser.add_argument_group(group_name,
@ -59,6 +73,38 @@ def add_logging_group(parser):
group.add_argument("--log-" + name, action="append", type=log_file,
help=help_str)
for optname, (cls, help_str, formatters) in fmt_options.iteritems():
for fmt in formatters:
group.add_argument("--log-%s-%s" % (fmt, optname), action="store",
type=str, help=help_str)
def setup_handlers(logger, formatters, formatter_options):
"""
Add handlers to the given logger according to the formatters and
options provided.
:param logger: The logger configured by this function.
:param formatters: A dict of {formatter, [streams]} to use in handlers.
:param formatter_options: a dict of {formatter: {option: value}} to
to use when configuring formatters.
"""
unused_options = set(formatter_options.keys()) - set(formatters.keys())
if unused_options:
msg = ("Options specified for unused formatter(s) (%s) have no effect" %
list(unused_options))
raise ValueError(msg)
for fmt, streams in formatters.iteritems():
formatter_cls = log_formatters[fmt][0]
formatter = formatter_cls()
for option, value in formatter_options[fmt].iteritems():
formatter = fmt_options[option][0](formatter, value)
for value in streams:
logger.add_handler(handlers.StreamHandler(stream=value,
formatter=formatter))
def setup_logging(suite, args, defaults=None):
"""
@ -78,8 +124,16 @@ def setup_logging(suite, args, defaults=None):
:rtype: StructuredLogger
"""
_option_defaults = {
'level': 'info',
}
logger = StructuredLogger(suite)
prefix = "log_"
# Keep track of any options passed for formatters.
formatter_options = defaultdict(lambda: _option_defaults.copy())
# Keep track of formatters and list of streams specified.
formatters = {}
found = False
found_stdout_logger = False
if not hasattr(args, 'iteritems'):
@ -92,31 +146,38 @@ def setup_logging(suite, args, defaults=None):
defaults = {"raw": sys.stdout}
for name, values in args.iteritems():
if name.startswith(prefix) and values is not None:
for value in values:
found = True
if isinstance(value, str):
value = log_file(value)
if value == sys.stdout:
found_stdout_logger = True
formatter_cls = log_formatters[name[len(prefix):]][0]
logger.add_handler(handlers.StreamHandler(stream=value,
formatter=formatter_cls()))
parts = name.split('_')
if len(parts) > 3:
continue
# Our args will be ['log', <formatter>] or ['log', <formatter>, <option>].
if parts[0] == 'log' and values is not None:
if len(parts) == 1 or parts[1] not in log_formatters:
continue
if len(parts) == 2:
_, formatter = parts
formatters[formatter] = []
for value in values:
found = True
if isinstance(value, str):
value = log_file(value)
if value == sys.stdout:
found_stdout_logger = True
formatters[formatter].append(value)
if len(parts) == 3:
_, formatter, opt = parts
formatter_options[formatter][opt] = values
#If there is no user-specified logging, go with the default options
if not found:
for name, value in defaults.iteritems():
formatter_cls = log_formatters[name][0]
logger.add_handler(handlers.StreamHandler(stream=value,
formatter=formatter_cls()))
formatters[name] = [value]
elif not found_stdout_logger and sys.stdout in defaults.values():
for name, value in defaults.iteritems():
if value == sys.stdout:
formatter_cls = log_formatters[name][0]
logger.add_handler(handlers.StreamHandler(stream=value,
formatter=formatter_cls()))
formatters[name] = [value]
setup_handlers(logger, formatters, formatter_options)
set_default_logger(logger)
return logger

View File

@ -36,7 +36,7 @@ class LogLevelFilter(object):
def __call__(self, item):
if (item["action"] != "log" or
log_levels[item["level"]] <= self.level):
log_levels[item["level"].upper()] <= self.level):
return self.inner(item)

View File

@ -358,9 +358,9 @@ class TestTypeconversions(BaseStructuredTest):
self.logger.add_handler(_handler)
self.logger.suite_start([])
self.logger.info("")
with open(logfile.name) as f:
data = f.readlines()
self.assertEquals(data[-1], "\n")
logfile.seek(0)
data = logfile.readlines()[-1].strip()
self.assertEquals(data, "")
self.logger.suite_end()
def test_arguments(self):
@ -393,6 +393,15 @@ class TestTypeconversions(BaseStructuredTest):
self.logger.suite_end()
class TestCommandline(unittest.TestCase):
def setUp(self):
self.logfile = mozfile.NamedTemporaryFile()
@property
def loglines(self):
self.logfile.seek(0)
return [line.strip() for line in self.logfile.readlines()]
def test_setup_logging(self):
parser = argparse.ArgumentParser()
commandline.add_logging_group(parser)
@ -408,6 +417,53 @@ class TestCommandline(unittest.TestCase):
self.assertEqual(len(logger.handlers), 1)
self.assertIsInstance(logger.handlers[0], handlers.StreamHandler)
def test_logging_defaultlevel(self):
parser = argparse.ArgumentParser()
commandline.add_logging_group(parser)
args = parser.parse_args(["--log-tbpl=%s" % self.logfile.name])
logger = commandline.setup_logging("test_fmtopts", args, {})
logger.info("INFO message")
logger.debug("DEBUG message")
logger.error("ERROR message")
# The debug level is not logged by default.
self.assertEqual(["INFO message",
"ERROR message"],
self.loglines)
def test_logging_errorlevel(self):
parser = argparse.ArgumentParser()
commandline.add_logging_group(parser)
args = parser.parse_args(["--log-tbpl=%s" % self.logfile.name, "--log-tbpl-level=error"])
logger = commandline.setup_logging("test_fmtopts", args, {})
logger.info("INFO message")
logger.debug("DEBUG message")
logger.error("ERROR message")
# Only the error level and above were requested.
self.assertEqual(["ERROR message"],
self.loglines)
def test_logging_debuglevel(self):
parser = argparse.ArgumentParser()
commandline.add_logging_group(parser)
args = parser.parse_args(["--log-tbpl=%s" % self.logfile.name, "--log-tbpl-level=debug"])
logger = commandline.setup_logging("test_fmtopts", args, {})
logger.info("INFO message")
logger.debug("DEBUG message")
logger.error("ERROR message")
# Requesting a lower log level than default works as expected.
self.assertEqual(["INFO message",
"DEBUG message",
"ERROR message"],
self.loglines)
def test_unused_options(self):
parser = argparse.ArgumentParser()
commandline.add_logging_group(parser)
args = parser.parse_args(["--log-tbpl-level=error"])
self.assertRaises(ValueError, commandline.setup_logging, "test_fmtopts", args, {})
class TestReader(unittest.TestCase):
def to_file_like(self, obj):
data_str = "\n".join(json.dumps(item) for item in obj)