diff --git a/CHANGES b/CHANGES index 2a3d4662f0..95cc961d38 100644 --- a/CHANGES +++ b/CHANGES @@ -1,3 +1,22 @@ +6.0.0-dev.522 | 2023-05-09 15:19:43 +0200 + + * cluster/supervisor: Multi-logger awareness (Arne Welzel, Corelight) + + 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. + + * Bump zeek-archiver submodule (Arne Welzel, Corelight) + 6.0.0-dev.519 | 2023-05-09 11:03:32 +0200 * Fixup Val.h/Val.cc: Actually move ValFromJSON into zeek::detail (Arne Welzel, Corelight) diff --git a/NEWS b/NEWS index 119e5b3ba2..a46b1a60e9 100644 --- a/NEWS +++ b/NEWS @@ -122,13 +122,17 @@ New Functionality stats.11:18:57-11:19:00-logger-2.log.gz Previously, in a multi-logger setup, individual logger processes would overwrite - each others log files during rotation, causing data loss. + each other's log files during rotation, causing data loss. For setups with a single logger, there's no change in behavior. The naming of the final logs can be customized by providing an alternative ``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 other's 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. diff --git a/VERSION b/VERSION index 07052b4a23..b38d40a251 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -6.0.0-dev.519 +6.0.0-dev.522 diff --git a/auxil/zeek-archiver b/auxil/zeek-archiver index 2b40a6bafe..e36862b3a6 160000 --- a/auxil/zeek-archiver +++ b/auxil/zeek-archiver @@ -1 +1 @@ -Subproject commit 2b40a6bafedbbf3fba16d292fd9fe8ba6e9de1bf +Subproject commit e36862b3a6e70bf8557885e12e74cbc91507a693 diff --git a/scripts/base/frameworks/cluster/nodes/logger.zeek b/scripts/base/frameworks/cluster/nodes/logger.zeek index 1021cee100..9dedac27a0 100644 --- a/scripts/base/frameworks/cluster/nodes/logger.zeek +++ b/scripts/base/frameworks/cluster/nodes/logger.zeek @@ -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", strip(k), strip(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. diff --git a/testing/btest/Baseline/supervisor.config-cluster-multi-logger/logs.out b/testing/btest/Baseline/supervisor.config-cluster-multi-logger/logs.out new file mode 100644 index 0000000000..a9a0561636 --- /dev/null +++ b/testing/btest/Baseline/supervisor.config-cluster-multi-logger/logs.out @@ -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 diff --git a/testing/btest/supervisor/config-cluster-multi-logger.zeek b/testing/btest/supervisor/config-cluster-multi-logger.zeek new file mode 100644 index 0000000000..51a7cfb229 --- /dev/null +++ b/testing/btest/supervisor/config-cluster-multi-logger.zeek @@ -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); + }