Extending the log writer DoInit() API.

We now pass in a Info struct that contains:

    - the path name (as before)
    - the rotation interval
    - the log_rotate_base_time in seconds
    - a table of key/value pairs with further configuration options.

To fill the table, log filters have a new field "config: table[string]
of strings". This gives a way to pass arbitrary values from
script-land to writers. Interpretation is left up to the writer.

Also splits calc_next_rotate() into two functions, one of which is
thread-safe and can be used with the log_rotate_base_time value from
DoInit().

Includes also updates to the None writer:

    - It gets its own script writers/none.bro.

    - New bool option LogNone::debug to enable debug output. It then
      prints out all the values passed to DoInit(). That's used by a
      btest test to ensure the new DoInit() values are right.

    - Fixed a bug that prevented Bro from terminating..

(scripts.base.frameworks.logging.rotate-custom currently fails.
Haven't yet investigated why.)

scripts/base/frameworks/logging/__load__.bro

@@ -2,3 +2,4 @@
 @load ./postprocessors
 @load ./writers/ascii
 @load ./writers/dataseries
+@load ./writers/none

scripts/base/frameworks/logging/main.bro

@@ -138,6 +138,10 @@ export {
 		## Callback function to trigger for rotated files. If not set, the
 		## default comes out of :bro:id:`Log::default_rotation_postprocessors`.
 		postprocessor: function(info: RotationInfo) : bool &optional;
+
+		## A key/value table that will be passed on the writer.
+                ## Interpretation of the values is left to the writer.
+                config: table[string] of string &default=table();
 	};
 
 	## Sentinel value for indicating that a filter was not found when looked up.
@@ -327,6 +331,8 @@ function __default_rotation_postprocessor(info: RotationInfo) : bool
 	{
 	if ( info$writer in default_rotation_postprocessors )
 		return default_rotation_postprocessors[info$writer](info);
+
+	return F;
 	}
 
 function default_path_func(id: ID, path: string, rec: any) : string

scripts/base/frameworks/logging/writers/none.bro

@@ -0,0 +1,17 @@
+##! Interface for the None log writer. Thiis writer is mainly for debugging.
+
+module LogNone;
+
+export {
+	## If true, output some debugging output that can be useful for unit
+        ##testing the logging framework.
+	const debug = F &redef;
+}
+
+function default_rotation_postprocessor_func(info: Log::RotationInfo) : bool
+	{
+	return T;
+	}
+
+redef Log::default_rotation_postprocessors += { [Log::WRITER_NONE] = default_rotation_postprocessor_func };
+

src/File.cc

@@ -572,8 +572,9 @@ void BroFile::InstallRotateTimer()
 			const char* base_time = log_rotate_base_time ?
 				log_rotate_base_time->AsString()->CheckString() : 0;
 
+			double base = parse_rotate_base_time(base_time);
 			double delta_t =
-				calc_next_rotate(rotate_interval, base_time);
+				calc_next_rotate(network_time, rotate_interval, base);
 			rotate_timer = new RotateTimer(network_time + delta_t,
 							this, true);
 			}

src/Val.cc

@@ -1651,6 +1651,7 @@ int TableVal::RemoveFrom(Val* val) const
 	while ( (v = tbl->NextEntry(k, c)) )
 		{
 		Val* index = RecoverIndex(k);
+
 		Unref(index);
 		Unref(t->Delete(k));
 		delete k;

src/bro.bif

@@ -4814,7 +4814,9 @@ function calc_next_rotate%(i: interval%) : interval
 	%{
 	const char* base_time = log_rotate_base_time ?
 		log_rotate_base_time->AsString()->CheckString() : 0;
-	return new Val(calc_next_rotate(i, base_time), TYPE_INTERVAL);
+	
+	double base = parse_rotate_base_time(base_time);
+	return new Val(calc_next_rotate(network_time, i, base), TYPE_INTERVAL);
 	%}
 
 ## Returns the size of a given file.

src/logging.bif

@@ -81,3 +81,9 @@ const extent_size: count;
 const dump_schema: bool;
 const use_integer_for_time: bool;
 const num_threads: count;
+
+# Options for the None writer.
+
+module LogNone;
+
+const debug: bool;

src/logging/Manager.cc

@@ -51,6 +51,7 @@ struct Manager::Filter {
 	string path;
 	Val* path_val;
 	EnumVal* writer;
+	TableVal* config;
 	bool local;
 	bool remote;
 	double interval;
@@ -519,6 +520,7 @@ bool Manager::AddFilter(EnumVal* id, RecordVal* fval)
 	Val* log_remote = fval->LookupWithDefault(rtype->FieldOffset("log_remote"));
 	Val* interv = fval->LookupWithDefault(rtype->FieldOffset("interv"));
 	Val* postprocessor = fval->LookupWithDefault(rtype->FieldOffset("postprocessor"));
+	Val* config = fval->LookupWithDefault(rtype->FieldOffset("config"));
 
 	Filter* filter = new Filter;
 	filter->name = name->AsString()->CheckString();
@@ -530,6 +532,7 @@ bool Manager::AddFilter(EnumVal* id, RecordVal* fval)
 	filter->remote = log_remote->AsBool();
 	filter->interval = interv->AsInterval();
 	filter->postprocessor = postprocessor ? postprocessor->AsFunc() : 0;
+	filter->config = config->Ref()->AsTableVal();
 
 	Unref(name);
 	Unref(pred);
@@ -538,6 +541,7 @@ bool Manager::AddFilter(EnumVal* id, RecordVal* fval)
 	Unref(log_remote);
 	Unref(interv);
 	Unref(postprocessor);
+	Unref(config);
 
 	// Build the list of fields that the filter wants included, including
 	// potentially rolling out fields.
@@ -768,6 +772,22 @@ bool Manager::Write(EnumVal* id, RecordVal* columns)
 			WriterBackend::WriterInfo info;
 			info.path = path;
 
+			HashKey* k;
+			IterCookie* c = filter->config->AsTable()->InitForIteration();
+
+			TableEntryVal* v;
+			while ( (v = filter->config->AsTable()->NextEntry(k, c)) )
+				{
+				ListVal* index = filter->config->RecoverIndex(k);
+				string key = index->Index(0)->AsString()->CheckString();
+				string value = v->Value()->AsString()->CheckString();
+				info.config.insert(std::make_pair(key, value));
+				Unref(index);
+				delete k;
+				}
+
+			// CreateWriter() will set the other fields in info.
+
 			writer = CreateWriter(stream->id, filter->writer,
 					      info, filter->num_fields,
 					      arg_fields, filter->local, filter->remote);
@@ -777,7 +797,6 @@ bool Manager::Write(EnumVal* id, RecordVal* columns)
 				Unref(columns);
 				return false;
 				}
-
 			}
 
 		// Alright, can do the write now.
@@ -977,8 +996,6 @@ WriterFrontend* Manager::CreateWriter(EnumVal* id, EnumVal* writer, const Writer
 	WriterFrontend* writer_obj = new WriterFrontend(id, writer, local, remote);
 	assert(writer_obj);
 
-	writer_obj->Init(info, num_fields, fields);
-
 	WriterInfo* winfo = new WriterInfo;
 	winfo->type = writer->Ref()->AsEnumVal();
 	winfo->writer = writer_obj;
@@ -1020,6 +1037,16 @@ WriterFrontend* Manager::CreateWriter(EnumVal* id, EnumVal* writer, const Writer
 		Stream::WriterMap::value_type(Stream::WriterPathPair(writer->AsEnum(), info.path),
 		winfo));
 
+	// Still need to set the WriterInfo's rotation parameters, which we
+	// computed above.
+	const char* base_time = log_rotate_base_time ?
+		log_rotate_base_time->AsString()->CheckString() : 0;
+
+	winfo->info.rotation_interval = winfo->interval;
+	winfo->info.rotation_base = parse_rotate_base_time(base_time);
+
+	writer_obj->Init(winfo->info, num_fields, fields);
+
 	return writer_obj;
 	}
 
@@ -1223,8 +1250,9 @@ void Manager::InstallRotationTimer(WriterInfo* winfo)
 			const char* base_time = log_rotate_base_time ?
 				log_rotate_base_time->AsString()->CheckString() : 0;
 
+			double base = parse_rotate_base_time(base_time);
 			double delta_t =
-				calc_next_rotate(rotation_interval, base_time);
+				calc_next_rotate(network_time, rotation_interval, base);
 
 			winfo->rotation_timer =
 				new RotationTimer(network_time + delta_t, winfo, true);

src/logging/WriterBackend.cc

@@ -63,12 +63,48 @@ using namespace logging;
 
 bool WriterBackend::WriterInfo::Read(SerializationFormat* fmt)
 	{
-	return fmt->Read(&path, "path");
+	int size;
+
+	if ( ! (fmt->Read(&path, "path") &&
+		fmt->Read(&rotation_base, "rotation_base") &&
+		fmt->Read(&rotation_interval, "rotation_interval") &&
+		fmt->Read(&size, "config_size")) )
+		return false;
+
+	config.clear();
+
+	while ( size )
+		{
+		string value;
+		string key;
+
+		if ( ! (fmt->Read(&value, "config-value") && fmt->Read(&value, "config-key")) )
+			return false;
+
+		config.insert(std::make_pair(value, key));
+		}
+
+	return true;
 	}
 
+
 bool WriterBackend::WriterInfo::Write(SerializationFormat* fmt) const
 	{
-	return fmt->Write(path, "path");
+	int size = config.size();
+
+	if ( ! (fmt->Write(path, "path") &&
+		fmt->Write(rotation_base, "rotation_base") &&
+		fmt->Write(rotation_interval, "rotation_interval") &&
+		fmt->Write(size, "config_size")) )
+		return false;
+
+	for ( config_map::const_iterator i = config.begin(); i != config.end(); ++i ) 
+		{
+		if ( ! (fmt->Write(i->first, "config-value") && fmt->Write(i->second, "config-key")) )
+			return false;
+		}
+
+	return true;
 	}
 
 WriterBackend::WriterBackend(WriterFrontend* arg_frontend) : MsgThread()

src/logging/WriterBackend.h

@@ -48,6 +48,8 @@ public:
 	 */
 	struct WriterInfo
 		{
+		typedef std::map<string, string> config_map;
+
 		/**
 		 * A string left to the interpretation of the writer
 		 * implementation; it corresponds to the value configured on
@@ -55,6 +57,22 @@ public:
 		 */
 		string path;
 
+		/**
+		 * The rotation interval as configured for this writer.
+		 */
+		double rotation_interval;
+
+		/**
+		 * The parsed value of log_rotate_base_time in seconds.
+		 */
+		double rotation_base;
+
+		/**
+		 * A map of key/value pairs corresponding to the relevant
+		 * filter's "config" table.
+		 */
+		std::map<string, string> config;
+
 		private:
 		friend class ::RemoteSerializer;
 

src/logging/writers/None.cc

@@ -1,9 +1,36 @@
 
 #include "None.h"
+#include "NetVar.h"
 
 using namespace logging;
 using namespace writer;
 
+bool None::DoInit(const WriterInfo& info, int num_fields,
+	    const threading::Field* const * fields)
+	{
+	if ( BifConst::LogNone::debug )
+		{
+		std::cout << "[logging::writer::None]" << std::endl;
+		std::cout << "  path=" << info.path << std::endl;
+		std::cout << "  rotation_interval=" << info.rotation_interval << std::endl;
+		std::cout << "  rotation_base=" << info.rotation_base << std::endl;
+
+		for ( std::map<string,string>::const_iterator i = info.config.begin(); i != info.config.end(); i++ )
+			std::cout << "  config[" << i->first << "] = " << i->second << std::endl;
+
+		for ( int i = 0; i < num_fields; i++ )
+			{
+			const threading::Field* field = fields[i];
+			std::cout << "  field " << field->name << ": "
+				  << type_name(field->type) << std::endl;
+			}
+
+		std::cout << std::endl;
+		}
+
+	return true;
+	}
+
 bool None::DoRotate(string rotated_path, double open, double close, bool terminating)
 	{
 	if ( ! FinishedRotation(string("/dev/null"), Info().path, open, close, terminating))

src/logging/writers/None.h

@@ -19,7 +19,7 @@ public:
 
 protected:
 	virtual bool DoInit(const WriterInfo& info, int num_fields,
-			    const threading::Field* const * fields)	{ return true; }
+			    const threading::Field* const * fields);
 
 	virtual bool DoWrite(int num_fields, const threading::Field* const* fields,
 			     threading::Value** vals)	{ return true; }
@@ -27,7 +27,7 @@ protected:
 	virtual bool DoRotate(string rotated_path, double open,
 			      double close, bool terminating);
 	virtual bool DoFlush()	{ return true; }
-	virtual bool DoFinish()	{ return true; }
+	virtual bool DoFinish()	{ WriterBackend::DoFinish(); return true; }
 };
 
 }

src/util.cc

@@ -1082,18 +1082,8 @@ const char* log_file_name(const char* tag)
 	return fmt("%s.%s", tag, (env ? env : "log"));
 	}
 
-double calc_next_rotate(double interval, const char* rotate_base_time)
+double parse_rotate_base_time(const char* rotate_base_time)
 	{
-	double current = network_time;
-
-	// Calculate start of day.
-	time_t teatime = time_t(current);
-
-	struct tm t;
-	t = *localtime(&teatime);
-	t.tm_hour = t.tm_min = t.tm_sec = 0;
-	double startofday = mktime(&t);
-
 	double base = -1;
 
 	if ( rotate_base_time && rotate_base_time[0] != '\0' )
@@ -1105,6 +1095,19 @@ double calc_next_rotate(double interval, const char* rotate_base_time)
 			base = t.tm_min * 60 + t.tm_hour * 60 * 60;
 		}
 
+	return base;
+	}
+
+double calc_next_rotate(double current, double interval, double base)
+	{
+	// Calculate start of day.
+	time_t teatime = time_t(current);
+
+	struct tm t;
+	t = *localtime_r(&teatime, &t);
+	t.tm_hour = t.tm_min = t.tm_sec = 0;
+	double startofday = mktime(&t);
+
 	if ( base < 0 )
 		// No base time given. To get nice timestamps, we round
 		// the time up to the next multiple of the rotation interval.

src/util.h

@@ -193,9 +193,22 @@ extern FILE* rotate_file(const char* name, RecordVal* rotate_info);
 // This mimics the script-level function with the same name.
 const char* log_file_name(const char* tag);
 
+// Parse a time string of the form "HH:MM" (as used for the rotation base
+// time) into a double representing the number of seconds. Returns -1 if the
+// string cannot be parsed. The function's result is intended to be used with
+// calc_next_rotate().
+//
+// This function is not thread-safe.
+double parse_rotate_base_time(const char* rotate_base_time);
+
 // Calculate the duration until the next time a file is to be rotated, based
-// on the given rotate_interval and rotate_base_time.
-double calc_next_rotate(double rotate_interval, const char* rotate_base_time);
+// on the given rotate_interval and rotate_base_time. 'current' the the
+// current time to be used as base, 'rotate_interval' the rotation interval,
+// and 'base' the value returned by parse_rotate_base_time(). For the latter,
+// if the function returned -1, that's fine, calc_next_rotate() handles that.
+//
+// This function is thread-safe.
+double calc_next_rotate(double current, double rotate_interval, double base);
 
 // Terminates processing gracefully, similar to pressing CTRL-C.
 void terminate_processing();

testing/btest/Baseline/scripts.base.frameworks.logging.none-debug/output

@@ -0,0 +1,12 @@
+[logging::writer::None]
+  path=ssh
+  rotation_interval=3600
+  rotation_base=300
+  config[foo] = bar
+  config[foo2] = bar2
+  field id.orig_p: port
+  field id.resp_h: addr
+  field id.resp_p: port
+  field status: string
+  field country: string
+

testing/btest/scripts/base/frameworks/logging/none-debug.bro

@@ -0,0 +1,37 @@
+#
+# @TEST-EXEC: bro -b %INPUT >output
+# @TEST-EXEC: btest-diff output
+
+redef Log::default_writer = Log::WRITER_NONE;
+redef LogNone::debug = T;
+redef Log::default_rotation_interval= 1hr;
+redef log_rotate_base_time = "00:05";
+
+module SSH;
+
+export {
+	redef enum Log::ID += { LOG };
+
+	type Log: record {
+		t: time;
+		id: conn_id; # Will be rolled out into individual columns.
+		status: string &optional;
+		country: string &default="unknown";
+	} &log;
+}
+
+event bro_init()
+{
+        local config: table[string] of string;
+        config["foo"]="bar";
+        config["foo2"]="bar2";
+
+	local cid = [$orig_h=1.2.3.4, $orig_p=1234/tcp, $resp_h=2.3.4.5, $resp_p=80/tcp];
+
+	Log::create_stream(SSH::LOG, [$columns=Log]);
+
+	Log::remove_default_filter(SSH::LOG);
+	Log::add_filter(SSH::LOG, [$name="f1", $exclude=set("t", "id.orig_h"), $config=config]);
+	Log::write(SSH::LOG, [$t=network_time(), $id=cid, $status="success"]);
+}
+