diff --git a/src/Event.cc b/src/Event.cc index 065cee5839..b5935b9527 100644 --- a/src/Event.cc +++ b/src/Event.cc @@ -7,7 +7,6 @@ #include "zeek/Desc.h" #include "zeek/Func.h" #include "zeek/NetVar.h" -#include "zeek/RunState.h" #include "zeek/Trigger.h" #include "zeek/Val.h" #include "zeek/iosource/Manager.h" @@ -19,10 +18,11 @@ zeek::EventMgr zeek::event_mgr; namespace zeek { -Event::Event(EventHandlerPtr arg_handler, zeek::Args arg_args, util::detail::SourceID arg_src, - analyzer::ID arg_aid, Obj* arg_obj) - : handler(arg_handler), args(std::move(arg_args)), src(arg_src), aid(arg_aid), obj(arg_obj), - next_event(nullptr) +Event::Event(const EventHandlerPtr& arg_handler, zeek::Args arg_args, + util::detail::SourceID arg_src, analyzer::ID arg_aid, Obj* arg_obj, + double arg_timestamp) + : handler(arg_handler), args(std::move(arg_args)), src(arg_src), aid(arg_aid), + timestamp(arg_timestamp), obj(arg_obj), next_event(nullptr) { if ( obj ) Ref(obj); @@ -74,6 +74,7 @@ EventMgr::EventMgr() head = tail = nullptr; current_src = util::detail::SOURCE_LOCAL; current_aid = 0; + current_ts = 0; src_val = nullptr; draining = false; } @@ -120,6 +121,8 @@ void EventMgr::QueueEvent(Event* event) void EventMgr::Dispatch(Event* event, bool no_remote) { current_src = event->Source(); + current_aid = event->Analyzer(); + current_ts = event->Time(); event->Dispatch(no_remote); Unref(event); } @@ -154,6 +157,7 @@ void EventMgr::Drain() current_src = current->Source(); current_aid = current->Analyzer(); + current_ts = current->Time(); current->Dispatch(); Unref(current); diff --git a/src/Event.h b/src/Event.h index dc3e931bd8..4dda7f679d 100644 --- a/src/Event.h +++ b/src/Event.h @@ -15,14 +15,19 @@ namespace zeek { +namespace run_state + { +extern double network_time; + } // namespace run_state + class EventMgr; class Event final : public Obj { public: - Event(EventHandlerPtr handler, zeek::Args args, + Event(const EventHandlerPtr& handler, zeek::Args args, util::detail::SourceID src = util::detail::SOURCE_LOCAL, analyzer::ID aid = 0, - Obj* obj = nullptr); + Obj* obj = nullptr, double timestamp = run_state::network_time); void SetNext(Event* n) { next_event = n; } Event* NextEvent() const { return next_event; } @@ -31,6 +36,7 @@ public: analyzer::ID Analyzer() const { return aid; } EventHandlerPtr Handler() const { return handler; } const zeek::Args& Args() const { return args; } + double Time() const { return timestamp; } void Describe(ODesc* d) const override; @@ -45,6 +51,7 @@ protected: zeek::Args args; util::detail::SourceID src; analyzer::ID aid; + double timestamp; Obj* obj; Event* next_event; }; @@ -95,6 +102,10 @@ public: // non-analyzer event. analyzer::ID CurrentAnalyzer() const { return current_aid; } + // Returns the timestamp of the last raised event. The timestamp reflects the network time + // the event was created. + double CurrentEventTime() const { return current_ts; } + int Size() const { return num_events_queued - num_events_dispatched; } void Describe(ODesc* d) const override; @@ -114,6 +125,7 @@ protected: Event* tail; util::detail::SourceID current_src; analyzer::ID current_aid; + double current_ts; RecordVal* src_val; bool draining; detail::Flare queue_flare; diff --git a/src/zeek.bif b/src/zeek.bif index b0e3c6611a..ac18b1817e 100644 --- a/src/zeek.bif +++ b/src/zeek.bif @@ -354,6 +354,17 @@ function set_network_time%(nt: time%): bool return zeek::val_mgr->True(); %} +## Returns the timestamp of the last raised event. The timestamp reflects the +## network time the event was created. +## +## Returns: The timestamp of the last raised event. +## +## .. zeek:see:: current_time set_network_time +function current_event_time%(%): time + %{ + return zeek::make_intrusive(zeek::event_mgr.CurrentEventTime()); + %} + ## Returns a system environment variable. ## ## var: The name of the variable whose value to request. diff --git a/testing/btest/Baseline/language.event-ts/out b/testing/btest/Baseline/language.event-ts/out new file mode 100644 index 0000000000..7ced6e45a0 --- /dev/null +++ b/testing/btest/Baseline/language.event-ts/out @@ -0,0 +1,51 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +>> Run 0 (1989-12-12-22:00:00): +[1989-12-12-22:00:00] Test 4 was scheduled at 1989-12-12-22:00:00 +[1989-12-12-22:00:00] Test 3 was scheduled at 1989-12-12-22:00:00 +[1989-12-12-22:00:00] Test 2 was scheduled at 1989-12-12-22:00:00 +[1989-12-12-22:00:01] Test 1 was scheduled at 1989-12-12-22:00:00 +>> Run 1 (1989-12-12-22:00:01): +[1989-12-12-22:00:01] Test 4 was scheduled at 1989-12-12-22:00:01 +[1989-12-12-22:00:01] Test 3 was scheduled at 1989-12-12-22:00:01 +[1989-12-12-22:00:01] Test 2 was scheduled at 1989-12-12-22:00:01 +[1989-12-12-22:00:02] Test 1 was scheduled at 1989-12-12-22:00:01 +>> Run 2 (1989-12-12-22:00:02): +[1989-12-12-22:00:02] Test 4 was scheduled at 1989-12-12-22:00:02 +[1989-12-12-22:00:02] Test 3 was scheduled at 1989-12-12-22:00:02 +[1989-12-12-22:00:02] Test 2 was scheduled at 1989-12-12-22:00:02 +[1989-12-12-22:00:03] Test 1 was scheduled at 1989-12-12-22:00:02 +>> Run 3 (1989-12-12-22:00:03): +[1989-12-12-22:00:03] Test 4 was scheduled at 1989-12-12-22:00:03 +[1989-12-12-22:00:03] Test 3 was scheduled at 1989-12-12-22:00:03 +[1989-12-12-22:00:03] Test 2 was scheduled at 1989-12-12-22:00:03 +[1989-12-12-22:00:04] Test 1 was scheduled at 1989-12-12-22:00:03 +>> Run 4 (1989-12-12-22:00:04): +[1989-12-12-22:00:04] Test 4 was scheduled at 1989-12-12-22:00:04 +[1989-12-12-22:00:04] Test 3 was scheduled at 1989-12-12-22:00:04 +[1989-12-12-22:00:04] Test 2 was scheduled at 1989-12-12-22:00:04 +[1989-12-12-22:00:05] Test 1 was scheduled at 1989-12-12-22:00:04 +>> Run 5 (1989-12-12-22:00:05): +[1989-12-12-22:00:05] Test 4 was scheduled at 1989-12-12-22:00:05 +[1989-12-12-22:00:05] Test 3 was scheduled at 1989-12-12-22:00:05 +[1989-12-12-22:00:05] Test 2 was scheduled at 1989-12-12-22:00:05 +[1989-12-12-22:00:06] Test 1 was scheduled at 1989-12-12-22:00:05 +>> Run 6 (1989-12-12-22:00:06): +[1989-12-12-22:00:06] Test 4 was scheduled at 1989-12-12-22:00:06 +[1989-12-12-22:00:06] Test 3 was scheduled at 1989-12-12-22:00:06 +[1989-12-12-22:00:06] Test 2 was scheduled at 1989-12-12-22:00:06 +[1989-12-12-22:00:07] Test 1 was scheduled at 1989-12-12-22:00:06 +>> Run 7 (1989-12-12-22:00:07): +[1989-12-12-22:00:07] Test 4 was scheduled at 1989-12-12-22:00:07 +[1989-12-12-22:00:07] Test 3 was scheduled at 1989-12-12-22:00:07 +[1989-12-12-22:00:07] Test 2 was scheduled at 1989-12-12-22:00:07 +[1989-12-12-22:00:08] Test 1 was scheduled at 1989-12-12-22:00:07 +>> Run 8 (1989-12-12-22:00:08): +[1989-12-12-22:00:08] Test 4 was scheduled at 1989-12-12-22:00:08 +[1989-12-12-22:00:08] Test 3 was scheduled at 1989-12-12-22:00:08 +[1989-12-12-22:00:08] Test 2 was scheduled at 1989-12-12-22:00:08 +[1989-12-12-22:00:09] Test 1 was scheduled at 1989-12-12-22:00:08 +>> Run 9 (1989-12-12-22:00:09): +[1989-12-12-22:00:09] Test 4 was scheduled at 1989-12-12-22:00:09 +[1989-12-12-22:00:09] Test 3 was scheduled at 1989-12-12-22:00:09 +[1989-12-12-22:00:09] Test 2 was scheduled at 1989-12-12-22:00:09 +[1989-12-12-22:00:09] Test 1 was scheduled at 1989-12-12-22:00:09 diff --git a/testing/btest/Traces/ticks-dns.pcap b/testing/btest/Traces/ticks-dns.pcap new file mode 100644 index 0000000000..41a9b3d74b Binary files /dev/null and b/testing/btest/Traces/ticks-dns.pcap differ diff --git a/testing/btest/language/event-ts.zeek b/testing/btest/language/event-ts.zeek new file mode 100644 index 0000000000..f35c3e5994 --- /dev/null +++ b/testing/btest/language/event-ts.zeek @@ -0,0 +1,28 @@ +# @TEST-EXEC: zeek -b -r $TRACES/ticks-dns.pcap %INPUT > out +# @TEST-EXEC: btest-diff out + +# Note: We use a PCAP with DNS queries only so that we have a single packet per +# time step. Thus the run loop will be executed only once per time step. + +global runs = -1; + +event test(depth: count) + { + if ( depth == 0 ) + return; + + print fmt("[%D] Test %s was scheduled at %D", network_time(), depth, current_event_time()); + event test(--depth); + } + +event new_connection(c: connection) + { + print fmt(">> Run %s (%D):", ++runs, network_time()); + # Descend into recursion to enqueue events until we add an event that will + # be handled in the next run loop iteration, i.e. at a different timestamp + # than it was enqueued. Use four levels of recursion as every drain of the + # event queue handles two layers and the event queue is drained two times. + # First after processing a packet and second in the run loop. Finally, we + # expect an event so that network_time() > current_event_time(). + event test(4); + }