Writing Debugging Information to a File

Problem

Contributed by: Bill Froelich

A bug has been reported, and you can't reproduce it in your development environment. To figure out what is happening, you want to do some specific logging in your production environment where you think the bug might be. You need a function that writes debugging information to a specific file, dedicated to this debugging effort.

Solution

Create a logging method to write messages to a logfile of your choosing. Add it to the application.rb file so that it is available throughout your application:

app/controllers/application.rb:

class ApplicationController < ActionController::Base
 def my_logger(msg)
 f = File.open(File.expand_path(File.dirname(__FILE__) + \
 "/../../log/recipe-list.log"),"a")
 f.puts msg
 f.close
 end
end

Once you have created the logging function, you can use it throughout your application to write debug information to the specified file. These examples assume you have the cookbook example application already installed. Here's how to add logging to the list method:

app/controllers/recipes_controller.rb:

class RecipesController < ApplicationController
 # ...
 def list
 my_logger("Starting Recipe List Method")
 @recipe_pages, @recipes = paginate :recipes, :per_page => 10
 my_logger(@recipes.inspect)
 my_logger("Leaving Recipe List Method")
 end end

Start your Rails server and view the recipes list view in your browser to trigger calls to my_logger:

http://localhost:3000/recipes/list

If you look at the logfile, you'll see a list of all the recipes. If the situation warrants it, you can implement much more copious logging.

Discussion

The my_logger method simply takes a parameter and appends its contents to the logfile specified in the File.open. The file is opened for appending (with "a"); it is automatically created if it doesn't already exist. After viewing the Recipe list in your browser, your logfile will look like this (depending on the contents of your recipe table):

Starting Recipe List Method
[#<Recipe:0x2556b28 @attributes={"see_also"=>"", "discussion"=>"",
 "sort_order"=>"0", "title"=>"Introduction", "id"=>"1", "chapter_id"=>nil,
 "solution"=>"", "problem"=>""}>, #<Recipe:0x2556a38
 @attributes={"see_also"=>"", "discussion"=>"", "sort_order"=>"0",
 "title"=>"Writing Debugging Information to a File", "id"=>"2",
 "chapter_id"=>nil, "solution"=>"", "problem"=>""}>]
Leaving Recipe List Method

You add information to the log simply by calling my_logger and passing in what you want to log. You can sprinkle the my_logger calls throughout your code, anywhere you want to collect output to be added to the logfile.

The my_logger method in the solution uses log/recipe-list.log as the file the method logs to. Rails puts its own logfiles in this directory, so if you use it, make sure you choose a unique file name. You can change the my_logger method to write to any file you want. For example, here's how you would log to a hardcoded path in /tmp:

File.open("/tmp/rails-logging/recipe-list.log")

But using the default Rails log directory makes your application much more portable: you won't have to make sure the logfile path exists and is writable by the user running your web server.

It is also helpful to know when the message was written. This is especially true if the application has been running for a while and has lots of logging calls. To add a timestamp to the log messages, modify my_logger to write the date and time before writing the msg parameter:

def my_logger(msg)
 f = File.open(File.expand_path(File.dirname(__FILE__) + \
 "/../../log/recipe-list.log"),"a")
 f.puts Time.now.strftime("%Y-%m-%d %H:%M:%S") + " " + msg
 f.close end

If you are viewing the list page again after making this change, your logfile will look something like this:

2006-06-08 21:07:33 Starting Recipe List Method
2006-06-08 21:07:33 [#<Recipe:0x2549590 @attributes={"see_also"=>"",
 "discussion"=>"", "sort_order"=>"0", "title"=>"Introduction", "id"=>"1",
 "chapter_id"=>nil, "solution"=>"", "problem"=>""}>, #<Recipe:0x2549554
 @attributes={"see_also"=>"", "discussion"=>"", "sort_order"=>"0",
 "title"=>"Writing Debugging Information to a File", "id"=>"2",
 "chapter_id"=>nil, "solution"=>"", "problem"=>""}>]
2006-06-08 21:07:33 Leaving Recipe List Method

Writing Debugging Information to a File

Problem

Solution

Discussion

See Also