[Django] #36380: SQL is formatted for logging regardless of whether it will be logged

[Django]

#36380: SQL is formatted for logging regardless of whether it will be logged
-------------------------------------+-------------------------------------
               Reporter:  Jacob      |          Owner:  Jacob Walls
  Walls                              |
                   Type:  Bug        |         Status:  assigned
              Component:  Database   |        Version:  dev
  layer (models, ORM)                |
               Severity:  Release    |       Keywords:  debug-sql
  blocker                            |
           Triage Stage:             |      Has patch:  0
  Unreviewed                         |
    Needs documentation:  0          |    Needs tests:  0
Patch needs improvement:  0          |  Easy pickings:  0
                  UI/UX:  0          |
-------------------------------------+-------------------------------------
 I have an endpoint that generates several large SQL strings. It performs
 10x worse (300ms -> 3000ms) on the main branch. Traced it to eager
 formatting of SQL.

 To reproduce, print or throw inside `format_debug_sql()`, and run a
 project without logging queries (i.e. without a `django.db` entry in
 `LOGGING` configured at the `DEBUG` level).

 {{{#!diff
 diff --git a/django/db/backends/base/operations.py
 b/django/db/backends/base/operations.py
 index fea73bc1e4..4c106f59e3 100644
 --- a/django/db/backends/base/operations.py
 +++ b/django/db/backends/base/operations.py
 @@ -791,4 +791,5 @@ class BaseDatabaseOperations:

      def format_debug_sql(self, sql):
          # Hook for backends (e.g. NoSQL) to customize formatting.
 +        print('eager formatting...')
          return sqlparse.format(sql, reindent=True, keyword_case="upper")
 }}}

 Regression in d8f093908c504ae0dbc39d3f5231f7d7920dde37.

 We might want a benchmark in django-asv for views with long SQL strings?

 This fix works for me; I can submit a patch with tests in the next few
 days:

 {{{#!diff
 diff --git a/django/db/backends/utils.py b/django/db/backends/utils.py
 index 568f510a67..ae810ffd12 100644
 --- a/django/db/backends/utils.py
 +++ b/django/db/backends/utils.py
 @@ -10,6 +10,7 @@ from hashlib import md5
  from django.apps import apps
  from django.db import NotSupportedError
  from django.utils.dateparse import parse_time
 +from django.utils.functional import lazy

  logger = logging.getLogger("django.db.backends")

 @@ -151,7 +152,7 @@ class CursorDebugWrapper(CursorWrapper):
              logger.debug(
                  "(%.3f) %s; args=%s; alias=%s",
                  duration,
 -                self.db.ops.format_debug_sql(sql),
 +                lazy(self.db.ops.format_debug_sql)(sql),
                  params,
                  self.db.alias,
                  extra={
 }}}
-- 
Ticket URL: <https://code.djangoproject.com/ticket/36380>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.

-- 
You received this message because you are subscribed to the Google Groups 
"Django updates" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to django-updates+unsubscr...@googlegroups.com.
To view this discussion visit 
https://groups.google.com/d/msgid/django-updates/01070196b638c765-913f0eba-dbdf-40a7-8195-8e66b491986e-000000%40eu-central-1.amazonses.com.