Vault Logging

Defines
#define	VLOGGER_LEVEL(level, message)   do { if (!VLogger::isDefaultLogLevelActive(level)) break; VLogger::getDefaultLogger()->log(level, NULL, 0, message, VString::EMPTY()); } while (false)

---

Detailed Description

Overview

The VLogger facility has been improved in Vault 3.3, keeping the macro API for emitting log output exactly the same, while changing the internals and changing some of the APIs needed when programmatically accessing logger objects or creating custom subclasses.

VLogger is the static API for accessing loggers directly and modifying the configuration on the fly. It is not an instantiable class.

A VNamedLogger is a filtering object that receives log data based on name match, and restricts output by log level. It sends filtered output to one or more appenders.

VLogAppender is an abstract class from which concrete classes are derived that write output to a specific destination such as a file or the console. Appenders receive level-filtered output from loggers that reference them. An appender can be referenced by more than one logger, and can be put in a "global appender" list to which all loggers also send their level-filtered output.

A factory pattern is used to allow a concrete appender object to be instantiated when a logger needs it. By registering your own factory before initialization, you can have custom appender classes referenced in the configuration that is set up during initialization.

In Vault 3.2 and earlier, an instantiated VLogger combined the functionality of VNamedLogger and VLogAppender, which was simpler but lacked flexibility in routing output at different log levels. With these improvements in 3.3, you now have the ability to route multiple loggers at different levels to the same appender, and route any logger's output to multiple appenders.

Emitting Log Output

Application code that wants to emit log output should simply use the various VLOGGER_xxxx() macros to write output. There are two flavors; the ones with shorter names of the form VLOGGER_<level>() write to the default logger at the specified level, while the ones with the longer names of the form VLOGGER_NAMED_<level>() have an extra parameter that is the name of the logger to write to.

These macros expand to code that does not evaluate the string value unless the output may actually be emitted. Therefore, the caller does not have to be concerned about any overhead of formatting a complex string that would not be logged at the current level. For example, if you were to log the following expensive-to-build string at DEBUG level, when no loggers are currently configured at DEBUG level, the expense is not incurred:

        VLOGGER_DEBUG(VSTRING_FORMAT("State is: %d.", expensiveStateCalculation()));
    

So there is no need to test the debug level before formatting in that case. However, if you do have a case where you want to avoid all overhead (say, in a tight loop or for precalculating some value to be used in subsequent logging), you can simply call VLOGGER_WOULD_LOG(level) or VLOGGER_NAMED_WOULD_LOG(name, level) in advance.

If a specified named logger is not found, the system emits to another logger. In the simple case, this just means using the default logger. However, you can set up a naming hierarchy where logger names use a "dot.separated.naming.convention", because the fallback search is done by repeatedly stripping off the last segment of such a name and looking for a match. Ultimately it falls back to the default logger. The hierarchical search only occurs if you actually use the dot separated naming convention in the name you supply when emitting. You can treat this much like log4j uses Java package names, but since C++ does not have such a hierarchy built-in you need to decide what the hierarchy is, and you can use arbitrary hierarchies for arbitrary purposes (for example, the hierarchy could be unrelated to the class structure of the code, and instead describe some hierarchy of entities and their ids).

Configuration XML

If you do nothing to configure logging, a logger at INFO level is created upon first use, and it creates an appender to the console output upon first need. So you get all output at the console.

The preferred way to configure logging is to call VLogger::configure() at startup, supplying it a VSettings object (which was loaded from XML) to define the loggers and appenders that are created.

Here is a simple example configuration that sets up logging to log at DEBUG level to a file "my.log". In this example, we show "<logging>" as the outer XML tag name; but in reality at runtime this can be whatever you want because you must locate that node and then pass it into the configure() API, and configure() only examines the attributes and children of that node.

        <logging>
            <appender name="default" kind="file" file="my.log">
            <logger name="default" level="80" appender="default">
        </logging>
    

Here is a more complex configuration with two loggers and two appenders, where one of the loggers writes to both of the appenders.

        <logging>
            <appender name="primary" kind="file" file="my.log">
            <appender name="console" kind="console">
            <logger name="default" level="60" appender="primary">
            <logger name="combo" level="80">
                <appender name="primary">
                <appender name="console">
            </logger>
        </logging>
    

For a given kind of appender, you can configure default property values to be applied to any particular appender of the kind where the values are not specified. For example, to set the default value of the "format-output" boolean to false for all file loggers, you would include:

        <logging>
            <appender-defaults kind="file" format-output="false" />
        </logging>
    

You can specify in that manner any property appropriate to the appender kind indicated.

The documentation for each concrete appender class describes the settings is supports. The following settings are defined by the base class VLogAppender, so they can be specified for any appender individually or via defaults:

• "format-output" (boolean) Defaults to true. This determines whether an appender formats each message before writing it. Typically the formatting means prefixing the message with a current timestamp, the log level name, and the current thread name. In some cases it may be useful to omit such prefix data, for example when using logging to emit output during tests that will need to be "diff'ed" without regard to the time each line was written.
• "format-spec" (string) If formatting is to be used, this string specifies what the format is. The following variables may be placed in the string to indicate special values; the rest of the string may be your own text and punctuation formatting. If your custom VLogAppender subclass overrides the _formatMessage() method, it can further control formatting beyond this. $localtime - The time stamp in local time. If simulated or frozen time is in effect, the true time is printed, followed by a space and the simulated time. The format used for times is given by the "time-format" setting described below. $utctime - The time stamp in UTC time. (The same as $localtime in other respects.) $level - The level name. This is a five-character upper case string such as "WARN " or "ERROR". For levels in between the large-grained values, for example 82, the string is three characters abbreviating the large-grained value, and two digits of the actual number, in this example "DBG82". $thread - The current thread name. $location - The file name and line number of the log statement; if printed, it will print a trailing space. This is normally only printed for levels ERROR and below (more serious conditions). It's recommended to not leave a space after the variable, so that the printed trailing space will provide spacing if present, yet the item will be completely missing if not printed. $message - The actual log message text. $specifiedlogger - The logger name that was specified in the VLOGGER_NAMED_xxx call. May be useful for debugging the logging configuration and flow of log output. $actuallogger - The logger name of the VLogger that actually received and emitted the log statement. May be useful for debugging the logging configuration and flow of log output. As an example, the default appender format is: "$localtime $level | $thread | $location$message"
• "time-format" (string) For the $localtime or $utctime variables in the format specification, this setting controls the format of the time stamp text. The directives you can put in this string are defined by the class VInstantFormatter, and generally are the same as the Java SimpleDateFormat. The default time format is "y-MM-dd HH:mm:ss.SSS".
• "print-stack-level" (int) Defaults to 0 (VLoggerLevel::OFF). If non-zero, this indicates a log level that when the appender receives a message at that level or less, the appender also emits a stack trace.
• "print-stack-count" (int) Defaults to -1. If greater than zero, this is the limit on the number of times a stack trace will be emitted via the "print-stack-level" trigger before being disabled. This can be used to prevent runaway repeated stack tracing.
• "print-stack-duration" (duration string such as "30s") Defaults to infinity ("INFINITY") meaning no limit. If specific, this is a time limit on how long stack tracing will continue to emit once triggered. It is another way of preventing runaway repeated stack tracing.

Custom Appenders

Call VLogger::registerLogAppenderFactory() to make your custom appender available to the system. Do so prior to calling VLogger::configure() if you want the XML configuration to be able to use your custom appenders.

At a minimum, derive your appender from VLogAppender, and override emitRaw() to write the specified string to the destination output medium. If you wish to alter the normal format of the output, instead (or in addition) override emit() which must format the actual string to be emitted and then emitRaw() it. Look at the provided appenders as examples.