Add a pformat() failure method and use it in the conductor

When the conductors engine raises a wrapped failure (which may
contain a single failure from a remote worker, or may contain many
failures if there were more than one such failures...) it is very
useful to show more than just the basic exception information (or at
least provide methods that can print out the information in a nice
manner).

This commit adds a pformat() failure method that formats the failure
in a nice and understandable manner and then uses it in the conductor
dispatching routine so that the conductors LOGs are much more useful.

Change-Id: I46afacf54c9b4cae885c76c09b51e61d71fe623a

taskflow/conductors/single_threaded.py

@@ -96,17 +96,24 @@ class SingleThreadedConductor(base.Conductor):
                 engine.run()
             except excp.WrappedFailure as e:
                 if all((f.check(*NO_CONSUME_EXCEPTIONS) for f in e)):
-                    LOG.warn("Job execution failed (consumption being"
-                             " skipped): %s", job, exc_info=True)
                     consume = False
-                else:
-                    LOG.warn("Job execution failed: %s", job, exc_info=True)
+                if LOG.isEnabledFor(logging.WARNING):
+                    if consume:
+                        LOG.warn("Job execution failed (consumption being"
+                                 " skipped): %s [%s failures]", job, len(e))
+                    else:
+                        LOG.warn("Job execution failed (consumption"
+                                 " proceeding): %s [%s failures]", job, len(e))
+                    # Show the failure/s + traceback (if possible)...
+                    for i, f in enumerate(e):
+                        LOG.warn("%s. %s", i + 1, f.pformat(traceback=True))
             except NO_CONSUME_EXCEPTIONS:
                 LOG.warn("Job execution failed (consumption being"
                          " skipped): %s", job, exc_info=True)
                 consume = False
             except Exception:
-                LOG.warn("Job execution failed: %s", job, exc_info=True)
+                LOG.warn("Job execution failed (consumption proceeding): %s",
+                         job, exc_info=True)
             else:
                 LOG.info("Job completed successfully: %s", job)
         return consume

taskflow/tests/unit/test_utils_failure.py

@@ -42,6 +42,10 @@ class GeneralFailureObjTestsMixin(object):
         self.assertEqual(list(self.fail_obj),
                          test_utils.RUNTIME_ERROR_CLASSES[:-2])
 
+    def test_pformat_no_traceback(self):
+        text = self.fail_obj.pformat()
+        self.assertNotIn("Traceback", text)
+
     def test_check_str(self):
         val = 'Exception'
         self.assertEqual(self.fail_obj.check(val), val)
@@ -91,6 +95,10 @@ class ReCreatedFailureTestCase(test.TestCase, GeneralFailureObjTestsMixin):
     def test_no_exc_info(self):
         self.assertIs(self.fail_obj.exc_info, None)
 
+    def test_pformat_traceback(self):
+        text = self.fail_obj.pformat(traceback=True)
+        self.assertIn("Traceback (most recent call last):", text)
+
     def test_reraises(self):
         exc = self.assertRaises(exceptions.WrappedFailure,
                                 self.fail_obj.reraise)
@@ -103,6 +111,10 @@ class FromExceptionTestCase(test.TestCase, GeneralFailureObjTestsMixin):
         super(FromExceptionTestCase, self).setUp()
         self.fail_obj = misc.Failure.from_exception(RuntimeError('Woot!'))
 
+    def test_pformat_no_traceback(self):
+        text = self.fail_obj.pformat(traceback=True)
+        self.assertIn("Traceback not available", text)
+
 
 class FailureObjectTestCase(test.TestCase):
 
@@ -188,6 +200,17 @@ class FailureObjectTestCase(test.TestCase):
         self.assertNotEqual(captured, None)
         self.assertFalse(captured.matches(None))
 
+    def test_pformat_traceback(self):
+        captured = _captured_failure('Woot!')
+        text = captured.pformat(traceback=True)
+        self.assertIn("Traceback (most recent call last):", text)
+
+    def test_pformat_traceback_captured_no_exc_info(self):
+        captured = _captured_failure('Woot!')
+        captured = misc.Failure.from_dict(captured.to_dict())
+        text = captured.pformat(traceback=True)
+        self.assertIn("Traceback (most recent call last):", text)
+
 
 class WrappedFailureTestCase(test.TestCase):
 

taskflow/utils/misc.py

@@ -707,8 +707,23 @@ class Failure(object):
         return None
 
     def __str__(self):
-        return 'Failure: %s: %s' % (self._exc_type_names[0],
-                                    self._exception_str)
+        return self.pformat()
+
+    def pformat(self, traceback=False):
+        buf = six.StringIO()
+        buf.write(
+            'Failure: %s: %s' % (self._exc_type_names[0], self._exception_str))
+        if traceback:
+            if self._traceback_str is not None:
+                traceback_str = self._traceback_str.rstrip()
+            else:
+                traceback_str = None
+            if traceback_str:
+                buf.write('\nTraceback (most recent call last):\n')
+                buf.write(traceback_str)
+            else:
+                buf.write('\nTraceback not available.')
+        return buf.getvalue()
 
     def __iter__(self):
         """Iterate over exception type names."""