zoukankan      html  css  js  c++  java
  • 慢查询日志分析和mysqldumpslow


    登录客户的数据库服务器查看慢查询日志,用于排查压力测试中响应时间较慢的sql语句。Mysql的慢日志是个ascii文件,可以直接用less等命令查看。
    [root@CC-DB1 ~]# tail -n 1000 /var/lib/mysql/CC-DB1-slow.log|less
    # Time: 140401 21:05:04
    # User@Host: root[root] @ localhost []
    # Query_time: 24.344446 Lock_time: 0.000048 Rows_sent: 0 Rows_examined: 0
    SET timestamp=1396357504;
    call p_insert();
    # Time: 140401 21:09:13
    # User@Host: root[root] @ [10.5.28.181]
    # Query_time: 11.530267 Lock_time: 0.000084 Rows_sent: 1 Rows_examined: 502693
    SET timestamp=1396357753;
    select count(distinct customer0_.CUSTOMER_NO) as x0_0_ from TBL_CUSTOMER customer0_ where (customer0_.CUSTOMER_TYPE='200164' );
    # Time: 140401 21:09:46
    # User@Host: root[root] @ [10.5.28.181]
    # Query_time: 11.921468 Lock_time: 0.000081 Rows_sent: 1 Rows_examined: 503963
    SET timestamp=1396357786;
    select count(distinct customer0_.CUSTOMER_NO) as x0_0_ from TBL_CUSTOMER customer0_ where (customer0_.CUSTOMER_TYPE='200164' );
    # Time: 140401 21:09:59
    # User@Host: root[root] @ [10.5.28.181]
    # Query_time: 16.455297 Lock_time: 0.000106 Rows_sent: 1 Rows_examined: 504024
    SET timestamp=1396357799;
    select count(distinct customer0_.CUSTOMER_NO) as x0_0_ from TBL_CUSTOMER customer0_ where (customer0_.CUSTOMER_TYPE='200164' );
    。。。

    对部分信息进行说明:
    # Time: 140401 21:09:59表示query语句的执行时间
    # User@Host: root[root] @ [10.5.28.181]表示执行query语句的client用户名和主机地址
    # Query_time: 16.455297 Lock_time: 0.000106 Rows_sent: 1 Rows_examined: 504024
    其中query_time表示query语句的执行时间,但是为秒,lock time是锁定的时间,rows_sent是query语句执行返回的记录数,而rows_examined则是优化器估算的扫描行数
    下面还包括的是时间戳和具体的query语句

    Mysql会对所有的query进行分析,当满足记录慢查询日志的条件的query语句则会记录到慢查询日志中,具体控制慢查询日志开发的相关参数如下:
    mysql> show variables like '%slow%';
    +---------------------+--------------------------------+
    | Variable_name | Value |
    +---------------------+--------------------------------+
    | log_slow_queries | ON |
    | slow_launch_time | 2 |
    | slow_query_log | ON |
    | slow_query_log_file | /var/lib/mysql/CC-DB1-slow.log |
    +---------------------+--------------------------------+
    4 rows in set (0.00 sec)

    其中slow_query_log控制是否启用慢查询日志,log_slow_queries指定日志文件存储位置,可以为空,slow_query_log_file慢查询日志的文件位置。

    mysql> show variables like 'long_query_time';
    +-----------------+-----------+
    | Variable_name | Value |
    +-----------------+-----------+
    | long_query_time | 10.000000 |
    +-----------------+-----------+
    1 row in set (0.00 sec)

    Long_query_time是控制query是否满足记录到slow query log中,当query执行时间大于等于long_query_time时,则会记录slow query log日志中。

    除此之外mysql的另一个参数log_queries_not_using_indexes还可以控制不启用索引的query语句记录到slow query log中,该参数默认是1,表示不启用索引的query都会记录到slow query log中,小鱼为了slow query log信息尽量简明清晰,一般都将这个参数修改为0.
    mysql> show variables like 'log_queries_not_using_indexes' ;
    +-------------------------------+-------+
    | Variable_name | Value |
    +-------------------------------+-------+
    | log_queries_not_using_indexes | OFF |
    +-------------------------------+-------+
    1 row in set (0.00 sec)

    Mysql也提供一个可执行文件mysqldumpslow来查看mysql的满查询日志
    [root@CC-DB1 ~]# mysqldumpslow --help
    Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]

    Parse and summarize the MySQL slow query log. Options are

    --verbose verbose
    --debug debug
    --help write this text to standard output

    -v verbose
    -d debug
    -s ORDER what to sort by (al, at, ar, c, l, r, t), 'at' is default
    al: average lock time
    ar: average rows sent
    at: average query time
    c: count
    l: lock time
    r: rows sent
    t: query time
    -r reverse the sort order (largest last instead of first)
    -t NUM just show the top n queries
    -a don't abstract all numbers to N and strings to 'S'
    -n NUM abstract numbers with at least n digits within names
    -g PATTERN grep: only consider stmts that include this string
    -h HOSTNAME hostname of db server for *-slow.log filename (can be wildcard),
    default is '*', i.e. match all
    -i NAME name of server instance (if using mysql.server startup script)
    -l don't subtract lock time from total time

    比如我们要查看慢查询日志中,最消耗时间的10条sql语句:
    [root@CC-DB1 ~]# mysqldumpslow -v -s t -t 10 /var/lib/mysql/CC-DB1-slow.log
    返回返回数据最多的10条sql语句:
    [root@CC-DB1 ~]# mysqldumpslow -v -s r -t 10 /var/lib/mysql/CC-DB1-slow.log
    这里还有一个参数-g可以用于过滤出我们需要的query语句,比如过滤出某些表
    [root@CC-DB1 ~]# mysqldumpslow -v -s at -t 10 -g "tbl_customer" /var/lib/mysql/CC-DB1-slow.log
    。。。
    Count: 843 Time=27.35s (23056s) Lock=0.04s (32s) Rows=1.0 (843), 2users@10hosts
    select count(distinct customer0_.CUSTOMER_NO) as x0_0_ from TBL_CUSTOMER customer0_ where (customer0_.CUSTOMER_TYPE='S' )

    Count: 1 Time=23.99s (23s) Lock=0.00s (0s) Rows=0.0 (0), root[root]@[116.228.62.230]
    DELETE FROM `tbl_customer`

    其中的count表示执行次数,time分别表示单次执行的时间和总共执行消耗的时间,lock表示锁定的时间,rows表示返回的行数信息。

    顺便查看了一下漫日志的大小,发觉已经有800多m了
    [root@CC-DB1 mysql]# ls -lh /var/lib/mysql/CC-DB1-slow.log
    -rw-rw---- 1 mysql mysql 818M Apr 2 15:11 /var/lib/mysql/CC-DB1-slow.log

    根据需求看是否需要mv备份下
    [root@CC-DB1 mysql]# mv /var/lib/mysql/CC-DB1-slow.log /var/lib/mysql/CC-DB1-slow.log.bak

    [root@CC-DB1 mysql]# mysqladmin --help

    flush-hosts Flush all cached hosts
    flush-logs Flush all logs
    flush-status Clear status variables
    flush-tables Flush all tables
    flush-threads Flush the thread cache
    flush-privileges Reload grant tables (same as reload)

    mysqladmin有个参数flush-logs用于刷新所有的日志
    [root@CC-DB1 mysql]# mysqladmin -uroot -phollycrm flush-logs

    刷新后发觉漫日志已经重新开始生成,
    [root@CC-DB1 mysql]# ls -lh /var/lib/mysql/CC-DB1-slow.log.bak
    -rw-rw---- 1 mysql mysql 818M Apr 2 15:11 /var/lib/mysql/CC-DB1-slow.log.bak

    同样flush-logs还会重新生成新的binlog
    [root@CC-DB1 mysql]# ls -lh /var/lib/mysql/CC-DB1-slow.log
    -rw-rw---- 1 mysql mysql 183 Apr 2 15:34 /var/lib/mysql/CC-DB1-slow.log

    [root@CC-DB1 mysql]# ls -lh /var/lib/mysql/|grep mysql-bin
    -rw-rw---- 1 mysql mysql 29K Nov 22 23:33 mysql-bin.000001
    -rw-rw---- 1 mysql mysql 1.1M Nov 22 23:33 mysql-bin.000002
    -rw-rw---- 1 mysql mysql 46M Nov 29 15:09 mysql-bin.000003
    -rw-rw---- 1 mysql mysql 639K Dec 5 13:11 mysql-bin.000004
    -rw-rw---- 1 mysql mysql 420K Dec 9 11:04 mysql-bin.000005
    -rw-rw---- 1 mysql mysql 4.7K Dec 9 11:32 mysql-bin.000006
    -rw-rw---- 1 mysql mysql 23K Dec 9 16:56 mysql-bin.000007
    -rw-rw---- 1 mysql mysql 1.1G Jan 16 22:49 mysql-bin.000008
    -rw-rw---- 1 mysql mysql 310M Jan 17 11:13 mysql-bin.000009
    -rw-rw---- 1 mysql mysql 37K Jan 17 11:30 mysql-bin.000010
    -rw-rw---- 1 mysql mysql 1.1G Apr 1 20:34 mysql-bin.000011
    -rw-rw---- 1 mysql mysql 592M Apr 2 15:34 mysql-bin.000012
    -rw-rw---- 1 mysql mysql 34K Apr 2 15:37 mysql-bin.000013
    -rw-rw---- 1 mysql mysql 416 Apr 2 15:34 mysql-bin.index

    此文转:http://www.dbaxiaoyu.com/archives/1904

    快乐生活每一天
  • 相关阅读:
    关于CoreData的使用
    【转】向iOS开发者介绍C++(-)
    Storyboard里面的几种Segue区别及视图的切换:push,modal,popover,replace和custom
    【转】Object-C 多线程中锁的使用-NSLock
    写了半天的返回
    oracle 锁表问题
    LINQ的基本认识
    Oracle客户端配置
    REVERSE
    vchar2和nvchar2
  • 原文地址:https://www.cnblogs.com/sunner/p/9317510.html
Copyright © 2011-2022 走看看