Merge remote-tracking branch 'lmr/improve-test-load-debug-v2'

avocado/runner.py

@@ -30,8 +30,10 @@ from avocado import sysinfo
 from avocado.core import exceptions
 from avocado.core import output
 from avocado.core import status
+from avocado.core import exit_codes
 from avocado.utils import path
 from avocado.utils import wait
+from avocado.utils import stacktrace
 
 
 class TestRunner(object):
@@ -62,13 +64,6 @@ class TestRunner(object):
         :param queue: Multiprocess queue.
         :type queue: :class`multiprocessing.Queue` instance.
         """
-        sys.stdout = output.LoggingFile(logger=logging.getLogger('avocado.test.stdout'))
-        sys.stderr = output.LoggingFile(logger=logging.getLogger('avocado.test.stderr'))
-        instance = self.job.test_loader.load_test(test_factory)
-        runtime.CURRENT_TEST = instance
-        early_state = instance.get_state()
-        queue.put(early_state)
-
         def timeout_handler(signum, frame):
             e_msg = "Timeout reached waiting for %s to end" % instance
             raise exceptions.TestTimeoutError(e_msg)
@@ -77,6 +72,22 @@ class TestRunner(object):
             e_msg = "Test %s interrupted by user" % instance
             raise exceptions.TestInterruptedError(e_msg)
 
+        sys.stdout = output.LoggingFile(logger=logging.getLogger('avocado.test.stdout'))
+        sys.stderr = output.LoggingFile(logger=logging.getLogger('avocado.test.stderr'))
+
+        try:
+            instance = self.job.test_loader.load_test(test_factory)
+            runtime.CURRENT_TEST = instance
+            early_state = instance.get_state()
+            queue.put(early_state)
+        except Exception:
+            exc_info = sys.exc_info()
+            app_logger = logging.getLogger('avocado.app')
+            app_logger.exception('Exception loading test')
+            tb_info = stacktrace.tb_info(exc_info)
+            queue.put({'load_exception': tb_info})
+            return
+
         signal.signal(signal.SIGUSR1, timeout_handler)
         signal.signal(signal.SIGINT, interrupt_handler)
 
@@ -127,6 +138,14 @@ class TestRunner(object):
             p.start()
 
             early_state = q.get()
+
+            if 'load_exception' in early_state:
+                self.job.view.notify(event='error',
+                                     msg='Avocado crashed during test load. '
+                                         'Some reports might have not been '
+                                         'generated. Aborting...')
+                sys.exit(exit_codes.AVOCADO_FAIL)
+
             # At this point, the test is already initialized and we know
             # for sure if there's a timeout set.
             if 'timeout' in early_state['params'].keys():

avocado/test.py

@@ -23,57 +23,19 @@ import os
 import shutil
 import sys
 import time
-import traceback
 import unittest
-import tempfile
 
 from avocado.core import data_dir
 from avocado.core import exceptions
 from avocado.utils import io
 from avocado.utils import path
 from avocado.utils import process
+from avocado.utils import stacktrace
 from avocado.utils.params import Params
 from avocado import sysinfo
 from avocado.version import VERSION
 
 
-log = logging.getLogger("avocado.test")
-
-
-def tb_info(exc_info):
-    """
-    Prepare traceback info.
-
-    :param exc_info: Exception info produced by sys.exc_info()
-    """
-    exc_type, exc_value, exc_traceback = exc_info
-    tb_info = traceback.format_exception(exc_type, exc_value,
-                                         exc_traceback.tb_next)
-    return tb_info
-
-
-def log_exc_info(exc_info):
-    """
-    Log exception info.
-
-    :param exc_info: Exception info produced by sys.exc_info()
-    """
-    log.error('')
-    for line in tb_info(exc_info):
-        for l in line.splitlines():
-            log.error(l)
-    log.error('')
-
-
-def prepare_exc_info(exc_info):
-    """
-    Prepare traceback info.
-
-    :param exc_info: Exception info produced by sys.exc_info()
-    """
-    return "".join(tb_info(exc_info))
-
-
 class Test(unittest.TestCase):
 
     """
@@ -413,18 +375,18 @@ class Test(unittest.TestCase):
         try:
             self.setup()
         except Exception, details:
-            log_exc_info(sys.exc_info())
+            stacktrace.log_exc_info(sys.exc_info(), logger='avocado.test')
             raise exceptions.TestSetupFail(details)
         try:
             self.action()
         except Exception, details:
-            log_exc_info(sys.exc_info())
+            stacktrace.log_exc_info(sys.exc_info(), logger='avocado.test')
             action_exception = details
         finally:
             try:
                 self.cleanup()
             except Exception, details:
-                log_exc_info(sys.exc_info())
+                stacktrace.log_exc_info(sys.exc_info(), logger='avocado.test')
                 cleanup_exception = details
 
         whiteboard_file = os.path.join(self.logdir, 'whiteboard')
@@ -442,12 +404,12 @@ class Test(unittest.TestCase):
                     try:
                         self.check_reference_stdout()
                     except Exception, details:
-                        log_exc_info(sys.exc_info())
+                        stacktrace.log_exc_info(sys.exc_info(), logger='avocado.test')
                         stdout_check_exception = details
                     try:
                         self.check_reference_stderr()
                     except Exception, details:
-                        log_exc_info(sys.exc_info())
+                        stacktrace.log_exc_info(sys.exc_info(), logger='avocado.test')
                         stderr_check_exception = details
 
             elif not job_standalone:
@@ -494,20 +456,18 @@ class Test(unittest.TestCase):
             self.status = detail.status
             self.fail_class = detail.__class__.__name__
             self.fail_reason = detail
-            self.traceback = prepare_exc_info(sys.exc_info())
+            self.traceback = stacktrace.prepare_exc_info(sys.exc_info())
         except AssertionError, detail:
             self.status = 'FAIL'
             self.fail_class = detail.__class__.__name__
             self.fail_reason = detail
-            self.traceback = prepare_exc_info(sys.exc_info())
+            self.traceback = stacktrace.prepare_exc_info(sys.exc_info())
         except Exception, detail:
             self.status = 'FAIL'
             self.fail_class = detail.__class__.__name__
             self.fail_reason = detail
-            exc_type, exc_value, exc_traceback = sys.exc_info()
-            tb_info = traceback.format_exception(exc_type, exc_value,
-                                                 exc_traceback.tb_next)
-            self.traceback = "".join(tb_info)
+            tb_info = stacktrace.tb_info(sys.exc_info())
+            self.traceback = stacktrace.prepare_exc_info(sys.exc_info())
             for e_line in tb_info:
                 self.log.error(e_line)
         finally:

avocado/utils/stacktrace.py

+"""
+Traceback standard module plus some additional APIs.
+"""
+from traceback import format_exception
+import logging
+
+
+def tb_info(exc_info):
+    """
+    Prepare traceback info.
+
+    :param exc_info: Exception info produced by sys.exc_info()
+    """
+    exc_type, exc_value, exc_traceback = exc_info
+    return format_exception(exc_type, exc_value, exc_traceback.tb_next)
+
+
+def prepare_exc_info(exc_info):
+    """
+    Prepare traceback info.
+
+    :param exc_info: Exception info produced by sys.exc_info()
+    """
+    return "".join(tb_info(exc_info))
+
+
+def log_exc_info(exc_info, logger='root'):
+    """
+    Log exception info to logger_name.
+
+    :param exc_info: Exception info produced by sys.exc_info()
+    :param logger: Name of the logger (defaults to root)
+    """
+    log = logging.getLogger(logger)
+    log.error('')
+    for line in tb_info(exc_info):
+        for l in line.splitlines():
+            log.error(l)
+    log.error('')