Merge remote-tracking branch 'origin/topic/awelzel/try-update-network-time'

* origin/topic/awelzel/try-update-network-time:
  NEWS: Some notes about timing related changes
  iosource: Remove non-existing ManagerBase friend
  broker::Manager: use_realtime_false when allow_network_time_forward=F
  A set of tests around set_network_time() and timer expiration
  Remove suspend-processing test
  Add a set of suspend_processing tests
  btest: More verbose recursive-event output
  broker::Manager: No more network_time forwarding
  TimerMgr: No network_time updates in Process()
  Event: No more network_time updates
  RunState: Implement forward_network_time_if_applicable()
  PktSrc: Add HasBeenIdleFor() method
  PktSrc: Move termination pseduo_realtime special case to RunState

CHANGES

@@ -1,3 +1,59 @@
+6.0.0-dev.266 | 2023-03-23 13:35:28 +0100
+
+  * iosource: Remove non-existing ManagerBase friend (Arne Welzel, Corelight)
+
+  * broker::Manager: use_realtime_false when allow_network_time_forward=F (Arne Welzel, Corelight)
+
+    Run the broker in non-realtime mode when allow_network_time_forward=F.
+    This may need an extra option for really advanced use-cases, but for
+    now this seems reasonable.
+
+  * A set of tests around network time handling (Arne Welzel, Corelight)
+
+  * broker::Manager: No more network_time forwarding (Arne Welzel, Corelight)
+
+    network_time forwarding will happen in the main-loop before draining the
+    EventMgr so timers/events scheduled based on broker messages should
+    behave similarly. This also keeps network_time unaffected during
+    non pseudo-realtime trace processing.
+
+  * TimerMgr: No network_time updates in Process() (Arne Welzel, Corelight)
+
+    network_time forwarding will now happen centrally in the main loop.
+    The TimerMgr returns a valid timeout that can be waited for and will
+    trigger network_time advancement, so we don't need to do it.
+
+  * Event: No more network_time updates (Arne Welzel, Corelight)
+
+    The whole docs read like this was only used to update the
+    network_time, so there may be a follow-up to ditch EventMgr
+    even being an IOSource (which could be argued it's not IO).
+
+  * RunState: Implement forward_network_time_if_applicable() (Arne Welzel, Corelight)
+
+    Add a central place where the decision when it's okay to update network time
+    to the current time (wallclock) is. It checks for pseudo_realtime and packet
+    source existence as well as packet source idleness.
+
+    A new const &redef allows to completely disable forwarding of network time.
+
+  * PktSrc: Add HasBeenIdleFor() method (Arne Welzel, Corelight)
+
+    This method will be used by the main loop to determine if an interface
+    has become idle. Initially this will be used to determine when it is
+    acceptable to update network_time to the current time (wallclock).
+
+  * PktSrc: Move termination pseduo_realtime special case to RunState (Arne Welzel, Corelight)
+
+    This also removes setting pseduo_realtime to 0.0 in the main loop
+    when the packet source has been closed. I had tried to understand
+    the implications it actually seems, if we shutdown the iosource::Manager
+    anyway, it shouldn't and it's just confusing.
+
+  * Bump zeekctl and doc submodule for updates regarding Site::local_nets (Christian Kreibich, Corelight)
+
+  * Update doc submodule [nomail] [skip ci] (zeek-bot)
+
 6.0.0-dev.250 | 2023-03-21 19:17:36 +0100
 
   * Expr: Factor out type tag extraction (Arne Welzel, Corelight)

NEWS

@@ -93,6 +93,11 @@ New Functionality
 
 - The supervisor framework can now start worker nodes that read from a trace file.
 
+- Zeek can be prevented from updating ``network_time()`` to the current time
+  by setting ``allow_network_time_forward=F``. Together with ``set_network_time()``
+  or a custom plugin, this allows control of ``network_time()`` without Zeek
+  interfering.
+
 Changed Functionality
 ---------------------
 
@@ -125,6 +130,37 @@ Changed Functionality
   ``io_poll_interval_live`` for ease of testing, development and debugging
   of the main-loop.
 
+- Zeek does not arbitrarily update ``network_time()`` to current time anymore.
+  When a packet source is providing a constant stream of packets, packets
+  drive network time. Previously, Zeek updated network time to the current
+  current time in various situations, disregarding timestamps of network packets.
+  Zeek will now update ``network_time()`` only when a packet source has been
+  inactive/idle for an interval of ``packet_source_inactivity_timeout``
+  (default 100msec). When a worker process suddenly observes no packets, timer
+  expiration may initially be delayed by ``packet_source_inactivity_timeout``.
+
+- Calling ``suspend_processing()`` when reading traces does not update network
+  time to the current time anymore. Instead, Zeek keeps ``network_time()`` according
+  to the trace file. This causes scheduled events to not fire once ``suspend_processing()``
+  is called. However, this appears more sensible behavior than arbitrarily setting
+  ``network_time()`` to the current time. Processing can still be continued from
+  broker events or input readers.
+
+- Previously, Zeek would process and dispatch events for the very first packet
+  in a trace file in order to initialize time, even if ``suspend_processing()``
+  was called in a ``zeek_init()`` handler. This has been changed such that the
+  first packet will only be processed once ``continue_processing()`` has been
+  invoked again. Some background around the previous behaviour can be found
+  in GH-938. With the availability of ``network_time_init()``, this behavior
+  seems more reasonable.
+
+- If an event is scheduled with a 0.0sec timeout from a ``zeek_init()`` handler
+  that also executes a ``suspend_processing()``, the scheduled event will fire
+  immediately with ``network_time()`` still yielding ``0.0``. Previously,
+  ``network_time()`` was set to the current time. The new behavior is considered
+  more sensible with regards of determinism and in line with timers stopping
+  during a ``suspend_processing()``.
+
 Removed Functionality
 ---------------------
 

VERSION

@@ -1 +1 @@
-6.0.0-dev.250
+6.0.0-dev.266

scripts/base/init-bare.zeek

@@ -161,6 +161,32 @@ type PacketSource: record {
 	netmask: count;
 };
 
+
+## If a packet source does not yield packets for this amount of time,
+## it is considered idle. When a packet source is found to be idle,
+## Zeek will update network_time to current time in order for timer expiration
+## to function. A packet source queueing up packets and not yielding them for
+## longer than this interval without yielding any packets will provoke
+## not-very-well-defined timer behavior.
+##
+## On Zeek workers with low packet rates, timer expiration may be delayed
+## by this many milliseconds after the last packet has been received.
+const packet_source_inactivity_timeout = 100msec &redef;
+
+## Whether Zeek will forward network_time to the current time upon
+## observing an idle packet source (or no configured packet source).
+##
+## Only set this to *F* if you really know what you're doing. Setting this to
+## *F* on non-worker systems causes :zeek:see:`network_time` to be stuck
+## at 0.0 and timer expiration will be non-functional.
+##
+## The main purpose of this option is to yield control over network time
+## to plugins or scripts via broker or other non-timer events.
+##
+## .. zeek:see:: network_time set_network_time packet_source_inactivity_timeout
+##
+const allow_network_time_forward = T &redef;
+
 ## A connection's transport-layer protocol. Note that Zeek uses the term
 ## "connection" broadly, using flow semantics for ICMP and UDP.
 type transport_proto: enum {

src/Event.cc

@@ -189,22 +189,12 @@ void EventMgr::Describe(ODesc* d) const
 
 void EventMgr::Process()
 	{
-	// If we don't have a source, or the source is closed, or we're
-	// reading live (which includes pseudo-realtime), advance the time
-	// here to the current time since otherwise it won't move forward.
-	iosource::PktSrc* pkt_src = iosource_mgr->GetPktSrc();
-	if ( ! pkt_src || ! pkt_src->IsOpen() || run_state::reading_live )
-		run_state::detail::update_network_time(util::current_time());
-
 	queue_flare.Extinguish();
 
 	// While it semes like the most logical thing to do, we dont want
 	// to call Drain() as part of this method. It will get called at
 	// the end of net_run after all of the sources have been processed
-	// and had the opportunity to spawn new events. We could use
+	// and had the opportunity to spawn new events.
-	// zeek::iosource_mgr->Wakeup() instead of making EventMgr an IOSource,
-	// but then we couldn't update the time above and nothing would
-	// drive it forward.
 	}
 
 void EventMgr::InitPostScript()

src/RunState.cc

@@ -137,6 +137,44 @@ void update_network_time(double new_network_time)
 	PLUGIN_HOOK_VOID(HOOK_UPDATE_NETWORK_TIME, HookUpdateNetworkTime(new_network_time));
 	}
 
+// Logic to decide when updating network_time is acceptable:
+static bool should_forward_network_time()
+	{
+	// In pseudo_realtime mode, always update time once
+	// we've dispatched and processed the first packet.
+	// run_state::detail::first_timestamp is currently set
+	// in PktSrc::ExtractNextPacketInternal()
+	if ( pseudo_realtime != 0.0 && run_state::detail::first_timestamp != 0.0 )
+		return true;
+
+	if ( iosource::PktSrc* ps = iosource_mgr->GetPktSrc() )
+		{
+		// Offline packet sources always control network time
+		// unless we're running pseudo_realtime, see above.
+		if ( ! ps->IsLive() )
+			return false;
+
+		if ( ! ps->HasBeenIdleFor(BifConst::packet_source_inactivity_timeout) )
+			return false;
+		}
+
+	// We determined that we don't have a packet source, or it is idle.
+	// Unless it has been disabled, network_time will now be moved forward.
+	return BifConst::allow_network_time_forward;
+	}
+
+static void forward_network_time_if_applicable()
+	{
+	if ( ! should_forward_network_time() )
+		return;
+
+	double now = util::current_time(true);
+	if ( now > network_time )
+		update_network_time(now);
+
+	return;
+	}
+
 void init_run(const std::optional<std::string>& interface,
               const std::optional<std::string>& pcap_input_file,
               const std::optional<std::string>& pcap_output_file, bool do_watchdog)
@@ -319,21 +357,21 @@ void run_loop()
 			// date on timers and events.  Because we only
 			// have timers as sources, going to sleep here
 			// doesn't risk blocking on other inputs.
-			update_network_time(util::current_time());
+			//
+			// TBD: Is this actually still relevant given that the TimerMgr
+			//      is an IO source now? It'll be processed once its
+			//      GetNextTimeout() yields 0 and before that there's nothing
+			//      to expire anyway.
+			forward_network_time_if_applicable();
 			expire_timers();
+
+			// Prevent another forward_network_time_if_applicable() below
+			// even if time wasn't actually updated.
+			time_updated = true;
 			}
 
-		// Ensure that the time gets updated every pass if we're reading live.
+		if ( ! time_updated )
-		// This is necessary for e.g. packet sources that don't have a selectable
+			forward_network_time_if_applicable();
-		// file descriptor. They'll always be ready on a very short timeout, but
-		// won't necessarily have a packet to process. In these case, sometimes
-		// the time won't get updated for a long time and timers don't function
-		// correctly.
-		if ( (! time_updated && reading_live) )
-			{
-			update_network_time(util::current_time());
-			expire_timers();
-			}
 
 		event_mgr.Drain();
 
@@ -352,17 +390,13 @@ void run_loop()
 			// the future on which we need to wait.
 			have_pending_timers = zeek::detail::timer_mgr->Size() > 0;
 
+		// Terminate if we're running pseudo_realtime and
+		// the interface has been closed.
 		if ( pseudo_realtime && communication_enabled )
 			{
-			auto have_active_packet_source = false;
-
 			iosource::PktSrc* ps = iosource_mgr->GetPktSrc();
-			if ( ps && ps->IsOpen() )
+			if ( ps && ! ps->IsOpen() )
-				have_active_packet_source = true;
+				iosource_mgr->Terminate();
-
-			if ( ! have_active_packet_source )
-				// Can turn off pseudo realtime now
-				pseudo_realtime = 0.0;
 			}
 		}
 

src/Timer.cc

@@ -93,14 +93,6 @@ int TimerMgr::Advance(double arg_t, int max_expire)
 
 void TimerMgr::Process()
 	{
-	// If we don't have a source, or the source is closed, or we're reading live (which includes
-	// pseudo-realtime), advance the timer here to the current time since otherwise it won't
-	// move forward and the timers won't fire correctly.
-	iosource::PktSrc* pkt_src = iosource_mgr->GetPktSrc();
-	if ( ! pkt_src || ! pkt_src->IsOpen() || run_state::reading_live ||
-	     run_state::is_processing_suspended() )
-		run_state::detail::update_network_time(util::current_time());
-
 	// Just advance the timer manager based on the current network time. This won't actually
 	// change the time, but will dispatch any timers that need dispatching.
 	run_state::current_dispatched += Advance(run_state::network_time,

src/broker/Manager.cc

@@ -262,6 +262,12 @@ void Manager::InitPostScript()
 	zeek_table_db_directory =
 		get_option("Broker::table_store_db_directory")->AsString()->CheckString();
 
+	// If Zeek's forwarding of network time to wallclock time was disabled,
+	// assume that also Broker does not use realtime and instead receives
+	// time via explicit AdvanceTime() calls.
+	if ( ! get_option("allow_network_time_forward")->AsBool() )
+		use_real_time = false;
+
 	detail::opaque_of_data_type = make_intrusive<OpaqueType>("Broker::Data");
 	detail::opaque_of_set_iterator = make_intrusive<OpaqueType>("Broker::SetIterator");
 	detail::opaque_of_table_iterator = make_intrusive<OpaqueType>("Broker::TableIterator");
@@ -1140,11 +1146,6 @@ void Manager::DispatchMessage(const broker::topic& topic, broker::data msg)
 
 void Manager::Process()
 	{
-	// Ensure that time gets update before processing broker messages, or events
-	// based on them might get scheduled wrong.
-	if ( use_real_time )
-		run_state::detail::update_network_time(util::current_time());
-
 	auto messages = bstate->subscriber.poll();
 
 	bool had_input = ! messages.empty();
@@ -1221,12 +1222,18 @@ void Manager::Process()
 	if ( had_input )
 		{
 		if ( run_state::network_time == 0 )
+			{
 			// If we're getting Broker messages, but still haven't initialized
 			// run_state::network_time, may as well do so now because otherwise the
 			// broker/cluster logs will end up using timestamp 0.
+			//
+			// Do not do this when allow_network_time_forard is set to F
+			// with the assumption that this is unwanted behavior.
+			if ( get_option("allow_network_time_forward")->AsBool() )
 				run_state::detail::update_network_time(util::current_time());
 			}
 		}
+	}
 
 void Manager::ProcessStoreEventInsertUpdate(const TableValPtr& table, const std::string& store_id,
                                             const broker::data& key, const broker::data& data,

src/const.bif

@@ -2,6 +2,8 @@
 ##! internally.  Documentation and default values for the scripting-layer
 ##! variables themselves are found in :doc:`/scripts/base/init-bare.zeek`.
 
+const packet_source_inactivity_timeout: interval;
+const allow_network_time_forward: bool;
 const ignore_keep_alive_rexmit: bool;
 const skip_http_data: bool;
 const use_conn_size_analyzer: bool;

src/iosource/PktDumper.h

@@ -90,7 +90,6 @@ public:
 
 protected:
 	friend class Manager;
-	friend class ManagerBase;
 
 	/**
 	 * Structure to pass back information about the packet dumper to the

src/iosource/PktSrc.cc

@@ -139,6 +139,16 @@ void PktSrc::Done()
 		Close();
 	}
 
+bool PktSrc::HasBeenIdleFor(double interval) const
+	{
+	if ( have_packet || had_packet )
+		return false;
+
+	// Take the hit of a current_time() call now.
+	double now = zeek::util::current_time(true);
+	return idle_at_wallclock < now - interval;
+	};
+
 void PktSrc::Process()
 	{
 	if ( ! IsOpen() )
@@ -191,13 +201,19 @@ bool PktSrc::ExtractNextPacketInternal()
 		}
 	else
 		{
-		had_packet = false;
+		// Update the idle_at timestamp the first time we've failed
+		// to extract a packet. This assumes ExtractNextPacket() is
+		// called regularly which is true for non-selectable PktSrc
+		// instances, but even for selectable ones with an FD the
+		// main-loop will call Process() on the interface regularly
+		// and detect it as idle.
+		if ( had_packet )
+			{
+			DBG_LOG(DBG_PKTIO, "source %s is idle now", props.path.c_str());
+			idle_at_wallclock = zeek::util::current_time(true);
 			}
 
-	if ( run_state::pseudo_realtime && ! IsOpen() )
+		had_packet = false;
-		{
-		if ( broker_mgr->Active() )
-			iosource_mgr->Terminate();
 		}
 
 	return false;

src/iosource/PktSrc.h

@@ -88,6 +88,24 @@ public:
 	 */
 	bool IsError() const;
 
+	/**
+	 * Return true if the source has been observed idle for the given
+	 * wallclock interval.
+	 *
+	 * The default implementation looks at failing ExtractNextPacket() calls
+	 * and keeps the wallclock timestamp when there was no packet available.
+	 * The source is considered idle when there has not been a packet since
+	 * \a interval seconds.
+	 *
+	 * Alternative implementations may check internally buffered packets
+	 * or queue lengths.
+	 *
+	 * @param interval Interval in seconds.
+	 *
+	 * @return True if the source has been idle for \a interval seconds.
+	 */
+	virtual bool HasBeenIdleFor(double interval) const;
+
 	/**
 	 * If the source encountered an error, returns a corresponding error
 	 * message. Returns an empty string otherwise.
@@ -207,7 +225,6 @@ public:
 
 protected:
 	friend class Manager;
-	friend class ManagerBase;
 
 	// Methods to use by derived classes.
 
@@ -365,6 +382,8 @@ private:
 	// Did the previous call to ExtractNextPacket() yield a packet.
 	bool had_packet;
 
+	double idle_at_wallclock = 0.0;
+
 	// For BPF filtering support.
 	std::vector<detail::BPF_Program*> filters;
 

src/zeek-setup.cc

@@ -1036,7 +1036,8 @@ SetupResult setup(int argc, char** argv, Options* zopts)
 				segment_logger = profiling_logger;
 			}
 
-		if ( ! run_state::reading_live && ! run_state::reading_traces )
+		if ( ! run_state::reading_live && ! run_state::reading_traces &&
+		     id::find_const("allow_network_time_forward")->AsBool() )
 			// Set up network_time to track real-time, since
 			// we don't have any other source for it.
 			run_state::detail::update_network_time(util::current_time());

testing/btest/Baseline/core.network_time.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

testing/btest/Baseline/core.network_time.broker/worker..stdout

@@ -0,0 +1,38 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+0.0, zeek_init: broker peering
+0.0, Broker::peer_added
+0.000, timer_tick, 1, 42.0
+42.000, timer_tick, 2, 42.25
+42.250, timer_tick, 3, 42.5
+42.500, timer, first timer (1 sec)
+42.500, timer_tick, 4, 42.75
+42.750, timer_tick, 5, 43.0
+43.000, timer_tick, 6, 43.25
+43.250, timer_tick, 7, 43.5
+43.500, timer_tick, 8, 43.75
+43.750, timer_tick, 9, 44.0
+44.000, timer_tick, 10, 44.25
+44.250, timer_tick, 11, 44.5
+44.500, timer_tick, 12, 44.75
+44.750, timer_tick, 13, 45.0
+45.000, timer, second timer (3 sec)
+45.000, timer_tick, 14, 45.25
+45.250, timer, third timer (3.5 sec)
+45.250, timer_tick, 15, 45.5
+45.500, timer_tick, 16, 45.75
+45.750, timer_tick, 17, 46.0
+46.000, timer_tick, 18, 46.25
+46.250, timer_tick, 19, 46.5
+46.500, timer_tick, 20, 46.75
+46.750, timer_tick, 21, 47.0
+47.000, timer, fourth timer (10 sec)
+47.000, timer_tick, 22, 47.25
+47.250, timer_tick, 23, 47.5
+47.500, timer_tick, 24, 47.75
+47.750, timer_tick, 25, 48.0
+48.000, timer_tick, 26, 48.25
+48.250, timer_tick, 27, 48.5
+48.500, timer_tick, 28, 48.75
+48.750, timer_tick, 29, 49.0
+49.000, timer_tick, 30, 49.25
+49.25, zeek_done

testing/btest/Baseline/core.network_time.no-update/output

@@ -0,0 +1,3 @@
+### 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_done

testing/btest/Baseline/core.network_time.set-network-time-expiration/output

@@ -0,0 +1,10 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+0.0, zeek_init (1)
+1.5, zeek_init (2)
+2.5, timer, first timer 1.0
+2.5, updating network time to 3.5
+4.0, timer, second timer
+4.0, calling terminate()
+4.0, net_done, 4.0
+4.0, timer, third timer
+4.0, zeek_done

testing/btest/Baseline/core.network_time.set-network-time/output

@@ -0,0 +1,4 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+0.0, zeek_init (1)
+1.5, zeek_init (2)
+2.5, zeek_done

testing/btest/Baseline/core.pcap.suspend-processing/.stderr

@@ -1,4 +0,0 @@
-### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
-XXXXXXXXXX.XXXXXX processing suspended
-XXXXXXXXXX.XXXXXX processing continued
-XXXXXXXXXX.XXXXXX received termination signal

testing/btest/Baseline/core.pcap.suspend-processing/output

@@ -1,23 +0,0 @@
-### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
-network_time: XXXXXXXXXX.XXXXXX
-Processing packet 1 at XXXXXXXXXX.XXXXXX
-network_time: XXXXXXXXXX.XXXXXX
-Processing packet 2 at XXXXXXXXXX.XXXXXX
-Processing packet 3 at XXXXXXXXXX.XXXXXX
-Processing packet 4 at XXXXXXXXXX.XXXXXX
-Processing packet 5 at XXXXXXXXXX.XXXXXX
-Processing packet 6 at XXXXXXXXXX.XXXXXX
-Processing packet 7 at XXXXXXXXXX.XXXXXX
-Processing packet 8 at XXXXXXXXXX.XXXXXX
-Processing packet 9 at XXXXXXXXXX.XXXXXX
-Processing packet 10 at XXXXXXXXXX.XXXXXX
-Processing packet 11 at XXXXXXXXXX.XXXXXX
-Processing packet 12 at XXXXXXXXXX.XXXXXX
-Processing packet 13 at XXXXXXXXXX.XXXXXX
-Processing packet 14 at XXXXXXXXXX.XXXXXX
-Processing packet 15 at XXXXXXXXXX.XXXXXX
-Processing packet 16 at XXXXXXXXXX.XXXXXX
-Processing packet 17 at XXXXXXXXXX.XXXXXX
-Processing packet 18 at XXXXXXXXXX.XXXXXX
-Processing packet 19 at XXXXXXXXXX.XXXXXX
-Processing packet 20 at XXXXXXXXXX.XXXXXX

testing/btest/Baseline/core.recursive-event/output

@@ -1,2 +1,22 @@
 ### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
-10
+XXXXXXXXXX.XXXXXX 0 1
+XXXXXXXXXX.XXXXXX 1 2
+XXXXXXXXXX.XXXXXX 0 3
+XXXXXXXXXX.XXXXXX 1 4
+XXXXXXXXXX.XXXXXX 0 5
+XXXXXXXXXX.XXXXXX 1 6
+XXXXXXXXXX.XXXXXX 0 7
+XXXXXXXXXX.XXXXXX 1 8
+XXXXXXXXXX.XXXXXX 0 9
+XXXXXXXXXX.XXXXXX 1 10
+XXXXXXXXXX.XXXXXX 0 11
+XXXXXXXXXX.XXXXXX 1 12
+XXXXXXXXXX.XXXXXX 0 13
+XXXXXXXXXX.XXXXXX 1 14
+XXXXXXXXXX.XXXXXX 0 15
+XXXXXXXXXX.XXXXXX 1 16
+XXXXXXXXXX.XXXXXX 0 17
+XXXXXXXXXX.XXXXXX 1 18
+XXXXXXXXXX.XXXXXX 0 19
+XXXXXXXXXX.XXXXXX 1 20
+unique_nt 11

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

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

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

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

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

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

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

testing/btest/core/network_time/broker.zeek

@@ -0,0 +1,97 @@
+# @TEST-DOC: Disable network_time forward on a worker and let a manager completely drive its network_time.
+# @TEST-PORT: BROKER_PORT
+# @TEST-EXEC: btest-bg-run manager "zeek -b ../manager.zeek"
+# @TEST-EXEC: btest-bg-run worker "zeek -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
+
+redef allow_network_time_forward = F;
+
+event zeek_init()
+	{
+	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";
+	exit(1);
+	}
+
+event timer(s: string)
+	{
+	print fmt("%.3f", network_time()), "timer", s;
+	}
+
+# The manager tells us our network_time.
+global received_ticks = 0;
+event timer_tick(ts: time) &is_used
+	{
+	++received_ticks;
+	print fmt("%.3f", network_time()), "timer_tick", received_ticks, ts;
+	set_network_time(ts);
+
+	# On the first tick, schedule a few timer for the future so
+	# that we can observe them expire.
+	if ( received_ticks == 1 )
+		{
+		schedule 0.5sec { timer("first timer (1 sec)") };
+		schedule 3sec { timer("second timer (3 sec)") };
+		schedule 3.25sec { timer("third timer (3.5 sec)") };
+		schedule 5sec { timer("fourth timer (10 sec)") };
+		}
+
+	if ( received_ticks == 30 )
+		terminate();
+	}
+
+event zeek_done()
+	{
+	print network_time(), "zeek_done";
+	}
+@TEST-END-FILE
+
+
+@TEST-START-FILE manager.zeek
+# The manager waits for a peer to appear, then starts sending timer
+# ticks until the peer is gone again.
+global timer_tick: event(ts: time);
+
+global fake_network_time = double_to_time(42.0);
+
+event zeek_init()
+	{
+	print "manager: listening";
+	Broker::listen("127.0.0.1", to_port(getenv("BROKER_PORT")));
+	}
+
+event local_tick() {
+	fake_network_time = fake_network_time + double_to_interval(0.25);
+	Broker::publish("zeek/event/my_topic", timer_tick, fake_network_time);
+	schedule 0.05 sec { local_tick() };
+}
+
+event Broker::peer_added(endpoint: Broker::EndpointInfo, msg: string)
+        {
+        print "manager: peer added, publishing do_continue_processing";
+	Broker::publish("zeek/event/my_topic", timer_tick, fake_network_time);
+	schedule 0.05 sec { local_tick() };
+        }
+
+event Broker::peer_lost(endpoint: Broker::EndpointInfo, msg: string)
+	{
+	print "manager: peer lost, terminating";
+	terminate();
+	}
+@TEST-END-FILE

testing/btest/core/network_time/no-update.zeek

@@ -0,0 +1,15 @@
+# @TEST-DOC: Ensure network_time stays 0.0 when configured that way.
+# @TEST-EXEC: zeek -b %INPUT >output
+# @TEST-EXEC: btest-diff output
+
+redef allow_network_time_forward = F;
+
+event zeek_init()
+	{
+	print network_time(), "zeek_init";
+	}
+
+event zeek_done()
+	{
+	print network_time(), "zeek_done";
+	}

testing/btest/core/network_time/set-network-time-expiration.zeek

@@ -0,0 +1,54 @@
+# @TEST-DOC: Does setting network trigger timer expiration? It should.
+# @TEST-EXEC: zeek -b %INPUT >output
+# @TEST-EXEC: btest-diff output
+
+redef allow_network_time_forward = F;
+
+# If this is F, we don't enter the IO loop :-(
+redef exit_only_after_terminate = T;
+
+event timer(s: string) {
+	print network_time(), "timer", s;
+	if ( /first timer/ in s )
+		{
+		print network_time(), "updating network time to 3.5";
+		set_network_time(double_to_time(4.0));
+		}
+
+	if ( /second timer/ in s )
+		{
+		print network_time(), "calling terminate()";
+		terminate();
+		}
+}
+
+event zeek_init()
+	{
+	print network_time(), "zeek_init (1)";
+	schedule 1sec { timer("first timer 1.0") };
+	set_network_time(double_to_time(1.5));
+	}
+
+event zeek_init() &priority=-1
+	{
+	print network_time(), "zeek_init (2)";
+	# This runs at network_time=1.5, so the timer is scheduled
+	# at network_time 3.5 seconds (which the first timer will
+	# move towards).
+	schedule 2sec { timer("second timer") };
+
+	# This is expired after net_done() because it ends
+	# up at 4.5 seconds and time is not moved that far.
+	schedule 3sec { timer("third timer") };
+	set_network_time(double_to_time(2.5));
+	}
+
+event net_done(t: time)
+	{
+	print network_time(), "net_done", t;
+	}
+
+event zeek_done()
+	{
+	print network_time(), "zeek_done";
+	}

testing/btest/core/network_time/set-network-time.zeek

@@ -0,0 +1,22 @@
+# @TEST-DOC: Ensure setting network time is reflected in following events.
+# @TEST-EXEC: zeek -b %INPUT >output
+# @TEST-EXEC: btest-diff output
+
+redef allow_network_time_forward = F;
+
+event zeek_init()
+	{
+	print network_time(), "zeek_init (1)";
+	set_network_time(double_to_time(1.5));
+	}
+
+event zeek_init() &priority=-1
+	{
+	print network_time(), "zeek_init (2)";
+	set_network_time(double_to_time(2.5));
+	}
+
+event zeek_done()
+	{
+	print network_time(), "zeek_done";
+	}

testing/btest/core/pcap/suspend-processing.zeek

@@ -1,34 +0,0 @@
-# @TEST-EXEC: zeek -b -C -r $TRACES/wikipedia.trace %INPUT >output
-# @TEST-EXEC: btest-diff output
-# @TEST-EXEC: btest-diff .stderr
-
-redef exit_only_after_terminate = T;
-
-event go_on()
-	{
-	continue_processing();
-	print fmt("network_time: %f", network_time());
-	}
-
-event pcap_init()
-	{
-	print fmt("network_time: %f", network_time());
-	suspend_processing();
-	# Some asynchronous work
-	schedule 5sec { go_on() };
-	}
-
-event zeek_init()
-	{
-	schedule 0sec { pcap_init() };
-	}
-
-global pkt_cnt: count = 0;
-
-event new_packet(c: connection, p: pkt_hdr)
-	{
-	pkt_cnt += 1;
-	print fmt("Processing packet %s at %f", pkt_cnt, network_time());
-	if ( pkt_cnt >= 20 )
-		terminate();
-	}

testing/btest/core/recursive-event.zeek

@@ -1,28 +1,34 @@
-# @TEST-EXEC: zeek -b %INPUT 2>&1 | grep -v termination | sort | uniq | wc -l | awk '{print $1}' >output
+# @TEST-EXEC: zeek -b %INPUT >output
 # @TEST-EXEC: btest-diff output
 
 # In old version, the event would keep triggering endlessly, with the network
 # time not moving forward and Zeek not terminating.
-# 
-# Note that the output will not be 20 because we still execute two rounds
-# of events every time we drain and also at startup several (currently 3)
-# rounds of events drain with the same network_time.
 
 redef exit_only_after_terminate=T;
 
 global c = 0;
+global last_nt = 0.0;
+global unique_nt: set[double];
 
 event test()
         {
 	c += 1;
+	local nt = time_to_double(network_time());
+	if ( last_nt == 0.0 )
+		last_nt = nt;
+
+	add unique_nt[nt];
+
+	print fmt("%.5f %d %d", nt, nt != last_nt, c);
+	last_nt = nt;
 
 	if ( c == 20 )
 		{
+		print fmt("unique_nt %d", |unique_nt|);
 		terminate();
 		return;
 		}
 
-        print network_time();
 	event test();
 	}
 

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

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";
+	}

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";
+	}

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";
+	}

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";
+	}

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";
+	}