Rails 3.2，Ruby 1.9和Unicorn - 第一个请求非常慢 - 如何调试？

我有一个在Unicorn上运行的大型2.3 Rails应用程序。我正在使用Unicorn，这样我可以实现零宕机部署。不过，我注意到重启后的第一个请求是很慢，很慢。Rails 3.2，Ruby 1.9和Unicorn - 第一个请求非常慢 - 如何调试？

第一个请求： Completed 304 Not Modified in 2771.8ms (ActiveRecord: 98.6ms)

第二个请求： Completed 304 Not Modified in 94.4ms (ActiveRecord: 26.9ms)

我有preload_app true，我重新建立在后叉数据库连接。

我不知道如何解释这两个值之间的2600ms背离。

有没有人有任何想法？真的，我正在寻找的是调试此问题的方法。

UPDATE

这里是一个重启后我unicorn.log：

I, [2014-05-16T13:46:26.529305 #11637] INFO -- : executing ["/data/app/current/ey_bundler_binstubs/unicorn", "-E", "staging", "-c", "/data/app/shared/config/custom_unicorn.rb", "-D", "/data/app/current/config.ru", {12=>#<Kgio::UNIXServer:fd 12>}] (in /data/app/releases/20140516184210) 
I, [2014-05-16T13:46:27.566115 #11637] INFO -- : inherited addr=/var/run/engineyard/unicorn_afar.sock fd=12 
I, [2014-05-16T13:46:27.566551 #11637] INFO -- : Refreshing Gem list 
I, [2014-05-16T13:47:13.036963 #8247] INFO -- : reaped #<Process::Status: pid 8681 exit 0> worker=3 
I, [2014-05-16T13:47:14.093196 #8247] INFO -- : reaped #<Process::Status: pid 8670 exit 0> worker=2 
I, [2014-05-16T13:47:14.100269 #12047] INFO -- : worker=0 ready 
I, [2014-05-16T13:47:15.105249 #12063] INFO -- : worker=1 ready 
I, [2014-05-16T13:47:15.114038 #8247] INFO -- : reaped #<Process::Status: pid 8655 exit 0> worker=1 
I, [2014-05-16T13:47:15.957970 #8247] INFO -- : reaped #<Process::Status: pid 8638 exit 0> worker=0 
I, [2014-05-16T13:47:15.958159 #8247] INFO -- : master complete 
I, [2014-05-16T13:47:16.087761 #12082] INFO -- : worker=2 ready 
I, [2014-05-16T13:47:16.876129 #11637] INFO -- : master process ready 
I, [2014-05-16T13:47:17.102994 #12095] INFO -- : worker=3 ready

这里是我的轨道记录的第一个请求：

Started GET "/" for 70.XX.XXX.XXX at 2014-05-16 13:47:51 -0700 
Processing by HomeController#index as HTML 
    (1.1ms) SELECT ..... <regular controller/ActiveRecord queries> 
Completed 304 Not Modified in 2724.8ms (ActiveRecord: 98.9ms)

来源

2014-05-16 earnold

我认为这是重启以后预期感：http://stackoverflow.com/questions/680302/how-can-i-find-out-why-my-app-is-slow –

First request to Rails app is very slow可能有关。

也许有一个依赖正在加载/运行在首页加载？

一些想法：

检查铁轨日志，看是否有针对独角兽或与其它服务器过什么事，时髦的事情
这只是发生？
与时间戳添加日志报表以获取什么应用程序的一部分花费很长的时间
尝试使用红宝石教授

来源

2014-05-16 20:39:11 Puhlze

我更新了一些额外的日志的问题。似乎没有任何事情发生。你认为哪里会是记录器声明的好地方？控制器内部？要么....？ – earnold

取决于您是否感觉缓慢可能来自哪里。如果这只是第一个请求，它可能超出了你的代码，所以像ruby prof这样的东西可能会提供更多信息。为了获得时间信息的快速方法，您可以将日志语句放在控制器，视图或模型中，以了解需要花费大量时间的情况。一大堆'logger.info Time.now'调用可以帮助揭示事情正在放缓的地方。在这种情况下，我会说尝试使用ruby-prof来玩一下，看看你是否能够更好地理解发生了什么。 – Puhlze

Rails 3.2，Ruby 1.9和Unicorn - 第一个请求非常慢 - 如何调试？

回答

相关问题