HOWTO_Debug_OGFS_Code (Sep 20 2003)


Contact the author.

This document describes some of the debug facilities of OpenGFS.

FILESYSTEM DEBUG

The filesystem code (in opengfs/src/fs and subdirectories) contains a number
of debug features, including printing messages to a dedicated circular buffer,
printing to Linux syslog (/var/log/messages), tracing through function
entries and exits, performance profiling using kernel timing resources,
and memory alloc/dealloc logging.

Most of these facilities are activated at compile time by using options for the
configure program (see HOWTO-nopool or HOWTO-generic for info on when/how 
to use configure).  

Brief descriptions (also see opengfs/src/fs/debug.h):

con_printf() prints error messages to the Linux syslog and the DEBUG_PRINT
facility described below.  con_printf() is not configurable.  It is always
active; it is used for error messages that need to be delivered to any user,
debugging or not.  If DEBUG_PRINT and DEBUG_PRINT_SYSLOG are both enabled,
a con_printf() message will appear twice in the syslog.  Note that con_printf()
does *not* insert a kernel message priority (e.g. KERN_INFO) into the message.

DEBUG_PRINT (--enable-fs-print-debug) prints debug messages to either a
dedicated message buffer (accessible via the ogfs_tool user-space program,
"dbdump" command) or the Linux syslog (usually viewable via /var/log/messages).
The default mechanism is the dedicated buffer.  Use DEBUG_PRINT_SYSLOG 
(--enable-fs-print-syslog-debug) to output to syslog instead.  Filesystem 
code uses the db_printf() call to create the messages.  Messages are 
implemented by ogfs_icdb_inc() for dedicated buffer, or kernel printk()
for syslog.

DEBUG_PRINT_SYSLOG (--enable-fs-print-syslog-debug) changes debug message
output from default dedicated buffer to Linux syslog.  Has no effect unless
DEBUG_PRINT (--enable-fs-print-debug) is also invoked.  Note that db_printf()
does *not* insert a kernel message priority (e.g. KERN_INFO) into the message.

DEBUG_TRACE (--enable-fs-trace-debug) creates a debug message when entering
and exiting selected filesystem functions.  Functions are selectable by two
methods:  1) use ogfs_tool user-space utility (after filesystem is mounted),
or 2) hard coding (for tracing before filesystem mount is complete).  See 
"DEBUG_TRACE details" below for more information.  Also supports IFDB(x, todo)
macro to execute "todo" code if the function "x" is selected for tracing.
Must be used with DEBUG_PRINT option enabled.

DEBUG_PROFILE (--enable-fs-profile-debug) accumulates statistics for
selected filesystem functions.  Statistics include:
   total # calls to function
   total accumulated # microseconds executing within function
   minimum # microseconds (fastest execution of function)
   maximum # microseconds (slowest execution of function)
Statistics may be viewed via the ogfs_tool "prof" command.
See "DEBUG_TRACE and DEBUG_PROFILE Details" below for more information.

As of this writing (May 23, 2003) it appears that DEBUG_PROFILE is not fully
implemented.  There is no instantiation of the ogfs_prof_stats[] array.

DEBUG_MEM (is there a config option for this??) logs memory allocations
and de-allocations.  I don't know much about it yet ... just noticed it
and thought I'd mention it here.  See src/fs/gmalloc.c.


DEBUG_TRACE and DEBUG_PROFILE details

Filesystem code uses two macros to create trace points and gather profile 
statistics:  ENTER(x) and EXIT(x).  You'll find these at the beginning and
end of almost every function (over 400) in the fs code.  These are #defined in 
opengfs/src/fs/debug.h to invoke ENTER_PROFILE(x), ENTER_PRINT(x), 
EXIT_PRINT(x), and EXIT_PROFILE(x), also #defined in opengfs/src/fs/debug.h.

The ENTER_PROFILE and EXIT_PROFILE macros accumulate statistics, including
timing, into the ogfs_prof_stats[] array of statistics structures.  The "x" 
is based on the name of the function, and is #defined in 
opengfs/src/fs/ogfs_debug.h (note the ogfs_ prefix) as an index number.
The index selects which array member to modify.

Another macro, PROFILE_TAP(x), simply counts the number of times a function has
been called, without doing any timing.  As of this writing (May 23, 2003), I
don't see any usage of PROFILE_TAP(x) in the filesystem code.

ENTER_PRINT(x) and EXIT_PRINT(x) print debug messages at the beginning and end
of each trace-enabled function.  The "x" is based on the name of the function,
and is #defined in opengfs/src/fs/ogfs_debug.h as an index number.  The index
accesses a bit map, ogfs_debug_flags[].  Each bit controls whether tracing is
on or off for a given function.

opengfs/src/fs/ogfs_debug.h is generated by a script:  
opengfs/scripts/build_debug.  This script scans through each filesystem source
file, searching for ENTER_PRINT and other macros.  It forms a list of all
functions containing the macros, grouped as to the source file.

If you add or remove ENTER_PRINT or other trace-related macros in the source,
do the following, in the opengfs directory, to regenerate ogfs_debug.h:

make build_debug

To select the functions you want to trace, use the ogfs_tool user-space
utility.  The following ogfs_tool commands are interesting:

"dbprint" -- prints list of debugging flags.  These include individual
functions, as well as groups of functions within each source file.  Note that
this info is compiled into ogfs_tool; ogfs_tool does not query the filesystem
at run-time for this info.  Therefore, you must recompile ogfs_tool any time
you add or remove ENTER_PRINT or other trace-related macros in the filesystem
code. 

"dbon"   -- turns debug tracing on for selected function or
function group.

"dboff"   -- turns debug tracing off for selected function or
function group.

dbon and dboff require that the filesystem is mounted, because they use ioctls
to the ogfs kernel module to turn on/off individual trace flags.  For a group,
a dbon or dboff command is executed via a series of ioctls, one for each 
individual function within the group.

Even though access to debug flags is not enabled until after the file system 
mounts, you can still trace the mount process.  Do this by compiling a debug
flag configuration into the filesystem module, so certain (or all) trace points
will be recorded in the system log.  See src/fs/arch_linux_2_4/main.c.
Search for "dbon" to find:

1)  definition of "dbon" macro
2)  initialization of debug flags within init_ogfs_fs()

Manipulate the memset command to preset all flags either "off" or "on", then
use dbon() or dboff() to manipulate individual flags.

SourceForge Logo