PabloBM

ActiveRecord: getting a backtrace of your SQL queries

The other day I had some strange database queries in my Rails log. I didn’t know what was originating them, so I set out to track down their origin.

Thus I found out about ActiveSupport::Notifications. It is used by Rails to notify about events ocurring inside the framework, and is used to generate the standard logs that we see in our applications. We can turn them to our advantage to solve the problem at hand.

We can tap into these notifications to find out what is generating those DB queries. To do this, we print out the backtrace of the program when we get notified of an SQL query happening. Like this:

# lib/query_tracer.rb
module QueryTracer

  # Borrowed some ANSI color sequences from elsewere
  CLEAR = ActiveSupport::LogSubscriber::CLEAR
  BOLD = ActiveSupport::LogSubscriber::BOLD

  def self.start!
    # Tap into notifications framework. Subscribe to sql.active_record messages
    ActiveSupport::Notifications.subscribe('sql.active_record') do |*args|
      QueryTracer.publish(*args)
    end
  end

  # Notice the 5 arguments that we can expect
  def self.publish(name, started, ended, id, payload)
    name = payload[:name]
    sql = payload[:sql]

    # Print out to logs
    ActiveRecord::Base.logger.debug "#{BOLD} TRACE: #{sql}#{CLEAR}"
    clean_trace.each do |line|
      ActiveRecord::Base.logger.debug "  #{line}"
    end
  end

  def self.clean_trace
    Rails.backtrace_cleaner.clean(caller[2..-1])
  end

end

QueryTracer.start!

To make this work, we only need to require the module from anywhere appropriate. An initializer would be a good place, for example:

# config/initializers/query_tracer.rb
require 'query_tracer'

Now, for each SQL query generated within ActiveRecord, we will get the following output in the logs:

 TRACE: INSERT INTO `user_words` (`created_at`, `updated_at`, `user_id`, `word_id`) VALUES ('2011-11-27 18:33:53', '2011-11-27 18:33:53', 2, 2)
  app/models/user.rb:18:in `block in add_word'
  app/models/user.rb:12:in `tap'
  app/models/user.rb:12:in `add_word'
  app/controllers/words_controller.rb:6:in `create'

And that’s it!

Eclipse doesn’t let me to findViewById

Yesterday I did my first bit of Android development ever. I created a very simple program that simply updated some text on screen.

I had a problem though. On my Activity, I had the following piece of code:

public void updateText(View view) {
    TextView t = (TextView)findViewById(R.id.button);
    t.setText("Updated!");
}

And the following bit ox XML in my layout (inside a LinearLayout):

<Button
    android:id="@+id/button"
    android:layout_width="wrap_content"
    android:layout_height="wrap_content"
    android:text="@string/button"
    android:onClick="updateText"
 />

Eclipse insisted that R.id was illegal. Specifically, the error was id cannot be resolved or is not a field, even though the button did exist in the view.

The problem was that I had not yet defined the string “button” in my strings.xml file:

<string name="button">Click me!</string>

Not sure of the exact internals, but I guess that Eclipse was trying to compile the layout, and it failed because the string was missing. In turn, this showed an error in the activity, because it was using a broken layout.