Effective print debugging

"The most effective debugging tool is still careful thought, coupled with judiciously placed print statements." Brian Kernighan, "Unix for Beginners" (1979)

Need to know the value of a variable? No problem, just add System.out.println("Something=" + something); to the next line and you are all set. It's easy, and chances are that you are modifying that piece of code anyway. There is no need to worry about logging frameworks, test suites, or debuggers; it's tempting to quickly add a println to check something. And as we programmers are so lazy, we do this from time to time.

This technique share similarities with manual end-to-end verification discussed in the previous post, but this time the code is augmented with additional print (or maybe log) statements to provide insight about what's going on in the bowels of the application. The additional requirement is to have access to the generated output.

Adding print statements shouldn't be hard even without an IDE, but it's worth checking out Komodo's new Print Debugging feature in action. It looks really awesome as it generates print statements for any given variable with a single click.

Komodo's print debugging feature

IntelliJ IDEA has a Live template shortcut built in to add print statements easily. Just type soutv and press TAB to print the name of the variable and its value.

IDEA's print debugging feature

Eclipse has a similar feature as well. If you type sysout and press CTRL+SPACE, it will expand to System.out.println. By default, Eclipse doesn't provide a template to print a specific variable like IDEA do, but a custom template can provide this feature.

Under the Window > Preferences > Java > Editor > Templates click New and add the following for sysoutv:

System.out.println("${var} = " + ${var});${cursor}
IDEA's print debugging feature

Pro

Besides its main selling point that its a no-brainer, print debugging has some other advantages. The generated log is a timeline of events with the snapshots of the internal state.

Authorizing: person='john'
Querying DB for 'john'
Record found: Person[id=42, username='john', firstName='John', lastName='Doe', age=20]
Checking age limit, ageLimit=18, user=Person[id=42, username='john', firstName='John', lastName='Doe', age=20]
Authorized

If you use logging libraries instead of simple print statements, you get timestamps and line numbers for free as well.

It can be great to catch sporadic events or to show trends and outliers of certain properties. The collected data can be easily visualized and processed with Excel or similar tools.

If you record the input parameters and return value of a function while you use the system, the log can be a great starting point to create automated unit tests. This can be handy if you have to modify code that lacks decent test coverage. This works best if your objects are nicely printable. In case of Java, it enforces toString-friendly classes.

The end of the bughunt can be a good time for some retrospective. The places where you had to inject extra print statements might pinpoint locations where the application's logging could be improved. The ad-hoc System.out.println calls can be promoted to actual log statements that adhere to the project's logging standards. By doing so, this technique can be used to catch bugs in the QA environment as well.

Con

The long feedback loop is true for this strategy as much as it is true for manual end-to-end verification. The application has to be redeployed after you add or remove the print statements, and the results have to be examined manually each time. The excessive use of logging can introduce problems on its own: storing, displaying and interpreting large volumes of text can be challenging.

Besides, it requires cluttering the codebase with print statements. Make sure not to commit them accidentally by reviewing the modified files.

This technique is a poor choice if you don't know exactly what you are looking for. Logging a few variables is one thing, but if you have to check multiple data structures and results from various method calls it can quickly get out of hands. It's even worse if you have to experiment with APIs in the middle of the code base and try to figure them out solely by printing the result of various method calls.

Using print debugging excessively can lead to boiling frog syndrome. Because it's easy, it's tempting to stick with it and add more and more print statements to the code, even when they clearly not get you closer to success. Try different approaches like debugging or unit testing when you feel overwhelmed by this method.

Summary

Simply adding println statements to the code can be one of the fastest ways of debugging. It builds atop of the same workflow used to build and run the application, and it's a great way to catch bugs that don't manifest in a typical development or debugging scenario. But it shouldn't be the only tool in the toolbox, as in many cases – like exploring APIs or complex state – simple debugging techniques are more efficient.

November 28, 2017
In this article