应用执行慢的定位案例

来自:bisal的个人杂货铺,作者:bisal

预计阅读时间:5分钟


最近测试搬迁的一个应用,用C写的后台进程,作用是读取本地数据文件,解析文件内容,向数据库表插入数据,在开发服务器上,无论功能,还是执行的性能,都可以满足需求,但是上传至生产服务器,测试执行的时候,发现一直hang住,无论从控制台输出信息,还是日志信息,都长时间未刷新。


开发服务器和生产服务器,都是Solaris系统,装了Oracle Client,且版本相同,代码是上传的二进制,因此版本相同,开发服务器位于浙江省,生产服务器位于北京市,二者连接的数据库位于浙江省。


程序的逻辑,比较简单,通过fread()函数来读取本地文件,然后逐行根据规则进行解析,将得到的字段,插入数据库表,过程如下

while(1) {
 ...
 fread(...)
 parse(...)
 insert into table values(...)
}


最初,在程序中加了一些断点,想打印出一次操作的时间,

while(1) {
...
fread(...)
log_time(...)
parse(...)
insert into table values(...)
}


发现在开发和生产环境,显示的执行时间,确实明显不同,相差两个数量级,


首先看的是系统内核参数,两者有些差别,于是比对开发,在生产环境中,调整了ulimit的参数,


发现此时处理速度提升一倍,但是和开发相比,还是较差,


此外,还猜测是fread()这步产生差异,于是分别在这两套环境,监控磁盘IO性能,发现相差无几,


这个应用程序,重要的两步,一个是读文件,一个是写数据库,既然读文件,没有什么问题,是不是数据库?


这才发现,刚才加的断点,其实有些粗了,只在一次while循环中,记录了时间,相当于只能知道,一次执行慢,但是没有更细粒度的定位,因此,除了fread(),在parse、insert步骤中,均加了断点,

while(1) {
...
fread(...)
log_time(...)
parse(...)
log_time(...)
insert into table values(...)
log_time(...)
}


于是,问题比较清楚了,一次insert操作,在开发环境,基本在1-2ms,而在生产环境,一次就要27ms左右,1000行数据就是27*1000=27秒,和上面测试的25秒,基本一致。


说明一次执行慢,就慢在了数据库操作。但是,为什么?


开发和生产,连接的是同一套数据库,为何有快有慢?


除了数据库自身,另外的介质,就是网络。


刚才我们说了,开发环境是“浙江省的应用服务器,访问浙江省的数据库”,生产环境是“北京的应用服务器,访问浙江省的数据库”,北京和浙江,相距一千多公里,理论上网络就会有延迟。


至于延迟多少,可以使用ping指令,下面显示的是,浙江省的应用服务器网段,ping浙江省的数据库网段,延迟0.26毫秒,


北京的应用服务器网段,ping浙江省的数据库网段,延迟26毫秒,


二者正巧相差了两个数量级,由于应用程序,是逐行读取文件,逐条插入数据表,因此1000行数据,相当于要执行1000次交互,累积起来,这个延时差距,就能正确解释了。


原因清楚了,解决自然有了,要么同网段资源访问,避免网络延迟,要么采用批量提交的方式,减少交互次数,降低延迟的影响。


其实,针对这个问题,最重要的不是这些结论,而是寻找问题的过程,出现程序执行慢,首先就要知道,程序都有哪些重要的步骤,和哪些外系统、设备、资源进行交互,例如本地磁盘、跨网段访问、数据库。


要是简单一些,可以向程序增加一些断点,无论是要打印到控制台,还是应用日志,其中需要注意的一点,就是断点的粒度,像上面的问题中,一开始断点粒度很粗,无法精确定位。


要是复杂一些,打出dump文件,从程序的调用栈,一步步进行判断。


我们需要积累的,不只是一些问题的结论,可能比较于结论,找出原因的过程,更值得我们总结,就像有人说过,大学学到的最重要技能,是学习的方法,相比于各种考试的成绩,有了适合自己的学习方法,这才是终身受益。

推荐↓↓↓
数据库开发
上一篇:Oracle RAC 集群结构 下一篇:MySQL更改数据库数据存储目录