Log SQL queries even if DEBUG=False

Question

This is my logging config in settings.py

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
        },
        'file': {
            'class': 'logging.FileHandler',
            'filename': os.path.join(BASE_DIR, 'logs', 'django.log'),
        },
    },
    'loggers': {
        'django': {
            'handlers': ['file', 'console'],
            'level': 'DEBUG',
        },
        'django.template': {
            'handlers': ['file', 'console'],
            'level': 'INFO',
        },
        'App': {
            'handlers': ['file', 'console'],
            'level': 'DEBUG',
        },
    },
}

There's a behavior that I can't explain: if I run with debug=True I can see all SQL queries being logged to the console, but when debug=False that doesn't happen, even if I don't change the configuration above.

Why is this? How can I determine in my logging config whether or not SQL queries are logged to the console?

Swadeshi

Answer 1

That's because existing loggers already filtered your logs. In this case is Django's logger.

DEFAULT_LOGGING = {
    'filters': {
        'require_debug_true': {
            '()': 'django.utils.log.RequireDebugTrue',
        },
    },
    'handlers': {
        'console': {
            'level': 'INFO',
            'filters': ['require_debug_true'],
            'class': 'logging.StreamHandler',
        },
    ...
}

and django.utils.log.RequireDebugTrue

class RequireDebugTrue(logging.Filter):
    def filter(self, record):
        return settings.DEBUG

To solve this issue, you could disable existing loggers by set disable_existing_loggers: True or you can override the filter like so:

LOGGING = {
    ...
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'filters': [],
        },
    ...
}

Kemppe

Answer 2

Query logging goes way deeper as Django wraps the database cursor based on the truthiness of a computed property.

From Line 226, django.db.backends.base.base v2.2.6 sources

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

This computed property gets to be decided on where debugging is forced or debugging is enabled in project settings

From Line 149, django.db.backends.base.base v2.2.6 sources

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

You should be able to get a proxy to the default connection and force the debug cursor to be used.

from django.db import connection

connection.force_debug_cursor = True

I however advise against this approach and favor query audits in the database.

Robyn

Following up a few years later - setting force_debug_cursor can be extremely useful if debugging an integration test failure, as you can set it and unset it around the single e.g. django.test.Client.post() call that is failing. – Actino

Answer 3

Step 1: Write patch_django function in patchers.py

# Created by [email protected] at 2022/6/6
import importlib
import importlib.util
import sys


# noinspection DuplicatedCode
def patch_module(module_name, modification_func):
    spec = importlib.util.find_spec(module_name)
    source = spec.loader.get_source(module_name)
    source = modification_func(source)
    module = importlib.util.module_from_spec(spec)
    code = compile(source, module.__spec__.origin, 'exec')
    exec(code, module.__dict__)
    sys.modules[module_name] = module
    return module


def patch_django():
    patch_module("django.db.backends.base.base", lambda x: x.replace(
        "self.force_debug_cursor = False",
        "self.force_debug_cursor = True"))

Step2: Call patch_django before django imported.

manage.py

__import__("importlib").import_module("patchers").patch_django()  # noqa
import os
import sys


def main():
    os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'mysite.settings')
    try:
        from django.core.management import execute_from_command_line
    except ImportError as exc:
        raise ImportError(
            "Couldn't import Django. Are you sure it's installed and "
            "available on your PYTHONPATH environment variable? Did you "
            "forget to activate a virtual environment?"
        ) from exc
    execute_from_command_line(sys.argv)


if __name__ == '__main__':
    main()

wsgi.py

__import__("importlib").import_module("patchers").patch_django()  # noqa
import os

from django.core.wsgi import get_wsgi_application

os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'mysite.settings')

application = get_wsgi_application()

asgi.py

__import__("importlib").import_module("patchers").patch_django()  # noqa
import os

from django.core.asgi import get_asgi_application

os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'mysite.settings')

application = get_asgi_application()

Step 3: Make sure django.db.backends is in debug level

        'django.db.backends': {
            'level': 'DEBUG',
        },

Enarthrosis