Django logging missing while testing through the interactive shell

Using Django Using the ORM
1

We added the below snippet to the file settings.py to show the SQL queries on the console. And as a proof of concept, we are following the online tutorial to build a testing project.

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
        },
    },
    'loggers': {
        'django.db.backends': {
            'level': 'DEBUG',
            'handlers': ['console'],
        }
    },
}

At the step of “Explore the free admin functionality”, for example, the console SQL logging works as expected. So, when clicking on the button, we see sample SQL logs like the one attached below.

However, using the interactive shell through the command python manage.py shell and calling python commands like Choice.objects.filter(question__pub_date__year=current_year), we did not see any SQL log.

We wonder if we missed anything for the backend logging on the interactive shell.

We are testing with Django v3.1.4 and Python v3.7.6. Just let us know if you need more details.

Sample Django backend logging records:

...
(0.000) SELECT "django_session"."session_key", "django_session"."session_data", "django_session"."expire_date" FROM "django_session" WHERE ("django_session"."expire_date" > '2022-11-21 23:03:45.762894' AND "django_session"."session_key" = 'dd9uy7q873cijz0603l5uu9zl3wujr2f') LIMIT 21; args=('2022-11-21 23:03:45.762894', 'dd9uy7q873cijz0603l5uu9zl3wujr2f')
(0.000) SELECT "auth_user"."id", "auth_user"."password", "auth_user"."last_login", "auth_user"."is_superuser", "auth_user"."username", "auth_user"."first_name", "auth_user"."last_name", "auth_user"."email", "auth_user"."is_staff", "auth_user"."is_active", "auth_user"."date_joined" FROM "auth_user" WHERE "auth_user"."id" = 1 LIMIT 21; args=(1,)
(0.000) BEGIN; args=None
(0.000) SELECT "polls_question"."id", "polls_question"."question_text", "polls_question"."pub_date" FROM "polls_question" WHERE "polls_question"."id" = 1 LIMIT 21; args=(1,)
[21/Nov/2022 23:03:45] "GET /admin/polls/question/1/change/ HTTP/1.1" 200 6693
(0.000) SELECT "django_session"."session_key", "django_session"."session_data", "django_session"."expire_date" FROM "django_session" WHERE ("django_session"."expire_date" > '2022-11-21 23:03:45.897163' AND "django_session"."session_key" = 'dd9uy7q873cijz0603l5uu9zl3wujr2f') LIMIT 21; args=('2022-11-21 23:03:45.897163', 'dd9uy7q873cijz0603l5uu9zl3wujr2f')
(0.000) SELECT "auth_user"."id", "auth_user"."password", "auth_user"."last_login", "auth_user"."is_superuser", "auth_user"."username", "auth_user"."first_name", "auth_user"."last_name", "auth_user"."email", "auth_user"."is_staff", "auth_user"."is_active", "auth_user"."date_joined" FROM "auth_user" WHERE "auth_user"."id" = 1 LIMIT 21; args=(1,)
[21/Nov/2022 23:03:45] "GET /admin/jsi18n/ HTTP/1.1" 200 3187
...
2

Just for clarification, issuing the command:

Does not result in a query being issued. Django querysets are lazy. Unless you cause that queryset to be executed, no SQL is sent to the database.

You would need to do something like:
list(Choice.objects.filter(question__pub_date__year=current_year))
to force the queryset to be resolved.

1 Like
3

Django’s QuerySet follows a lazy approach, so the SQL query waits until the program accesses the data. Also, the shell does not have the statements to create a logger object, so we need to follow this blog post about Django enables SQL to debug logging in shell:

Start the Django shell:

python manage.py shell

Paste this into your shell:

import logging
log = logging.getLogger('django.db.backends')
log.setLevel(logging. DEBUG)
log.addHandler(logging.StreamHandler())