The other day, I decided I wanted to create a decorator to catch exceptions and log them. I found a rather complex example on Github that I used for some ideas on how to approach this task and came up with the following:
# exception_decor.py import functools import logging def create_logger(): """ Creates a logging object and returns it """ logger = logging.getLogger("example_logger") logger.setLevel(logging.INFO) # create the logging file handler fh = logging.FileHandler("/path/to/test.log") fmt = '%(asctime)s - %(name)s - %(levelname)s - %(message)s' formatter = logging.Formatter(fmt) fh.setFormatter(formatter) # add handler to logger object logger.addHandler(fh) return logger def exception(function): """ A decorator that wraps the passed in function and logs exceptions should one occur """ @functools.wraps(function) def wrapper(*args, **kwargs): logger = create_logger() try: return function(*args, **kwargs) except: # log the exception err = "There was an exception in " err += function.__name__ logger.exception(err) # re-raise the exception raise return wrapper
In this code, we have two functions. The first one creates a logging object and returns it. The second function is our decorator function. Here we wrap the passed in function in a try/except and log any exceptions that occur using our logger. You will note that I am also logging the function name the the exception occurred in.
Now we just need to test this decorator out. To do so, you can create a new Python script and add the following code to it. Make sure you save this in the same location that you saved the code above.
from exception_decor import exception @exception def zero_divide(): 1 / 0 if __name__ == '__main__': zero_divide()
When you run this code from the command line, you should end up with a log file that has the following contents:
2016-06-09 08:26:50,874 - example_logger - ERROR - There was an exception in zero_divide Traceback (most recent call last): File "/home/mike/exception_decor.py", line 29, in wrapper return function(*args, **kwargs) File "/home/mike/test_exceptions.py", line 5, in zero_divide 1 / 0 ZeroDivisionError: integer division or modulo by zero
I thought this was a handy piece of code and I hope you will find it useful too!
UPDATE: An astute reader pointed out that it would be a good idea to generalize this script such that you can pass the decorator a logger object. So let’s look at how that works!
Passing a logger to our decorator
First off, let’s split our logging code off into its own module. Let’s call it exception_logger.py. Here’s the code to put into that file:
# exception_logger.py import logging def create_logger(): """ Creates a logging object and returns it """ logger = logging.getLogger("example_logger") logger.setLevel(logging.INFO) # create the logging file handler fh = logging.FileHandler(r"/path/to/test.log") fmt = '%(asctime)s - %(name)s - %(levelname)s - %(message)s' formatter = logging.Formatter(fmt) fh.setFormatter(formatter) # add handler to logger object logger.addHandler(fh) return logger logger = create_logger()
Next we need to modify our decorator code so we can accept a logger as an argument. Be sure to save it as exception_decor.py
# exception_decor.py import functools def exception(logger): """ A decorator that wraps the passed in function and logs exceptions should one occur @param logger: The logging object """ def decorator(func): def wrapper(*args, **kwargs): try: return func(*args, **kwargs) except: # log the exception err = "There was an exception in " err += func.__name__ logger.exception(err) # re-raise the exception raise return wrapper return decorator
You will note that we have multiple levels of nested functions here. Be sure to study it closely to understand what’s going on. Finally we need to modify our testing script:
from exception_decor import exception from exception_logger import logger @exception(logger) def zero_divide(): 1 / 0 if __name__ == '__main__': zero_divide()
Here we import our decorator and our logger. Then we decorate our function and pass the decorator our logger object. If you run this code, you should see the same file generated as you did in the first example. Have fun!
This is really cool. And timely too, as I need something like this for a project I’m working on. Not sure how this would impact a try/catch block in my code. I’ll have to test it out.
I’m glad you found it useful. I thought it was pretty neat too
One small improvement would be to apply the functools.wraps decorator to the wrapper function:
@functools.wraps(function)
def wrapper(*args, **kwargs):
...
That way the the decorated function inherits the name and docstring of the undecorated one.
Yup…I don’t know why I didn’t add that especially after writing an article all about wraps. Regardless, I just fixed it. Thanks!
The shoemaker’s son always goes barefoot 😉
I copied the code and tried it and got an error in Python 3.5:
RuntimeError: No active exception to reraise
Hits in line 42.
I indented the line and it works as expected.
It also works as expected in a finally: clause.
You’re running create_logger() in the wrong scope – it’s going to run every time the wrapped function is called. It would be better to call it in the outer scope. It would be even better to pass in a logger object as an argument to the decorator. That would give users the flexibility to use different loggers for different functions.
I fixed it by indenting the code. I don’t think you’d want to put the raise into a finally clause or you would always attempt to raise an error
That’s an interesting idea. I gave that a try and added an example to the article.