Logging in Rails
Rails has logging built right into the framework. Or, to be more accurate,
Rails exposes a Logger object to all the code in a Rails application.
Logger is a simple logging framework that ships with recent versions of
Ruby. (You can get more information by typing ri Logger at a command
prompt or by looking in the standard library documentation in Programming
Ruby [TH01]). For our purposes, it’s enough to know that we can
generate log messages at the warning, info, error, and fatal levels. We can
then decide (probably in an environment file) which levels of logging to
write to the log files.
logger.warn("I don't think that's a good idea")
logger.info("Dave's trying to do something bad")
logger.error("Now he's gone and broken it")
logger.fatal("I give up")
In a Rails application, these messages are written to a file in the log directory.
The file used depends on the environment in which your application
is running. A development application will log to log/development.log, an
application under test to test.log, and a production app to production.log.
13.7 Debugging Hints
Bugs happen. Even in Rails applications. This section has some hints on
tracking them down.
First and foremost, write tests! Rails makes it easy to write both unit
tests and functional tests (as we saw in Chapter 12, Task T: Testing, on
page 132). Use them, and you’ll find that your bug rate drops way down.
You’ll also decrease the likelihood of bugs suddenly appearing in code that
you wrote a month ago. Tests are cheap insurance.
Tests tell you whether something works or not, and they help you isolate
the code that has a problem. Sometimes, though, the cause isn’t immediately
apparent.
If the problem is in a model, you might be able to track it down by running
the offending class outside the context of a web application. The
scripts/console script lets you bring up part of a Rails application in an irb
session, letting you experiment with methods. Here’s a session where we
use the console to update the price of a product.
depot> ruby script/console
Loading development environment.
irb(main):001:0> pr = Product.find(:first)
=> #<Product:0x248acd0 @attributes={"image_url"=>"/images/sk..."
irb(main):002:0> pr.price
=> 29.95
irb(main):003:0> pr.price = 34.95
=> 34.95
irb(main):004:0> pr.save
=> true
Logging and tracing are a great way of understanding the dynamics of
complex applications. You’ll find a wealth of information in the development
log file. When something unexpected happens, this should probably
be the first place you look. It’s also worth inspecting the web server log for
anomalies. If you use WEBrick in development, this will be scrolling by on
the console you use to issue the script/server command.
You can add your own messages to the log with Logger object described in
the previous section. Sometimes the log files are so busy that it’s hard to
find the message you added. In those cases, and if you’re using WEBrick,
writing to STDERR will cause your message to appear on the WEBrick console,
intermixed with the normal WEBrick tracing..
If a page comes up displaying the wrong information, you might want to
dump out the objects being passed in from the controller. The debug( )
helper method is good for this. It formats objects nicely and makes sure
that their contents are valid HTML.
<h3>Your Order</h3>
<%= debug(@order) %>
<div id="ordersummary">
. . .
</div>
Finally, for those problems that just don’t seem to want to get fixed, you
can roll out the big guns and point a debugger at your running application.
This is normally available only for applications in the development
environment.
To use breakpoints:
1. Insert a call to the method breakpoint( ) at the point in your code where
you want your application to first stop. You can pass this method a
string if you’d like—this becomes an identifying message later.
2. On a convenient console, navigate to your application’s base directory
and enter the command
depot> ruby script/breakpointer
No connection to breakpoint service at
druby://localhost:42531 (DRb::DRbConnError)
Tries to connect will be made every 2 seconds...
Don’t worry about the No connection message—it just means that
your breakpoint hasn’t hit yet.
3. Using a browser, prod your application to make it hit the breakpoint( )
method. When it does, the console where breakpointer is running will
burst into life—you’ll be in an irb session, talking to your running
web application. You can inspect variables, set values, add other
breakpoints, and generally have a good time. When you quit irb, your
application will continue running.
By default, breakpoint support uses a local network connection to talk
between your application and the breakpointer client. You might be able to
use the -s option when you run breakpointer to connect to an application on
another machine.