feat: success callback + success_log for post-retry recovery

doc/source/index.rst

@@ -342,6 +342,29 @@ In the same spirit, It's possible to execute after a call that failed:
     def raise_my_exception():
         raise MyException("Fail")
 
+Note that ``after`` runs only when an attempt *failed* and may be retried (or
+is about to stop after failures). To run code when the call ultimately
+**succeeds** — for example to log a ``retry_success`` line only after recovery
+— use the ``success`` callback (or the built-in ``success_log`` helper):
+
+.. testcode::
+
+    import logging
+    import sys
+    from tenacity import retry, stop_after_attempt, success_log
+
+    logging.basicConfig(stream=sys.stderr, level=logging.DEBUG)
+
+    logger = logging.getLogger(__name__)
+
+    @retry(stop=stop_after_attempt(3),
+           success=success_log(logger, logging.INFO))
+    def might_fail():
+        return "ok"
+
+By default ``success_log`` only emits when ``attempt_number > 1`` (i.e. at least
+one retry happened). Pass ``only_if_retried=False`` to also log first-try wins.
+
 It's also possible to only log failures that are going to be retried. Normally
 retries happen after a wait interval, so the keyword argument is called
 ``before_sleep``:

tenacity/__init__.py

@@ -28,7 +28,7 @@
 from . import _utils
 
 # Import all built-in after strategies for easier usage.
-from .after import after_log, after_nothing
+from .after import after_log, after_nothing, success_log, success_nothing
 
 # Import all built-in before strategies for easier usage.
 from .before import before_log, before_nothing
@@ -244,6 +244,7 @@ def __init__(
         before: t.Callable[["RetryCallState"], None] = before_nothing,
         after: t.Callable[["RetryCallState"], None] = after_nothing,
         before_sleep: t.Callable[["RetryCallState"], None] | None = None,
+        success: t.Callable[["RetryCallState"], None] | None = None,
         reraise: bool = False,
         retry_error_cls: type[RetryError] = RetryError,
         retry_error_callback: t.Callable[["RetryCallState"], t.Any] | None = None,
@@ -257,6 +258,7 @@ def __init__(
         self.before = before
         self.after = after
         self.before_sleep = before_sleep
+        self.success = success
         self.reraise = reraise
         self._local = threading.local()
         self.retry_error_cls = retry_error_cls
@@ -272,13 +274,14 @@ def copy(
         retry: retry_base | object = _unset,
         before: t.Callable[["RetryCallState"], None] | object = _unset,
         after: t.Callable[["RetryCallState"], None] | object = _unset,
-        before_sleep: t.Callable[["RetryCallState"], None] | None | object = _unset,
+        before_sleep: t.Callable[["RetryCallState"], None] | object | None = _unset,
+        success: t.Callable[["RetryCallState"], None] | object | None = _unset,
         reraise: bool | object = _unset,
         retry_error_cls: type[RetryError] | object = _unset,
         retry_error_callback: t.Callable[["RetryCallState"], t.Any]
-        | None
-        | object = _unset,
-        name: str | None | object = _unset,
+        | object
+        | None = _unset,
+        name: str | object | None = _unset,
         enabled: bool | object = _unset,
     ) -> "Self":
         """Copy this object with some parameters changed if needed."""
@@ -290,6 +293,7 @@ def copy(
             before=_first_set(before, self.before),
             after=_first_set(after, self.after),
             before_sleep=_first_set(before_sleep, self.before_sleep),
+            success=_first_set(success, self.success),
             reraise=_first_set(reraise, self.reraise),
             retry_error_cls=_first_set(retry_error_cls, self.retry_error_cls),
             retry_error_callback=_first_set(
@@ -440,7 +444,16 @@ def _begin_iter(self, retry_state: "RetryCallState") -> None:
 
     def _post_retry_check_actions(self, retry_state: "RetryCallState") -> None:
         if not (self.iter_state.is_explicit_retry or self.iter_state.retry_run_result):
-            self._add_action_func(lambda rs: rs.outcome.result())
+            # Terminal attempt that will not be retried: either success, or a
+            # non-retryable failure (result() re-raises). Fire ``success`` only
+            # on a clean outcome so callers can log "recovered after N tries".
+            def _finish(rs: "RetryCallState") -> t.Any:
+                fut = rs.outcome
+                if fut is not None and not fut.failed and self.success is not None:
+                    self.success(rs)
+                return fut.result()  # type: ignore[union-attr]
+
+            self._add_action_func(_finish)
             return
 
         if self.after is not None:
@@ -701,9 +714,10 @@ def retry(
     stop: "StopBaseT" = ...,
     wait: "WaitBaseT" = ...,
     retry: "RetryBaseT | tasyncio.retry.RetryBaseT" = ...,
-    before: t.Callable[["RetryCallState"], None | t.Awaitable[None]] = ...,
-    after: t.Callable[["RetryCallState"], None | t.Awaitable[None]] = ...,
-    before_sleep: t.Callable[["RetryCallState"], None | t.Awaitable[None]] | None = ...,
+    before: t.Callable[["RetryCallState"], t.Awaitable[None] | None] = ...,
+    after: t.Callable[["RetryCallState"], t.Awaitable[None] | None] = ...,
+    before_sleep: t.Callable[["RetryCallState"], t.Awaitable[None] | None] | None = ...,
+    success: t.Callable[["RetryCallState"], t.Awaitable[None] | None] | None = ...,
     reraise: bool = ...,
     retry_error_cls: type["RetryError"] = ...,
     retry_error_callback: t.Callable[["RetryCallState"], t.Any | t.Awaitable[t.Any]]
@@ -718,10 +732,11 @@ def retry(
     stop: "StopBaseT" = stop_never,
     wait: "WaitBaseT" = wait_none(),
     retry: "RetryBaseT | tasyncio.retry.RetryBaseT" = retry_if_exception_type(),
-    before: t.Callable[["RetryCallState"], None | t.Awaitable[None]] = before_nothing,
-    after: t.Callable[["RetryCallState"], None | t.Awaitable[None]] = after_nothing,
-    before_sleep: t.Callable[["RetryCallState"], None | t.Awaitable[None]]
+    before: t.Callable[["RetryCallState"], t.Awaitable[None] | None] = before_nothing,
+    after: t.Callable[["RetryCallState"], t.Awaitable[None] | None] = after_nothing,
+    before_sleep: t.Callable[["RetryCallState"], t.Awaitable[None] | None]
     | None = None,
+    success: t.Callable[["RetryCallState"], t.Awaitable[None] | None] | None = None,
     reraise: bool = False,
     retry_error_cls: type["RetryError"] = RetryError,
     retry_error_callback: t.Callable[["RetryCallState"], t.Any | t.Awaitable[t.Any]]
@@ -818,6 +833,8 @@ def wrap(f: t.Callable[P, R]) -> _RetryDecorated[P, R]:
     "stop_before_delay",
     "stop_never",
     "stop_when_event_set",
+    "success_log",
+    "success_nothing",
     "wait_chain",
     "wait_combine",
     "wait_exception",

tenacity/after.py

@@ -44,3 +44,40 @@ def log_it(retry_state: "RetryCallState") -> None:
         )
 
     return log_it
+
+
+def success_nothing(retry_state: "RetryCallState") -> None:
+    """Success strategy that does nothing."""
+
+
+def success_log(
+    logger: _utils.LoggerProtocol,
+    log_level: int,
+    sec_format: str = "%.3g",
+    *,
+    only_if_retried: bool = True,
+) -> typing.Callable[["RetryCallState"], None]:
+    """Log when a retried call ultimately succeeds.
+
+    Unlike :func:`after_log` (which runs only on *failed* attempts that will
+    be retried — see the retry controller), this callback runs on the
+    successful exit path. Set ``only_if_retried=False`` to also log first-try
+    successes.
+
+    Addresses the common need to emit a "retry_success" line only when
+    recovery actually happened (GitHub #531 / Stack Overflow).
+    """
+
+    def log_it(retry_state: "RetryCallState") -> None:
+        if only_if_retried and retry_state.attempt_number <= 1:
+            return
+        fn_name = retry_state.get_fn_name()
+        secs = retry_state.seconds_since_start
+        logger.log(
+            log_level,
+            f"Successful call to '{fn_name}' "
+            f"after {sec_format % secs if secs is not None else '?'}(s), "
+            f"this was the {_utils.to_ordinal(retry_state.attempt_number)} time calling it.",
+        )
+
+    return log_it

tenacity/asyncio/__init__.py

@@ -75,17 +75,18 @@ class AsyncRetrying(BaseRetrying):
     def __init__(
         self,
         sleep: t.Callable[
-            [int | float], None | t.Awaitable[None]
+            [int | float], t.Awaitable[None] | None
         ] = _portable_async_sleep,
         stop: "StopBaseT" = tenacity.stop.stop_never,
         wait: "WaitBaseT" = tenacity.wait.wait_none(),
         retry: "SyncRetryBaseT | RetryBaseT" = tenacity.retry_if_exception_type(),
         before: t.Callable[
-            ["RetryCallState"], None | t.Awaitable[None]
+            ["RetryCallState"], t.Awaitable[None] | None
         ] = before_nothing,
-        after: t.Callable[["RetryCallState"], None | t.Awaitable[None]] = after_nothing,
-        before_sleep: t.Callable[["RetryCallState"], None | t.Awaitable[None]]
+        after: t.Callable[["RetryCallState"], t.Awaitable[None] | None] = after_nothing,
+        before_sleep: t.Callable[["RetryCallState"], t.Awaitable[None] | None]
         | None = None,
+        success: t.Callable[["RetryCallState"], t.Awaitable[None] | None] | None = None,
         reraise: bool = False,
         retry_error_cls: type["RetryError"] = RetryError,
         retry_error_callback: t.Callable[["RetryCallState"], t.Any | t.Awaitable[t.Any]]
@@ -101,6 +102,7 @@ def __init__(
             before=before,  # type: ignore[arg-type]
             after=after,  # type: ignore[arg-type]
             before_sleep=before_sleep,  # type: ignore[arg-type]
+            success=success,  # type: ignore[arg-type]
             reraise=reraise,
             retry_error_cls=retry_error_cls,
             retry_error_callback=retry_error_callback,

tenacity/retry.py

@@ -221,7 +221,7 @@ class retry_if_exception_message(retry_if_exception):
     def __init__(
         self,
         message: str | None = None,
-        match: None | str | re.Pattern[str] = None,
+        match: str | re.Pattern[str] | None = None,
     ) -> None:
         if message is not None and match is not None:
             raise TypeError(

tests/test_success.py

@@ -0,0 +1,136 @@
+"""Tests for the success callback / success_log helper (#531)."""
+
+from __future__ import annotations
+
+import logging
+import unittest
+import unittest.mock
+
+from tenacity import (
+    _utils,
+    retry,
+    retry_if_exception_type,
+    stop_after_attempt,
+    success_log,
+    wait_none,
+)
+
+from . import test_tenacity
+
+
+class TestSuccessCallback(unittest.TestCase):
+    def test_success_fires_after_retry_recovery(self) -> None:
+        calls: list[int] = []
+
+        @retry(
+            stop=stop_after_attempt(5),
+            wait=wait_none(),
+            retry=retry_if_exception_type(ValueError),
+            success=lambda rs: calls.append(rs.attempt_number),
+            reraise=True,
+        )
+        def flaky(n: list[int] = [0]) -> str:  # noqa: B006
+            n[0] += 1
+            if n[0] < 3:
+                raise ValueError("not yet")
+            return "ok"
+
+        self.assertEqual(flaky(), "ok")
+        self.assertEqual(calls, [3])
+
+    def test_success_fires_on_first_try(self) -> None:
+        calls: list[int] = []
+
+        @retry(
+            stop=stop_after_attempt(3),
+            success=lambda rs: calls.append(rs.attempt_number),
+        )
+        def ok() -> str:
+            return "ok"
+
+        self.assertEqual(ok(), "ok")
+        self.assertEqual(calls, [1])
+
+    def test_success_not_called_when_exhausted(self) -> None:
+        calls: list[int] = []
+
+        @retry(
+            stop=stop_after_attempt(2),
+            wait=wait_none(),
+            retry=retry_if_exception_type(ValueError),
+            success=lambda rs: calls.append(rs.attempt_number),
+            reraise=True,
+        )
+        def always_fail() -> None:
+            raise ValueError("nope")
+
+        with self.assertRaises(ValueError):
+            always_fail()
+        self.assertEqual(calls, [])
+
+    def test_after_still_only_on_failed_attempts(self) -> None:
+        """Regression: ``after`` must not suddenly fire on success."""
+        after_calls: list[int] = []
+        success_calls: list[int] = []
+
+        @retry(
+            stop=stop_after_attempt(5),
+            wait=wait_none(),
+            retry=retry_if_exception_type(ValueError),
+            after=lambda rs: after_calls.append(rs.attempt_number),
+            success=lambda rs: success_calls.append(rs.attempt_number),
+            reraise=True,
+        )
+        def flaky(n: list[int] = [0]) -> str:  # noqa: B006
+            n[0] += 1
+            if n[0] < 2:
+                raise ValueError("x")
+            return "ok"
+
+        self.assertEqual(flaky(), "ok")
+        # after runs once for the failed attempt that will be retried
+        self.assertEqual(after_calls, [1])
+        self.assertEqual(success_calls, [2])
+
+
+class TestSuccessLog(unittest.TestCase):
+    def test_only_if_retried_skips_first_try(self) -> None:
+        log = unittest.mock.MagicMock(spec="logging.Logger.log")
+        logger = unittest.mock.MagicMock(spec="logging.Logger", log=log)
+        from tenacity import Future
+
+        rs = test_tenacity.make_retry_state(1, 0.05)
+        fut = Future(1)
+        fut.set_result("ok")
+        rs.outcome = fut
+        rs.outcome_timestamp = rs.start_time + 0.05
+
+        success_log(logger, logging.INFO)(rs)
+        log.assert_not_called()
+
+        success_log(logger, logging.INFO, only_if_retried=False)(rs)
+        log.assert_called_once()
+        msg = log.call_args[0][1]
+        self.assertIn("Successful call", msg)
+        self.assertIn(_utils.to_ordinal(1), msg)
+
+    def test_logs_when_recovered(self) -> None:
+        log = unittest.mock.MagicMock(spec="logging.Logger.log")
+        logger = unittest.mock.MagicMock(spec="logging.Logger", log=log)
+        rs = test_tenacity.make_retry_state(3, 0.2)
+        from tenacity import Future
+
+        fut = Future(3)
+        fut.set_result("ok")
+        rs.outcome = fut
+        rs.outcome_timestamp = rs.start_time + 0.2
+
+        success_log(logger, logging.INFO)(rs)
+        log.assert_called_once()
+        msg = log.call_args[0][1]
+        self.assertIn("Successful call", msg)
+        self.assertIn(_utils.to_ordinal(3), msg)
+
+
+if __name__ == "__main__":
+    unittest.main()