From aad66b3cfffb91160c1332b43cc127762e77a418 Mon Sep 17 00:00:00 2001 From: Arne Welzel Date: Wed, 15 Mar 2023 13:03:46 +0100 Subject: [PATCH] Add a set of suspend_processing tests Placed into core/ but relies on a few not-so-core things. --- .../manager..stdout | 4 + .../worker..stdout | 8 ++ .../core.suspend_processing.config/output | 6 ++ .../output | 16 ++++ .../output | 21 +++++ .../core.suspend_processing.raw-input/output | 6 ++ .../output | 17 ++++ .../btest/core/suspend_processing/broker.zeek | 83 +++++++++++++++++++ .../btest/core/suspend_processing/config.zeek | 42 ++++++++++ .../event-from-zeek-init.zeek | 50 +++++++++++ .../core/suspend_processing/event-order.zeek | 54 ++++++++++++ .../core/suspend_processing/raw-input.zeek | 62 ++++++++++++++ .../scheduled-event-from-zeek-init.zeek | 57 +++++++++++++ 13 files changed, 426 insertions(+) create mode 100644 testing/btest/Baseline/core.suspend_processing.broker/manager..stdout create mode 100644 testing/btest/Baseline/core.suspend_processing.broker/worker..stdout create mode 100644 testing/btest/Baseline/core.suspend_processing.config/output create mode 100644 testing/btest/Baseline/core.suspend_processing.event-from-zeek-init/output create mode 100644 testing/btest/Baseline/core.suspend_processing.event-order/output create mode 100644 testing/btest/Baseline/core.suspend_processing.raw-input/output create mode 100644 testing/btest/Baseline/core.suspend_processing.scheduled-event-from-zeek-init/output create mode 100644 testing/btest/core/suspend_processing/broker.zeek create mode 100644 testing/btest/core/suspend_processing/config.zeek create mode 100644 testing/btest/core/suspend_processing/event-from-zeek-init.zeek create mode 100644 testing/btest/core/suspend_processing/event-order.zeek create mode 100644 testing/btest/core/suspend_processing/raw-input.zeek create mode 100644 testing/btest/core/suspend_processing/scheduled-event-from-zeek-init.zeek diff --git a/testing/btest/Baseline/core.suspend_processing.broker/manager..stdout b/testing/btest/Baseline/core.suspend_processing.broker/manager..stdout new file mode 100644 index 0000000000..658d123ea1 --- /dev/null +++ b/testing/btest/Baseline/core.suspend_processing.broker/manager..stdout @@ -0,0 +1,4 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +manager: listening +manager: peer added, publishing do_continue_processing +manager: peer lost, terminating diff --git a/testing/btest/Baseline/core.suspend_processing.broker/worker..stdout b/testing/btest/Baseline/core.suspend_processing.broker/worker..stdout new file mode 100644 index 0000000000..739641fb8f --- /dev/null +++ b/testing/btest/Baseline/core.suspend_processing.broker/worker..stdout @@ -0,0 +1,8 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +0.0, zeek_init: suspend_processing() +0.0, zeek_init: broker peering +0.0, Broker::peer_added +0.0, do_continue_processing +1300475167.096535, network_time_init +1300475173.475401, Pcap::file_done, <...>/wikipedia.trace +1300475173.475401, zeek_done diff --git a/testing/btest/Baseline/core.suspend_processing.config/output b/testing/btest/Baseline/core.suspend_processing.config/output new file mode 100644 index 0000000000..f0442e65bc --- /dev/null +++ b/testing/btest/Baseline/core.suspend_processing.config/output @@ -0,0 +1,6 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +0.0, zeek_init +0.0, end_of_data, intel-intel.dat, intel.dat +1300475167.096535, network_time_init +1300475173.475401, Pcap::file_done, <...>/wikipedia.trace +1300475173.475401, zeek_done diff --git a/testing/btest/Baseline/core.suspend_processing.event-from-zeek-init/output b/testing/btest/Baseline/core.suspend_processing.event-from-zeek-init/output new file mode 100644 index 0000000000..274823d7fd --- /dev/null +++ b/testing/btest/Baseline/core.suspend_processing.event-from-zeek-init/output @@ -0,0 +1,16 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +0.0, zeek_init +0.0, zeek_post +0.0, one_line, first line +1467818432.675392, network_time_init +1467818432.675392, raw_packet, [hl=20, tos=0, len=78, id=55704, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818432.675732, raw_packet, [hl=20, tos=0, len=78, id=38782, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818432.676047, raw_packet, [hl=20, tos=0, len=134, id=55705, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818432.676385, raw_packet, [hl=20, tos=0, len=134, id=38783, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818433.677322, raw_packet, [hl=20, tos=0, len=134, id=55737, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818433.677452, raw_packet, [hl=20, tos=0, len=134, id=39026, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818434.678483, raw_packet, [hl=20, tos=0, len=134, id=55959, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818434.678691, raw_packet, [hl=20, tos=0, len=134, id=39224, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818435.680481, raw_packet, [hl=20, tos=0, len=134, id=56032, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818435.680663, raw_packet, [hl=20, tos=0, len=134, id=39359, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818435.680663, zeek_done diff --git a/testing/btest/Baseline/core.suspend_processing.event-order/output b/testing/btest/Baseline/core.suspend_processing.event-order/output new file mode 100644 index 0000000000..fc0454e54a --- /dev/null +++ b/testing/btest/Baseline/core.suspend_processing.event-order/output @@ -0,0 +1,21 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +0.0, zeek_init +0.0, one_line, first line +1467818432.675392, network_time_init +1467818432.675392, new_connection, CHhAvVGS1DHFjwGM9 +1467818432.675392, raw_packet, [hl=20, tos=0, len=78, id=55704, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818432.675732, new_connection, ClEkJM2Vm5giqnMf4h +1467818432.675732, raw_packet, [hl=20, tos=0, len=78, id=38782, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818432.676047, new_connection, C4J4Th3PJpwUYZZ6gc +1467818432.676047, new_connection, CtPZjS20MLrsMUOJi2 +1467818432.676047, raw_packet, [hl=20, tos=0, len=134, id=55705, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818432.676385, new_connection, CUM0KZ3MLUfNB0cl11 +1467818432.676385, raw_packet, [hl=20, tos=0, len=134, id=38783, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818433.677322, raw_packet, [hl=20, tos=0, len=134, id=55737, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818433.677452, raw_packet, [hl=20, tos=0, len=134, id=39026, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818434.678483, raw_packet, [hl=20, tos=0, len=134, id=55959, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818434.678691, raw_packet, [hl=20, tos=0, len=134, id=39224, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818435.680481, raw_packet, [hl=20, tos=0, len=134, id=56032, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818435.680663, raw_packet, [hl=20, tos=0, len=134, id=39359, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818435.680663, Pcap::file_done, <...>/vxlan.pcap +1467818435.680663, zeek_done diff --git a/testing/btest/Baseline/core.suspend_processing.raw-input/output b/testing/btest/Baseline/core.suspend_processing.raw-input/output new file mode 100644 index 0000000000..cf1ba9fd92 --- /dev/null +++ b/testing/btest/Baseline/core.suspend_processing.raw-input/output @@ -0,0 +1,6 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +0.0, zeek_init +0.0, one_line, first line +1300475167.096535, network_time_init +1300475173.475401, Pcap::file_done, <...>/wikipedia.trace +1300475173.475401, zeek_done diff --git a/testing/btest/Baseline/core.suspend_processing.scheduled-event-from-zeek-init/output b/testing/btest/Baseline/core.suspend_processing.scheduled-event-from-zeek-init/output new file mode 100644 index 0000000000..b13d7ce3a0 --- /dev/null +++ b/testing/btest/Baseline/core.suspend_processing.scheduled-event-from-zeek-init/output @@ -0,0 +1,17 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +0.0, zeek_init +0.0, zeek_post +0.0, zeek_scheduled +0.0, one_line, first line +1467818432.675392, network_time_init +1467818432.675392, raw_packet, [hl=20, tos=0, len=78, id=55704, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818432.675732, raw_packet, [hl=20, tos=0, len=78, id=38782, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818432.676047, raw_packet, [hl=20, tos=0, len=134, id=55705, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818432.676385, raw_packet, [hl=20, tos=0, len=134, id=38783, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818433.677322, raw_packet, [hl=20, tos=0, len=134, id=55737, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818433.677452, raw_packet, [hl=20, tos=0, len=134, id=39026, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818434.678483, raw_packet, [hl=20, tos=0, len=134, id=55959, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818434.678691, raw_packet, [hl=20, tos=0, len=134, id=39224, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818435.680481, raw_packet, [hl=20, tos=0, len=134, id=56032, ttl=64, p=17, src=192.168.56.11, dst=192.168.56.12] +1467818435.680663, raw_packet, [hl=20, tos=0, len=134, id=39359, ttl=64, p=17, src=192.168.56.12, dst=192.168.56.11] +1467818435.680663, zeek_done diff --git a/testing/btest/core/suspend_processing/broker.zeek b/testing/btest/core/suspend_processing/broker.zeek new file mode 100644 index 0000000000..6bf9606773 --- /dev/null +++ b/testing/btest/core/suspend_processing/broker.zeek @@ -0,0 +1,83 @@ +# @TEST-DOC: Suspend pcap processing on a worker and wait for the manager to trigger continue processing via a broker message. Ensure network_time() is not initialized until continue_processing() is called. +# @TEST-PORT: BROKER_PORT +# @TEST-EXEC: btest-bg-run manager "zeek -b ../manager.zeek" +# @TEST-EXEC: btest-bg-run worker "zeek -r $TRACES/wikipedia.trace -b ../worker.zeek" +# @TEST-EXEC: btest-bg-wait 5 + +# @TEST-EXEC: TEST_DIFF_CANONIFIER=$SCRIPTS/diff-remove-abspath btest-diff worker/.stdout +# @TEST-EXEC: TEST_DIFF_CANONIFIER=$SCRIPTS/diff-remove-abspath btest-diff manager/.stdout + +@TEST-START-FILE worker.zeek + +# If we're not setting this, broker will initialize network_time. +redef allow_network_time_forward = F; + +event zeek_init() + { + print network_time(), "zeek_init: suspend_processing()"; + suspend_processing(); + } + +event zeek_init() &priority=-5 + { + print network_time(), "zeek_init: broker peering"; + Broker::peer("127.0.0.1", to_port(getenv("BROKER_PORT"))); + Broker::subscribe("zeek/event/my_topic"); + } + +event Broker::peer_added(endpoint: Broker::EndpointInfo, msg: string) + { + print network_time(), "Broker::peer_added"; + } + +event Broker::peer_lost(endpoint: Broker::EndpointInfo, msg: string) + { + print network_time(), "[FAIL] Broker::peer_lost"; + } + +event do_continue_processing() &is_used + { + print network_time(), "do_continue_processing"; + continue_processing(); + } + +event network_time_init() + { + print network_time(), "network_time_init"; + } + +event Pcap::file_done(path: string) + { + print network_time(), "Pcap::file_done", path; + terminate(); + } + +event zeek_done() + { + print network_time(), "zeek_done"; + } +@TEST-END-FILE + + +@TEST-START-FILE manager.zeek +# The manager waits for a peer and directly publishes do_continue_processing() +# to it. It terminates when the peer is lost. +global do_continue_processing: event(); + +event zeek_init() + { + print "manager: listening"; + Broker::listen("127.0.0.1", to_port(getenv("BROKER_PORT"))); + } + +event Broker::peer_added(endpoint: Broker::EndpointInfo, msg: string) + { + print "manager: peer added, publishing do_continue_processing"; + Broker::publish("zeek/event/my_topic", do_continue_processing); + } +event Broker::peer_lost(endpoint: Broker::EndpointInfo, msg: string) + { + print "manager: peer lost, terminating"; + terminate(); + } +@TEST-END-FILE diff --git a/testing/btest/core/suspend_processing/config.zeek b/testing/btest/core/suspend_processing/config.zeek new file mode 100644 index 0000000000..b47a4a1f9f --- /dev/null +++ b/testing/btest/core/suspend_processing/config.zeek @@ -0,0 +1,42 @@ +# @TEST-DOC: Test that finishing reading an intel file resumes processing and network_time() isn't initialized until continue_processing() happens. +# @TEST-EXEC: zeek -b -C -r $TRACES/wikipedia.trace %INPUT >output +# @TEST-EXEC: TEST_DIFF_CANONIFIER=$SCRIPTS/diff-remove-abspath btest-diff output + +@load base/frameworks/intel + + +@TEST-START-FILE intel.dat +#fields indicator indicator_type meta.source meta.desc meta.url +putty.exe Intel::FILE_NAME source1 SSH utility https://www.putty.org +zeek.exe Intel::FILE_NAME source1 A network monitor https://zeek.org +@TEST-END-FILE + +redef Intel::read_files += { "intel.dat" }; + +event Input::end_of_data(name: string, source: string) + { + print network_time(), "end_of_data", name, source; + if ( /intel.dat/ in source ) + continue_processing(); + } + +event zeek_init() + { + print network_time(), "zeek_init"; + suspend_processing(); + } + +event network_time_init() + { + print network_time(), "network_time_init"; + } + +event Pcap::file_done(path: string) + { + print network_time(), "Pcap::file_done", path; + } + +event zeek_done() + { + print network_time(), "zeek_done"; + } diff --git a/testing/btest/core/suspend_processing/event-from-zeek-init.zeek b/testing/btest/core/suspend_processing/event-from-zeek-init.zeek new file mode 100644 index 0000000000..1f89ddd135 --- /dev/null +++ b/testing/btest/core/suspend_processing/event-from-zeek-init.zeek @@ -0,0 +1,50 @@ +# @TEST-DOC: Previously, the zeek_post() event would have access to the first packet's network_time, even if suspend_processing() was called in zeek_init(). This changed in Zeek 6.0 to return 0.0 as network_time_init() is now available. +# @TEST-EXEC: echo "first line" > raw_file +# @TEST-EXEC: zeek -b -C -r $TRACES/tunnels/vxlan.pcap %INPUT >output +# @TEST-EXEC: TEST_DIFF_CANONIFIER=$SCRIPTS/diff-remove-abspath btest-diff output + +type OneLine: record { + s: string; +}; + +event one_line(desc: Input::EventDescription, e: Input::Event, s: string) { + print network_time(), "one_line", s; + continue_processing(); +} + +event zeek_post() + { + print network_time(), "zeek_post"; + } + +event zeek_init() + { + print network_time(), "zeek_init"; + event zeek_post(); + suspend_processing(); + + Input::add_event([ + $name="raw-read", + $source="./raw_file", + $reader=Input::READER_RAW, + $mode=Input::STREAM, + $fields=OneLine, + $ev=one_line, + $want_record=F, + ]); + } + +event network_time_init() + { + print network_time(), "network_time_init"; + } + +event raw_packet(p: raw_pkt_hdr) + { + print network_time(), "raw_packet", p$ip; + } + +event zeek_done() + { + print network_time(), "zeek_done"; + } diff --git a/testing/btest/core/suspend_processing/event-order.zeek b/testing/btest/core/suspend_processing/event-order.zeek new file mode 100644 index 0000000000..4d6ebea7f0 --- /dev/null +++ b/testing/btest/core/suspend_processing/event-order.zeek @@ -0,0 +1,54 @@ +# @TEST-DOC: Previously, suspend_processing() within zeek_init() would not prevent packets and connection processing, it does with Zeek 6.0 and later. +# @TEST-EXEC: echo "first line" > raw_file +# @TEST-EXEC: zeek -b -C -r $TRACES/tunnels/vxlan.pcap %INPUT >output +# @TEST-EXEC: TEST_DIFF_CANONIFIER=$SCRIPTS/diff-remove-abspath btest-diff output + +type OneLine: record { + s: string; +}; + +event one_line(desc: Input::EventDescription, e: Input::Event, s: string) { + print network_time(), "one_line", s; + continue_processing(); +} + +event zeek_init() + { + print network_time(), "zeek_init"; + suspend_processing(); + + Input::add_event([ + $name="raw-read", + $source="./raw_file", + $reader=Input::READER_RAW, + $mode=Input::STREAM, + $fields=OneLine, + $ev=one_line, + $want_record=F, + ]); + } + +event network_time_init() + { + print network_time(), "network_time_init"; + } + +event raw_packet(p: raw_pkt_hdr) + { + print network_time(), "raw_packet", p$ip; + } + +event new_connection(c: connection) + { + print network_time(), "new_connection", c$uid; + } + +event Pcap::file_done(path: string) + { + print network_time(), "Pcap::file_done", path; + } + +event zeek_done() + { + print network_time(), "zeek_done"; + } diff --git a/testing/btest/core/suspend_processing/raw-input.zeek b/testing/btest/core/suspend_processing/raw-input.zeek new file mode 100644 index 0000000000..9ba181a0da --- /dev/null +++ b/testing/btest/core/suspend_processing/raw-input.zeek @@ -0,0 +1,62 @@ +# @TEST-DOC: suspend_processing() in zeek_init() +# @TEST-EXEC: echo "first line" > raw_file +# @TEST-EXEC: zeek -b -C -r $TRACES/wikipedia.trace %INPUT >output +# @TEST-EXEC: TEST_DIFF_CANONIFIER=$SCRIPTS/diff-remove-abspath btest-diff output + +type OneLine: record { + s: string; +}; + +event one_line(desc: Input::EventDescription, e: Input::Event, s: string) + { + print network_time(), "one_line", s; + continue_processing(); + } + +event Input::end_of_data(name: string, source: string) + { + print network_time(), "end_of_data", name, source; + } + +event zeek_init() + { + print network_time(), "zeek_init"; + suspend_processing(); + + Input::add_event([ + $name="raw-read", + # Can not use a raw command here because input reading is done + # using heartbeats and those are working based off of network + # time instead of either realtime or actually propagating back + # to the main-loop when there's data ready for reading. + # + # IMO that's a bug in how things are implemented with the + # readers being poll/heartbeat based. If polling based, seems + # wallclock time would've been the better choice. + # + # A file works, because the first DoUpdate() does the job. + # + # $source="sleep 1 |", + $source="./raw_file", + $reader=Input::READER_RAW, + $mode=Input::STREAM, + $fields=OneLine, + $ev=one_line, + $want_record=F, + ]); + } + +event network_time_init() + { + print network_time(), "network_time_init"; + } + +event Pcap::file_done(path: string) + { + print network_time(), "Pcap::file_done", path; + } + +event zeek_done() + { + print network_time(), "zeek_done"; + } diff --git a/testing/btest/core/suspend_processing/scheduled-event-from-zeek-init.zeek b/testing/btest/core/suspend_processing/scheduled-event-from-zeek-init.zeek new file mode 100644 index 0000000000..2e0b2c39c8 --- /dev/null +++ b/testing/btest/core/suspend_processing/scheduled-event-from-zeek-init.zeek @@ -0,0 +1,57 @@ +# @TEST-DOC: What network_time() does an event observe that's scheduled from zeek_init() +# @TEST-EXEC: echo "first line" > raw_file +# @TEST-EXEC: zeek -b -C -r $TRACES/tunnels/vxlan.pcap %INPUT >output +# @TEST-EXEC: TEST_DIFF_CANONIFIER=$SCRIPTS/diff-remove-abspath btest-diff output + +type OneLine: record { + s: string; +}; + +event one_line(desc: Input::EventDescription, e: Input::Event, s: string) { + print network_time(), "one_line", s; + continue_processing(); +} + +event zeek_post() + { + print network_time(), "zeek_post"; + } + +event zeek_scheduled() + { + print network_time(), "zeek_scheduled"; + } + +event zeek_init() + { + print network_time(), "zeek_init"; + event zeek_post(); + schedule 0.0sec { zeek_scheduled() }; + + suspend_processing(); + + Input::add_event([ + $name="raw-read", + $source="./raw_file", + $reader=Input::READER_RAW, + $mode=Input::STREAM, + $fields=OneLine, + $ev=one_line, + $want_record=F, + ]); + } + +event network_time_init() + { + print network_time(), "network_time_init"; + } + +event raw_packet(p: raw_pkt_hdr) + { + print network_time(), "raw_packet", p$ip; + } + +event zeek_done() + { + print network_time(), "zeek_done"; + }