Recipe 4.9. Inspecting Requests with Filters
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.