Pull request #4297: flow: Connection profiling feature

Merge in SNORT/snort3 from ~OSTEPANO/snort3:connection_profiling to master

Squashed commit of the following:

commit defdedb08111c9d4358e2a7b8f153d50bf38ad15
Author: Sreeja Athirkandathil Narayanan <sathirka@cisco.com>
Date:   Fri Mar 15 14:51:44 2024 -0400

    flow: Connection profiling feature

diff --git a/src/flow/flow.cc b/src/flow/flow.cc
index cba3e0264d385d82778f3519465cc69c729b210a..c870cf692f7b68924dd4767ae60f3df36195e565 100644 (file)
--- a/src/flow/flow.cc
+++ b/src/flow/flow.cc
@@ -36,6 +36,7 @@
 #include "protocols/tcp.h"
 #include "pub_sub/intrinsic_event_ids.h"
 #include "sfip/sf_ip.h"
+#include "time/clock_defs.h"
 #include "utils/stats.h"
 #include "utils/util.h"
 
@@ -106,6 +107,9 @@ inline void Flow::clean()
     delete bitop;
     bitop = nullptr;
     filtering_state.clear();
+
+    inspected_packet_count = 0;
+    inspection_duration = 0;
 }
 
 void Flow::flush(bool do_cleanup)
@@ -199,6 +203,25 @@ void Flow::trust()
     disable_inspection();
 }
 
+uint64_t Flow::fetch_add_inspection_duration()
+{
+    if (inspected_packet_count != 0)
+        return get_inspection_duration();
+
+    auto c = DetectionEngine::get_context();
+
+    if (c and c->packet and c->packet->inspection_started_timestamp)
+    {
+        auto packet = c->packet;
+        const auto timestamp = TO_USECS_FROM_EPOCH(SnortClock::now());
+
+        add_inspection_duration(timestamp - packet->inspection_started_timestamp);
+        packet->inspection_started_timestamp = timestamp;
+    }
+
+    return get_inspection_duration();
+}
+
 int Flow::set_flow_data(FlowData* fd)
 {
     if ( !fd ) return -1;

diff --git a/src/flow/flow.h b/src/flow/flow.h
index 119000b775f7125a5ab5ebab78164ab8c48483db..84ebac467f39120d420bea4ab64e9cb2401f6b9b 100644 (file)
--- a/src/flow/flow.h
+++ b/src/flow/flow.h
@@ -43,6 +43,7 @@
 #include "protocols/layer.h"
 #include "sfip/sf_ip.h"
 #include "target_based/snort_protocols.h"
+#include "time/clock_defs.h"
 
 #define SSNFLAG_SEEN_CLIENT         0x00000001
 #define SSNFLAG_SEEN_SENDER         0x00000001
@@ -293,7 +294,13 @@ public:
     { return (flow_state <= FlowState::INSPECT) and !is_inspection_disabled(); }
 
     void set_state(FlowState fs)
-    { flow_state = fs; }
+    { 
+        flow_state = fs;
+        if (fs > FlowState::INSPECT)
+        {
+            inspected_packet_count = flowstats.client_pkts + flowstats.server_pkts;
+        }
+    }
 
     void set_client(Inspector* ins)
     {
@@ -410,9 +417,31 @@ public:
 
     bool trust_is_deferred() const
     { return deferred_trust.is_deferred(); }
- 
+
     void set_idle_timeout(unsigned timeout)
-    { idle_timeout = timeout; }  
+    { idle_timeout = timeout; }
+
+    uint16_t get_inspected_packet_count() const
+    { return inspected_packet_count ? inspected_packet_count : (flowstats.client_pkts + flowstats.server_pkts); }
+
+    void add_inspection_duration(const uint64_t& duration)
+    {
+        if (inspected_packet_count != 0)
+            return;
+
+        inspection_duration += duration;
+    }
+
+    uint64_t get_inspection_duration() const
+    {
+#ifdef USE_TSC_CLOCK
+        return clock_usecs(inspection_duration.load());
+#else
+        return inspection_duration.load();
+#endif
+    }
+
+    uint64_t fetch_add_inspection_duration();
 
 public:  // FIXIT-M privatize if possible
     // fields are organized by initialization and size to minimize
@@ -518,6 +547,8 @@ public:  // FIXIT-M privatize if possible
 
 private:
     void clean();
+    std::atomic_ullong inspection_duration{0};
+    uint16_t inspected_packet_count{0};
 };
 
 inline void Flow::set_to_client_detection(bool enable)

diff --git a/src/flow/test/flow_test.cc b/src/flow/test/flow_test.cc
index db41870a75bb6c8ea1a565837388fdca01d621af..560eeb24dfc917fbc700a3e5c3c2acb4c1b74a2b 100644 (file)
--- a/src/flow/test/flow_test.cc
+++ b/src/flow/test/flow_test.cc
@@ -36,6 +36,7 @@
 #include "protocols/ip.h"
 #include "protocols/layer.h"
 #include "protocols/packet.h"
+#include "time/clock_defs.h"
 
 #include <CppUTest/CommandLineTestRunner.h>
 #include <CppUTest/TestHarness.h>
@@ -70,6 +71,9 @@ DetectionEngine::DetectionEngine() { context = nullptr; }
 
 DetectionEngine::~DetectionEngine() = default;
 
+Packet test_packet;
+Packet* DetectionEngine::get_current_packet() { return &test_packet; }
+
 bool layer::set_outer_ip_api(const Packet* const, ip::IpApi&, int8_t&)
 { return false; }
 
@@ -103,6 +107,36 @@ TEST(nondefault_timeout, hard_expiration)
     delete flow;
 }
 
+TEST_GROUP(inspection_time_presence)
+{
+};
+
+TEST(inspection_time_presence, inspection_time_addition)
+{
+    Flow *flow = new Flow;
+
+    flow->flowstats.client_pkts = 3;
+    flow->flowstats.server_pkts = 3;
+
+    flow->add_inspection_duration(2);
+    flow->add_inspection_duration(3);
+
+    CHECK(flow->get_inspection_duration() == 5);
+    CHECK(flow->get_inspected_packet_count() == 6);
+
+    flow->set_state(Flow::FlowState::ALLOW);
+
+    flow->add_inspection_duration(2);
+
+    flow->flowstats.client_pkts = 5;
+    flow->flowstats.server_pkts = 5;
+
+    CHECK(flow->get_inspection_duration() == 5);
+    CHECK(flow->get_inspected_packet_count() == 6);
+
+    delete flow;
+}
+
 int main(int argc, char** argv)
 {
     int return_value = CommandLineTestRunner::RunAllTests(argc, argv);

diff --git a/src/managers/inspector_manager.cc b/src/managers/inspector_manager.cc
index dd73991ff0874e61d6e34f1eaeecdb1de6f6a5fb..aa58eb756f7cdc6f89026dac4c094dd857b51e44 100644 (file)
--- a/src/managers/inspector_manager.cc
+++ b/src/managers/inspector_manager.cc
@@ -41,6 +41,7 @@
 #include "main/snort_module.h"
 #include "main/thread_config.h"
 #include "protocols/packet.h"
+#include "profiler/profiler_defs.h"
 #include "pub_sub/intrinsic_event_ids.h"
 #include "search_engines/search_tool.h"
 #include "target_based/snort_protocols.h"
@@ -2239,11 +2240,16 @@ inline void InspectorManager::internal_execute(Packet* p)
 // new it_xxx) is run just once per flow (and all non-flow packets).
 void InspectorManager::execute(Packet* p)
 {
+    p->inspection_started_timestamp = TO_USECS_FROM_EPOCH(SnortClock::now());
+
     if ( trace_enabled(snort_trace, TRACE_INSPECTOR_MANAGER, DEFAULT_TRACE_LOG_LEVEL, p) )
         internal_execute<true>(p);
     else
         internal_execute<false>(p);
 
+    if ( p->flow )
+        p->flow->add_inspection_duration(TO_USECS_FROM_EPOCH(SnortClock::now()) - p->inspection_started_timestamp);
+
     if ( p->flow && ( !p->is_cooked() or p->is_defrag() ) )
         ExpectFlow::handle_expected_flows(p);
 }

diff --git a/src/managers/test/get_inspector_stubs.h b/src/managers/test/get_inspector_stubs.h
index f13fa64151c47a138ad31f163c67b2c116bad62c..27e80aefe71d9bc40b7f89676f0f9942b4f72ac8 100644 (file)
--- a/src/managers/test/get_inspector_stubs.h
+++ b/src/managers/test/get_inspector_stubs.h
@@ -26,11 +26,14 @@
 #include "managers/inspector_manager.h"
 #include "managers/module_manager.h"
 #include "network_inspectors/binder/bind_module.h"
+#include "profiler/rule_profiler_defs.h"
+#include "profiler/time_profiler_defs.h"
 #include "search_engines/search_tool.h"
 #include "trace/trace.h"
 #include "trace/trace_api.h"
 
 THREAD_LOCAL const snort::Trace* snort_trace = nullptr;
+THREAD_LOCAL bool RuleContext::enabled = false;
 
 std::shared_ptr<PolicyTuple> PolicyMap::get_policies(Shell*) { return nullptr; }
 void InspectionPolicy::configure() { }
@@ -88,4 +91,6 @@ void set_inspection_policy(InspectionPolicy*) { }
 void set_ips_policy(IpsPolicy*) { }
 unsigned get_instance_id() { return 0; }
 void trace_vprintf(const char*, TraceLevel, const char*, const Packet*, const char*, va_list) { }
+
+THREAD_LOCAL bool TimeProfilerStats::enabled = false;
 }

diff --git a/src/protocols/packet.cc b/src/protocols/packet.cc
index 74bcc9220b1e3d667a1cc962aa2051f685a6adeb..04161f1c4bdc27932bfada67eb96d858c635e831 100644 (file)
--- a/src/protocols/packet.cc
+++ b/src/protocols/packet.cc
@@ -91,6 +91,7 @@ void Packet::reset()
     vlan_idx = 0;
     filtering_state.clear();
     sect = PS_NONE;
+    inspection_started_timestamp = 0;
 }
 
 void Packet::release_helpers()

diff --git a/src/protocols/packet.h b/src/protocols/packet.h
index 80001f6a44b8a8c609eae3adc8824a30586d06bc..c12708df7b2897f5fcd1be15f83fd5854b828531 100644 (file)
--- a/src/protocols/packet.h
+++ b/src/protocols/packet.h
@@ -164,6 +164,8 @@ struct SO_PUBLIC Packet
     uint64_t user_ips_policy_id;
     uint64_t user_network_policy_id;
 
+    uint64_t inspection_started_timestamp;
+
     uint8_t vlan_idx;
     uint8_t ts_packet_flags; // FIXIT-M packet flags should always be thread safe
 

diff --git a/src/pub_sub/test/pub_sub_eve_process_event_test.cc b/src/pub_sub/test/pub_sub_eve_process_event_test.cc
index f0734205acdaf5b70aa18c265f8ee86b4542e7c8..f2e8fc2726bd02e69e0596b584d8b130b31cc6bc 100644 (file)
--- a/src/pub_sub/test/pub_sub_eve_process_event_test.cc
+++ b/src/pub_sub/test/pub_sub_eve_process_event_test.cc
@@ -33,7 +33,7 @@ using namespace snort;
 Packet::Packet(bool)
     : flow(nullptr), packet_flags(0), xtradata_mask(0), proto_bits(0), alt_dsize(0), num_layers(0),
     disable_inspect(true), sect(PS_NONE), active_inst(nullptr), pkth(nullptr), pkt(nullptr), layers(nullptr),
-    user_inspection_policy_id(0), user_ips_policy_id(0), user_network_policy_id(0), vlan_idx(0),
+    user_inspection_policy_id(0), user_ips_policy_id(0), user_network_policy_id(0), inspection_started_timestamp(0), vlan_idx(0),
     ts_packet_flags(0), allocated(false)
 { }
 Packet::~Packet() = default;

diff --git a/src/time/clock_defs.h b/src/time/clock_defs.h
index d24d738b72a1192c948c2e65015b1e75b24387eb..2eb9fa53cacac74d0f23e2f73168a1f071f8ca45 100644 (file)
--- a/src/time/clock_defs.h
+++ b/src/time/clock_defs.h
@@ -27,6 +27,7 @@ using SnortClock = TscClock;
 #define DURA_ZERO 0
 #define TO_TICKS(t) (t)
 #define TO_USECS(t) (t)
+#define TO_USECS_FROM_EPOCH(t) (t)
 #define TO_NSECS(t) (t)
 #define TO_DURATION(v, t) (t)
 
@@ -39,6 +40,7 @@ inline long clock_scale() { return 1; }
 #define DURA_ZERO Clock::duration::zero()
 #define TO_TICKS(t) (t.count())
 #define TO_USECS(t) (std::chrono::duration_cast<std::chrono::microseconds>(t).count())
+#define TO_USECS_FROM_EPOCH(t) (TO_USECS(t.time_since_epoch()))
 #define TO_NSECS(t) (std::chrono::duration_cast<std::chrono::nanoseconds>(t).count())
 #define TO_DURATION(v, t) (std::chrono::duration_cast<decltype(v)>(std::chrono::microseconds(t)))
 #endif

diff --git a/src/time/stopwatch.h b/src/time/stopwatch.h
index c17d5b2592a5cc89e939ac945df37d46fe44cd1f..48e97c13e4166705953ba45ed423fb69c33e2f70 100644 (file)
--- a/src/time/stopwatch.h
+++ b/src/time/stopwatch.h
@@ -65,6 +65,9 @@ public:
     void cancel()
     { running = false; }
 
+    time_point get_start_time() const
+    { return start_time; }
+
 private:
     duration get_delta() const
     { return Clock::now() - start_time; }