Details
-
Task
-
Status: In Review (View Workflow)
-
Minor
-
Resolution: Unresolved
-
None
Description
SHOW PROFILE shows that most time is spent for 'sending data' which is confusing as the time is actually shown for executing the query.
Suggestion to fix this:
stage_executing in JOIN::exec_inner should be replace with a new stage "Prepare for executing"
stage_sending_data in JOIN::exec_inner should be replaced with stage_executing
Attachments
Activity
While you are at it, check whether "Opening tables" is bogus: https://stackoverflow.com/questions/31317428/sql-queries-sometimes-slow-show-profile-opening-table-too-long And maybe "creating table": https://stackoverflow.com/questions/76500932/mysql-8-tables-created-too-slowly
svoj, can I trouble you for a review.
I've only changed the commit message from the original PR and pushed the test fixes.
I'm assuming this change is still suitable for main/12.0, I don't think its a new feature (could be wrong), so I'm unsure of the process for it now.
Thanks rjasdfiii;
The profile fora create table on current 12.0
MariaDB [test]> show profile;
|
+------------------------+----------+
|
| Status | Duration |
|
+------------------------+----------+
|
| Starting | 0.000076 |
|
| checking permissions | 0.000008 |
|
| Opening tables | 0.000075 |
|
| After opening tables | 0.000004 |
|
| System lock | 0.000004 |
|
| table lock | 0.000013 |
|
| creating table | 0.000848 |
|
| After create | 0.000014 |
|
| Query end | 0.000005 |
|
| closing tables | 0.000004 |
|
| Unlocking tables | 0.000002 |
|
| closing tables | 0.000002 |
|
| Query end | 0.000005 |
|
| Starting cleanup | 0.000003 |
|
| Freeing items | 0.000005 |
|
| Updating status | 0.000037 |
|
| Reset for next command | 0.000004 |
|
+------------------------+----------+
|
17 rows in set (0.001 sec)
|
> While you are at it, check whether "Opening tables" is bogus: https://stackoverflow.com/questions/31317428/sql-queries-sometimes-slow-show-profile-opening-table-too-long
There's two locations in the code for the "Opening tables". One open_table and the other open_ltable (used by more by system tables).
So by "bogus" is it because "Opening" is implying the table exists rather than being created? Its possible to do a different stage name based on thd->lex->sql_command (SQLCOM_CREATE_TABLE) vs SQLCOM_SELECT. If this is what is wanted can you create a new issue.
> And maybe "creating table": https://stackoverflow.com/questions/76500932/mysql-8-tables-created-too-slowly
Not sure what about "creating table" is bogus. On a IF NOT EXISTS where the table exists the profile is:
MariaDB [test]> crEATE TABLE if not exists t8 (id INT);
|
Query OK, 0 rows affected, 1 warning (0.001 sec)
|
|
|
MariaDB [test]> show profile;
|
+------------------------+----------+
|
| Status | Duration |
|
+------------------------+----------+
|
| Starting | 0.000139 |
|
| checking permissions | 0.000010 |
|
| Opening tables | 0.000100 |
|
| After opening tables | 0.000004 |
|
| closing tables | 0.000007 |
|
| Query end | 0.000004 |
|
| closing tables | 0.000003 |
|
| Query end | 0.000003 |
|
| Starting cleanup | 0.000003 |
|
| Freeing items | 0.000005 |
|
| Updating status | 0.000032 |
|
| Reset for next command | 0.000004 |
|
+------------------------+----------+
|
12 rows in set (0.001 sec)
|
I see the anomaly in Query end, can't explain it at the moment.
updated mtr results and commit message.
mtr test perfschema.processlist_57 disabled so didn't touch this one.
ready to review after checking test pass https://buildbot.mariadb.org/#/grid?branch=refs%2Fpull%2F3594%2Fmerge