Opened 6 months ago
Last modified 4 months ago
#35448 assigned Cleanup/optimization
test --debug-sql SQL formatting is applied to more than the query
Reported by: | Tim Graham | Owned by: | Hana Burtin |
---|---|---|---|
Component: | Testing framework | Version: | dev |
Severity: | Normal | Keywords: | |
Cc: | Triage Stage: | Accepted | |
Has patch: | yes | Needs documentation: | no |
Needs tests: | yes | Patch needs improvement: | yes |
Easy pickings: | no | UI/UX: | no |
Description
Since #34111 (3283120cca5d5eba5c3619612d0de5ad49dcf054), the output of manage.py test --debug-sql
is formatted with sqlparse. Because this log message contains more than SQL (including a prefix with the query's duration as well as a suffix that includes the query parameters and database alias) there are some problems with the output.
For example:
(0.000) SELECT "basic_article"."id", "basic_article"."headline", "basic_article"."pub_date" FROM "basic_article" WHERE "basic_article"."id" = 1 LIMIT 21; args=(1,); alias=default (0.000) SELECT "basic_article"."id", "basic_article"."headline", "basic_article"."pub_date" FROM "basic_article" WHERE "basic_article"."id" = 1 LIMIT 21; args=(1,); alias=default
becomes:
(0.000) SELECT "basic_article"."id", "basic_article"."headline", "basic_article"."pub_date" FROM "basic_article" WHERE "basic_article"."id" = 1 LIMIT 21; args=(1,); ALIAS=DEFAULT (0.000) SELECT "basic_article"."id", "basic_article"."headline", "basic_article"."pub_date" FROM "basic_article" WHERE "basic_article"."id" = 1 LIMIT 21; args=(1,); ALIAS=DEFAULT
"alias=default" is unexpectedly capitalized since these are SQL reserved words. There is also the addition of a newline after the duration but not at the end of the query such that the output from one query runs into the other: "ALIAS=DEFAULT (0.000)".
Change History (18)
comment:1 by , 6 months ago
Triage Stage: | Unreviewed → Accepted |
---|---|
Type: | Bug → Cleanup/optimization |
comment:3 by , 6 months ago
Owner: | changed from | to
---|---|
Status: | new → assigned |
comment:4 by , 6 months ago
Has patch: | set |
---|
comment:5 by , 6 months ago
Patch needs improvement: | set |
---|
comment:6 by , 6 months ago
Patch needs improvement: | unset |
---|
comment:7 by , 6 months ago
I reverted the [commit(3283120)](https://github.com/django/django/commit/3283120cca5d5eba5c3619612d0de5ad49dcf054) to resolving the issue of the ticket
comment:8 by , 6 months ago
Needs tests: | set |
---|---|
Patch needs improvement: | set |
comment:9 by , 6 months ago
Needs tests: | unset |
---|---|
Patch needs improvement: | unset |
follow-up: 11 comment:10 by , 6 months ago
Patch needs improvement: | set |
---|
I don't think we want any solution that involves parsing the output using regular expressions. That's too complicated. Why not format the SQL before it's added to the logging statement in db/backends/utils.py
?
(Incidentally, I'm working on a MongoDB backend for Django and would like to override the formatting since it won't be SQL. If the formatting were done there, I could move the formatting to an overridable DatabaseOperations.format_sql()
hook.)
comment:11 by , 6 months ago
Replying to Tim Graham:
I don't think we want any solution that involves parsing the output using regular expressions. That's too complicated. Why not format the SQL before it's added to the logging statement in
db/backends/utils.py
?
(Incidentally, I'm working on a MongoDB backend for Django and would like to override the formatting since it won't be SQL. If the formatting were done there, I could move the formatting to an overridable
DatabaseOperations.format_sql()
hook.)
I also think the regular expression is complicated. I only applied the part because I was worried that it would also apply to other logs. Am I misunderstanding or missing the overall flow?
comment:12 by , 6 months ago
Owner: | removed |
---|---|
Status: | assigned → new |
comment:13 by , 6 months ago
Has patch: | unset |
---|---|
Patch needs improvement: | unset |
comment:14 by , 6 months ago
Owner: | set to |
---|---|
Status: | new → assigned |
We can set a workaround using the TestCase
log handler and reformat the queries from here.
Preparing a MR
comment:15 by , 6 months ago
Has patch: | set |
---|
comment:16 by , 6 months ago
Triage Stage: | Accepted → Ready for checkin |
---|
comment:17 by , 6 months ago
Triage Stage: | Ready for checkin → Accepted |
---|
A reviewer should advance the ticket to "Ready for checkin," not the patch author.
comment:18 by , 4 months ago
Needs tests: | set |
---|---|
Patch needs improvement: | set |
Thank you Tim. Now that you mention it, I also noticed a weird output when posting in ticket:35381#comment:1 but I did not realize it was caused by the SQL formatting.