Using Wrappers to Log in PythonLauro BravarBlockedUnblockFollowFollowingMar 12Logging in Python can be tedious, especially when you use it to debug.
I am not a fan of Conda or Pycharm myself (or any other fancy IDE), but for those of you that are you will always have the problem of debugging/controlling when you have to put your code in production.
A lot of precious time is lost adding tons of lines of code to see what’s going on, and the Python Debugger (pdb) offers very little help to say the least.
But more importantly, most of the times, as developers, we are required to add logs to our code, so logging is most likely not an option we can opt out of.
For that reason I decided to make this post, in which I will show you a very easy, time-saving and powerful way to log your Python scripts.
You can extrapolate the details to others languages, as long as they have wrappers and loggers (I might do another post with those in the future).
The main concept is fairly simple: you want to log every time you enter or exit a function.
You want that for most of the functions, at least the upper level ones, so that if the code breaks at some point, you have an idea of where it broke and why.
The problem comes when writing a line of code for every time you want to log entrance or exit to a function (or any other important event).
But for every problem there is a solution, and in this case the solution is wrapping.
First I will show how wrapping works in Python, then logging, and then I will combine both of them to show a simple example.
Finally I will show a more complex example that portrays the power of this fairly simple concept.
WrappingPhoto by freestocks.
org on UnsplashFor those of you that don’t know what wrapping is.
Wrapping a function means that whenever that function is called “something” is going to be done.
That something is what you define (in code) inside the wrapper.
An example for a wrapper:Obtained from here.
The pre and post variables received as arguments in the wrap function are in this case the functions that you are going to call before and after the function that is being wrapped.
So if for example, you are wrapping the function bake_pie(), and you pass as arguments to the wrapper the functions before_baking and after_baking, the code will execute the function before_baking(), then bake_pie() and finally after_baking().
The usual form of the functions for wrappers is to have something like this:As you can see, the arguments for the functions entering and exiting are another function (the one you are wrapping) and its arguments.
Let’s move on to logging!LoggingLogging is like printing but to a file and with many control options and time displays.
It is mostly used to know what is going on with an app on a server or to debug on deployment.
A basic logging configuration in Python could look like this:As you can see you can declare the name of the file which you want to write to, the level of debugging you want (so that only certain messages are written to the file) and some other configurations about the format of the messages.
I will not get into detail about logging because there’s plenty written about it and it’s not that fun to be honest!Logging with wrappersSo now that we have wrappers and loggers it’s just a matter of adding them up.
What we need to do is put the logger functionality in the entering() and exiting() functions to show what’s going on in the logfile as we travel the different functions of our code.
A basic example could be like this one:Where we added logging messages to both the entering and exiting functions.
The last thing that remains is adding the wrapper “tag” to the function we want to wrap.
That tag is usally called an anotation and it’s just an “@” sign followed by the name of the wrapper right on top of your function:If we put all the pieces together it will look like this:Logging with wrappers 101If you execute the function bake_pie with bake_pie(3) for example, you will get the next logfile:2019–03–08 09:38:47,800 DEBUG Entered bake_pie2019–03–08 09:38:47,800 DEBUG Exited bake_pieYou can add the annotation @wrap(entering, exiting) to any other function and it will do the same, that’s the power of it, all the functionality with adding just one simple line.
Fancy Logging with WrappersPhoto by Jordane Mathieu on UnsplashAnd of course you can do much fancier things.
Just to show some of them, here is another example:I’ve changed the arguments in “pre” function so that it now receives the argument of the function it’s wrapping via *args.
Now we change the important part, the pre function itself, so that it gives more detailed information about the function it is logging:As you can see, we now log the following:Function nameFunction docstringWhere it is in the file (line no.
) and the name of that fileFirst argument passed to the function (if it has one)All of those with different levels of logging (debug, info and warning)This is what running bake_pie(3) will write to the logfile:2019–03–08 10:15:44,919 DEBUG Entered bake_pie2019–03–08 10:15:44,919 INFO Bakes a certain amount of pies 2019–03–08 10:15:44,919 INFO Function at line 36 in loggin_with_wrappers.
py2019–03–08 10:15:44,919 WARNING The argument amount is 32019–03–08 10:15:44,919 DEBUG Exited bake_pieTo check some of the cool built-ins you can display go here.
You sure can go crazy with wrappers adding a lot of logic to them so as to get the best possible logging information necessary…I hope this post helped you reduce the time you spend logging and the quality of it.
Happy logging :).