Merge lp:~facundo/magicicada-gui/log-exceptions into lp:magicicada-gui

[Facundo Batista]

Log unhandled exceptions.

[lp:~facundo/magicicada-gui/log-exceptions]

68. By Facundo Batista on 2010-08-18

Tested the logging

69. By Facundo Batista on 2010-08-18

Make pylint and pep8 happy

[Natalia Bidart (nataliabidart)]

Lovely.

review: Approve

=== modified file 'magicicada/logger.py'
--- magicicada/logger.py	2010-06-20 19:50:46 +0000
+++ magicicada/logger.py	2010-08-18 21:20:58 +0000
@@ -21,6 +21,8 @@
 
 import logging
 import os
+import sys
+import traceback
 
 from logging.handlers import RotatingFileHandler
 
@@ -35,6 +37,18 @@
         self.doRollover()
 
 
+def exception_handler(exc_type, exc_value, tb):
+    """Handle an unhandled exception."""
+    # stderr
+    exception = traceback.format_exception(exc_type, exc_value, tb)
+    exception = "".join(exception)
+    print >> sys.stderr, exception
+
+    # log
+    logger = logging.getLogger('magicicada')
+    logger.error("Unhandled exception!\n%s", exception)
+
+
 def set_up():
     """Set up the logging."""
 
@@ -53,3 +67,6 @@
                                   '%Y-%m-%d %H:%M:%S')
     handler.setFormatter(formatter)
     logger.setLevel(logging.DEBUG)
+
+    # hook the exception handler
+    sys.excepthook = exception_handler

=== modified file 'magicicada/tests/helpers.py'
--- magicicada/tests/helpers.py	2010-06-19 18:55:01 +0000
+++ magicicada/tests/helpers.py	2010-08-18 21:20:58 +0000
@@ -33,21 +33,21 @@
         """Just add the record to self.records."""
         self.records.append(record)
 
-    def check(self, level, msg):
+    def check(self, level, *msgs):
         """Check that something is logged."""
         for rec in self.records:
-            if rec.levelname == level and str(msg) in rec.message:
+            if rec.levelname == level and all(m in rec.message for m in msgs):
                 return True
         return False
 
-    def check_error(self, msg):
+    def check_error(self, *msgs):
         """Shortcut for ERROR check."""
-        return self.check('ERROR', msg)
+        return self.check('ERROR', *msgs)
 
-    def check_info(self, msg):
+    def check_info(self, *msgs):
         """Shortcut for INFO check."""
-        return self.check('INFO', msg)
+        return self.check('INFO', *msgs)
 
-    def check_debug(self, msg):
+    def check_debug(self, *msgs):
         """Shortcut for DEBUG check."""
-        return self.check('DEBUG', msg)
+        return self.check('DEBUG', *msgs)

=== added file 'magicicada/tests/test_logger.py'
--- magicicada/tests/test_logger.py	1970-01-01 00:00:00 +0000
+++ magicicada/tests/test_logger.py	2010-08-18 21:20:58 +0000
@@ -0,0 +1,83 @@
+# Tests some logging functions
+#
+# Author: Facundo Batista <[e-mail]>
+#
+# Copyright 2010 Chicharreros
+#
+# This program is free software: you can redistribute it and/or modify it
+# under the terms of the GNU General Public License version 3, as published
+# by the Free Software Foundation.
+#
+# This program is distributed in the hope that it will be useful, but
+# WITHOUT ANY WARRANTY; without even the implied warranties of
+# MERCHANTABILITY, SATISFACTORY QUALITY, or FITNESS FOR A PARTICULAR
+# PURPOSE.  See the GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License along
+# with this program.  If not, see <http://www.gnu.org/licenses/>.
+
+"""Tests some logging functions."""
+
+import cStringIO
+import logging
+import sys
+import unittest
+
+from magicicada.logger import exception_handler
+from magicicada.tests.helpers import MementoHandler
+
+
+# It's ok to access private data in the test suite
+# pylint: disable=W0212
+
+
+class ExceptionTests(unittest.TestCase):
+    """Test that we log on unhandled exceptions."""
+
+    def _get_exception_data(self):
+        """Return data from a real exception."""
+        try:
+            1 / 0
+        except ZeroDivisionError:
+            return sys.exc_info()
+
+    def test_hook(self):
+        """Check that we're hooked in sys."""
+        self.assertTrue(sys.excepthook is exception_handler)
+
+    def test_logs(self):
+        """Unhandled exceptions logs in error."""
+        # set up logger
+        handler = MementoHandler()
+        handler.setLevel(logging.DEBUG)
+        l = logging.getLogger('magicicada')
+
+        # call
+        l.addHandler(handler)
+        exc = self._get_exception_data()
+        try:
+            exception_handler(*exc)
+        finally:
+            l.removeHandler(handler)
+
+        # check
+        self.assertTrue(handler.check_error("Unhandled exception",
+                                            "ZeroDivisionError"))
+
+    def test_stderr(self):
+        """Unhandled exceptions are also sent to stderr."""
+        fh = cStringIO.StringIO()
+
+        # call
+        orig_stderr = sys.stderr
+        sys.stderr = fh
+        exc = self._get_exception_data()
+        try:
+            exception_handler(*exc)
+        finally:
+            sys.stderr = orig_stderr
+
+        # check
+        shown = fh.getvalue()
+        self.assertTrue("Traceback" in shown)
+        self.assertTrue("ZeroDivisionError" in shown)