Skip to content

How to enable and capture VDB log messages

kwrodarmer edited this page Jul 6, 2016 · 6 revisions

VDB has extensive and detailed logging capabilities that user code can both hook into and capture. This document will demonstrate how a c++ program using VDB might do this.

// VERY IMPORTANT:
// _DEBUGGING is needed to turn on debugging messages
// VDB code does NOT obey DEBUG
#define _DEBUGGING 1
#include <klib/log.h>
#include <klib/debug.h>

#include <iostream>
#include <string>
#include <stdexcept>
#include <assert.h>

// a calling convention define for Windows
#ifndef CC
 #if defined _MSC_VER
  #define CC __cdecl
 #else
  #define CC
 #endif
#endif

class VDBLog
{
    // in this example, we pump all logging to cerr, regardless of the type of log
    // real code might want to separate the output and/or add more information
    void log(std::string const &message) {
        std::cerr << message << std::endl;
    }

    // declare callback function to hook into logging output
    // for Windows builds, this function must use __cdecl calling convention
    // ( see the "CC" macro defined above )
    static rc_t CC receive(void *p, const char *buffer, size_t size, size_t *written);
public:
    /* version is XXYYZZZZ in hex; XX is major version, YY is minor version; ZZZZ is revision
     * it is used to print a version number in log messages
     *
     * logLevel sets the minimum severity for messages to be logged; it is defined in klib/log.h:
     *
     *   klogFatal    fatal errors
     *   klogSys      errors from the system
     *   klogInt      internal software errors
     *   klogErr      ordinary errors, generally related to inputs and data
     *   klogWarn     non-errors which may indicate an unusual condition
     *   klogInfo     non-errors, like progress or success messages
     *   klogDebug    debugging messages which are not removed in release code
     *
     *
     * debugFlag is for turning on debug messages for a particular module. These messages are removed
     * in release builds. This facility is extensive and extensible. The values are structured strings
     * `module` or `module-condition`. Each module has its own set of condition codes; I won't document
     * them here. See klib/debug.h for the complete list of current values.
     * Some of the modules currently defined are:
     *
     *   KDB     low-level database access
     *   KFG     configuration
     *   KNS     low-level network access
     *   KRYPTO  crypto
     *   REF     object lifetimes
     *   VDB     high-level database access
     *   VFS     high-level network and file access
     */
    explicit VDBLog(char const program[], int version, int logLevel = klogErr, char const *debugFlag = 0);
    ~VDBLog();
};

// not implemented here; left as an exercise to the reader
static void doSomeVDBStuff(char const run_accession[]);

int main(int argc, char *argv[])
{
    // initialize with path to program and version 1.0.0, enable debugging of VFS
    VDBLog log(argv[0], 0x1000000, klogDebug, "VFS");
    try {
        doSomeVDBStuff("ERR1417836");
    }
    catch (std::exception const &e) {
        std::cerr << e.what() << std::endl;
    }

    return 0;
}

// this callback function is being used to receive a buffer of data to log
// in this example, it is being used for LOG, STATUS and DEBUG messages since
// all it does is to print to cerr. Real code would probably want to have separate
// handlers. NB - the calling convention must be cdecl on Windows.
//
// "user_data" here is passed in during logger initialization
//
// "buffer" and "size" contain the data to be written.
// they are expected to be terminated with a newline.
//
// "written" is an OUTPUT parameter for conveying the number of bytes actually written
// by the callback function.
rc_t CC VDBLog::receive(void *user_data, const char *buffer, size_t size, size_t *written) {

    // we initially passed in a VDBLog*
    VDBLog *const objp = static_cast<VDBLog *>(user_data);

    // convert data buffer to a string, removing trailing newline
    assert(buffer != 0);
    assert(size != 0);
    assert(buffer[size - 1] == '\n');
    std::string const &message = std::string(buffer, size - 1);

    // write message to output
    objp->log(message);

    // claim to have written all bytes of input
    *written = size;

    // no error
    return 0;
}

VDBLog::VDBLog(const char program[], int version, int logLevel, const char *debugFlag)
{
    rc_t rc = 0;

    rc = KWrtInit(program, version);
    if (rc != 0)
        throw std::runtime_error("KWrtInit failed!");

    // to receive log messages generated from the library
    // log messages are routed to two separate handlers:
    //   one for the application
    //   the other for messages generated by the library
    rc = KLogLibHandlerSet(VDBLog::receive, (void *)this);
    if (rc != 0)
        throw std::runtime_error("KLogLibHandlerSet failed!");

    // for comparison, this is how you would set a handler for
    // log messages generated by the application.
    // after setting this handler, your code could also call
    // the VDB functions LogMsg() or LogErr() and use the same
    // logging mechanism.
    rc = KLogHandlerSet(VDBLog::receive, (void *)this);
    if (rc != 0)
        throw std::runtime_error("KLogHandlerSet failed!");

    // process-global log severity level
    // call calls to logging will present a severity level for the message
    // if that level is <= the process-global severity level,
    // your callback will receive the message.
    rc = KLogLevelSet(logLevel);
    if (rc != 0)
        throw std::runtime_error("KLogLevelSet failed!");

    // to receive status (verbosity) messages from the library
    // normally this would use a separate callback function,
    // but for this example they are all handled by the same one
    rc = KStsHandlerSet(VDBLog::receive, (void *)this);
    if (rc != 0)
        throw std::runtime_error("KStsHandlerSet failed!");

    // to receive debugging messages; this doesn't do anything in release code
    rc = KDbgHandlerSet(VDBLog::receive, (void *)this);
    if (rc != 0)
        throw std::runtime_error("KDbgHandlerSet failed!");

    if (debugFlag != 0) {
        // to turn on output from a particular module
        // this can actually be called many times to turn on multiple modules/conditions
        rc = KDbgSetString(debugFlag);
        if (rc != 0)
            throw std::runtime_error("KDbgSetString failed!");
    }
}

VDBLog::~VDBLog(void)
{
    // replace our callback with default handlers
    KDbgHandlerSetStdErr();
    KLogHandlerSetStdErr();
    KLogLibHandlerSetStdErr();
    KDbgHandlerSetStdErr();
}