Merge pull request #2763 in SNORT/snort3 from ~SMULKA/snort3:daq_trace to master

Squashed commit of the following:

commit 222b106f98bbade0ad7c89dbf526feea8fd1f46e
Author: smulka <smulka@cisco.com>
Date:   Sat Feb 20 15:35:35 2021 -0500

    packet_tracer: Added daq buffer to hold daq logs

diff --git a/src/flow/test/flow_cache_test.cc b/src/flow/test/flow_cache_test.cc
index 1fb570f99c050e3d1f3f001ad339a6d7cbca86ca..12ca11be9ba41db1785b86a6a3f6cab96eba6b48 100644 (file)
--- a/src/flow/test/flow_cache_test.cc
+++ b/src/flow/test/flow_cache_test.cc
@@ -59,7 +59,7 @@ PacketTracer::~PacketTracer() { }
 void PacketTracer::log(const char*, ...) { }
 void PacketTracer::open_file() { }
 void PacketTracer::dump_to_daq(Packet*) { }
-void PacketTracer::reset() { }
+void PacketTracer::reset(bool) { }
 void PacketTracer::pause() { }
 void PacketTracer::unpause() { }
 void Active::set_drop_reason(char const*) { }

diff --git a/src/flow/test/flow_control_test.cc b/src/flow/test/flow_control_test.cc
index b49bee6e0ee7abcebb79267d682f7be300085588..7b5064d25f088864ec6ff5abd7f69994b0ae0b83 100644 (file)
--- a/src/flow/test/flow_control_test.cc
+++ b/src/flow/test/flow_control_test.cc
@@ -59,7 +59,7 @@ PacketTracer::~PacketTracer() = default;
 void PacketTracer::log(const char*, ...) { }
 void PacketTracer::open_file() { }
 void PacketTracer::dump_to_daq(Packet*) { }
-void PacketTracer::reset() { }
+void PacketTracer::reset(bool) { }
 void PacketTracer::pause() { }
 void PacketTracer::unpause() { }
 void Active::set_drop_reason(char const*) { }

diff --git a/src/main/analyzer.cc b/src/main/analyzer.cc
index fc7a8de596675352251d54fd6ed31c9a14b98f7d..2aa9e40b49fe47ffa6e987cb05df4220a7cd9614 100644 (file)
--- a/src/main/analyzer.cc
+++ b/src/main/analyzer.cc
@@ -322,6 +322,9 @@ void Analyzer::post_process_daq_pkt_msg(Packet* p)
         PacketTracer::dump(p);
     }
 
+    if (PacketTracer::is_daq_activated())
+        PacketTracer::daq_dump(p);
+
     HighAvailabilityManager::process_update(p->flow, p);
 
     if (verdict != MAX_DAQ_VERDICT)

diff --git a/src/main/test/stubs.h b/src/main/test/stubs.h
index 703f4e6e6cdf77c51105b2af6f9d295d33977984..984652f7f93b6763ae7d747333df9a688cd1cfdb 100644 (file)
--- a/src/main/test/stubs.h
+++ b/src/main/test/stubs.h
@@ -171,6 +171,7 @@ void PacketTracer::thread_init() { }
 void PacketTracer::thread_term() { }
 void PacketTracer::log(const char*, ...) { }
 void PacketTracer::dump(Packet*) { }
+void PacketTracer::daq_dump(Packet*) { }
 void PacketTracer::activate(const Packet&) { }
 void TraceApi::thread_init(const TraceConfig*) { }
 void TraceApi::thread_term() { }

diff --git a/src/network_inspectors/packet_tracer/packet_tracer.cc b/src/network_inspectors/packet_tracer/packet_tracer.cc
index 258ddaf45a1ba0993facedfd44f351ffe5dd4f0e..d711facb6942d6f0706ff55f5e03059760aad0c3 100644 (file)
--- a/src/network_inspectors/packet_tracer/packet_tracer.cc
+++ b/src/network_inspectors/packet_tracer/packet_tracer.cc
@@ -53,6 +53,8 @@ using namespace snort;
 // FIXIT-M refactor the way this is used so all methods are members called against this pointer
 THREAD_LOCAL PacketTracer* snort::s_pkt_trace = nullptr;
 
+THREAD_LOCAL Stopwatch<SnortClock>* snort::pt_timer = nullptr;
+
 // so modules can register regardless of when packet trace is activated
 static THREAD_LOCAL struct{ unsigned val = 0; } global_mutes;
 
@@ -72,6 +74,9 @@ template<typename T> void PacketTracer::_thread_init()
     if ( s_pkt_trace == nullptr )
         s_pkt_trace = new T();
 
+    if ( pt_timer == nullptr )
+        pt_timer = new Stopwatch<SnortClock>;
+
     s_pkt_trace->mutes.resize(global_mutes.val, false);
     s_pkt_trace->open_file();
     s_pkt_trace->user_enabled = config_status;
@@ -88,6 +93,12 @@ void PacketTracer::thread_term()
         delete s_pkt_trace;
         s_pkt_trace = nullptr;
     }
+
+    if (pt_timer)
+    {
+        delete pt_timer;
+        pt_timer = nullptr;
+    }
 }
 
 void PacketTracer::dump(char* output_buff, unsigned int len)
@@ -99,7 +110,7 @@ void PacketTracer::dump(char* output_buff, unsigned int len)
         memcpy(output_buff, s_pkt_trace->buffer,
             (len < s_pkt_trace->buff_len + 1 ? len : s_pkt_trace->buff_len + 1));
 
-    s_pkt_trace->reset();
+    s_pkt_trace->reset(false);
 }
 
 void PacketTracer::dump(Packet* p)
@@ -107,9 +118,6 @@ void PacketTracer::dump(Packet* p)
     if (is_paused())
         return;
 
-    if (s_pkt_trace->daq_activated)
-        s_pkt_trace->dump_to_daq(p);
-
     if ((s_pkt_trace->buff_len > 0)
         and (s_pkt_trace->user_enabled or s_pkt_trace->shell_enabled))
     {
@@ -119,7 +127,29 @@ void PacketTracer::dump(Packet* p)
         LogMessage(s_pkt_trace->log_fh, "%s\n", s_pkt_trace->buffer);
     }
 
-    s_pkt_trace->reset();
+    s_pkt_trace->reset(false);
+}
+
+void PacketTracer::daq_dump(Packet *p)
+{
+    if (is_paused())
+        return;
+
+    if (s_pkt_trace->daq_activated)
+        s_pkt_trace->dump_to_daq(p);
+
+    s_pkt_trace->reset(true);
+}
+
+void PacketTracer::daq_log(const char* format, ...)
+{
+    if (is_paused())
+        return;
+
+    va_list ap;
+    va_start(ap, format);
+    s_pkt_trace->log_va(format, ap, true);
+    va_end(ap);
 }
 
 void PacketTracer::log(const char* format, ...)
@@ -129,7 +159,7 @@ void PacketTracer::log(const char* format, ...)
 
     va_list ap;
     va_start(ap, format);
-    s_pkt_trace->log_va(format, ap);
+    s_pkt_trace->log_va(format, ap, false);
     va_end(ap);
 }
 
@@ -140,7 +170,7 @@ void PacketTracer::log(TracerMute mute, const char* format, ...)
 
     va_list ap;
     va_start(ap, format);
-    s_pkt_trace->log_va(format, ap);
+    s_pkt_trace->log_va(format, ap, false);
     va_end(ap);
 
     s_pkt_trace->mutes[mute] = true;
@@ -203,7 +233,7 @@ void PacketTracer::activate(const Packet& p)
     else
         s_pkt_trace->daq_activated = false;
 
-    if (s_pkt_trace->daq_activated or s_pkt_trace->user_enabled or s_pkt_trace->shell_enabled)
+    if (s_pkt_trace->user_enabled or s_pkt_trace->shell_enabled)
     {
         if (!p.ptrs.ip_api.is_ip())
         {
@@ -226,6 +256,12 @@ void PacketTracer::activate(const Packet& p)
         s_pkt_trace->active = false;
 }
 
+void PacketTracer::pt_timer_start()
+{
+    pt_timer->reset();
+    pt_timer->start();
+}
+
 // -----------------------------------------------------------------------------
 // non-static functions
 // -----------------------------------------------------------------------------
@@ -240,11 +276,22 @@ PacketTracer::~PacketTracer()
     }
 }
 
-void PacketTracer::log_va(const char* format, va_list ap)
+void PacketTracer::populate_buf(const char* format, va_list ap, char* buffer, uint32_t& buff_len)
+{
+    const int buff_space = max_buff_size - buff_len;
+    const int len = vsnprintf(buffer + buff_len, buff_space, format, ap);
+
+    if (len >= 0 and len < buff_space)
+        buff_len += len;
+    else
+        buff_len = max_buff_size - 1;
+}
+
+void PacketTracer::log_va(const char* format, va_list ap, bool daq_log)
 {
     // FIXIT-L Need to find way to add 'PktTracerDbg' string as part of format string.
     std::string dbg_str;
-    if (shell_enabled) // only add debug string during shell execution
+    if (shell_enabled and !daq_log) // only add debug string during shell execution
     {
         dbg_str = "PktTracerDbg ";
         if (strcmp(format, "\n") != 0)
@@ -253,13 +300,10 @@ void PacketTracer::log_va(const char* format, va_list ap)
         format = dbg_str.c_str();
     }
 
-    const int buff_space = max_buff_size - buff_len;
-    const int len = vsnprintf(buffer + buff_len, buff_space, format, ap);
-
-    if (len >= 0 and len < buff_space)
-        buff_len += len;
+    if (daq_log)
+        s_pkt_trace->populate_buf(format, ap, daq_buffer, daq_buff_len);
     else
-        buff_len = max_buff_size - 1;
+        s_pkt_trace->populate_buf(format, ap, buffer, buff_len);
 }
 
 void PacketTracer::add_ip_header_info(const Packet& p)
@@ -418,17 +462,26 @@ void PacketTracer::open_file()
 void PacketTracer::dump_to_daq(Packet* p)
 {
     assert(p);
-    p->daq_instance->set_packet_trace_data(p->daq_msg, (uint8_t *)buffer, buff_len + 1);
+    p->daq_instance->set_packet_trace_data(p->daq_msg, (uint8_t *)daq_buffer, daq_buff_len + 1);
 }
 
-void PacketTracer::reset()
+void PacketTracer::reset(bool daq_log)
 {
-    buff_len = 0;
-    buffer[0] = '\0';
+    if ( daq_log )
+    {
+        daq_buff_len = 0;
+        daq_buffer[0] = '\0';
+    }
+    else
+    {
+        buff_len = 0;
+        buffer[0] = '\0';
 
-    for ( unsigned i = 0; i < mutes.size(); i++ )
-        mutes[i] = false;
+        for ( unsigned i = 0; i < mutes.size(); i++ )
+            mutes[i] = false;
+    }
 }
+
 // --------------------------------------------------------------------------
 // unit tests
 // --------------------------------------------------------------------------
@@ -449,6 +502,12 @@ public:
     static unsigned int get_buff_len()
     { return ((TestPacketTracer*)s_pkt_trace)->buff_len; }
 
+    static char* get_daq_buff()
+    { return ((TestPacketTracer*)s_pkt_trace)->daq_buffer; }
+
+    static unsigned int get_daq_buff_len()
+    { return ((TestPacketTracer*)s_pkt_trace)->daq_buff_len; }
+
     static void set_user_enable(bool status)
     { ((TestPacketTracer*)s_pkt_trace)->user_enabled = status; }
 
@@ -497,26 +556,59 @@ TEST_CASE("basic log", "[PacketTracer]")
     TestPacketTracer::thread_term();
 }
 
+TEST_CASE("basic daq log", "[PacketTracer]")
+{
+    char test_str[] = "1234567890";
+    // instantiate a packet tracer
+    TestPacketTracer::thread_init();
+    TestPacketTracer::pt_timer_start();
+    TestPacketTracer::set_daq_enable(true);
+    TestPacketTracer::daq_log("%s", test_str);
+    CHECK(!(strcmp(TestPacketTracer::get_daq_buff(), test_str)));
+    CHECK((TestPacketTracer::get_daq_buff_len() == 10));
+    TestPacketTracer::daq_log("%s", "ABCDEFG");
+    CHECK((strcmp(TestPacketTracer::get_daq_buff(), "1234567890ABCDEFG") == 0));
+    CHECK((TestPacketTracer::get_daq_buff_len() == strlen(TestPacketTracer::get_daq_buff())));
+
+    // log empty string won't change existed buffer
+    unsigned int curr_len = TestPacketTracer::get_daq_buff_len();
+    char empty_str[] = "";
+    TestPacketTracer::daq_log("%s", empty_str);
+    CHECK((TestPacketTracer::get_daq_buff_len() == curr_len));
+
+    TestPacketTracer::thread_term();
+}
+
 TEST_CASE("corner cases", "[PacketTracer]")
 {
     char test_str[] = "1234567890", empty_str[] = "";
     TestPacketTracer::thread_init();
     TestPacketTracer::set_user_enable(true);
+    TestPacketTracer::set_daq_enable(true);
     // init length check
     CHECK((TestPacketTracer::get_buff_len() == 0));
+    CHECK((TestPacketTracer::get_daq_buff_len() == 0));
     // logging empty string to start with
     TestPacketTracer::log("%s", empty_str);
     CHECK((TestPacketTracer::get_buff_len() == 0));
+    TestPacketTracer::daq_log("%s", empty_str);
+    CHECK((TestPacketTracer::get_daq_buff_len() == 0));
 
     // log messages larger than buffer size
     for(int i=0; i<1024; i++)
+    {
         TestPacketTracer::log("%s", test_str);
+        TestPacketTracer::daq_log("%s", test_str);
+    }
     // when buffer limit is  reached, buffer length will stopped at max_buff_size-1
     CHECK((TestPacketTracer::get_buff_len() == (TestPacketTracer::max_buff_size-1)));
+    CHECK((TestPacketTracer::get_daq_buff_len() == (TestPacketTracer::max_buff_size-1)));
 
     // continue logging will not change anything
     TestPacketTracer::log("%s", test_str);
     CHECK((TestPacketTracer::get_buff_len() == (TestPacketTracer::max_buff_size-1)));
+    TestPacketTracer::daq_log("%s", test_str);
+    CHECK((TestPacketTracer::get_daq_buff_len() == (TestPacketTracer::max_buff_size-1)));
 
     TestPacketTracer::thread_term();
 }

diff --git a/src/network_inspectors/packet_tracer/packet_tracer.h b/src/network_inspectors/packet_tracer/packet_tracer.h
index a9013417b1204d7918a4c554ba04b16253d413e5..6890dd5dac441aa1ba94514b04f2ef3aa68c2232 100644 (file)
--- a/src/network_inspectors/packet_tracer/packet_tracer.h
+++ b/src/network_inspectors/packet_tracer/packet_tracer.h
@@ -32,6 +32,8 @@
 #include "protocols/ipv6.h"
 #include "protocols/protocol_ids.h"
 #include "sfip/sf_ip.h"
+#include "time/clock_defs.h"
+#include "time/stopwatch.h"
 
 // %s %u -> %s %u %u AS=%u ID=%u GR=%hd-%hd
 // IPv6 Port -> IPv6 Port Proto AS=ASNum ID=InstanceNum GR=SrcGroupNum-DstGroupNum
@@ -57,6 +59,7 @@ public:
 
     static void dump(char* output_buff, unsigned int len);
     static void dump(Packet*);
+    static void daq_dump(Packet*);
 
     static void configure(bool status, const std::string& file_name);
     static void set_constraints(const PacketConstraints* constraints);
@@ -66,12 +69,16 @@ public:
     static SO_PUBLIC void unpause();
     static SO_PUBLIC bool is_paused();
     static SO_PUBLIC bool is_active();
+    static SO_PUBLIC bool is_daq_activated();
 
     static SO_PUBLIC TracerMute get_mute();
 
     static SO_PUBLIC void log(const char* format, ...) __attribute__((format (printf, 1, 2)));
     static SO_PUBLIC void log(TracerMute, const char* format, ...) __attribute__((format (printf, 2, 3)));
 
+    static SO_PUBLIC void daq_log(const char* format, ...) __attribute__((format (printf, 1, 2)));
+    static SO_PUBLIC void pt_timer_start();
+
 protected:
 
 
@@ -80,6 +87,8 @@ protected:
     std::vector<bool> mutes;
     char buffer[max_buff_size];
     unsigned buff_len = 0;
+    char daq_buffer[max_buff_size];
+    unsigned daq_buff_len = 0;
 
     unsigned pause_count = 0;
     bool user_enabled = false;
@@ -94,7 +103,8 @@ protected:
     template<typename T = PacketTracer> static void _thread_init();
 
     // non-static functions
-    void log_va(const char*, va_list);
+    void log_va(const char*, va_list, bool);
+    void populate_buf(const char*, va_list, char*, uint32_t&);
     void add_ip_header_info(const snort::Packet&);
     void add_eth_header_info(const snort::Packet&);
     void add_packet_type_info(const snort::Packet&);
@@ -103,15 +113,18 @@ protected:
 
     virtual void open_file();
     virtual void dump_to_daq(Packet*);
-    virtual void reset();
-
+    virtual void reset(bool);
 };
 
 SO_PUBLIC extern THREAD_LOCAL PacketTracer* s_pkt_trace;
+SO_PUBLIC extern THREAD_LOCAL Stopwatch<SnortClock>* pt_timer;
 
 inline bool PacketTracer::is_active()
 { return s_pkt_trace ? s_pkt_trace->active : false; }
 
+inline bool PacketTracer::is_daq_activated()
+{ return s_pkt_trace ? s_pkt_trace->daq_activated : false; }
+
 struct SO_PUBLIC PacketTracerSuspend
 {
     PacketTracerSuspend()

diff --git a/src/time/clock_defs.h b/src/time/clock_defs.h
index 95b2a7f349a16ec5e0bc961e3069b535da39125f..82008ec87637ef3dcb30f0c5954d9778730dd593 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_NSECS(t) (t)
 #define TO_DURATION(v, t) (t)
 
 #else
@@ -38,6 +39,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_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