URLs, Filters and the Rails Action Controller

Problem

You have taken over development of a Rails application, and you are trying to figure out how it processes requests. To do so, you want to install a logging mechanism that will let you inspect the request cycle in real time.

Solution

Use an after_filter to invoke a custom logging method for each request. Define a CustomLoggerFilter class:

app/controllers/custom_logger_filter.rb:

  require 'logger'
  require 'pp'
  require 'stringio'

  class CustomLoggerFilter 

    def self.filter(controller)
      log = Logger.new('/var/log/custom.log')
      log.warn("params: "+controller.params.print_pretty)
    end
  end

  class Object
    def print_pretty
      str = StringIO.new
      PP.pp(self,str)
      return str.string.chop
    end
  end

Install the logger in the AccountsController by passing it as an argument in a call to after_filter:

app/controllers/accounts_controller.rb:

  class AccountsController
< ApplicationController

    after_filter CustomLoggerFilter

    def index
      list
      render :action => 'list'
    end

    def list
      @account_pages, @accounts = paginate
:accounts, :per_page => 10
    end

    def show
      @account = Account.find(params[:id])
    end

    def new
      @account = Account.new
    end

    def create
      @account = Account.new(params[:account])
      if @account.save
        flash[:notice] = 'Account was successfully
created.'
        redirect_to :action => 'list'
      else
        render :action => 'new'
      end
    end

    def edit
      @account = Account.find(params[:id])
    end

    def update
      @account = Account.find(params[:id])
      if @account.update_attributes(params[:account])
        flash[:notice] = 'Account was successfully
updated.'
        redirect_to :action => 'show',
:id => @account
      else
        render :action => 'edit'
      end
   end

    def destroy
      Account.find(params[:id]).destroy
      redirect_to :action => 'list' 
    end
  end 

Discussion

Rails filters allow you to do additional processing before or after controller actions. In the solution, we’ve implemented a custom logging class that is invoked after calls to any actions in the Accounts controller. Our logger opens a filehandle and prints a formatted version of the params hash for easy inspection.

With the logger in place, you can use the Unix tail command to watch the logfile as it grows. You’ll see what happens to the params hash with every action that’s called:

  tail -f /var/log/custom.log

For the AccountsController in the solution, you can watch the log as you list, create, and destroy accounts.

  params: {"action"=>"list",
"controller"=>"accounts"} 
  params: {"action"=>"new",
"controller"=>"accounts"}
  params: {"commit"=>"Create",
   "account"=>{"balance"=>"100.0", "first_name"=>"John",
"last_name"=>"Smythe"},
   "action"=>"create",
   "controller"=>"accounts"} 
  params: {"action"=>"list",
"controller"=>"accounts"} 
  params: {"action"=>"destroy",
"id"=>"2", "controller"=>"accounts"}
  params: {"action"=>"list",
"controller"=>"accounts"}

Rails comes with a number of built-in logging facilities. This approach gives you an easy way to add logging to a controller with only one line of code. You can also limit what actions of the controller the filter is applied to.

See Also

Recipe 4.10, “Logging with Filters”