Marty Andrews

ruby files as libraries or scripts

Listen to this article

Include the following snippet at the end of a Ruby file:

if $0 == __FILE__
    # do something
end

If you execute the file, the 'do something' block will run, but if you require the file, it won't. That way you can use the file as both a library and a script.

Posted by Marty Andrews at 12:50 PM | Permalink | Comments (0)

Classification does not equal prioritisation

Listen to this article

One of the classic mistakes that people make in planning agile software projects comes about when someone is asked to prioritise the stories to be done by the software team. The conversation usually goes like this:

Q: What do you think about Story A?
A: That's a priority one.

Q: Ok, what do you think about Story B?
A: That's a priority one as well.

At this point, the stories have not been prioritised. They have been classified into groups, where the group is named "Priority One". Whilst this may be a useful culling technique, do not fool yourself into thinking they are prioritised. What's worse for you is that, whether you like it or not, the stories will get done in some order. If the team is ready to start on a story and finds two of them that are both "Priority One", then they will pick one of them to do first. Sometimes, they will pick the wrong one.

Do your team a favour. Don't classify your stories. Prioritise them.

Posted by Marty Andrews at 10:10 PM | Permalink | Comments (1)

Logging in Ruby on Rails

Listen to this article

Ruby on Rails has a bunch of built in configuration items that are related to logging. You can set them up in your environment.rb file, or any of the specific environment override files. Here's an example of that file with all of the attributes listed:

Rails::Initializer.run do |config|
  config.logger = Logger.new
  config.log_level = :debug
  config.log_path = "log/myfilename.log"
  config.whiny_nils = true
  config.active_record.logger = Logger.new
  config.active_record.colorize_logging = false
  config.action_controller.logger = Logger.new
  config.action_mailer.logger = Logger.new
end

The logger attributes allow you to create a global logger, or a specific logger for the active record, action controller and action mailer framweworks. The log_level controls how much logging gets printed out (we'll see an example a bit later). log_path defines the location of your log file. whiny_nils gives you some more verbose output if you call a method on a nil object, and colorize_logging gives you colored output in your logs, which is useful if you're viewing them in a *nix terminal window.

As an example, I can create a Rails controller like this.

class SampleController < ApplicationController
  def do_logging
    logger.debug("what?")
    logger.info("done")
    logger.warn("uh oh")
    logger.error("bang!")
    logger.fatal("KABOOM")
  end
end

When executing the do_logging method on this class in a newly created Rails application, the following output appears in the terminal window:

what?
done
uh oh
bang!
KABOOM

I don't find this very useful, so I try configuring my Rails applications wth log4r instead. Here's an example of my setup in the development.rb file.

config.log_level = :debug
Log4r::Logger.root.level = Log4r::DEBUG
formatter = Log4r::PatternFormatter.new(:pattern => "[%5l] %d %30C - %m")
Log4r::StderrOutputter.new('console', :formatter => formatter)
Log4r::Logger.new('App').add('console')
RAILS_DEFAULT_LOGGER = Log4r::Logger.new('App::Rails')

This has substituted the Rails logger with a Log4r logger instead. The pattern formatter has been configured to print out the log level, date, context (logger name) and a log message. I've created a top level logger call 'App', and another logger called 'Rails' which is a child of the 'App' logger. The call to Logger.new with the parameter 'App::Rails' hooked the two together by name. Log4r loggers write to their parents output as well as their own, so I don't need to create any more outputters. Finally, I set my newly created logger to be the default Rails logger. Running my controller again now produces this output:

[DEBUG] 2007-06-26 11:45:56              App::Rails - what?
[ INFO] 2007-06-26 11:45:56              App::Rails - done
[ WARN] 2007-06-26 11:45:56              App::Rails - uh oh
[ERROR] 2007-06-26 11:45:56              App::Rails - bang!
[FATAL] 2007-06-26 11:45:56              App::Rails - KABOOM

That's much more useful now, however, I don't have any meaningful way of distinguishing log messages coming from the Rails framework to log messages coming from my code. Framework log messages will all have the context of 'App::Rails' too. I'd like to have a different context. I can now change my controller to be like this though.

require "log4r"

class SampleController < ApplicationController
  def initialize
    @@log = Log4r::Logger.new('App::SampleController')
  end
  
  def do_logging
    @@log.debug("what?")
    @@log.info("done")
    @@log.warn("uh oh")
    @@log.error("bang!")
    @@log.fatal("KABOOM")
  end
end

Making this change gets me the following output:

[DEBUG] 2007-06-26 11:45:56   App::SampleController - what?
[ INFO] 2007-06-26 11:45:56   App::SampleController - done
[ WARN] 2007-06-26 11:45:56   App::SampleController - uh oh
[ERROR] 2007-06-26 11:45:56   App::SampleController - bang!
[FATAL] 2007-06-26 11:45:56   App::SampleController - KABOOM

Now I can easily tell apart my log messages from the Rails framework messages.

You may have noticed that the Log4r configuration I used in development mode only outputs to the console, and not to a file as happens by default. I find that much more useful, as I don't have to bother cleaning up development log files any more. One final Log4r trick that I use is in production mode is to use a different outputter that automatically creates a new log file every day and names the files according to date. My production.rb file looks like this:

config.log_level = :warn
Log4r::Logger.root.level = Log4r::WARN
formatter = Log4r::PatternFormatter.new(:pattern => "[%5l] %d %30C - %m")
Log4r::DateFileOutputter.new('logfile', :dirname => "log", :formatter => formatter)
Log4r::Logger.new('App').add('logfile')
RAILS_DEFAULT_LOGGER = Log4r::Logger.new('App::Rails')

Those settings makes it easy to manage log files in production mode. Some people have reported possible errors when multiple mongrel processes try to roll a log file at the same time, and I haven't tested it in anger. Be careful that you test if you get into that situation. Otherwise, this setup has worked quite well for me.

Posted by Marty Andrews at 12:46 PM | Permalink | Comments (1)

Ruby articles in Builder AU

Listen to this article

Steve has been invited to contribute regularly to the Ruby series of articles in Builder AU. His first article, "Kicking off with Ruby", has just been published. Stay tuned for more.

Posted by Marty Andrews at 11:58 PM | Permalink | Comments (0)

Ruby Nuby Screencasts

Listen to this article

The Melbourne Ruby Group recently ran a Ruby Nuby night where they got a bunch of different people to do five minute presentations on various aspects of Ruby and Rails. I went along and recorded all of the presentations as screencasts. You can see them all on the Cogent Consulting screencasts page.

If Ruby on Rails is something you think you want to get into, we're running an introductory Ruby on Rails workshop on July 21. You can find out the details of our innovative pricing model and bid for a spot via our Easy Access Training page.

Posted by Marty Andrews at 05:17 PM | Permalink | Comments (1)