当前位置: 首页 > 图文教程 > 数据库 > MYSQL > Mysql教程:性能跟踪语句

MYSQL
Mysql中mysqldump命令使用详解
常见mysql错误代码详细解析
设置 MySql 数据同步
MySQL集群配置
ASP连接MySQL数据库的方法
linux操作系统下建立mysql镜像数据库
加大MySql的最大连接数
使用"函数递归"实现基于php和MySQL的动态树型菜单
基于MySQL的高性能数据库应用开发
在同一台机器上运行多个MySQL服务器
从MySQL到ORACLE程序迁移的注意事项
安全专家讲解Mysql故障详细的诊断过程
Mysql中日期和时间函数应用不用求人
你可能不知道 Mysql的常用命令收集
您可能不知道 MySQL表最大能达到多少
mysql5中遭遇的字符集问题及其解决方案
教你轻松的掌握 MYSQL连接字符集和校对
快速的掌握可以运行MySQL的操作系统
在服务器上安装使用 MySQL 的注意事项
简简单单掌握对MySQL无效数据的约束

MYSQL 中的 Mysql教程:性能跟踪语句


出处:互联网   整理: 软晨网(RuanChen.com)   发布: 2009-10-30   浏览: 85 ::
收藏到网摘: n/a

原文链接:http://blog.chinaunix.net/u/29134/showart_480834.html

MYSQL5.0家族提供的性能跟踪器确实很爽。
要注意两点。
1、不过版本要在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、变量profiling是用户变量,每次都得重新启用。
以下是我做的一些实验。数据很明显,就不多解释了。
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(*) |
+
----------+

| 2097152 |
+
----------+

1 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 |
+----------+------------+------------------------+
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                           | 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 |
+--------------------------------+----------+
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                                    |
|        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 |
+----------+-------------+------------------------------------------------+
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(*) |
+----------+
|  4194304 |
+----------+
1 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                         |
+----------+-------------+------------------------------------------------+
5 rows in set (0.00 sec)

mysql> show profile cpu,block io,memory,swaps,context switches,source for query 5;
+--------------------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+-------+---------------------------+---------------+-------------+
| 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.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 |     0 | exec                      | sql_select.cc |        1565 |
| executing                      | 0.000006 | 0        | 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 |
+--------------------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+-------+---------------------------+---------------+-------------+
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                                    |
|        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'                |
+----------+-------------+------------------------------------------------+
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 |     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 |     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 |
+----------------------+-----------+-----------+------------+-------------------+---------------------+--------------+---------------+-------+-----------------------+---------------+-------------+
12 rows in set (0.00 sec)