MySQL uses profile to parse SQL execution state

mysql> Use test
Database changed
Mysql> set profiling=1;
Query OK, 0 rows Affected (0.00 sec)

Mysql> Show tables;
+----------------+
| Tables_in_test |
+----------------+
| Bag_item |
| Bag_user |
| Score |
| T |
+----------------+
Rows in Set (0.03 sec)

Mysql> Select COUNT (*) from T;
+----------+
| COUNT (*) |
+----------+
| 2097152 |
+----------+
Row in Set (0.74 sec)

Mysql> Show Profiles;
+----------+------------+------------------------+
| query_id | Duration | Query |
+----------+------------+------------------------+
| 1 | 0.02717000 | Show Tables |
| 2 | 0.74770100 | Select COUNT (*) from T |
+----------+------------+------------------------+
Rows in Set (0.00 sec)

Mysql> Show profile for query 2;
+--------------------------------+----------+
| Status | Duration |
+--------------------------------+----------+
| (initialization) | 0.000004 |
| Checking query cache for Query | 0.000044 |
| Opening Tables | 0.000012 |
| System Lock | 0.000017 |
| Table Lock | 0.00003 |
| init | 0.000013 |
| Optimizing | 0.000008 |
| Statistics | 0.000013 |
| Preparing | 0.000011 |
| Executing | 0.000006 |
| Sending Data | 0.747313 |
| End | 0.000014 |
| Query End | 0.000006 |
| Storing result in query cache | 0.000006 |
| Freeing items | 0.000012 |
| Closing Tables | 0.000009 |
| Logging Slow Query | 0.000183 |
+--------------------------------+----------+
Rows in Set (0.00 sec)

Mysql> Show profile block io,cpu for Query 2;
+--------------------------------+----------+----------+------------+--------------+---------------+
| Status | Duration | Cpu_user | Cpu_system | block_ops_in | Block_ops_out |
+--------------------------------+----------+----------+------------+--------------+---------------+
| (initialization) | 0.000004 | 0 | 0 | 0 | 0 |
| Checking query cache for Query | 0.000044 | 0 | 0 | 0 | 0 |
| Opening Tables | 0.000012 | 0 | 0 | 0 | 0 |
| System Lock | 0.000017 | 0 | 0 | 0 | 0 |
| Table Lock | 0.00003 | 0 | 0 | 0 | 0 |
| init | 0.000013 | 0 | 0 | 0 | 0 |
| Optimizing | 0.000008 | 0 | 0 | 0 | 0 |
| Statistics | 0.000013 | 0 | 0 | 0 | 0 |
| Preparing | 0.000011 | 0 | 0 | 0 | 0 |
| Executing | 0.000006 | 0 | 0 | 0 | 0 |
| Sending Data | 0.747313 | 0.746887 | 0 | 0 | 0 |
| End | 0.000014 | 0 | 0 | 0 | 0 |
| Query End | 0.000006 | 0 | 0 | 0 | 0 |
| Storing result in query cache | 0.000006 | 0 | 0 | 0 | 0 |
| Freeing items | 0.000012 | 0 | 0 | 0 | 0 |
| Closing Tables | 0.000009 | 0 | 0 | 0 | 0 |
| Logging Slow Query | 0.000183 | 0 | 0 | 0 | 0 |
+--------------------------------+----------+----------+------------+--------------+---------------+
Rows in Set (0.00 sec)

mysql> INSERT into T (username) select username from T;
Query OK, 2097152 rows Affected (34.17 sec)
records:2097152 duplicates:0 warnings:0

Mysql> Show Profiles;
+----------+-------------+------------------------------------------------+
| query_id | Duration | Query |
+----------+-------------+------------------------------------------------+
| 1 | 0.02717000 | Show Tables |
| 2 | 0.74770100 | Select COUNT (*) from T |
| 3 | 0.00004200 | Show Prifile for Query 2 |
| 4 | 34.30410100 | INSERT into T (username) select username from T |
+----------+-------------+------------------------------------------------+
Rows in Set (0.00 sec)

Mysql> Show profile Cpu,block io,memory,swaps for query 4;

Mysql> Select COUNT (*) from T;
+----------+
| COUNT (*) |
+----------+
| 4194304 |
+----------+
Row in Set (1.51 sec)

Mysql> Show Profiles;
+----------+-------------+------------------------------------------------+
| query_id | Duration | Query |
+----------+-------------+------------------------------------------------+
| 1 | 0.02717000 | Show Tables |
| 2 | 0.74770100 | Select COUNT (*) from T |
| 3 | 0.00004200 | Show Prifile for Query 2 |
| 4 | 34.30410100 | INSERT into T (username) select username from T |
| 5 | 1.50563800 | Select COUNT (*) from T |
+----------+-------------+------------------------------------------------+
Rows in Set (0.00 sec)

Mysql> Show Profile Cpu,block io,memory,swaps,context switches,source for query 5;
......
Mysql> Update t set username = ' Waill ';
Query OK, 4194304 rows Affected (44.82 sec)
Rows matched:4194304 changed:4194304 warnings:0

Mysql> Show Profiles;
+----------+-------------+------------------------------------------------+
| query_id | Duration | Query |
+----------+-------------+------------------------------------------------+
| 1 | 0.02717000 | Show Tables |
| 2 | 0.74770100 | Select COUNT (*) from T |
| 3 | 0.00004200 | Show Prifile for Query 2 |
| 4 | 34.30410100 | INSERT into T (username) select username from T |
| 5 | 1.50563800 | Select COUNT (*) from T |
| 6 | 44.82054700 | Update T set username = ' Waill ' |
+----------+-------------+------------------------------------------------+
Rows in Set (0.00 sec)

Mysql> Show Profile Cpu,block io,memory,swaps,context switches,source for query 6;

Reprint: http://hi.baidu.com/chssheng2007/blog/item/a97888b3e8ac0ebfd9335aae.html

MySQL uses profile to parse SQL execution state