From f2e60fdaff54095592fa30532e338c4b982bb6bf Mon Sep 17 00:00:00 2001 From: Arne Welzel Date: Tue, 22 Apr 2025 12:22:14 +0200 Subject: [PATCH] btest/cluster: Add broker logging test for sanity Not very related to the PR, but created to help provoke an issue with the broker changes. --- .../cluster.broker.logging/manager.out | 12 ++ .../test.log.normalized | 166 ++++++++++++++++++ testing/btest/cluster/broker/logging.zeek | 148 ++++++++++++++++ 3 files changed, 326 insertions(+) create mode 100644 testing/btest/Baseline/cluster.broker.logging/manager.out create mode 100644 testing/btest/Baseline/cluster.broker.logging/test.log.normalized create mode 100644 testing/btest/cluster/broker/logging.zeek diff --git a/testing/btest/Baseline/cluster.broker.logging/manager.out b/testing/btest/Baseline/cluster.broker.logging/manager.out new file mode 100644 index 0000000000..96183afb51 --- /dev/null +++ b/testing/btest/Baseline/cluster.broker.logging/manager.out @@ -0,0 +1,12 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +A zeek_init, manager +B nodes_up, 2 +B nodes_up, 3 +B nodes_up, 4 +B nodes_up, 5 +C cluster_started +D send_finish +E node_down, logger +E node_down, proxy +E node_down, worker-1 +E node_down, worker-2 diff --git a/testing/btest/Baseline/cluster.broker.logging/test.log.normalized b/testing/btest/Baseline/cluster.broker.logging/test.log.normalized new file mode 100644 index 0000000000..fcdbdbbbb5 --- /dev/null +++ b/testing/btest/Baseline/cluster.broker.logging/test.log.normalized @@ -0,0 +1,166 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +logger 1 +logger 10 +logger 11 +logger 12 +logger 13 +logger 14 +logger 15 +logger 16 +logger 17 +logger 18 +logger 19 +logger 2 +logger 20 +logger 21 +logger 22 +logger 23 +logger 24 +logger 25 +logger 26 +logger 27 +logger 28 +logger 29 +logger 3 +logger 30 +logger 31 +logger 32 +logger 33 +logger 4 +logger 5 +logger 6 +logger 7 +logger 8 +logger 9 +manager 1 +manager 10 +manager 11 +manager 12 +manager 13 +manager 14 +manager 15 +manager 16 +manager 17 +manager 18 +manager 19 +manager 2 +manager 20 +manager 21 +manager 22 +manager 23 +manager 24 +manager 25 +manager 26 +manager 27 +manager 28 +manager 29 +manager 3 +manager 30 +manager 31 +manager 32 +manager 33 +manager 4 +manager 5 +manager 6 +manager 7 +manager 8 +manager 9 +proxy 1 +proxy 10 +proxy 11 +proxy 12 +proxy 13 +proxy 14 +proxy 15 +proxy 16 +proxy 17 +proxy 18 +proxy 19 +proxy 2 +proxy 20 +proxy 21 +proxy 22 +proxy 23 +proxy 24 +proxy 25 +proxy 26 +proxy 27 +proxy 28 +proxy 29 +proxy 3 +proxy 30 +proxy 31 +proxy 32 +proxy 33 +proxy 4 +proxy 5 +proxy 6 +proxy 7 +proxy 8 +proxy 9 +worker-1 1 +worker-1 10 +worker-1 11 +worker-1 12 +worker-1 13 +worker-1 14 +worker-1 15 +worker-1 16 +worker-1 17 +worker-1 18 +worker-1 19 +worker-1 2 +worker-1 20 +worker-1 21 +worker-1 22 +worker-1 23 +worker-1 24 +worker-1 25 +worker-1 26 +worker-1 27 +worker-1 28 +worker-1 29 +worker-1 3 +worker-1 30 +worker-1 31 +worker-1 32 +worker-1 33 +worker-1 4 +worker-1 5 +worker-1 6 +worker-1 7 +worker-1 8 +worker-1 9 +worker-2 1 +worker-2 10 +worker-2 11 +worker-2 12 +worker-2 13 +worker-2 14 +worker-2 15 +worker-2 16 +worker-2 17 +worker-2 18 +worker-2 19 +worker-2 2 +worker-2 20 +worker-2 21 +worker-2 22 +worker-2 23 +worker-2 24 +worker-2 25 +worker-2 26 +worker-2 27 +worker-2 28 +worker-2 29 +worker-2 3 +worker-2 30 +worker-2 31 +worker-2 32 +worker-2 33 +worker-2 4 +worker-2 5 +worker-2 6 +worker-2 7 +worker-2 8 +worker-2 9 diff --git a/testing/btest/cluster/broker/logging.zeek b/testing/btest/cluster/broker/logging.zeek new file mode 100644 index 0000000000..a00e2c3e84 --- /dev/null +++ b/testing/btest/cluster/broker/logging.zeek @@ -0,0 +1,148 @@ +# @TEST-DOC: Startup a Broker cluster by hand, testing basic logging and node_up and node_down events on the manager. +# +# @TEST-PORT: BROKER_PORT1 +# @TEST-PORT: BROKER_PORT2 +# @TEST-PORT: BROKER_PORT3 +# @TEST-PORT: BROKER_PORT4 +# @TEST-PORT: BROKER_PORT5 +# +# @TEST-EXEC: chmod +x ./check-test-log.sh +# +# @TEST-EXEC: btest-bg-run manager "ZEEKPATH=$ZEEKPATH:.. && CLUSTER_NODE=manager zeek -b ../manager.zeek >out" +# @TEST-EXEC: btest-bg-run logger "ZEEKPATH=$ZEEKPATH:.. && CLUSTER_NODE=logger zeek -b ../other.zeek >out" +# @TEST-EXEC: btest-bg-run proxy "ZEEKPATH=$ZEEKPATH:.. && CLUSTER_NODE=proxy zeek -b ../other.zeek >out" +# @TEST-EXEC: btest-bg-run worker-1 "ZEEKPATH=$ZEEKPATH:.. && CLUSTER_NODE=worker-1 zeek -b ../other.zeek >out" +# @TEST-EXEC: btest-bg-run worker-2 "ZEEKPATH=$ZEEKPATH:.. && CLUSTER_NODE=worker-2 zeek -b ../other.zeek >out" +# +# @TEST-EXEC: btest-bg-wait 30 +# @TEST-EXEC: btest-diff test.log.normalized +# @TEST-EXEC: sort manager/out > manager.out +# @TEST-EXEC: btest-diff manager.out + +# @TEST-START-FILE cluster-layout.zeek +redef Cluster::manager_is_logger = F; + +redef Cluster::nodes = { + ["manager"] = [$node_type=Cluster::MANAGER, $ip=127.0.0.1, $p=to_port(getenv("BROKER_PORT1"))], + ["logger"] = [$node_type=Cluster::LOGGER, $ip=127.0.0.1, $p=to_port(getenv("BROKER_PORT2")), $manager="manager"], + ["proxy"] = [$node_type=Cluster::PROXY, $ip=127.0.0.1, $p=to_port(getenv("BROKER_PORT3")), $manager="manager"], + ["worker-1"] = [$node_type=Cluster::WORKER, $ip=127.0.0.1, $p=to_port(getenv("BROKER_PORT4")), $manager="manager"], + ["worker-2"] = [$node_type=Cluster::WORKER, $ip=127.0.0.1, $p=to_port(getenv("BROKER_PORT5")), $manager="manager"], +}; +# @TEST-END-FILE + +# @TEST-START-FILE common.zeek +@load frameworks/cluster/experimental + +redef Log::default_rotation_interval = 0sec; +redef Log::flush_interval = 0.01sec; + +type Info: record { + self: string &log &default=Cluster::node; + c: count &log; +}; + +redef enum Log::ID += { TEST_LOG }; + +global finish: event(name: string) &is_used; + +event zeek_init() { + print "A zeek_init", Cluster::node; + Log::create_stream(TEST_LOG, [$columns=Info, $path="test"]); +} + +const to_write = 33; +global write = 0; + +event tick() + { + ++write; + Log::write(TEST_LOG, [$c=write]); + if ( write < to_write ) + schedule 0.05sec { tick() }; + } + +event Cluster::Experimental::cluster_started() + { + print "C cluster_started"; + schedule 0.05sec { tick() }; + } +# @TEST-END-FILE + +# @TEST-START-FILE manager.zeek +@load ./common.zeek + +global nodes_up: set[string] = {"manager"}; +global nodes_down: set[string] = {"manager"}; + +event send_finish() { + print "D send_finish"; + for ( n in nodes_up ) + Cluster::publish(Cluster::node_topic(n), finish, Cluster::node); +} + +event check_test_log() { + if ( file_size("DONE") >= 0 ) { + event send_finish(); + return; + } + + system("../check-test-log.sh"); + schedule 0.1sec { check_test_log() }; +} + +event zeek_init() { + schedule 0.1sec { check_test_log() }; +} + + +event Cluster::node_up(name: string, id: string) &priority=-1 { + add nodes_up[name]; + print "B nodes_up", |nodes_up|; +} + +event Cluster::node_down(name: string, id: string) { + print "E node_down", name; + add nodes_down[name]; + if ( |nodes_down| == |Cluster::nodes| ) + terminate(); +} +# @TEST-END-FILE + +# @TEST-START-FILE other.zeek +@load ./common.zeek + +event finish(name: string) { + terminate(); +} +# @TEST-END-FILE + +# @TEST-START-FILE check-test-log.sh +#!/bin/sh +# +# This script checks logger/test.log until the expected number +# of log entries have been observed and puts a normalized version +# into the testing directory for baselining. +TEST_LOG=../logger/test.log + +if [ ! -f $TEST_LOG ]; then + echo "$TEST_LOG not found!" >&2 + exit 1; +fi + +if [ -f DONE ]; then + exit 0 +fi + +# Remove hostname and pid from node id in message. +zeek-cut self c < $TEST_LOG | sort > test.log.tmp + +# 5 times 33 = 165 +if [ $(wc -l < test.log.tmp) = 165 ]; then + echo "DONE!" >&2 + mv test.log.tmp ../test.log.normalized + echo "DONE" > DONE +fi + +exit 0 +# @TEST-END-FILE