Logging

Logging and tracing facility. More...

Macros
#define	QOF_MOD_ENGINE   "qof.engine"
#define	PRETTY_FUNC_NAME   qof_log_prettify(G_STRFUNC)
#define	FATAL(format, args...)
	Log a fatal error. More...
#define	PERR(format, args...)
	Log a serious error. More...
#define	PWARN(format, args...)
	Log a warning. More...
#define	PINFO(format, args...)
	Print an informational note. More...
#define	DEBUG(format, args...)
	Print a debugging message. More...
#define	ENTER(format, args...)
	Print a function entry debugging message. More...
#define	LEAVE(format, args...)
	Print a function exit debugging message. More...
#define	gnc_leave_return_val_if_fail(test, val)
	Replacement for g_return_val_if_fail, but calls LEAVE if the test fails. More...
#define	gnc_leave_return_if_fail(test)
	Replacement for g_return_if_fail, but calls LEAVE if the test fails. More...

Typedefs
typedef const gchar *	QofLogModule

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_MESSAGE = G_LOG_LEVEL_MESSAGE,   QOF_LOG_INFO = G_LOG_LEVEL_INFO, QOF_LOG_DEBUG = G_LOG_LEVEL_DEBUG }

Functions
const char *	qof_log_level_to_string (QofLogLevel lvl)
QofLogLevel	qof_log_level_from_string (const char *str)
void	qof_log_indent (void)
	Indents one level; see ENTER macro. More...
void	qof_log_dedent (void)
	De-dent one level, capped at 0; see LEAVE macro.
void	qof_log_init (void)
	Initialize the error logging subsystem. More...
void	qof_log_set_level (QofLogModule module, QofLogLevel level)
	Set the logging level of the given log_module. More...
void	qof_log_set_file (FILE *outfile)
	Specify an alternate log output, to pipe or file. More...
void	qof_log_init_filename (const gchar *logfilename)
	Specify a filename for log output. More...
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*)
void	qof_log_parse_log_config (const char *filename)
	Parse a log-configuration file. More...
void	qof_log_shutdown (void)
	Be nice, close the logfile if possible. More...
const gchar *	qof_log_prettify (const gchar *name)
	Cleans up subroutine names. More...
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. More...

Detailed Description

Logging and tracing facility.

See also

"Logging overhaul" announcement https://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:

• Define both static QofLogModule log_module and #define G_LOG_DOMAIN to the same value.
• Define a logical, specific path as the log domain; "gnc.gui.plugin-pages.sx-list" or "gnc.register.gnome.cell.quickfill" are good examples.
• Prefer the macros defined here (PERR, PWARN, PINFO, etc.) to the GLib-provided functions that they wrap because it allows us to more easily replace the GLib logging functinos with another implementation and besides our macros are able to short-circuit GLib's rather slow domain and level matching.

See also

qof_log_parse_log_config(const char*)

Macro Definition Documentation

DEBUG

#define DEBUG	(		format,
			args...
	)

Value:

do {                      \
    if (qof_log_check(log_module, QOF_LOG_DEBUG)) {      \
        g_log (log_module, G_LOG_LEVEL_DEBUG,         \
               "[%s] " format, PRETTY_FUNC_NAME , ## args);     \
    } \
} while(0)

Print a debugging message.

Definition at line 264 of file qoflog.h.

ENTER

#define ENTER	(		format,
			args...
	)

Value:

do {                     \
    if (qof_log_check(log_module, QOF_LOG_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 272 of file qoflog.h.

FATAL

#define FATAL	(		format,
			args...
	)

Value:

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

Log a fatal error.

Definition at line 238 of file qoflog.h.

gnc_leave_return_if_fail

#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 300 of file qoflog.h.

gnc_leave_return_val_if_fail

#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 294 of file qoflog.h.

LEAVE

#define LEAVE	(		format,
			args...
	)

Value:

do {                     \
    if (qof_log_check(log_module, QOF_LOG_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 282 of file qoflog.h.

PERR

#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 244 of file qoflog.h.

PINFO

#define PINFO	(		format,
			args...
	)

Value:

do {                  \
    if (qof_log_check(log_module, QOF_LOG_INFO)) {   \
        g_log (log_module, G_LOG_LEVEL_INFO,         \
               "[%s] " format, PRETTY_FUNC_NAME , ## args);     \
    } \
} while (0)

Print an informational note.

Definition at line 256 of file qoflog.h.

PWARN

#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 250 of file qoflog.h.

Function Documentation

qof_log_check()

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 328 of file qoflog.cpp.

{
// Check the global levels
    if (level > current_max)
        return FALSE;
    if (level <= default_level)
        return TRUE;
    auto module = get_modules();
    // If the level <= the default then no need to look further.
    if (level <= module->m_level)
        return TRUE;

    if (!domain)
        return FALSE;

    auto domain_vec = split_domain(domain);

    for (auto part : domain_vec)
    {
        auto iter = std::find_if(module->m_children.begin(),
                               module->m_children.end(),
                               [part](auto& child) {
                                   return child && part == child->m_name; });

        if (iter == module->m_children.end())
            return FALSE;

        if (level <= (*iter)->m_level)
            return TRUE;

        module = iter->get();
    }
    return FALSE;
}

qof_log_indent()

void qof_log_indent

(

void

)

Indents one level; see ENTER macro.

Definition at line 134 of file qoflog.cpp.

{
    qof_log_num_spaces += QOF_LOG_INDENT_WIDTH;
}

qof_log_init()

void qof_log_init

(

void

)

Initialize the error logging subsystem.

Defaults to a level-threshold of "warning", and logging to stderr.

Definition at line 160 of file qoflog.cpp.

{
    qof_log_init_filename(NULL);
}

qof_log_init_filename()

void qof_log_init_filename

(

const gchar *

logfilename

)

Specify a filename for log output.

Definition at line 211 of file qoflog.cpp.

{
    gboolean warn_about_missing_permission = FALSE;
    auto modules = get_modules();

    if (!qof_logger_format)
        qof_logger_format = g_strdup ("* %s %*s <%s> %*s%s%s"); //default format

    if (log_filename)
    {
        int fd;
        gchar *fname;

        if (fout != NULL && fout != stderr && fout != stdout)
            fclose(fout);

        fname = g_strconcat(log_filename, ".XXXXXX.log", nullptr);

        if ((fd = g_mkstemp(fname)) != -1)
        {
#if PLATFORM(WINDOWS)
            /* MSVC compiler: Somehow the OS thinks file descriptor from above
             * still isn't open. So we open normally with the file name and that's it. */
            fout = g_fopen(fname, "wb");
#else
            /* We must not overwrite /dev/null */
            g_assert(g_strcmp0(log_filename, "/dev/null") != 0);

            /* Windows prevents renaming of open files, so the next command silently fails there
             * No problem, the filename on Winows will simply have the random characters */
            g_rename(fname, log_filename);
            fout = fdopen(fd, "w");
#endif
            if (!fout)
                warn_about_missing_permission = TRUE;
        }
        else
        {
            warn_about_missing_permission = TRUE;
            fout = stderr;
        }
        g_free(fname);
    }

    if (!fout)
        fout = stderr;

    if (previous_handler == NULL)
        previous_handler = g_log_set_default_handler(log4glib_handler, modules);

    if (warn_about_missing_permission)
    {
        g_critical("Cannot open log output file \"%s\", using stderr.", log_filename);
    }
}

qof_log_parse_log_config()

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 419 of file qoflog.cpp.

{
    const gchar *levels_group = "levels", *output_group = "output";
    GError *err = NULL;
    GKeyFile *conf = g_key_file_new();

    if (!g_key_file_load_from_file(conf, filename, G_KEY_FILE_NONE, &err))
    {
        g_warning("unable to parse [%s]: %s", filename, err->message);
        g_error_free(err);
        return;
    }

    DEBUG("parsing log config from [%s]", filename);
    if (g_key_file_has_group(conf, levels_group))
    {
        gsize num_levels;
        unsigned int key_idx;
        gchar **levels;
        gint logger_max_name_length = 12;
        gchar *str = NULL;

        levels = g_key_file_get_keys(conf, levels_group, &num_levels, NULL);

        for (key_idx = 0; key_idx < num_levels && levels[key_idx] != NULL; key_idx++)
        {
            QofLogLevel level;
            gchar *logger_name = NULL, *level_str = NULL;

            logger_name = g_strdup(levels[key_idx]);
            logger_max_name_length = MAX (logger_max_name_length, (gint) strlen (logger_name));
            level_str = g_key_file_get_string(conf, levels_group, logger_name, NULL);
            level = qof_log_level_from_string(level_str);

            DEBUG("setting log [%s] to level [%s=%d]", logger_name, level_str, level);
            qof_log_set_level(logger_name, level);

            g_free(logger_name);
            g_free(level_str);
        }

        str = g_strdup_printf ("%d", logger_max_name_length);
        if (qof_logger_format)
            g_free (qof_logger_format);
        qof_logger_format = g_strconcat ("* %s %*s <%-", str, ".", str, "s> %*s%s%s", nullptr);

        g_free (str);
        g_strfreev(levels);
    }

    if (g_key_file_has_group(conf, output_group))
    {
        gsize num_outputs;
        unsigned int output_idx;
        gchar **outputs;

        outputs = g_key_file_get_keys(conf, output_group, &num_outputs, NULL);
        for (output_idx = 0; output_idx < num_outputs && outputs[output_idx] != NULL; output_idx++)
        {
            gchar *key = outputs[output_idx];
            gchar *value;

            if (g_ascii_strcasecmp("to", key) != 0)
            {
                g_warning("unknown key [%s] in [outputs], skipping", key);
                continue;
            }

            value = g_key_file_get_string(conf, output_group, key, NULL);
            DEBUG("setting [output].to=[%s]", value);
            qof_log_init_filename_special(value);
            g_free(value);
        }
        g_strfreev(outputs);
    }

    g_key_file_free(conf);
}

qof_log_prettify()

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.

qof_log_set_file()

void qof_log_set_file

(

FILE *

outfile

)

Specify an alternate log output, to pipe or file.

Definition at line 149 of file qoflog.cpp.

{
    if (!outfile)
    {
        fout = stderr;
        return;
    }
    fout = outfile;
}

qof_log_set_level()

void qof_log_set_level	(	QofLogModule	module,
		QofLogLevel	level
	)

Set the logging level of the given log_module.

Definition at line 295 of file qoflog.cpp.

{
    if (!log_module || level == QOF_LOG_FATAL)
        return;

    if (level > current_max)
        current_max = level;

    auto module_parts = split_domain(log_module);
    auto module = get_modules();
    for (auto part : module_parts)
    {
        auto iter = std::find_if(module->m_children.begin(),
                              module->m_children.end(),
                              [part](auto& child){
                                  return child && part == child->m_name;
                              });
        if (iter == module->m_children.end())
        {
            auto child = std::make_unique<ModuleEntry>(part, default_level);
            module->m_children.emplace_back(std::move(child));
            module = module->m_children.back().get();
        }
        else
        {
            module = iter->get();
        }
    }
    module->m_level = level;
}

qof_log_shutdown()

void qof_log_shutdown

(

void

)

Be nice, close the logfile if possible.

Definition at line 268 of file qoflog.cpp.

{
    if (fout && fout != stderr && fout != stdout)
    {
        fclose(fout);
        fout = NULL;
    }

    if (function_buffer)
    {
        g_free(function_buffer);
        function_buffer = NULL;
    }

    if (_modules != NULL)
    {
        _modules = nullptr;
    }

    if (previous_handler != NULL)
    {
        g_log_set_default_handler(previous_handler, NULL);
        previous_handler = NULL;
    }
}