Mysql使用pt-query-digest分析日志

发表于   |  

1. 开启慢查询日志

（1）首先我们要创建一个文件夹用于保存慢查询日志文件，并且设置 mysql 有权读写该目录：

1
mkdir` `/``var``/log/mysql``sudo ``chown` `mysql:mysql -R /``var``/log/mysql

（2）我们可以登入 mysql 命令行后执行如下命令，使用 set 设置变量来临时开启。注意这种方式重启服务即失效。

1
set ``global` `slow_query_log=on; ``//开启慢查询功能``set ``global` `slow_query_log_file=``'/var/log/mysql/mysql-slow.log'``; ``//指定慢查询日志文件位置``set ``global` `log_queries_not_using_indexes=on;  ``//记录没有使用索引的查询（非必须）``set ``global` `long_query_time=1;  ``//只记录处理时间1s以上的慢查询

（3）或者我们也可以通过修改配置文件来永久开启慢查询日志功能，首先编辑配置文件：

1
vi /etc/my.cnf
  • 然后在里面添加如下高亮配置：
1
[mysqld]``slow_query_log=on #开启慢查询功能``slow_query_log_file=``'/var/log/mysql/mysql-slow.log'` `#指定慢查询日志文件位置``log_queries_not_using_indexes=on  #记录没有使用索引的查询（非必须）``long_query_time=1  #只记录处理时间1s以上的慢查询
  • 保存关闭文件后，执行如下命令重启 mysql 即可：
1
service mysqld restart

2. 查看慢查询功能是否开启

（1）登入 mysql 命令行后执行如下命令可以查看慢查询开启状态，以及慢查询日志存放的位置：

1
show variables like ``'slow_query%'``;

（2）执行如下命令可以查看查询超过多少秒才记录：

1
show variables like ``'long_query_time'``;

3. 慢查询测试

（1）首先我们执行一个如下的 sql，模拟一个 2 秒的慢查询：

1
select sleep(2);

（2）查看日志可以发现这个慢查询已经被记录：

1
cat /``var``/log/mysql/mysql-slow.log

使用 pt-query-digest 工具分析慢查询日志

1，工具安装

（1）首先我们执行如下命令将 rpm 包下载到本地：

注意：如果下载不下来也可访问其官网（点击打开），手动下载下来再上传到服务器上。

1
wget https:``//downloads.percona.com/downloads/percona-toolkit/3.2.1/binary/redhat/7/x86_64/percona-toolkit-3.2.1-1.el7.x86_64.rpm

（2）接着使用 yum 命令进行安装：

1
yum install -y percona-toolkit-3.2.1-1.el7.x86_64.rpm

2. 分析慢查询日志

（1）执行如下命令可以分析指定的慢查询日志文件：

1
pt-query-digest /``var``/log/mysql/mysql-slow.log

（2）分析结果分为三部分，第一部分是总体统计结果：

  • Overall：总共有多少条查询
  • Time range：查询执行的时间范围
  • unique：唯一查询数量，即对查询条件进行参数化以后，总共有多少个不同的查询
  • total：所有查询总计时长
  • min：所有查询最小时长
  • max：所有查询最大时长
  • avg：所有查询平均时长
  • 95%：把所有时长值从小到大排列，位置位于 95% 的那个时长数，这个数一般最具有参考价值
  • median：中位数，把所有时长值从小到大排列，位置位于中间那个时长数

（3）第二部分是查询分组统计结果：

  • Rank：所有语句的排名，默认按查询时间降序排列，通过 –order-by 指定
  • Query ID：语句的 ID（去掉多余空格和文本字符，计算 hash 值）
  • Response：总的响应时间
  • time：该查询在本次分析中总的时间占比
  • Calls：执行次数，即本次分析总共有多少条这种类型的查询语句
  • R/Call：平均每次执行的响应时间
  • V/M：响应时间 Variance-to-mean 的比率
  • Item：查询对象

（4）第三部分是每一种查询比较慢的 sql 的详细统计结果：

  • pct：该 sql 语句某执行属性占所有慢查询语句某执行属性的百分比
  • total：该 sql 语句某执行属性的所有属性时间。
  • Count：sql 语句执行的次数。对应的 pct 表示此 sql 语句执行次数占所有慢查询语句执行次数的 % 比（下图为 10%），对应的 total 表示总共执行了 3 次。
  • Exec time：sql 执行时间
  • Lock time：sql 执行期间被锁定的时间
  • Rows sent：传输的有效数据，在 select 查询语句中才有值
  • Rows examine：总共查询的数据，非目标数据。
  • Query_time distribution：查询时间分布
  • SQL 语句：下图中为 select sleep(7)\G

3. 进阶用法

（1）分析 slow.log 日志，并将分析报告输入到 slow_report.log 中：

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

（2）分析最近 12 小时内的查询：

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

（3）分析指定时间范围内的查询：

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

（4）分析指含有 select 语句的慢查询：

1
pt-query-digest --filter ``'$event->{fingerprint} =~ m/^select/i'` `slow.log> slow_report4.log

（5）针对某个用户的慢查询：

1
pt-query-digest --filter ``'($event->{user} || "") =~ m/^root/i'` `slow.log> slow_report5.log

（6）查询所有的全表扫描或 full join 的慢查询：

1
pt-query-digest --filter ``'(($event->{Full_scan} || "") eq "yes") ||(($event->{Full_join} || "") eq "yes")'` `slow.log> slow_report6.log

（7）把查询保存到 query_review 表：

1
pt-query-digest --user=root –password=abc123 --review h=localhost,D=test,t=query_review--create-review-table slow.log

（8）通过 tcpdump 抓取 mysql 的 tcp 协议数据，然后再分析：

1
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

（9）分析 binlog：

1
mysqlbinlog mysql-bin.000093 > mysql-bin000093.sql``pt-query-digest --type=binlog mysql-bin000093.sql > slow_report10.log

（10）分析 general log：

1
pt-query-digest --type=genlog localhost.log > slow_report11.log