Monkey patch the logging module to make debugging poorly written
logging statements easier.
Signed-off-by: Gregory Smith <gps@google.com>
git-svn-id: http://test.kernel.org/svn/autotest/trunk@3066 592f7852-d20e-0410-864c-8624ca9c26a4
diff --git a/client/setup_modules.py b/client/setup_modules.py
index dcad6a8..76cacea 100644
--- a/client/setup_modules.py
+++ b/client/setup_modules.py
@@ -1,6 +1,6 @@
__author__ = "jadmanski@google.com (John Admanski)"
-import os, sys, new, glob
+import os, sys, new, glob, logging, traceback
def _create_module(name):
@@ -61,6 +61,17 @@
return getattr(from_module, module)
+def _autotest_logging_handle_error(self, record):
+ """Method to monkey patch into logging.Handler to replace handleError."""
+ # The same as the default logging.Handler.handleError but also prints
+ # out the original record causing the error so there is -some- idea
+ # about which call caused the logging error.
+ if logging.raiseExceptions:
+ sys.stderr.write('Exception occurred formatting message: '
+ '%r using args %r\n' % (record.msg, record.args))
+ traceback.print_stack()
+
+
def setup(base_path, root_module_name=""):
"""
Perform all the necessary setup so that all the packages at
@@ -80,6 +91,13 @@
if glob.glob(logging_py):
os.system("rm -f %s" % logging_py)
+ # Monkey patch our own handleError into the logging module's StreamHandler.
+ # A nicer way of doing this -might- be to have our own logging module define
+ # an autotest Logger instance that added our own Handler subclass with this
+ # handleError method in it. But that would mean modifying tons of code.
+ assert callable(logging.Handler.handleError)
+ logging.Handler.handleError = _autotest_logging_handle_error
+
# Hack... Any better ideas?
if (root_module_name == 'autotest_lib.client' and
os.path.exists(os.path.join(os.path.dirname(__file__),
diff --git a/client/setup_modules_unittest.py b/client/setup_modules_unittest.py
new file mode 100644
index 0000000..571f449
--- /dev/null
+++ b/client/setup_modules_unittest.py
@@ -0,0 +1,72 @@
+#!/usr/bin/python2.4
+
+import cStringIO, logging, os, sys, unittest
+
+# direct imports; autotest_lib has not been setup while testing this.
+from common_lib.test_utils import mock
+import setup_modules
+
+
+class LoggingErrorStderrTests(unittest.TestCase):
+ def setUp(self):
+ autotest_dir = os.path.abspath(os.path.join(setup_modules.dirname,
+ '..'))
+ setup_modules.setup(autotest_dir, root_module_name='autotest_lib')
+ self.god = mock.mock_god()
+ self.test_stderr = cStringIO.StringIO()
+ self.god.stub_with(sys, 'stderr', self.test_stderr)
+ self.old_root_logging_level = logging.root.level
+ logging.basicConfig(level=logging.ERROR)
+
+
+ def tearDown(self):
+ self.god.unstub_all()
+ # Undo the setUp logging.basicConfig call.
+ logging.basicConfig(level=self.old_root_logging_level)
+
+
+ def assert_autotest_logging_handle_error_called(self):
+ self.stderr_str = self.test_stderr.getvalue()
+ self.assertTrue('Exception occurred formatting' in self.stderr_str,
+ repr(self.stderr_str))
+
+
+ def test_autotest_logging_handle_error(self):
+ record = logging.LogRecord(
+ 'test', logging.DEBUG, __file__, 0, 'MESSAGE', 'ARGS', None)
+ try:
+ raise RuntimeError('Exception context needed for the test.')
+ except RuntimeError:
+ setup_modules._autotest_logging_handle_error(logging.Handler(),
+ record)
+ else:
+ self.fail()
+ self.assert_autotest_logging_handle_error_called()
+ self.assertTrue(('MESSAGE' in self.stderr_str), repr(self.stderr_str))
+ self.assertTrue(('ARGS' in self.stderr_str), repr(self.stderr_str))
+ self.assertTrue(('Exception' in self.stderr_str), repr(self.stderr_str))
+ self.assertTrue(('setup_modules_unittest.py' in self.stderr_str),
+ repr(self.stderr_str))
+
+
+ def test_logging_monkey_patch_wrong_number_of_args(self):
+ logging.error('logging unittest %d %s', 32)
+ self.assert_autotest_logging_handle_error_called()
+ self.assertTrue('logging unittest' in self.stderr_str,
+ repr(self.stderr_str))
+
+
+ def test_logging_monkey_patch_wrong_type_of_arg(self):
+ logging.error('logging unittest %d', 'eighteen')
+ self.assert_autotest_logging_handle_error_called()
+ self.assertTrue('logging unittest' in self.stderr_str,
+ repr(self.stderr_str))
+
+
+ def test_logging_no_error(self):
+ logging.error('logging unittest. %s %s', 'meep', 'meep!')
+ self.assertEqual('', self.test_stderr.getvalue())
+
+
+if __name__ == "__main__":
+ unittest.main()