LDM Logging
LDM Logging

Copyright 2019 University Corporation for Atmospheric Research. All rights reserved. See the the file COPYRIGHT in the top-level source-directory for licensing conditions.

Author
: Steven R. Emmerson

Table of Contents


Introduction

The logging component of the LDM comprises a single API with two implementations: one using a simple implementation and the other using the LDM's original ulog module (that module is still part of the LDM library for backward compatibility with user-developed code). By default the simple implementation is used. The ulog implementation will be used if the option --with-ulog is given to the configure script.

Unless otherwise stated, this documentation is primarily on the simple implementation rather than the ulog implementation, which is documented elsewhere.

Both implementations manage a FIFO queue of log messages for each thread in a process. log_add*() functions add to the queue. At some point, one of the following should occur:

  • A final message optionally added;
  • The accumulated messages emitted by one of the log_flush_*() functions (e.g., "log_flush_error()"); or
  • The queue cleared by log_clear().

By default, log messages are written to

  • If the process is a daemon (i.e., doesn't have a controlling terminal)
    • Simple Implementation: The LDM log file
    • ulog implementation: The system logging daemon
  • If the process is not a daemon: The standard error stream

(Note that the LDM server, ldmd, daemonizes itself by default. It is the only program that does.)

If the output destination is a file, then a USR1 signal sent to any LDM utility will cause this logging module to close and re-open the output file. This allows the log files to be rotated and purged by an external process so that the disk partition doesn't become full.

A USR2 signal sent to any LDM utility will cause the logging level to be "rotated" in the following sequence:

NOTICE -> INFO -> DEBUG -> NOTICE -> ...

Be advised that logging at the DEBUG level will likely cause the log file to become very large, very quickly.

The default destination for log messages can usually be overridden by the command-line option -l dest:

dest Destination
"" System logging daemon
"-" Standard error stream
path File whose pathname is path

Example

Here's a contrived example:

#include <log.h>
#include <errno.h>
#include <pthread.h>
#include <stdio.h>
#include <unistd.h>
static int system_failure()
{
(void)close(-1); // Guaranteed failure for the purpose of this example
log_add_syserr("close() failure"); // Uses `errno`; adds to message queue
return -1;
}
static int func()
{
int status = system_failure();
if (status)
log_add("system_failure() returned %d", status); // Adds to message queue
return status;
}
static pid_t exec_child(const char* const path)
{
int pid = fork();
if (pid < 0) {
log_add_syserr("Couldn't fork() process"); // Uses `errno`
}
else if (pid > 0) {
// Child process
(void)execl(path, path, NULL)
/*
* Adds to empty message queue using `errno`, prints queue at ERROR
* level, then clears queue:
*/
log_add_syserr("execl(\"%s\") failure", path); // Uses `errno`
log_fini(); // Good form
exit(1);
}
return pid;
}
// Called by pthread_create()
static void* start(void* arg)
{
...
log_free(); // Frees thread-specific resources
return NULL;
}
static int daemonize(void)
{
int status;
pid_t pid = fork();
if (pid == -1) {
log_add_syserr("fork() failure"); // Uses `errno`
status = -1;
}
else {
if (pid > 0) {
// Parent process
(void)printf("%ld\n", (long)pid);
status = 0;
}
else {
// Child process
(void)setsid();
(void)fclose(stdin);
(void)fclose(stdout);
(void)fclose(stderr);
log_avoid_stderr(); // Because this process is now a daemon
...
status = 0;
}
}
return status;
}
int main(int argc, char* argv)
{
...
log_init(argv[0]); // Necessary
...
while ((int c = getopt(argc, argv, "l:vx") != EOF) {
extern char *optarg;
switch (c) {
case 'l':
(void)log_set_output(optarg);
break;
case 'v':
// In case "-x" option specified first (e.g., "-xv")
break;
case 'x':
break;
...
}
}
...
if (func()) {
if (log_is_enabled_info) { // Test because of `slow_func()`
// Adds to message queue, prints queue at INFO level, clears queue
log_add("func() failure: reason = %s", slow_func());
}
}
if (func()) {
// Adds to message queue, prints queue at ERROR level, clears queue
log_add("func() failure: reason = %s", fast_func());
}
const char program[] = "utility";
if (exec_child(program) < 0) {
// Adds to message queue, prints queue at ERROR level, clears queue
log_add("Couldn't execute program %s", program);
}
pthread_t thread_id;
int status = pthread_create(&thread_id, NULL, start, NULL);
if (status) {
// Adds to message queue, prints queue at ERROR level, clears queue
log_add("Couldn't create thread");
}
status = daemonize();
if (status) {
// Adds to message queue, prints queue at ERROR level, clears queue
log_add("Couldn't daemonize");
}
...
log_fini(); // Good form
return status ? 1 : 0;
}
#define log_free()
Definition: log.h:330
int log_set_level(const log_level_t level)
#define log_fini()
Definition: log.h:138
#define log_flush_info()
Definition: log.h:637
int log_init(const char *const id)
#define log_is_enabled_info
Definition: log.h:363
#define log_flush_error()
Definition: log.h:622
@ LOG_LEVEL_DEBUG
Debug messages.
Definition: log.h:33
@ LOG_LEVEL_INFO
Informational messages.
Definition: log.h:34
void log_avoid_stderr(void)
#define log_add_syserr(...)
Definition: log.h:534

Format of Log Messages

Log messages sent to either the standard error stream or the LDM log file by the simple implementation will have the following format:

time proc loc level msg

where:

time
Is the creation-time of the message in the form YYYYMMDDThhmmss.uuuuuuZ (e.g., 20160121T163218.391847Z).
proc
Is the identifier of the process in the form id[pid], where id is the identifier given to log_init(), log_set_id(), or log_set_upstream_id(), and pid is the system's numeric process-identifier.
loc
Is the location where the message was created in the form file:func, where file and func are, respectively, the names of the file and function that generated the message.
level
Is the logging-level (i.e., priority) of the message. One of DEBUG, INFO, NOTE, WARN, or ERROR.
msg
Is the actual message given to one of the logging functions.

Log messages sent to the system logging daemon will, in general, have the same proc, loc, and msg components as above, but the time and level components will depend on the system logging daemon. Additionally, the system logging daemon might alter the order of the components and/or add additional components (e.g., the name of the local host).