#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 [email protected].
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.
