Entry Exit Logging (EEL) in Python for Debugging logs
Sometimes things go wrong, like an error in processing a web request in a web server. While serving a single request, dozens of function calls are made and any of them can go wrong, so when this happens, logs come to our rescue. But what can we figure out from logs if we haven’t logged proper information. So, for that one of the good practices of logging, Entry Exit Logging (EEL) will help us to pinpoint a point of failure.
Entry Exit Logging is conceptually very simple concept, all we need to do is log when a function starts executing and completes. If you are coming for Spring Boot/Java, you would know AspectJ, which is an Aspect Oriented Programing package, by using which you can easily do EEL without much of a hassle. But due to fundamental differences in programming language there are differences in ways we can achieve this goal of EEL in Python.
Simplest possible way of doing it would be writing log statements at the start and the end of the function.
Example — Simplest implementation of EEL
But if you’ll keep doing this, it’ll quickly became tedious. If you need to add EEL to existing codebase, then this is too much of a redundant work.
So, if we want to do elegantly, Decorators are way to go. Let’s write a simple decorator for the same.
Example — Simple Decorators Implementation
Output —
As given in above output, we have got Entry Exit function logging in the function without writing even a single logging related statement inside our function.
But there’s still a minor issue. If you notice carefully, you’ll realize that this will fail if exception is raised inside do_work function.
As do_work would raise an Exception, __after_call will not get called. So, only entry log will come. There’s a fix around it.
Example — EEL with Exception Handling
Output —
So, in conclusion we have implemented Entry Exit Logging in Python. Further we can improve more by adding Tracer ID for every request that comes in for server applications (MDC Logging). Could also modify __before_call , __after_call and __on_exception to log additional data like functional params and all.
Hope you find this article helpful. 😁