Profiling Database Queries in Rails

Mar 13, 2008 @ 2:16 pm

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.

To get this working, first I monkey patch the MysqlAdapter to collect database stats:

  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:

<% 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 %>
  <br />
  <% 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">
    <a style="color:magenta" href="#" onclick="superHide()">super hide!</a>
  </p>
  </h4>
  <script type="text/javascript">
    function superHide() {
      document.cookie = 'debug=hidden; path=/; domain=<%= request.host %>; max-age=14400';
    }
    if(document.cookie.indexOf('debug=hidden') != -1) {
      $('debug').hide();
    }
  </script>
<% 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