Opened 2 months ago

Last modified 2 days 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 Natalia Bidart, 2 months ago

Triage Stage: UnreviewedAccepted
Type: BugCleanup/optimization

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.

comment:2 by Jae Hyuck Sa , 2 months ago

I'll try to fix it!

comment:3 by Jae Hyuck Sa , 2 months ago

Owner: changed from nobody to Jae Hyuck Sa
Status: newassigned

comment:4 by Jae Hyuck Sa , 2 months ago

Has patch: set

comment:5 by Mariusz Felisiak, 2 months ago

Patch needs improvement: set

comment:6 by Jae Hyuck Sa , 2 months ago

Patch needs improvement: unset

comment:7 by Jae Hyuck Sa , 2 months ago

Last edited 2 months ago by Jae Hyuck Sa (previous) (diff)

comment:8 by Mariusz Felisiak, 2 months ago

Needs tests: set
Patch needs improvement: set

comment:9 by Jae Hyuck Sa , 2 months ago

Needs tests: unset
Patch needs improvement: unset

comment:10 by Tim Graham, 2 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.)

in reply to:  10 comment:11 by Jae Hyuck Sa , 2 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 Jae Hyuck Sa , 2 months ago

Owner: Jae Hyuck Sa removed
Status: assignednew

comment:13 by Jae Hyuck Sa , 2 months ago

Has patch: unset
Patch needs improvement: unset

comment:14 by Hana Burtin, 7 weeks ago

Owner: set to Hana Burtin
Status: newassigned

We can set a workaround using the TestCase log handler and reformat the queries from here.

Preparing a MR

comment:15 by Hana Burtin, 7 weeks ago

Has patch: set

comment:16 by Hana Burtin, 7 weeks ago

Triage Stage: AcceptedReady for checkin

comment:17 by Tim Graham, 7 weeks ago

Triage Stage: Ready for checkinAccepted

A reviewer should advance the ticket to "Ready for checkin," not the patch author.

comment:18 by Sarah Boyce, 2 days ago

Needs tests: set
Patch needs improvement: set
Note: See TracTickets for help on using tickets.
Back to Top