Tenderlove Making

Profiling Database Queries in Rails

Despite the recent Ruby webserver speed contests, most of the slowness at my job results from slow (or too many) database queries.

To help keep database queries down, I added a stats to every page that shows the number of queries vs. cache hits, the number of rows returned, and the amount of data transferred from the database. In this screenshot I’m using the “live” environment, 3 cache hits, 169 misses, 577 rows returned, and 458.9k data transferred. Clicking the box hides it, and clicking “Super Hide!” hides the box and sets a cookie so that the box doesn’t show up again for a while.

Debug Window

To get this working, first I monkey patch the MysqlAdapter to collect database stats: ~~~ ruby ActiveRecord::ConnectionAdapters::MysqlAdapter.module_eval do @@stats_queries = @@stats_bytes = @@stats_rows = 0

def self.get_stats
  { :queries => @@stats_queries,
    :rows => @@stats_rows,
    :bytes => @@stats_bytes }
end
def self.reset_stats
  @@stats_queries = @@stats_bytes = @@stats_rows = 0
end

def select_with_stats(sql, name)
  bytes = 0
  rows = select_without_stats(sql, name)
  rows.each do |row|
    row.each do |key, value|
      bytes += key.length
      bytes += value.length if value
    end
  end
  @@stats_queries += 1
  @@stats_rows += rows.length
  @@stats_bytes += bytes
  rows
end
alias_method_chain :select, :stats   end ~~~

Next I patched the QueryCache to keep track of hits and misses:

  ActiveRecord::ConnectionAdapters::QueryCache.module_eval do
    @@hits = @@misses = 0

    def self.get_stats
      { :hits => @@hits,
        :misses => @@misses }
    end
    def self.reset_stats
      @@hits = @@misses = 0
    end

    def cache_sql_with_stats(sql, &block)
      if @query_cache.has_key?(sql)
        @@hits += 1
      else
        @@misses += 1
      end
      cache_sql_without_stats(sql, &block)
    end
    alias_method_chain :cache_sql, :stats
  end

Then modify ActionController to reset stats for each request:

  ActionController::Base.module_eval do
    def perform_action_with_reset
      ActiveRecord::ConnectionAdapters::MysqlAdapter::reset_stats
      ActiveRecord::ConnectionAdapters::QueryCache::reset_stats
      perform_action_without_reset
    end

    alias_method_chain :perform_action, :reset

    def active_record_runtime(runtime)
      stats = ActiveRecord::ConnectionAdapters::MysqlAdapter::get_stats
      "#{super} #{sprintf("%.1fk", stats[:bytes].to_f / 1024)} queries: #{stats[:queries]}"
    end
  end

Just drop all that inside the after_initialize in your development.rb and you’ll get the nice stats. After that, just create a partial that displays the stats and include the partial at the bottom of your layout. Our partial looks like this: ~~~ html <% unless %w(production test).include?(RAILS_ENV) -%> <h4 id="debug" onclick="$(this).remove()" style="background:pink;text-align:center;position:absolute;top:16px;left:35%;padding:0.5em;border: 2px solid red;"> <%= RAILS_ENV %>
<% if ActiveRecord::ConnectionAdapters::QueryCache.respond_to?(:get_stats) %> <% stats = ActiveRecord::ConnectionAdapters::QueryCache.get_stats %> Queries: <%= stats[:hits] %> / <%= stats[:misses] %> / <%= number_to_percentage((stats[:hits].to_f / (stats[:hits] + stats[:misses])) * 100, :precision => 0) %> | <% end %> <% if ActiveRecord::ConnectionAdapters::MysqlAdapter.respond_to?(:get_stats) %> <% stats = ActiveRecord::ConnectionAdapters::MysqlAdapter.get_stats %> Rows: <%= stats[:rows] %> | Transfer: <%= sprintf(“%.1fk”, stats[:bytes].to_f / 1024) %> <% end %> <p style="margin:0"> super hide! </p> </h4> <% end -%> ~~~

It’s a little work, but it helps keep my mind on reducing the queries. With enough work, one of these days the speed of the webserver will matter to me. Thanks to Adam Doppelt for the basis of this monkey patch. Any bugs are mine, not his!

« go back