Tail Your Test Logs

Dan Croak

Rails’ logs contain valuable information. You’ve probably seen output like the following:

Processing PagesController#show (for at 2009-09-09 19:07:29) [GET]
  Parameters: {"id"=>"about"}
Rendering template within layouts/narrow
Rendering pages/about
Rendered shared/_navigation (2.7ms)
Rendered shared/_flashes (0.8ms)
Rendered shared/_javascript (1.2ms)
Completed in 28ms (View: 21, DB: 0) | 200 OK [http://localhost/]

In my case, I ran script/server. If you’re running Passenger, you might run:

tail -f log/development.log

Tail your test log

If I do not understand a functional test failure, I run my tests in one shell and tail my test log in another. Usually, I’m checking to make sure the params are correct.

tail -f log/test.log

Tail your Cucumber log

Cucumber is pretty cool. One downside is lack of information in the backtrace. You can find out more by tailing the log!

tail -f log/cucumber.log

There’s a lot going on, isn’t there

Watching test logs, especially in the Test::Unit/Shoulda world, reminds me:

  • how much of the stack gets executed in functional tests
  • the quieting, focusing effect that stubbing and spying can have
  • stubbing and spying aren’t enough when you have to worry about what is happening in the view during your functional tests

Tiger bath