MySQL tutorial on using profile to query performance

MYSQL's profiling functionality cannot be used until Mysql version 5.0.37 or above.

Check to see if profile is on

mysql> show variables like '%profil%';

+------------------------+-------+
| Variable_name     | Value |
+------------------------+-------+
| profiling       | OFF  |     -- open SQL Statement profiling                          
| profiling_history_size | 15  |     -- Set the reserve profiling The default is 15 , the range of 0 to 100 for 0 When will disable profiling
+------------------------+-------+
2 rows in set (0.00 sec)

Open based on session level

mysql> set profiling = 1;     -- Close by set profiling = off

Query OK, 0 rows affected (0.00 sec)

mysql> select distinct d.account,a.server_id from tab_appserver_user a
  -> inner join tab_department_parent b on a.key_id = b.parent_id
  -> inner join tab_department_member c on b.department_id = c.department_id and c.state=1
  -> and c.isdefault=1 inner join tab_user_info d on c.user_id = d.user_id and d.state=1
  -> where a.type=1 
  -> union          
  -> select distinct b.account,a.server_id from tab_appserver_user a
  -> inner join tab_user_info b on a.key_id = b.user_id and b.state=1
  -> where a.type=0;

Check if the Settings are in effect:

select @@profiling;

Default is 0, set success is 1

Run the SQL statement:

mysql> select * FROM hx_line WHERE id = '1455023';

Check the profiles

mysql> show profiles;

+----------+------------+---------------------------------------------+
| Query_ID | Duration  | Query                    |
+----------+------------+---------------------------------------------+
|    1 | 0.00036150 | select * FROM hx_line WHERE id = '1455023' |
+----------+------------+---------------------------------------------+

See profile for a specific item

mysql> show profile FOR QUERY 1;

+------------------------+-------+
| Variable_name     | Value |
+------------------------+-------+
| profiling       | OFF  |     -- open SQL Statement profiling                          
| profiling_history_size | 15  |     -- Set the reserve profiling The default is 15 , the range of 0 to 100 for 0 When will disable profiling
+------------------------+-------+
2 rows in set (0.00 sec)

0

We see a simple query with MYSQL doing 24 operations internally.
In addition, I see the operation of 1 heap query cache, try to turn query_cache_size=0, turn off query_cache, and test again:

+------------------------+-------+
| Variable_name     | Value |
+------------------------+-------+
| profiling       | OFF  |     -- open SQL Statement profiling                          
| profiling_history_size | 15  |     -- Set the reserve profiling The default is 15 , the range of 0 to 100 for 0 When will disable profiling
+------------------------+-------+
2 rows in set (0.00 sec)

1

+------------------------+-------+
| Variable_name     | Value |
+------------------------+-------+
| profiling       | OFF  |     -- open SQL Statement profiling                          
| profiling_history_size | 15  |     -- Set the reserve profiling The default is 15 , the range of 0 to 100 for 0 When will disable profiling
+------------------------+-------+
2 rows in set (0.00 sec)

2

When query_cache is turned on, it takes 6 more operations, 0.000087s more in this example.

Query the usage of this statement for CPU:

mysql> show profile cpu FOR QUERY 1;

+------------------------+-------+
| Variable_name     | Value |
+------------------------+-------+
| profiling       | OFF  |     -- open SQL Statement profiling                          
| profiling_history_size | 15  |     -- Set the reserve profiling The default is 15 , the range of 0 to 100 for 0 When will disable profiling
+------------------------+-------+
2 rows in set (0.00 sec)

4

View consumption of io and cpu

+------------------------+-------+
| Variable_name     | Value |
+------------------------+-------+
| profiling       | OFF  |     -- open SQL Statement profiling                          
| profiling_history_size | 15  |     -- Set the reserve profiling The default is 15 , the range of 0 to 100 for 0 When will disable profiling
+------------------------+-------+
2 rows in set (0.00 sec)

5

+------------------------+-------+
| Variable_name     | Value |
+------------------------+-------+
| profiling       | OFF  |     -- open SQL Statement profiling                          
| profiling_history_size | 15  |     -- Set the reserve profiling The default is 15 , the range of 0 to 100 for 0 When will disable profiling
+------------------------+-------+
2 rows in set (0.00 sec)

6

Use a query statement to sort the consumption

+------------------------+-------+
| Variable_name     | Value |
+------------------------+-------+
| profiling       | OFF  |     -- open SQL Statement profiling                          
| profiling_history_size | 15  |     -- Set the reserve profiling The default is 15 , the range of 0 to 100 for 0 When will disable profiling
+------------------------+-------+
2 rows in set (0.00 sec)

7

+--------------------------------+----------+-------+-------+--------------+
| STATE             | Total_R | Pct_R | Calls | R/Call    |
+--------------------------------+----------+-------+-------+--------------+
| Copying to tmp table      | 0.704931 | 81.26 |   2 | 0.3524655000 |
| Sending data          | 0.154089 | 17.76 |   6 | 0.0256815000 |
| removing tmp table       | 0.006735 | 0.78 |   3 | 0.0022450000 |
| Opening tables         | 0.000963 | 0.11 |   1 | 0.0009630000 |
| Creating tmp table       | 0.000197 | 0.02 |   2 | 0.0000985000 |
| Table lock           | 0.000169 | 0.02 |   1 | 0.0001690000 |
| freeing items         | 0.000144 | 0.02 |   1 | 0.0001440000 |
| checking query cache for query | 0.000099 | 0.01 |   1 | 0.0000990000 |
| statistics           | 0.000061 | 0.01 |   3 | 0.0000203333 |
| optimizing           | 0.000053 | 0.01 |   3 | 0.0000176667 |
| preparing           | 0.000043 | 0.00 |   3 | 0.0000143333 |
| starting            | 0.000018 | 0.00 |   1 | 0.0000180000 |
| System lock          | 0.000015 | 0.00 |   1 | 0.0000150000 |
| storing result in query cache | 0.000011 | 0.00 |   1 | 0.0000110000 |
| executing           | 0.000008 | 0.00 |   3 | 0.0000026667 |
| cleaning up          | 0.000006 | 0.00 |   1 | 0.0000060000 |
| logging slow query       | 0.000003 | 0.00 |   1 | 0.0000030000 |
| query end           | 0.000003 | 0.00 |   1 | 0.0000030000 |
+--------------------------------+----------+-------+-------+--------------+
18 rows in set (0.01 sec)

show profile additional commands:
* ALL - displays all information
* BLOCK IO - displays counts for block input and output Operations
* CONTEXT SWITCHES - displays counts for voluntary and involuntary context switches
* ipC - displays counts for messages sent and received
* MEMORY - is not currently implemented
* PAGE FAULTS - displays counts for major and minor page faults
* SOURCE - displays the names of functions from the source code, together with the name and line number of the file in which the function occurs
* SWAPS - displays swap counts

Finally, profile is a very quantitative sub-index, which can be used to compare the consumption of various resources according to these quantitative indicators, which is conducive to our overall control of the statement!