使用pt-query-digest分析mysql slow query log

本文涉及的产品
RDS MySQL Serverless 基础系列,0.5-2RCU 50GB
云数据库 RDS MySQL,高可用系列 2核4GB
RDS MySQL Serverless 高可用系列,价值2615元额度,1个月
简介:

            使用pt-query-digest分析mysql slow query log


下载地址:

http://www.percona.com/software/percona-toolkit/

官方文档:

http://www.percona.com/doc/percona-toolkit/pt-query-digest.html


1,yum安装 ,先配置好 yum 源 

1
2
3
4
5
6
7
8
vim  /etc/yum .repos.d /percona .repo  
 
[percona]
name = CentOS $releasever - Percona
baseurl=http: //repo .percona.com /centos/ $releasever /os/ $basearch/
enabled = 1
gpgkey =  file : ///etc/pki/rpm-gpg/RPM-GPG-KEY-percona
gpgcheck = 0


2,开始安装:

1
yum  install  percona-toolkit -y


3,打开慢查询日志

请先确定在my.cnf中打开了mysql的slow_query_log,并且保证long_query_time参数设置得很合理。

1
2
3
4
vim  my.cnf
slow-query-log
slow-query-log- file  = slow.log
long-query- time  = 1


4,下载分析工具

pt-query-digest是一个perl脚本,只需下载即可

1
2
3
[arno.sun@srv-nc-ssh1 slowlog]$ wget percona.com /get/pt-query-digest 
[arno.sun@srv-nc-ssh1 slowlog]$  file  pt-query-digest pt-query-digest: a perl script text executable 
[arno.sun@srv-nc-ssh1 slowlog]$  chmod  +x pt-query-digest



5,使用:

直接上就行了,简单粗暴也没有问题。

事实上,这个工具确实有点简单粗暴,如果slow log够大的话,会消耗相当多的cpu和内存,所以最好把slow log和pt-query-digest放到其它的server上面运行。

pt-query-digest  slow.log > slow_report.log

分析结果解释说明:


第一部分是摘要:

cat slow_report.log


# 620ms user time, 10ms system time, 19.76M rss, 115.84M vsz

# Current date: Wed Mar 20 16:09:35 2013

# Hostname: srv-nc-ssh1                           

# Files: slow.log

# Overall: 371 total, 35 unique, 0.00 QPS, 0.05x concurrency _____________

# Time range: 2013-03-18 14:08:55 to 2013-03-19 12:23:36

# Attribute          total     min     max     avg     95%  stddev  median

# ============     ======= ======= ======= ======= ======= ======= =======

# Exec time          3959s      1s     73s     11s     37s     12s      7s

# Lock time           246s       0     42s   663ms   204us      4s    66us

# Rows sent         37.53M       0   6.10M 103.58k 485.50k 580.16k       0

# Rows examine      71.32M       0   6.10M 196.86k 961.27k 607.20k       0

# Rows affecte       1.03M       0 973.91k   2.83k    0.99  49.98k    0.99

# Rows read         37.53M       0   6.10M 103.58k 485.50k 580.16k       0

# Bytes sent         4.48G      14 383.55M  12.36M 101.56M  45.74M   13.83

# Tmp tables           110       0       5    0.30    0.99    0.79       0

# Tmp disk tbl          12       0       1    0.03       0    0.18       0

# Tmp tbl size      21.67M       0 1009.90k  59.82k 245.21k 158.04k      0

# Query size        71.10k      31     983  196.25  400.73  100.16  166.51


对于第一部分摘要的解释:

========================================================================================================

# 620ms user time, 10ms system time, 19.76M rss, 115.84M vsz

该工具执行日志分析的用户时间,系统时间,物理内存占用大小,虚拟内存占用大小。

# Hostname: srv-nc-ssh1  

运行分析工具的主机名

# Files: slow.log

被分析的文件名

# Overall: 371 total, 35 unique, 0.00 QPS, 0.05x concurrency _____________

语句总数量 (371),唯一的语句(35),Qps, 并发数

# Time range: 2013-03-18 14:08:55 to 2013-03-19 12:23:36

日志记录的时间范围

# Attribute          total     min     max     avg     95%  stddev  median


在这些值中,最有意义的恐怕就是95%了,与中位数类似,它也是把所有值从小到大排列,位置位于95%的那个数。

#Row sent            发送到客户端的行数

#Query size          查询的字符大小

========================================================================================================


继续看第二部分:



# Profile

# Rank Query ID           Response time   Calls R/Call  Apdx V/M   

Item# ==== ================== =============== ===== ======= ==== ===== =======

#    1 0x3BE81BF6A30F4C74 1702.9604 43.0%   182  9.3569 0.15  5.91 INSERT u_search_record

#    2 0x861AC23E20A17B65 1490.0836 37.6%    54 27.5941 0.05 13.54 SELECT UNION t_ask_price_info t_vouch_info t_cust_book t_hn_info

#    3 0xD43C719B4CE15C37   96.9039  2.4%    14  6.9217 0.11  1.42 SELECT u_car_info t_stas_auc_car

#    4 0x414D67056BE15CF4   58.2516  1.5%    20  2.9126 0.40  0.56 INSERT u_auction_back_cache

#    5 0x4A78E978D2543BCD   56.5418  1.4%     3 18.8473 0.00  3.14 SELECT t_cust_book

#    6 0x3A12FD01A8D9DA10   52.8541  1.3%     3 17.6180 0.00  0.00 SELECT t_auction_back_cache

#    7 0x9186BF39CBE58A0E   50.4508  1.3%     3 16.8169 0.00  0.01 SELECT t_check_result

#    8 0x68738A978FAB0D06   42.6112  1.1%     6  7.1019 0.17  4.66 SELECT t_sys_config t_hn_info t_hn_quote_list u_car_info

#    9 0x65EBDC4319D9955A   36.9794  0.9%     1 36.9794 0.00  0.00 INSERT SELECT t_hn_info t_hn_audit_quote

#   10 0x5203D60E3716D608   35.1022  0.9%     5  7.0204 0.00  0.05 SELECT mina_send

#   11 0x64C380BEB00DFB63   28.7720  0.7%    12  2.3977 0.50  0.40 SELECT u_vehicle_type

#   12 0xCDDA52E5A6B9F0B7   27.5927  0.7%     3  9.1976 0.00  0.00 SELECT rbvehicle

#   13 0xA5E766B81112B13A   27.5218  0.7%     4  6.8804 0.12  3.51 SELECT u_auction_back_cache

#   14 0x597A26236611758F   26.7460  0.7%     3  8.9153 0.00  0.65 SELECT t_hn_audit_quote t_ask_price_info

#   15 0x443D2230FC99811C   25.2928  0.6%     3  8.4309 0.00  0.00 SELECT t_hn_quote_list


Response: 总的响应时间。
time: 该查询在本次分析中总的时间占比。
calls: 执行次数,即本次分析总共有多少条这种类型的查询语句。
R/Call: 平均每次执行的响应时间。
Item : 查询对象

这一部分显示了最慢的十六种类型的SQL语句。

我这里最慢的是INSERT INTO u_search_record…… 共有182条语句,虽然每次插入的数据都是不同的,但也被归于同一类型的语句了。



第三部分最重要了。

以排名第一的SQL为例。



# Query 1: 0.00 QPS, 0.02x concurrency, ID 0x3BE81BF6A30F4C74 at byte 121216

# This item is included in the report because it matches --limit.

# Scores: Apdex = 0.15 [1.0], V/M = 5.91

# Query_time sparkline: |    


# Time range: 2013-03-18 15:53:08 to 2013-03-19 12:23:36


# Attribute    pct   total     min     max     avg     95%  stddev  median

# ============ === ======= ======= ======= ======= ======= ======= =======

# Count         49     182

# Exec time     43   1703s      1s     42s      9s     21s      7s      8s

# Lock time      0    12ms    41us   133us    64us    84us    15us    60us

# Rows sent      0       0       0       0       0       0       0       0

# Rows examine   0       0       0       0       0       0       0       0

# Rows affecte   0     182       1       1       1       1       0       1

# Rows read      0       0       0       0       0       0       0       0

# Bytes sent     0   2.49k      14      14      14      14       0      14

# Tmp tables     0       0       0       0       0       0       0       0

# Tmp disk tbl   0       0       0       0       0       0       0       0

# Tmp tbl size   0       0       0       0       0       0       0       0

# Query size    44  31.47k     166     291  177.04  192.76   24.93  158.58

# String:


# Databases    xinche

# Hosts


# InnoDB trxID 855383 (1/0%), 85538E (1/0%), 855391 (1/0%)... 179 more

# Last errno   0


# Users        carsingweb

# Query_time distribution

# 1us

# 10us

# 100us

# 1ms

# 10ms

# 100ms


#  1s   #################################################################  

#  10s+ #############################################

# Tables


# SHOW TABLE STATUS FROM `xinche` LIKE 'u_search_record'\G#    SHOW CREATE TABLE `xinche`.`u_search_record`\G

insert into u_search_record (ip, uri, params, create_date) values ('127.0.0.1', '/car/car!ajaxGetCarInfo.action', '[{"carinfo.id":["91202"]}]', '2013-03-18 17:17:08')\G



从上面可以看出,共有182条语句 

[95%]Exec time是21s,时间长得比较离谱了 

数据库为xinche,用户名为carsingweb 

然后是query time的分布图,这个图太恶心了,不过也可以看得出来大部分是处于1-10s之间的, 还有

一些超过10秒了。

最后是几条SQL语句, 是pt-query-digest生成的,这些语句有助于分析问题。

 




常见用法列表:


例(1)直接分析慢查询文件:pt-query-digest  slow.log > slow_report.log
(2)分析最近12小时内的查询:

pt-query-digest  --since=12h  slow.log > slow_report2.log

(3)分析指定时间范围内的查询:

pt-query-digest slow.log --since '2014-04-17 09:30:00' --until '2014-04-17 10:00:00'> > slow_report3.log

(4)分析指含有select语句的慢查询
pt-query-digest--filter '$event->{fingerprint} =~ m/^select/i' slow.log> slow_report4.log

(5) 针对某个用户的慢查询
pt-query-digest--filter '($event->{user} || "") =~ m/^root/i' slow.log> slow_report5.log

(6) 查询所有所有的全表扫描或full join的慢查询
pt-query-digest--filter '(($event->{Full_scan} || "") eq "yes") ||(($event->{Full_join} || "") eq "yes")' slow.log> slow_report6.log

(7)
把查询保存到query_review
pt-query-digest  --user=root –password=abc123 --review  h=localhost,D=test,t=query_review--create-review-table  slow.log

(8)把查询保存到query_history表
pt-query-digest  --user=root –password=abc123 --review  h=localhost,D=test,t=query_ history--create-review-table  slow.log_20140401
pt-query-digest  --user=root –password=abc123--review  h=localhost,D=test,t=query_history--create-review-table  slow.log_20140402

(9)通过tcpdump抓取mysqltcp协议数据,然后再分析
tcpdump -s 65535 -x -nn -q -tttt -i any -c 1000 port 3306 > mysql.tcp.txt
pt-query-digest --type tcpdump mysql.tcp.txt> slow_report9.log

(10)分析binlog
mysqlbinlog mysql-bin.000093 > mysql-bin000093.sql
pt-query-digest  --type=binlog  mysql-

bin000093.sql > slow_report10.log

(11)分析general log
pt-query-digest  --type=genlog  localhost.log > slow_report11.log




官网资料

http://dev.mysql.com/doc/refman/5.1/en/slow-query-log.html






      本文转自crazy_charles 51CTO博客,原文链接:http://blog.51cto.com/douya/1597679,如需转载请自行联系原作者




相关实践学习
每个IT人都想学的“Web应用上云经典架构”实战
本实验从Web应用上云这个最基本的、最普遍的需求出发,帮助IT从业者们通过“阿里云Web应用上云解决方案”,了解一个企业级Web应用上云的常见架构,了解如何构建一个高可用、可扩展的企业级应用架构。
MySQL数据库入门学习
本课程通过最流行的开源数据库MySQL带你了解数据库的世界。   相关的阿里云产品:云数据库RDS MySQL 版 阿里云关系型数据库RDS(Relational Database Service)是一种稳定可靠、可弹性伸缩的在线数据库服务,提供容灾、备份、恢复、迁移等方面的全套解决方案,彻底解决数据库运维的烦恼。 了解产品详情: https://www.aliyun.com/product/rds/mysql 
相关文章
|
16天前
|
SQL 运维 关系型数据库
深入探讨MySQL的二进制日志(binlog)选项
总结而言,对MySQL binlogs深度理解并妥善配置对数据库运维管理至关重要;它不仅关系到系统性能优化也是实现高可靠性架构设计必须考虑因素之一。通过精心规划与周密部署可以使得该机能充分发挥作用而避免潜在风险带来影响。
51 6
|
5月前
|
SQL 监控 关系型数据库
MySQL日志分析:binlog、redolog、undolog三大日志的深度探讨。
数据库管理其实和写小说一样,需要规划,需要修订,也需要有能力回滚。理解这些日志的作用与优化,就像把握写作工具的使用与运用,为我们的数据库保驾护航。
212 23
|
6月前
|
SQL 运维 关系型数据库
MySQL Binlog 日志查看方法及查看内容解析
本文介绍了 MySQL 的 Binlog(二进制日志)功能及其使用方法。Binlog 记录了数据库的所有数据变更操作,如 INSERT、UPDATE 和 DELETE,对数据恢复、主从复制和审计至关重要。文章详细说明了如何开启 Binlog 功能、查看当前日志文件及内容,并解析了常见的事件类型,包括 Format_desc、Query、Table_map、Write_rows、Update_rows 和 Delete_rows 等,帮助用户掌握数据库变化历史,提升维护和排障能力。
|
7月前
|
SQL 缓存
【YashanDB知识库】YashanDB run.log中有slow log queue is full信息
【YashanDB知识库】YashanDB run.log中有slow log queue is full信息
|
7月前
|
存储 SQL 关系型数据库
mysql的undo log、redo log、bin log、buffer pool
MySQL的undo log、redo log、bin log和buffer pool是确保数据库高效、安全和可靠运行的关键组件。理解这些组件的工作原理和作用,对于优化数据库性能和保障数据安全具有重要意义。通过适当的配置和优化,可以显著提升MySQL的运行效率和数据可靠性。
112 4
|
7月前
|
SQL 存储 关系型数据库
简单聊聊MySQL的三大日志(Redo Log、Binlog和Undo Log)各有什么区别
在MySQL数据库管理中,理解Redo Log(重做日志)、Binlog(二进制日志)和Undo Log(回滚日志)至关重要。Redo Log确保数据持久性和崩溃恢复;Binlog用于主从复制和数据恢复,记录逻辑操作;Undo Log支持事务的原子性和隔离性,实现回滚与MVCC。三者协同工作,保障事务ACID特性。文章还详细解析了日志写入流程及可能的异常情况,帮助深入理解数据库日志机制。
848 0
|
5月前
|
监控 容灾 算法
阿里云 SLS 多云日志接入最佳实践:链路、成本与高可用性优化
本文探讨了如何高效、经济且可靠地将海外应用与基础设施日志统一采集至阿里云日志服务(SLS),解决全球化业务扩展中的关键挑战。重点介绍了高性能日志采集Agent(iLogtail/LoongCollector)在海外场景的应用,推荐使用LoongCollector以获得更优的稳定性和网络容错能力。同时分析了多种网络接入方案,包括公网直连、全球加速优化、阿里云内网及专线/CEN/VPN接入等,并提供了成本优化策略和多目标发送配置指导,帮助企业构建稳定、低成本、高可用的全球日志系统。
624 54
|
11月前
|
XML 安全 Java
【日志框架整合】Slf4j、Log4j、Log4j2、Logback配置模板
本文介绍了Java日志框架的基本概念和使用方法,重点讨论了SLF4J、Log4j、Logback和Log4j2之间的关系及其性能对比。SLF4J作为一个日志抽象层,允许开发者使用统一的日志接口,而Log4j、Logback和Log4j2则是具体的日志实现框架。Log4j2在性能上优于Logback,推荐在新项目中使用。文章还详细说明了如何在Spring Boot项目中配置Log4j2和Logback,以及如何使用Lombok简化日志记录。最后,提供了一些日志配置的最佳实践,包括滚动日志、统一日志格式和提高日志性能的方法。
2975 31
【日志框架整合】Slf4j、Log4j、Log4j2、Logback配置模板
|
10月前
|
监控 安全 Apache
什么是Apache日志?为什么Apache日志分析很重要?
Apache是全球广泛使用的Web服务器软件,支持超过30%的活跃网站。它通过接收和处理HTTP请求,与后端服务器通信,返回响应并记录日志,确保网页请求的快速准确处理。Apache日志分为访问日志和错误日志,对提升用户体验、保障安全及优化性能至关重要。EventLog Analyzer等工具可有效管理和分析这些日志,增强Web服务的安全性和可靠性。
259 9

热门文章

最新文章

推荐镜像

更多