Ascii reader error changes - fix small bugs

The changes are now a bit more succinct with less code changes required.
Behavior is tested a little bit more thoroughly and a memory problem
when reading incomplete lines was fixed. ReadHeader also always directly
returns if header reading failed.

Error messages now are back to what they were before the change, if the
new behavior is not used.

I also tweaked the documentation text a bit.

scripts/base/frameworks/input/readers/ascii.bro

@@ -19,16 +19,32 @@ export {
 	## String to use for an unset &optional field.
 	const unset_field = Input::unset_field &redef;
 
-	## Choose if the ascii input reader should globally
+	## Fail on invalid lines. If set to false, the ascii
-	## fail on invalid lines and continue parsing afterward.
+	## input reader will jump over invalid lines, reporting
-	## Individual readers can use a different value.
+	## warnings in reporter.log. If set to true, errors in
+	## input lines will be handled as fatal errors for the
+	## reader thread; reading will abort immediately and
+	## an error will be logged to reporter.log.
+	## Invidivual readers can use a different value using
+	## the $config table.
+	## fail_on_invalid_lines = T was the default behavior
+	## untill Bro 2.5.
 	const fail_on_invalid_lines = F &redef;
 
-	## Set to true if you would like the old behavior of the 
+	## Fail on file read problems. If set to true, the ascii
-	## ascii reader where the reader thread would die if any file 
+	## input reader will fail when encountering any problems
-	## errors occur (like permissions problems or file missing). 
+	## while reading a file different from invalid lines.
-	## The default behavior is to continue attempting to open and read
+	## Examples fur such problems are permission problems, or
-	## the file even in light of problems.
+	## missing files.
-	## Individual readers can use a different value.
+	## When set to false, these problems will be ignored. This
+	## has an especially big effect for the REREAD mode, which will
+	## seamlessly recover from read errors when a file is
+	## only temporarily inaccessible. For MANUAL or STREAM files,
+	## errors will most likely still be fatal since no automatic
+	## re-reading of the file is attempted.
+	## Invidivual readers can use a different value using
+	## the $config table.
+	## fail_on_file_problem = T was the default behavior
+	## untill Bro 2.5.
 	const fail_on_file_problem = F &redef;
 }

src/input/readers/ascii/Ascii.cc

@@ -61,7 +61,7 @@ void Ascii::DoClose()
 
 bool Ascii::DoInit(const ReaderInfo& info, int num_fields, const Field* const* fields)
 	{
-	is_failed = false;
+	suppress_warnings = false;
 
 	separator.assign( (const char*) BifConst::InputAscii::separator->Bytes(),
 	                 BifConst::InputAscii::separator->Len());
@@ -109,43 +109,48 @@ bool Ascii::DoInit(const ReaderInfo& info, int num_fields, const Field* const* f
 	formatter::Ascii::SeparatorInfo sep_info(separator, set_separator, unset_field, empty_field);
 	formatter = unique_ptr<threading::formatter::Formatter>(new formatter::Ascii(this, sep_info));
 
-	DoUpdate();
+	return DoUpdate();
-
-	return true;
 	}
 
-void Ascii::FailWarn(bool is_error, const char *msg)
+void Ascii::FailWarn(bool is_error, const char *msg, bool suppress_future)
 	{
 	if ( is_error )
 		Error(msg);
 	else
-		Warning(msg);
+		{
+		// suppress error message when we are already in error mode.
+		// There is no reason to repeat it every second.
+		if ( ! suppress_warnings )
+			Warning(msg);
+
+		if ( suppress_future )
+			suppress_warnings = true;
+		}
 	}
 
 bool Ascii::OpenFile()
 	{
-	if ( file.is_open() && ! is_failed )
+	if ( file.is_open() )
 		return true;
 
 	file.open(Info().source);
+
 	if ( ! file.is_open() )
 		{
-		if ( ! is_failed )
+		FailWarn(fail_on_file_problem, Fmt("Init: cannot open %s", Info().source), true);
-			FailWarn(fail_on_file_problem, Fmt("Init: cannot open %s", Info().source));
+
-		is_failed = true;
+		return ! fail_on_file_problem;
-		return !fail_on_file_problem;
 		}
 
 	if ( ReadHeader(false) == false )
 		{
-		if ( ! is_failed )
+		FailWarn(fail_on_file_problem, Fmt("Init: cannot open %s; problem reading file header", Info().source), true);
-			FailWarn(fail_on_file_problem, Fmt("Init: cannot open %s; headers are incorrect", Info().source));
+
 		file.close();
-		is_failed = true;
+		return ! fail_on_file_problem;
-		return !fail_on_file_problem;
 		}
 
-	is_failed = false;
+	suppress_warnings = false;
 	return true;
 	}
 
@@ -158,7 +163,11 @@ bool Ascii::ReadHeader(bool useCached)
 	if ( ! useCached )
 		{
 		if ( ! GetLine(line) )
+			{
+			FailWarn(fail_on_file_problem, Fmt("Could not read input data file %s; first line could not be read",
+							 Info().source), true);
 			return false;
+			}
 
 		headerline = line;
 		}
@@ -198,12 +207,10 @@ bool Ascii::ReadHeader(bool useCached)
 				continue;
 				}
 
-			if ( ! is_failed )
+			FailWarn(fail_on_file_problem, Fmt("Did not find requested field %s in input data file %s.",
-				FailWarn(fail_on_file_problem, Fmt("Did not find requested field %s in input data file %s.",
+							 field->name, Info().source), true);
-				         field->name, Info().source));
 
-			is_failed = true;
+			return false;
-			return !fail_on_file_problem;
 			}
 
 		FieldMapping f(field->name, field->type, field->subtype, ifields[field->name]);
@@ -213,12 +220,10 @@ bool Ascii::ReadHeader(bool useCached)
 			map<string, uint32_t>::iterator fit2 = ifields.find(field->secondary_name);
 			if ( fit2 == ifields.end() )
 				{
-				if ( ! is_failed )
+				FailWarn(fail_on_file_problem, Fmt("Could not find requested port type field %s in input data file.",
-					FailWarn(fail_on_file_problem, Fmt("Could not find requested port type field %s in input data file.",
+								 field->secondary_name), true);
-					         field->secondary_name));
 
-				is_failed = true;
+				return false;
-				return !fail_on_file_problem;
 				}
 
 			f.secondary_position = ifields[field->secondary_name];
@@ -258,7 +263,7 @@ bool Ascii::GetLine(string& str)
 bool Ascii::DoUpdate()
 	{
 	if ( ! OpenFile() )
-		return !fail_on_file_problem;
+		return ! fail_on_file_problem;
 
 	switch ( Info().mode ) {
 		case MODE_REREAD:
@@ -267,11 +272,10 @@ bool Ascii::DoUpdate()
 			struct stat sb;
 			if ( stat(Info().source, &sb) == -1 )
 				{
-				if ( ! is_failed )
+				FailWarn(fail_on_file_problem, Fmt("Could not get stat for %s", Info().source), true);
-					FailWarn(fail_on_file_problem, Fmt("Could not get stat for %s", Info().source));
+
 				file.close();
-				is_failed = true;
+				return ! fail_on_file_problem;
-				return !fail_on_file_problem;
 				}
 
 			if ( sb.st_mtime <= mtime ) // no change
@@ -293,10 +297,9 @@ bool Ascii::DoUpdate()
 				if ( Info().mode == MODE_STREAM )
 					{
 					file.clear(); // remove end of file evil bits
-					if ( !ReadHeader(true) )
+					if ( ! ReadHeader(true) )
 						{
-						is_failed = true;
+						return ! fail_on_file_problem; // header reading failed
-						return !fail_on_file_problem; // header reading failed
 						}
 
 					break;
@@ -360,15 +363,15 @@ bool Ascii::DoUpdate()
 			if ( (*fit).position > pos || (*fit).secondary_position > pos )
 				{
 				FailWarn(fail_on_invalid_lines, Fmt("Not enough fields in line %s. Found %d fields, want positions %d and %d",
-					  line.c_str(), pos,  (*fit).position, (*fit).secondary_position));
+					  line.c_str(), pos, (*fit).position, (*fit).secondary_position));
-
-				for ( int i = 0; i < fpos; i++ )
-					delete fields[i];
-
-				delete [] fields;
 
 				if ( fail_on_invalid_lines )
 					{
+					for ( int i = 0; i < fpos; i++ )
+						delete fields[i];
+
+					delete [] fields;
+
 					return false;
 					}
 				else
@@ -432,7 +435,7 @@ bool Ascii::DoUpdate()
 bool Ascii::DoHeartbeat(double network_time, double current_time)
 	{
 	if ( ! OpenFile() )
-		return !fail_on_file_problem;
+		return ! fail_on_file_problem;
 
 	switch ( Info().mode )
 		{

src/input/readers/ascii/Ascii.h

@@ -56,8 +56,10 @@ private:
 	bool ReadHeader(bool useCached);
 	bool GetLine(string& str);
 	bool OpenFile();
-	void FailWarn(bool is_error, const char *msg);
+	// Call Warning or Error, depending on the is_error boolean.
-
+	// In case of a warning, setting suppress_future to true will suppress all future warnings
+	// (by setting suppress_warnings to true, until suppress_warnings is set back to false)
+	void FailWarn(bool is_error, const char *msg, bool suppress_future = false);
 
 	ifstream file;
 	time_t mtime;
@@ -77,8 +79,8 @@ private:
 	bool fail_on_file_problem;
 
 	// this is an internal indicator in case the read is currently in a failed state
-	// it's used by the options for continuing instead of failing and killing the reader.
+	// it's used to suppress duplicate error messages.
-	bool is_failed;
+	bool suppress_warnings;
 
 	std::unique_ptr<threading::formatter::Formatter> formatter;
 };

testing/btest/Baseline/scripts.base.frameworks.input.invalid-lines/out

@@ -0,0 +1,26 @@
+{
+[-43] = [b=T, e=SSH::LOG, c=21, p=123/unknown, sn=10.0.0.0/24, a=1.2.3.4, d=3.14, t=1315801931.273616, iv=100.0, s=hurz, ns=4242 HOHOHO, sc={
+2,
+4,
+1,
+3
+}, ss={
+BB,
+AA,
+CC
+}, se={
+
+}, vc=[10, 20, 30], ve=[]],
+[-42] = [b=T, e=SSH::LOG, c=21, p=123/unknown, sn=10.0.0.0/24, a=1.2.3.4, d=3.14, t=1315801931.273616, iv=100.0, s=hurz, ns=4242, sc={
+2,
+4,
+1,
+3
+}, ss={
+BB,
+AA,
+CC
+}, se={
+
+}, vc=[10, 20, 30], ve=[]]
+}

testing/btest/Baseline/scripts.base.frameworks.input.missing-file-initially/bro..stderr

@@ -1,4 +1,8 @@
 warning: ../does-not-exist.dat/Input::READER_ASCII: Init: cannot open ../does-not-exist.dat
+warning: ../does-not-exist.dat/Input::READER_ASCII: Init: cannot open ../does-not-exist.dat
+warning: ../does-not-exist.dat/Input::READER_ASCII: Init: cannot open ../does-not-exist.dat
 error: ../does-not-exist.dat/Input::READER_ASCII: Init: cannot open ../does-not-exist.dat
+error: ../does-not-exist.dat/Input::READER_ASCII: Init failed
 error: ../does-not-exist.dat/Input::READER_ASCII: terminating thread
+warning: ../does-not-exist.dat/Input::READER_ASCII: Could not get stat for ../does-not-exist.dat
 received termination signal

testing/btest/Baseline/scripts.base.frameworks.input.missing-file-initially/bro..stdout

@@ -1,2 +1,5 @@
 now it does
 and more!
+now it does
+and more!
+Streaming still works

testing/btest/Baseline/scripts.base.frameworks.input.missing-file/bro..stderr

@@ -1,2 +1,4 @@
-warning: does-not-exist.dat/Input::READER_ASCII: Init: cannot open does-not-exist.dat
+error: does-not-exist.dat/Input::READER_ASCII: Init: cannot open does-not-exist.dat
+error: does-not-exist.dat/Input::READER_ASCII: Init failed
+error: does-not-exist.dat/Input::READER_ASCII: terminating thread
 received termination signal

testing/btest/scripts/base/frameworks/input/invalid-lines.bro

@@ -0,0 +1,67 @@
+# @TEST-EXEC: btest-bg-run bro bro -b %INPUT
+# @TEST-EXEC: btest-bg-wait 10
+# @TEST-EXEC: btest-diff out
+
+redef exit_only_after_terminate = T;
+redef InputAscii::fail_on_invalid_lines = F;
+
+@TEST-START-FILE input.log
+#separator \x09
+#path	ssh
+#fields	b	i	e	c	p	sn	a	d	t	iv	s	sc	ss	se	vc	ve	ns
+#types	bool	int	enum	count	port	subnet	addr	double	time	interval	string	table	table	table	vector	vector	string
+T	-42	SSH::LOG	21	123	10.0.0.0/24	1.2.3.4	3.14	1315801931.273616	100.000000	hurz	2,4,1,3	CC,AA,BB	EMPTY	10,20,30
+T	-42	SSH::LOG	21	123	10.0.0.0/24	1.2.3.4	3.14	1315801931.273616	100.000000	hurz	2,4,1,3	CC,AA,BB	EMPTY	10,20,30	EMPTY	4242
+T	-43	SSH::LOG	21	123	10.0.0.0/24	1.2.3.4	3.14	1315801931.273616	100.000000	hurz	2,4,1,3	CC,AA,BB	EMPTY	10,20,30	EMPTY	4242 HOHOHO
+T	-41
+@TEST-END-FILE
+
+@load base/protocols/ssh
+
+global outfile: file;
+
+redef InputAscii::empty_field = "EMPTY";
+
+module A;
+
+type Idx: record {
+	i: int;
+};
+
+type Val: record {
+	b: bool;
+	e: Log::ID;
+	c: count;
+	p: port;
+	sn: subnet;
+	a: addr;
+	d: double;
+	t: time;
+	iv: interval;
+	s: string;
+	ns: string;
+	sc: set[count];
+	ss: set[string];
+	se: set[string];
+	vc: vector of int;
+	ve: vector of int;
+};
+
+global servers: table[int] of Val = table();
+global servers2: table[int] of Val = table();
+
+event bro_init()
+	{
+	outfile = open("../out");
+	# first read in the old stuff into the table...
+	Input::add_table([$source="../input.log", $name="ssh", $idx=Idx, $val=Val, $destination=servers]);
+	Input::add_table([$source="../input.log", $name="ssh2", $idx=Idx, $val=Val, $destination=servers2, $config=table(["fail_on_invalid_lines"] = "T")]);
+	}
+
+event Input::end_of_data(name: string, source:string)
+	{
+	print outfile, servers;
+	Input::remove("ssh");
+	close(outfile);
+	terminate();
+	}

testing/btest/scripts/base/frameworks/input/invalidtext.bro

@@ -13,6 +13,7 @@
 @TEST-END-FILE
 
 redef exit_only_after_terminate = T;
+redef InputAscii::fail_on_invalid_lines = T;
 
 global outfile: file;
 

testing/btest/scripts/base/frameworks/input/missing-file-initially.bro

@@ -1,10 +1,12 @@
 # This tests files that don't exist initially and then do later during
 # runtime to make sure the ascii reader is resilient to files missing.
-# It does a second test at the same time which configures the old 
+# It does a second test at the same time which configures the old
 # failing behavior.
 
 # @TEST-EXEC: btest-bg-run bro bro %INPUT
-# @TEST-EXEC: btest-bg-wait -k 5
+# @TEST-EXEC: sleep 2; cp does-exist.dat does-not-exist.dat
+# @TEST-EXEC: sleep 2; mv does-not-exist.dat does-not-exist-again.dat; echo "Streaming still works" >> does-not-exist-again.dat
+# @TEST-EXEC: btest-bg-wait -k 3
 # @TEST-EXEC: btest-diff bro/.stdout
 # @TEST-EXEC: btest-diff bro/.stderr
 
@@ -40,8 +42,8 @@ event line2(description: Input::EventDescription, tpe: Input::Event, v: Val)
 event bro_init()
 	{
 	Input::add_event([$source="../does-not-exist.dat", $name="input", $reader=Input::READER_ASCII, $mode=Input::REREAD, $fields=Val, $ev=line, $want_record=T]);
-	Input::add_event([$source="../does-not-exist.dat", $name="input2", $reader=Input::READER_ASCII, $mode=Input::REREAD, $fields=Val, $ev=line2, $want_record=T, 
+	Input::add_event([$source="../does-not-exist.dat", $name="inputstream", $reader=Input::READER_ASCII, $mode=Input::STREAM, $fields=Val, $ev=line, $want_record=T]);
+	Input::add_event([$source="../does-not-exist.dat", $name="inputmanual", $reader=Input::READER_ASCII, $mode=Input::MANUAL, $fields=Val, $ev=line, $want_record=T]);
+	Input::add_event([$source="../does-not-exist.dat", $name="input2", $reader=Input::READER_ASCII, $mode=Input::REREAD, $fields=Val, $ev=line2, $want_record=T,
 	                  $config=table(["fail_on_file_problem"] = "T")]);
-
-	system("sleep 2; mv ../does-exist.dat ../does-not-exist.dat;");
 	}

testing/btest/scripts/base/frameworks/input/missing-file.bro

@@ -3,6 +3,7 @@
 # @TEST-EXEC: btest-diff bro/.stderr
 
 redef exit_only_after_terminate = T;
+redef InputAscii::fail_on_file_problem = T;
 
 global outfile: file;
 global try: count;