Logging Framework

Bro comes with a flexible key-value based logging interface that allows fine-grained control of what gets logged and how it is logged. This document describes how logging can be customized and extended.

Terminology

Bro’s logging interface is built around three main abstractions:

Log streams
A stream corresponds to a single log. It defines the set of fields that a log consists of with their names and fields. Examples are the conn for recording connection summaries, and the http stream for recording HTTP activity.
Filters
Each stream has a set of filters attached to it that determine what information gets written out. By default, each stream has one default filter that just logs everything directly to disk with an automatically generated file name. However, further filters can be added to record only a subset, split a stream into different outputs, or to even duplicate the log to multiple outputs. If all filters are removed from a stream, all output is disabled.
Writers
A writer defines the actual output format for the information being logged. At the moment, Bro comes with only one type of writer, which produces tab separated ASCII files. In the future we will add further writers, like for binary output and direct logging into a database.

Basics

The data fields that a stream records are defined by a record type specified when it is created. Let’s look at the script generating Bro’s connection summaries as an example, base/protocols/conn/main.bro. It defines a record Conn::Info that lists all the fields that go into conn.log, each marked with a &log attribute indicating that it is part of the information written out. To write a log record, the script then passes an instance of Conn::Info to the logging framework’s Log::write function.

By default, each stream automatically gets a filter named default that generates the normal output by recording all record fields into a single output file.

In the following, we summarize ways in which the logging can be customized. We continue using the connection summaries as our example to work with.

Filtering

To create a new output file for an existing stream, you can add a new filter. A filter can, e.g., restrict the set of fields being logged:

event bro_init()
    {
    # Add a new filter to the Conn::LOG stream that logs only
    # timestamp and originator address.
    local filter: Log::Filter = [$name="orig-only", $path="origs", $include=set("ts", "id.orig_h")];
    Log::add_filter(Conn::LOG, filter);
    }

Note the fields that are set for the filter:

name
A mandatory name for the filter that can later be used to manipulate it further.
path
The filename for the output file, without any extension (which may be automatically added by the writer). Default path values are generated by taking the stream’s ID and munging it slightly. Conn::LOG is converted into conn, PacketFilter::LOG is converted into packet_filter, and Known::CERTS_LOG is converted into known_certs.
include
A set limiting the fields to the ones given. The names correspond to those in the Conn::Info record, with sub-records unrolled by concatenating fields (separated with dots).

Using the code above, you will now get a new log file origs.log that looks like this:

#separator \x09
#path   origs
#fields ts      id.orig_h
#types  time    addr
1128727430.350788       141.42.64.125
1128727435.450898       141.42.64.125

If you want to make this the only log file for the stream, you can remove the default filter (which, conveniently, has the name default):

event bro_init()
    {
    # Remove the filter called "default".
    Log::remove_filter(Conn::LOG, "default");
    }

An alternate approach to “turning off” a log is to completely disable the stream:

event bro_init()
    {
    Log::disable_stream(Conn::LOG);
    }

If you want to skip only some fields but keep the rest, there is a corresponding exclude filter attribute that you can use instead of include to list only the ones you are not interested in.

A filter can also determine output paths dynamically based on the record being logged. That allows, e.g., to record local and remote connections into separate files. To do this, you define a function that returns the desired path:

function split_log(id: Log::ID, path: string, rec: Conn::Info) : string
    {
    # Return "conn-local" if originator is a local IP, otherwise "conn-remote".
    local lr = Site::is_local_addr(rec$id$orig_h) ? "local" : "remote";
    return fmt("%s-%s", path, lr);
    }

event bro_init()
    {
    local filter: Log::Filter = [$name="conn-split", $path_func=split_log, $include=set("ts", "id.orig_h")];
    Log::add_filter(Conn::LOG, filter);
    }

Running this will now produce two files, local.log and remote.log, with the corresponding entries. One could extend this further for example to log information by subnets or even by IP address. Be careful, however, as it is easy to create many files very quickly ...

While so far we have seen how to customize the columns being logged, you can also control which records are written out by providing a predicate that will be called for each log record:

function http_only(rec: Conn::Info) : bool
    {
    # Record only connections with successfully analyzed HTTP traffic
    return rec$service == "http";
    }

event bro_init()
    {
    local filter: Log::Filter = [$name="http-only", $path="conn-http", $pred=http_only];
    Log::add_filter(Conn::LOG, filter);
    }

This will result in a log file conn-http.log that contains only traffic detected and analyzed as HTTP traffic.

Extending

You can add further fields to a log stream by extending the record type that defines its content. Let’s say we want to add a boolean field is_private to Conn::Info that indicates whether the originator IP address is part of the RFC 1918 space:

# Add a field to the connection log record.
redef record Conn::Info += {
    ## Indicate if the originator of the connection is part of the
    ## "private" address space defined in RFC1918.
    is_private: bool &default=F &log;
};

Now we need to set the field. A connection’s summary is generated at the time its state is removed from memory. We can add another handler at that time that sets our field correctly:

event connection_state_remove(c: connection)
    {
    if ( c$id$orig_h in Site::private_address_space )
        c$conn$is_private = T;
    }

Now conn.log will show a new field is_private of type bool.

Notes:

  • For extending logs this way, one needs a bit of knowledge about how the script that creates the log stream is organizing its state keeping. Most of the standard Bro scripts attach their log state to the connection record where it can then be accessed, just as the c$conn above. For example, the HTTP analysis adds a field http of type HTTP::Info to the connection record. See the script reference for more information.
  • When extending records as shown above, the new fields must always be declared either with a &default value or as &optional. Furthermore, you need to add the &log attribute or otherwise the field won’t appear in the output.

Hooking into the Logging

Sometimes it is helpful to do additional analysis of the information being logged. For these cases, a stream can specify an event that will be generated every time a log record is written to it. All of Bro’s default log streams define such an event. For example, the connection log stream raises the event Conn::log_conn. You could use that for example for flagging when a connection to a specific destination exceeds a certain duration:

redef enum Notice::Type += {
    ## Indicates that a connection remained established longer
    ## than 5 minutes.
    Long_Conn_Found
};

event Conn::log_conn(rec: Conn::Info)
    {
    if ( rec$duration > 5mins )
        NOTICE([$note=Long_Conn_Found,
                $msg=fmt("unusually long conn to %s", rec$id$resp_h),
                $id=rec$id]);
    }

Often, these events can be an alternative to post-processing Bro logs externally with Perl scripts. Much of what such an external script would do later offline, one may instead do directly inside of Bro in real-time.

Rotation

By default, no log rotation occurs, but it’s globally controllable for all filters by redefining the Log::default_rotation_interval option:

redef Log::default_rotation_interval = 1 hr;

Or specifically for certain Log::Filter instances by setting their interv field. Here’s an example of changing just the Conn::LOG stream’s default filter rotation.

event bro_init()
    {
    local f = Log::get_filter(Conn::LOG, "default");
    f$interv = 1 min;
    Log::remove_filter(Conn::LOG, "default");
    Log::add_filter(Conn::LOG, f);
    }

ASCII Writer Configuration

The ASCII writer has a number of options for customizing the format of its output, see base/frameworks/logging/writers/ascii.bro.

Adding Streams

It’s easy to create a new log stream for custom scripts. Here’s an example for the Foo module:

module Foo;

export {
    # Create an ID for our new stream. By convention, this is
    # called "LOG".
    redef enum Log::ID += { LOG };

    # Define the fields. By convention, the type is called "Info".
    type Info: record {
        ts: time     &log;
        id: conn_id  &log;
    };

    # Define a hook event. By convention, this is called
    # "log_<stream>".
    global log_foo: event(rec: Info);

}

# This event should be handled at a higher priority so that when
# users modify your stream later and they do it at priority 0,
# their code runs after this.
event bro_init() &priority=5
    {
    # Create the stream. This also adds a default filter automatically.
    Log::create_stream(Foo::LOG, [$columns=Info, $ev=log_foo]);
    }

You can also add the state to the connection record to make it easily accessible across event handlers:

redef record connection += {
    foo: Info &optional;
    }

Now you can use the Log::write method to output log records and save the logged Foo::Info record into the connection record:

event connection_established(c: connection)
    {
    local rec: Foo::Info = [$ts=network_time(), $id=c$id];
    c$foo = rec;
    Log::write(Foo::LOG, rec);
    }

See the existing scripts for how to work with such a new connection field. A simple example is base/protocols/syslog/main.bro.

When you are developing scripts that add data to the connection record, care must be given to when and how long data is stored. Normally data saved to the connection record will remain there for the duration of the connection and from a practical perspective it’s not uncommon to need to delete that data before the end of the connection.

Copyright 2013, The Bro Project. Last updated on June 15, 2015. Created using Sphinx 1.2.2.