监视Rails进程内存泄漏的技巧
Rails应用比较容易遇到的两类性能问题:一类是Rails执行很慢,CPU消耗过高;另一类是Rails进程内存泄漏。解决这两类问题都需要你首先能够精确定位出现问题的代码,然后才知道如何对症下药。一、如何监控Rails进程的执行性能
定位消耗CPU高,执行速度缓慢的Rails代码,是相当容易的事情,仅仅需要你对production.log做一点统计分析,抽取出来执行时间最长的请求,问题就昭然若揭了。由于production.log对Rails请求的执行时间做了详细的统计,例如:
Completed in 0.00693 (144 reqs/sec) | Rendering: 0.00489 (70%) | DB: 0.00000 (0%) | 200 OK Completed in 0.17238 (5 reqs/sec) | Rendering: 0.10011 (58%) | DB: 0.06244 (36%) | 200 OK Completed in 0.20508 (4 reqs/sec) | Rendering: 0.19373 (94%) | DB: 0.00645 (3%) | 200 OK
所以我们只需要写一行shell命令,就搞定了!他把最耗时的前500个请求筛选出来,保存到timing.log里面。
grep "200 OK" production.log | awk '{print "ALL: " $3 "View: " $8 " DB: " $12 "URL: " $17 }' \| sort -r | head -n 500 > timing.log
排序好的结果例如:
ALL: 5.51774View: 5.38277 DB: 0.13338URL: ALL: 5.51316View: 5.31300 DB: 0.19400URL: ALL: 5.51311View: 5.39321 DB: 0.11234URL: ALL: 5.51135View: 5.37604 DB: 0.12652URL: ALL: 5.49881View: 5.35998 DB: 0.10637URL:
哪些请求执行的慢,一目了然。 当然除此之外,我们还可以实时监控,在top监视窗口显示Rails当前正在执行的请求URL。
二、如何监控Rails进程的内存泄漏
监控CPU是很容易的事情,但要监控Rails进程的内存泄漏,却非常困难,原因在于production.log里面并没有记录进程的内存变化状况,甚至你找不到任何ruby API可以用来直接查询到进程使用的物理内存。实际上,要获取一个进程的物理内存是一个平台相关的操作,每个操作系统都会自己特定的API,并不通用,即使用C语言来编码,也不是一件容易的事情。
不过对于Linux操作系统来说,我们有一个捷径可以获取进程的内存状况。Linux的/proc文件系统是内核的映象,/proc/进程pid/status 文件记录了这个进程的状态信息,例如:
Name: dispatch.fcgiState:S (sleeping)SleepAVG: 135%Tgid: 26645Pid: 26645PPid: 1TracerPid: 0Uid: 1002 1002 1002 1002Gid: 100 100 100 100FDSize: 64Groups: 14 16 17 33 100 VmSize: 245680 kBVmLck: 0 kBVmRSS: 209104 kBVmData: 205116 kBVmStk: 824 kBVmExe: 764 kBVmLib: 4220 kBThreads: 1SigPnd: 0000000000000000ShdPnd: 0000000000000000SigBlk: 0000000000000000SigIgn: 0000000000001000SigCgt: 0000000002006e47CapInh: 0000000000000000CapPrm: 0000000000000000CapEff: 0000000000000000
注意第14行VmRSS,记录了该进程使用的常驻物理内存(Residence),这个就是该进程实际占用的物理内存了。因此只要我们读取该文件第14行,就可以得到内存信息。
所以我们的任务变成了:在Rails处理请求之前记录内存,等Rails处理完请求之后,再记录内存,计算内存的变化状况,写入到production.log里面去。完成这个工作,只需要我们在Rails应用的app/controllers/application.rb里面添加几行代码:
around_filter :record_memorydef record_memory process_status = File.open("/proc/#{Process.pid}/status") 13.times { process_status.gets } rss_before_action = process_status.gets.split.to_i process_status.close yield process_status = File.open("/proc/#{Process.pid}/status") 13.times { process_status.gets } rss_after_action = process_status.gets.split.to_i process_status.close logger.info("CONSUME MEMORY: #{rss_after_action - rss_before_action} \KB\tNow: #{rss_after_action} KB\t#{request.url}")end
我们定义了一个AroundFilter,记录一下处理请求前后的内存变化。有了这个信息,我们接下来的事情就简单了,只需要从production.log里面抽取出来这行log,进行统计分析就可以了,这也仅仅只需要一行shell就搞定了:
grep "CONSUME MEMORY" production.log | grep -v "CONSUME MEMORY: 0" |\ grep -v "CONSUME MEMORY: -" |awk '{print $3 "\t" $6 "\t" $8 }' | sort -r -n | \ head -n 500 > memory.log
抽取内存记录,去掉内存没有增加,去掉内存减少(发生了GC)的请求,然后对那些处理请求之后内存上升的记录进行排序,取出来前500条记录保存到memory.log里面,结果如下所示:
增加数 内存占用 请求URL-----------------------------------------------9528175264http://www.iteye.com/topic/3045949524129512http://knityster.iteye.com/blog/1729909496147544http://www.iteye.com/forums/9492197800http://duyiwuer.iteye.com/rss9452146668http://www.iteye.com/forums9452133844http://wildlife.iteye.com/blog/476939440157824http://www.iteye.com/rss/blogs9424204664http://www.iteye.com/wiki/topic/2519649384142200http://towerhe.iteye.com/blog/937049380165372http://www.iteye.com/wiki/topic/774349368207460http://superleo.iteye.com/rss
第一列是访问了一个请求以后,Rails进程的内存上升了9MB多,第二列是处理完请求,Rails进程当前实际占了170多MB内存,第三列是处理了什么请求。
根据这个统计结果,你可以很容易找出那些造成你Rails进程内存泄漏的罪魁祸首,哪些请求一访问你的Rails进程内存就飚升已经是一目了然的事情了,这是不是很简单?事实上通过这个办法,JavaEye仅用了半个多小时,就解决了曾经困扰了半年多的内存泄漏问题,办法虽土,却很有效!
页:
[1]