Merge remote-tracking branch 'origin/topic/awelzel/2120-logdir-leftover'

* origin/topic/awelzel/2120-logdir-leftover:
  sqlite default-logdir test: Remove ls ./logs baseline
  logging/sqlite: Recognize Log::default_logdir and place files there if set
  logging: Introduce Log::default_logdir deprecate LogAscii::logdir and per writer logdir
  logging/ascii: Fix .shadow paths when using LogAscii::logdir

CHANGES

@@ -1,3 +1,26 @@
+5.1.0-dev.192 | 2022-07-07 07:51:04 +0200
+
+  * sqlite default-logdir test: Remove ls ./logs baseline (Arne Welzel, Corelight)
+
+    Observed .sqlite-journal files and missing reporter.sqlite files
+    in CI runs. Subsequently reading the ./test.sqlite file is more
+    reliable and should be good enough.
+
+  * logging/sqlite: Recognize Log::default_logdir and place files there if set (Arne Welzel, Corelight)
+
+  * logging: Introduce Log::default_logdir deprecate LogAscii::logdir and per writer logdir (Arne Welzel, Corelight)
+
+    Also modify FormatRotationPath to keep rotated logs within
+    Log::default_logdir unless the rotation function explicitly
+    set dir, e.g. by when the user redef'ed default_rotation_interval.
+
+  * logging/ascii: Fix .shadow paths when using LogAscii::logdir (Arne Welzel, Corelight)
+
+    With the introduction of LogAscii::logdir, log filenames can now include
+    parent directories rather than being plain basenames. Enabling log rotation,
+    leftover log rotation and setting LogAscii::logdir broke due to not
+    handling this situation.
+
 5.1.0-dev.186 | 2022-07-05 22:18:52 +0000
 
   * Remove unnecssary includes of Dict.h (Tim Wojtulewicz, Corelight)

NEWS

@@ -38,12 +38,18 @@ Changed Functionality
   we cannot determine the connection direction, because both sides of the connection
   send packets that are associated with being a client/server.
 
+- The default logging directory is now set globally across all log
+  writers through ``Log::default_logdir``.
+
 Deprecated Functionality
 ------------------------
 
 - The PDict class is now an alias to Dictionary and has been deprecated. Use Dictionary
   directly, passing a pointer type to the template.
 
+- ``LogAscii::logdir`` and per-writer log directories have been
+  deprecated in favor of the new ``Log::default_logdir``.
+
 Zeek 5.0.0
 ==========
 

VERSION

@@ -1 +1 @@
-5.1.0-dev.186
+5.1.0-dev.192

scripts/base/frameworks/logging/main.zeek

@@ -26,6 +26,14 @@ export {
 	## Default writer to use if a filter does not specify anything else.
 	const default_writer = WRITER_ASCII &redef;
 
+	## Default logging directory. An empty string implies using the
+	## current working directory.
+	##
+	## This directory is also used for rotated logs in cases where
+	## :zeek:see:`Log::rotation_format_func` returns a record with
+	## an empty or unset ``dir`` field.
+	const default_logdir = "" &redef;
+
 	## Default separator to use between fields.
 	## Individual writers can use a different value.
 	const separator = "\t" &redef;

scripts/base/frameworks/logging/writers/ascii.zeek

@@ -57,7 +57,10 @@ export {
 	## Define the default logging directory. If empty, logs are written
 	## to the current working directory.
 	##
-	const logdir = "" &redef;
+	## This setting is superseded by :zeek:see:`Log::default_logdir`. The
+	## latter applies to all file writers and also interacts better with
+	## log rotation.
+	const logdir = "" &redef &deprecated="Remove in v6.1. Use 'Log::default_logdir'.";
 
 	## Format of timestamps when writing out JSON. By default, the JSON
 	## formatter will use double values for timestamps which represent the

src/logging/Manager.cc

@@ -1529,6 +1529,13 @@ std::string Manager::FormatRotationPath(EnumValPtr writer, std::string_view path
 		auto prefix = rp_val->GetFieldAs<StringVal>(1)->CheckString();
 		auto dir = dir_val->AsString()->CheckString();
 
+		// If rotation_format_func returned an empty dir in RotationPath
+		// and Log::default_logdir is set, use it so that rotation is
+		// confined within it.
+		auto default_logdir = zeek::id::find_const<StringVal>("Log::default_logdir")->ToStdString();
+		if ( util::streq(dir, "") && ! default_logdir.empty() )
+			dir = default_logdir.c_str();
+
 		if ( ! util::streq(dir, "") && ! util::detail::ensure_intermediate_dirs(dir) )
 			{
 			reporter->Error("Failed to create dir '%s' returned by "

src/logging/writers/ascii/Ascii.cc

@@ -15,11 +15,14 @@
 #include <string>
 #include <vector>
 
+#include "zeek/3rdparty/doctest.h"
 #include "zeek/Func.h"
 #include "zeek/RunState.h"
 #include "zeek/logging/Manager.h"
+#include "zeek/logging/logging.bif.h"
 #include "zeek/logging/writers/ascii/ascii.bif.h"
 #include "zeek/threading/SerialTypes.h"
+#include "zeek/util.h"
 
 using namespace std;
 using zeek::threading::Field;
@@ -38,7 +41,7 @@ namespace zeek::logging::writer::detail
 struct LeftoverLog
 	{
 	/*
-	 * Name of leftover log, relative to working dir.
+	 * Name of leftover log.
 	 */
 	std::string filename;
 
@@ -83,9 +86,9 @@ struct LeftoverLog
 
 	/**
 	 * Return the "path" (logging framework parlance) of the log without the
-	 * file extension. E.g. the "path" of "conn.log" is just "conn".
+	 * directory or file extension. E.g. the "path" of "logs/conn.log" is just "conn".
 	 */
-	std::string Path() const { return filename.substr(0, filename.size() - extension.size()); }
+	std::string Path() const { return zeek::filesystem::path(filename).stem(); }
 
 	/**
 	 * Deletes the shadow file and returns whether it succeeded.
@@ -93,9 +96,31 @@ struct LeftoverLog
 	bool DeleteShadow() const { return unlink(shadow_filename.data()) == 0; }
 	};
 
+/**
+ * Prefix the basename part of the given path with prefix.
+ *
+ * prefix_basename_with("logs/conn.log", ".shadow") -> logs/.shadow.conn.log"
+ */
+static std::string prefix_basename_with(const std::string& path, const std::string& prefix)
+	{
+	auto fspath = zeek::filesystem::path(path);
+	auto new_filename = prefix + fspath.filename().string();
+	return (fspath.parent_path() / new_filename).string();
+	}
+
+TEST_CASE("writers.ascii prefix_basename_with")
+	{
+	CHECK(prefix_basename_with("", ".shadow.") == ".shadow.");
+	CHECK(prefix_basename_with("conn.log", ".shadow.") == ".shadow.conn.log");
+	CHECK(prefix_basename_with("/conn.log", ".shadow.") == "/.shadow.conn.log");
+	CHECK(prefix_basename_with("a/conn.log", ".shadow.") == "a/.shadow.conn.log");
+	CHECK(prefix_basename_with("/a/conn.log", ".shadow.") == "/a/.shadow.conn.log");
+	CHECK(prefix_basename_with("a/b/conn.log", ".shadow.") == "a/b/.shadow.conn.log");
+	}
+
 static std::optional<LeftoverLog> parse_shadow_log(const std::string& fname)
 	{
-	auto sfname = shadow_file_prefix + fname;
+	auto sfname = prefix_basename_with(fname, shadow_file_prefix);
 
 	LeftoverLog rval;
 	rval.filename = fname;
@@ -238,8 +263,13 @@ void Ascii::InitConfigOptions()
 	gzip_file_extension.assign((const char*)BifConst::LogAscii::gzip_file_extension->Bytes(),
 	                           BifConst::LogAscii::gzip_file_extension->Len());
 
+	// Remove in v6.1: LogAscii::logdir should be gone in favor
+	// of using Log::default_logdir.
 	logdir.assign((const char*)BifConst::LogAscii::logdir->Bytes(),
 	              BifConst::LogAscii::logdir->Len());
+
+	if ( logdir.empty() )
+		logdir = zeek::id::find_const<StringVal>("Log::default_logdir")->ToStdString();
 	}
 
 bool Ascii::InitFilterOptions()
@@ -350,8 +380,14 @@ bool Ascii::InitFilterOptions()
 			gzip_file_extension.assign(i->second);
 
 		else if ( strcmp(i->first, "logdir") == 0 )
+			{
+			// This doesn't play nice with leftover log rotation
+			// and log rotation in general. There's no documentation
+			// or a test for this specifically, so deprecate it.
+			reporter->Warning("Remove in v6.1. Per writer logdir is deprecated.");
 			logdir.assign(i->second);
 			}
+		}
 
 	if ( ! InitFormatter() )
 		return false;
@@ -457,17 +493,7 @@ bool Ascii::DoInit(const WriterInfo& info, int num_fields, const threading::Fiel
 			}
 
 		if ( fname.front() != '/' && ! logdir.empty() )
-			{
+			fname = zeek::filesystem::path(logdir) / fname;
-			string path = logdir;
-			std::size_t last = path.find_last_not_of('/');
-
-			if ( last == string::npos ) // Nothing but slashes -- weird but ok...
-				path = "/";
-			else
-				path.erase(last + 1);
-
-			fname = path + "/" + fname;
-			}
 
 		fname += ext;
 
@@ -476,8 +502,8 @@ bool Ascii::DoInit(const WriterInfo& info, int num_fields, const threading::Fiel
 
 		if ( use_shadow )
 			{
-			auto sfname = shadow_file_prefix + fname;
+			auto sfname = prefix_basename_with(fname, shadow_file_prefix);
-			auto tmp_sfname = ".tmp" + sfname;
+			auto tmp_sfname = prefix_basename_with(sfname, ".tmp");
 			auto sfd = open(tmp_sfname.data(), O_WRONLY | O_CREAT | O_TRUNC, 0666);
 
 			if ( sfd < 0 )
@@ -698,7 +724,7 @@ bool Ascii::DoRotate(const char* rotated_path, double open, double close, bool t
 
 	if ( use_shadow )
 		{
-		auto sfname = shadow_file_prefix + fname;
+		auto sfname = prefix_basename_with(fname, shadow_file_prefix);
 
 		if ( unlink(sfname.data()) != 0 )
 			{
@@ -734,22 +760,26 @@ static std::vector<LeftoverLog> find_leftover_logs()
 	std::vector<LeftoverLog> rval;
 	std::vector<std::string> stale_shadow_files;
 	auto prefix_len = strlen(shadow_file_prefix);
+	auto default_logdir = zeek::id::find_const<StringVal>("Log::default_logdir")->ToStdString();
 
-	auto d = opendir(".");
+	// Find any .shadow files within LogAscii::logdir, Log::default_logdir
+	// or otherwise search in the current working directory.
+	auto logdir = zeek::filesystem::current_path();
+
+	if ( ! default_logdir.empty() )
+		logdir = zeek::filesystem::absolute(default_logdir);
+
+	// Remove LogAscii::logdir fallback in v6.1.
+	if ( BifConst::LogAscii::logdir->Len() > 0 )
+		logdir = zeek::filesystem::absolute(BifConst::LogAscii::logdir->ToStdString());
+
+	auto d = opendir(logdir.c_str());
 	struct dirent* dp;
 
 	if ( ! d )
 		{
-		char cwd[PATH_MAX];
+		reporter->Error("failed to open directory '%s' in search of leftover logs: %s",
-
+		                logdir.c_str(), strerror(errno));
-		if ( ! getcwd(cwd, sizeof(cwd)) )
-			{
-			cwd[0] = '.';
-			cwd[1] = '\0';
-			}
-
-		reporter->Error("failed to open directory '%s' in search of leftover logs: %s", cwd,
-		                strerror(errno));
 		return rval;
 		}
 
@@ -758,27 +788,28 @@ static std::vector<LeftoverLog> find_leftover_logs()
 		if ( strncmp(dp->d_name, shadow_file_prefix, prefix_len) != 0 )
 			continue;
 
-		std::string log_name = dp->d_name + prefix_len;
+		std::string shadow_fname = logdir / dp->d_name;
+		std::string log_fname = logdir / (dp->d_name + prefix_len);
 
-		if ( util::is_file(log_name) )
+		if ( util::is_file(log_fname) )
 			{
-			if ( auto ll = parse_shadow_log(log_name) )
+			if ( auto ll = parse_shadow_log(log_fname) )
 				{
 				if ( ll->error.empty() )
 					rval.emplace_back(std::move(*ll));
 				else
-					reporter->Error("failed to process leftover log '%s': %s", log_name.data(),
+					reporter->Error("failed to process leftover log '%s': %s", log_fname.data(),
 					                ll->error.data());
 				}
 			}
 		else
 			// There was a log here.  It's gone now.
-			stale_shadow_files.emplace_back(dp->d_name);
+			stale_shadow_files.emplace_back(shadow_fname);
 		}
 
 	for ( const auto& f : stale_shadow_files )
 		if ( unlink(f.data()) != 0 )
-			reporter->Error("cannot unlink %s: %s", f.data(), strerror(errno));
+			reporter->Error("cannot unlink stale %s: %s", f.data(), strerror(errno));
 
 	closedir(d);
 	return rval;

src/logging/writers/sqlite/SQLite.cc

@@ -10,6 +10,7 @@
 
 #include "zeek/logging/writers/sqlite/sqlite.bif.h"
 #include "zeek/threading/SerialTypes.h"
+#include "zeek/util.h"
 
 using namespace std;
 using zeek::threading::Field;
@@ -128,8 +129,11 @@ bool SQLite::DoInit(const WriterInfo& info, int arg_num_fields, const Field* con
 	num_fields = arg_num_fields;
 	fields = arg_fields;
 
-	string fullpath(info.path);
+	auto fullpath = zeek::filesystem::path(
-	fullpath.append(".sqlite");
+		zeek::id::find_const<StringVal>("Log::default_logdir")->ToStdString());
+
+	fullpath /= info.path;
+	fullpath += ".sqlite";
 	string tablename;
 
 	WriterInfo::config_map::const_iterator it = info.config.find("tablename");

testing/btest/Baseline/scripts.base.frameworks.logging.rotate-ascii-logdir-leftover-log-rotation-shadow-files/logs.cat

@@ -0,0 +1,3 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+leftover conn log
+leftover dns log

testing/btest/Baseline/scripts.base.frameworks.logging.rotate-ascii-logdir-leftover-log-rotation-shadow-files/out

@@ -0,0 +1,4 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+### NOTE: This file has been sorted with diff-sort.
+running my rotation postprocessor for path 'conn'
+running my rotation postprocessor for path 'dns'

testing/btest/Baseline/scripts.base.frameworks.logging.rotate-ascii-logdir-leftover-log-rotation-stale-shadow-files/out

@@ -0,0 +1,2 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+warning in <...>/rotate-ascii-logdir-leftover-log-rotation-stale-shadow-files.zeek, line 20: deprecated (LogAscii::logdir): Remove in v6.1. Use 'Log::default_logdir'.

testing/btest/Baseline/scripts.base.frameworks.logging.rotate-ascii-logdir-leftover-log-rotation/out

@@ -0,0 +1,132 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+test.2011-03-07-03-00-05.log test 11-03-07_03.00.05 11-03-07_04.00.05 0 ascii
+test.2011-03-07-04-00-05.log test 11-03-07_04.00.05 11-03-07_05.00.05 0 ascii
+test.2011-03-07-05-00-05.log test 11-03-07_05.00.05 11-03-07_06.00.05 0 ascii
+test.2011-03-07-06-00-05.log test 11-03-07_06.00.05 11-03-07_07.00.05 0 ascii
+test.2011-03-07-07-00-05.log test 11-03-07_07.00.05 11-03-07_08.00.05 0 ascii
+test.2011-03-07-08-00-05.log test 11-03-07_08.00.05 11-03-07_09.00.05 0 ascii
+test.2011-03-07-09-00-05.log test 11-03-07_09.00.05 11-03-07_10.00.05 0 ascii
+test.2011-03-07-10-00-05.log test 11-03-07_10.00.05 11-03-07_11.00.05 0 ascii
+test.2011-03-07-11-00-05.log test 11-03-07_11.00.05 11-03-07_12.00.05 0 ascii
+test.2011-03-07-12-00-05.log test 11-03-07_12.00.05 11-03-07_12.59.55 1 ascii
+warning in <...>/rotate-ascii-logdir-leftover-log-rotation.zeek, line 22: deprecated (LogAscii::logdir): Remove in v6.1. Use 'Log::default_logdir'.
+> test.2011-03-07-03-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1024
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	0
+#close XXXX-XX-XX-XX-XX-XX
+> test.2011-03-07-04-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1025
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	1
+#close XXXX-XX-XX-XX-XX-XX
+> test.2011-03-07-05-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1026
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	2
+#close XXXX-XX-XX-XX-XX-XX
+> test.2011-03-07-06-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1027
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	3
+#close XXXX-XX-XX-XX-XX-XX
+> test.2011-03-07-07-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1028
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	4
+#close XXXX-XX-XX-XX-XX-XX
+> test.2011-03-07-08-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1029
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	5
+#close XXXX-XX-XX-XX-XX-XX
+> test.2011-03-07-09-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1030
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	6
+#close XXXX-XX-XX-XX-XX-XX
+> test.2011-03-07-10-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1031
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	7
+#close XXXX-XX-XX-XX-XX-XX
+> test.2011-03-07-11-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1032
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	8
+#close XXXX-XX-XX-XX-XX-XX
+> test.2011-03-07-12-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1033
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	9
+#close XXXX-XX-XX-XX-XX-XX

testing/btest/Baseline/scripts.base.frameworks.logging.rotate-default-logdir-leftover-log-rotation-shadow-files/logs.cat

@@ -0,0 +1,3 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+leftover conn log
+leftover dns log

testing/btest/Baseline/scripts.base.frameworks.logging.rotate-default-logdir-leftover-log-rotation-shadow-files/out

@@ -0,0 +1,4 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+### NOTE: This file has been sorted with diff-sort.
+running my rotation postprocessor for path 'conn'
+running my rotation postprocessor for path 'dns'

testing/btest/Baseline/scripts.base.frameworks.logging.rotate-default-logdir-leftover-log-rotation-stale-shadow-files/out

@@ -0,0 +1 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.

testing/btest/Baseline/scripts.base.frameworks.logging.rotate-default-logdir/out

@@ -0,0 +1,131 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+./logs/test.2011-03-07-03-00-05.log test 11-03-07_03.00.05 11-03-07_04.00.05 0 ascii
+./logs/test.2011-03-07-04-00-05.log test 11-03-07_04.00.05 11-03-07_05.00.05 0 ascii
+./logs/test.2011-03-07-05-00-05.log test 11-03-07_05.00.05 11-03-07_06.00.05 0 ascii
+./logs/test.2011-03-07-06-00-05.log test 11-03-07_06.00.05 11-03-07_07.00.05 0 ascii
+./logs/test.2011-03-07-07-00-05.log test 11-03-07_07.00.05 11-03-07_08.00.05 0 ascii
+./logs/test.2011-03-07-08-00-05.log test 11-03-07_08.00.05 11-03-07_09.00.05 0 ascii
+./logs/test.2011-03-07-09-00-05.log test 11-03-07_09.00.05 11-03-07_10.00.05 0 ascii
+./logs/test.2011-03-07-10-00-05.log test 11-03-07_10.00.05 11-03-07_11.00.05 0 ascii
+./logs/test.2011-03-07-11-00-05.log test 11-03-07_11.00.05 11-03-07_12.00.05 0 ascii
+./logs/test.2011-03-07-12-00-05.log test 11-03-07_12.00.05 11-03-07_12.59.55 1 ascii
+> ./logs/test.2011-03-07-03-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1024
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	0
+#close XXXX-XX-XX-XX-XX-XX
+> ./logs/test.2011-03-07-04-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1025
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	1
+#close XXXX-XX-XX-XX-XX-XX
+> ./logs/test.2011-03-07-05-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1026
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	2
+#close XXXX-XX-XX-XX-XX-XX
+> ./logs/test.2011-03-07-06-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1027
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	3
+#close XXXX-XX-XX-XX-XX-XX
+> ./logs/test.2011-03-07-07-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1028
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	4
+#close XXXX-XX-XX-XX-XX-XX
+> ./logs/test.2011-03-07-08-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1029
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	5
+#close XXXX-XX-XX-XX-XX-XX
+> ./logs/test.2011-03-07-09-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1030
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	6
+#close XXXX-XX-XX-XX-XX-XX
+> ./logs/test.2011-03-07-10-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1031
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	7
+#close XXXX-XX-XX-XX-XX-XX
+> ./logs/test.2011-03-07-11-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1032
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	8
+#close XXXX-XX-XX-XX-XX-XX
+> ./logs/test.2011-03-07-12-00-05.log
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	test
+#open XXXX-XX-XX-XX-XX-XX
+#fields	t	id.orig_h	id.orig_p	id.resp_h	id.resp_p
+#types	time	addr	port	addr	port
+XXXXXXXXXX.XXXXXX	10.0.0.1	20	10.0.0.2	1033
+XXXXXXXXXX.XXXXXX	10.0.0.2	20	10.0.0.3	9
+#close XXXX-XX-XX-XX-XX-XX

testing/btest/Baseline/scripts.base.frameworks.logging.rotate-leftover-log-rotation-shadow-files/logs.cat

@@ -0,0 +1,3 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+leftover conn log
+leftover dns log

testing/btest/Baseline/scripts.base.frameworks.logging.rotate-leftover-log-rotation-shadow-files/out

@@ -0,0 +1,4 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+### NOTE: This file has been sorted with diff-sort.
+running my rotation postprocessor for path 'conn'
+running my rotation postprocessor for path 'dns'

testing/btest/Baseline/scripts.base.frameworks.logging.sqlite.default-logdir/test.select

@@ -0,0 +1,21 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+XXXXXXXXXX.XXXXXX|10.0.0.1|20|10.0.0.2|1024
+XXXXXXXXXX.XXXXXX|10.0.0.2|20|10.0.0.3|0
+XXXXXXXXXX.XXXXXX|10.0.0.1|20|10.0.0.2|1025
+XXXXXXXXXX.XXXXXX|10.0.0.2|20|10.0.0.3|1
+XXXXXXXXXX.XXXXXX|10.0.0.1|20|10.0.0.2|1026
+XXXXXXXXXX.XXXXXX|10.0.0.2|20|10.0.0.3|2
+XXXXXXXXXX.XXXXXX|10.0.0.1|20|10.0.0.2|1027
+XXXXXXXXXX.XXXXXX|10.0.0.2|20|10.0.0.3|3
+XXXXXXXXXX.XXXXXX|10.0.0.1|20|10.0.0.2|1028
+XXXXXXXXXX.XXXXXX|10.0.0.2|20|10.0.0.3|4
+XXXXXXXXXX.XXXXXX|10.0.0.1|20|10.0.0.2|1029
+XXXXXXXXXX.XXXXXX|10.0.0.2|20|10.0.0.3|5
+XXXXXXXXXX.XXXXXX|10.0.0.1|20|10.0.0.2|1030
+XXXXXXXXXX.XXXXXX|10.0.0.2|20|10.0.0.3|6
+XXXXXXXXXX.XXXXXX|10.0.0.1|20|10.0.0.2|1031
+XXXXXXXXXX.XXXXXX|10.0.0.2|20|10.0.0.3|7
+XXXXXXXXXX.XXXXXX|10.0.0.1|20|10.0.0.2|1032
+XXXXXXXXXX.XXXXXX|10.0.0.2|20|10.0.0.3|8
+XXXXXXXXXX.XXXXXX|10.0.0.1|20|10.0.0.2|1033
+XXXXXXXXXX.XXXXXX|10.0.0.2|20|10.0.0.3|9

testing/btest/Baseline/scripts.base.frameworks.logging.sqlite.default-logdir/zeek.out

@@ -0,0 +1,2 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+XXXXXXXXXX.XXXXXX test/Log::WRITER_SQLITE: tablename configuration option not found. Defaulting to path test

testing/btest/scripts/base/frameworks/logging/rotate-ascii-logdir-leftover-log-rotation-shadow-files.zeek

@@ -0,0 +1,34 @@
+# @TEST-DOC: Test that .shadow files are picked up from LogAscii::logdir.
+# @TEST-EXEC: mkdir logs
+# @TEST-EXEC: echo ".log" >> logs/.shadow.conn.log
+# @TEST-EXEC: echo "my_rotation_postprocessor" >> logs/.shadow.conn.log
+# @TEST-EXEC: echo "leftover conn log" > logs/conn.log
+# @TEST-EXEC: echo ".log" >> logs/.shadow.dns.log
+# @TEST-EXEC: echo "my_rotation_postprocessor" >> logs/.shadow.dns.log
+# @TEST-EXEC: echo "leftover dns log" > logs/dns.log
+
+# @TEST-EXEC: zeek -b %INPUT > out
+
+# @TEST-EXEC: ! test -f logs/.shadow.conn.log
+# @TEST-EXEC: ! test -f logs/conn.log
+# @TEST-EXEC: ! test -f logs/.shadow.dns.log
+# @TEST-EXEC: ! test -f logs/dns.log
+
+# Ensure rotated logs ends-up in the current working directory: This may change in the future.
+# @TEST-EXEC: cat ./conn-*.log ./dns-*.log > logs.cat
+
+# @TEST-EXEC: TEST_DIFF_CANONIFIER=$SCRIPTS/diff-sort btest-diff out
+# @TEST-EXEC: btest-diff logs.cat
+
+module GLOBAL;
+
+function my_rotation_postprocessor(info: Log::RotationInfo) : bool
+	{
+	print fmt("running my rotation postprocessor for path '%s'", info$path);
+	return T;
+	}
+
+redef LogAscii::logdir = "./logs";
+redef LogAscii::enable_leftover_log_rotation = T;
+redef Log::default_rotation_interval = 1hr;
+redef Log::default_rotation_postprocessor_cmd = "echo";

testing/btest/scripts/base/frameworks/logging/rotate-ascii-logdir-leftover-log-rotation-stale-shadow-files.zeek

@@ -0,0 +1,23 @@
+# @TEST-DOC: Test that stale .shadow files are removed from LogAscii::logdir.
+# @TEST-EXEC: mkdir logs
+# @TEST-EXEC: echo ".log" >> logs/.shadow.conn.log
+# @TEST-EXEC: echo "my_rotation_postprocessor" >> logs/.shadow.conn.log
+
+# @TEST-EXEC: zeek -b %INPUT > out 2>&1
+
+# @TEST-EXEC: ! test -f logs/.shadow.conn.log
+
+# @TEST-EXEC: TEST_DIFF_CANONIFIER='$SCRIPTS/diff-remove-abspath | $SCRIPTS/diff-remove-timestamps' btest-diff out
+
+module GLOBAL;
+
+function my_rotation_postprocessor(info: Log::RotationInfo) : bool
+	{
+	print fmt("running my rotation postprocessor for path '%s'", info$path);
+	return T;
+	}
+
+redef LogAscii::logdir = "./logs";
+redef LogAscii::enable_leftover_log_rotation = T;
+redef Log::default_rotation_interval = 1hr;
+redef Log::default_rotation_postprocessor_cmd = "echo";

testing/btest/scripts/base/frameworks/logging/rotate-ascii-logdir-leftover-log-rotation.zeek

@@ -0,0 +1,35 @@
+# @TEST-DOC: Enable leftover log rotation and logdir. Note, files are rotated into the cwd.
+# @TEST-EXEC: mkdir logs
+# @TEST-EXEC: zeek -b -r ${TRACES}/rotation.trace %INPUT >zeek.out 2>&1
+# @TEST-EXEC: grep "test" zeek.out | sort >out
+# @TEST-EXEC: for i in `ls test.*.log | sort`; do printf '> %s\n' $i; cat $i; done >>out
+# @TEST-EXEC: TEST_DIFF_CANONIFIER='$SCRIPTS/diff-remove-abspath | $SCRIPTS/diff-remove-timestamps' btest-diff out
+
+module Test;
+
+export {
+	# Create a new ID for our log stream
+	redef enum Log::ID += { LOG };
+
+	# Define a record with all the columns the log file can have.
+	# (I'm using a subset of fields from ssh-ext for demonstration.)
+	type Log: record {
+		t: time;
+		id: conn_id; # Will be rolled out into individual columns.
+	} &log;
+}
+
+redef LogAscii::logdir = "./logs";
+redef LogAscii::enable_leftover_log_rotation = T;
+redef Log::default_rotation_interval = 1hr;
+redef Log::default_rotation_postprocessor_cmd = "echo";
+
+event zeek_init()
+	{
+	Log::create_stream(Test::LOG, [$columns=Log]);
+	}
+
+event new_connection(c: connection)
+	{
+	Log::write(Test::LOG, [$t=network_time(), $id=c$id]);
+	}

testing/btest/scripts/base/frameworks/logging/rotate-default-logdir-leftover-log-rotation-shadow-files.zeek

@@ -0,0 +1,34 @@
+# @TEST-DOC: Test that .shadow files are picked up from Log::default_logdir.
+# @TEST-EXEC: mkdir logs
+# @TEST-EXEC: echo ".log" >> logs/.shadow.conn.log
+# @TEST-EXEC: echo "my_rotation_postprocessor" >> logs/.shadow.conn.log
+# @TEST-EXEC: echo "leftover conn log" > logs/conn.log
+# @TEST-EXEC: echo ".log" >> logs/.shadow.dns.log
+# @TEST-EXEC: echo "my_rotation_postprocessor" >> logs/.shadow.dns.log
+# @TEST-EXEC: echo "leftover dns log" > logs/dns.log
+
+# @TEST-EXEC: zeek -b %INPUT > out
+
+# @TEST-EXEC: ! test -f logs/.shadow.conn.log
+# @TEST-EXEC: ! test -f logs/conn.log
+# @TEST-EXEC: ! test -f logs/.shadow.dns.log
+# @TEST-EXEC: ! test -f logs/dns.log
+
+# Ensure rotated logs ends-up in the ./logs directory.
+# @TEST-EXEC: cat ./logs/conn-*.log ./logs/dns-*.log > logs.cat
+
+# @TEST-EXEC: TEST_DIFF_CANONIFIER=$SCRIPTS/diff-sort btest-diff out
+# @TEST-EXEC: btest-diff logs.cat
+
+module GLOBAL;
+
+function my_rotation_postprocessor(info: Log::RotationInfo) : bool
+	{
+	print fmt("running my rotation postprocessor for path '%s'", info$path);
+	return T;
+	}
+
+redef LogAscii::enable_leftover_log_rotation = T;
+redef Log::default_logdir = "./logs";
+redef Log::default_rotation_interval = 1hr;
+redef Log::default_rotation_postprocessor_cmd = "echo";

testing/btest/scripts/base/frameworks/logging/rotate-default-logdir-leftover-log-rotation-stale-shadow-files.zeek

@@ -0,0 +1,23 @@
+# @TEST-DOC: Test that stale .shadow files are removed from ::default_logdir
+# @TEST-EXEC: mkdir logs
+# @TEST-EXEC: echo ".log" >> logs/.shadow.conn.log
+# @TEST-EXEC: echo "my_rotation_postprocessor" >> logs/.shadow.conn.log
+
+# @TEST-EXEC: zeek -b %INPUT > out 2>&1
+
+# @TEST-EXEC: ! test -f logs/.shadow.conn.log
+
+# @TEST-EXEC: TEST_DIFF_CANONIFIER='$SCRIPTS/diff-remove-abspath | $SCRIPTS/diff-remove-timestamps' btest-diff out
+
+module GLOBAL;
+
+function my_rotation_postprocessor(info: Log::RotationInfo) : bool
+	{
+	print fmt("running my rotation postprocessor for path '%s'", info$path);
+	return T;
+	}
+
+redef Log::default_logdir = "./logs";
+redef LogAscii::enable_leftover_log_rotation = T;
+redef Log::default_rotation_interval = 1hr;
+redef Log::default_rotation_postprocessor_cmd = "echo";

testing/btest/scripts/base/frameworks/logging/rotate-default-logdir.zeek

@@ -0,0 +1,34 @@
+# @TEST-DOC: Set Log::default_logdir to ./logs. Ensure logs stay within ./logs.
+# @TEST-EXEC: mkdir logs
+# @TEST-EXEC: zeek -b -r ${TRACES}/rotation.trace %INPUT >zeek.out 2>&1
+# @TEST-EXEC: grep "test" zeek.out | sort >out
+# @TEST-EXEC: for i in `ls ./logs/test.*.log | sort`; do printf '> %s\n' $i; cat $i; done >>out
+# @TEST-EXEC: btest-diff out
+
+module Test;
+
+export {
+	# Create a new ID for our log stream
+	redef enum Log::ID += { LOG };
+
+	# Define a record with all the columns the log file can have.
+	# (I'm using a subset of fields from ssh-ext for demonstration.)
+	type Log: record {
+		t: time;
+		id: conn_id; # Will be rolled out into individual columns.
+	} &log;
+}
+
+redef Log::default_logdir = "./logs";
+redef Log::default_rotation_interval = 1hr;
+redef Log::default_rotation_postprocessor_cmd = "echo";
+
+event zeek_init()
+	{
+	Log::create_stream(Test::LOG, [$columns=Log]);
+	}
+
+event new_connection(c: connection)
+	{
+	Log::write(Test::LOG, [$t=network_time(), $id=c$id]);
+	}

testing/btest/scripts/base/frameworks/logging/rotate-leftover-log-rotation-shadow-files.zeek

@@ -0,0 +1,49 @@
+# @TEST-DOC: Enable leftover log rotation, put shadow files for conn and dns in the cwd and ensure rotation happens during startup.
+# @TEST-EXEC: echo ".log" >> .shadow.conn.log
+# @TEST-EXEC: echo "my_rotation_postprocessor" >> .shadow.conn.log
+# @TEST-EXEC: echo "leftover conn log" > conn.log
+
+# @TEST-EXEC: echo ".log" >> .shadow.dns.log
+# @TEST-EXEC: echo "my_rotation_postprocessor" >> .shadow.dns.log
+# @TEST-EXEC: echo "leftover dns log" > dns.log
+
+# @TEST-EXEC: zeek -b %INPUT > out
+
+# Ensure leftover files were removed.
+# @TEST-EXEC: ! test -f .shadow.conn.log
+# @TEST-EXEC: ! test -f conn.log
+# @TEST-EXEC: ! test -f .shadow.dns.log
+# @TEST-EXEC: ! test -f dns.log
+
+# Ensure the rotated conn log ends-up in the current working directory.
+# @TEST-EXEC: ls ./conn-*.log
+# @TEST-EXEC: cat ./conn-*.log ./dns-*.log > logs.cat
+
+# @TEST-EXEC: TEST_DIFF_CANONIFIER=$SCRIPTS/diff-sort btest-diff out
+# @TEST-EXEC: btest-diff logs.cat
+
+module Test;
+
+export {
+	# Create a new ID for our log stream
+	redef enum Log::ID += { LOG };
+
+	# Define a record with all the columns the log file can have.
+	# (I'm using a subset of fields from ssh-ext for demonstration.)
+	type Log: record {
+		t: time;
+		id: conn_id; # Will be rolled out into individual columns.
+	} &log;
+}
+
+module GLOBAL;
+
+function my_rotation_postprocessor(info: Log::RotationInfo) : bool
+	{
+	print fmt("running my rotation postprocessor for path '%s'", info$path);
+	return T;
+	}
+
+redef LogAscii::enable_leftover_log_rotation = T;
+redef Log::default_rotation_interval = 1hr;
+redef Log::default_rotation_postprocessor_cmd = "echo";

testing/btest/scripts/base/frameworks/logging/sqlite/default-logdir.zeek

@@ -0,0 +1,44 @@
+#
+# @TEST-REQUIRES: which sqlite3
+# @TEST-REQUIRES: has-writer Zeek::SQLiteWriter
+# @TEST-GROUP: sqlite
+#
+# @TEST-EXEC: mkdir logs
+# @TEST-EXEC: zeek -b -r ${TRACES}/rotation.trace %INPUT >zeek.out 2>&1
+# @TEST-EXEC: sqlite3 ./logs/test.sqlite 'select * from test' > test.select
+# @TEST-EXEC: btest-diff test.select
+# @TEST-EXEC: btest-diff zeek.out
+#
+# @TEST-DOC: Configure Log::default_writer, Log::default_logdir and ensure the test.sqlite database is in ./logs
+
+redef Log::default_writer = Log::WRITER_SQLITE;
+redef Log::default_logdir = "./logs";
+
+# Also enable log-rotation, but it has no effect on sqlite.
+redef Log::default_rotation_interval = 1hr;
+redef Log::default_rotation_postprocessor_cmd = "echo";
+
+redef LogSQLite::unset_field = "(unset)";
+
+module Test;
+
+export {
+	# Create a new ID for our log stream
+	redef enum Log::ID += { LOG };
+
+	# Define a record with all the columns the log file can have.
+	# (I'm using a subset of fields from ssh-ext for demonstration.)
+	type Log: record {
+		t: time;
+		id: conn_id; # Will be rolled out into individual columns.
+	} &log;
+}
+event zeek_init()
+	{
+	Log::create_stream(Test::LOG, [$columns=Log]);
+	}
+
+event new_connection(c: connection)
+	{
+	Log::write(Test::LOG, [$t=network_time(), $id=c$id]);
+	}