4. Log

YAZ has evolved a fairly complex log system which should be useful both for debugging YAZ itself, debugging applications that use YAZ, and for production use of those applications.

The log functions are declared in header yaz/log.h and implemented in src/log.c. Due to name clash with syslog and some math utilities the logging interface has been modified as of YAZ 2.0.29. The obsolete interface is still available in header file yaz/log.h. The key points of the interface are:

    void yaz_log(int level, const char *fmt, ...)
    void yaz_log_init(int level, const char *prefix, const char *name);
    void yaz_log_init_file(const char *fname);
    void yaz_log_init_level(int level);
    void yaz_log_init_prefix(const char *prefix);
    void yaz_log_time_format(const char *fmt);
    void yaz_log_init_max_size(int mx);

    int yaz_log_mask_str(const char *str);
    int yaz_log_module_level(const char *name);
   

The reason for the whole log module is the yaz_log function. It takes a bitmask indicating the log levels, a printf-like format string, and a variable number of arguments to log.

The log level is a bit mask, that says on which level(s) the log entry should be made, and optionally set some behaviour of the logging. In the most simple cases, it can be one of YLOG_FATAL, YLOG_DEBUG, YLOG_WARN, YLOG_LOG. Those can be combined with bits that modify the way the log entry is written:YLOG_ERRNO, YLOG_NOTIME, YLOG_FLUSH. Most of the rest of the bits are deprecated, and should not be used. Use the dynamic log levels instead.

Applications that use YAZ, should not use the LOG_LOG for ordinary messages, but should make use of the dynamic loglevel system. This consists of two parts, defining the loglevel and checking it.

To define the log levels, the (main) program should pass a string to yaz_log_mask_str to define which log levels are to be logged. This string should be a comma-separated list of log level names, and can contain both hard-coded names and dynamic ones. The log level calculation starts with YLOG_DEFAULT_LEVEL and adds a bit for each word it meets, unless the word starts with a '-', in which case it clears the bit. If the string 'none' is found, all bits are cleared. Typically this string comes from the command-line, often identified by -v. The yaz_log_mask_str returns a log level that should be passed to yaz_log_init_level for it to take effect.

Each module should check what log bits should be used, by calling yaz_log_module_level with a suitable name for the module. The name is cleared of a preceding path and an extension, if any, so it is quite possible to use __FILE__ for it. If the name has been passed to yaz_log_mask_str, the routine returns a non-zero bitmask, which should then be used in consequent calls to yaz_log. (It can also be tested, so as to avoid unnecessary calls to yaz_log, in time-critical places, or when the log entry would take time to construct.)

Yaz uses the following dynamic log levels: server, session, request, requestdetail for the server functionality. zoom for the zoom client API. ztest for the simple test server. malloc, nmem, odr, eventl for internal debugging of yaz itself. Of course, any program using yaz is welcome to define as many new ones as it needs.

By default the log is written to stderr, but this can be changed by a call to yaz_log_init_file or yaz_log_init. If the log is directed to a file, the file size is checked at every write, and if it exceeds the limit given in yaz_log_init_max_size, the log is rotated. The rotation keeps one old version (with a .1 appended to the name). The size defaults to 1GB. Setting it to zero will disable the rotation feature.

    A typical yaz-log looks like this
  13:23:14-23/11 yaz-ztest(1) [session] Starting session from tcp:127.0.0.1 (pid=30968)
  13:23:14-23/11 yaz-ztest(1) [request] Init from 'YAZ' (81) (ver 2.0.28) OK
  13:23:17-23/11 yaz-ztest(1) [request] Search Z: @attrset Bib-1 foo  OK:7 hits
  13:23:22-23/11 yaz-ztest(1) [request] Present: [1] 2+2  OK 2 records returned
  13:24:13-23/11 yaz-ztest(1) [request] Close OK
   

The log entries start with a time stamp. This can be omitted by setting the YLOG_NOTIME bit in the loglevel. This way automatic tests can be hoped to produce identical log files, that are easy to diff. The format of the time stamp can be set with yaz_log_time_format, which takes a format string just like strftime.

Next in a log line comes the prefix, often the name of the program. For yaz-based servers, it can also contain the session number. Then comes one or more logbits in square brackets, depending on the logging level set by yaz_log_init_level and the loglevel passed to yaz_log_init_level. Finally comes the format string and additional values passed to yaz_log

The log level YLOG_LOGLVL, enabled by the string loglevel, will log all the log-level affecting operations. This can come in handy if you need to know what other log levels would be useful. Grep the logfile for [loglevel].

The log system is almost independent of the rest of YAZ, the only important dependence is of nmem, and that only for using the semaphore definition there.

The dynamic log levels and log rotation were introduced in YAZ 2.0.28. At the same time, the log bit names were changed from LOG_something to YLOG_something, to avoid collision with syslog.h.