Converting a Bro Script to A New Stream

Zeek
1

I have a short bro script that I wrote that hooks the DNS log
(http://www.bro-ids.org/documentation/logging.html#hooking-into-the-logging).
Each time a DNS::log_dns event fires, if a specific IP is in
rec$answers, the script prints out rec$ts, rec$uid, rec$id$orig_h, and
rec$query.

I want the entries from the script to go to their own log, though. I
am struggling to figure out how to make that work. Based on the
documentation for logging, it looks like I'd need to define a new
Stream to create a new log file.
(http://www.bro-ids.org/documentation/logging.html#adding-streams)

Here's my original script that hooks the DNS logs:

event DNS::log_dns(rec: DNS::Info)
    {
        for( i in rec$answers )
                if( "1.2.3.4" in rec$answers[i] )
                        print fmt("%s %s %s %s", rec$ts, rec$uid,
rec$id$orig_h, rec$query);
    }

To make this go to its own log, I tried this:

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;
        uid: string &log;
        orig_ip: string &log;
        query: string &log;
    };

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

}

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

# 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]);
    }

event DNS::log_dns(rec: DNS::Info)
    {
        for( i in rec$answers )
                if( "1.2.3.4" in rec$answers[i] )
                        local rec: Foo::Info = [ $ts=rec$ts,
$uid=rec$uid, $orig_h=rec$id$orig_h, $query=rec$query];
                        rec$foo = rec;
                        Log::write(Foo::LOG, rec);
    }

I get the errors:

error in ./test.bro, line 22: unknown identifier (Foo::rec)
error in ./test.bro, line 35 and ./test.bro, line 39: already defined (Foo::rec)

I am new to writing Bro scripts. Any pointers on what I'm doing wrong?

-Chris

2

I was able to make some progress. This script does what I want, but
there are still some problems.

module Foo;

export {
    redef enum Log::ID += { LOG };

    type Info: record {
        ts: time &log;
        uid: string &log;
        orig_ip: addr &log;
        query: string &log;
    };

}

event bro_init() &priority=5
    {
    Log::create_stream(Foo::LOG, [$columns=Info]);
    }

event DNS::log_dns(rec: DNS::Info)
    {
        if(rec$qtype_name == "A")
                if( |rec$answers| > 0 )
                        for( i in rec$answers )
                                if( "1.2.3.4" in rec$answers[i] )
                                        Log::write(Foo::LOG, [
$ts=rec$ts, $uid=rec$uid, $orig_ip=rec$id$orig_h, $query=rec$query]);
    }

I get the log I want, with the data I expect.

The problem is, I get thousands of entries in reporter.log that say:

"Reporter::ERROR field value missing [Foo::rec$qtype_name]"

And I get hundreds of entries that say:

"Reporter::ERROR field value missing [Foo::rec$answers]"

I think I'm getting these error messages because log_dns fires, but
rec is empty or doesn't exist. How can I check my theory? If that is
truly the case, is there a better way to write the initial logic in
event DNS::log_dns(rec: DNS::Info) that would break out of that
function if rec does not exist? I thought that checking for DNS
answers and then checking to make sure that there is a positive number
of answers would help to eliminate the errors I see in reporter.log,
but it doesn't.

-Chris

3

This is really simple.. see some of the examples here:

http://blog.bro-ids.org/2012/02/filtering-logs-with-bro.html

You want to use Log:add_filter with a pred function that does the
filtering. like this example:

Log::add_filter(HTTP::LOG, [$name = "http-executables",
                             $path = "http_exe",
                             $pred(rec: HTTP::Info) = { return rec?$mime_type && rec$mime_type == "application/x-dosexec"; }]);

4

I don't think you need that little chunk of code I left above. We do that in many base scripts as a way of hiding protocol specific information within the connection record. There is no existing record type named "rec" though and it doesn't look like you need to hide this information anywhere since you are deriving all of your log directly from data in the DNS::log_dns event.

There is a better way to do this though and it was something we specifically considered in the logging framework. Here's a log filter you can run that will give you the log you want…

event bro_init()
  {
  local filter: Log::Filter = [
    $name="only-1.2.3.4",
    $path="foo",
    $pred(rec: DNS::Info) = {
      if ( rec?$qtype_name && rec?$answers &&
           rec$qtype_name == "A" )
        {
        for ( i in rec$answers )
          if ( "1.2.3.4" in rec$answers[i] )
            return T;
        }
      return F;
    },
    $include=set("ts", "uid", "id.orig_h", "query")];
  Log::add_filter(DNS::LOG, filter);
  }

5

Thanks, Seth. This works great, and it gives me better insight into
how to write my own bro scripts.

Now, I feel like my follow up question has an obvious answer, but I'm
just not seeing it --

Let's say I want to also email the alert, in addition to logging it.
I've added a notice statement, an attempted to redefine
Notice::mail_dest and Notice::policy as outlined in the bro docs:
http://www.bro-ids.org/documentation/notice.html

When I run the script, though, I don't receive an email. I know that
bro's email is working, because I am receiving hourly reports. What
am I missing?

Attached the script, but if it doesn't post to the list, I'll follow
up this post with the code.

-Chris

bro-script.txt (1.25 KB)

6

Looks like the code didn't post.

For the benefit of the mailing list, this is what the script looks like:

export {
        redef Notice::mail_dest = "email_address@inet.com";

        redef enum Notice::Type += {
                Foo,
        };

        redef Notice::emailed_types += {
                Foo,
        };
}

redef Notice::policy += {
  [$pred(n: Notice::Info) = {
     return n$note == Foo;
   },
   $action = Notice::ACTION_EMAIL]
  };

event bro_init()
        {
        local filter: Log::Filter = [
                $name="poison_hits",
                $path="poison_hits",
                $pred(rec: DNS::Info) = {
                        if ( rec?$qtype_name && rec?$answers &&
rec$qtype_name == "A" )
                                {
                                for ( i in rec$answers )
                                        if ( "1.2.3.4" in rec$answers[i] )
                                                {
                                                NOTICE([$note=Foo,
$msg="Foo detected."]);
                                                return T;
                                                }
                                }
                        return F;
                },
                $include=set("ts", "uid", "id.orig_h", "query")];
        Log::add_filter(DNS::LOG, filter);
        }

7

I've got a general question around this idea. When is it best to
create a log filter vs. creating a log file with just the information
you want in it vs. adding an additional field to a existing log?

I'm curious becase I would have approached this the same way (an
output log for the data I was interested in), but you mentioned that
for this case the filter was the better way to do this.

Any insight would be appreciated.

Thanks!

8

In this case, the log being created was a strict subset of the existing log. I definitely wouldn't bother creating a completely new log just to restrict the output columns since we have that supported as a feature of the logging framework.

I guess in most cases where you are just going to end up outputting all of the same fields from an existing log I wouldn't bother creating a new log stream. There are some cases where it just comes down to a style decision if you are adding extra fields but you are also including several fields from an existing log whether or not you create a new log stream.

A good rule of thumb is if your first thought is to handle a log stream event (i.e. DNS::log_dns, HTTP::log_http, etc) to fill out your log file, you should probably use a filter.

  .Seth

9

One additional note. Foo is showing up in my notice.log:

#separator \x09
#set_separator ,
#empty_field (empty)
#unset_field -
#path notice
#fields ts uid id.orig_h id.orig_p id.resp_h id.resp_p proto note msg sub src dst p n peer_descr actions policy_items suppress_for dropped remote_location.country_code remote_location.region remote_location.city remote_location.latitude remote_location.longitude metric_index.host metric_index.str metric_index.network
#types time string addr port addr port enum enum string string addr addr port count string table[enum] table[count] interval bool string string string double double addr string subnet
1345028672.101773 - - - - - - Foo Foo
detected. - - - - - bro Notice::ACTION_LOG,Notice::ACTION_EMAIL 7,6 3600.000000 F - - - - - - - -

So, the notice framework seems to be doing something.

-Chris

10

Foo shows up notice_policy.log too:

#separator \x09
#set_separator ,
#empty_field (empty)
#unset_field -
#path notice_policy
#fields position priority action pred halt suppress_for
#types count count enum func bool interval
0 10 Notice::ACTION_ADD_GEODATA anonymous-function\x0a{ \x0areturn
((Notice::n$note in Notice::lookup_location_types));\x0a} F -
1 9 Notice::ACTION_NO_SUPPRESS anonymous-function\x0a{ \x0areturn
((Notice::n$note in Notice::not_suppressed_types));\x0a} F -
2 9 Notice::ACTION_NONE anonymous-function\x0a{ \x0areturn
((Notice::n$note in Notice::ignored_types));\x0a} T -
3 8 Notice::ACTION_NONE anonymous-function\x0a{ \x0aif (Notice::n$note
in Notice::type_suppression_intervals) \x0a\x09{
\x0a\x09Notice::n$suppress_for =
Notice::type_suppression_intervals[Notice::n$note];\x0a\x09return
(T);\x0a\x09}\x0a\x0areturn (F);\x0a} F -
4 8 Notice::ACTION_ALARM anonymous-function\x0a{ \x0areturn
((Notice::n$note in Notice::alarmed_types));\x0a} F -
5 8 Notice::ACTION_EMAIL anonymous-function\x0a{ \x0areturn
((Notice::n$note in Notice::emailed_types));\x0a} F -
6 5 Notice::ACTION_EMAIL anonymous-function\x0a{ \x0areturn (n$note ==
Foo);\x0a} F -
7 0 Notice::ACTION_LOG - F -