When writing applications or even just longer programs, I used to sprinkle in PRINT statements regularly, telling me of the progress of the program. At some point, I would think the program is working correctly and I would then have to search through the code to find all the PRINT statements to either comment them out (smart, but leaves ugly code behind) or delete them (dumb, I would eventually need them again when I discovered some problem). This approach has some definite drawbacks:

1. there is no easy way to turn the complete output on and off, much less on a more granular level
2. output goes to the output log, but sometimes it would be nicer to send the output to a log file
3. PRINT provides little help for things that I commonly need to print like the time/date, the routine that the message is originating from, etc.

I’ve created the MG_LOG routine to help with these problems.

At it’s most basic MG_LOG just prints out a message that you provide:

IDL> mg_log, 'Hello'
2011-11-17 11:41:44.000 DEBUG: $MAIN$: Hello

There are five priority levels of messages; in decreasing priority they are:

1. critical
2. error
3. warning
4. informational
5. debug

The default is a “debug”-level message, but we can set that when we provide a message:

IDL> mg_log, 'Hello', /informational
2011-11-17 11:45:28.000 INFORMATIONAL: $MAIN$: Hello

We can also configure the logger to only show messages of a certain level or higher:

IDL> mg_log, level=3
IDL> mg_log, 'Hello', /informational   ;note no output because 2 < 3
IDL> mg_log, 'Hello', /warning
2011-11-17 11:46:55.000 WARNING: $MAIN$: Hello

This solves problem #1 above, you only need to set the level in one location in your program, e.g., on startup. Setting the level to 0 turns off all messages, further granularity is provided by the other levels. Even more granularity is provided by named loggers which are organized into hierarchies and can be individually configured, but I’m not going to go into detail about those right now.

Output can also be redirected to files when the logger is configured:

IDL> mg_log, level=3, filename='myapp.log'
IDL> mg_log, 'Hello', /critical

Now look at the contents of myapp.log:

IDL> $cat myapp.log
2011-11-17 11:52:26.000 CRITICAL: $MAIN$: Hello

The file is opened and closed between each writing, so you don’t have to worry about the log file not being up-to-date. This solves problem #2.

For problem #3, MG_LOG also provides a FORMAT keyword that gives a few variables that can be inserted automatically into the log message. For example, let’s set the FILENAME to a null string so that output goes to the output log again and try a new log message format:

IDL> mg_log, format='%(levelname)s: %(message)s', filename=''
IDL> mg_log, 'Hello', /critical, filename=''
CRITICAL: Hello

The default log message format is:

%(time)s %(levelname)s: %(routine)s: %(message)s

The FORMAT keyword uses a special syntax to substitute a selection of predefined variables (“time”, “levelname”, “routine”, “message”, “stacktrace”, and “name”) into the log message.

In the course of writing the logging framework I had to write a routine, MG_SUBS, that performs substitution of variables into a string by name. I wanted to make this routine as usable for general use as possible, so we get a very flexible formatting syntax. It uses the C format codes with the addition of a name in parenthesis between the % and the rest of the format code indicating which variable should get substituted into that format code. For example, this can be used by itself like:

IDL> print, mg_subs('%(loc)s temp: %(temp)0.1f F', $
IDL>                {loc: 'Boulder', temp: 65.})
Boulder temp: 65.0 F

This allows the variables to be provided in any order, to be used twice in the format, and to even provide variables that are not used in the format.

There is also a TIME_FORMAT keyword to further specify the format of the “time” variable in the FORMAT property. It uses Fortran-style format codes since there are no C-style calendar format codes. The default time format is:

C(CYI4.4,"-",CMOI2.2,"-",CDI2.2," ",CHI2.2,":",CMI2.2,":",CSF06.3)

Together FORMAT and TIME_FORMAT provide a lot of control and flexibility in the log message format.

To get the code for the logging framework (and MG_SUBS), grab the dist_tools package with Subversion:

svn co http://svn.idldev.com/dist_tools/trunk dist_tools

Let me know if this is useful to you or you have problems/requests!