3.4.1 单条查询问题还是服务器问题(2)
使用SHOW PROCESSLIST 命令时,在尾部加上\G 可以垂直的方式输出结果,这很有用, 因为这样会将每一行记录的每一列都单独输出为一行, 这样可以方便地使用sort|uniq|sort 一类的命令来计算某个列值出现的次数:
$ mysql -e 'SHOW PROCESSLIST\G' | grep State: | sort | uniq -c | sort -rn
744 State:
67 State: Sending data
36 State: freeing items
8 State: NULL
6 State: end
4 State: Updating
4 State: cleaning up
2 State: update
1 State: Sorting result
1 State: logging slow query
如果要查看不同的列,只需要修改grep 的模式即可。在大多数案例中,State 列都非常有用。从这个例子的输出中可以看到,有很多线程处于查询执行的结束部分的状态,包括“freeing items”、end”、“cleaning up”和“logging slow query”。事实上,在案例中的这台服务器上,同样模式或类似的输出采样出现了很多次。大量的线程处于“freeingitems”状态是出现了大量有问题查询的很明显的特征和指示。
用这种技术查找问题,上面的命令行不是***的方法。如果MySQL 服务器的版本较新,也可以直接查询INFORMATION_SCHEMA 中的PROCESSLIST 表;或者使用innotop 工具以较高的频率刷新,以观察屏幕上出现的不正常查询堆积。上面演示的这个例子是由于InnoDB 内部的争用和脏块刷新所导致,但有时候原因可能比这个要简单得多。一个经典的例子是很多查询处于“Locked”状态,这是MyISAM 的一个典型问题,它的表级别锁定,在写请求较多时,可能迅速导致服务器级别的线程堆积。
使用查询日志
如果要通过查询日志发现问题,需要开启慢查询日志并在全局级别设置long_query_time 为0,并且要确认所有的连接都采用了新的设置。这可能需要重置所有连接以使新的全局设置生效;或者使用Percona Server 的一个特性,可以在不断开现有连接的情况下动态地使设置强制生效。
如果因为某些原因,不能设置慢查询日志记录所有的查询,也可以通过tcpdump 和ptquery-digest 工具来模拟替代。要注意找到吞吐量突然下降时间段的日志。查询是在完成阶段才写入到慢查询日志的,所以堆积会造成大量查询处于完成阶段,直到阻塞其他查询的资源占用者释放资源后,其他的查询才能执行完成。这种行为特征的一个好处是,当遇到吞吐量突然下降时,可以归咎于吞吐量下降后完成的***个查询(有时候也不一定是***个查询。当某些查询被阻塞时,其他查询可以不受影响继续运行,所以不能完全依赖这个经验)。
再重申一次,好的工具可以帮助诊断这类问题,否则要人工去几百GB 的查询日志中找原因。下面的例子只有一行代码,却可以根据MySQL 每秒将当前时间写入日志中的模式统计每秒的查询数量:
$ awk '/^# Time:/{print $3, $4, c;c=0}/^# User/{c++}' slow-query.log
080913 21:52:17 51
080913 21:52:18 29
080913 21:52:19 34
080913 21:52:20 33
080913 21:52:21 38
080913 21:52:22 15
080913 21:52:23 47
080913 21:52:24 96
080913 21:52:25 6
080913 21:52:26 66
080913 21:52:27 37
080913 21:52:28 59
从上面的输出可以看到有吞吐量突然下降的情况发生,而且在下降之前还有一个突然的高峰,仅从这个输出而不去查询当时的详细信息很难确定发生了什么,但应该可以说这个突然的高峰和随后的下降一定有关联。不管怎么说,这种现象都很奇怪,值得去日志中挖掘该时间段的详细信息(实际上通过日志的详细信息,可以发现突然的高峰时段有很多连接被断开的现象,可能是有一台应用服务器重启导致的。所以不是所有的问题都是MySQL 的问题)。
理解发现的问题(Making sense of the findings)
能又消失了。这样我们很容易会认为其实没有问题。
发现输出的图形异常意味着什么?通常来说可能是查询在某个地方排队了,或者某种查询的量突然飙升了。接下来的任务就是找出这些原因。
【责任编辑:book TEL:(010)68476606】
点赞 0