From 9526da9ec94da3b581bcc7a1bfdbd9a81f568635 Mon Sep 17 00:00:00 2001 From: James Graham Date: Fri, 21 Nov 2014 11:43:54 +0000 Subject: [PATCH] Bug 1098404 - Implement per-component filters for mozlog, r=chmanchester This allows individual component loggers to e.g. discard all messages below a set level, or rewrite messages from one level to another. --HG-- extra : rebase_source : 9b37981368edb099ac555a2dacfafd486f8fcd2d extra : histedit_source : 144d17f582944703b07529e31bf13b845d5f9695%2C706e2b7db06a1217d0e956614f0232c153a6a3d0 --- .../mozlog/mozlog/structured/structuredlog.py | 25 +++++- .../mozbase/mozlog/tests/test_structured.py | 82 ++++++++++++++++++- 2 files changed, 103 insertions(+), 4 deletions(-) diff --git a/testing/mozbase/mozlog/mozlog/structured/structuredlog.py b/testing/mozbase/mozlog/mozlog/structured/structuredlog.py index b45ade0732f5..ac84f18af2e1 100644 --- a/testing/mozbase/mozlog/mozlog/structured/structuredlog.py +++ b/testing/mozbase/mozlog/mozlog/structured/structuredlog.py @@ -101,7 +101,11 @@ class LoggerState(object): self.handlers = [] self.running_tests = set() self.suite_started = False + self.component_states = {} +class ComponentState(object): + def __init__(self): + self.filter_ = None class StructuredLogger(object): _lock = Lock() @@ -120,9 +124,11 @@ class StructuredLogger(object): if name not in self._logger_states: self._logger_states[name] = LoggerState() - @property - def _state(self): - return self._logger_states[self.name] + if component not in self._logger_states[name].component_states: + self._logger_states[name].component_states[component] = ComponentState() + + self._state = self._logger_states[name] + self._component_state = self._state.component_states[component] def add_handler(self, handler): """Add a handler to the current logger""" @@ -141,6 +147,14 @@ class StructuredLogger(object): message is logged from this logger""" return self._state.handlers + @property + def component_filter(self): + return self._component_state.filter_ + + @component_filter.setter + def component_filter(self, value): + self._component_state.filter_ = value + def log_raw(self, raw_data): if "action" not in raw_data: raise ValueError @@ -170,6 +184,11 @@ class StructuredLogger(object): def _handle_log(self, data): with self._lock: + if self.component_filter: + data = self.component_filter(data) + if data is None: + return + for handler in self.handlers: handler(data) diff --git a/testing/mozbase/mozlog/tests/test_structured.py b/testing/mozbase/mozlog/tests/test_structured.py index 27f9aeb50324..fe9a88d6fbaf 100644 --- a/testing/mozbase/mozlog/tests/test_structured.py +++ b/testing/mozbase/mozlog/tests/test_structured.py @@ -30,6 +30,10 @@ class TestHandler(object): def last_item(self): return self.items[-1] + @property + def empty(self): + return not self.items + class BaseStructuredTest(unittest.TestCase): def setUp(self): @@ -365,7 +369,7 @@ class TestStructuredLog(BaseStructuredTest): "message": "line 4"}) -class TestTypeconversions(BaseStructuredTest): +class TestTypeConversions(BaseStructuredTest): def test_raw(self): self.logger.log_raw({"action":"suite_start", "tests":[1], "time": "1234"}) self.assert_log_equals({"action": "suite_start", @@ -434,6 +438,82 @@ class TestTypeconversions(BaseStructuredTest): self.logger.suite_end() +class TestComponentFilter(BaseStructuredTest): + def test_filter_component(self): + component_logger = structuredlog.StructuredLogger(self.logger.name, + "test_component") + component_logger.component_filter = handlers.LogLevelFilter(lambda x:x, "info") + + self.logger.debug("Test") + self.assertFalse(self.handler.empty) + self.assert_log_equals({"action": "log", + "level": "DEBUG", + "message": "Test"}) + self.assertTrue(self.handler.empty) + + component_logger.info("Test 1") + self.assertFalse(self.handler.empty) + self.assert_log_equals({"action": "log", + "level": "INFO", + "message": "Test 1", + "component": "test_component"}) + + component_logger.debug("Test 2") + self.assertTrue(self.handler.empty) + + component_logger.component_filter = None + + component_logger.debug("Test 3") + self.assertFalse(self.handler.empty) + self.assert_log_equals({"action": "log", + "level": "DEBUG", + "message": "Test 3", + "component": "test_component"}) + + def test_filter_default_component(self): + component_logger = structuredlog.StructuredLogger(self.logger.name, + "test_component") + + self.logger.debug("Test") + self.assertFalse(self.handler.empty) + self.assert_log_equals({"action": "log", + "level": "DEBUG", + "message": "Test"}) + + self.logger.component_filter = handlers.LogLevelFilter(lambda x:x, "info") + + self.logger.debug("Test 1") + self.assertTrue(self.handler.empty) + + component_logger.debug("Test 2") + self.assertFalse(self.handler.empty) + self.assert_log_equals({"action": "log", + "level": "DEBUG", + "message": "Test 2", + "component": "test_component"}) + + self.logger.component_filter = None + + self.logger.debug("Test 3") + self.assertFalse(self.handler.empty) + self.assert_log_equals({"action": "log", + "level": "DEBUG", + "message": "Test 3"}) + + def test_filter_message_mutuate(self): + def filter_mutate(msg): + if msg["action"] == "log": + msg["message"] = "FILTERED! %s" % msg["message"] + return msg + + self.logger.component_filter = filter_mutate + self.logger.debug("Test") + self.assert_log_equals({"action": "log", + "level": "DEBUG", + "message": "FILTERED! Test"}) + self.logger.component_filter = None + + class FormatterTest(unittest.TestCase): def setUp(self):