NetLogger Cookbook

$ nl_parser -m bp -i
Module     : netlogger.parsers.modules.bp
Description: Parse Best-Practices logs into Best-Practices logs.
Parameters :
  - has_gid {True,*False*}: If true, the "gid=" keyword in the input will be
    replaced by the currently correct "guid=".
  - verify {*True*,False}: Verify the format of the input, otherwise simply
    pass it through without looking at it.

$ nl_parser -mbp /tmp/sample_file.bp -p host=`hostname`

$ nl_parser -c $config_file

$ ps -o pid,comm

"""Parse result of 'ps -o pid,comm'"""
import time
# Import the superclass
from netlogger.parsers.base import BaseParser
#  Required class `Parser`, which inherits from `BaseParser`
class Parser(BaseParser):
    # Your parser must take a positional fileobj, then 0 or more
    # named parameters, and then keyword arguments to pass up
    # to the `BaseParser`
    def __init__(self, f, my_param = 'foo', **kw):
        # Pass the fileobj and keywords up to the BaseParser. The fullname is
        # used as the qualname argument to the Python logging.getLogger()
        BaseParser.__init__(self, f, fullname=__name__, **kw)
    # This method does all the work of parsing.
    # Each invocation gets a single line from the input sources, and is
    # expected to return a sequence of 0 or more dictionaries that will be
    # turned into NetLogger log entries.
    def process(self, line):
        # If there is nothing to return, just return an empty sequence
        if line.startswith("PID"): return ()
        # Parsing logic..
        pid, comm = line.split(' ',1)
        # Build the return value. The value for the `ts` keyword should be
        # either the floating-point number of seconds since the UNIX epoch
        # (midnight on Jan 1, 1970) or a string formatted as an ISO 8601
        # timestamp like '2008-06-05T19:28:26.718230Z'.
        # The timezone ('Z') can optionally be replaced with a +/-HH:MM.
        # The value for the 'event' keyword should be a unique name using
        # the Java class name convention of prefixing with a reversed
        # DNS ('org.mydomain', in this case). If the event is part of a pair
        # indicating the start and end of something, the pair of events should
        # use the suffixes '.start' and '.end', respectively.
        # See the CEDPS Logging Best Practices guide for details on the above.
        d = dict(ts=time.time(), event="org.mydomain.ps.item",
                 pid=int(pid), command=comm)
        # Return a sequence. Remember to always return a sequence even if
        # you have only one return value.
        return (d,)

#!/usr/bin/env python
"""
Unittests for ps_parser.py
"""
import unittest
from netlogger.tests import testBase
import ps_parser

class TestCase(testBase.BaseParserTestCase):
    """Unit test cases.
    """
    basename = "ps_parser-"
    parser_class = ps_parser.Parser

    def testBasic(self):
        """Basic test of ps_parser
        """
        # the full path should be data/ps_parser-sample.log
        filename = "sample.log"
        # count lines in file
        expected = len(list(file(self.getFullPath(filename))))
        # subtract one for ps's header line
        expected = expected - 1
        # Check if all lines got parsed
        self.checkGood(filename=filename, num_expected=expected)

# Boilerplate to run the tests
def suite():
    return testBase.suite(TestCase)
if __name__ == '__main__':
    testBase.main()

# for UNIX sh/bash/ksh, etc.
sh$ DIR=/opt/netlogger ; export DIR
# or, if you use a C-Shell derivative
csh% setenv DIR /opt/netlogger

$DIR
  |
  +- etc
  |   |
  |   +- nl_parser.conf
  |   +- nl_loader.conf
  |
  +- var
      |
      +- log
      |   |
      |   +- nl_parser.log
      |   +- nl_loader.log
      |   +- nl_pipeline.log
      |
      +- run
          |
          +- nl_parser.pid
          +- nl_loader.pid
          +- nl_pipeline.pid

nl_pipeline -n -v -c $DIR/etc -l $DIR/var/log -p $DIR/var/run -i 30

would run:
/usr/bin/nl_parser -d $DIR/var/run/nl_parser.pid -c $DIR/etc/nl_parser.conf
/usr/bin/nl_loader -d $DIR/var/run/nl_loader.pid -c $DIR/etc/nl_loader.conf
# reload parser configuration every 30 seconds

/usr/bin/nl_parser -c $DIR/etc/nl_parser.conf &
/usr/bin/nl_loader -c $DIR/etc/nl_loader.conf &
# If these both run without error, try sending each of them a SIGHUP.
# This signal causes them to re-read their configuration files.
kill -HUP %1
kill -HUP %2

kill %1 %2
rm -f $DIR/var/*.state
nl_pipeline -v -c $DIR/etc -l $DIR/var/log -p $DIR/var/run -i 30

$ mysqldump fake > fake.dmp
# Alternatively, to name the database in the dump file
$ mysqldump -B fake > fake.dmp

$ mysql -e "create database fake"
$ mysql -D fake < fake.dmp
# Or, if -B was used during dump:
$ mysql < fake.dmp

--
-- Put event types in a temporary table
--
create temporary table event_types (id integer, name varchar(255))
select id,
       count(*) 'num',
       min(time) 'first',
       max(time) 'last',
       (case
           when startend = 0 then concat(name,'.start')
           when startend = 1 then concat(name,'.end')
           else name
       end) name
       from event group by name, startend;
--
-- Join with attr(ibutes) table
--
create temporary table event_attrs (event varchar(255), names varchar(4096))
select e.name as 'event',
       group_concat(attr.name order by attr.e_id separator ',') as 'names'
from event_types e
     left join attr on e.id = attr.e_id
group by e.name;

--
-- Join with ident(ifiers) table
--
create temporary table event_idents (event varchar(255), names varchar(4096))
select e.name as 'event',
       group_concat(ident.name order by ident.e_id separator ',') 'names'
from event_types e
     left join ident on e.id = ident.e_id
group by e.name;

--
-- Join with DN table
--
create temporary table event_dn (event varchar(255), has_dn varchar(3))
select e.name as 'event',
(case when isnull(dn.id) then 'no' else 'yes' end) 'has_dn'
from event_types e
     left join dn on e.id = dn.e_id
group by e.name;

--
-- Join with text table
--
create temporary table event_text (event varchar(255), has_text varchar(3))
select e.name as 'event',
(case when isnull(text.id) then 'no' else 'yes' end) 'has_text'
from event_types e
     left join text on e.id = text.e_id
group by e.name;

--
-- Project them all into the same table
--
select x.event, e.num, from_unixtime(e.first, "%Y-%m-%dT%H:%i:%S") 'first', from_unixtime(e.last, "%Y-%m-%dT%H:%i:%S") 'last', x.names 'attributes', y.names 'identifiers', d.has_dn, t.has_text
from event_attrs x
join event_idents y on x.event = y.event
join event_types e on x.event=e.name
join event_dn d on d.event=e.name
join event_text t on t.event=e.name
order by num;

/*
Copyright (c) 2004, The Regents of the University of California, through
Lawrence Berkeley National Laboratory (subject to receipt of any required
approvals from the U.S. Dept. of Energy).  All rights reserved.
*/
/** @file
 * @ingroup examples */

/**
 * Sample high-level C API usage. This is the API that most people
 * would be expected to use.
 */
#include <stdio.h>
#include "nl.h"

 /**
  * Pretend to do something. Actually a no-op.
  */
void do_something(void)
{
    return;
}


/**
 * MAIN
 */
int main(int argc, char **argv)
{
    NL_log_T environment, screen, debug;
    int i;

    /* If the destination is NULL, setting
     * the environment variable 'NL_DEST' will redirect it, e.g.:
     *    % export NL_DEST=/tmp/myData.log
     */
    environment = NL_open(NULL);

    /* Set destination to stderr, output level to 'info', and
     * add a string constant to every message
     */
    screen = NL_open("&");
    NL_set_level(screen, NL_LVL_INFO);
    NL_set_const(screen, "constant:s", "constant value");

    /* Debugging handle */
    debug = NL_open("&");
    NL_set_level(debug, NL_LVL_DEBUG1);

    /* Write an empty 'program.start' event to the 'screen' log. */
    NL_write(screen, NL_LVL_INFO, "program.start", "");

    /*
     * log a 'loop.start' event with two values to the 'debug' log.
     * since we know the values are constant, we can use a ':'
     * instead of an '=' as the keyword:datatype separator.
     *
     * By default, these will not be logged, but could be
     * "turned on" by using the dynamic levels feature.
     * e.g., if you execute the (bash) shell commands
     *    % export NL_CFG=/tmp/levels.cfg
     *    % echo 5 > /tmp/levels.cfg
     * before running this program, you will see the messages.
     */
    NL_write(debug, NL_LVL_DEBUG, "loop.start", "start:i stop:i", 0, 10);
    for (i = 0; i < 10; i++) {
        /*
         * Wrap do_something() with an eponymous event at
         * a higher (more fine-grained) debugging level.
         *
         * To turn on these messages, you will need to set the
         * logging level to '6' (see comment above).
         */
        NL_write(debug, NL_LVL_DEBUG1, "do.something.start", "index=i", i);
        do_something();
        NL_write(debug, NL_LVL_DEBUG1, "do.something.end", "index=i", i);
    }
    /*
     * these are just mirror images of the loop.start/program.start
     * messages
     */
    NL_write(debug, NL_LVL_DEBUG, "loop.end", "start=i stop=i", 0, 10);
    NL_write(screen, NL_LVL_INFO, "program.end", "", 1.0);

    /* close logs */
    NL_close(environment);
    NL_close(debug);
    NL_close(screen);

    return 0;
}

#include <stdarg.h>
#include <stdio.h>
#include <string.h>
#include <sys/time.h>
#include <unistd.h>
#include "nl.h"

int main(int argc, char **argv)
{
    int len;
    char buf[65536];
    struct timeval start_t, end_t;
    gettimeofday(&start_t, 0);
    gettimeofday(&end_t, 0);
    len = NL_sprintf(buf, "gridftp.FTP_INFO", NL_LVL_INFO,
                     "HOST=s PROG=s "
                     "START.TM=d END.TM=d "
                     "USER=s FILE=s "
                     "BUFFER=l BLOCK=l NBYTES=l VOLUME=d "
                     "STREAMS=i STRIPES=i "
                     "DEST=s TYPE=s CODE=i",
                     "131.243.2.1", "GridFTP",
                     start_t.tv_sec + start_t.tv_usec / 1e6,
                     end_t.tv_sec + end_t.tv_usec / 1e6,
                     "Elmo", "SesameStreet.txt",
                     1LL, 2LL, 32767LL, 1e9,
                     8, 12, "123.456.3.2", "what", 1);
    write(STDOUT_FILENO, buf, len);
}

/*
Copyright (c) 2007, The Regents of the University of California, through
Lawrence Berkeley National Laboratory (subject to receipt of any required
approvals from the U.S. Dept. of Energy).  All rights reserved.
*/
static const volatile char rcsid[] = "$Id$";
/** @file nltransfer_example.c
 *  @ingroup nlsumm examples
 */
/*@{*/

/**
 * Example usage of the NetLogger "transfer" API.
 * See usage() function for program arguments.
 */

#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>
#include "nltransfer.h"

/** In reality, blocks would probably be O(100K) */
#define BLOCK_SIZE 8

/* Pretend to read some data */
int read_bytes(void)
{
    usleep(1);
    return BLOCK_SIZE;
}

/* Pretend to write some data */
int write_bytes(void)
{
    usleep(20);
    return BLOCK_SIZE;
}

/* With apologies to Mark Harris */
int bang_the_drum_slowly(void)
{
    usleep(500000);
    return BLOCK_SIZE;
}

/* Prototype for run function */
typedef int (*run_fn_t)(const char *, int);

/*
 * Get GUID from NetLogger
 */
void get_my_guid(char **guid)
{
    if (!NL_get_guid(guid) && !NL_get_someid(guid)) {
        *guid = strdup("00000000-0000-0000-0000-000000000000");
    }
}

/**
 * Log everything to the same place.
 */
int run1(const char *logfile, long summ_usec )
{

    char err_why[1024]; /* for error reporting */
    char *guid;
    NL_summ_T summ;
    NL_log_T log;
    const char *stdout_logfile = "-";
    char *result_str;

    /* Get a GUID */
    get_my_guid(&guid);
    /* Set log file to stdout if NULL */
    if (!logfile)
        logfile = stdout_logfile;

    /*
        (1) Create NetLogger log instance
    */
    /* Open log, return on error */
    log = NL_open(logfile);
    if (!log) {
        sprintf(err_why,"opening '%s'", logfile);
        goto error;
    }
    /* Set log to DEBUG level */
    NL_set_level(log, NL_LVL_DEBUG);

    /*
        (2) Create summarizer
    */
    summ = NL_summ();
    /* Make summarizer output go to log, too */
    NL_summ_set_shared_output(summ, log);
    /* Add NL_transfer events to summarizer.
       Set interval to -1 to mean "until NL_finalize()".
     */
    NL_transfer_init(summ, summ_usec,  NL_LVL_DEBUG);
    /* Don't let summarizer 'consume' the events,
     * we want them to "pass through" and get logged
     * in their full detail.
     */
    NL_transfer_set_passthrough(summ);
    /* Add this summarizer to log instance */
    NL_summ_add_log(summ, log);

    /*
        (3) Log some activity
     */
    NL_write(log, NL_LVL_INFO, "nltransfer_example.activity.start", "");
    {
        NL_transfer_blockid_t block_id;
        NL_transfer_streamid_t stream_id;
        NL_transfer_op_t op;
        double nbytes;

        for (block_id = 0; block_id < 2; block_id++) {
            for (stream_id = 11; stream_id < 13; stream_id++) {
                int opctr;
                for (opctr=NL_TRANSFER_DISK_READ; opctr < NL_TRANSFER_NOEVENT; opctr++) {
                    op = (NL_transfer_op_t)opctr;
                    NL_transfer_start(log, NL_LVL_DEBUG, op,
                                      guid, stream_id, block_id);
                    nbytes = bang_the_drum_slowly();
                    NL_transfer_end(log, NL_LVL_DEBUG, op,
                                    guid, stream_id, block_id, nbytes);
                }
            }
        }
    }
    NL_write(log, NL_LVL_INFO, "nltransfer_example.activity.end", "");

    /*
        (4) Finalize handles and get result string.
            Then close everything up
     */
    NL_transfer_finalize(summ);
    result_str = NL_transfer_get_result_string(summ, guid);
    printf("RESULT STRING:\n%s", result_str);
    NL_summ_del(summ);
    NL_close(log);

    return 0;

error:
    fprintf(stderr,"Error:%s:%s\n", err_why, NL_err_str());
    return -1;
}

/**
 * Print usage message and exit
 */
void usage(void)
{
    printf("Program usage: nltransfer_example [-o logfile] [-i usec]\n");
    exit(0);
}

/**
 * Program entry point
 */
int main(int argc, char **argv)
{
    long usec;
    int i, result = 0;
    char *logfile, *endptr;

    logfile = NULL;
    usec = -1;
    if (argc >= 2) {
        for (i=1; i < argc-1; i++) {
            if (argv[i][0] != '-')
                usage();
            switch (argv[i][1]) {
                case 'i':
                    usec = strtol(argv[i +1], &endptr, 10);
                    if (endptr == NULL)
                        usage();
                    break;
                case 'o':
                    logfile = strdup(argv[i+1]);
                    break;
                default:
                    usage();
            }
        }
    }

    if (usec < 0)
        usec = 1000000;
    if (!logfile)
        logfile = strdup("-");

    printf("--------------------------------------------------\n");
    result = run1(logfile, usec);

    free(logfile); /* keep valgrind happy */

    return result;
}

/*@}*/

import gov.lbl.netlogger.LogMessage;
import java.util.UUID;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;

/**
 * Example use of NetLogger.
 */
public class NetLoggerExample {

    private String guid;
    private Log log;
    private static int COUNT = 2;

    /**
     * Constructor
     */
    public NetLoggerExample() {
        this.guid = UUID.randomUUID().toString();
        this.log = LogFactory.getLog(NetLoggerExample.class);
    }

     /**
     * Make a short example log without log4j.
     */
    public void nolog4j() {
        LogMessage m;
        for (int i = 0; i < COUNT; i++) {
            m = new LogMessage("nolog4j.start").add("guid",guid).add("count",i);
            print(m);
            m = new LogMessage("nolog4j.end").add("guid",guid).add("count",i);
            print(m);
        }
    }

    /**
     * Make a short example log with log4j.
     */
    public void withlog4j() {
       LogMessage m;
       for (int i = 0; i < COUNT; i++) {
            m = new LogMessage("log4j.start").add("guid",guid).add("count",i);
            this.log.info(m);
            m = new LogMessage("log4j.end").add("guid",guid).add("count",i);
            this.log.info(m);
        }
    }

    /**
     * Program entry point.
     *
     * @param argv
     */
    public static void main(String[] argv) {
        NetLoggerExample ex = new NetLoggerExample();
        ex.nolog4j();
        ex.withlog4j();
    }

   /**
    * Helper function to print to console.
    */
    private static void print(LogMessage m) {
        System.out.println(m.toString());
    }

}

#####################################################################
# log4j logging configuration file.
# to enable log4j, run java with
#       java -Dlog4j.configuration=file:path/to/log4j.properties ...
#####################################################################

log4j.rootLogger=INFO

# Send 'NetLoggerExample' messages to the NETLOGGER appender
log4j.logger.NetLoggerExample=DEBUG, NETLOGGER

# - Append to file
#log4j.appender.NETLOGGER=org.apache.log4j.FileAppender
#log4j.appender.NETLOGGER.File=netlogger-example.log
#log4j.appender.NETLOGGER.bufferedIO=true
#log4j.appender.NETLOGGER.bufferSize=16384

# - Append to console
log4j.appender.NETLOGGER=org.apache.log4j.ConsoleAppender

# Layout for NETLOGGER appender
log4j.appender.NETLOGGER.layout=org.apache.log4j.PatternLayout
log4j.appender.NETLOGGER.layout.ConversionPattern=%mlevel=%p\n

# Layout for Console appender
log4j.appender.Console=org.apache.log4j.ConsoleAppender
log4j.appender.Console.layout=org.apache.log4j.PatternLayout

use NetLogger;
use Carp;

$h = {
      val => "1",
     };
$log = NetLogger->new();
$log->set_level($NetLogger::INFO);
# Write messages to 'foo.log'
$log->open("foo.log");
$log->debug("hello",$h);
$log->warning("goodbye",$h);
# Write the same messages to a socket
$r = $log->open("x-netlog://www.mit.edu:123");
print "log open silently failed\n" unless $r;
$log->debug("hello",$h);
$log->warning("goodbye",$h);
# Write the to stdout as well
$log->open("-");
$log->info("info.message",$h);
# Now try UDP
$r = $log->open("x-netlog-udp://localhost:15000");
print "UDP log open silently failed\n" unless $r;
$log->debug("hello",$h);
$log->warning("goodbye",$h);

"""
Logging Best Practices messages in Python.
"""
import logging
from netlogger import nllog

# Instead of logging.getLogger(), use nllog.getLogger()
log = nllog.getLogger("my.program")
# Otherwise proceed as usual
log.addHandler(logging.StreamHandler())
log.setLevel(logging.INFO)
# Log a message with event name as first argument,
# then keyword=value pairs for the rest. Use
# double underscore to mean '.'
log.info("hello", to__whom="world", from__whom="me")

ts=2008-09-24T22:23:30.402704Z event=my.program.hello level=INFO from.whom=me to.whom=world

"""
Example of bpize.py module
"""
import logging
from netlogger import bpize

# set up logger
logging.basicConfig()
for hndlr in logging.getLogger().handlers:
    bpize.BPize(hndlr, namespace="test.")
log = logging.getLogger("bpize_example")
log.setLevel(logging.INFO)
# write message
log.info('did.foo bar=purple baz="red, white and blue"')

ts=2008-09-24T15:15:37.044-08:00 guid=506b4f0a-8a86-11dd-8e9a-001b63926e0d event=test.did.foo bar=purple baz="red, white and blue" level=INFO