logging: Introduce Log::default_logdir deprecate LogAscii::logdir and per writer logdir

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.

scripts/base/frameworks/logging/main.zeek

@@ -26,6 +26,13 @@ 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 superseeded 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

@@ -19,6 +19,7 @@
 #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"
@@ -262,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()
@@ -374,7 +380,13 @@ 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() )
@@ -748,10 +760,16 @@ 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();
 
-	// Find any .shadow files within LogAscii::logdir if set or
+	// Find any .shadow files within LogAscii::logdir, Log::default_logdir
-	// otherwise search in the current working directory.
+	// 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());
 

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

@@ -1 +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

@@ -9,6 +9,7 @@ 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	,

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/scripts/base/frameworks/logging/rotate-ascii-logdir-leftover-log-rotation-stale-shadow-files.zeek

@@ -7,7 +7,7 @@
 
 # @TEST-EXEC: ! test -f logs/.shadow.conn.log
 
-# @TEST-EXEC: btest-diff out
+# @TEST-EXEC: TEST_DIFF_CANONIFIER='$SCRIPTS/diff-remove-abspath | $SCRIPTS/diff-remove-timestamps' btest-diff out
 
 module GLOBAL;
 

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

@@ -3,7 +3,7 @@
 # @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: btest-diff out
+# @TEST-EXEC: TEST_DIFF_CANONIFIER='$SCRIPTS/diff-remove-abspath | $SCRIPTS/diff-remove-timestamps' btest-diff out
 
 module Test;
 

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