before_sleep_log: Add an exc_info option to include exception tracebacks (#227)
* before_sleep_log: More specific tests to show how log messages look
* before_sleep_log: Add an exc_info option to include exception tracebacks
* fixup! before_sleep_log: Add an exc_info option to include exception tracebacks
Fix pep8 failures.
* fixup! before_sleep_log: Add an exc_info option to include exception tracebacks
* Add release note.
diff --git a/releasenotes/notes/before_sleep_log-improvements-d8149274dfb37d7c.yaml b/releasenotes/notes/before_sleep_log-improvements-d8149274dfb37d7c.yaml
new file mode 100644
index 0000000..b8d16ee
--- /dev/null
+++ b/releasenotes/notes/before_sleep_log-improvements-d8149274dfb37d7c.yaml
@@ -0,0 +1,3 @@
+---
+features:
+ - Add an ``exc_info`` option to the ``before_sleep_log()`` strategy.
\ No newline at end of file
diff --git a/tenacity/before_sleep.py b/tenacity/before_sleep.py
index b5fd601..c8b3d33 100644
--- a/tenacity/before_sleep.py
+++ b/tenacity/before_sleep.py
@@ -15,23 +15,32 @@
# limitations under the License.
from tenacity import _utils
+from tenacity.compat import get_exc_info_from_future
def before_sleep_nothing(retry_state):
"""Before call strategy that does nothing."""
-def before_sleep_log(logger, log_level):
+def before_sleep_log(logger, log_level, exc_info=False):
"""Before call strategy that logs to some logger the attempt."""
def log_it(retry_state):
if retry_state.outcome.failed:
- verb, value = 'raised', retry_state.outcome.exception()
+ ex = retry_state.outcome.exception()
+ verb, value = 'raised', '%s: %s' % (type(ex).__name__, ex)
+
+ if exc_info:
+ local_exc_info = get_exc_info_from_future(retry_state.outcome)
+ else:
+ local_exc_info = False
else:
verb, value = 'returned', retry_state.outcome.result()
+ local_exc_info = False # exc_info does not apply when no exception
logger.log(log_level,
"Retrying %s in %s seconds as it %s %s.",
_utils.get_callback_name(retry_state.fn),
getattr(retry_state.next_action, 'sleep'),
- verb, value)
+ verb, value,
+ exc_info=local_exc_info)
return log_it
diff --git a/tenacity/compat.py b/tenacity/compat.py
index 026c248..6bd815e 100644
--- a/tenacity/compat.py
+++ b/tenacity/compat.py
@@ -299,3 +299,24 @@
'retry_error_callback', fn, stacklevel=4)
return fn(retry_state.outcome)
return wrapped_retry_error_callback
+
+
+def get_exc_info_from_future(future):
+ """
+ Get an exc_info value from a Future.
+
+ Given a a Future instance, retrieve an exc_info value suitable for passing
+ in as the exc_info parameter to logging.Logger.log() and related methods.
+
+ On Python 2, this will be a (type, value, traceback) triple.
+ On Python 3, this will be an exception instance (with embedded traceback).
+
+ If there was no exception, None is returned on both versions of Python.
+ """
+ if six.PY3:
+ return future.exception()
+ else:
+ ex, tb = future.exception_info()
+ if ex is None:
+ return None
+ return type(ex), ex, tb
diff --git a/tenacity/tests/test_tenacity.py b/tenacity/tests/test_tenacity.py
index 490d03a..4fbed6e 100644
--- a/tenacity/tests/test_tenacity.py
+++ b/tenacity/tests/test_tenacity.py
@@ -14,6 +14,8 @@
# See the License for the specific language governing permissions and
# limitations under the License.
import logging
+import os
+import re
import sys
import time
import typing
@@ -1157,12 +1159,42 @@
finally:
logger.removeHandler(handler)
- etalon_re = r'Retrying .* in 0\.01 seconds as it raised .*\.'
+ etalon_re = (r"^Retrying .* in 0\.01 seconds as it raised "
+ r"(IO|OS)Error: Hi there, I'm an IOError\.$")
self.assertEqual(len(handler.records), 2)
- self.assertRegexpMatches(handler.records[0].getMessage(), etalon_re)
- self.assertRegexpMatches(handler.records[1].getMessage(), etalon_re)
+ fmt = logging.Formatter().format
+ self.assertRegexpMatches(fmt(handler.records[0]), etalon_re)
+ self.assertRegexpMatches(fmt(handler.records[1]), etalon_re)
- def test_before_sleep_log_returns(self):
+ def test_before_sleep_log_raises_with_exc_info(self):
+ thing = NoIOErrorAfterCount(2)
+ logger = logging.getLogger(self.id())
+ logger.propagate = False
+ logger.setLevel(logging.INFO)
+ handler = CapturingHandler()
+ logger.addHandler(handler)
+ try:
+ _before_sleep = tenacity.before_sleep_log(logger,
+ logging.INFO,
+ exc_info=True)
+ retrying = Retrying(wait=tenacity.wait_fixed(0.01),
+ stop=tenacity.stop_after_attempt(3),
+ before_sleep=_before_sleep)
+ retrying.call(thing.go)
+ finally:
+ logger.removeHandler(handler)
+
+ etalon_re = re.compile(r"^Retrying .* in 0\.01 seconds as it raised "
+ r"(IO|OS)Error: Hi there, I'm an IOError\.{0}"
+ r"Traceback \(most recent call last\):{0}"
+ r".*$".format(os.linesep),
+ flags=re.MULTILINE)
+ self.assertEqual(len(handler.records), 2)
+ fmt = logging.Formatter().format
+ self.assertRegexpMatches(fmt(handler.records[0]), etalon_re)
+ self.assertRegexpMatches(fmt(handler.records[1]), etalon_re)
+
+ def test_before_sleep_log_returns(self, exc_info=False):
thing = NoneReturnUntilAfterCount(2)
logger = logging.getLogger(self.id())
logger.propagate = False
@@ -1170,7 +1202,9 @@
handler = CapturingHandler()
logger.addHandler(handler)
try:
- _before_sleep = tenacity.before_sleep_log(logger, logging.INFO)
+ _before_sleep = tenacity.before_sleep_log(logger,
+ logging.INFO,
+ exc_info=exc_info)
_retry = tenacity.retry_if_result(lambda result: result is None)
retrying = Retrying(wait=tenacity.wait_fixed(0.01),
stop=tenacity.stop_after_attempt(3),
@@ -1179,10 +1213,14 @@
finally:
logger.removeHandler(handler)
+ etalon_re = r'^Retrying .* in 0\.01 seconds as it returned None\.$'
self.assertEqual(len(handler.records), 2)
- etalon_re = r'Retrying .* in 0\.01 seconds as it returned None'
- self.assertRegexpMatches(handler.records[0].getMessage(), etalon_re)
- self.assertRegexpMatches(handler.records[1].getMessage(), etalon_re)
+ fmt = logging.Formatter().format
+ self.assertRegexpMatches(fmt(handler.records[0]), etalon_re)
+ self.assertRegexpMatches(fmt(handler.records[1]), etalon_re)
+
+ def test_before_sleep_log_returns_with_exc_info(self):
+ self.test_before_sleep_log_returns(exc_info=True)
class TestReraiseExceptions(unittest.TestCase):
