That gave us code like this:
def defuse_bomb
with_log('defuse_bomb') {puts "Snip the red wire..."}
end
Our with_log method took care of printing out some logging info before and after executing the block given to it.
But as Adam pointed out in the comments, this is still kind of ugly. We don't have all the actual logging code inside of the "defuse_bomb" method, but have had to modify it to use with_log. What if we could add logging more transparently?
We can! With some metaprogramming magic added to the Logging module, here's the way the DangerBox class looks now:
class DangerBox
extend Logging
add_logging_to(:defuse_bomb, :throw_error)
def defuse_bomb
puts "Snip the red wire..."
end
def throw_error
puts 'I feel an error coming on...'
raise 'Success: an error!'
end
# This method's output won't be logged
def eat_poison
puts "Mmmmm, poison!! Nom Nom Nom Nom!!!!"
end
end
It still works the same way as it did before:
d = DangerBox.new d.defuse_bomb # ==== Sun Jun 12 16:55:49 -0400 2011 ==== # About to execute 'defuse_bomb'... # Snip the red wire... # Executed 'defuse_bomb' successfully. d.throw_error # ==== Sun Jun 12 16:55:49 -0400 2011 ==== # About to execute 'throw_error'... # I feel an error coming on... # Error while executing 'throw_error': 'Success: an error!'! d.eat_poison # Mmmmm, poison!! Nom Nom Nom Nom!!!!
Adam, I see your "hmmmm" and raise you a "BOOYAH!" (Although I didn't write tests for my version of this, so you still win on that front.)
But how the heck did we get all this logging output? Obviously, it's something to do with the line that says:
add_logging_to(:defuse_bomb, :throw_error)
Well, yes: that and a spiffy new Logging module that redefines our methods on the fly to use logging. Here's the code:
module Logging
# Keeps track of the methods we want to log
def add_logging_to(*args)
@logged_methods ||= []
@logged_methods.concat(args)
end
# Anytime a method gets added to our class (like with "def"),
# this will execute
def method_added(method_name)
if @logged_methods.include?(method_name)
# A lock to prevent infinite recursion; since we're
# going to add a method below, we don't want that
# to make method_added fire again, which would
# make it fire again, etc...
unless @adding_with_metaprogramming
@adding_with_metaprogramming = true
stashed_method = "stashed_#{method_name}".to_sym
# Creates a new method named, for example,
# "stashed_defuse_bomb", which does the same
# thing as "defuse_bomb"
alias_method stashed_method, method_name
# Now we redefine "defuse_bomb" to do this:
define_method method_name do
begin
puts "==== #{Time.now} ===="
puts "About to execute '#{method_name}'..."
# Calls "stashed_defuse_bomb" to get the original version
send(stashed_method)
puts "Executed '#{method_name}' successfully."
rescue Exception => e
puts "Error while executing '#{method_name}': '#{e.message}'!"
ensure
puts "\n\n"
end
end
end
# Remove the lock
@adding_with_metaprogramming = false
end
end
end
Metaprogramming! It sounds terrifying, doesn't it? Like, if programs can write programs, next thing you know, the Terminator is going to be ripping through your door! But it's actually slightly less terrifying than that.
Anyway, I got the idea for the last post from reading one chapter in "Eloquent Ruby," and I got the idea for this post while lying in bed after reading another chapter. So: thumbs up, Eloquent Ruby! I hereby recommend you.
