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:
- there is no easy way to turn the complete output on and off, much less on a more granular level
- output goes to the output log, but sometimes it would be nicer to send the output to a log file
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:
- critical
- error
- warning
- informational
- 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!
November 17th, 2011 at 3:52 pm
Cool, that’s much better than any of the logging solutions I’ve come up with. Though the search-and-replace required to use it now is a bit heavy…
November 18th, 2011 at 11:22 am
I didn’t know that people used the forums on the Exelis VIS website!
November 18th, 2011 at 5:23 pm
Wow – I must say, I absolutely love this. I’ve been wanting something like this for ages – and I think I might spend most of Monday adding this in to most of the code I’ve written.
mg_subs sounds great too – seems to be very like the Ruby syntax for including strings, which I prefer to almost any other language.
Keep up the great work,
Robin
November 18th, 2011 at 11:50 pm
Thanks! I have really found
MG_SUBS
to be pretty useful. Another feature about it that I didn’t mention is that substitution variables can be provided via a hash as well.November 23rd, 2011 at 1:22 am
Looks to be a useful tool for IDLDE testing. The filename parameter to a log file is not implemented in the version 1.0 is it?
November 23rd, 2011 at 11:40 am
I’m not sure what you mean by a “filename parameter to a log file”? The filename for a log file can be specified using the
FILENAME
keyword toMG_LOG
.November 24th, 2011 at 3:08 am
I must have downloaded an old version of mg_log from svn.
November 26th, 2011 at 4:00 am
sorry my error, Mike..
August 5th, 2014 at 9:01 am
[…] use mg_log as my logging utility. It is simple to use, but has some powerful features for filtering and […]
May 19th, 2015 at 7:33 am
[…] a routine that lets you configure log output in an application. For more detailed information, see previous I have published about it. But the simplest example […]