当我们的IO密集型的应用怀疑设备的IO抖动，比如说一段时间的wait时间过长导致性能或其他疑难问题的时候，这个现象处理起来就比较棘手，因为硬件的抖动有偶发性很难重现或者重现的代价比较高。
幸运的是systemtap可以拯救我们。从原理上讲，我们应用的IO都是通过文件系统来访问的，不管read/write/sync都是，而且我们的文件大部分都是以buffered方式打开的。在这个模式下，如果pagecache不命中的话，就需要访问设备。 知道了这个基本的原理以后，我们就可以用万能的systemtap往vfs的读写请求中受控的注入延迟，来达到这个目的。
要点有以下几个：
1. 受控的时间点。
2. 延迟时间可控。
3. 目标设备可控。
我写了个脚本注入IO延迟，模拟ssd/fio硬件的抖动来验证是否是IO抖动会给应用造成影响，三个步骤如下：
步骤1: 编译模块
$ cat inject_ka.stp
global inject, ka_cnt
probe procfs("cnt").read {
$value = sprintf("%d\n", ka_cnt);
}
probe procfs("inject").write {
inject= $value;
printf("inject count %d, ka %s", ka_cnt, inject);
}
probe vfs.read.return,
vfs.write.return {
if ($return &&
devname == @1 &&
inject == "on\n")
{
ka_cnt++;
udelay($2);
}
}
probe begin{
println("ik module begin:)");
}
$ stap -V
Systemtap translator/driver (version 2.1/0.152, commit release-2.0-385-gab733d5)
Copyright (C) 2005-2013 Red Hat, Inc. and others
This is free software; see the source for copying conditions.
enabled features: LIBSQLITE3 NSS BOOST_SHARED_PTR TR1_UNORDERED_MAP NLS
$ sudo stap -p4 -DMAXSKIPPED=9999 -m ik -g inject_ka.stp sda6 300
ik.ko
其中参数sda6是目标设备的名字，300是希望延迟的时间，单位us（超过300很容易报错，因为通常systemtap会对脚本执行的cpu进行检查，占用过多cpu的时候会触发保护机制，导致stap抱怨退出），通常对于ssd设备是足够的。
这个步骤会生成ik.ko，请验证生成模块的机器和目标的机器，操作系统的版本是一模一样的，而且请确保你的stap版本比较高，因为udelay函数在高版本的Stap才有。
步骤2:
将ik.ko拷贝到目标机器，执行
$ sudo staprun ik.ko
ik module begin:)
步骤3:
启动应用程序开始测试后一段时间，运行如下命令开始注入：
$ echo on|sudo tee /proc/systemtap/ik/inject && sleep 10 && echo off|sudo tee /proc/systemtap/ik/inject
其中sleep N 是希望打开注入开关的时间。
小结：systemtap用好很无敌！
祝玩得开心！
晚上朔海同学问：
一个文件正在被进程写 我想查看这个进程 文件一直在增大 找不到谁在写 使用lsof也没找到
这个问题挺有普遍性的，解决方法应该很多，这里我给大家提个比较直观的方法。
linux下每个文件都会在某个块设备上存放，当然也都有相应的inode, 那么透过vfs.write我们就可以知道谁在不停的写入特定的设备上的inode。
幸运的是systemtap的安装包里带了inodewatch.stp，位于/usr/local/share/doc/systemtap/examples/io目录下，就是用来这个用途的。
我们来看下代码：
$ cat inodewatch.stp
#! /usr/bin/env stap
probe vfs.write, vfs.read
{
# dev and ino are defined by vfs.write and vfs.read
if (dev == MKDEV($1,$2) # major/minor device
&& ino == $3)
printf ("%s(%d) %s 0x%x/%u\n",
execname(), pid(), probefunc(), dev, ino)
}
这个脚本的使用方法如下： stap inodewatch.stp major minor ino
下面我们构造个场景： dd不停的写入一个文件，查出这个文件的ino, 以及它所在设备的major, minor, 运行stap脚本就可以得到答案。
Read more…
今天曲山同学在线上问道：
我测试发现，如果cp一个文件，然后direct io读这个文件，会消耗很长时间。
我猜测dio不能用page cache，而这个文件cp以后都在cache里面，要强制刷到磁盘，才能读？
我cp这个文件很大，超过256M
由于数据文件默认是用bufferedio方式打开的，也就是说它的数据是先缓冲在pagecache里面的，写入的数据会导致大量的脏页，而且这部分数据如果内核内存不紧张的话，是一直放在内存里面的的。我们知道directio是直接旁路掉pagecache直接发起设备IO的，也就是说在发起IO之前要保证数据是先落地到介质去，所以如果文件比较大的话，这个时间会比较长。从pagecahce的回写行为我们可以知道，只要脏页的数量不超过总内存的10%, 我们的机器有4G的内存，所以2个100M的文件总共才200M，不会导致writeback发生，我们可以很顺利的观察到这个现象。
有了上面的分析，下面我们来重现下这个问题。以下是我的步骤：
Read more…
今天在内核群里印风同学问了个问题：
某台机器的ulimit -t 不知道为啥是300， 这是不是意味着程序占用CPU 300秒后会收到SIGKILL ？
我用gdb跑mysqld 跑了一会，收到SIGKILL信号，没有配置cgroup，也没啥后台脚本，看了下，就ulimit -t 比较诡异，其他机器都是unlimited。
简单的man ulimit下手册说：
-t The maximum amount of cpu time in seconds
貌似限制的是CPU最大执行时间，以秒为单位。
为了验证上面的说法，我特地设计了以下的场景：我们首先运行一个死循环程序消耗CPU时间，同时把进程的最大CPU消耗时间设定在180秒，期待在这个时间点进程会被杀掉。
以下是验证过程：
$ uname -r
2.6.32-131.21.1.tb477.el6.x86_64
$ ulimit -t 180
$ ulimit -t
180
$ cat busy.c
int main(int argc, char *argv[]) {
for(;;);
return 0;
}
$ gcc busy.c
$ time ./a.out
Killed
real 3m0.029s
user 2m59.966s
sys 0m0.007s
从现象来看，3分钟后我们的busy进程确实被杀了，dmesg也没说什么原因被杀。
Read more…
刚@淘宝雕梁 告诉我 GLIBC 2.16 支持systemtap静态检查点，消息源在这里， 摘抄相关部分如下：
* New configure option –enable-systemtap builds SystemTap static probes
into libc for setjmp and longjmp and into libpthread for various operations.
So far the setjmp/longjmp probes and some of the libpthread probes are
provided only for i*86 and x86_64.
Implemented by Roland McGrath and Rayson Ho.
目前主要是在setjmp/longjmp和pthread相关的锁操作，而且只支持 i*86 and x86_64 平台。我们到源码验证下：
Read more…
最新的Erlang虚拟机（R15B01）很大的一个改进就是加入了对dtrace探测点的支持了， 具体参见这里, 主要目标是方便在生产实践中定位复杂的性能问题。
目前Erlang的虚拟机的探测点支持Linux的systemtap和freebsd的dtrace，我们刚好能够享受的到。
作者Scott Lystig Fritchie在去年的euc中做了个很有意思的报告，参见这里，该PPT很详细的介绍了利用dtrace的探测点可以观察到erlang的行为如下：
Processes: spawn, exit, hibernate, scheduled, …
Messages: send, queued, received, exit signals
Memory: GC minor & major, proc heap grow & shrink
Data copy: within heap, across heaps
Function calls: function & BIF & NIF, entry & return
Network distribution: monitor, port busy, output events
Ports: open, command, control, busy/not busy
Drivers: callback API 100% instrumented
efile_drv.c fifile I/O driver: 100% instrumented
这些探测点基本上属于IO，进程调度，消息发送，driver等虚拟机最底层的和操作系统耦合的部分，对性能的影响巨大。
目前Erlang自己的基础设施并没有涵盖到这部分内容，如dbg,trace机制都无法了解到这些数据，导致在大型的集群系统里面一旦发现性能问题无法很好的展开调查，所以这些探测点刚好填补了空白。
目前这些dtrace probe点是用static marker实现的，细节可以参看这里 和 这里，好处是不用这些特性的时候，不会对性能有任何的影响，只需要为使用付代价。目前支持这种机制的语言和系统有java,python,mysql,pgsql等，可见威力强劲。
好拉，废话少说，我们来体验下。
Read more…
最近公司在MySQL的数据库上由于采用了高速的如PCIe卡以及大内存，去年在压力测试的时候突然发现数据库的流量可以把一个千M网卡压满了。随着数据库的优化，现在流量可以达到150M，所以我们采用了双网卡，在交换机上绑定，做LB的方式，提高系统的吞吐量。
但是在最近压测试的一个数据库中，mpstat发现其中一个核的CPU被软中断耗尽：
Mysql QPS 2W左右
——– —–load-avg—- —cpu-usage— —swap— -QPS- -TPS- -Hit%-
time | 1m 5m 15m |usr sys idl iow| si so| ins upd del sel iud| lor hit|
13:43:46| 0.00 0.00 0.00| 67 27 3 3| 0 0| 0 0 0 0 0| 0 100.00|
13:43:47| 0.00 0.00 0.00| 30 10 60 0| 0 0| 0 0 0 19281 0| 326839 100.00|
13:43:48| 0.00 0.00 0.00| 28 10 63 0| 0 0| 0 0 0 19083 0| 323377 100.00|
13:43:49| 0.00 0.00 0.00| 28 10 63 0| 0 0| 0 0 0 19482 0| 330185 100.00|
13:43:50| 0.00 0.00 0.00| 26 9 65 0| 0 0| 0 0 0 19379 0| 328575 100.00|
13:43:51| 0.00 0.00 0.00| 27 9 64 0| 0 0| 0 0 0 19723 0| 334378 100.00|
mpstat -P ALL 1说：
针对这个问题，我们利用工具，特别是systemtap, 一步步来调查和解决问题。
Read more…
Recent Comments