Rails Unicorn - Delay between starting request and reaching controller

Question

I am using Unicorn as my app server for my Rails app, and am trying to figure out why there sometimes is sometimes a non-trivial (> 5 seconds) delay between the start of a request, and when it reaches my controller.

This is what my production.log prints out:

Started GET "/search/articles.json?q=mashable.com" for 138.7.7.33 at 2015-07-23 14:59:19 -0400**
  Parameters: {"q"=>"mashable.com"}

Searching articles for keyword: mashable.com, format: json, Time: 2015-07-23 14:59:26 -0400

Notice how there is a 7 second delay in between STARTED GET: and "Searching articles for keyword", which is the first thing the controller method does.

articles.json is routed to my controller method "articles" which simply does this for now:

def articles
        format = params[:format]
        keyword = params["q"]

        Rails.logger.info "Searching articles for keyword: #{keyword}, format: #{format}, Time: #{Time.now.to_s}"

end

This is my routes.rb

MyApp::Application.routes.draw do
    match '/search/articles' => 'search#articles' 
    #more routes here, but articles is the first route
end

What could possibly cause this delay? Is it because an Unicorn worker is busy? Is it because an Unicorn worker is taking up too much memory which leads the system to be slow?

Note: I don't believe the delay is in making any database connections but I could be wrong. The code doesn't need to make a database call, and the max connections for my database is 1000, and there are usually at most 1-2 connections.

Answer 1

Three thoughts:

1. You'll probably be better served using Puma instead of Unicorn

2. It could be that your system is running out of memory, or it could have plenty of memory available: install New Relic to troubleshoot where the bottleneck is

3. It could also be that you have more Unicorn instances than the number of connections your DB allows, in which case the instance is having to wait for others to disconnect before it can connect. This would likely manifest itself with irregular 5-second delays rather than happening every time.