========================== Customizing Bro's Logging ========================== .. rst-class:: opening 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. .. contents:: 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, :doc:`scripts/base/protocols/conn/main`. It defines a record :bro:type:`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 :bro:type:`Conn::Info` to the logging framework's :bro:id:`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 new 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: .. code:: bro 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. :bro:enum:`Conn::LOG` is converted into ``conn``, :bro:enum:`PacketFilter::LOG` is converted into ``packet_filter``, and :bro:enum:`Notice::POLICY_LOG` is converted into ``notice_policy``. ``include`` A set limiting the fields to the ones given. The names correspond to those in the :bro:type:`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``): .. code:: bro 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: .. code:: bro 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: .. code:: bro 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 ... .. sidebar:: A More Generic Path Function The ``split_log`` method has one draw-back: it can be used only with the :bro:enum:`Conn::LOG` stream as the record type is hardcoded into its argument list. However, Bro allows to do a more generic variant: .. code:: bro function split_log(id: Log::ID, path: string, rec: record { id: conn_id; } ) : string { return Site::is_local_addr(rec$id$orig_h) ? "local" : "remote"; } This function can be used with all log streams that have records containing an ``id: conn_id`` field. 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: .. code:: bro 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 results 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 :bro:type:`Conn::Info` that indicates whether the originator IP address is part of the :rfc:`1918` space: .. code:: bro # 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: .. code:: bro 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 :bro:type:`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 :bro:type:`HTTP::Info` to the :bro:type:`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 :bro:id:`Conn::log_conn`. You could use that for example for flagging when a connection to specific destination exceeds a certain duration: .. code:: bro 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("unsually 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 :bro:id:`Log::default_rotation_interval` option: .. code:: bro redef Log::default_rotation_interval = 1 hr; Or specifically for certain :bro:type:`Log::Filter` instances by setting their ``interv`` field. Here's an example of changing just the :bro:enum:`Conn::LOG` stream's default filter rotation. .. code:: bro 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 :doc:`scripts/base/frameworks/logging/writers/ascii`. Adding Streams ============== It's easy to create a new log stream for custom scripts. Here's an example for the ``Foo`` module: .. code:: bro module Foo; export { # Create an ID for the 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_". 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 :bro:type:`connection` record to make it easily accessible across event handlers: .. code:: bro redef record connection += { foo: Info &optional; } Now you can use the :bro:id:`Log::write` method to output log records and save the logged ``Foo::Info`` record into the connection record: .. code:: bro 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 :doc:`scripts/base/protocols/syslog/main`. When you are developing scripts that add data to the :bro:type:`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.