Logging or debugger?

It all begins when I read a small story over the net:

A young girl watching her mother prepare a ham to bake for dinner. As the mother cut both ends off the ham, the daughter asked why. Mom replied that her mother had always done it that way. When the daughter still insisted on knowing why, a quick call to grandma revealed the reason: “Because the pan was too small.”

The story above is exactly what I usually get when I try to present something new. Like what I’m going to do here.

Well, not exactly new. Debugging by using log vs. debugging using debugger was a long time debate. We can google dozens of articles written about the subject. And while most of them use the very political phrase “it depends” as an answer, I would confidently tell you “logging is obviously superior in 99% of the time“.

However, when meeting with some recent graduated students from universities, somehow they don’t feel the same way. They were still sticking to using debugger, because everyone is doing it. Even their professors, even their friends.

Debugger is sexy, isn’t it? You can stop the program at any point you want, check the variables’ values, verify if you do it right or wrong. Isn’t that cool? Why do I need to type all the statements to log the values we need? Of course, just click where I want the program to stop is much easier than write a log message. It made me think.

That’s exactly where the problem lies. People don’t want to think, and for good reasons. Why wasting our energy to do something that the debugger has prepared readily for us?

However, there’s a small problem with that thinking. Do you know where to put the check point?

When a bug happen, you say: “I’m not sure where it comes from, but it must be in function X”. Then you go and put a checkpoint in that function. After going through, you can find no obvious problem. Then you change the input and go through it, step by step, again. Repeat until you find the bug. Reasonable, right?

So what if you find the abnormal value? Unfortunately, there’s no Back button in the debugger. You don’t know what cause the variable has the wrong value. You will need to repeat the process again. It may link to another abnormal value.

And that is if you found the abnormal. If you don’t have a good test cases, probably you will miss cases. Even if you have, there’s probably the chance that your bug isn’t there. You made a guess in the beginning, remember? The bug may be not in function X.

So how about this? For each important step of the business process, you put a logging statement. Just a simple sentence will work:

LOG.debug("Customer ID {0} buy package {1} with  value {2}", id, package.Name, package.Value)
LOG.debug("Value of package {0} after discount:: {1}", package.Name, package.Price)
LOG.debug("Customer ID {0} buy package {1} with  price {2}", id, package.Name, package.Value)

The logging will be like:

10:00 AM – Customer 1001 buy package Training Program 101 with value $1000.

10:01 AM - Value of package Training Program 101 after discount $900.

10:01 AM - Customer 1001 buy package Training Program 101 with price $1000.

Simply speaking, debugging by using log have you cover the ground quicker. You look at the business process as a whole, not as many fragmented snapshots. When looking on a global level, locating the problem and discovering the root cause are much easier.

There’s also the benefit of trouble-shooting live system. But that’s another story.