ruby-on-railsrubymemory-leaksrack-mini-profiler

How to determine the cause of a delay before an action is hit in my Rails app?


I've come to a dead-end with my troubleshooting, and I'm really hoping someone can help.

I'm using rack-mini-profiler to help locate a potential memory leak in my Rails website. I narrowed it down to the method that is being called.

High-level profile: rack-mini-profiler high-level

SQL profile: rack-mini-profiler results

In the SQL profile picture, notice the start times of the query just above and just below the gray bar have a difference of 1037ms. That is the delay I am noticing, and it grows until I restart the application.

When running this locally, I can monitor the terminal. When that method is requested, there is just that 1 second delay, and then it executes. No queries or commands show up in the terminal during that delay.

Does anyone have any ideas as to how I can figure out what is causing this delay?

I'm using Ruby 2.2.0 with Rails 4.1.6.

Thanks!!

EDIT:

This is the method rack-mini-profiler is pointing to:

def submit_answer
    quiz_attempt = CourseCompletion.find_by_id(params[:course_completion_id]).quiz_started
    choice = Choice.new(:answer_id => params[:answer], :quiz_attempt_id => quiz_attempt.id)
    @success = choice.save
    @answer = choice.answer
    @question = @answer.question
    @quiz_attempt = choice.quiz_attempt
    render :layout => false
  end

Solution

  • take a look on ruby-prof github.com/ruby-prof/ruby-prof. Try to wrap body of your action into the block:

    require 'ruby-prof'
    
    # profile the code
    RubyProf.start
    # ... code to profile ...
    result = RubyProf.stop
    
    # print a flat profile to text
    printer = RubyProf::FlatPrinter.new(result)
    printer.print(STDOUT)
    

    and you should receive output in console which would look like: enter image description here

    You also can redirect output of profiler to log or some file on the server.

    So in your case edit code:

    def submit_answer
        require 'ruby-prof'
        # profile the code
        RubyProf.start
    
    
        quiz_attempt = CourseCompletion.find_by_id(params[:course_completion_id]).quiz_started
        choice = Choice.new(:answer_id => params[:answer], :quiz_attempt_id => quiz_attempt.id)
        @success = choice.save
        @answer = choice.answer
        @question = @answer.question
        @quiz_attempt = choice.quiz_attempt
        render :layout => false
    
        result = RubyProf.stop
        # print a flat profile to text
        printer = RubyProf::FlatPrinter.new(result)
        printer.print(STDOUT)
      end
    

    Add to gemfile

    gem 'ruby-prof'
    

    Run bundle install and restart the server. Try to run action again and check rails console output. Methods on top of the table are most time consuming.