Logging

MACSio’s logging package is a small utility for logging various kinds of messages from processors. This includes debugging messages, warnings and errors.

A log is a single text file that is divided into groups of message lines. Each processor gets its own group of lines within the file it may write to. Rank 0 gets the first group of lines. Rank 1, the next group of lines and so forth. Each line has a maximum length too.

When a log is created with MACSIO_LOG_LogInit(), the caller specifies the MPI communicator the log will be used for, the number of message lines per task to allocate plus a count of extra lines for rank 0 and the maximum length of any message. Rank 0 initializes the text file with all space characters except for header lines to distinguish each processor’s group of lines in the file. Note that for a large run on say 10^5 processors, it may take rank 0 several seconds to initialize this file.

Messages are restricted to a single line of text. Any embedded new-line characters are removed from a message and replaced with a ‘!’ character. If a processor’s message is longer than the maximum length of a line for the log, the message is truncated to fit within the line. As processors issue messages, they are written to the processors group of lines in round-robin fashion. As the set of messages issued from a processor reaches the end of its group of lines within the file, it starts issuing new messages at the beginning of the group. So, older messages can wind up getting overwritten by newer messages. However, all the most recent messages prior to any significant error will at least be captured in the log.

Parallelism in writing to a MACSIO_LOG file is achieved by ensuring no two processor attempt to write data in overlapping regions in the file by using pwrite() to do the actual writes.

MACSio’s main creates a default log, MACSIO_LOG_MainLog, on the MACSIO_MAIN_Comm. That log is probably the only log needed by MACSio proper or any of its plugins. The convenience macro, MACSIO_LOG_MSG, is the only method one need to worry about to log messages to the main log. That macro will also capture more detailed information regarding error states around the time the message issue issued including the file and line number, the system errno and the most recent MPI error state.

If you use MACSIO_LOG_MSG, messages are allowed one of several severities; Dbg1, Dbg2, Dbg3, Warn, Err and Die. A severity of Die causes an abort. Depending on the current debug level setting, Dbg1 - Dbg3 messages may or may not be recorded to a log.

MACSio’s main also creates a log for issuing messages to stderr, MACSIO_LOG_StdErr. However, there is no convenience macro like MACSIO_LOG_MSG for logging messages to MACSIO_LOG_StdErr. A caller simply has to use the logging interface methods to issue messages to MACSIO_LOG_StdErr.

However, any plugin or other portion of MACSio may, optionally, create its own, private, log using MACSIO_LOG_LogInit(). Once a log is created, any processor can independently issue messages to the log. There is no parallel communication involved in issuing messages to logs.

Examples of the use of the logging package can be found in Example (tstlog.c).

Logging API

group MACSIO_LOG

Message logging utilities.

Defines

MACSIO_LOG_DEFAULT_LINE_COUNT
MACSIO_LOG_DEFAULT_EXTRA_LINES
MACSIO_LOG_DEFAULT_LINE_LENGTH
__BASEFILE__

Same as basename(FILE) Used to strip unnecessary path terms from in messages.

MACSIO_LOG_MSG(SEV, MSG)

Convenience macro for logging a message to the main log.

Parameters

  • [in] SEV: Abbreviated message severity (e.g. ‘Dbg1’, ‘Warn’)

  • [in] MSG: Caller’s sprintf-style message enclosed in parenthises (e.g. ‘(“Rank %d failed”,rank))’

MACSIO_LOG_MSGV(VSEV, MSG)

Alterantive to MACSIO_LOG_MSG when severity is a runtime variable.

Parameters

  • [in] VSEV: Runtime variable in which message severity is stored

  • [in] MSG: Caller’s sprintf-style message enclosed in parenthises (e.g. ‘(“Rank %d failed”,rank))’

MACSIO_LOG_MSGL(LOG, SEV, MSG)

Convenience macro for logging a message to any specific log.

Parameters

  • [in] LOG: The log handle

  • [in] SEV: Abbreviated message severity (e.g. ‘Dbg1’, ‘Warn’)

  • [in] MSG: Caller’s sprintf-style message enclosed in parenthises (e.g. ‘(“Rank %d failed”,rank))’

MACSIO_LOG_MSGLV(LOG, VSEV, MSG)

Convenience macro for logging a message with variable severity to any specific log.

Parameters

  • [in] LOG: The log handle

  • [in] VSEV: Runtime variable in which message severity is stored

  • [in] MSG: Caller’s sprintf-style message enclosed in parenthises (e.g. ‘(“Rank %d failed”,rank))’

Typedefs

typedef struct _log_flags_t log_flags_t
typedef struct _MACSIO_LOG_LogHandle_t MACSIO_LOG_LogHandle_t
typedef enum _MACSIO_LOG_MsgSeverity_t MACSIO_LOG_MsgSeverity_t
typedef struct _MACSIO_LOG_LogHandle_t MACSIO_LOG_LogHandle_t

Enums

enum _MACSIO_LOG_MsgSeverity_t

Values:

enumerator MACSIO_LOG_MsgDbg1

Debug level 1: For coarse grained debugging messages (rare enough performance isn’t effected)

enumerator MACSIO_LOG_MsgDbg2

Debug level 2: For moderate grained debugging messages (may effect performance)

enumerator MACSIO_LOG_MsgDbg3

Debug level 3: For fine grained debugging messages (most likely effects performance)

enumerator MACSIO_LOG_MsgInfo

Informational messages

enumerator MACSIO_LOG_MsgWarn

Warnings of minor problems that can be recovered from without undue effects

enumerator MACSIO_LOG_MsgErr

Error conditions that result in unexpected behavior

enumerator MACSIO_LOG_MsgDie

Unrecoverable errors

Functions

char const *MACSIO_LOG_MakeMsg(char const *format, ...)

Internal convenience method to build a message from a printf-style format string and args.

Parameters

  • format: A printf-like error message format string.

This method is public only because it is used within the MACSIO_LOG_MSG convenience macro.

MACSIO_LOG_LogHandle_t *MACSIO_LOG_LogInit(MPI_Comm comm, char const *path, int line_len, int lines_per_proc, int extra_lines_proc0)

Initialize a log.

Parameters

  • comm: MPI Communicator of tasks that will issue messages to this log

  • path: The name of the log file

  • line_len: The length of each message line in the log file

  • lines_per_proc: The number of message lines for each MPI task

  • extra_lines_proc0: The number of extra message lines for processor rank 0

All processors in the comm communicator must call this function collectively with identical values for path, line_len, and lines_per_proc.

void MACSIO_LOG_LogMsg(MACSIO_LOG_LogHandle_t const *log, char const *fmt, ...)

Issue a printf-style message to a log.

Parameters

  • log: The handle for the specified log

  • fmt: A printf-style format string for the log message

May be called independently by any processor in the communicator used to initialize the log.

void MACSIO_LOG_LogMsgWithDetails(MACSIO_LOG_LogHandle_t const *log, char const *linemsg, MACSIO_LOG_MsgSeverity_t sevVal, char const *sevStr, int sysErrno, int mpiErrno, char const *theFile, int theLine)

Convenience method for building a detailed message for a log.

Parameters

  • log: Log handle to issue message to

  • linemsg: Caller’s message string

  • sevVal: Caller’s message severity value

  • sevStr: Caller’s message severity abbreviation string

  • sysErrno: Current (most recnet) system’s errno

  • mpiErrno: Current (most recent) MPI error

  • theFile: Caller’s file name

  • theLine: Caller’s line number within the file

void MACSIO_LOG_LogFinalize(MACSIO_LOG_LogHandle_t *log)

Finalize and close an open log Should be called collectively by all processors that created the log.

Parameters

  • log: The log to be closed

Variables

int mpi_errno

Error code returned by most recent MPI call.

MACSIO uses mpi_errno much like the system’s errno. However, there is no way to enforce that any particular MPI function calls set mpi_errno. MACSIO relies upon the honor system of develepors to always make MPI calls by setting mpi_errno to the return value of those calls. Assuming this practice is followed throughout MACSIO and any of its plugins, then the global variable mpi_errno should always hold the MPI error return value of the most recent MPI call.

int MACSIO_LOG_DebugLevel

Filtering level for debugging messages.

MACSIO generates 3 levels of debug messages numbered 1, 2 and 3. Each level is intended to represent more and more detailed debugging messages. Level 1 messages are issued rare enough by MACSIO (e.g. coarse grained) that they will not impact performance. Level 3 messages can be issued often enough by MACSIO that they will almost certainly impact performance. Level 2 messages are somewhere in between. The global variable MACSIO_LOG_DebugLevel is used to filter what messages generated by MACSIO that will actually make it into a detailed log message. If MACSIO_LOG_DebugLevel is set to level N, then messages at and below N debug level will appear in a log when written via MACSIO_LOG_LogMsgWithDetails. However, messages above this level will be discarded. As developers write code blocks in MACSIO, developers must choose what kind of messages are issued and, for debugging kinds of messages, the appropriate debug level.

MACSIO_LOG_LogHandle_t *MACSIO_LOG_MainLog

Log handle for MACSIO’s main log.

Typically, developers will use MACSIO_LOG_MSG macro to log messages. Such messages are automatically logged to the main log. The main log is created by MACSIO’s main.

MACSIO_LOG_LogHandle_t *MACSIO_LOG_StdErr

Log handle for MACSIO’s stderr output.

In rare cases, developers may want to issues messages to stderr. In this case, MACSIO’s stderr log handle should be used.

struct _log_flags_t

Public Members

unsigned int was_logged

Indicates if a message was ever logged to the log

struct _MACSIO_LOG_LogHandle_t

Public Members

MPI_Comm comm

MPI Communicator of tasks that will issue messages to this log

char *pathname

Name of the log file

int logfile

Log file file descriptor

int rank

Rank of the processor that created this log handle

int size

Size of the communicator that created this log handle

int log_line_length

Maximum length of a message line in the log file

int lines_per_proc

Number of message lines allocated in the file for each processor

int extra_lines_proc0

Additional number of message lines for processor with MPI rank 0

int current_line

Index into this processor’s group of lines in the log file at which the next message will be written

log_flags_t flags

Informational flags regarding the log

Example (tstlog.c)

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87

#include <errno.h>
#include <stdlib.h>
#include <strings.h>

#include <macsio_log.h>

#ifdef HAVE_MPI
#include <mpi.h>
#endif

int MACSIO_MAIN_Rank;
int MACSIO_MAIN_Size;
int MACSIO_MAIN_Comm;

int main (int argc, char **argv)
{
    int i;
    int rank=0, size=1;
    int num_cols = 128, num_rows = 20, extra_lines = 20;
#ifdef HAVE_MPI
    MPI_Comm comm = MPI_COMM_WORLD;
#else
    int comm = 0;
#endif

    for (i = 0; i < argc; i++)
    {
        if (!strncasecmp(argv[i], "num_cols=", 9))
            num_cols = strtol(argv[i]+9, 0, 10);
        else if (!strncasecmp(argv[i], "num_rows=", 9))
            num_rows = strtol(argv[i]+9, 0, 10);
        else if (!strncasecmp(argv[i], "extra_lines=", 9))
            extra_lines = strtol(argv[i]+9, 0, 10);
    }

#ifdef HAVE_MPI
    MPI_Init(&argc, &argv);
    MPI_Comm_size(comm, &size);
    MPI_Comm_rank(comm, &rank);
#endif

    MACSIO_LOG_DebugLevel = 2; /* should only see debug messages level 1 and 2 */
    MACSIO_LOG_MainLog = MACSIO_LOG_LogInit(comm, "tstlog.log", num_cols, num_rows, extra_lines);
    MACSIO_LOG_StdErr = MACSIO_LOG_LogInit(comm, 0, 0, 0, 0);

    if (rank == 1)
    {
        MACSIO_LOG_MSG(Dbg1, ("I am staring with processor 1"));
        MACSIO_LOG_MSG(Dbg2, ("Test output of a very, very, very, very, very, very, very, very, very, very, very, very, very, very, very, very, very, very, very, very, very, very, very, very, very, very long line"));
    }
    else if (rank == 2)
    {
        MACSIO_LOG_MSG(Warn, ("Starting on proc 2"));
        MACSIO_LOG_LogMsg(MACSIO_LOG_StdErr, "Logging a message to stderr for rank %d", rank);
    }
    else if (rank == 0)
    {
        errno = EOVERFLOW;
#ifdef HAVE_MPI_
        mpi_errno = MPI_ERR_COMM;
#else
        mpi_errno = 0;
#endif

        MACSIO_LOG_MSG(Err, ("I am here on proc 0"));
    }
    else
    {
        int i;
        MACSIO_LOG_MsgSeverity_t sev = rank%2?MACSIO_LOG_MsgDbg2:MACSIO_LOG_MsgDbg3;
        for (i = 0; i < 25; i++)
        {
            MACSIO_LOG_MSGV(sev, ("Outputing line %d for rank %d\n", i, rank));
        }
    }

    MACSIO_LOG_LogFinalize(MACSIO_LOG_StdErr);
    MACSIO_LOG_LogFinalize(MACSIO_LOG_MainLog);

#ifdef HAVE_MPI
    MPI_Finalize();
#endif

    return 0;

}