#include "packet_tracer.h"
#include <cstdarg>
+#include <cstdio>
+#include <unordered_map>
-#include "log.h"
#include "packet_io/sfdaq.h"
#include "protocols/eth.h"
#include "protocols/ip.h"
#include "protocols/packet.h"
#include "protocols/tcp.h"
+#include "log.h"
+#include "messages.h"
+
#ifdef UNIT_TEST
#include "catch/snort_catch.h"
#endif
using namespace snort;
-#define PACKET_TRACER_USER_ENABLED 0x00000001
-#define PACKET_TRACER_DAQ_ENABLED 0x00000002
-
+static const uint8_t VERDICT_REASON_NO_BLOCK = 2; /* Not blocking packet; all enum defined after this indicates blocking */
+static std::unordered_map<uint8_t, uint8_t> reasons = { {VERDICT_REASON_NO_BLOCK, PacketTracer::PRIORITY_UNSET} };
+
+// FIXIT-M refactor the way this is used so all methods are members called against this pointer
static THREAD_LOCAL PacketTracer* s_pkt_trace = nullptr;
+// so modules can register regardless of when packet trace is activated
+static THREAD_LOCAL struct{ unsigned val = 0; } global_mutes;
+
+static std::string log_file = "-";
+
+PacketTracer::PacketTracer()
+{ reason = VERDICT_REASON_NO_BLOCK; }
+
+void PacketTracer::register_verdict_reason(uint8_t reason_code, uint8_t priority)
+{
+ auto it = reasons.find(reason_code);
+ assert( it == reasons.end() );
+
+ reasons[reason_code] = priority;
+}
+
+void PacketTracer::set_log_file(std::string file)
+{ log_file = file; }
+
+void PacketTracer::open_file()
+{
+ if ( log_file == "-" )
+ log_fh = stdout;
+ else
+ {
+ std::string path;
+ const char* fname = get_instance_file(path, log_file.c_str());
+ log_fh = fopen(fname, "a+");
+
+ if ( log_fh == nullptr )
+ {
+ WarningMessage("Could not open %s for packet trace logging\n", log_file.c_str());
+ log_fh = stdout;
+ }
+ }
+}
+
+// template needed for unit tests
+template<typename T> void PacketTracer::_thread_init()
+{
+ if ( s_pkt_trace == nullptr )
+ s_pkt_trace = new T();
+
+ s_pkt_trace->mutes.resize(global_mutes.val, false);
+ s_pkt_trace->open_file();
+}
+template void PacketTracer::_thread_init<PacketTracer>();
+
void PacketTracer::thread_init()
+{ _thread_init(); }
+
+PacketTracer::~PacketTracer()
{
- if (s_pkt_trace == nullptr)
+ if ( log_fh && log_fh != stdout )
{
- s_pkt_trace = new PacketTracer();
+ fclose(log_fh);
+ log_fh = nullptr;
}
}
void PacketTracer::thread_term()
{
- if (s_pkt_trace)
+ if ( s_pkt_trace )
{
delete s_pkt_trace;
s_pkt_trace = nullptr;
}
}
-bool PacketTracer::get_enable(const uint32_t mask)
-{
- if (!s_pkt_trace)
- return false;
- if (mask)
- return (s_pkt_trace->enable_flags & mask);
- else
- return (s_pkt_trace->enable_flags != 0);
-}
-
-void PacketTracer::enable_user_trace()
+void PacketTracer::dump_to_daq(const DAQ_PktHdr_t* pkt_hdr)
{
- assert(s_pkt_trace);
- s_pkt_trace->enable_flags |= PACKET_TRACER_USER_ENABLED;
+ SFDAQ::get_local_instance()->modify_flow_pkt_trace(pkt_hdr, s_pkt_trace->reason,
+ (uint8_t *)s_pkt_trace->buffer, s_pkt_trace->buff_len + 1);
}
-void PacketTracer::enable_daq_trace()
+void PacketTracer::reset()
{
- assert(s_pkt_trace);
- s_pkt_trace->enable_flags |= PACKET_TRACER_DAQ_ENABLED;
-}
+ buff_len = 0;
+ buffer[0] = '\0';
+ reason = VERDICT_REASON_NO_BLOCK;
-void PacketTracer::disable_daq_trace()
-{
- assert(s_pkt_trace);
- s_pkt_trace->enable_flags &= ~PACKET_TRACER_DAQ_ENABLED;
+ for ( unsigned i = 0; i < mutes.size(); i++ )
+ mutes[i] = false;
}
void PacketTracer::dump(char* output_buff, unsigned int len)
{
- if (!get_enable())
+ if (!active())
return;
if (output_buff)
memcpy(output_buff, s_pkt_trace->buffer,
(len < s_pkt_trace->buff_len + 1 ? len : s_pkt_trace->buff_len + 1));
- s_pkt_trace->buff_len = 0;
- s_pkt_trace->buffer[0] = '\0';
+ s_pkt_trace->reset();
}
-void PacketTracer::dump(const DAQ_PktHdr_t* pkthdr, DAQ_Verdict verdict)
+void PacketTracer::dump(const DAQ_PktHdr_t* pkt_hdr)
{
- if (!get_enable())
+ if (!active())
return;
- if (get_enable(PACKET_TRACER_DAQ_ENABLED))
- {
- SFDAQ::get_local_instance()->modify_flow_pkt_trace(pkthdr, verdict,
- (uint8_t *)s_pkt_trace->buffer, s_pkt_trace->buff_len + 1);
- }
+ if (s_pkt_trace->daq_enabled)
+ s_pkt_trace->dump_to_daq(pkt_hdr);
- if (get_enable(PACKET_TRACER_USER_ENABLED))
- printf("%s\n", s_pkt_trace->buffer);
+ if (s_pkt_trace->user_enabled)
+ LogMessage(s_pkt_trace->log_fh, "%s\n", s_pkt_trace->buffer);
- s_pkt_trace->buff_len = 0;
- s_pkt_trace->buffer[0] = '\0';
+ s_pkt_trace->reset();
}
-void PacketTracer::log(const char* format, ...)
+void PacketTracer::set_reason(uint8_t reason)
{
- if (!get_enable())
+ if ( !active() )
return;
- va_list ap;
+ if ( reasons[reason] > reasons[s_pkt_trace->reason] )
+ s_pkt_trace->reason = reason;
+}
+
+void PacketTracer::log(const char* format, va_list ap)
+{
+ if ( !active() )
+ return;
- va_start(ap, format);
const int buff_space = max_buff_size - s_pkt_trace->buff_len;
const int len = vsnprintf(s_pkt_trace->buffer + s_pkt_trace->buff_len,
buff_space, format, ap);
- va_end(ap);
if (len >= 0 and len < buff_space)
- {
s_pkt_trace->buff_len += len;
- }
else
- {
s_pkt_trace->buff_len = max_buff_size - 1;
- }
+}
+
+void PacketTracer::log(const char* format, ...)
+{
+ va_list ap;
+ va_start(ap, format);
+ log(format, ap);
+ va_end(ap);
+}
+
+void PacketTracer::log(TracerMute mute, const char* format, ...)
+{
+ if ( s_pkt_trace->mutes[mute] )
+ return; // logged under this mute once. don't log again until dump.
+
+ va_list ap;
+ va_start(ap, format);
+ log(format, ap);
+ va_end(ap);
+
+ s_pkt_trace->mutes[mute] = true;
}
void PacketTracer::add_header_info(Packet* p)
{
- if (!get_enable())
+ if (!active())
return;
if ( auto eh = layer::get_eth_layer(p) )
}
}
-#ifdef UNIT_TEST
-char* PacketTracer::get_buff()
+bool PacketTracer::active()
+{
+ if ( !s_pkt_trace )
+ return false;
+
+ if ( s_pkt_trace->pause_count )
+ return false;
+
+ return s_pkt_trace->user_enabled || s_pkt_trace->daq_enabled;
+}
+
+void PacketTracer::enable_user()
+{ s_pkt_trace->user_enabled = true; }
+
+void PacketTracer::enable_daq()
+{ s_pkt_trace->daq_enabled = true; }
+
+void PacketTracer::disable_daq()
+{ s_pkt_trace->daq_enabled = false; }
+
+void PacketTracer::pause()
+{ s_pkt_trace->pause_count++; }
+
+void PacketTracer::unpause()
{
- return buffer;
+ assert(s_pkt_trace->pause_count);
+
+ s_pkt_trace->pause_count--;
}
-unsigned int PacketTracer::get_buff_len()
+PacketTracer::TracerMute PacketTracer::get_mute()
{
- return buff_len;
+ global_mutes.val++;
+ if ( s_pkt_trace == nullptr )
+ return global_mutes.val - 1;
+
+ s_pkt_trace->mutes.push_back(false);
+ return s_pkt_trace->mutes.size() - 1;
}
-#define MAX_PKT_TRACE_BUFF_SIZE 2048
+#ifdef UNIT_TEST
+#include <fcntl.h>
+#include <unistd.h>
+
+class TestPacketTracer : public PacketTracer
+{
+public:
+ uint8_t dump_reason = VERDICT_REASON_NO_BLOCK;
+
+ static void thread_init()
+ { PacketTracer::_thread_init<TestPacketTracer>(); }
+
+ static char* get_buff()
+ { return ((TestPacketTracer*)s_pkt_trace)->buffer; }
+
+ static unsigned int get_buff_len()
+ { return ((TestPacketTracer*)s_pkt_trace)->buff_len; }
+
+ static bool is_user_enabled()
+ { return ((TestPacketTracer*)s_pkt_trace)->user_enabled; }
+
+ static bool is_daq_enabled()
+ { return ((TestPacketTracer*)s_pkt_trace)->daq_enabled; }
+
+ static bool is_paused()
+ { return ((TestPacketTracer*)s_pkt_trace)->pause_count; }
+
+ static uint8_t get_reason()
+ { return ((TestPacketTracer*)s_pkt_trace)->reason; }
+
+ static uint8_t get_dump_reason()
+ { return ((TestPacketTracer*)s_pkt_trace)->dump_reason; }
+
+ virtual void dump_to_daq(const DAQ_PktHdr_t*) override
+ { dump_reason = reason; }
+
+ static std::vector<bool> get_mutes()
+ { return ((TestPacketTracer*)s_pkt_trace)->mutes; }
+
+ static FILE* get_log_fh()
+ { return ((TestPacketTracer*)s_pkt_trace)->log_fh; }
+};
TEST_CASE("basic log", "[PacketTracer]")
{
char test_str[] = "1234567890";
// instantiate a packet tracer
- PacketTracer::thread_init();
- PacketTracer::enable_user_trace();
+ TestPacketTracer::thread_init();
+ TestPacketTracer::enable_user();
// basic logging
- PacketTracer::log("%s", test_str);
- CHECK(!(strcmp(s_pkt_trace->get_buff(), test_str)));
- CHECK((s_pkt_trace->get_buff_len() == 10));
+ TestPacketTracer::log("%s", test_str);
+ CHECK(!(strcmp(TestPacketTracer::get_buff(), test_str)));
+ CHECK((TestPacketTracer::get_buff_len() == 10));
// continue log will add message to the buffer
- PacketTracer::log("%s", "ABCDEFG");
- CHECK((strcmp(s_pkt_trace->get_buff(), "1234567890ABCDEFG") == 0));
- CHECK((s_pkt_trace->get_buff_len() == strlen(s_pkt_trace->get_buff())));
+ TestPacketTracer::log("%s", "ABCDEFG");
+ CHECK((strcmp(TestPacketTracer::get_buff(), "1234567890ABCDEFG") == 0));
+ CHECK((TestPacketTracer::get_buff_len() == strlen(TestPacketTracer::get_buff())));
// log empty string won't change existed buffer
- unsigned int curr_len = s_pkt_trace->get_buff_len();
+ unsigned int curr_len = TestPacketTracer::get_buff_len();
char empty_str[] = "";
- PacketTracer::log("%s", empty_str);
- CHECK((s_pkt_trace->get_buff_len() == curr_len));
+ TestPacketTracer::log("%s", empty_str);
+ CHECK((TestPacketTracer::get_buff_len() == curr_len));
- PacketTracer::thread_term();
+ TestPacketTracer::thread_term();
}
TEST_CASE("corner cases", "[PacketTracer]")
{
char test_str[] = "1234567890", empty_str[] = "";
- PacketTracer::thread_init();
- PacketTracer::enable_user_trace();
+ TestPacketTracer::thread_init();
+ TestPacketTracer::enable_user();
// init length check
- CHECK((s_pkt_trace->get_buff_len() == 0));
+ CHECK((TestPacketTracer::get_buff_len() == 0));
// logging empty string to start with
- PacketTracer::log("%s", empty_str);
- CHECK((s_pkt_trace->get_buff_len() == 0));
+ TestPacketTracer::log("%s", empty_str);
+ CHECK((TestPacketTracer::get_buff_len() == 0));
// log messages larger than buffer size
for(int i=0; i<1024; i++)
- PacketTracer::log("%s", test_str);
+ TestPacketTracer::log("%s", test_str);
// when buffer limit is reached, buffer length will stopped at max_buff_size-1
- CHECK((s_pkt_trace->get_buff_len() == (MAX_PKT_TRACE_BUFF_SIZE-1)));
+ CHECK((TestPacketTracer::get_buff_len() == (TestPacketTracer::max_buff_size-1)));
// continue logging will not change anything
- PacketTracer::log("%s", test_str);
- CHECK((s_pkt_trace->get_buff_len() == (MAX_PKT_TRACE_BUFF_SIZE-1)));
+ TestPacketTracer::log("%s", test_str);
+ CHECK((TestPacketTracer::get_buff_len() == (TestPacketTracer::max_buff_size-1)));
- PacketTracer::thread_term();
+ TestPacketTracer::thread_term();
}
TEST_CASE("dump", "[PacketTracer]")
{
- char test_string[MAX_PKT_TRACE_BUFF_SIZE];
+ char test_string[TestPacketTracer::max_buff_size];
char test_str[] = "ABCD", results[] = "ABCD3=400";
- PacketTracer::thread_init();
- PacketTracer::enable_user_trace();
- PacketTracer::log("%s%d=%d", test_str, 3, 400);
- PacketTracer::dump(test_string, MAX_PKT_TRACE_BUFF_SIZE);
+ TestPacketTracer::thread_init();
+ TestPacketTracer::enable_user();
+ TestPacketTracer::log("%s%d=%d", test_str, 3, 400);
+ TestPacketTracer::dump(test_string, TestPacketTracer::max_buff_size);
CHECK(!strcmp(test_string, results));
- CHECK((s_pkt_trace->get_buff_len() == 0));
+ CHECK((TestPacketTracer::get_buff_len() == 0));
// dump again
- PacketTracer::dump(test_string, MAX_PKT_TRACE_BUFF_SIZE);
+ TestPacketTracer::dump(test_string, TestPacketTracer::max_buff_size);
CHECK(!strcmp(test_string, ""));
- CHECK((s_pkt_trace->get_buff_len() == 0));
+ CHECK((TestPacketTracer::get_buff_len() == 0));
- PacketTracer::thread_term();
+ TestPacketTracer::thread_term();
}
TEST_CASE("enable", "[PacketTracer]")
{
- PacketTracer::thread_init();
+ TestPacketTracer::thread_init();
// packet tracer is disabled by default
- CHECK(!PacketTracer::get_enable());
+ CHECK(!TestPacketTracer::active());
// enabled from user
- PacketTracer::enable_user_trace();
- CHECK(PacketTracer::get_enable());
- CHECK(PacketTracer::get_enable(PACKET_TRACER_USER_ENABLED));
- CHECK(!PacketTracer::get_enable(PACKET_TRACER_DAQ_ENABLED));
+ TestPacketTracer::enable_user();
+ CHECK(TestPacketTracer::active());
+ CHECK(TestPacketTracer::is_user_enabled());
+ CHECK(!TestPacketTracer::is_daq_enabled());
// enabled from DAQ
- PacketTracer::enable_daq_trace();
- CHECK(PacketTracer::get_enable());
- CHECK(PacketTracer::get_enable(PACKET_TRACER_DAQ_ENABLED));
+ TestPacketTracer::enable_daq();
+ CHECK(TestPacketTracer::active());
+ CHECK(TestPacketTracer::is_daq_enabled());
// disable DAQ enable
- PacketTracer::disable_daq_trace();
- CHECK(!PacketTracer::get_enable(PACKET_TRACER_DAQ_ENABLED));
+ TestPacketTracer::disable_daq();
+ CHECK(!TestPacketTracer::is_daq_enabled());
// user configuration remain enabled
- CHECK(PacketTracer::get_enable());
- CHECK(PacketTracer::get_enable(PACKET_TRACER_USER_ENABLED));
+ CHECK(TestPacketTracer::active());
+ CHECK(TestPacketTracer::is_user_enabled());
- PacketTracer::thread_term();
+ TestPacketTracer::thread_term();
+}
+
+TEST_CASE("pause", "[PacketTracer]")
+{
+ char test_str[] = "1234567890";
+
+ TestPacketTracer::thread_init();
+ TestPacketTracer::enable_user();
+ TestPacketTracer::pause();
+ TestPacketTracer::pause();
+ TestPacketTracer::pause();
+
+ TestPacketTracer::log("%s", test_str);
+ CHECK( TestPacketTracer::get_buff()[0] == '\0' );
+ CHECK( TestPacketTracer::get_buff_len() == 0 );
+
+ TestPacketTracer::unpause();
+
+ TestPacketTracer::log("%s", test_str);
+ CHECK( TestPacketTracer::get_buff()[0] == '\0' );
+ CHECK( TestPacketTracer::get_buff_len() == 0 );
+
+ TestPacketTracer::unpause();
+
+ TestPacketTracer::log("%s", test_str);
+ CHECK( TestPacketTracer::get_buff()[0] == '\0' );
+ CHECK( TestPacketTracer::get_buff_len() == 0 );
+
+ TestPacketTracer::unpause();
+
+ TestPacketTracer::log("%s", test_str);
+ CHECK( !strcmp(TestPacketTracer::get_buff(), test_str) );
+ CHECK( TestPacketTracer::get_buff_len() == 10 );
+
+ TestPacketTracer::thread_term();
+}
+
+TEST_CASE("reasons", "[PacketTracer]")
+{
+ TestPacketTracer::thread_init();
+ TestPacketTracer::enable_daq();
+ uint8_t low1 = 100, low2 = 101, high = 102;
+ TestPacketTracer::register_verdict_reason(low1, PacketTracer::PRIORITY_LOW);
+ TestPacketTracer::register_verdict_reason(low2, PacketTracer::PRIORITY_LOW);
+ TestPacketTracer::register_verdict_reason(high, PacketTracer::PRIORITY_HIGH);
+
+ // Init
+ CHECK( TestPacketTracer::get_reason() == VERDICT_REASON_NO_BLOCK );
+
+ // Update
+ TestPacketTracer::set_reason(low1);
+ CHECK( TestPacketTracer::get_reason() == low1 );
+
+ // Don't update if already set
+ TestPacketTracer::set_reason(VERDICT_REASON_NO_BLOCK);
+ CHECK( TestPacketTracer::get_reason() == low1 );
+ TestPacketTracer::set_reason(low2);
+ CHECK( TestPacketTracer::get_reason() == low1 );
+
+ // Always update for high priority
+ TestPacketTracer::set_reason(high);
+ CHECK( TestPacketTracer::get_reason() == high );
+
+ // Dump resets reason
+ TestPacketTracer::dump(nullptr);
+ CHECK( TestPacketTracer::get_reason() == VERDICT_REASON_NO_BLOCK );
+
+ // Dump delivers reason to daq
+ CHECK( TestPacketTracer::get_dump_reason() == high );
+
+ TestPacketTracer::thread_term();
+}
+
+TEST_CASE("verbosity", "[PacketTracer]")
+{
+ TestPacketTracer::thread_init();
+ TestPacketTracer::enable_user();
+ PacketTracer::TracerMute mute_1 = TestPacketTracer::get_mute();
+ PacketTracer::TracerMute mute_2 = TestPacketTracer::get_mute();
+
+ TestPacketTracer::log(mute_1, "this should log\n");
+ TestPacketTracer::log(mute_1, "this should not log\n");
+ TestPacketTracer::log(mute_1, "this should not log\n");
+ TestPacketTracer::log(mute_2, "this should also log\n");
+ TestPacketTracer::log(mute_2, "this should not log\n");
+ TestPacketTracer::log(mute_2, "this should not log\n");
+
+ std::string val = TestPacketTracer::get_buff();
+ std::string expected = "this should log\nthis should also log\n";
+ CHECK( val == expected );
+
+ // reset mutes
+ TestPacketTracer::dump(nullptr, 0);
+ TestPacketTracer::log(mute_1, "this should log\n");
+ TestPacketTracer::log(mute_2, "this should also log\n");
+ val = TestPacketTracer::get_buff();
+ CHECK( val == expected );
+
+ TestPacketTracer::thread_term();
+}
+
+TEST_CASE("mute on inactive", "[PacketTracer]")
+{
+ global_mutes.val = 0;
+
+ CHECK( TestPacketTracer::get_mute() == 0 );
+ CHECK( TestPacketTracer::get_mute() == 1 );
+ CHECK( TestPacketTracer::get_mute() == 2 );
+
+ // activation mid-run
+ TestPacketTracer::thread_init();
+
+ CHECK( TestPacketTracer::get_mute() == 3 );
+ CHECK( TestPacketTracer::get_mute() == 4 );
+ CHECK( TestPacketTracer::get_mute() == 5 );
+
+ std::vector<bool> expected = {false, false, false, false, false, false};
+ CHECK( TestPacketTracer::get_mutes() == expected );
+
+ TestPacketTracer::thread_term();
+}
+
+TEST_CASE("open stdout", "[PacketTracer]")
+{
+ TestPacketTracer::set_log_file("-");
+ TestPacketTracer::thread_init();
+ CHECK( log_file == "-" );
+ CHECK( TestPacketTracer::get_log_fh() == stdout );
+
+ TestPacketTracer::thread_term();
+}
+
+TEST_CASE("open file", "[PacketTracer]")
+{
+ TestPacketTracer::set_log_file("packet_tracer_tmp");
+ TestPacketTracer::thread_init();
+ CHECK( log_file == "packet_tracer_tmp" );
+
+ FILE* fh = TestPacketTracer::get_log_fh();
+ CHECK( fh != stdout );
+
+ TestPacketTracer::thread_term();
+ std::string path;
+ remove(get_instance_file(path, "packet_tracer_tmp"));
}
#endif
projects / thirdparty / snort3.git / commitdiff
