Hooking into the Logging Framework.

doc/user-manual/scripting.rst

@@ -51,7 +51,7 @@ The export section redefines an enumerable constant that describes the type of n
    :linenos:
    :lines: 26-44
 
-The workhorse of the script is contained in the event handler for log_http.  The log_http event is defined as an event-hook in the base/protocols/http/main.bro script and allows scripts to handle a connection as it is being passed to the logging framework. The event handler is passed an HTTP::Info data structure which will be referred to as "rec" in body of the event handler.
+The workhorse of the script is contained in the event handler for ``log_http``.  The ``log_http`` event is defined as an event-hook in the base/protocols/http/main.bro script and allows scripts to handle a connection as it is being passed to the logging framework. The event handler is passed an HTTP::Info data structure which will be referred to as "rec" in body of the event handler.
 
 An if statement is used to check for the existence of a data structure named "md5" nested within the rec data structure.  Bro uses the "$" as a deference operator and as such, and it is employed in this script to check if rec$md5 is present by including the "?" operator within the path.  If the rec data structure includes a nested data structure named "md5", the statement is processed as true and a local variable named "hash_domain" is provisioned and given a format string based on the contents of rec$md5 to produce a valid DNS lookup.  
 
@@ -484,16 +484,20 @@ Now, if we run the new version of the script, instead of generating logging info
 
 While the previous example is a simplistic one, it serves to demonstrate the small pieces of script that need to be in place in order to generate logs.  For example, it's common to call ``Log::create_stream()`` in ``bro_init()`` and while in a live example, determining when to call ``Log::write()`` would likely be done in an event handler, in this case we use ``bro_done()``.  
 
-If you've already spent time with a deployment of Bro, you've likely had the opportunity to view, search through, or manipulate the logs produced by the Logging Framework.  The log output from a default installation of Bro is substantial to say the least, however, there are times in which the way the Logging Framework by default isn't ideal for the situation.  This can range from needing to log more or less data with each call to ``Log::write()`` or even the need to split log files based on arbitrary logic.  In the later case, Filters come into play along with the Logging Framework.  Filters grant a level of customization to Bro's scriptland, allowing the scripter to include or exclude fields in the log and even make alterations to the path of the file in which the logs are being placed.  Each stream, when created, is given a default filter called, not surprisingly, ``default``.  When using the ``default`` filter, every key value pair with the ``&log`` attribute is written to a single file.  For the example we've been using, let's extend it so as to write any factorial which is a factor of 5 to an alternate file, while writing the remaining logs to factor.log.  
+If you've already spent time with a deployment of Bro, you've likely had the opportunity to view, search through, or manipulate the logs produced by the Logging Framework.  The log output from a default installation of Bro is substantial to say the least, however, there are times in which the way the Logging Framework by default isn't ideal for the situation.  This can range from needing to log more or less data with each call to ``Log::write()`` or even the need to split log files based on arbitrary logic.  In the later case, Filters come into play along with the Logging Framework.  Filters grant a level of customization to Bro's scriptland, allowing the script writer to include or exclude fields in the log and even make alterations to the path of the file in which the logs are being placed.  Each stream, when created, is given a default filter called, not surprisingly, ``default``.  When using the ``default`` filter, every key value pair with the ``&log`` attribute is written to a single file.  For the example we've been using, let's extend it so as to write any factorial which is a factor of 5 to an alternate file, while writing the remaining logs to factor.log.  
 
-.. rootedliteralinclude:: ${BRO_SRC_ROOT}/testing/btest/doc/manual/framework_logging_factorial_02.bro
+.. rootedliteralinclude:: ${BRO_SRC_ROOT}/testing/btest/doc/manual/framework_logging_factorial_03.bro
    :language: bro
    :linenos:
    :lines: 43-60
 
 To dynamically alter the file in which a stream writes its logs a filter can specify function returns a string to be used as the filename for the current call to ``Log::write()``. The definition for this function has to take as its parameters a Log::ID called id, a string called path and the appropriate record type for the logs called "rec".  You can see the definition of ``mod5`` used in this example on line one conforms to that requirement.  The function simply returns "factor-mod5" if the factorial is divisible evenly by 5, otherwise, it returns "factor-non5".  In the additional ``bro_init()`` event handler, we define a locally scoped ``Log::Filter`` and assign it a record that defines the ``name`` and ``path_func`` fields.  We then call ``Log::add_filter()`` to add the filter to the ``Factor::LOG`` Log::ID and call ``Log::remove_filter()`` to remove the ``default`` filter for Factor::LOG.  Had we not removed the ``default`` filter, we'd have ended up with three log files:  factor-mod5.log with all the factorials that are a factors of 5, factor-non5.log with the factorials that are not factors of 5, and factor.log which would have included all factorials.  
 
+The ability of Bro to generate easily customizable and extensible logs which remain easily parsable is a big part of the reason Bro has gained a large measure of respect.  In fact, it's difficult at times to think of something that Bro doesn't log and as such, it is often advantageous for analysts and systems architects to instead hook into the logging framework to be able to perform custom actions based upon the data being sent to the Logging Frame.  To that end, every default log stream in Bro generates a custom event that can be handled by anyone wishing to act upon the data being sent to the stream.  By convention these events are usually in the format ``log_x`` where x is the name of the logging stream; as such the event raised for every log sent to the Logging Framework by the HTTP parser would be ``log_http``.  In fact, we've already seen a script handle the ``log_http`` event when we broke down how the ``detect-MHR.bro`` script worked.  In that example, as each log entry was sent to the logging framework, post-processing was taking place in the ``log_http`` event.  Instead of using an external script to parse the ``http.log`` file and do post-processing for the entry, post-processing can be done in real time in Bro.  
 
+Telling Bro to raise an event in your own Logging stream is as simple as exporting that event name and then adding that event in the call to ``Log::create_stream``.  Going back to our simple example of logging the factorial of an integer, we add ``log_factor`` to the ``export`` block and define the value to be passed to it, in this case the ``Factor::Info`` record.  We then list the ``log_factor`` function as the ``$ev`` field in the call to ``Log::create_stream``
 
-
+.. rootedliteralinclude:: ${BRO_SRC_ROOT}/testing/btest/doc/manual/framework_logging_factorial_04.bro
-
+   :language: bro
+   :linenos:
+   :lines: 4-62

testing/btest/doc/manual/framework_logging_factorial_04.bro

@@ -0,0 +1,62 @@
+# @TEST-EXEC: bro %INPUT
+# @TEST-EXEC: btest-diff factor-mod5.log
+# @TEST-EXEC: btest-diff factor-non5.log
+
+module Factor;
+
+export {
+    redef enum Log::ID += { LOG };
+
+    type Info: record {
+        num:           count &log;
+        factorial_num: count &log;
+        };
+    
+    global log_factor: event(rec: Info);
+    }
+
+function factorial(n: count): count
+    {
+    if ( n == 0 )
+        {
+        return 1;
+        }
+    else
+        {
+        return ( n * factorial(n - 1) );
+        }
+    }
+
+event bro_init()
+    {
+    Log::create_stream(LOG, [$columns=Info, $ev=log_factorial]);
+    }
+
+event bro_done()
+    {
+    local numbers: vector of count = vector(1, 2, 3, 4, 5, 6, 7, 8, 9, 10);    
+    for ( n in numbers )
+        {
+        Log::write( Factor::LOG, [$num=numbers[n],
+                                  $factorial_num=factorial(numbers[n])]);
+        }
+    }
+
+function mod5(id: Log::ID, path: string, rec: Factor::Info) : string    
+    {
+    if ( rec$factorial_num % 5 == 0 )
+        {
+        return "factor-mod5";
+        }
+    else
+        {
+        return "factor-non5";
+        }
+    }
+
+event bro_init()
+    {
+    local filter: Log::Filter = [$name="split-mod5s", $path_func=mod5];
+    Log::add_filter(Factor::LOG, filter);
+    Log::remove_filter(Factor::LOG, "default");
+    }