Be careful with callbacks and log messages in Rails

A lot of times I see a very annoying 'feature' in rails projects.

People using log messages in some callbacks of ActiveRecord to display some values.

before_save :add_generated_order_number

def add_generated_order_number
  self.order_number = SequenceNumber.next_order_number
  log.debug "Added #{order_number}"
end 

This is potentially dangerous, since log has a very nice feature. It returns a value depending on the log level. If log level is on DEBUG (typically development and test mode setting) it will return TRUE, if log level is on INFO (typically production mode setting) it will return FALSE, breaking the chain of callbacks, thus the record is NOT being saved. Make sure you're testing your code against production mode. Put the loglevel in your test environment setting to the same value as your production setting.

See add function return values:
http://www.ruby-doc.org/stdlib/libdoc/logger/rdoc/classes/Logger.html#M000901