DEREK N
DEREK N

Reputation: 965

Rails controller action hanging

I am a newbie in ruby/rails and have been breaking my head with a problem for the past 2 days and am hoping that someone in this forum can help me out with it.

I am working on rails 4 and running an application in production using Passenger + Nginx with Mysql database (mysql2 adapter). I have following code in my ProductsController.rb (log_info is my custom logging wrapper that just calls the Rails logger):

def index
    log_info("ProductsController", "Getting Products...")
    @products = Product.get_products(params[:offset])
    log_info("ProductsController", "Got all Products...")

    # populate access_url before sending the data through
    update_products_with_access_url(@products)
end

Here is the definition of get_products function inside Product model:

def self.get_products(products_offset)
    products_offset ||= 0

    Product.includes(:categories, :suppliers).
            where(active: true).order(updated_at: :desc).
            limit(20).
            offset(products_offset * 20)
end

The problem is that my application hangs in production (works fine in dev) for a few mins when the index action is called. This behaviour is happening almost half the time - it works fine the other half of time.

I can see in the log that the action has been called but is not getting executed. Here is a snippet from the log file:

I, [2015-06-10T13:31:01.802673 #14916]  INFO -- : Processing by ProductsController#index as HTML
I, [2015-06-10T13:33:09.718339 #14916]  INFO -- : [INFO][2015-06-10 13:33:09 UTC][ProductsController][Getting Products...]
I, [2015-06-10T13:33:09.719365 #14916]  INFO -- : [INFO][2015-06-10 13:33:09 UTC][ProductsController][Got all Products...]
D, [2015-06-10T13:33:09.720980 #14916] DEBUG -- :   Product Load (0.8ms)  SELECT  `products`.* FROM `products` WHERE `products`.`active` = 1  ORDER BY `products`.`updated_at` DESC LIMIT 12 OFFSET 0
D, [2015-06-10T13:33:09.725110 #14916] DEBUG -- :   ProductCategory Load (0.5ms)  SELECT `product_categories`.* FROM `product_categories` WHERE `product_categories`.`product_id` IN (30, 29, 28, 27, 26, 25, 24, 23, 22, 21, 20, 19)

As you can see there is difference of at least 2 mins between the first two lines of log file above. And the log shows that index action had received the call, but I am not sure why it is taking so long (sometimes more than 5 mins.) to execute the very first line in that index action. I suspect there is some kind of caching happening. I was earlier thinking that the call might be hanging in connecting with MySQL database, but now am not sure. Am I missing something here?

Can someone please help me out in fixing this application hang issue?

Upvotes: 0

Views: 146

Answers (1)

Eugene Myasyshchev
Eugene Myasyshchev

Reputation: 4635

Please check if there are any before filters, quite often they can be the reason of such hangs.

Upvotes: 1

Related Questions