Organized Logs with LogCabin

While optimizing our Rails apps, I used the standard Rails Logger to output performance information about specific trouble-spots of code. Having to constantly grep through the production log, however, was driving me nuts. What I really wanted to do was to write information about a specific problem area to a specific file, without adding a lot of extra code.

And now the LogCabin Rails plugin makes this very easy (Get it on GitHub).

The LogCabin plugin is designed to give you the flexibility to
write information about blocks of code and their execution times to
specific log files in your Rails project. LogCabin can also be used in Rake tasks, which can be incredibly helpful for debugging and monitoring long-running tasks.

Example Usage

This is especially useful when monitoring and debugging a specific set of
code in a model or controller file. As a contrived example:

class UsersController < ApplicationController
  def index

    LogCabin.log_to :user_search do |log|
      log.debug "Finding all users with params = '#{params[:user_search].map{|k,v| "#{k}: #{v}"}.join(', ')}'"

      @users = User.search(params[:user_search])
      log.info "Found a total of #{@users.length} users"

      log.warn "ONLY FOUND #{@users.length} USERS" if @users.length < 50

    end
  end
end

LogCabin logs the time it took to run the block, along with any info, debug or warn messages that you ran on the log object. This code might print the following out to RAILS_ROOT/log/user_search.log:

DEBUG: Finding all users with params = 'last_name: Smith, city: Chicago'
INFO: Found a total of 32 users
WARN: ONLY FOUND 32 USERS
TIME: Tue Nov 18 12:34:52 -0600 2008: Operation took 3.2876 seconds

It is also possible to pass an :if or :unless option to LogCabin#log_to, ex:

LogCabin.log_to :users_query, :if => RAILS_ENV == 'development' do |log|

  log.info "This will not output anything unless we're in development"
  puts "But any other Ruby code in this block will always be run"
end

Leveraging Capistrano

I think one of the best parts about using LogCabin is how easy it is to check up on these logs across multiple production servers using Capistrano. Here’s a cap task that will let you tail a specific log or monitor the live stream:

# Assumes the deploy_to variable has been set in your Capistrano config
namespace :deploy do
  namespace :log do

    desc "Tails a log "
    task :tail, :roles => [:app] do

      set(:log_name) do
        Capistrano::CLI.ui.ask "Which log do you want to fetch? "

      end
      set(:line_count) do
        Capistrano::CLI.ui.ask "How many lines should I fetch? (blank to tail log) "

      end
      if line_count.strip! =~ /^d+$/

        run "tail -n #{line_count} #{deploy_to}/current/log/#{log_name.gsub(/.log$/, '')}.log"
      else
        run "tail -f #{deploy_to}/current/log/#{log_name.gsub(/.log$/, '')}.log"

      end
    end
  end
end

Download LogCabin from GitHub