pythonpython-tenacity

Python Tenacity log exception on retry


I'm using the tenacity package to retry a function. My retry decorator looks like this:

@retry(wait=wait_exponential(multiplier=1/(2**5), max=60), after=after_log(logger, logging.INFO))

On exception I get a logging message like this:

INFO:mymodule:Finished call to 'mymodule.MyClass.myfunction' after 0.001(s), this was the 1st time calling it.

I want to log the actual exception (1-line format, not stack trace preferably) in addition to what is already logged. Can this be done with tenacity? Or do I just have to catch the exception, print, and re-raise?


Solution

  • You can set the before_sleep parameter. This callable receives the exc_info thrown by your code. Ref.: https://tenacity.readthedocs.io/en/latest/api.html#module-tenacity.before_sleep

    Example

    import logging
    from typing import Final
    
    from tenacity import (
        after_log,
        before_sleep_log,
        retry,
        retry_if_exception_type,
        stop_after_attempt,
        wait_exponential,
    )
    
    logger: Final = logging.getLogger(__name__)
    logging.basicConfig(level=logging.INFO)
    
    
    @retry(
        reraise=True,
        before_sleep=before_sleep_log(logger, logging.INFO),
        after=after_log(logger, logging.INFO),
        wait=wait_exponential(multiplier=1, min=1, max=8),
        retry=retry_if_exception_type(ZeroDivisionError),
        stop=stop_after_attempt(4),
    )
    def never_gonna_give_you_up() -> None:
        1 / 0
    
    
    if __name__ == "__main__":
        never_gonna_give_you_up()
    

    Output

    INFO:__main__:Finished call to '__main__.never_gonna_give_you_up' after 0.000(s), this was the 1st time calling it.
    INFO:__main__:Retrying __main__.never_gonna_give_you_up in 1.0 seconds as it raised ZeroDivisionError: division by zero.
    INFO:__main__:Finished call to '__main__.never_gonna_give_you_up' after 1.015(s), this was the 2nd time calling it.
    INFO:__main__:Retrying __main__.never_gonna_give_you_up in 2.0 seconds as it raised ZeroDivisionError: division by zero.
    INFO:__main__:Finished call to '__main__.never_gonna_give_you_up' after 3.031(s), this was the 3rd time calling it.
    INFO:__main__:Retrying __main__.never_gonna_give_you_up in 4.0 seconds as it raised ZeroDivisionError: division by zero.
    INFO:__main__:Finished call to '__main__.never_gonna_give_you_up' after 7.031(s), this was the 4th time calling it.
    Traceback (most recent call last):
      File "C:\***.py", line 33, in <module>
        never_gonna_give_you_up()
      File "C:\Users\***\lib\site-packages\tenacity\__init__.py", line 324, in wrapped_f
        return self(f, *args, **kw)
      File "C:\Users\***\lib\site-packages\tenacity\__init__.py", line 404, in __call__
        do = self.iter(retry_state=retry_state)
      File "C:\Users\***\lib\site-packages\tenacity\__init__.py", line 360, in iter
        raise retry_exc.reraise()
      File "C:\Users\***\lib\site-packages\tenacity\__init__.py", line 193, in reraise
        raise self.last_attempt.result()
      File "C:\Users\***\AppData\Local\Programs\Python\Python310\lib\concurrent\futures\_base.py", line 439, in result
        return self.__get_result()
      File "C:\Users\***\AppData\Local\Programs\Python\Python310\lib\concurrent\futures\_base.py", line 391, in __get_result
        raise self._exception
      File "C:\Users\***\lib\site-packages\tenacity\__init__.py", line 407, in __call__
        result = fn(*args, **kwargs)
      File "C:\***.py", line 29, in never_gonna_give_you_up
        1 / 0
    ZeroDivisionError: division by zero
    

    These lines are printed by before_sleep_log:

    Retrying __main__.never_gonna_give_you_up in 1.0 seconds as it raised ZeroDivisionError: division by zero.