logging: Support rotation_postprocessor_command_env

This new table provides a mechanism to add environment variables to the
postprocessor execution. Use case is from ZeekControl to inject a suffix
to be used when running with multiple logger.

NEWS

@@ -147,6 +147,9 @@ New Functionality
   seen on link, and packets filtered) are now reported to the Telemetry
   framework, under the ``zeek_net`` prefix.
 
+- Environment variables for the execution of log rotation postprocessors can
+  be set via ``Log::default_rotation_postprocessor_cmd_env``.
+
 Changed Functionality
 ---------------------
 

scripts/base/frameworks/logging/main.zeek

@@ -172,6 +172,14 @@ export {
 	## Default shell command to run on rotated files. Empty for none.
 	const default_rotation_postprocessor_cmd = "" &redef;
 
+	## This table contains environment variables to be used for the
+	## :zeek:see:`Log::default_rotation_postprocessor_cmd` command
+	## when executed via :zeek:see:`Log::run_rotation_postprocessor_cmd`.
+	##
+	## The entries in this table will be prepended with ``ZEEK_ARG_``
+	## as done by :zeek:see:`system_env`.
+	option default_rotation_postprocessor_cmd_env: table[string] of string = {};
+
 	## Specifies the default postprocessor function per writer type.
 	## Entries in this table are initialized by each writer type.
 	const default_rotation_postprocessors: table[Writer] of function(info: RotationInfo) : bool &redef;
@@ -578,6 +586,7 @@ export {
 	##          to postprocess a rotated log file.
 	##
 	## .. zeek:see:: Log::default_rotation_date_format
+	##    Log::default_rotation_postprocessor_cmd_env
 	##    Log::default_rotation_postprocessor_cmd
 	##    Log::default_rotation_postprocessors
 	global run_rotation_postprocessor_cmd: function(info: RotationInfo, npath: string) : bool;
@@ -654,8 +663,7 @@ function default_path_func(id: ID, path: string, rec: any) : string
 		return to_lower(id_str);
 	}
 
-# Run post-processor on file. If there isn't any postprocessor defined,
+# Run post-processor on file.
-# we move the file to a nicer name.
 function run_rotation_postprocessor_cmd(info: RotationInfo, npath: string) : bool
 	{
 	local pp_cmd = default_rotation_postprocessor_cmd;
@@ -668,11 +676,15 @@ function run_rotation_postprocessor_cmd(info: RotationInfo, npath: string) : boo
 
 	# The date format is hard-coded here to provide a standardized
 	# script interface.
-	system(fmt("%s %s %s %s %s %d %s",
+	#
+	# Note that system_env() does not clear the environment, it only
+	# adds entries from the given table. Unusual, but useful here.
+	system_env(fmt("%s %s %s %s %s %d %s",
 	               pp_cmd, safe_shell_quote(npath), safe_shell_quote(info$path),
 	               strftime("%y-%m-%d_%H.%M.%S", info$open),
 	               strftime("%y-%m-%d_%H.%M.%S", info$close),
-               info$terminating, writer));
+	               info$terminating, writer),
+	           Log::default_rotation_postprocessor_cmd_env);
 
 	return T;
 	}

testing/btest/Baseline/plugins.hooks/output

@@ -564,6 +564,7 @@
 0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (Input::default_reader, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (KRB::ignored_errors, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (Log::default_rotation_dir, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)) -> <no result>
+0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (Log::default_rotation_postprocessor_cmd_env, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (MQTT::max_payload_size, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (NetControl::default_priority, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (Notice::alarmed_types, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)) -> <no result>
@@ -2144,6 +2145,7 @@
 0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (Input::default_reader, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100))
 0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (KRB::ignored_errors, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100))
 0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (Log::default_rotation_dir, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100))
+0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (Log::default_rotation_postprocessor_cmd_env, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100))
 0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (MQTT::max_payload_size, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100))
 0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (NetControl::default_priority, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100))
 0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (Notice::alarmed_types, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100))
@@ -3723,6 +3725,7 @@
 0.000000 | HookCallFunction Option::set_change_handler(Input::default_reader, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)
 0.000000 | HookCallFunction Option::set_change_handler(KRB::ignored_errors, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)
 0.000000 | HookCallFunction Option::set_change_handler(Log::default_rotation_dir, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)
+0.000000 | HookCallFunction Option::set_change_handler(Log::default_rotation_postprocessor_cmd_env, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)
 0.000000 | HookCallFunction Option::set_change_handler(MQTT::max_payload_size, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)
 0.000000 | HookCallFunction Option::set_change_handler(NetControl::default_priority, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)
 0.000000 | HookCallFunction Option::set_change_handler(Notice::alarmed_types, Config::config_option_changed{ if (<skip-config-log> == Config::location) return (Config::new_value)Config::log = Config::Info($ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value))if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, to_any_coerceConfig::log)return (Config::new_value)}, -100)

testing/btest/Baseline/scripts.base.frameworks.logging.rotate-pp-env/out

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

testing/btest/scripts/base/frameworks/logging/rotate-pp-env.zeek

@@ -0,0 +1,32 @@
+# @TEST-DOC: Using a custom environment for the postprocessor command.
+# @TEST-EXEC: ZEEK_ARG_EXTERNAL=external zeek -b -r ${TRACES}/rotation.trace %INPUT >out 2>&1
+# @TEST-EXEC: btest-diff out
+
+module Test;
+
+export {
+	redef enum Log::ID += { LOG };
+
+	type Log: record {
+		t: time;
+		id: conn_id;
+	} &log;
+}
+
+redef Log::default_rotation_interval = 1hr;
+redef Log::default_rotation_postprocessor_cmd = "env | grep ZEEK_ARG | sort; true ";
+
+redef Log::default_rotation_postprocessor_cmd_env += {
+	["REDEF"] = "redef",
+};
+
+event zeek_init()
+	{
+	Log::create_stream(Test::LOG, [$columns=Log]);
+	Log::default_rotation_postprocessor_cmd_env["INIT"] = "zeek_init";
+	}
+
+event new_connection(c: connection)
+	{
+	Log::write(Test::LOG, [$t=network_time(), $id=c$id]);
+	}