Stupid Simple Debugging

There are all kinds of fancy debugging tools out there, but personally, I get the most mileage out of good old puts statements.

When I started with Ruby, several years ago, I used puts like this to debug:

puts account.inspect

The problem with this is two fold. First, if you have a few puts statements, you don’t know which one is actually which object. This always led me to doing something like this:

puts "account: #{account.inspect}"

Second, depending on whether you are just in Ruby or running an app through a web server, puts is sometimes swallowed. This led me to often times do something like this when using Rails:

Rails.logger.debug "account: #{account.inspect}"

Now, not only do I have to think about which method to use to debug something, I also have to think about where the output will be sent so I can watch for it.

Enter Log Buddy

Then, one fateful afternoon, I stumbled across log buddy (gem install log_buddy). In every project, whether it be a library, Rails app, or Sinatra app, one of the first gems I throw in my Gemfile is log_buddy.

Once you have the gem installed, you can tell log buddy where your log file is and whether or not to actually log like so:

LogBuddy.init({
  :logger   => Gauges.logger,
  :disabled => Gauges.production?,
})

Simply provide log buddy with a logger and tell it if you want it to be silenced in a given situation or environment and you get some nice bang for your buck.

One Method, One Character

First, log buddy adds a nice and short method named d. d is 4X shorter than puts, so right off the bat you get some productivity gains. The d method takes any argument and calls inspect on it. Short and sweet.

d account # will puts account.inspect
d 'Some message' # will puts "Some message"

The cool part is that on top of printing the inspected object to stdout, it also logs it to the logger provided in in LogBuddy.init. No more thinking about which method to use or where output will be. One method, output is sent to multiple places.

This is nice, but it won’t win you any new friends. Where log buddy gets really cool, is when you pass it a block.

d { account } # puts and logs account = <Account ...>

Again, one method, output to stdout and your log file, but when you use a block, it does magic to print out the variable name and that inspected value. You can also pass in several objects, separating them with semi-colons.

d { account; account.creator; current_user }

This gives you each variable on its own line with the name and inspected value. Nothing fancy, but log buddy has saved me a lot of time over the past year. I figured it was time I send it some love.

13 Comments

Keith DeLong
Sep 01, 2011

Log_buddy automagically getting its own line with the name and inspected value is going to be a huge time saver. Beautiful. Thank you John!
Jaime Macey
Sep 01, 2011

No link to the code on github ?!? That’s the most important part!
Mark Wilden
Sep 01, 2011

LogBuddy is great. It does have limitations, though. If memory serves, it finds the name of what it’s displaying by opening the source file and parsing its own call. Pretty cool. However, that means you can’t put two calls on one line, or one call on multiple lines. Not a big deal, I imagine.

d is not a good method name – just try grepping for it. My own tool started off as l, then became ll, then (when Rails started using that), lll. And that’s where it stands today (gem install lll).

lll doesn’t require any initialization. It just automatically logs to the Rails log (if there is one), it does its puts’ing in reverse video, and has a couple of other small benefits. You call it with lll {’account’} (which is a good candidate for an editor macro).
gmarik
Sep 01, 2011

what about `p account` ?
James sadler
Sep 02, 2011

You should be able to avoid the source file parsing by looking at the bindings of the current scope (Kernel#binding).
Peter Cooper
Sep 02, 2011

Is it possible to make log_buddy use awesome_print style output? #inspect is grim once you get used to awesome_print and its indentation and unravelling of complex data structures :-)
John Nunemaker
Sep 02, 2011

@Peter – I’m sure it is. Probably would just need to add an option for what method to be called instead of doing inspect. Please do investigate… :D
Ryan Davis
Sep 02, 2011

@mark:

Please use grep properly: grep -nr ‘\bd\b’ lib
Mark Wilden
Sep 03, 2011

@ryan: I think it’s easier to grep for a unique term. I also label lll’s output with ‘lll’ so it’s easy to find in log files or in the terminal window. But point taken.
Mark Wilden
Sep 03, 2011

@james: I don’t see how Kernel.binding would help you determine the text of the expression.

@john, @peter: Another alternative is to use pretty_inspect instead of inspect. pretty_inspect is in the standard library.
Jack Dempsey
Sep 06, 2011

Awesome John, had been thinking about building this exact functionality today. Thanks for saving the time.
Rob Sanheim
Sep 11, 2011

Thanks for the writeup, John. Although LogBuddy hasn’t been touched in quite awhile, we still use it in all our recent Rails / Ruby apps at Relevance. Patches and pull requests are welcome…
Dhiren Gupta
Sep 14, 2011

Thanks for sharing this.
@john: please tell us which one do you prefer log_buddy or awesome_print?..your suggestion would be helpful.