Rails3中的性能分析方法
(转帖请注明出处: http://qa.taobao.com/?p=15025)
性能分析是Web应用开发中非常重要的一个环节,相比访问缓慢的站点,访问快速的站点拥有更好的用户体验,帮助用户节省更多时间,带来更多的用户访问。
作为当前十分流行的Web框架, rubyonrails当然也提供很多方式进行性能分析。
几种常见的方式
Rails日志文件
Rails日志文件中,清晰的打印出了总时间,以及MVC各层消耗的时间,这为性能瓶颈分析提供了最直接的数据。例如,从下面的日志可以看出DB:1.2ms,View: 4.3ms,总时间:13ms
Started GET "/issues/attachments/86674" for 10.13.46.33 at 2012-04-28 20:58:50 +0800 Processing by AttachmentsController#view as JS Rendered attachments/_screenshot.rhtml (0.3ms) Rendered attachments/_attachment.rhtml (2.7ms) Rendered attachments/view.js.erb (3.9ms) Completed 200 OK in 13ms (Views: 4.3ms | ActiveRecord: 1.2ms)
request-log-analyzer
如果要从Rails日志中大海捞针式的找到性能瓶颈未免太痛苦了, request-log-analyzer可以帮助你解决这一问题。她能够分析rails日志,并能自动生成html报告,清楚的告诉你最常访问的URL,瓶颈最慢的URL,DB最慢的URL等等;这些信息对于你掌握系统的性能概况是很有帮助的。
newrelic
当掌握了慢URL后,接下来就是要分析rails在处理请求过程中具体的性能瓶颈,此时可以借助 newrelic工具来完成。她能够清晰的列举出Rails request过程中各SQL语句耗用的时间,以及MVC各层消耗的时间。但遗憾的是,免费版只能用development方式启动,而不能分析production的性能瓶颈。
当然也可以用ruby-prof来分析,但是她来者不拒,分析了所有ruby api的调用,通常分析一个request会得到几个百个api的数据,而从这里面要找出MVC哪一层出了问题是比较难的。
真正的问题:生产环境性能
在真实的场景中,Rails是以生产环境为用户提供服务,我们真正需要分析的是生产环境性能问题:哪个URL、什么时间、慢到什么程度,更进一步要分析问题出在哪个层面:DB,ruby计算,服务器等。要进行这些分析,需要拿到生产环境上的基础数据:慢URL(比如:responseTime超过5S),并且获得MVC各层消耗的具体时间。
抓取慢URL
在Rails3中要拿到这组基础数据并不难,利用Rails3提供的ActiveSupport::Notifications就可以获取详细的性能数据(类似Rails日志中的数据)。以下代码演示了Rails中如何捕获慢url,并记录到DB,供后续分析:
ActiveSupport::Notifications.subscribe "process_action.action_controller" \ do |name, start, finish, transaction_id, payload| total_duration = (finish - start) * 1000 # record visited page rate by duration max_duration = 4700 min_duration = 300 if total_duration > (rand(max_duration) + min_duration) VisitedPage.create! do |page_request| page_request.path = payload[:path] page_request.total_duration = total_duration page_request.view_duration = payload[:view_runtime] page_request.db_duration = payload[:db_runtime] page_request.hostname = `hostname`.strip end end end
常见分析方法
访问慢的URL
比如分析访问时间超过1S的:
select substring_index(path,'?',1) as url, avg(total_duration) as avg_duration, count(id) as count \ from visited_pages where total_duration > 1 and created_at > DATE_SUB(CURDATE(),INTERVAL 7 DAY) \ group by url order by avg_duration desc 分析结果: url, avg_duration(ms), count "uri1",162865,1 "uri2",162488,1 "uri3",161998,1
最耗费服务器资源的URL
访问慢的URL不一定就要优化,有两个方面可以来判定:用户是否能够感觉到,或者 对服务器负载是否高;
按负载来看 最需优化的URL:
select substring_index(path,'?',1) as url, SUM(total_duration) as sum_duration, \ avg(total_duration) as avg_duration, avg(db_duration) as avg_db, count(id) as count \ from visited_pages where created_at > DATE_SUB(CURDATE(),INTERVAL 7 DAY) \ group by url order by sum_duration desc 分析结果: url, sum_duration(ms), count "uri1",25873458,936 "uri2",21962420,710 "uri3",13119986,607
DB负载最高的URL
在一些请求当中,DB访问不合理会引起响应时间变长,db压力大;
select substring_index(path,'?',1) as url, SUM(db_duration) as sum_db_duration, count(id) as count \ from visited_pages where created_at > DATE_SUB(CURDATE(),INTERVAL 7 DAY) \ group by url order by sum_db_duration desc 分析结果: url, sum_db_duration(ms), visited_count "uri1",82088173,4666 "uri2",25319961,936 "uri3",5573929,607 "uri4",4121130,34
最繁忙的服务器
简单的说,可以按照机器承担的计算时间来评估 机器的负载是否过高;
select SUM(total_duration) as sum_duration, hostname from visited_pages \ where created_at > DATE_SUB(CURDATE(),INTERVAL 7 DAY) \ group by hostname order by sum_duration desc 分析结果: sum_duration(ms), hostname 140590337,"host1" 21120945,"host1" 20193051,"host2"
最繁忙的时间段
通常,对于一个用户量大的系统,在一天24小时的访问量分布是有规律的。比如:通过对kelude服务器的CPU、Memory监控发现,工作日的09:00-10:00 负载是一天中最高的;
而下面按照24小时统计的计算负载分布 也反应了这一点:
select SUM(total_duration) as sum_duration, count(id) as cnt, hostname, hour(created_at) as h \ from visited_pages where created_at > DATE_SUB(CURDATE(),INTERVAL 7 DAY) \ group by hostname,h order by sum_duration desc; 分析结果: sum_duration(ms), visited_count, hostname, hour 38837429,397,"host1",2 16109302,225,"host1",19 15204958,181,"host1",21 11442125,1463,"host2",0
基于上面的分析数据,相信你已经很清楚系统的性能瓶颈,然后再决定是否要优化DB,是否要添加ruby服务器,是否要负载均衡,是否要调整某些计算任务的时间等等。