'Twas the night before launch...

Written on 7:10:00 PM by S. Potter

Oh fun times! On such fateful nights you know you will find something that will screw things up unless immediately addressed. It must be someone's law already, but if it isn't I call dibs on it and it should thus be called "Potter's Law":). On a night before launch that I recently experienced, I had a heart stopping moment. The last 5 days of the sprint I had been churning out last minute changes based on usability feedback from the client. In the process, I had neglected to include benchmarking and memory leak testing with the same discipline I prefer. On the night before launch I ran my usual benchmarking scripts. The results were pretty good except on one action. We could have lived with that performance, but the real problem came when I ran tests to detect memory leaks in my Rails application. Let the real fun begin! Before continuing, I should mention there is only thing I hate more than uber visual tasks (editing/creating graphics, layout tweaking, etc.) and that is debugging memory leaks. I ran the ab (Apache Bench) utility on a few different types of pages in the staging environment and didn't notice any problems. The Rails application was consistently teetering under 50M RAM. Excellent! Then I tried the second most requested type of page (this was a static site we were rewriting in Rails to create an easy to use domain-specific CMS - so we had live production web statistics) and my heart skipped a beat or three. Memory usage spiraled out of control. From 49.5M the single mongrel process eventually grew to 250M after a few ab -c2 -n100 .... runs. I first checked out the view since I knew the controller action code was only 6 lines (how much could go wrong there?). I tried removing different parts of the view code and rerunning my tests while monitoring the memory usage of the process. Still no change. So I reluctantly looked in the controller and saw something like the following:


  def show
    @eto = ExchangeTradedOption.find_active(params[:id])

    respond_to do |format|
      format.html # show.rhtml
      format.xml  { render :action => "xml", :layout => false }
      format.csv  { render :action => "csv", :layout => false }
    end
  end
What on earth was in the ExchangeTradedOption.find_active method?

  class << self
    def find_active(id)
      now = Time.now
      find(
        id,
        :include => [:exchange, {:vendor_symbols => [:vendor]}],
        :conditions => [
          %{options.expires_at <= ? AND options.active = 1 AND 
            vendor_symbols.effective_date <= ? AND vendor_symbols.expiration_date >= ?}, 
          now, now, now
        ],
        :order => 'vendor_symbols.effective_date DESC'
      )
    end
  end
Ouch! The problem was that I still needed all vendor symbols and vendors for the view in question and didn't want to make the extra SQL queries for the Vendor on each VendorSymbol as that would have added between 5-10 extra SQL queries per action invocation. I guessed the nested includes in the find was most likely to be causing the issue. So I refactored as followed:

# Controller action code: ExchangeTradedOptionsController#show
  def show
    @eto = ExchangeTradedOption.find_active(params[:id])
    @vendor_symbols = VendorSymbol.find_active_for(params[:id])

    respond_to do |format|
      format.html # show.rhtml
      format.xml  { render :action => "xml", :layout => false }
      format.csv  { render :action => "csv", :layout => false }
    end
  end

# Model finder code: ExchangeTradedOption.find_active
  class << self
    def find_active(id)
      now = Time.now
      find(
        id,
        :include => [:exchange],
        :conditions => [%{options.expires_at <= ? AND options.active = 1}, now],
      )
    end
  end

# The VendorSymbol.find_active_for method implementation is left as an exercise for the reader
# but it is very, very simple!

# Changed view to refer to @vendor_symbols array instead of @eto.vendor_symbols
# This also helped reduce indirection and prevented Law of Demeter violations in the view code!
Of course, I didn't leave it without verifying! Never just guess that the problem is solved, you should always verify this with tests (either automated or manual). There were a few solutions, of course. One is the one I provided above. The second solution I thought of trying was removing the vendor_symbols SQL conditions and sorting in Ruby. This seemed a waste of CPU to me and extra lines of code I felt was unnecessary (remember the less code you write the less you need to maintain!). The third solution was to execute an optimized raw SQL query myself. I also didn't like this option as the first one presented about seemed cleaner and more maintainable going forward. The first solution does cause more than one SQL query to be executed each time the action is run, but it is scalable as it remains constant at two queries per invocation. In addition I added one extra instance variable, which is also not ideal, but again this didn't seem to me to be the worst problem at this stage with only two instance variables in the action being set for the view. The benchmarking results proved my assumptions correct regarding the various solutions. The moral of the story is find the best solution based on the context rather than attempting to apply a one-query-per-action-invocation rule to the whole application, which might be ideal, but occasionally unrealistic and/or catastrophic.

If you enjoyed this post Subscribe to our feed

No Comment

Post a Comment