cluster/supervisor: Multi-logger awareness

When multiple loggers are configured in a Supervisor controlled cluster
configuration, encode extra information into the rotated filename to
identify which logger produced the log.

This is similar to the approach taken for ZeekControl, re-using the
log_suffix terminology, but as there's only a single zeek-archiver
process and no postprocessors and no other side-channel for additional
information, we encode extra metadata into the filename. zeek-archiver
is extended to recognize the special metadata part of the filename.

This also solves the issue that multiple loggers in a supervisor setup
overwrite each others log files within a single log-queue directory.
This commit is contained in:
Arne Welzel 2023-04-20 15:54:16 +02:00
parent 2f035dbc07
commit c813872915
4 changed files with 139 additions and 0 deletions

4
NEWS
View file

@ -116,6 +116,10 @@ New Functionality
``make-archive-name`` script and using the new ``ZEEK_ARG_LOG_SUFFIX``
environment variable.
- A supervisor controlled Zeek cluster is now multi-logger aware. This avoids
loggers overwriting each others log files within a single log-queue directory.
By default, a logger's name is appended to the rotated logs by zeek-archiver.
- Introduce a new command-line option ``-V`` / ``--build-info``. It produces
verbose output in JSON format about the repository state and any included
plugins.

View file

@ -22,6 +22,32 @@ redef Log::default_rotation_interval = 1 hrs;
## Alarm summary mail interval.
redef Log::default_mail_alarms_interval = 24 hrs;
## Generic log metadata rendered into the filename that zeek-archiver may interpret.
## This is populated with a log_suffix entry within zeek_init() when multiple
## logger nodes are defined in cluster-layout.zeek.
global log_metadata: table[string] of string;
## Encode the given table as zeek-archiver understood metadata part.
function encode_log_metadata(tbl: table[string] of string): string
{
local metadata_vec: vector of string;
for ( k, v in log_metadata )
{
if ( |v| == 0 ) # Assume concious decision to skip this entry.
next;
if ( /[,=]/ in k || /[,=]/ in v )
{
Reporter::warning(fmt("Invalid log_metadata: k='%s' v='%s'", k, v));
next;
}
metadata_vec += fmt("%s=%s", k, v);
}
return join_string_vec(metadata_vec, ",");
}
## This function will rotate logs in a format compatible with zeek-archiver.
## If you're using the Supervisor framework, this function will be used,
## if not, you can set :zeek:see:`Log::rotation_format_func` to this function.
@ -30,6 +56,10 @@ function archiver_rotation_format_func(ri: Log::RotationFmtInfo): Log::RotationP
local open_str = strftime(Log::default_rotation_date_format, ri$open);
local close_str = strftime(Log::default_rotation_date_format, ri$close);
local base = fmt("%s__%s__%s__", ri$path, open_str, close_str);
if ( |log_metadata| > 0 )
base = fmt("%s%s__", base, encode_log_metadata(log_metadata));
local rval = Log::RotationPath($file_basename=base);
return rval;
}
@ -42,6 +72,14 @@ redef Log::rotation_format_func = archiver_rotation_format_func;
redef LogAscii::enable_leftover_log_rotation = T;
event zeek_init()
{
if ( "log_suffix" in log_metadata )
return;
if ( Cluster::get_node_count(Cluster::LOGGER) > 1 )
log_metadata["log_suffix"] = Cluster::node;
}
@else
## Use the cluster's archive logging script.

View file

@ -0,0 +1,3 @@
### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
zeek/log-queue/test__XXXX-XX-XX-XX-XX-XX__XXXX-XX-XX-XX-XX-XX__log_suffix=logger-1__.log
zeek/log-queue/test__XXXX-XX-XX-XX-XX-XX__XXXX-XX-XX-XX-XX-XX__log_suffix=logger-2__.log

View file

@ -0,0 +1,94 @@
# @TEST-PORT: SUPERVISOR_PORT
# @TEST-PORT: LOGGER_PORT1
# @TEST-PORT: LOGGER_PORT2
# Run multiple loggers with the supervisor and verify the generated log files
# contain their node names as log_suffix metadata within the log-queue directory.
#
# @TEST-EXEC: btest-bg-run zeek zeek -j -b %INPUT
# @TEST-EXEC: btest-bg-wait 10
# @TEST-EXEC: ls zeek/log-queue/test*logger-1__.log >> logs.out
# @TEST-EXEC: ls zeek/log-queue/test*logger-2__.log >> logs.out
# @TEST-EXEC: TEST_DIFF_CANONIFIER='sed "s/[0-9][0-9]/XX/g"' btest-diff logs.out
@load base/frameworks/cluster
# Make both loggers log into the same log-queue directory.
redef Log::default_rotation_dir = "../log-queue";
global topic = "test-topic";
module Test;
export {
redef enum Log::ID += { LOG };
type Log: record {
s: string;
} &log;
}
module GLOBAL;
global pong_count = 0;
event pong()
{
++pong_count;
if ( pong_count == 2 )
terminate();
}
event ping()
{
Log::write(Test::LOG, [$s="test"]);
Broker::publish(topic, pong);
}
event zeek_init()
{
Log::create_stream(Test::LOG, [$columns=Test::Log]);
if ( Supervisor::is_supervisor() )
{
Broker::subscribe(topic);
Broker::listen("127.0.0.1", to_port(getenv("SUPERVISOR_PORT")));
Broker::peer("127.0.0.1", to_port(getenv("LOGGER_PORT1")));
Broker::peer("127.0.0.1", to_port(getenv("LOGGER_PORT2")));
local cluster: table[string] of Supervisor::ClusterEndpoint;
cluster["logger-1"] = [
$role=Supervisor::LOGGER,
$host=127.0.0.1,
$p=to_port(getenv("LOGGER_PORT1")),
];
cluster["logger-2"] = [
$role=Supervisor::LOGGER,
$host=127.0.0.1,
$p=to_port(getenv("LOGGER_PORT2")),
];
for ( n, ep in cluster )
{
local sn = Supervisor::NodeConfig($name = n);
sn$cluster = cluster;
sn$directory = n;
local res = Supervisor::create(sn);
if ( res != "" )
print fmt("failed to create node %s: %s", n, res);
}
}
else
{
Broker::subscribe(topic);
Broker::peer("127.0.0.1", to_port(getenv("SUPERVISOR_PORT")));
}
}
event Broker::peer_added(endpoint: Broker::EndpointInfo, msg: string)
{
if ( Supervisor::is_supervisor() )
Broker::publish(topic, ping);
}