Log all SQL queries in Django.

As this part said, we can log all queries in Django with DEBUG=True.

DEBUG option is a global configure item, if we set it True, it will also affect other codes. So it is hard to active it in production environment.

How to get all SQL queries or we want in production? MySQL or database middleware can log these. But for all kinds of limitation, it's better to log it by ourselves.

Here are some methods to log it without active DEBUG option.

Logging Methods

When we set DEBUG with True, we have two places to get queries.
One is in log file, the output like this:

DEBUG 2020-02-21 10:35:12,214 33337 [utils.py:91] (0.036) SELECT @@SQL_AUTO_IS_NULL; args=None
DEBUG 2020-02-21 10:35:12,251 33337 [utils.py:91] (0.036) SELECT VERSION(); args=None

Another one is using Django database connection's 'queries' property(code1, doc1). It stores all queries in one request, and is cleared automatically in here. So we can add a middleware to traverse 'queries' to log all SQLs.

Above two methods can be enabled by set DEBUG with True.

The following part will discuss how to enable database logging function without set DEBUG.

Custom Methods

Enable database logging function.

From codes, we find database logging/recording SQL functions are controlled by 'queries_logged' property. And it is determined by settings.DEBUG and self.force_debug_cursor, the last one is hard-coded without function argument, setting option to set it. Even in subclass, the concrete database backends.

# https://github.com/django/django/blob/3.0.3/django/db/backends/base/base.py#L150

    def queries_logged(self):
        return self.force_debug_cursor or settings.DEBUG

Can we set self.force_debug_cursor with True? Yes, we can.

1. self.force_debug_cursor is BaseDatabaseWrapper object's field, not class's. BaseDatabaseWrapper is base class of all backends' DatabaseWrapper, which are the database connection's class we use in code.
2. Every thread has its own DatabaseWrapper(database connection) object, not a singleton. The following is related code:

class ConnectionHandler:
    
    ...
    
    def __getitem__(self, alias):
        if hasattr(self._connections, alias):
            return getattr(self._connections, alias)

        self.ensure_defaults(alias)
        self.prepare_test_settings(alias)
        db = self.databases[alias]
        backend = load_backend(db['ENGINE'])
        conn = backend.DatabaseWrapper(db, alias)
        setattr(self._connections, alias, conn)
        return conn

ConnectionHandler is the class of django.db.connections. self._connections is a thread local variable. So we can set force_debug_cursor to True in middleware, for each threading's connection object. Like this:

from django.db import connections

class SimpleMiddleware:
    def __init__(self, get_response):
        self.get_response = get_response

    def __call__(self, request):
        # Enable database logging.
        connections['default'].force_debug_cursor = True
        response = self.get_response(request)
        return response

Or if there are other thread scope initialization points, we can also do in there. If you know, please tell me.

Write custom database backend.

Since there are no choice to set force_debug_cursor, how about add a setting method?

Yes, we can. Write a custom database backend:

#  $ tree custom_backend/
#  custom_backend/
#  ├── base.py
#  └── __init__.py

# file: custom_backend/base.py
from django.db.backends.mysql import base

class DatabaseWrapper(base.DatabaseWrapper):
  def __init__(self, *args, **kwargs):
    super().__init__(*args, **kwargs)
    self.force_debug_cursor = True

In settings, use this module to access MySQL service:

DATABASES = {
    'default': {
        'ENGINE': 'common.custom_backend',
        'NAME': 'DATABASE-NAME',
        'USER': 'ACCOUNT',
        ...
    }
}

Same with other database backends.

Hook exist backend.

With previous two methods, we can enable logging SQL into log files and connection.queries variable. This method does not aim to enable someone, but to log by ourselves.

From documents and code, we can find in backend internal it uses cursor object to do fetch operation. code1 code2 doc1 doc2

We can also find Django implements logging function by different wrapper classes for cursor:

# https://github.com/django/django/blob/3.0.3/django/db/backends/base/base.py#L224

    def _prepare_cursor(self, cursor):
        """
        Validate the connection is usable and perform database cursor wrapping.
        """
        self.validate_thread_sharing()
        if self.queries_logged:
            wrapped_cursor = self.make_debug_cursor(cursor)
        else:
            wrapped_cursor = self.make_cursor(cursor)
        return wrapped_cursor

So we can implement our own cursor wrapper class to record anything as we want. And next, how to let Django use our custom cursor wrapper class.

We can also implement a custom database backend and overwrite cursor creator function, like MySQL backend does:

# https://github.com/django/django/blob/3.0.3/django/db/backends/mysql/base.py#L252

    @async_unsafe
    def create_cursor(self, name=None):
        cursor = self.connection.cursor()
        return CursorWrapper(cursor)

Another one is to hook django.db.backends.utils.CursorWrapper class in process scope. Here is a example from django-extensions: link