Performance tracking_mysql provided by the MYSQL5.0 family

The performance tracker provided by the MYSQL5.0 family is really good.
Pay attention to two points.
1. versions later than 5.0.37

(Show profiles and show profile were added in MySQL 5.0.37 .)
Important
Please note that the show profile and show profiles functionality is part of the MySQL 5.0 Community Server only.
2. the variable profiling is the user variable and must be re-enabled each time.
Below are some of my experiments. The data is obvious, so I will not explain it much.
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 |
+ ---------------- +

4 rows in set (0.03 sec)

Mysql> select count (*) from t;
+ ---------- +

| Count (*) |
+ ---------- +

| 1, 2097152 |
+ ---------- +

1 row in set (0.74 sec)

Mysql> show profiles;
+ ---------- + ------------ + ------------------------ +
| Query_ID | Duration | Query |
+ ---------- + ------------ + ------------------------ +
| 1 | 0.02717000 | show tables |
| 1 | 0.74770100 | select count (*) from t |
+ ---------- + ------------ + ------------------------ +
2 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 | 1, 0.000013 |
| Optimizing | 0.000008 |
| Statistics | 0.000013 |
| Preparing | 0.000011 |
| Executing | 0.000006 |
| Sendingdata | 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 |
+ -------------------------------- + ---------- +
17 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 |
+ ------------------------------ + ---------- + ------------ + ---------------- + --------------- +
17 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 |
| 1 | 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 |
+ ---------- + ------------- + ------------------------------------------------ +
4 rows in set (0.00 sec)

Mysql> show profile cpu, block io, memory, swaps for query 4;
+ ---------------------------- + ----------- + ------------ + -------------- + ----------------- + ------- +
| Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | Swaps |
+ ---------------------------- + ----------- + ------------ + -------------- + ----------------- + ------- +
| (Initialization) | 0.000038 | 0 | 0 | 0 | 0 | 0 |
| Checking permissions | 0.000016 | 0 | 0 | 0 | 0 | 0 |
| Opening tables | 0.000014 | 0 | 0 | 0 | 0 | 0 |
| System lock | 0.000007 | 0 | 0 | 0 | 0 | 0 |
| Table lock | 0.000013 | 0 | 0 | 0 | 0 | 0 |
| Init | 0.000015 | 0 | 0 | 0 | 0 | 0 |
| Optimizing | 0.000006 | 0 | 0 | 0 | 0 | 0 |
| Statistics | 0.000012 | 0 | 0 | 0 | 0 | 0 |
| Preparing | 0.000011 | 0 | 0 | 0 | 0 | 0 |
| Creating tmp table | 0.000029 | 0 | 0 | 0 | 0 | 0 |
| Executing | 0.000005 | 0 | 0 | 0 | 0 | 0 |
| Copying to tmp table | 1.262877 | 1.24981 | 0.012998 | 0 | 0 | 0 |
| Converting HEAP to MyISAM | 0.384814 | 0.187971 | 0.19797 | 0 | 0 | 0 |
| Copying to tmp table on disk | 1.417069 | 1.203817 | 0.191971 | 0 | 0 | 0 |
| Sending data | 31.104185 | 13.965877 | 0.843872 | 0 | 0 | 0 |
| End| 0.000017 | 0 | 0 | 0 | 0 | 0 |
| Removing tmp table | 0.134872 | 0 | 0.029995 | 0 | 0 | 0 |
| End| 0.000026 | 0 | 0 | 0 | 0 | 0 |
| Query end | 0.000006 | 0 | 0 | 0 | 0 | 0 |
| Freeing items | 0.000011 | 0 | 0 | 0 | 0 | 0 |
| Closing tables | 0.000009 | 0 | 0 | 0 | 0 | 0 |
| Logging slow query | 0.000049 | 0 | 0 | 0 | 0 | 0 |
+ ---------------------------- + ----------- + ------------ + -------------- + ----------------- + ------- +
22 rows in set (0.00 sec)

Mysql> select count (*) from t;
+ ---------- +
| Count (*) |
+ ---------- +
| 1, 4194304 |
+ ---------- +
1 row in set (1.51 sec)

Mysql> show profiles;
+ ---------- + ------------- + ------------------------------------------------ +
| Query_ID | Duration | Query |
+ ---------- + ------------- + ------------------------------------------------ +
| 1 | 0.02717000 | show tables |
| 1 | 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 |
+ ---------- + ------------- + ------------------------------------------------ +
5 rows in set (0.00 sec)

Mysql> show profile cpu, block io, memory, swaps, context switches, source for query 5;
+ Certificate + ---------- + ------------ + --------------------- + ------------------- + -------------- + --------------- + ------- + certificate + --------------- + ------------- +
| Status | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Swaps | Source_function | Source_file | Source_line |
+ Certificate + ---------- + ------------ + --------------------- + ------------------- + -------------- + --------------- + ------- + certificate + --------------- + ------------- +
| (Initialization) | 0.000004 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | send_result_to_client | SQL _cache.cc| 1099 |
| Checking query cache for query | 0.000048 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | open_tables | SQL _base.cc | 2629 |
| Opening tables | 0.000011 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_lock_tables | lock. cc | 153 |
| System lock | 0.000007 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_lock_tables | lock. cc | 162 |
| Table lock | 0.000032 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_select | SQL _select.cc | 2242 |
| Init | 0.000013 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | optimize | SQL _select.cc | 745 |
| Optimizing | 0.000008 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | optimize | SQL _select.cc | 904 |
| Statistics | 0.000013 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | optimize | SQL _select.cc | 914 |
| Preparing | 0.000011 | 0 | 0 | 0 | 0 | 0 | 0 | exec | SQL _select.cc | 1565 |
| Executing | 0.000006 | 0 | 0 | 0 | 0 | 0 | 0 | exec | SQL _select.cc | 2083 |
| Sending data | 1.505401 | 1.504771 | 0 | 3 | 5 | 0 | 0 | 0 | mysql_select | SQL _select.cc | 2287 |
| End | 0.000015 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_execute_command | SQL _parse.cc | 5122 |
| Query end | 0.000005 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | query_cache_end_of_result | SQL _cache.cc | 729 |
| Storing result in query cache | 0.000007 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_parse | SQL _parse.cc | 6116 |
| Freeing items | 0.00001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | dispatch_command | SQL _parse.cc | 2146 |
| Closing tables | 0.000009 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | log_slow_statement | SQL _parse.cc | 2204 |
| Logging slow query | 0.000038 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | dispatch_command | SQL _parse.cc | 2169 |
+ Certificate + ---------- + ------------ + --------------------- + ------------------- + -------------- + --------------- + ------- + certificate + --------------- + ------------- +
17 rows in set (0.00 sec)
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 |
| 1 | 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' |
+ ---------- + ------------- + ------------------------------------------------ +
6 rows in set (0.00 sec)

Mysql> show profile cpu, block io, memory, swaps, context switches, source for query 6;
+ ---------------------- + ----------- + ------------ + ------------------- + -------------- + --------------- + ------- + --------------- + -------------
| Status | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Swaps | Source_function | Source_file | Source_line |
+ ---------------------- + ----------- + ------------ + ------------------- + -------------- + --------------- + ------- + --------------- + -------------
| (Initialization) | 0.000035 | 0 | 0 | 0 | 0 | 0 | 0 | check_access | SQL _parse.cc | 5306 |
| Checking permissions | 0.000011 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | open_tables | SQL _base.cc | 2629 |
| Opening tables | 0.000011 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_lock_tables | lock. cc | 153 |
| System lock | 0.000007 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_lock_tables | lock. cc | 162 |
| Table lock | 0.000008 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_update | SQL _update.cc | 167 |
| Init | 0.000021 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_update | SQL _update.cc | 429 |
| Updating | 44.514679 | 27.976747 | 2.818571 | 9949 | 1584 | 0 | 0 | mysql_update | SQL _update.cc | 560 |
| End | 0.305671 | 0.028996 | 0.023997 | 43 | 18 | 0 | 0 | 0 | mysql_execute_command | SQL _parse.cc | 5122 |
| Query end | 0.000026 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_parse | SQL _parse.cc | 6116 |
| Freeing items | 0.000016 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | dispatch_command | SQL _parse.cc | 2146 |
| Closing tables | 0.000012 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | log_slow_statement | SQL _parse.cc | 2204 |
| Logging slow query | 0.00005 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | dispatch_command | SQL _parse.cc | 2169 |
+ ---------------------- + ----------- + ------------ + ------------------- + -------------- + --------------- + ------- + --------------- + -------------