DebuggerHelper - A Handy Debugging Class for IDL Developers

Remember our old friend the IDL PRINT procedure?

In addition to faithfully showing us our derived output, it has also bailed us out of a lot of sticky code development problems over the years when Workbench breakpoints alone didn't suffice. Yes, sometimes bugs end up even in my code, put there by cosmic rays, random keystrokes and bouts of brain freeze.

PRINT does have its drawbacks as a debugging utility, however.  Here are four of them:

1. You have to type "PRINT,". And then some. That's a lot of typing.  (See Implied Print.)
2. Unless you develop applications for an audience of one, you generally need to eventually locate and comment out or remove all your debugging PRINT statements. If you choose otherwise, your live demo in front of your customer, manager, or thesis committee may show questionable comments in the IDL Console tab. Don't ask me how I know this.
3. When your workbench or command line window is closed as a result of willful misconduct (see: bugs), you'll lose any PRINT output that could have helped you debug the problem causing the needed information to disappear in a puff of illogic.
4. If you distribute IDL Runtime applications, as we frequently produce in the NV5 Custom Solutions team, the PRINT statement is of little or no value because there is no console output. You need a way to get useful information from your end user, to supplement the standard description of "IDL crashed!"

Over the course of a number of years a design pattern emerged in my application development. I found I really wanted a number of useful features:

1. It has to be easy to use and not obstruct the real work my application must perform
2. Debugging information should display in a widget separate from the IDL Console, if desired
3. Debugging output should be written to an auto-generated text file with a unique name, if desired
4. The command to produce output should be simpler to type than "PRINT,"
5. The utility should be a class that I can instantiate or from which I can subclass
6. The utility should automatically produce time-stamping and contextual information
7. I should be able to enable debugging without modifying my source code

Now I will hook you in with the simplicity of the resulting IDL class, one that provides all this capability but is only about 150 lines long. The code is listed at the bottom of the article.  Copy, paste and compile to play along.

Create the DebuggerHelper object and toggle on the debugging

IDL> d = debuggerhelper(/on)

This creates both a log file and a debug text widget. It can't get much easier to instantiate, thereby satisfying my first three requirements.

Generate a line of debugging output.

IDL> d.o, 'Hello bug'
(DEBUGGERHELPER) $MAIN$:Hello bug

Requirement 4?  Check.

I'm only showing the output in the IDL Console here, but I'm also writing information to a stand-alone text widget AND a text file. The displayed data shows the class from which the output is produced, which may be a subclass of DebuggerHelper, along with the context of the call. In this case we're at the IDL command line so this is $MAIN$.

If it were called from within an IDL function or procedure, that routine's name would replace $MAIN$, as shown later.

I can turn on TIC and TOC management to help test performance. This wasn't an original requirement, but I added it to my class while writing this article since it was incredibly simple to do so.

IDL> d.tic, 'Timer 1'
IDL> d.o, 'How long did it take me to type this?', toc = 'Timer 1'
(DEBUGGERHELPER) $MAIN$, Performance timer 1 dt=21.950000:How long did it take me to type this?
IDL> d.o, 'That was not very fast.'
(DEBUGGERHELPER) $MAIN$:That was not very fast.

I can have multiple timers defined by name to manage different code sections, if I desire.

Obviously, TIC and TOC aren't going to be as precise for high-performance testing when embedded in debugging statements since the act of watching and logging perturbs the system. However, they're still useful for cases where the operations under test take significantly more time than the debug I/O.

I can programmatically toggle my debugging on and off, which means I don't need to edit my source code, checking another item off my requirements.

IDL> d.off
IDL> d.o, 'Do not criticize my typing speed'
IDL> d.on
IDL> d.o, 'Sorry about that'
(DEBUGGERHELPER) $MAIN$:Sorry about that

The debug log file is automatically generated with a unique name, satisfying another requirement.  Let's see where it was put.

IDL> d.file
C:\mylib\logs\DEBUGGERHELPER1403199697.log

In this implementation, the log file is created relative to the location of the source .pro file (or SAVE file) by utilizing ROUTINE_FILEPATH, but you can follow your bliss when modifying the source code, or when subclassing from the original implementation.

Even after the object is destroyed or IDL exits, I can still view my debug information unless I proactively delete the file.

IDL> file = d.file
IDL> obj_destroy, d
IDL> b = strarr(file_lines(file))
IDL> openr,lun,file,/get_lun & readf, lun, b & free_lun, lun
IDL> b
[        11.310, 1403199708.570] (DEBUGGERHELPER) $MAIN$:Hello bug
[        66.141, 1403199763.401] (DEBUGGERHELPER) $MAIN$, Timer 1 dt=21.950000:How long did it take me to type this?
[        84.052, 1403199781.312] (DEBUGGERHELPER) $MAIN$:That was not very fast.
[       119.896, 1403199817.156] (DEBUGGERHELPER) $MAIN$:Sorry about that

Notice that the log file contains additional time stamp information that was not printed to the IDL Console.

I like to show two times. The first is the elapsed time in seconds since the object was created.  It's easier for me to do elapsed-time math in my head with numbers formatted this way. The second time is SYSTIME(1) output. If I have multiple debug objects in an application, I can later merge the log files and sort messages by time. For example I may want to sequence device communication protocols used in different parts of my application, or even among individual, stand-alone applications or IDL_IDLBridge processes.

I may want to ask a customer running my application to turn debugging on so that internal statements I'd built into the code will come to life. How do we fully address the final requirement, that I should not need to change the source code to enable debugging from a Runtime IDL application?

GETENV or COMMAND_LINE_ARGS offer two alternatives. For example, I may ask a client to create an environment variable in their operating system, whose name I have hardwired into the code, before starting my IDL Runtime application. During execution, I always create the debug object but I toggle the debugging statements on or off based on the environment variable setting, for example

toDebug = getenv('DEBUG_IDL_APP') eq 'YES'

d = debuggerhelper(on = toDebug, no_file = ~toDebug)

Here, if the user has not created an environment variable named DEBUG_IDL_APP or they have not populated that environment variable with the string "YES", then the debug helper object will be created, but it will be silent.

Even the presence or absence of a file placed in a particular directory can be used for this purpose, along with a corresponding FILE_TEST call in your code.

Adding the debug object to another class, or subclassing from it, will provide additional feedback. Here, we will create a DebuggerHelper object as a member variable within a new "MyObj" class.

IDL> .run
- function myobj::init
- return, 1
- end
% Compiled module: MYOBJ::INIT.
IDL> .run
- function myobj::init
- self.d = debuggerhelper(/on)
- return, 1
- end

IDL> .run
- pro myobj::yelp
- self.d.o, 'Within myobj'
- end
% Compiled module: MYOBJ::YELP.

Create an object of this class and call the method that generates debugging output

IDL> m = myobj()
IDL> m.yelp
(DEBUGGERHELPER) MYOBJ::YELP:Within myobj

Notice that the class and method names from which the debug output was generated are now displayed in my output as well.

Here's the source IDL for DebuggerHelper. I think it's straightforward, but leave a comment if you have questions. I'd enjoy the feedback, and I'd get a better sense if only web crawlers read our blogs.