Mysql Operations Tutorial using profile query performance _mysql

MySQL's profiling feature should be used in MySQL version 5.0.37.

See if profile is open

Mysql> Show variables like '%profil% ';

+------------------------+-------+
| Variable_name     | Value |
+------------------------+-------+
| profiling       | Off  |     --Open SQL statement profiling function |                         
profiling_history_size |     --Set the number of reserved profiling, the default is 15, range is 0 to 100, 0 o'clock will disable profiling
+------------------------+-------+
2 rows in Set (0.00 Sec

Open based on session level

mysql> Set profiling = 1;     --close with 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;

To see if the settings are valid:

SELECT @ @profiling;

Default is 0, set success is 1

To run the SQL statement:

Mysql> SELECT * from hx_line WHERE id = ' 1455023 ';

View Profiles

Mysql> Show Profiles;

+----------+------------+---------------------------------------------+
| query_id | Duration  | Query                    |
+----------+------------+---------------------------------------------+
|    1 | 0.00036150 | SELECT * FROM hx_line WHERE id = ' 1455023 ' |
+----------+------------+---------------------------------------------+

View the profile of a specific article

Mysql> Show profiles for QUERY 1;

+--------------------------------+----------+
| Status |
Duration | +--------------------------------+----------+
| Starting | 0.000013 | | Waiting for query Cache lock | 0.000014 | | Checking query cache for Query | 0.000038 | | Checking Permissions | 0.000006 | | Opening Tables | 0.000013 | | System Lock | 0.000009 | | Waiting for query Cache lock | 0.000024 | | init | 0.000060 | | Optimizing | 0.000014 | | Statistics | 0.000046 | | Preparing | 0.000017 | | Executing | 0.000004 | | Sending Data | 0.000081 | | End | 0.000005 | | Query End | 0.000004 | | Closing Tables | 0.000008 | | Freeing items | 0.000009 | | Waiting for query Cache lock | 0.000003 | | Freeing items | 0.000013 | | Waiting for query Cache lock | 0.000003 | | Freeing items | 0.000003 | | Storing result in query cache | 0.000005 | |    Logging Slow Query   | 0.000003 | | Cleaning Up |
0.000004 |

 +--------------------------------+----------+ rows

We see a simple query that MySQL has done 24 times inside the operation.
In addition, see a bunch of query cache operation, try to put query_cache_size=0, Query_cache closed, again test:

Mysql> Show profiles for QUERY 1;

+----------------------+----------+
| Status        | Duration |
+----------------------+----------+
| starting |       0.000040 |
| checking permissions | 0.000007 |
| Opening Tables    | 0.000015 |
| System lock     | 0.000010 |
| init         | 0.000061 |
| optimizing      | 0.000013 |
| statistics      | 0.000059 |
| Preparing      | 0.000018 | |
| executing |      0.000004
| | Sending Data     | 0.000092 |
| | end         | 0.000006 | | | |
closing Tables    | 0.000008 |
| Freeing Items    | 0.000020 |
| logging slow Query  | 0.000003 |
| cleaning up     | 0.000004 |
+----------------------+----------+
rows in Set (0.00 sec)

When the Query_cache is turned on, you need to operate 6 more times, and in this example, 0.000087s is much more.

Query the CPU usage of this statement:

Mysql> Show Profiles CPU for QUERY 1;

+----------------------+----------+----------+------------+
| Status | Duration | Cpu_user |
Cpu_system | +----------------------+----------+----------+------------+
| Starting | 0.000037 |  0.000000 | 0.000000 | | Checking Permissions | 0.000009 |  0.000000 | 0.000000 | | Opening Tables | 0.000014 |  0.000000 | 0.000000 | | System Lock | 0.000009 |  0.000000 | 0.000000 | | init | 0.000059 |  0.000000 | 0.000000 | | Optimizing | 0.000009 |  0.000000 | 0.000000 | | Statistics | 0.000044 |  0.000000 | 0.000000 | | Preparing | 0.000015 |  0.000000 | 0.000000 | | Executing | 0.000004 |  0.000000 | 0.000000 | | Sending Data | 0.000081 |  0.000000 | 0.000000 | | End | 0.000006 |  0.000000 | 0.000000 | | Query End | 0.000004 |  0.000000 | 0.000000 | | Closing Tables | 0.000008 |  0.000000 | 0.000000 | | Freeing items | 0.000021 |  0.000000 | 0.000000 | | Logging Slow Query | 0.000004 |  0.000000 | 0.000000 | | Cleaning uP | 0.000004 |  0.000000 |
0.000000 |

 +----------------------+----------+----------+------------+

View IO and CPU consumption

Mysql> Show profile blocks io,cpu for query 1;

+--------------------------------+----------+----------+------------+--------------+---------------+
| Status | Duration | Cpu_user | Cpu_system | block_ops_in |
Block_ops_out | +--------------------------------+----------+----------+------------+--------------+---------------+
| Starting |   0.000018 |    NULL |     NULL |     NULL | NULL | | Checking query cache for Query |   0.000099 |    NULL |     NULL |     NULL | NULL | | Opening Tables |   0.000963 |    NULL |     NULL |     NULL | NULL | | System Lock |   0.000015 |    NULL |     NULL |     NULL | NULL | | Table Lock |   0.000169 |    NULL |     NULL |     NULL | NULL | | Optimizing |   0.000020 |    NULL |     NULL |     NULL | NULL | | Statistics |   0.000027 |    NULL |     NULL |     NULL | NULL | | Preparing |   0.000018 |    NULL |     NULL |     NULL | NULL | | Creating TMP Table |   0.000055 |    NULL |     NULL |     NULL | NULL | | Executing |   0.000003 |    NULL |     NULL |     NULL | NULL | | Copying to TMP table |   0.704845 |    NULL |     NULL |     NULL | NULL | | Sending Data |   0.130039 |    NULL |     NULL |     NULL | NULL | | Optimizing |   0.000029 |    NULL |     NULL |     NULL | NULL | | Statistics |   0.000029 |    NULL |     NULL |     NULL | NULL | | Preparing |   0.000020 |    NULL |     NULL |     NULL | NULL | | Creating TMP Table |   0.000142 |    NULL |     NULL |     NULL | NULL | | Executing |   0.000003 |    NULL |     NULL |     NULL | NULL | | Copying to TMP table |   0.000086 |    NULL |     NULL |     NULL | NULL | | Sending Data |   0.000067 |    NULL |     NULL |     NULL | NULL | | Optimizing |   0.000004 |    NULL |     NULL |     NULL | NULL | | Statistics |   0.000005 |    NULL |     NULL |     NULL | NULL | | Preparing |   0.000005 |    NULL |     NULL | NULL |     NULL | | Executing |   0.000002 |    NULL |     NULL |     NULL | NULL | | Sending Data |   0.023963 |    NULL |     NULL |     NULL | NULL | | removing TMP table |   0.003420 |    NULL |     NULL |     NULL | NULL | | Sending Data |   0.000005 |    NULL |     NULL |     NULL | NULL | | removing TMP table |   0.003308 |    NULL |     NULL |     NULL | NULL | | Sending Data |   0.000006 |    NULL |     NULL |     NULL | NULL | | removing TMP table |   0.000007 |    NULL |     NULL |     NULL | NULL | | Sending Data |   0.000009 |    NULL |     NULL |     NULL | NULL | | Query End |   0.000003 |    NULL |     NULL |     NULL | NULL | | Freeing items |   0.000144 |    NULL |     NULL |     NULL | NULL | | Storing result in query cache |   0.000011 |    NULL |     NULL |     NULL | NULL | | Logging Slow Query |   0.000003 |    NULL |     NULL |     NULL | NULL | | Cleaning Up | 0.000006 |  NULL |     NULL |     NULL |
NULL | +--------------------------------+----------+----------+------------+--------------+---------------+ rows in

 Set (0.00 sec)

Use query statements to sort consumption

mysql> SELECT State, SUM (DURATION) as Total_r,round (DURATION)/(SE
CT sum (DURATION)
  -> from INFO Rmation_schema. PROFILING WHERE query_id = 1), 2) as Pct_r, CO
T (*) as Calls,sum (DURATION)/COUNT (*) as "R/call"
  -> from Infor Mation_schema. PROFILING WHERE query_id = 1 GROUP by state O
ER by Total_r DESC;

+--------------------------------+----------+-------+-------+--------------+
| 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 |

 +--------------------------------+----------+-------+-------+--------------+ rows in Set (0.01 sec)

Show Profile extra 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 WHI CH The function occurs
* Swaps-displays swap Counts

Finally: Profile is a very quantitative sub-standard, can be based on these quantitative indicators to compare the consumption of various resources, conducive to our overall control of the sentence!