SYNTAX
#include "V.h" /* Pick one */ #include "audit.h" #include "trace.h" #include "verbose.h"argc = Vinit(argc,argv); /* Pick one */ argc = D_init(argc,argv); argc = V_init(argc,argv);
D1 fmt,v,... D; /* Debug message */ H5 buf,n,lbl D; /* Hex dump */ P3 fmt,v,... D; /* Plain message */ S2(SYS_ERR,fmt,v,...); /* Syslog message */ V4 fmt,v,... D; /* Verbose message */
DD(c,l) fmt,v,... d; /* Messages tied to specific debug flag */ DH(c,l) buf,n,lbl d; DP(c,l) fmt,v,... d; DS(c,l) SYS_ERR,fmt,v,... d; DV(c,l) fmt,v,... d;
char *Vtime() -- Get time in multiple formats. int Vchklog() -- Create new Vout file if needed.
Function-stack debug hooks:
Fenter(fctname); -- Should be first statement in function. Fexit; -- Should be before every return. ChkFlvl; -- Check the debug function stack. FExit; -- The same as (ChkFlvl,Fexit);
char *caller(n) -- name of function n away in the stack. char *Caller -- name of the next-higher function. char *Fctname -- name of this function. char *progname -- full name of this program (argv[0]). char *pname -- short name of this program.
DESCRIPTION
This describes John Chambers' C debug/audit/verbose package. This is an assortment of useful tools and hooks for making problems with C programs easier to diagnose. This is a merger of three older C packages (V, audit, verbose) that had similar functionality. The intent is to provide aids for the initial debugging of C code, plus tools for writing audit trails, and tools for making programs wordy at times and silent at others.
This is a big package, with lots of odds and ends, and you don't want to treat it as a "black box". You will want to study its features, and you will probably want to make changes for your own needs. I don't advise putting this package into a library. If you use the whole thing, it will load your executables down with a lot of baggage that you aren't using. Rather, make your own copy and strip it down to the essential features that you need.
The V package mostly writes to the "Vout" file, which is opened by the Vinit() routine, and defaults to stderr. There are also the "V" output routines which always write to stderr. It is easy to control this package's behavior from the environment, with minimal impact on the original code. But you will need to add a call to the init routine and add lots of debug output lines.
There is a global variable "Vlvl" which controls the level of detail to be reported, and a debug output stream "Vout" which defaults to stderr, but which may be easily assigned to a file. There are a set of routines and macros that produce assorted debug output messages to the Vout stream and/or to the syslog, and also some hexdump routines. There are also macros that are wrappers around the system calls, plus as assortment of useful little routines.
In most cases, you can verbosize a C file by replacing the #include of stdio.h with any of:
#include "V.h"
#include "audit.h"
#include "verbose.h"
and by adding one of these calls at the start of main():
argc = Vinit(argc,argv);
argc = D_init(argc,argv);
argc = V_init(argc,argv);
If main() is declared to use all three of its arguments; you could use envv instead of environ. You may find that other #include lines need to be removed or commented out; look in V.h and local.h for hints. In most cases, you can add
#include "V.h"
after the last #include in the source file, and things will compile
without problems.
It should be noted that V.h itself includes several other header files, primarily local.h, which must be present, and is used to tailor things for a particular system. It has been found easiest to divide the work up into multiple header files, though this can be a bit confusing at first.
You should edit local.h to make sure that it's right for your system. Almost everything in it is system-dependent. It also has a set of enable/disable flags for pieces of this package.
In addition, V.h includes the str.h header for the string package, and wrappers.h which defines macros as "wrappers" around lots of functions to enforce correct types and numbers of parameters. There are probably other header files #included; this depends on which version of this package you have. Here's a list that is likely to be accurate, but the easiest way is to just try a compile and see what comes up missing. The V directory should contain all the needed header files, which can be linked into any directory where they are needed.
In summary, including V.h may #include any or all of:
"local.h" -- System-dependent stuff.
"str.h" -- String-handling package.
"wrappers.h" -- Macros to replace function calls.
"V_wrap.h" -- Debug versions of some of the wrappers.
"sys_wrap.h" -- Plain versions of some of the wrappers.
"sys_ctype.h" -- Standard C types.
"sys_types.h" -- Unix types.
"sys_time.h" -- Unix clock routines.
"sys_stdio.h" -- Standard C I/O library.
"sys_errno.h" -- Unix error codes.
You MUST edit local.h; you might want to look into the others to see what they're doing. The sys_*.h files are to handle the porting problems caused by differences in /usr/include on various systems; you might need to edit them to get them to include things the right way for your system. Start with sys_time.h, which can be tricky.
This package generally has two naming conventions, "verbose" and "debug", due to the fact that it is designed to be used for two different (but similar) purposes. As a "verbose" package, its job is to make it easy to add an audit trail to a program, and to use that audit trail for explanations of problems that the program may encounter while trying to do its job. As a "debug" package, its job is to help diagnose problems within the program itself. The latter is mostly of interest during development, but problems ("bugs") often arise in the distributed versions of programs, too.
SYNTAX
Very simple. The C preprocessor doesn't allow us to have a macro with a variable number of arguments. The final D macros is usually not really needed; it just expands to ')' by default, and I've often used parens instead of D. But there's one situation where the final D macro is quite valuable: It allows you to do something after the call.
What would you want to do after the call that can't be done inside the Vdmsg() function? The most common answer that I've had is: global locking and unlocking of mutexes when using threads. What I've done is add code to the Dn macros to set a global lock, and D expands to '),' plus a global unlock. On several systems, this has provided a quick and elegant "proof" that the stdio package is not thread safe.
Note that, if you are to do this, you will need to convert all stdio functions to a form that does locking and unlocking. This is easy with the ones that have a fixed number of args; V.h contains capitalized versions of most of them, and a single sweep with your favorite editor will do the capitalization. The remaining problems are with the variable-arg stdio functions: [fs]printf() and [fs]scanf(). There are FP...F and PF...F macros pairs that should be used to replace fprintf() and printf(). The scanf functions are so far handled merely by having capitalized versions of their names, which you can modify to generate a '(', but otherwise it has been ignored. The scanf functions aren't used all that often that I've had to worry much about them.
So, if you don't like the Dn "..." D; syntax, feel free to edit V.h to eliminate them. I've done just that on occasion. But I've found that this syntax turns out to be useful when you least expect it. And it does make the debug stuff stand out, both to human eyes and to text processing software.
INITIALIZATION
Before calling anything in this package, you should call Vinit (D_init and V_init are synonyms), passing it the arguments from main(), as shown above. This does assorted initialization, examines the environment vector for any interesting information (as described below), and also examines the command line for a verbose option as follows.
The most important thing that Vinit does is to open the Vout stream. It is stderr by default, but there are several mechanisms for pointing it at a file.
To minimize the possibility of conflict with other option-handling code, the V package has a global variable "Vflgchr" whose value defaults to '%'; an option starting with this char plus a 'D' or 'd' is a debug option. It will be removed from the argv[] vector, and the new arg count will be returned. Thus you can use %D2 as an extra command-line argument, and the program won't see it.
The rest of the debug option string should be of the form:
The debug level defaults to 1, which should produce only serious
error messages. The file name defaults to standard error, file 2.
This string is actually parsed by calling Vopt(argv[a]+2), and
you may call Vopt() yourself to initialize the debug output
stream. Calling Vopt(0L) will re-initialize, including closing
and reopening the Vout stream; this may be used (e.g., in
response to a CONT or HUP signal) to continue after deleting a
large logfile.
ENVIRONMENT
The Vinit() routine examines the environment for a variable whose name is "V_" or "D_" plus the current program's name. Thus a program /usr/lib/foo would have a debug environment variable "V_foo" or "D_foo". The value of this variable is of the form:
where
setenv V_bar 3/tmp/bar.log
and the first line of your main() routine would look like:
argc = Vinit(argc,argv);
This call would pick up the V_bar variable from the environment,
set the Vlvl variable to 3, and set the Vout file to the named
file by calling fopen("/tmp/bar.log","a").
If there is both a command-line and environment debug setting, the one from the command line is used. If neither exists, the defaults debug option is "1", which writes level 0 and 1 messages to stderr.
The environment variables HEX_FMT and HEX_WORD may be used to set the hex_fmt and hex_word variables for hex dumps in all programs.
The environment variable DBG_SIZE is used to set the value of the global variable Vsizlim, which is used by some programs to decide when to delete (or rename) the logfile and create a new one. After renaming Vfile, you can call Vopt(0L) to close and reopen the Vout stream.
USAGE
This package has several debug output routines, and a set of macros that surround them and make them easier to type. The most useful is
Dn(format,value,...);
where n is a debug level [0-9], format is a printf() string,
followed by the usual list of values to print. The Dn() functions
print their message only if Vlvl is n or higher; they also
prepend the last n functions on the stack if you have used the
Fenter() routine. Note that the Dn() functions don't require a
final '\n'; they always add one, and they always call fflush() to
force the output into the stream.
There is also a set of macros Pn that act like Dn, but they don't add any initial function identification to the output. I call them frequently in the form:
P2("%s ### Can't open \"%s\" [Err %d=%s=%s]",Vtime(),fname,Erreason);
The Vtime() routine returns the current timestamp as a printable
string; Erreason is a macro that gives errno, the error mnemonic,
and the error message string.
The Vn() functions are similar to Pn(), but they write to stderr. The intent is to make these "verbose" messages that explain what's happening to the user. These functions should be used sparingly, to avoid flooding the user with messages. (Perhaps there should also be a set of such routines that write to stdout, but so far we haven't found much need for them.)
The Sn() macros are conditional calls of syslog(); they take the syslog priority code as their first arg, and are otherwise like the Dn() and Pn() macros. Note that there are several variants of the syslog package, and they aren't all compatible, so if you use these macros, you might have to modify the V_s() routine that they call to get things to work right.
The Hn() macros invoke a hexdump routine. The call:
H5(buf,n,"INpkt");
will produce a hex dump of n bytes starting at buf. The first line
of output will be labeled "INpkt"; subsequent lines will have the
offset (in both hex and decimal) as labels.
There are three hexdump formats, controled by the hex_fmt variable, which may be set from the HEX_FMT environment variable. The default format is the 3-line "vertical" style: The first line shows the printable ASCII form, or '_' if it isn't printable; the second line shows the high-order hex digit for the char above it; the third line shows the low-order hex digit. This format is convenient (since it shows the hex immediately below the ASCII char) and compact (showing 64 bytes on 3 lines). It is by default divided into 8-byte "words"; this may be changed by assigning a different value to the global variable "hex_word"; a value of 0 suppresses these extra spaces. There is also a "horizontal" hex dump format that some people prefer; and also a one-line IBM-style dump. The values for hex_fmt are:
'3' or 'v' Vertical format (default) 64 bytes per 3 lines.
'2' or 'h' Horizontal 2-line format 32 bytes per 2 lines.
'1' 1-line IBM-style format 16 bytes per 1 line.
The Dn() routines can show the function stack as part of their output messages. To enable this feature, you must call Fenter("function") on entry to each routine, and use either Fexit (no args) or Freturn(v) on exit. Unfortunately, there is no easy way to automate this within C. There are some alternatives defined to Fenter and Fexit, for experimenting on a few systems where there are problems with the V package itself. If you use Fenter in a routine, you may use Fctname in your own messages to get the name of the function. Note that since Fenter has both a declaration and an assignment statement, it must be used at the boundary between the declarations and the statements in a function.
The recommended form of a C function is:
foo(x,y)
...
{ int r=0;
Fenter("foo");
...
done:
fail:
Fexit;
return r;
}
where Fenter() must immediately follow the local variables, and the
{Fexit;return r;} may be abbreviated to Freturn(r);
This package also defines a set of "wrappers" around the system calls that you may use in two ways, as follows. First, there are a set of macros whose names start with capitals that do casts on all their arguments and call debug versions whose names start with "s_". Thus the Open(n,f,m) macro calls s_open((char*)n,(int)f,(int)m) This has the advantage that type and arg-count problems will be caught and either corrected or flagged during compilation if the compiler can't do the cast. In a few cases, like open(), the system calls don't always have the same number of arguments, so there are macros Open2(n,f) and Open3(n,f,m) that are more specific. You may also, of course, call the s_* routines directly. The macros are recommended, because they will do type conversion of arguments, and will tell you if you have the wrong number of arguments. Note that a few of the functions have abbreviated names, due to the length limitations in some linkers. Look at s_ghbn(), for instance.
There are some extra system-call macros that have an 'M' on the end of their names, and have an extra parameter that is a string to be used in debug messages. Thus you can write:
if (!(p = (char*)MallocM(n,"rtable")))
Fail;
and if there aren't n bytes available, a message will be written to
the audit trail saying that it can't get n bytes for rtable. This
can be used to make code smaller and more readable.
It is often useful to include timestamps in debug output. There is a Vtime() function that returns a pointer to an ASCII string that may be used in debug output. It is a somewhat shortened version of the localtime() routine's output. As an aside, Vtime() also leaves the time in the "Vtimp" variable, and leaves the 32-bit value in the "Vtiml" variable. There are also global pointers that give you the date to various precisions:
Vtimy = "YY/MM/DD hh:mm:ss"
Vtimm = "MM/DD hh:mm:ss"
Vtimh = "hh:mm:ss"
As of this writing, Vtimp and Vtime() regurn Vtimm, but this
may be easily changed according to local preference.
LEVELS
There are 10 debug levels supported [0-9]. How these are used is pretty much up to you, of course. On the other hand, it is useful if there are some general guidelines that will help the user guess which level to use to diagnose a problem. Note that the default level is 1, and level 0 is not recommended, except in extreme cases. It is occasionally handy to have level 0 suppress all messages. Here are some suggested (and very rough) debug levels:
It can be useful to set things up so that during installation, the tests are run at debug level 2 or 3, and this should give the tester a good idea as to what has failed and where to look to fix problems. A person with the source should be told to run at levels 5-7 next to diagnose the problems. Levels 8 and 9 should be rarely used, except during initial testing to isolate such problems as compiler bugs and non-portable code.
GLOBALS
The V package has a number of variables which you may find useful. The Fenter() macro declares a local struct Vfct; you may use Vfct.name to access the name of the current function. This can be handy in writing further macros that thus don't need to be told the name of the function they're called from. Note that the C preprocessor also defines the _FILE_ and _LINE_ symbols, and they are also very useful in debug messages. The Venvvar variable is the name of the program's environment V variable; it is really only useful in help messages.
The global variable Vlvl holds the debug level; Vflvl holds the
current depth of the function stack. The Vout stream's name is
kept in Vfile. The current debug string (
The variable Vfshow is the number of functions to show in D*()
messages; setting it to -1 means to show Vlvl functions. The
default is 3.
The Vtime() routine returns a printable date+time, without the
final \n that the Unix localtime() and gmtime() produce. Its value
is left in a set of global variables:
Usually, Vtime() returns Vtimp, but it is sometimes convenient
for some applications to modify it to return Vtimm or Vtimh. It
is easy enough to change this; see Vtime.b for details.
For hexdumps, the hex_word variable holds the "word size", i.e.,
the number of bytes between blank columns. The default is 8;
setting it to 0 turns off these blank columns. Also, the hex_fmt
variable may be 'V' or '3' for the 3-line vertical format (the
default), 'H' or '2' for the 2-line horizontal format, or '1' for
the 1-line format.
FLAGS
This is a new feature that hasn't been fully tested or integrated with the rest of the package yet. You might try it out and let me know what you think of it.
There is a table of 256 debug "flags" that may be used to provide different debug levels for different packages within a program. They are set by starting the debug option string with one or more 2-byte flag settings, separated by white space or by any of the punctuation chars ",:;-". For example:
setenv V_bar '6M:3r:5%:2/tmp/bar.out'
This would set the 'M' flag to 6, the 'r' flag to 3, the '%' flag
to 5, and all the rest of the flags (and Vlvl) to 2, with the
output going to "/tmp/bar.out". You can use these debug flags via
the macros:
DD(c,l)(fmt,...);
DP(c,l)(fmt,...);
DS(c,l)(code,fmt,...);
DV(c,l)(fmt,...);
Use of non-printing chars as debug flags is not recommended (but we
may come up with some neat way to deal with them in the future).
The memory-allocation routines Malloc(), MallocM(), Realloc(), ReallocM() and Free() have been modified to write their messages under control of the 'M' flag. You can set the M flag to 6 (or higher) to get output from all your calls of these macros. This is useful in hunting down memory leaks. The VM.h file defines some compact debug macros for the 'M' flag, and is included as a sample of how you might define abbreviations for the use of other flags.
(Note also that the memchunk module is now included as an alternate way of getting space, with extra description args to help diagnose memory leaks, so you may not want to use Malloc() et al.)
The Vtest program has some calls on the memory routines; you can see these calls by typing something like: Vtest %d6M:1 This will get you the 'M' debug messages 0-6, which includes the calls and results of these routines.
There are a few functions in the library that can put a process to sleep; Sleep(), Wait() and Select() are the best-known of these. Their messages use the 'S' debug flag, which is defined in the VS.h header file.
You are encouraged to include the VM.h and VS.h header files in your programs, and use them to generate your own messages when you allocate memory or do things that may cause sleeping.
To set up a specific debug flag for your own package, the easiest way is probably to clone VM.h or VS.h and edit it.
MISC
The Vout file can grow to be large. You are encouraged to catch the CONT signal with a routine that calls Vopt(0L) to close and reopen this logfile. If this is done, then a daemon's logfile can be truncated by renaming or removing it and sending a "kill -CONT" to the daemon. It is also common practice for the INT signal to do this, so perhaps you should catch both of them.
There is a function caller(n) that returns a pointer to the name of the function n levels away in the stack. Note that caller(0) is your own name; caller(1) is the name of the function that called you, and so on. The parameterless "Caller" macro is a short name for caller(1), for convenience in writing nasty error messages about bad parameters. Fctname and caller(0) should always return the same string (though Fctname won't work in routines that don't call Fenter()).
The Vchklog() function checks the Vout file's size. If it is bigger than Vsizlim, or is missing, a new V file is created. The old one will be renamed according to the BACKUP environment variable (default: '-' is appended).
On systems that implement the syscall() routine, it is possible for this debug package to intercept the standard Unix library routines such as open(), read(), etc. You may or may not like this feature. You can disable it if you like with no damage to the package. You will have to grep for the uses of SYSCALL, and #ifdef out the code that you find there.
If you call Open() instead of open(), the debug package's version of this routine remembers the file name. You can use FileName(f) to get the name used to open a file f. This also works for the standard three files, and for file handles returned by Pipe() and Socket(), too, but what is returned is a descriptive string. The intent is that FileName(f) returns a string that can be used in debug messages, so please don't modify it to return a null.
COMPILE-TIME OPTIONS
There are a few things used in this package that are determined at compile time. It is usually risky to link code compiled one way with a libV.a that is compiled differently. The V.h header file includes local.h, as a way of making it obvious what is local and what is not. You should look into local.h for how things are set up on your system.
#undef LITTLENDIAN #define BIGENDIAN #undef MIXEDENDIAN
Exactly one of these should be defined. A few routines, such as those dealing with IP addresses, need to know the byte order.
#define MEMUNIT(n)
This is the memory chunk size on this system. It's ok if it gives a too-small value, but a too-large value may be a disaster, because several pieces of code use this to round a chunk's size up. This is mostly to determine whether a realloc is needed.
#define USE__LINE__
If this symbol is defined, the D*, H* and P* macros will store the current value of __LINE__ in the current function's header, and the number may then be included in debug messages. The line number is generally the last call of a debug macro, not where the program is actually executing. Getting the real line number can't be done in C in a portable fashion, because C compilers simply don't supply that information. Some compilers have a -p options to enable the collection of run-time line numbers, and you might be able to add this to your copy of V.
EDITORIAL
One of the curious things about the way the human mind works is illustrated by the following sort of conversation, which I've heard on numerous occasions, where A is a programmer and B is a manager:
It seems that B never realizes that A has really just asked the same question three times. All too often, programmers ask only the first one, and then delete all the audit/verbose messages to make the program small and fast. This often also makes it unusable by many customers. It is usually far better, especially in early releases, to delete only the "development" debug code that is no longer needed, but leave all the error checking and informative messages. If they are all dependent on the Vlvl flag, it is easy for you to enable them when the customer needs them. The cost is small compared to the aggravation of a customer trying to deal with a program that "doesn't work and won't tell me what's wrong".
Someone once wrote: Removing debug code from a program before you send it to customers is like taking flight lessons and wearing a parachute in ground school, but taking it off when you get into a plane. When a customer can't get it to work is when you *really* need that debug code. So leave it in until you have a lot of satisfied customers that have never used it. If your boss doesn't like the idea, call it "audit trail" or "tracing" or "verbose mode" and maybe it'll be accepted.
AUTHOR
This has been developed while working on an assortment of projects, for an assortment of employers, and in my spare time on my home system. It is still under active development as I find new things that need to be added. Most of the code I wrote myself; some of it was gathered from various newsgroups and mailing lists and integrated into the package.
Feel free to distribute this package to anyone anywhere, and to modify it for your own personal use. Consider it an educational tool as well as a collection of useful hacks. And if you add any really neat new features, please send me a copy.
SEE ALSO