Setting up request response logs in Django

Django was the first web framework that I’ve learned. It helped me to land my first job. So I have a special place for Django in my heart. Whenever I work with a new framework or coding practice, I instinctively try to think- If I were using Django, how would I be doing it.

Right now I use Java, specifically Spring-boot for most of my tasks. The transition was a bit hard. I missed Django shell most for quickly testing or prototyping a piece of code. For a way around I learned to write Tests , not really full fledged TDD, but just for ease of development. I also do that now when working on Django for something.

May be it’s not only just Java or Spring, it’s also the wisdom of my current colleagues that I’ve learned some beautiful ways of separating the concerns. One of the example is using AOP to write logs for methods. For most of our use cases writing input and output arguments and if any exception occurs in log is good enough regardless of the method’s class, whether it is a controller, service or repository. And if we need some extra log we can use the logger inside the method, but that’s rare.

@loggable
private SomeReturnType doSomething(SomeParameter someParameter){
    /*method body*/
    return someReturn;
} 

Here loggable is an annotation type which is wired to a LoggingAspect class, where necessary codes for logging are written. This way we can start basic logging for a method just by inserting loggable annotation on top of the method.

This inspired me to do something similar in Django. Due to the dynamic nature of the language Python, we don’t need any language extension here. There are many ways we can inspect even modify a class property during runtime. Decorator is one of them.

But in Django, you can achieve things without writing a method. You can use Class Based Views where you just specify a model, link the view class in urls.py and boom! So how can we do something like before here?

I’ve done some googling and stack-overflowing, and found many ways to achieve that. And the solution I liked most is not even touching the view class! You wrote your necessary codes in a class, suppse you name it Loggable then use it in urls.py like this:

urlpatterns=[
    ...
    path('someurl', Loggable(SomeCBView).as_view()),
    ...
]

And the structure of the class looks like this:

The example here may or may not work, but I’ll share a working copy at the latter of this post.

Notice that, most business logic is written inside as_view() method. It is simply to maintain consistency and out of convention of calling as_view() during url configuration for CBVs.

Inside the as_view() method, I’ve used wraps decorator of python functools here. It helps to inject codes before execution of the function and can manipulate result of the execution of the function.

Here is how it works step by step:

1. Retrieve the actual instance of view:

self.view_func = self.view_func.as_view(*args, **kwargs)

2. Pass the instance for supervised execution inside _wrapped_view_func using wraps decorator

@wraps(self.view_func)
def _wrapped_view_func(request, *args, **kwargs):
   ....

3. Write some log containing requests method, path, username etc:

reqMessage = {'method': request.method,                                                 'path': request.path,                                                 'username': request.user.username                                                 }                                   
self.logger.info({'request': reqMessage})

4. Actually execute the function and handle exception in the try… catch block.

To get you up and running I’ve created a package for option with configurable logger. Here it is: https://pypi.org/project/django-loggable-util/

And the git repo here: https://github.com/Ruhshan/django-loggable-util

Feel free to check it out, issues and PRs are welcome.

It would be great if you could let me know any gap in my understanding and any better way of doing things.