Logging
[Query Object Framework]

Detailed Description

Logging and tracing facility.

See also:
"Logging overhaul" announcement <http://lists.gnucash.org/pipermail/gnucash-devel/2007-February/019836.html>
qof_log_init(void) installs a handler that interprets the "log_domain" as a "."-separated path. Log level thresholds can be set for each level in the tree. When a message is logged, the longest level match is found, and used as the threshold.

For instance, we can set the levels as such: 

   "qof"                        = WARN
   "gnc"                        = WARN
   "gnc.ui"                     = INFO
   "gnc.ui.plugin-page.sx-list" = DEBUG

When code in the log_module of "gnc.import" attempts to log at DEBUG (let's say), the handler will attempt to match the log domain to successively-longer paths: first "", then "gnc", then "gnc.import". Given the settings above, the path "gnc" will match -- at a level of "WARN" -- and the DEBUG-level log will be rejected. When code in the log domain of "gnc.ui.plugin-page.sx-list" logs at DEBUG, however, it will match at DEBUG, and be allowed.

The current log format is as above:

     * [timestamp] [level] <[log-domain]> [message]

The timestamp and level are constant width (level is 5 characters). The log domain is re-iterated, which gives some context, but could become annoying if they get long.

Trailing newlines (e.g. PINFO("...\n", ...)) are removed; the logger will newline separate output.

Best Practices

Code should:

See also:
qof_log_parse_log_config(const char*)


Defines

#define QOF_MOD_ENGINE   "qof.engine"
#define LOG_LEVEL_LIST(_)
#define PRETTY_FUNC_NAME   qof_log_prettify(__FUNCTION__)
#define FATAL(format, args...)
#define PERR(format, args...)
#define PWARN(format, args...)
#define PINFO(format, args...)
#define DEBUG(format, args...)
#define ENTER(format, args...)
#define gnc_leave_return_val_if_fail(test, val)
#define gnc_leave_return_if_fail(test)
#define LEAVE(format, args...)
#define START_CLOCK(clockno, format, args...)
#define REPORT_CLOCK(clockno, format, args...)
#define REPORT_CLOCK_TOTAL(clockno, format, args...)

Enumerations

enum  QofLogLevel {
  QOF_LOG_FATAL = G_LOG_LEVEL_ERROR, QOF_LOG_ERROR = G_LOG_LEVEL_CRITICAL, QOF_LOG_WARNING = G_LOG_LEVEL_WARNING, QOF_LOG_INFO = G_LOG_LEVEL_INFO,
  QOF_LOG_DEBUG = G_LOG_LEVEL_DEBUG
}

Functions

gchar * qof_log_level_to_string (QofLogLevel lvl)
QofLogLevel qof_log_level_from_string (const gchar *str)
void qof_log_indent (void)
void qof_log_dedent (void)
void qof_log_init (void)
void qof_log_set_level (QofLogModule module, QofLogLevel level)
void qof_log_set_file (FILE *outfile)
void qof_log_init_filename (const gchar *logfilename)
void qof_log_init_filename_special (const char *log_to_filename)
void qof_log_parse_log_config (const char *filename)
void qof_log_shutdown (void)
const gchar * qof_log_prettify (const gchar *name)
gboolean qof_log_check (QofLogModule log_module, QofLogLevel log_level)
void qof_log_set_default (QofLogLevel log_level)
void qof_start_clock (gint clockno, QofLogModule log_module, QofLogLevel log_level, const gchar *function_name, const gchar *format,...)
void qof_report_clock (gint clockno, QofLogModule log_module, QofLogLevel log_level, const gchar *function_name, const gchar *format,...)
void qof_report_clock_total (gint clockno, QofLogModule log_module, QofLogLevel log_level, const gchar *function_name, const gchar *format,...)

Define Documentation

#define DEBUG ( format,
args...   ) 

Value:

do { \
    g_log (log_module, G_LOG_LEVEL_DEBUG, \
      "[%s] " format, PRETTY_FUNC_NAME , ## args); \
} while (0)
Print a debugging message

Definition at line 195 of file qoflog.h.

#define ENTER ( format,
args...   ) 

Value:

do { \
    if (qof_log_check(log_module, G_LOG_LEVEL_DEBUG)) { \
      g_log (log_module, G_LOG_LEVEL_DEBUG, \
        "[enter %s:%s()] " format, __FILE__, \
        PRETTY_FUNC_NAME , ## args); \
      qof_log_indent(); \
    } \
} while (0)
Print a function entry debugging message

Definition at line 201 of file qoflog.h.

#define FATAL ( format,
args...   ) 

Value:

do { \
    g_log (log_module, G_LOG_LEVEL_FATAL, \
      "[%s()] " format, PRETTY_FUNC_NAME , ## args); \
} while (0)
Log a fatal error

Definition at line 171 of file qoflog.h.

#define gnc_leave_return_if_fail ( test   ) 

Value:

do { \
  if (! (test)) { LEAVE(""); } \
  g_return_if_fail(test); \
} while (0);
Replacement for g_return_if_fail, but calls LEAVE if the test fails.

Definition at line 217 of file qoflog.h.

#define gnc_leave_return_val_if_fail ( test,
val   ) 

Value:

do { \
  if (! (test)) { LEAVE(""); } \
  g_return_val_if_fail(test, val); \
} while (0);
Replacement for g_return_val_if_fail, but calls LEAVE if the test fails.

Definition at line 211 of file qoflog.h.

#define LEAVE ( format,
args...   ) 

Value:

do { \
    if (qof_log_check(log_module, G_LOG_LEVEL_DEBUG)) { \
      qof_log_dedent(); \
      g_log (log_module, G_LOG_LEVEL_DEBUG, \
        "[leave %s()] " format, \
        PRETTY_FUNC_NAME , ## args); \
    } \
} while (0)
Print a function exit debugging message.

Definition at line 223 of file qoflog.h.

#define LOG_LEVEL_LIST ( _   ) 

Value:

_(QOF_LOG_FATAL,   = G_LOG_LEVEL_ERROR)   \
  _(QOF_LOG_ERROR,   = G_LOG_LEVEL_CRITICAL)   \
  _(QOF_LOG_WARNING, = G_LOG_LEVEL_WARNING) \
  _(QOF_LOG_INFO,    = G_LOG_LEVEL_INFO)    \
  _(QOF_LOG_DEBUG,   = G_LOG_LEVEL_DEBUG)

Definition at line 94 of file qoflog.h.

#define PERR ( format,
args...   ) 

Value:

do { \
    g_log (log_module, G_LOG_LEVEL_CRITICAL, \
      "[%s()] " format, PRETTY_FUNC_NAME , ## args); \
} while (0)
Log a serious error

Definition at line 177 of file qoflog.h.

#define PINFO ( format,
args...   ) 

Value:

do { \
    g_log (log_module, G_LOG_LEVEL_INFO, \
      "[%s] " format, PRETTY_FUNC_NAME , ## args); \
} while (0)
Print an informational note

Definition at line 189 of file qoflog.h.

#define PWARN ( format,
args...   ) 

Value:

do { \
    g_log (log_module, G_LOG_LEVEL_WARNING, \
      "[%s()] " format, PRETTY_FUNC_NAME , ## args); \
} while (0)
Log a warning

Definition at line 183 of file qoflog.h.

#define REPORT_CLOCK ( clockno,
format,
args...   ) 

Value:

do {       \
  if (qof_log_check (log_module, QOF_LOG_INFO))          \
    qof_report_clock (clockno, log_module, QOF_LOG_INFO, \
             __FUNCTION__, format , ## args);               \
} while (0)
report elapsed time since last report on a particular timer

Definition at line 261 of file qoflog.h.

#define REPORT_CLOCK_TOTAL ( clockno,
format,
args...   ) 

Value:

do {       \
  if (qof_log_check (log_module, QOF_LOG_INFO))                \
    qof_report_clock_total (clockno, log_module, QOF_LOG_INFO, \
             __FUNCTION__, format , ## args);               \
} while (0)
report total elapsed time since timer started

Definition at line 268 of file qoflog.h.

#define START_CLOCK ( clockno,
format,
args...   ) 

Value:

do {        \
  if (qof_log_check (log_module, QOF_LOG_INFO))          \
    qof_start_clock (clockno, log_module, QOF_LOG_INFO,  \
             __FUNCTION__, format , ## args);               \
} while (0)
start a particular timer

Definition at line 254 of file qoflog.h.

Enumeration Type Documentation

enum QofLogLevel

Enumerator:
QOF_LOG_FATAL 
QOF_LOG_ERROR 
QOF_LOG_WARNING 
QOF_LOG_INFO 
QOF_LOG_DEBUG 

Definition at line 101 of file qoflog.h.

00137 :
 * @verbatim

Function Documentation

gboolean qof_log_check ( QofLogModule  log_module,
QofLogLevel  log_level 
)

Check to see if the given log_module is configured to log at the given log_level. This implements the "log.path.hierarchy" logic.

Definition at line 314 of file qoflog.c.

00315 {
00316 //#define _QLC_DBG(x) x
00317 #define _QLC_DBG(x)
00318      GHashTable *log_levels = log_table;
00319      gchar *domain_copy = g_strdup(log_domain == NULL ? "" : log_domain);
00320      gchar *dot_pointer = domain_copy;
00321      static const QofLogLevel default_log_thresh = QOF_LOG_WARNING;
00322      QofLogLevel longest_match_level = default_log_thresh;
00323 
00324      {
00325           gpointer match_level;
00326           if ((match_level = g_hash_table_lookup(log_levels, "")) != NULL)
00327                longest_match_level = (QofLogLevel)GPOINTER_TO_INT(match_level);
00328      }
00329 
00330      _QLC_DBG({ printf("trying [%s] (%d):", log_domain, g_hash_table_size(log_levels)); });
00331      if (G_LIKELY(log_levels))
00332      {
00333           // e.g., "a.b.c\0" -> "a\0b.c\0" -> "a.b\0c\0", "a.b.c\0"
00334           gpointer match_level;
00335           while ((dot_pointer = g_strstr_len(dot_pointer, strlen(dot_pointer), ".")) != NULL)
00336           {
00337                *dot_pointer = '\0';
00338                _QLC_DBG({ printf(" [%s]", domain_copy); });
00339                if (g_hash_table_lookup_extended(log_levels, domain_copy, NULL, &match_level))
00340                {
00341                     longest_match_level = (QofLogLevel)GPOINTER_TO_INT(match_level);
00342                     _QLC_DBG(printf("*"););
00343                }
00344                *dot_pointer = '.';
00345                dot_pointer++;
00346           }
00347 
00348           _QLC_DBG({ printf(" [%s]", domain_copy); });
00349           if (g_hash_table_lookup_extended(log_levels, domain_copy, NULL, &match_level))
00350           {
00351                longest_match_level = (QofLogLevel)GPOINTER_TO_INT(match_level);
00352                _QLC_DBG({ printf("*"); });
00353           }
00354      }
00355      _QLC_DBG({ printf(" found [%d]\n", longest_match_level); });
00356      g_free(domain_copy);
00357 
00358      return log_level <= longest_match_level;
00359 }

void qof_log_dedent ( void   ) 

De-dent one level, capped at 0; see LEAVE macro.

Definition at line 69 of file qoflog.c.

00070 {
00071         qof_log_num_spaces
00072          = (qof_log_num_spaces < QOF_LOG_INDENT_WIDTH)
00073          ? 0
00074          : qof_log_num_spaces - QOF_LOG_INDENT_WIDTH;
00075 }

void qof_log_indent ( void   ) 

Indents one level; see ENTER macro.

Definition at line 63 of file qoflog.c.

00064 {
00065      qof_log_num_spaces += QOF_LOG_INDENT_WIDTH;
00066 }

void qof_log_init ( void   ) 

Initialize the error logging subsystem. Defaults to a level-threshold of "warning", and logging to stderr.

Definition at line 85 of file qoflog.c.

00086 {
00087      qof_log_init_filename(NULL);
00088 }

void qof_log_init_filename ( const gchar *  logfilename  ) 

Specify a filename for log output.

Definition at line 128 of file qoflog.c.

00129 {
00130      if (log_table == NULL)
00131           log_table = g_hash_table_new_full(g_str_hash, g_str_equal,
00132                                             g_free, NULL);
00133 
00134      if (log_filename)
00135      {
00136           int fd;
00137           gchar *fname;
00138 
00139           if (fout != NULL && fout != stderr && fout != stdout)
00140                fclose(fout);
00141 
00142           fname = g_strconcat(log_filename, ".XXXXXX", NULL);
00143 
00144           if ((fd = g_mkstemp(fname)) != -1)
00145           {
00146                g_rename(fname, log_filename);
00147                fout = fdopen(fd, "w");
00148           }
00149           else
00150           {
00151                fout = stderr;
00152           }
00153           g_free(fname);
00154      }
00155 
00156      if (!fout)
00157           fout = stderr;
00158 
00159      // @@fixme really, the userdata is a struct { log_table, fout, previous_handler }
00160      if (previous_handler == NULL)
00161           previous_handler = g_log_set_default_handler(log4glib_handler, log_table);
00162 }

void qof_log_init_filename_special ( const char *  log_to_filename  ) 

If log_to_filename is "stderr" or "stdout" (exactly, case-insensitive), then those special files are used; otherwise, the literal filename as given, as qof_log_init_filename(gchar*)

Definition at line 227 of file qoflog.c.

00228 {
00229      if (g_ascii_strcasecmp("stderr", log_to_filename) == 0)
00230      {
00231           qof_log_set_file(stderr);
00232      }
00233      else if (g_ascii_strcasecmp("stdout", log_to_filename) == 0)
00234      {
00235           qof_log_set_file(stdout);
00236      }
00237      else
00238      {
00239           qof_log_init_filename(log_to_filename);
00240      }
00241 }

void qof_log_parse_log_config ( const char *  filename  ) 

Parse a log-configuration file. A GKeyFile-format file of the schema: 

    [levels] 
    # log.ger.path=level
    gnc.engine.sx=debug
    gnc.gui.sx=debug
    gnc.import-export.qif.parse=debug
    [output]
    # to=["stderr"|"stdout"|filename]
    to=stderr

Definition at line 244 of file qoflog.c.

00245 {
00246      const gchar *levels_group = "levels", *output_group = "output";
00247      GError *err;
00248      GKeyFile *conf = g_key_file_new();
00249 
00250      if (!g_key_file_load_from_file(conf, filename, G_KEY_FILE_NONE, &err))
00251      {
00252           g_warning("unable to parse [%s]: %s", filename, err->message);
00253           g_error_free(err);
00254           return;
00255      }
00256 
00257      g_debug("parsing log config from [%s]", filename);
00258      if (g_key_file_has_group(conf, levels_group))
00259      {
00260           gsize num_levels;
00261           int key_idx;
00262           gchar **levels;
00263 
00264           levels = g_key_file_get_keys(conf, levels_group, &num_levels, NULL);
00265 
00266           for (key_idx = 0; key_idx < num_levels && levels[key_idx] != NULL; key_idx++)
00267           {
00268                QofLogLevel level;
00269                gchar *logger_name = NULL, *level_str = NULL;
00270 
00271                logger_name = g_strdup(levels[key_idx]);
00272                level_str = g_key_file_get_string(conf, levels_group, logger_name, NULL);
00273                level = qof_log_level_from_string(level_str);
00274 
00275                g_debug("setting log [%s] to level [%s=%d]", logger_name, level_str, level);
00276                qof_log_set_level(logger_name, level);
00277 
00278                g_free(logger_name);
00279                g_free(level_str);
00280           }
00281           g_strfreev(levels);
00282      }
00283 
00284      if (g_key_file_has_group(conf, output_group))
00285      {
00286           gsize num_outputs;
00287           int output_idx;
00288           gchar **outputs;
00289           
00290           outputs = g_key_file_get_keys(conf, output_group, &num_outputs, NULL);
00291           for (output_idx = 0; output_idx < num_outputs && outputs[output_idx] != NULL; output_idx++)
00292           {
00293                gchar *key = outputs[output_idx];
00294                gchar *value;
00295 
00296                if (g_ascii_strcasecmp("to", key) != 0)
00297                {
00298                     g_warning("unknown key [%s] in [outputs], skipping", key);
00299                     continue;
00300                }
00301 
00302                value = g_key_file_get_string(conf, output_group, key, NULL);
00303                g_debug("setting [output].to=[%s]", value);
00304                qof_log_init_filename_special(value);
00305                g_free(value);
00306           }
00307           g_strfreev(outputs);
00308      }
00309 
00310      g_key_file_free(conf);
00311 }

const gchar* qof_log_prettify ( const gchar *  name  ) 

Cleans up subroutine names. AIX/xlC has the habit of printing signatures not names; clean this up. On other operating systems, truncate name to QOF_LOG_MAX_CHARS chars.

void qof_log_set_default ( QofLogLevel  log_level  ) 

Set the default level for QOF-related log paths.

Definition at line 362 of file qoflog.c.

00363 {
00364     qof_log_set_level("", log_level);
00365     qof_log_set_level("qof", log_level);
00366 }

void qof_log_set_file ( FILE *  outfile  ) 

Specify an alternate log output, to pipe or file.

Definition at line 78 of file qoflog.c.

00079 {
00080      if (!outfile) { fout = stderr; return; }
00081      fout = outfile;
00082 }

void qof_log_set_level ( QofLogModule  module,
QofLogLevel  level 
)

Set the logging level of the given log_module.

Definition at line 193 of file qoflog.c.

00194 {
00195         if (!log_module || level == 0) { return; }
00196         if (!log_table)
00197         {
00198                 log_table = g_hash_table_new(g_str_hash, g_str_equal);
00199         }
00200         g_hash_table_insert(log_table, g_strdup((gchar*)log_module), GINT_TO_POINTER((gint)level));
00201 }

void qof_log_shutdown ( void   ) 

Be nice, close the logfile if possible.

Definition at line 165 of file qoflog.c.

00166 {
00167         if (fout && fout != stderr && fout != stdout)
00168     {
00169          fclose(fout);
00170          fout = NULL;
00171     }
00172 
00173         if (function_buffer)
00174     {
00175          g_free(function_buffer);
00176          function_buffer = NULL;
00177     }
00178 
00179     if (log_table != NULL)
00180     {
00181          g_hash_table_destroy(log_table);
00182          log_table = NULL;
00183     }
00184 
00185     if (previous_handler != NULL)
00186     {
00187          g_log_set_default_handler(previous_handler, NULL);
00188          previous_handler = NULL;
00189     }
00190 }

void qof_start_clock ( gint  clockno,
QofLogModule  log_module,
QofLogLevel  log_level,
const gchar *  function_name,
const gchar *  format,
  ... 
)

Infrastructure to make timing measurements for critical pieces of code. Used for only for performance tuning & debugging.

Generated on Mon Sep 8 05:04:44 2008 for GnuCash by  doxygen 1.5.2