From: Michael Altizer (mialtize) Date: Wed, 25 Mar 2020 22:15:48 +0000 (+0000) Subject: Merge pull request #2045 in SNORT/snort3 from ~SVLASIUK/snort3:trace_log_level to... X-Git-Tag: 3.0.1-1~11 X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=b25fcefc01f2066e3fbbb63ce2f4d662125e30d9;p=thirdparty%2Fsnort3.git Merge pull request #2045 in SNORT/snort3 from ~SVLASIUK/snort3:trace_log_level to master Squashed commit of the following: commit b83b61ba207177d583ef57ec3642ae130b9a7680 Author: Serhii Vlasiuk Date: Fri Feb 14 16:33:00 2020 +0200 modules: Support verbosity level for module trace options, modify trace logging macros. Log level range [0-255]. There are conditional debug_log/debug_logf and unconditional trace_log/trace_logf macros for logging. Now log messages have format: module:sub_module:log_level: msg. Ex: detection:rule_eval:1: Fast pattern search Added trace 'all' option for detection module. --- diff --git a/src/codecs/codec_module.cc b/src/codecs/codec_module.cc index 713b81f74..f619e3870 100644 --- a/src/codecs/codec_module.cc +++ b/src/codecs/codec_module.cc @@ -30,11 +30,13 @@ using namespace snort; #define codec_module_help \ "general decoder rules" -Trace TRACE_NAME(decode); +static const char s_module_name[] = "decode"; + +Trace decode_trace(s_module_name); static const Parameter s_params[] = {{ nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr }}; -CodecModule::CodecModule() : Module("decode", codec_module_help, s_params, false, &TRACE_NAME(decode)) +CodecModule::CodecModule() : Module(s_module_name, codec_module_help, s_params, false, &decode_trace) { } bool CodecModule::set(const char* fqn, Value& v, SnortConfig* sc) diff --git a/src/codecs/codec_module.h b/src/codecs/codec_module.h index efb1ad6c1..a180c0984 100644 --- a/src/codecs/codec_module.h +++ b/src/codecs/codec_module.h @@ -243,7 +243,7 @@ public: }; } -extern Trace TRACE_NAME(decode); +extern snort::Trace decode_trace; #endif diff --git a/src/connectors/file_connector/test/file_connector_module_test.cc b/src/connectors/file_connector/test/file_connector_module_test.cc index 6a1605609..c69d0af4c 100644 --- a/src/connectors/file_connector/test/file_connector_module_test.cc +++ b/src/connectors/file_connector/test/file_connector_module_test.cc @@ -45,6 +45,12 @@ char* snort_strdup(const char* s) { return strdup(s); } } +Trace::Trace(const char*, const TraceOptionString*, size_t) {} +Trace::Trace(const char*) {} +bool Trace::set(const snort::Value&) { return true; } +void Trace::reset() {} +void Trace::enable() {} + TEST_GROUP(file_connector_module) { }; diff --git a/src/connectors/file_connector/test/file_connector_test.cc b/src/connectors/file_connector/test/file_connector_test.cc index cc7be66a2..825d2c648 100644 --- a/src/connectors/file_connector/test/file_connector_test.cc +++ b/src/connectors/file_connector/test/file_connector_test.cc @@ -59,6 +59,12 @@ const char* get_instance_file(std::string& file, const char* name) { file += name; return nullptr; } } +Trace::Trace(const char*, const TraceOptionString*, size_t) {} +Trace::Trace(const char*) {} +bool Trace::set(const snort::Value&) { return true; } +void Trace::reset() {} +void Trace::enable() {} + FileConnectorModule::FileConnectorModule() : Module("FC", "FC Help", nullptr) { } diff --git a/src/connectors/tcp_connector/test/tcp_connector_module_test.cc b/src/connectors/tcp_connector/test/tcp_connector_module_test.cc index 0f94e0b58..45b384c91 100644 --- a/src/connectors/tcp_connector/test/tcp_connector_module_test.cc +++ b/src/connectors/tcp_connector/test/tcp_connector_module_test.cc @@ -45,6 +45,12 @@ char* snort_strdup(const char* s) { return strdup(s); } } +Trace::Trace(const char*, const TraceOptionString*, size_t) {} +Trace::Trace(const char*) {} +bool Trace::set(const snort::Value&) { return true; } +void Trace::reset() {} +void Trace::enable() {} + TEST_GROUP(tcp_connector_module) { }; diff --git a/src/connectors/tcp_connector/test/tcp_connector_test.cc b/src/connectors/tcp_connector/test/tcp_connector_test.cc index 454effd24..b144f50d2 100644 --- a/src/connectors/tcp_connector/test/tcp_connector_test.cc +++ b/src/connectors/tcp_connector/test/tcp_connector_test.cc @@ -170,6 +170,12 @@ static void set_normal_status() s_rec_return_zero = false; } +Trace::Trace(const char*, const TraceOptionString*, size_t) {} +Trace::Trace(const char*) {} +bool Trace::set(const snort::Value&) { return true; } +void Trace::reset() {} +void Trace::enable() {} + TcpConnectorModule::TcpConnectorModule() : Module("TCPC", "TCPC Help", nullptr) { } diff --git a/src/detection/context_switcher.cc b/src/detection/context_switcher.cc index 7debfdbf6..ed3625199 100644 --- a/src/detection/context_switcher.cc +++ b/src/detection/context_switcher.cc @@ -72,7 +72,8 @@ void ContextSwitcher::start() assert(!c->has_callbacks()); c->context_num = ++global_context_num; - trace_logf(detection, TRACE_DETECTION_ENGINE, "(wire) %" PRIu64 " cs::start %" PRIu64 " (i=%zu, b=%zu)\n", + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, + "(wire) %" PRIu64 " cs::start %" PRIu64 " (i=%zu, b=%zu)\n", get_packet_number(), c->context_num, idle.size(), busy.size()); idle.pop_back(); @@ -93,7 +94,8 @@ void ContextSwitcher::stop() assert(!c->has_callbacks()); assert(!c->dependencies()); - trace_logf(detection, TRACE_DETECTION_ENGINE, "(wire) %" PRIu64 " cs::stop %" PRIu64 " (i=%zu, b=%zu)\n", + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, + "(wire) %" PRIu64 " cs::stop %" PRIu64 " (i=%zu, b=%zu)\n", get_packet_number(), c->context_num, idle.size(), busy.size()); c->clear_context_data(); @@ -107,7 +109,8 @@ void ContextSwitcher::stop() void ContextSwitcher::abort() { - trace_logf(detection, TRACE_DETECTION_ENGINE, "(wire) %" PRIu64 " cs::abort (i=%zu, b=%zu)\n", + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, + "(wire) %" PRIu64 " cs::abort (i=%zu, b=%zu)\n", get_packet_number(), idle.size(), busy.size()); busy.clear(); @@ -119,11 +122,11 @@ void ContextSwitcher::abort() case IpsContext::IDLE: continue; case IpsContext::BUSY: - trace_logf(detection, TRACE_DETECTION_ENGINE, "%" PRIu64 " cs::abort busy", + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, "%" PRIu64 " cs::abort busy", c->packet_number); break; case IpsContext::SUSPENDED: - trace_logf(detection, TRACE_DETECTION_ENGINE, "%" PRIu64 " cs::abort suspended", + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, "%" PRIu64 " cs::abort suspended", c->packet_number); break; } @@ -149,7 +152,8 @@ IpsContext* ContextSwitcher::interrupt() assert(c->state == IpsContext::IDLE); c->context_num = ++global_context_num; - trace_logf(detection, TRACE_DETECTION_ENGINE, "%" PRIu64 " cs::interrupt %" PRIu64 " (i=%zu, b=%zu)\n", + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, + "%" PRIu64 " cs::interrupt %" PRIu64 " (i=%zu, b=%zu)\n", busy.empty() ? get_packet_number() : busy.back()->packet_number, busy.empty() ? 0 : busy.back()->context_num, idle.size(), busy.size()); @@ -169,7 +173,8 @@ IpsContext* ContextSwitcher::complete() assert(!c->dependencies()); assert(!c->has_callbacks()); - trace_logf(detection, TRACE_DETECTION_ENGINE, "%" PRIu64 " cs::complete %" PRIu64 " (i=%zu, b=%zu)\n", + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, + "%" PRIu64 " cs::complete %" PRIu64 " (i=%zu, b=%zu)\n", c->packet_number, c->context_num, idle.size(), busy.size()); busy.pop_back(); @@ -190,8 +195,10 @@ void ContextSwitcher::suspend() IpsContext* c = busy.back(); assert(c->state == IpsContext::BUSY); - trace_logf(detection, TRACE_DETECTION_ENGINE, "%" PRIu64 " cs::suspend %" PRIu64 " (i=%zu, b=%zu, wh=%zu)\n", - c->packet_number, c->context_num, idle.size(), busy.size(), contexts.size() - idle.size() - busy.size()); + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, + "%" PRIu64 " cs::suspend %" PRIu64 " (i=%zu, b=%zu, wh=%zu)\n", + c->packet_number, c->context_num, idle.size(), busy.size(), + contexts.size() - idle.size() - busy.size()); c->state = IpsContext::SUSPENDED; busy.pop_back(); @@ -206,7 +213,8 @@ void ContextSwitcher::resume(IpsContext* c) { assert(c->state == IpsContext::SUSPENDED); - trace_logf(detection, TRACE_DETECTION_ENGINE, "%" PRIu64 " cs::resume %" PRIu64 " (i=%zu)\n", + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, + "%" PRIu64 " cs::resume %" PRIu64 " (i=%zu)\n", c->packet_number, c->context_num, idle.size()); IpsContextChain& chain = c->packet->flow ? c->packet->flow->context_chain : non_flow_chain; diff --git a/src/detection/detect_trace.cc b/src/detection/detect_trace.cc index 4387db604..3ddc3af78 100644 --- a/src/detection/detect_trace.cc +++ b/src/detection/detect_trace.cc @@ -39,12 +39,8 @@ using namespace snort; using namespace std; -Trace TRACE_NAME(detection); - #ifdef DEBUG_MSGS -const uint64_t trace_buffer = TRACE_BUFFER_MINIMAL | TRACE_BUFFER_VERBOSE; - static THREAD_LOCAL char* cursor_name = nullptr; static THREAD_LOCAL unsigned cursor_pos = -1; @@ -83,7 +79,7 @@ void print_pkt_info(Packet* p, const char* task) dst_port = p->ptrs.dp; } - trace_logf(detection, TRACE_RULE_EVAL,"packet %" PRIu64 " %s %s:%u %s:%u (%s)\n", + debug_logf(detection_trace, TRACE_RULE_EVAL,"packet %" PRIu64 " %s %s:%u %s:%u (%s)\n", p->context->packet_number, dir, src_addr, src_port, dst_addr, dst_port, task); } @@ -92,7 +88,7 @@ void print_pattern(const PatternMatchData* pmd) string hex, txt, opts; get_pattern_info(pmd, pmd->pattern_buf, pmd->pattern_size, hex, txt, opts); - trace_logf(detection, TRACE_RULE_EVAL, + debug_logf(detection_trace, TRACE_RULE_EVAL, "Fast pattern %s[%u] = '%s' |%s| %s\n", pm_type_strings[pmd->pm_type], pmd->pattern_size, txt.c_str(), hex.c_str(), opts.c_str()); @@ -100,12 +96,12 @@ void print_pattern(const PatternMatchData* pmd) void dump_buffer(const uint8_t* buff, unsigned len, Packet* p) { - if (!trace_enabled(TRACE_NAME(detection), trace_buffer)) + if ( !detection_trace.enabled(TRACE_BUFFER) ) return; if (len == 0) { - trace_log(detection, "Buffer dump - empty buffer\n"); + debug_log(detection_trace, TRACE_BUFFER, "Buffer dump - empty buffer\n"); return; } @@ -119,23 +115,21 @@ void node_eval_trace(const detection_option_tree_node_t* node, const Cursor& cur if (node->option_type != RULE_OPTION_TYPE_LEAF_NODE ) { - trace_logf(detection, TRACE_RULE_EVAL, + debug_logf(detection_trace, TRACE_RULE_EVAL, "Evaluating option %s, cursor name %s, cursor position %u\n", ((IpsOption*)node->option_data)->get_name(), name, pos); } else { - trace_logf(detection, TRACE_RULE_EVAL, "Reached leaf, cursor name %s, cursor position %u\n", - name, pos); + debug_logf(detection_trace, TRACE_RULE_EVAL, + "Reached leaf, cursor name %s, cursor position %u\n", name, pos); } - if (!trace_enabled(TRACE_NAME(detection), trace_buffer)) + if ( !detection_trace.enabled(TRACE_BUFFER) ) return; - if (trace_enabled(TRACE_NAME(detection), TRACE_BUFFER_VERBOSE)) - { - dump_buffer(cursor.buffer() + pos, cursor.length(), p); - } + if ( detection_trace.enabled(TRACE_BUFFER, 5) ) + dump_buffer(cursor.buffer() + pos, cursor.length(), p); else if ((pos != cursor_pos) || strcmp(cursor_name, name)) { cursor_pos = pos; diff --git a/src/detection/detect_trace.h b/src/detection/detect_trace.h index 43189147e..af4b09097 100644 --- a/src/detection/detect_trace.h +++ b/src/detection/detect_trace.h @@ -28,24 +28,25 @@ namespace snort { - struct Packet; +struct Packet; +struct Trace; } +extern snort::Trace detection_trace; + struct detection_option_tree_node_t; struct PatternMatchData; enum { - TRACE_NONE = 0, - TRACE_DETECTION_ENGINE = 0x1, - TRACE_RULE_EVAL = 0x2, - TRACE_BUFFER_MINIMAL = 0x4, - TRACE_BUFFER_VERBOSE = 0x8, - TRACE_RULE_VARS = 0x10, - TRACE_FP_SEARCH = 0x20, - TRACE_PKT_DETECTION = 0x40, - TRACE_OPTION_TREE = 0x80, - TRACE_TAG = 0x100, + TRACE_DETECTION_ENGINE = 0, + TRACE_RULE_EVAL, + TRACE_BUFFER, + TRACE_RULE_VARS, + TRACE_FP_SEARCH, + TRACE_PKT_DETECTION, + TRACE_OPTION_TREE, + TRACE_TAG, }; void clear_trace_cursor_info(); diff --git a/src/detection/detection_engine.cc b/src/detection/detection_engine.cc index db34ca33a..b7c92151d 100644 --- a/src/detection/detection_engine.cc +++ b/src/detection/detection_engine.cc @@ -325,8 +325,8 @@ void DetectionEngine::clear_replacement() void DetectionEngine::disable_all(Packet* p) { p->context->active_rules = IpsContext::NONE; - trace_logf(detection, TRACE_PKT_DETECTION, - "Disabled all detect, packet %" PRIu64"\n", p->context->packet_number); + debug_logf(detection_trace, TRACE_PKT_DETECTION, "Disabled all detect, packet %" PRIu64"\n", + p->context->packet_number); } bool DetectionEngine::all_disabled(Packet* p) @@ -337,7 +337,7 @@ void DetectionEngine::disable_content(Packet* p) if ( p->context->active_rules == IpsContext::CONTENT ) p->context->active_rules = IpsContext::NON_CONTENT; - trace_logf(detection, TRACE_PKT_DETECTION, + debug_logf(detection_trace, TRACE_PKT_DETECTION, "Disabled content detect, packet %" PRIu64"\n", p->context->packet_number); } @@ -372,9 +372,9 @@ bool DetectionEngine::do_offload(Packet* p) p->context->conf = SnortConfig::get_conf(); - trace_logf(detection, TRACE_DETECTION_ENGINE, "%" PRIu64 " de::offload %" PRIu64 - " (r=%d)\n", p->context->packet_number, p->context->context_num, - offloader->count()); + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, + "%" PRIu64 " de::offload %" PRIu64 " (r=%d)\n", + p->context->packet_number, p->context->context_num, offloader->count()); sw->suspend(); p->set_offloaded(); @@ -424,12 +424,12 @@ void DetectionEngine::idle() { while ( offloader->count() ) { - trace_logf(detection, - TRACE_DETECTION_ENGINE, "(wire) %" PRIu64 " de::sleep\n", get_packet_number()); + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, "(wire) %" PRIu64 " de::sleep\n", + get_packet_number()); onload(); } - trace_logf(detection, TRACE_DETECTION_ENGINE, "(wire) %" PRIu64 " de::idle (r=%d)\n", + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, "(wire) %" PRIu64 " de::idle (r=%d)\n", get_packet_number(), offloader->count()); offloader->stop(); @@ -443,8 +443,8 @@ void DetectionEngine::onload(Flow* flow) while ( flow->is_suspended() ) { - trace_logf(detection, - TRACE_DETECTION_ENGINE, "(wire) %" PRIu64 " de::sleep\n", get_packet_number()); + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, + "(wire) %" PRIu64 " de::sleep\n", get_packet_number()); resume_ready_suspends(flow->context_chain); // FIXIT-M makes onload reentrant-safe onload(); @@ -459,7 +459,7 @@ void DetectionEngine::onload() while (offloader->count() and offloader->get(p)) { - trace_logf(detection, TRACE_DETECTION_ENGINE, + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, "%" PRIu64 " de::onload %" PRIu64 " (r=%d)\n", p->context->packet_number, p->context->context_num, offloader->count()); @@ -486,7 +486,8 @@ void DetectionEngine::resume_ready_suspends(const IpsContextChain& chain) void DetectionEngine::complete(Packet* p) { - trace_logf(detection, TRACE_DETECTION_ENGINE, "%" PRIu64 " de::resume %" PRIu64 " (r=%d)\n", + debug_logf(detection_trace, TRACE_DETECTION_ENGINE, + "%" PRIu64 " de::resume %" PRIu64 " (r=%d)\n", p->context->packet_number, p->context->context_num, offloader->count()); ContextSwitcher* sw = Analyzer::get_switcher(); diff --git a/src/detection/detection_module.cc b/src/detection/detection_module.cc index 639880a2e..e97ba5847 100644 --- a/src/detection/detection_module.cc +++ b/src/detection/detection_module.cc @@ -35,26 +35,28 @@ using namespace snort; +static const char s_module_name[] = "detection"; + /* *INDENT-OFF* */ // Uncrustify handles this section incorrectly. static const Parameter detection_module_trace_values[] = { - { "detect_engine", Parameter::PT_INT, "0:max53", "0", "enable detection engine trace logging" }, + { "all", Parameter::PT_INT, "0:255", "0", "enable detection module trace logging options" }, - { "rule_eval", Parameter::PT_INT, "0:max53", "0", "enable rule evaluation trace logging" }, + { "detect_engine", Parameter::PT_INT, "0:255", "0", "enable detection engine trace logging" }, - { "buf_min", Parameter::PT_INT, "0:max53", "0", "enable min buffer trace logging" }, + { "rule_eval", Parameter::PT_INT, "0:255", "0", "enable rule evaluation trace logging" }, - { "buf_verbose", Parameter::PT_INT, "0:max53", "0", "enable verbose buffer trace logging" }, + { "buffer", Parameter::PT_INT, "0:255", "0", "enable buffer trace logging" }, - { "rule_vars", Parameter::PT_INT, "0:max53", "0", "enable rule variables trace logging" }, + { "rule_vars", Parameter::PT_INT, "0:255", "0", "enable rule variables trace logging" }, - { "fp_search", Parameter::PT_INT, "0:max53", "0", "enable fast pattern search trace logging" }, + { "fp_search", Parameter::PT_INT, "0:255", "0", "enable fast pattern search trace logging" }, - { "pkt_detect", Parameter::PT_INT, "0:max53", "0", "enable packet detection trace logging" }, + { "pkt_detect", Parameter::PT_INT, "0:255", "0", "enable packet detection trace logging" }, - { "opt_tree", Parameter::PT_INT, "0:max53", "0", "enable tree option trace logging" }, + { "opt_tree", Parameter::PT_INT, "0:255", "0", "enable tree option trace logging" }, - { "tag", Parameter::PT_INT, "0:max53", "0", "enable tag trace logging" }, + { "tag", Parameter::PT_INT, "0:255", "0", "enable tag trace logging" }, { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } }; @@ -66,12 +68,11 @@ static const Parameter detection_module_trace[] = { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } }; -static const TraceValue detection_trace_masks[] = +static const TraceOptionString detection_trace_options[] = { { "detect_engine", TRACE_DETECTION_ENGINE }, { "rule_eval", TRACE_RULE_EVAL }, - { "buf_min", TRACE_BUFFER_MINIMAL }, - { "buf_verbose", TRACE_BUFFER_VERBOSE }, + { "buffer", TRACE_BUFFER }, { "rule_vars", TRACE_RULE_VARS }, { "fp_search", TRACE_FP_SEARCH }, { "pkt_detect", TRACE_PKT_DETECTION }, @@ -79,8 +80,8 @@ static const TraceValue detection_trace_masks[] = { "tag", TRACE_TAG } }; -static TraceMask detection_module_trace_mask(detection_trace_masks, - (sizeof(detection_trace_masks) / sizeof(TraceValue))); +Trace detection_trace(s_module_name, detection_trace_options, + (sizeof(detection_trace_options) / sizeof(TraceOptionString))); static const Parameter detection_params[] = { @@ -131,8 +132,8 @@ static const Parameter detection_params[] = #define detection_help \ "configure general IPS rule processing parameters" -DetectionModule::DetectionModule() : Module("detection", detection_help, - detection_params, false, &TRACE_NAME(detection), detection_module_trace, &detection_module_trace_mask) +DetectionModule::DetectionModule() : Module(s_module_name, detection_help, + detection_params, false, &detection_trace, detection_module_trace) { } bool DetectionModule::end(const char*, int, SnortConfig* sc) diff --git a/src/detection/detection_module.h b/src/detection/detection_module.h index 547a84fff..996b3caa4 100644 --- a/src/detection/detection_module.h +++ b/src/detection/detection_module.h @@ -45,6 +45,4 @@ public: }; } -extern Trace TRACE_NAME(detection); - #endif // DETECTION_MODULE_H diff --git a/src/detection/detection_options.cc b/src/detection/detection_options.cc index f7124f8c9..c948b7c3f 100644 --- a/src/detection/detection_options.cc +++ b/src/detection/detection_options.cc @@ -53,6 +53,7 @@ #include "profiler/rule_profiler_defs.h" #include "protocols/packet_manager.h" #include "utils/util.h" +#include "utils/util_cstring.h" #include "detection_engine.h" #include "detection_module.h" @@ -315,7 +316,7 @@ void print_option_tree(detection_option_tree_node_t* node, int level) opt = buf; } - trace_logf(detection, TRACE_OPTION_TREE, "%3d %3d %p %*s\n", + debug_logf(detection_trace, TRACE_OPTION_TREE, "%3d %3d %p %*s\n", level, node->num_children, node->option_data, (int)(level + strlen(opt)), opt); for ( int i=0; inum_children; i++ ) @@ -383,7 +384,7 @@ int detection_option_node_evaluate( !(p->packet_flags & PKT_IP_RULE_2ND) && !p->is_udp_tunneled() ) { - trace_log(detection, TRACE_RULE_EVAL, + debug_log(detection_trace, TRACE_RULE_EVAL, "Was evaluated before, returning last check result\n"); return last_check.result; } @@ -435,7 +436,7 @@ int detection_option_node_evaluate( if ( !sig_info.services.empty() and check_ports ) { - trace_logf(detection, TRACE_RULE_EVAL, + debug_logf(detection_trace, TRACE_RULE_EVAL, "SID %u not matched because of service mismatch %d\n", sig_info.sid, snort_protocol_id); break; // out of case @@ -456,7 +457,7 @@ int detection_option_node_evaluate( if ( otn->detection_filter ) { - trace_log(detection, TRACE_RULE_EVAL, + debug_log(detection_trace, TRACE_RULE_EVAL, "Evaluating detection filter\n"); f_result = !detection_filter_test(otn->detection_filter, p->ptrs.ip_api.get_src(), p->ptrs.ip_api.get_dst(), @@ -471,7 +472,7 @@ int detection_option_node_evaluate( { #ifdef DEBUG_MSGS const SigInfo& si = otn->sigInfo; - trace_logf(detection, TRACE_RULE_EVAL, + debug_logf(detection_trace, TRACE_RULE_EVAL, "Matched rule gid:sid:rev %u:%u:%u\n", si.gid, si.sid, si.rev); #endif fpAddMatch(p->context->otnx, otn); @@ -481,7 +482,7 @@ int detection_option_node_evaluate( } #ifdef DEBUG_MSGS else - trace_log(detection, TRACE_RULE_EVAL, "Header check failed\n"); + debug_log(detection_trace, TRACE_RULE_EVAL, "Header check failed\n"); #endif break; @@ -533,13 +534,13 @@ int detection_option_node_evaluate( if ( rval == (int)IpsOption::NO_MATCH ) { - trace_log(detection, TRACE_RULE_EVAL, "no match\n"); + debug_log(detection_trace, TRACE_RULE_EVAL, "no match\n"); state.last_check.result = result; return result; } else if ( rval == (int)IpsOption::FAILED_BIT ) { - trace_log(detection, TRACE_RULE_EVAL, "failed bit\n"); + debug_log(detection_trace, TRACE_RULE_EVAL, "failed bit\n"); eval_data.flowbit_failed = 1; // clear the timestamp so failed flowbit gets eval'd again state.last_check.flowbit_failed = 1; @@ -552,18 +553,29 @@ int detection_option_node_evaluate( // so nodes below this don't alert. tmp_noalert_flag = eval_data.flowbit_noalert; eval_data.flowbit_noalert = 1; - trace_log(detection, TRACE_RULE_EVAL, "flowbit no alert\n"); + debug_log(detection_trace, TRACE_RULE_EVAL, "flowbit no alert\n"); } // Back up byte_extract vars so they don't get overwritten between rules - trace_log(detection, TRACE_RULE_VARS, "Rule options variables: \n"); for ( unsigned i = 0; i < NUM_IPS_OPTIONS_VARS; ++i ) { GetVarValueByIndex(&(tmp_byte_extract_vars[i]), (int8_t)i); - trace_logf_wo_name(detection, TRACE_RULE_VARS, "var[%d]=%d ", i, - tmp_byte_extract_vars[i]); } - trace_log_wo_name(detection, TRACE_RULE_VARS, "\n"); +#ifdef DEBUG_MSGS + if ( detection_trace.enabled(TRACE_RULE_VARS) ) + { + char var_buf[100]; + std::string rule_vars; + rule_vars.reserve(sizeof(var_buf)); + for ( unsigned i = 0; i < NUM_IPS_OPTIONS_VARS; ++i ) + { + safe_snprintf(var_buf, sizeof(var_buf), "var[%d]=%d ", i, tmp_byte_extract_vars[i]); + rule_vars.append(var_buf); + } + debug_logf(detection_trace, TRACE_RULE_VARS, "Rule options variables: %s\n", + rule_vars.c_str()); + } +#endif if ( PacketLatency::fastpath() ) { diff --git a/src/detection/detection_options.h b/src/detection/detection_options.h index f5523cfaa..8cfca7ac6 100644 --- a/src/detection/detection_options.h +++ b/src/detection/detection_options.h @@ -37,8 +37,6 @@ #include "time/clock_defs.h" #include "main/snort_debug.h" -extern Trace TRACE_NAME(detection); - namespace snort { class HashNode; diff --git a/src/detection/fp_detect.cc b/src/detection/fp_detect.cc index 55057a973..21135de0c 100644 --- a/src/detection/fp_detect.cc +++ b/src/detection/fp_detect.cc @@ -346,7 +346,7 @@ static int detection_option_tree_evaluate(detection_option_tree_root_t* root, Cursor c(eval_data.p); int rval = 0; - trace_log(detection, TRACE_RULE_EVAL, "Starting tree eval\n"); + debug_log(detection_trace, TRACE_RULE_EVAL, "Starting tree eval\n"); for ( int i = 0; i < root->num_children; ++i ) { @@ -806,7 +806,8 @@ bool MpseStash::process(MpseMatch match, void* context) #ifdef DEBUG_MSGS if (count == 0) - trace_log(detection, TRACE_RULE_EVAL, "Fast pattern processing - no matches found\n"); + debug_log(detection_trace, TRACE_RULE_EVAL, + "Fast pattern processing - no matches found\n"); #endif unsigned i = 0; for ( auto it : queue ) @@ -814,7 +815,7 @@ bool MpseStash::process(MpseMatch match, void* context) Node& node = it; i++; // process a pattern - case is handled by otn processing - trace_logf(detection, TRACE_RULE_EVAL,"Processing pattern match #%d\n", i); + debug_logf(detection_trace, TRACE_RULE_EVAL,"Processing pattern match #%d\n", i); int res = match(node.user, node.tree, node.index, context, node.list); if ( res > 0 ) @@ -895,7 +896,7 @@ static inline int search_buffer( if ( MpseGroup* so = pg->mpsegrp[pmt] ) { // FIXIT-H DELETE ME done - get the context packet number - trace_logf(detection, TRACE_FP_SEARCH, "%" PRIu64 " fp %s.%s[%d]\n", + debug_logf(detection_trace, TRACE_FP_SEARCH, "%" PRIu64 " fp %s.%s[%d]\n", p->context->packet_number, gadget->get_name(), pm_type_strings[pmt], buf.len); batch_search(so, p, buf.data, buf.len, cnt); @@ -909,7 +910,7 @@ static int fp_search(PortGroup* port_group, Packet* p) Inspector* gadget = p->flow ? p->flow->gadget : nullptr; InspectionBuffer buf; - trace_log(detection, TRACE_RULE_EVAL, "Fast pattern search\n"); + debug_log(detection_trace, TRACE_RULE_EVAL, "Fast pattern search\n"); if ( p->data and p->dsize ) { @@ -918,7 +919,7 @@ static int fp_search(PortGroup* port_group, Packet* p) { if ( uint16_t pattern_match_size = p->get_detect_limit() ) { - trace_logf(detection, TRACE_FP_SEARCH, "%" PRIu64 " fp %s[%u]\n", + debug_logf(detection_trace, TRACE_FP_SEARCH, "%" PRIu64 " fp %s[%u]\n", p->context->packet_number, pm_type_strings[PM_TYPE_PKT], pattern_match_size); batch_search(so, p, p->data, pattern_match_size, pc.pkt_searches); @@ -956,7 +957,7 @@ static int fp_search(PortGroup* port_group, Packet* p) if ( file_data.len ) { - trace_logf(detection, TRACE_FP_SEARCH, "%" PRIu64 " fp search %s[%d]\n", + debug_logf(detection_trace, TRACE_FP_SEARCH, "%" PRIu64 " fp search %s[%d]\n", p->context->packet_number, pm_type_strings[PM_TYPE_FILE], file_data.len); batch_search(so, p, file_data.data, file_data.len, pc.file_searches); @@ -1046,7 +1047,7 @@ static inline void eval_nfp( int rval = 0; { - trace_log(detection, TRACE_RULE_EVAL, "Testing non-content rules\n"); + debug_log(detection_trace, TRACE_RULE_EVAL, "Testing non-content rules\n"); rval = detection_option_tree_evaluate( (detection_option_tree_root_t*)port_group->nfp_tree, eval_data); } diff --git a/src/detection/tag.cc b/src/detection/tag.cc index 200d31b57..dc6d1f2ee 100644 --- a/src/detection/tag.cc +++ b/src/detection/tag.cc @@ -328,7 +328,7 @@ static void AddTagNode(Packet* p, TagData* tag, int mode, uint32_t now, TagNode* returned; XHash* tag_cache_ptr = nullptr; - trace_logf(detection, TRACE_TAG, "Adding new Tag Head\n"); + debug_log(detection_trace, TRACE_TAG, "Adding new Tag Head\n"); if ( tag->tag_metric & TAG_METRIC_SESSION ) { diff --git a/src/detection/tag.h b/src/detection/tag.h index 444e4c0dd..0edf6609e 100644 --- a/src/detection/tag.h +++ b/src/detection/tag.h @@ -30,7 +30,6 @@ #include #include "main/snort_debug.h" -extern Trace TRACE_NAME(detection); namespace snort { diff --git a/src/framework/module.cc b/src/framework/module.cc index 5015cdfa1..ec5b390e8 100644 --- a/src/framework/module.cc +++ b/src/framework/module.cc @@ -27,7 +27,7 @@ using namespace snort; static const Parameter default_trace[] = { - { "all", Parameter::PT_INT, "0:max32", "0", "enabling traces in module" }, + { "all", Parameter::PT_INT, "0:255", "0", "enable traces in module" }, { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } }; @@ -39,14 +39,6 @@ static const Parameter default_trace_params[] = { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } }; -static const TraceValue default_trace_values[] = -{ - { "all", 1 } -}; - -static TraceMask s_default_trace_values(default_trace_values, - (sizeof(default_trace_values) / sizeof(TraceValue))); - std::string Command::get_arg_list() const { std::string args = "("; @@ -63,24 +55,10 @@ std::string Command::get_arg_list() const return args; } -bool TraceMask::set(const Value& v, Trace* mask) +void Module::reset_trace() { - const TraceValue* tv = &values[0]; - int isize = m_size; - - while ( isize-- ) - { - if ( v.is(tv->alias) ) - { - uint8_t opt_val = v.get_uint8(); - if ( opt_val ) - *mask |= tv->mask; - return true; - } - tv++; - } - - return false; + if ( trace ) + trace->reset(); } void Module::init(const char* s, const char* h) @@ -97,7 +75,7 @@ Module::Module(const char* s, const char* h) { init(s, h); } Module::Module(const char* s, const char* h, const Parameter* p, bool is_list, Trace* t, - const Parameter* module_trace_param, TraceMask* module_trace_mask) + const Parameter* module_trace_param) { init(s, h); list = is_list; @@ -110,12 +88,10 @@ Module::Module(const char* s, const char* h, const Parameter* p, bool is_list, T if ( module_trace_param ) { default_params = module_trace_param; - trace_mask = module_trace_mask; } else { default_params = default_trace_params; - trace_mask = &s_default_trace_values; } } } @@ -123,7 +99,7 @@ Module::Module(const char* s, const char* h, const Parameter* p, bool is_list, T bool Module::set(const char* fqn, Value& v, SnortConfig*) { if ( strstr(fqn, ".trace.") ) - return trace_mask and trace_mask->set(v, trace); + return trace and trace->set(v); return false; } @@ -240,8 +216,8 @@ bool Module::verified_end(const char* fqn, int idx, SnortConfig* c) void Module::enable_trace() { - if ( trace_mask ) - trace_mask->set(trace); + if ( trace ) + trace->enable(); } namespace snort diff --git a/src/framework/module.h b/src/framework/module.h index dbfc76442..fcf64a415 100644 --- a/src/framework/module.h +++ b/src/framework/module.h @@ -75,30 +75,6 @@ struct RuleMap const char* msg; }; -struct TraceValue { - const char* alias; - Trace mask; -}; - -class TraceMask -{ -public: - TraceMask(const TraceValue* array, size_t size) : values(array), m_size(size) - {} - - bool set(const Value& v, Trace* mask); - - bool set(Trace* mask) - { - *mask = 1; - return true; - } - -private: - const TraceValue* values; - size_t m_size; -}; - class SO_PUBLIC Module { public: @@ -212,11 +188,12 @@ public: { return CONTEXT; } void enable_trace(); + void reset_trace(); protected: Module(const char* name, const char* help); Module(const char* name, const char* help, const Parameter*, - bool is_list = false, Trace* = nullptr, const Parameter* = nullptr, TraceMask* = nullptr); + bool is_list = false, Trace* = nullptr, const Parameter* = nullptr); private: friend ModuleManager; @@ -230,11 +207,9 @@ private: const Parameter* params; const Parameter* default_params = nullptr; - TraceMask* trace_mask = nullptr; bool list; int table_level = 0; - - Trace* trace; + Trace* trace = nullptr; void set_peg_count(int index, PegCount value) { diff --git a/src/host_tracker/test/host_cache_module_test.cc b/src/host_tracker/test/host_cache_module_test.cc index 4f1a5a94a..e048064c0 100644 --- a/src/host_tracker/test/host_cache_module_test.cc +++ b/src/host_tracker/test/host_cache_module_test.cc @@ -67,6 +67,12 @@ extern "C" const char* luaL_optlstring(lua_State*, int, const char*, size_t*) { return nullptr; } } +Trace::Trace(const char*, const TraceOptionString*, size_t) {} +Trace::Trace(const char*) {} +bool Trace::set(const snort::Value&) { return true; } +void Trace::reset() {} +void Trace::enable() {} + void show_stats(PegCount*, const PegInfo*, unsigned, const char*) { } void show_stats(PegCount*, const PegInfo*, const IndexVec&, const char*, FILE*) { } diff --git a/src/host_tracker/test/host_tracker_module_test.cc b/src/host_tracker/test/host_tracker_module_test.cc index ad74160c9..c69cc8435 100644 --- a/src/host_tracker/test/host_tracker_module_test.cc +++ b/src/host_tracker/test/host_tracker_module_test.cc @@ -42,6 +42,12 @@ char* snort_strdup(const char* s) time_t packet_time() { return 0; } } +Trace::Trace(const char*, const TraceOptionString*, size_t) {} +Trace::Trace(const char*) {} +bool Trace::set(const snort::Value&) { return true; } +void Trace::reset() {} +void Trace::enable() {} + // Fake show_stats to avoid bringing in a ton of dependencies. void show_stats(PegCount*, const PegInfo*, unsigned, const char*) { } void show_stats(PegCount*, const PegInfo*, const IndexVec&, const char*, FILE*) { } diff --git a/src/ips_options/test/ips_regex_test.cc b/src/ips_options/test/ips_regex_test.cc index b3d5e45da..6962a362d 100644 --- a/src/ips_options/test/ips_regex_test.cc +++ b/src/ips_options/test/ips_regex_test.cc @@ -98,6 +98,12 @@ extern const BaseApi* ips_regex; Cursor::Cursor(Packet* p) { set("pkt_data", p->data, p->dsize); } +Trace::Trace(const char*, const TraceOptionString*, size_t) {} +Trace::Trace(const char*) {} +bool Trace::set(const snort::Value&) { return true; } +void Trace::reset() {} +void Trace::enable() {} + void show_stats(PegCount*, const PegInfo*, unsigned, const char*) { } void show_stats(PegCount*, const PegInfo*, const IndexVec&, const char*, FILE*) { } diff --git a/src/main.cc b/src/main.cc index 8d5afaa53..24665ae49 100644 --- a/src/main.cc +++ b/src/main.cc @@ -212,7 +212,7 @@ bool Pig::queue_command(AnalyzerCommand* ac, bool orphan) #ifdef DEBUG_MSGS unsigned ac_ref_count = ac->get(); - trace_logf(snort, "[%u] Queuing command %s for execution (refcount %u)\n", + debug_logf(snort_trace, "[%u] Queuing command %s for execution (refcount %u)\n", idx, ac->stringify(), ac_ref_count); #else ac->get(); @@ -226,13 +226,13 @@ void Pig::reap_command(AnalyzerCommand* ac) unsigned ac_ref_count = ac->put(); if (ac_ref_count == 0) { - trace_logf(snort, "[%u] Destroying completed command %s\n", + debug_logf(snort_trace, "[%u] Destroying completed command %s\n", idx, ac->stringify()); delete ac; } #ifdef DEBUG_MSGS else - trace_logf(snort, "[%u] Reaped ongoing command %s (refcount %u)\n", + debug_logf(snort_trace, "[%u] Reaped ongoing command %s (refcount %u)\n", idx, ac->stringify(), ac_ref_count); #endif } @@ -294,7 +294,7 @@ void snort::main_broadcast_command(AnalyzerCommand* ac, bool from_shell) unsigned dispatched = 0; ac = get_command(ac, from_shell); - trace_logf(snort, "Broadcasting %s command\n", ac->stringify()); + debug_logf(snort_trace, "Broadcasting %s command\n", ac->stringify()); for (unsigned idx = 0; idx < max_pigs; ++idx) { @@ -702,7 +702,7 @@ static void reap_commands() { AnalyzerCommand* ac = orphan_commands.front(); orphan_commands.pop(); - trace_logf(snort, "Destroying orphan command %s\n", ac->stringify()); + debug_logf(snort_trace, "Destroying orphan command %s\n", ac->stringify()); delete ac; } } diff --git a/src/main/CMakeLists.txt b/src/main/CMakeLists.txt index f522bdd44..1ae5531e9 100644 --- a/src/main/CMakeLists.txt +++ b/src/main/CMakeLists.txt @@ -6,12 +6,9 @@ set (INCLUDES snort_debug.h snort_types.h thread.h + trace.h ) -if ( ENABLE_DEBUG_MSGS ) - set ( DEBUG_MSGS_SOURCES snort_debug.cc ) -endif ( ENABLE_DEBUG_MSGS ) - if ( ENABLE_SHELL ) set ( SHELL_SOURCES control.cc control.h control_mgmt.cc control_mgmt.h ac_shell_cmd.h ac_shell_cmd.cc) endif ( ENABLE_SHELL ) @@ -37,6 +34,7 @@ add_library (main OBJECT snort.cc snort.h snort_config.cc + snort_debug.cc snort_module.h snort_module.cc swapper.cc @@ -44,7 +42,7 @@ add_library (main OBJECT thread.cc thread_config.h thread_config.cc - ${DEBUG_MSGS_SOURCES} + trace.cc ${INCLUDES} ${SHELL_SOURCES} ) diff --git a/src/main/modules.cc b/src/main/modules.cc index 2e348583d..913b7b885 100644 --- a/src/main/modules.cc +++ b/src/main/modules.cc @@ -1987,96 +1987,3 @@ void module_init() ModuleManager::add_module(new HostTrackerModule); ModuleManager::add_module(new HostCacheModule); } - -#ifdef UNIT_TEST - -#include - -//------------------------------------------------------------------------- -// Set trace option tests -//------------------------------------------------------------------------- - -namespace -{ -const TraceValue default_trace_values[] = -{ - { "all", 1 } -}; - -TraceMask s_default_trace_values(default_trace_values, - (sizeof(default_trace_values) / sizeof(TraceValue))); -} - -TEST_CASE("TraceMask - single trace value", "[trace_mask]") -{ - Trace test_bitmask = 0; - Parameter p("all", Parameter::PT_INT, "0:max32", "0", "enabling traces in module"); - Value trace_val((double)1); - trace_val.set(&p); - - bool result = s_default_trace_values.set(trace_val, &test_bitmask); - CHECK( result == true ); - CHECK( test_bitmask == 1 ); -} - -TEST_CASE("TraceMask - multiple trace values", "[trace_mask]") -{ - enum - { - TEST_TRACE_DETECTION_ENGINE = 0x1, - TEST_TRACE_RULE_VARS = 0x10, - TEST_TRACE_OPTION_TREE = 0x80, - TEST_TRACE_TAG = 0x100, - }; - const TraceValue test_trace_values[] = - { - { "detect_engine", TEST_TRACE_DETECTION_ENGINE }, - { "rule_vars", TEST_TRACE_RULE_VARS }, - { "opt_tree", TEST_TRACE_OPTION_TREE }, - { "tag", TEST_TRACE_TAG } - }; - TraceMask test_mask(test_trace_values, (sizeof(test_trace_values) / sizeof(TraceValue))); - - Trace test_bitmask = 0; - Parameter p1("detect_engine", Parameter::PT_INT, "0:max32", "0", "p1"); - Parameter p2("rule_vars", Parameter::PT_INT, "0:max32", "0", "p2"); - Parameter p3("opt_tree", Parameter::PT_INT, "0:max32", "0", "p3"); - Parameter p4("tag", Parameter::PT_INT, "0:max32", "0", "p4"); - Value trace_val("trace"); - trace_val.set(&p1); - trace_val.set_enum(1); - - bool result = test_mask.set(trace_val, &test_bitmask); - CHECK( result == true ); - CHECK( test_bitmask == TEST_TRACE_DETECTION_ENGINE ); - - trace_val.set(&p2); - result = test_mask.set(trace_val, &test_bitmask); - CHECK( result == true ); - CHECK( test_bitmask == (TEST_TRACE_DETECTION_ENGINE | TEST_TRACE_RULE_VARS) ); - - trace_val.set(&p3); - result = test_mask.set(trace_val, &test_bitmask); - CHECK( result == true ); - CHECK( test_bitmask == (TEST_TRACE_DETECTION_ENGINE | TEST_TRACE_RULE_VARS | TEST_TRACE_OPTION_TREE) ); - - trace_val.set(&p4); - result = test_mask.set(trace_val, &test_bitmask); - CHECK( result == true ); - CHECK( test_bitmask == (TEST_TRACE_DETECTION_ENGINE | TEST_TRACE_RULE_VARS | TEST_TRACE_OPTION_TREE | TEST_TRACE_TAG) ); -} - -TEST_CASE("TraceMask - incorrect trace value", "[trace_mask]") -{ - Trace test_bitmask = 0; - Parameter p("test", Parameter::PT_INT, "0:max32", "0", "p"); - Value trace_val("trace"); - trace_val.set(&p); - trace_val.set_enum(1); - - bool result = s_default_trace_values.set(trace_val, &test_bitmask); - CHECK( result == false ); - CHECK( test_bitmask == 0 ); -} - -#endif // UNIT_TEST diff --git a/src/main/snort_debug.cc b/src/main/snort_debug.cc index 72ec34559..e3ff27705 100644 --- a/src/main/snort_debug.cc +++ b/src/main/snort_debug.cc @@ -33,18 +33,19 @@ #include "snort_config.h" -using namespace snort; - +namespace snort +{ template -static inline void trace_vprintf(const char* name, const char* fmt, va_list ap) +static inline void trace_vprintf(const char* name, TraceLevel log_level, + const char* trace_option, const char* fmt, va_list ap) { char buf[STD_BUF]; int buf_len = sizeof(buf); char* buf_ptr = buf; - if (name) + if ( name ) { - int size = snprintf(buf, buf_len, "%s: ", name); + int size = snprintf(buf, buf_len, "%s:%s:%d: ", name, trace_option, log_level); if ( size >= buf_len ) size = buf_len - 1; if ( size > 0 ) @@ -62,25 +63,26 @@ static inline void trace_vprintf(const char* name, const char* fmt, va_list ap) output(buf, stdout); } -void trace_vprintf(const char* name, const char* fmt, va_list ap) +void trace_vprintf(const char* name, TraceLevel log_level, + const char* trace_option, const char* fmt, va_list ap) { - trace_vprintf(name, fmt, ap); + trace_vprintf(name, log_level, trace_option, fmt, ap); +} } #ifdef UNIT_TEST #include +#ifdef DEBUG_MSGS + +using namespace snort; + //stringify the expansion of the macro #define sx(code) sm(code) //stringify the macro #define sm(code) #code -#define TRACE_SECTION_1 0x0000000000000001 -#define TRACE_SECTION_2 0x0000000000000002 -#define TRACE_SECTION_3 0x0000000000000004 -#define TRACE_SECTION_4 0x0000000000000008 - struct TestCase { const char* test; @@ -100,20 +102,20 @@ TEST_CASE("macros", "[trace]") TestCase cases[] = { { - sx(trace_log(testing, "my message")), - "trace_print(\"testing\", testing_trace, \"my message\")" + sx(debug_log(1, testing, "my message")), + "trace_print(1, testing, \"my message\")" }, { - sx(trace_log(testing, my_flags, "my message")), - "trace_print(\"testing\", testing_trace, my_flags, \"my message\")" + sx(debug_log(testing, my_flags, "my message")), + "trace_print(testing, my_flags, \"my message\")" }, { - sx(trace_logf(testing, "%s %s", "my", "message")), - "trace_printf(\"testing\", testing_trace, \"%s %s\", \"my\", \"message\")" + sx(debug_logf(1, testing, "%s %s", "my", "message")), + "trace_printf(1, testing, \"%s %s\", \"my\", \"message\")" }, { - sx(trace_logf(testing, my_flags, "%s %s", "my", "message")), - "trace_printf(\"testing\", testing_trace, my_flags, \"%s %s\", \"my\", \"message\")" + sx(debug_logf(testing, my_flags, "%s %s", "my", "message")), + "trace_printf(testing, my_flags, \"%s %s\", \"my\", \"message\")" } }; @@ -132,43 +134,180 @@ TEST_CASE("macros", "[trace]") #define trace_print trace_print> #define trace_printf trace_printf> -TEST_CASE("trace_log", "[trace]") +enum +{ + TEST_TRACE_OPTION1 = 0, + TEST_TRACE_OPTION2, + TEST_TRACE_OPTION3, + TEST_TRACE_OPTION4, + TEST_TRACE_OPTION5, +}; + +const TraceOptionString test_trace_values[] = +{ + { "option1", TEST_TRACE_OPTION1 }, + { "option2", TEST_TRACE_OPTION2 }, + { "option3", TEST_TRACE_OPTION3 }, + { "option4", TEST_TRACE_OPTION4 }, + { "option5", TEST_TRACE_OPTION5 }, +}; + +TEST_CASE("trace all=0", "[trace]") { - Trace TRACE_NAME(testing) = TRACE_SECTION_2 | TRACE_SECTION_3; + Trace test("test"); + + Parameter p("all", Parameter::PT_INT, "0:255", "0", "enabling traces in module"); + Value trace_val((double)0); + trace_val.set(&p); + + test.set(trace_val); testing_dump[0] = '\0'; - trace_log(testing, "my message"); - CHECK( !strcmp(testing_dump, "testing: my message") ); + debug_log(test, "my message"); + CHECK( testing_dump[0] == '\0' ); +} + +TEST_CASE("debug_log", "[trace]") +{ + Trace test("test"); + + Parameter p("all", Parameter::PT_INT, "0:255", "0", "enabling traces in module"); + Value trace_val((double)1); + trace_val.set(&p); + + test.set(trace_val); testing_dump[0] = '\0'; - trace_log(testing, TRACE_SECTION_1, "my masked message"); + debug_log(test, "my message"); + CHECK( !strcmp(testing_dump, "test:all:1: my message") ); + + Parameter p_all("all", Parameter::PT_INT, "0:255", "0", "p_all"); + Parameter p1("option1", Parameter::PT_INT, "0:255", "0", "p1"); + Parameter p2("option3", Parameter::PT_INT, "0:255", "0", "p2"); + Value trace_val1("trace"); + + Trace testing_opt("testing_opt", test_trace_values, + (sizeof(test_trace_values) / sizeof(TraceOptionString))); + + // set log_level = 1 for TEST_TRACE_OPTION1 + trace_val1.set(&p1); + trace_val1.set_enum(1); + testing_opt.set(trace_val1); + + // set log_level = 5 for TEST_TRACE_OPTION3 + trace_val1.set(&p2); + trace_val1.set_enum(5); + testing_opt.set(trace_val1); + + // set log_level = 2 for TEST_TRACE_OPTION2, TEST_TRACE_OPTION4, TEST_TRACE_OPTION5 + trace_val1.set(&p_all); + trace_val1.set_enum(2); + testing_opt.set(trace_val1); + + testing_dump[0] = '\0'; + debug_log(testing_opt, TEST_TRACE_OPTION1, "my other masked message"); + CHECK( !strcmp(testing_dump, "testing_opt:option1:1: my other masked message") ); + + testing_dump[0] = '\0'; + debug_log(3, testing_opt, TEST_TRACE_OPTION2, "log option2 message"); CHECK( testing_dump[0] == '\0' ); testing_dump[0] = '\0'; - trace_log(testing, TRACE_SECTION_2, "my other masked message"); - CHECK( !strcmp(testing_dump, "testing: my other masked message") ); + debug_log(testing_opt, TEST_TRACE_OPTION2, "log option2 message"); + CHECK( !strcmp(testing_dump, "testing_opt:option2:1: log option2 message") ); + + testing_dump[0] = '\0'; + debug_log(6, testing_opt, TEST_TRACE_OPTION3, "log option3 message"); + CHECK( testing_dump[0] == '\0' ); + + testing_dump[0] = '\0'; + debug_log(3, testing_opt, TEST_TRACE_OPTION3, "log option3 message"); + CHECK( !strcmp(testing_dump, "testing_opt:option3:3: log option3 message") ); + + testing_dump[0] = '\0'; + debug_log(2, testing_opt, TEST_TRACE_OPTION4, "log option4 message"); + CHECK( !strcmp(testing_dump, "testing_opt:option4:2: log option4 message") ); + + testing_dump[0] = '\0'; + debug_log(4, testing_opt, TEST_TRACE_OPTION5, "log option5 message"); + CHECK( testing_dump[0] == '\0' ); } -TEST_CASE("trace_logf", "[trace]") +TEST_CASE("debug_logf", "[trace]") { - Trace TRACE_NAME(testing) = TRACE_SECTION_2 | TRACE_SECTION_3; + Trace test("test"); + + Parameter p("all", Parameter::PT_INT, "0:255", "0", "enabling traces in module"); + Value trace_val((double)1); + trace_val.set(&p); + test.set(trace_val); + + testing_dump[0] = '\0'; + debug_logf(test, "%s %s", "my", "message"); + CHECK( !strcmp(testing_dump, "test:all:1: my message") ); + + Parameter p_all("all", Parameter::PT_INT, "0:255", "0", "p_all"); + Parameter p1("option1", Parameter::PT_INT, "0:255", "0", "p1"); + Parameter p2("option3", Parameter::PT_INT, "0:255", "0", "p2"); + Value trace_val1("trace"); + + Trace testing_opt("testing_opt", test_trace_values, + (sizeof(test_trace_values) / sizeof(TraceOptionString))); + + // set log_level = 1 for TEST_TRACE_OPTION1 + trace_val1.set(&p1); + trace_val1.set_enum(1); + testing_opt.set(trace_val1); + + // set log_level = 5 for TEST_TRACE_OPTION3 + trace_val1.set(&p2); + trace_val1.set_enum(5); + testing_opt.set(trace_val1); + + // set log_level = 3 for TEST_TRACE_OPTION2, TEST_TRACE_OPTION4, TEST_TRACE_OPTION5 + trace_val1.set(&p_all); + trace_val1.set_enum(3); + testing_opt.set(trace_val1); + + testing_dump[0] = '\0'; + debug_logf(testing_opt, TEST_TRACE_OPTION1, "%s %s %s", "log", "option1", "message"); + CHECK( !strcmp(testing_dump, "testing_opt:option1:1: log option1 message") ); + + testing_dump[0] = '\0'; + debug_logf(testing_opt, TEST_TRACE_OPTION2, "%s %s %s", "log", "option2", "message"); + CHECK( !strcmp(testing_dump, "testing_opt:option2:1: log option2 message") ); testing_dump[0] = '\0'; - trace_logf(testing, "%s %s", "my", "message"); - CHECK( !strcmp(testing_dump, "testing: my message") ); + debug_logf(4, testing_opt, TEST_TRACE_OPTION2, "%s %s %s", "log", "option2", "message"); + CHECK( testing_dump[0] == '\0' ); + + testing_dump[0] = '\0'; + debug_logf(3, testing_opt, TEST_TRACE_OPTION3, "%s %s %s", "log", "option3", "message"); + CHECK( !strcmp(testing_dump, "testing_opt:option3:3: log option3 message") ); testing_dump[0] = '\0'; - trace_logf(testing, TRACE_SECTION_1, "%s %s %s", "my", "masked", "message"); + debug_logf(6, testing_opt, TEST_TRACE_OPTION3, "%s %s %s", "log", "option3", "message"); CHECK( testing_dump[0] == '\0' ); + + testing_dump[0] = '\0'; + debug_logf(2, testing_opt, TEST_TRACE_OPTION4, "%s %s %s", "log", "option4", "message"); + CHECK( !strcmp(testing_dump, "testing_opt:option4:2: log option4 message") ); testing_dump[0] = '\0'; - trace_logf(testing, TRACE_SECTION_2, "%s %s %s %s", "my", "other", "masked", "message"); - CHECK( !strcmp(testing_dump, "testing: my other masked message") ); + debug_logf(4, testing_opt, TEST_TRACE_OPTION5, "%s %s %s", "log", "option5", "message"); + CHECK( testing_dump[0] == '\0' ); } TEST_CASE("safety", "[trace]") { - Trace TRACE_NAME(testing) = TRACE_SECTION_2 | TRACE_SECTION_3; + Trace test("test"); + + Parameter p("all", Parameter::PT_INT, "0:255", "0", "enabling traces in module"); + Value trace_val((double)1); + trace_val.set(&p); + + test.set(trace_val); + char message[STD_BUF + 1]; for( int i = 0; i < STD_BUF; i++ ) @@ -176,9 +315,26 @@ TEST_CASE("safety", "[trace]") message[STD_BUF] = '\0'; testing_dump[0] = '\0'; - trace_log(testing, message); + debug_log(test, message); CHECK( (strlen(testing_dump) == STD_BUF - 1) ); -} + Trace testing_opt("testing_opt", test_trace_values, + (sizeof(test_trace_values) / sizeof(TraceOptionString))); + + Parameter p1("option3", Parameter::PT_INT, "0:255", "0", "p1"); + Value trace_val1("trace"); + trace_val1.set(&p1); + trace_val1.set_enum(5); + testing_opt.set(trace_val1); + + testing_dump[0] = '\0'; + debug_log(3, testing_opt, TEST_TRACE_OPTION3, message); + CHECK( (strlen(testing_dump) == STD_BUF - 1) ); + + testing_dump[0] = '\0'; + debug_log(6, testing_opt, TEST_TRACE_OPTION3, message); + CHECK( (strlen(testing_dump) == 0) ); +} #endif +#endif diff --git a/src/main/snort_debug.h b/src/main/snort_debug.h index ddae34c7c..8069b3d22 100644 --- a/src/main/snort_debug.h +++ b/src/main/snort_debug.h @@ -28,91 +28,133 @@ #include #include "main/snort_types.h" +#include "main/trace.h" -typedef uint64_t Trace; +namespace snort +{ +SO_PUBLIC void trace_vprintf(const char* name, TraceLevel log_level, + const char* trace_option, const char* fmt, va_list); +} -#define TRACE_NAME(name) name##_trace +using trace_func = void(const char*, TraceLevel, const char*, const char*, va_list); -#ifdef DEBUG_MSGS +template +static inline void trace_printf(TraceLevel log_level, const snort::Trace& trace, + TraceOption trace_option, const char* fmt, ...) __attribute__((format (printf, 4, 5))); -void trace_vprintf(const char* name, const char* fmt, va_list); +template +static inline void trace_printf(TraceLevel log_level, const snort::Trace& trace, + TraceOption trace_option, const char* fmt, ...) +{ + if ( !trace.enabled(trace_option, log_level) ) + return; + + va_list ap; + va_start(ap, fmt); -static inline bool trace_enabled(Trace mask, Trace flags) -{ return mask & flags; } + const char* trace_option_name = trace.option_name(trace_option); + trace_vprintf(trace.module_name(), log_level, trace_option_name, fmt, ap); -static inline bool trace_enabled(Trace mask) -{ return mask; } + va_end(ap); +} -template -static inline void trace_printf(const char* name, Trace mask, Trace flags, const char* fmt, ...) - __attribute__((format (printf, 4, 5))); +template +static inline void trace_printf(TraceLevel log_level, const snort::Trace& trace, + const char* fmt, ...) __attribute__((format (printf, 3, 4))); -template -static inline void trace_printf(const char* name, Trace mask, Trace flags, const char* fmt, ...) +template +static inline void trace_printf(TraceLevel log_level, const snort::Trace& trace, + const char* fmt, ...) { - if (!trace_enabled(mask, flags)) + if ( !trace.enabled(DEFAULT_TRACE_OPTION, log_level) ) return; va_list ap; va_start(ap, fmt); - trace_vprintf(name, fmt, ap); + const char* trace_option_name = trace.option_name(DEFAULT_TRACE_OPTION); + trace_vprintf(trace.module_name(), log_level, trace_option_name, fmt, ap); va_end(ap); } -template -static inline void trace_printf(const char* name, Trace mask, const char* fmt, ...) - __attribute__((format (printf, 3, 4))); +template +static inline void trace_printf(const snort::Trace& trace, + TraceOption trace_option, const char* fmt, ...) __attribute__((format (printf, 3, 4))); -template -static inline void trace_printf(const char* name, Trace mask, const char* fmt, ...) +template +static inline void trace_printf(const snort::Trace& trace, + TraceOption trace_option, const char* fmt, ...) { - if (!trace_enabled(mask)) + if ( !trace.enabled(trace_option) ) return; va_list ap; va_start(ap, fmt); - trace_vprintf(name, fmt, ap); + const char* trace_option_name = trace.option_name(trace_option); + trace_vprintf(trace.module_name(), DEFAULT_LOG_LEVEL, trace_option_name, fmt, ap); va_end(ap); } -template -static inline void trace_print(const char* name, Trace mask, const char* msg) +template +static inline void trace_printf(const snort::Trace& trace, + const char* fmt, ...) __attribute__((format (printf, 2, 3))); + +template +static inline void trace_printf(const snort::Trace& trace, const char* fmt, ...) { - trace_printf(name, mask, UINT64_MAX, "%s", msg); + if ( !trace.enabled(DEFAULT_TRACE_OPTION) ) + return; + + va_list ap; + va_start(ap, fmt); + + const char* trace_option_name = trace.option_name(DEFAULT_TRACE_OPTION); + trace_vprintf(trace.module_name(), DEFAULT_LOG_LEVEL, trace_option_name, fmt, ap); + + va_end(ap); } -template -static inline void trace_print(const char* name, Trace mask, Trace flags, const char* msg) +template +static inline void trace_print(TraceLevel log_level, const snort::Trace& trace, + TraceOption trace_option, const char* msg) { - trace_printf(name, mask, flags, "%s", msg); + trace_printf(log_level, trace, trace_option, "%s", msg); } -#define trace_print trace_print -#define trace_printf trace_printf +template +static inline void trace_print(const snort::Trace& trace, TraceOption trace_option, const char* msg) +{ + trace_printf(trace, trace_option, "%s", msg); +} -#define trace_log(tracer, ...) \ - trace_print(#tracer, tracer##_trace, __VA_ARGS__) +template +static inline void trace_print(TraceLevel log_level, const snort::Trace& trace, + const char* msg) +{ + trace_printf(log_level, trace, "%s", msg); +} -#define trace_log_wo_name(tracer, ...) \ - trace_print(nullptr, tracer##_trace, __VA_ARGS__) +template +static inline void trace_print(const snort::Trace& trace, const char* msg) +{ + trace_printf(trace, "%s", msg); +} -#define trace_logf(tracer, ...) \ - trace_printf(#tracer, tracer##_trace, __VA_ARGS__) +#define trace_print trace_print +#define trace_printf trace_printf -#define trace_logf_wo_name(tracer, ...) \ - trace_printf(nullptr, tracer##_trace, __VA_ARGS__) +#define trace_log(...) trace_print(__VA_ARGS__) +#define trace_logf(...) trace_printf(__VA_ARGS__) +#ifdef DEBUG_MSGS +#define debug_log trace_log +#define debug_logf trace_logf #else - -#define trace_log(tracer, ...) -#define trace_log_wo_name(tracer, ...) -#define trace_logf(tracer, ...) -#define trace_logf_wo_name(tracer, ...) - +#define debug_log(...) +#define debug_logf(...) #endif #endif diff --git a/src/main/snort_module.cc b/src/main/snort_module.cc index 94cdde1af..b7f55bdc4 100644 --- a/src/main/snort_module.cc +++ b/src/main/snort_module.cc @@ -600,12 +600,12 @@ static const Parameter s_params[] = "command line configuration" #endif -Trace TRACE_NAME(snort); +Trace snort_trace(s_name); class SnortModule : public Module { public: - SnortModule() : Module(s_name, s_help, s_params, false, &TRACE_NAME(snort)) + SnortModule() : Module(s_name, s_help, s_params, false, &snort_trace) { } #ifdef SHELL diff --git a/src/main/snort_module.h b/src/main/snort_module.h index b20803db2..b1781c833 100644 --- a/src/main/snort_module.h +++ b/src/main/snort_module.h @@ -31,7 +31,7 @@ namespace snort class Module; } -extern Trace TRACE_NAME(snort); +extern snort::Trace snort_trace; snort::Module* get_snort_module(); #endif diff --git a/src/main/trace.cc b/src/main/trace.cc new file mode 100644 index 000000000..8bd5e2f49 --- /dev/null +++ b/src/main/trace.cc @@ -0,0 +1,179 @@ +//-------------------------------------------------------------------------- +// Copyright (C) 2020-2020 Cisco and/or its affiliates. All rights reserved. +// +// This program is free software; you can redistribute it and/or modify it +// under the terms of the GNU General Public License Version 2 as published +// by the Free Software Foundation. You may not use, modify or distribute +// this program under any other version of the GNU General Public License. +// +// This program is distributed in the hope that it will be useful, but +// WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU +// General Public License for more details. +// +// You should have received a copy of the GNU General Public License along +// with this program; if not, write to the Free Software Foundation, Inc., +// 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. +//-------------------------------------------------------------------------- +// trace.cc author Serhii Vlasiuk + +#ifdef HAVE_CONFIG_H +#include "config.h" +#endif + +#include "trace.h" + +using namespace snort; + +static const TraceOptionString default_trace_option[] = +{ + { "all", DEFAULT_TRACE_OPTION } +}; +static const size_t default_trace_size = (sizeof(default_trace_option) / sizeof(TraceOptionString)); + +Trace::Trace(const char* name, const TraceOptionString* trace_options, size_t size) +{ + assert(trace_options); + mod_name = name; + options = trace_options; + option_levels.resize(size, 0); + config_options.resize(size, false); +} + +Trace::Trace(const char* name) +{ + mod_name = name; + options = default_trace_option; + option_levels.resize(default_trace_size, 0); + config_options.resize(default_trace_size, false); +} + +bool Trace::set(const snort::Value& v) +{ + size_t size = option_levels.size(); + if ( v.is("all") ) + { + for ( size_t index = 0; index < size; ++index ) + if ( !config_options[index] ) + option_levels[index] = v.get_uint8(); + return true; + } + + for ( size_t index = 0; index < size; ++index ) + { + if ( v.is(option_name(index)) ) + { + TraceOption trace_option = options[index].option; + + option_levels[trace_option] = v.get_uint8(); + config_options[trace_option] = true; + return true; + } + } + return false; +} + +void Trace::reset() +{ + std::fill(option_levels.begin(), option_levels.end(), 0); + std::fill(config_options.begin(), config_options.end(), false); +} + +void Trace::enable() +{ + option_levels[DEFAULT_TRACE_OPTION] = DEFAULT_LOG_LEVEL; +} + +#ifdef UNIT_TEST + +#include + +//------------------------------------------------------------------------- +// Set trace option tests +//------------------------------------------------------------------------- + + +#define LOG_LEVEL_TEST 1 + +TEST_CASE("Trace - single trace value", "[trace]") +{ + Trace test_trace("test"); + + Parameter p("all", Parameter::PT_INT, "0:255", "0", "enabling traces in module"); + Value trace_val((double)1); + trace_val.set(&p); + + bool result = test_trace.set(trace_val); + CHECK( result == true ); + CHECK( test_trace.option_levels[DEFAULT_TRACE_OPTION] == LOG_LEVEL_TEST ); +} + +TEST_CASE("Trace - multiple trace values", "[trace]") +{ + enum + { + TEST_TRACE_DETECTION_ENGINE = 0, + TEST_TRACE_RULE_VARS, + TEST_TRACE_OPTION_TREE, + TEST_TRACE_TAG, + }; + const TraceOptionString test_trace_values[] = + { + { "detect_engine", TEST_TRACE_DETECTION_ENGINE }, + { "rule_vars", TEST_TRACE_RULE_VARS }, + { "opt_tree", TEST_TRACE_OPTION_TREE }, + { "tag", TEST_TRACE_TAG } + }; + + Trace test_trace("test", test_trace_values, + (sizeof(test_trace_values) / sizeof(TraceOptionString))); + + Parameter p1("detect_engine", Parameter::PT_INT, "0:255", "0", "p1"); + Parameter p2("rule_vars", Parameter::PT_INT, "0:255", "0", "p2"); + Parameter p3("opt_tree", Parameter::PT_INT, "0:255", "0", "p3"); + Parameter p4("tag", Parameter::PT_INT, "0:255", "0", "p4"); + Value trace_val("trace"); + trace_val.set(&p1); + trace_val.set_enum(1); + + bool result = test_trace.set(trace_val); + CHECK( result == true ); + CHECK( test_trace.option_levels[TEST_TRACE_DETECTION_ENGINE] == LOG_LEVEL_TEST ); + + trace_val.set(&p2); + result = test_trace.set(trace_val); + CHECK( result == true ); + CHECK( test_trace.option_levels[TEST_TRACE_DETECTION_ENGINE] == LOG_LEVEL_TEST ); + CHECK( test_trace.option_levels[TEST_TRACE_RULE_VARS] == LOG_LEVEL_TEST ); + + trace_val.set(&p3); + result = test_trace.set(trace_val); + CHECK( result == true ); + CHECK( test_trace.option_levels[TEST_TRACE_DETECTION_ENGINE] == LOG_LEVEL_TEST ); + CHECK( test_trace.option_levels[TEST_TRACE_RULE_VARS] == LOG_LEVEL_TEST ); + CHECK( test_trace.option_levels[TEST_TRACE_OPTION_TREE] == LOG_LEVEL_TEST ); + + trace_val.set(&p4); + result = test_trace.set(trace_val); + CHECK( result == true ); + CHECK( test_trace.option_levels[TEST_TRACE_DETECTION_ENGINE] == LOG_LEVEL_TEST ); + CHECK( test_trace.option_levels[TEST_TRACE_RULE_VARS] == LOG_LEVEL_TEST ); + CHECK( test_trace.option_levels[TEST_TRACE_OPTION_TREE] == LOG_LEVEL_TEST ); + CHECK( test_trace.option_levels[TEST_TRACE_TAG] == LOG_LEVEL_TEST ); +} + +TEST_CASE("Trace - incorrect trace value", "[trace]") +{ + Trace test_trace("test"); + Parameter p("test", Parameter::PT_INT, "0:255", "0", "p"); + Value trace_val("trace"); + trace_val.set(&p); + trace_val.set_enum(1); + + bool result = test_trace.set(trace_val); + CHECK( result == false ); + CHECK( test_trace.option_levels[DEFAULT_TRACE_OPTION] == TraceLevel(0) ); +} + +#endif // UNIT_TEST + diff --git a/src/main/trace.h b/src/main/trace.h new file mode 100644 index 000000000..b8e5e4359 --- /dev/null +++ b/src/main/trace.h @@ -0,0 +1,76 @@ +//-------------------------------------------------------------------------- +// Copyright (C) 2020-2020 Cisco and/or its affiliates. All rights reserved. +// +// This program is free software; you can redistribute it and/or modify it +// under the terms of the GNU General Public License Version 2 as published +// by the Free Software Foundation. You may not use, modify or distribute +// this program under any other version of the GNU General Public License. +// +// This program is distributed in the hope that it will be useful, but +// WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU +// General Public License for more details. +// +// You should have received a copy of the GNU General Public License along +// with this program; if not, write to the Free Software Foundation, Inc., +// 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. +//-------------------------------------------------------------------------- +// trace.h author Serhii Vlasiuk + +#ifndef TRACE_H +#define TRACE_H + +#include +#include + +#include "framework/value.h" +#include "main/snort_types.h" + +#define DEFAULT_TRACE_OPTION 0 +#define DEFAULT_LOG_LEVEL 1 + +typedef uint8_t TraceOption; +typedef uint8_t TraceLevel; + + +struct TraceOptionString +{ + const char* alias; + TraceOption option; +}; + +namespace snort +{ +struct SO_PUBLIC Trace +{ + Trace(const char*, const TraceOptionString*, size_t); + Trace(const char*); + ~Trace() = default; + + bool set(const snort::Value&); + void reset(); + void enable(); + + const char* module_name() const + { return mod_name; } + + const char* option_name(size_t index) const + { + assert(index < option_levels.size()); + return options[index].alias; + } + + bool enabled(TraceOption trace_option, TraceLevel log_level = DEFAULT_LOG_LEVEL) const + { + assert(trace_option < option_levels.size()); + return option_levels[trace_option] >= log_level; + } + + const TraceOptionString* options; + std::vector option_levels; + std::vector config_options; + const char* mod_name; +}; +} + +#endif diff --git a/src/managers/module_manager.cc b/src/managers/module_manager.cc index 08b21f7da..36b818fde 100644 --- a/src/managers/module_manager.cc +++ b/src/managers/module_manager.cc @@ -567,6 +567,7 @@ static bool begin(Module* m, const Parameter* p, const char* s, int idx, int dep // Module::(verified_)begin() will be called for top-level tables, lists, and list items only if ( top_level(s) ) { + m->reset_trace(); if ( !m->verified_begin(s, idx, s_config) ) return false; // don't set list defaults diff --git a/src/network_inspectors/appid/appid_module.cc b/src/network_inspectors/appid/appid_module.cc index 070a5275e..382ec586b 100644 --- a/src/network_inspectors/appid/appid_module.cc +++ b/src/network_inspectors/appid/appid_module.cc @@ -46,7 +46,7 @@ using namespace snort; using namespace std; -Trace TRACE_NAME(appid_module); +Trace appid_module_trace(MOD_NAME); //------------------------------------------------------------------------- // appid module @@ -257,7 +257,7 @@ static const PegInfo appid_pegs[] = }; AppIdModule::AppIdModule() : - Module(MOD_NAME, MOD_HELP, s_params, false, &TRACE_NAME(appid_module)) + Module(MOD_NAME, MOD_HELP, s_params, false, &appid_module_trace) { config = nullptr; } @@ -321,7 +321,7 @@ bool AppIdModule::set(const char* fqn, Value& v, SnortConfig* c) return true; } -bool AppIdModule::begin(const char* /*fqn*/, int, SnortConfig*) +bool AppIdModule::begin(const char*, int, SnortConfig*) { if ( config ) return false; diff --git a/src/network_inspectors/appid/appid_module.h b/src/network_inspectors/appid/appid_module.h index 7944c4db2..323fec56c 100644 --- a/src/network_inspectors/appid/appid_module.h +++ b/src/network_inspectors/appid/appid_module.h @@ -33,7 +33,7 @@ extern THREAD_LOCAL snort::ProfileStats appid_perf_stats; -extern Trace TRACE_NAME(appid_module); +extern snort::Trace appid_module_trace; #define MOD_NAME "appid" #define MOD_HELP "application and service identification" diff --git a/src/network_inspectors/appid/detector_plugins/detector_pattern.cc b/src/network_inspectors/appid/detector_plugins/detector_pattern.cc index 5b3464a3b..021657b48 100644 --- a/src/network_inspectors/appid/detector_plugins/detector_pattern.cc +++ b/src/network_inspectors/appid/detector_plugins/detector_pattern.cc @@ -39,12 +39,12 @@ static void dump_patterns(const char* name, PatternService* pList) { UNUSED(name); - trace_logf(appid_module,"Adding pattern for \"%s\"\n", name); + debug_logf(appid_module_trace, "Adding pattern for \"%s\"\n", name); for (PatternService* ps = pList; ps; ps = ps->next) for (Pattern* pattern = ps->pattern; pattern; pattern = pattern->next) if (pattern->data && pattern->length) { - trace_logf(appid_module,"\t\t%s, %u\n",pattern->data, pattern->length); + debug_logf(appid_module_trace, "\t\t%s, %u\n",pattern->data, pattern->length); } } diff --git a/src/network_inspectors/appid/detector_plugins/detector_pattern.h b/src/network_inspectors/appid/detector_plugins/detector_pattern.h index 1b0701089..b4449713b 100644 --- a/src/network_inspectors/appid/detector_plugins/detector_pattern.h +++ b/src/network_inspectors/appid/detector_plugins/detector_pattern.h @@ -27,7 +27,6 @@ #include "service_plugins/service_detector.h" #include "main/snort_debug.h" -extern Trace TRACE_NAME(appid_module); namespace snort { diff --git a/src/network_inspectors/appid/detector_plugins/test/http_url_patterns_test.cc b/src/network_inspectors/appid/detector_plugins/test/http_url_patterns_test.cc index 83236cd9a..5df4890f7 100644 --- a/src/network_inspectors/appid/detector_plugins/test/http_url_patterns_test.cc +++ b/src/network_inspectors/appid/detector_plugins/test/http_url_patterns_test.cc @@ -74,6 +74,12 @@ DnsPatternMatchers::~DnsPatternMatchers() { } SipPatternMatchers::~SipPatternMatchers() { } SslPatternMatchers::~SslPatternMatchers() { } +Trace::Trace(const char*, const TraceOptionString*, size_t) {} +Trace::Trace(const char*) {} +bool Trace::set(const snort::Value&) { return true; } +void Trace::reset() {} +void Trace::enable() {} + TEST_GROUP(http_url_patterns_tests) { void setup() override diff --git a/src/network_inspectors/appid/lua_detector_api.cc b/src/network_inspectors/appid/lua_detector_api.cc index b0744109f..4d89c51c1 100644 --- a/src/network_inspectors/appid/lua_detector_api.cc +++ b/src/network_inspectors/appid/lua_detector_api.cc @@ -299,7 +299,7 @@ static int detector_log_message(lua_State* L) break; case LUA_LOG_TRACE: - trace_logf(appid_module, "%s:%s\n", name.c_str(), message); + debug_logf(appid_module_trace, "%s:%s\n", name.c_str(), message); break; default: diff --git a/src/network_inspectors/appid/lua_detector_api.h b/src/network_inspectors/appid/lua_detector_api.h index e62b793ff..baa67f72f 100644 --- a/src/network_inspectors/appid/lua_detector_api.h +++ b/src/network_inspectors/appid/lua_detector_api.h @@ -33,8 +33,6 @@ #include "main/snort_debug.h" -extern Trace TRACE_NAME(appid_module); - namespace snort { struct Packet; diff --git a/src/network_inspectors/appid/service_plugins/test/service_plugin_mock.h b/src/network_inspectors/appid/service_plugins/test/service_plugin_mock.h index 214b33ae2..b9d428538 100644 --- a/src/network_inspectors/appid/service_plugins/test/service_plugin_mock.h +++ b/src/network_inspectors/appid/service_plugins/test/service_plugin_mock.h @@ -64,7 +64,7 @@ public: SO_PUBLIC static Inspector* get_inspector(const char*, bool, SnortConfig*) {return nullptr;} }; Module::Module(const char*, const char*) {} -Module::Module(const char*, const char*, const Parameter*, bool, Trace*, const Parameter*, TraceMask*) +Module::Module(const char*, const char*, const Parameter*, bool, Trace*, const Parameter*) {} PegCount Module::get_global_count(char const*) const { return 0; } void Module::show_interval_stats(std::vector >&, FILE*) {} diff --git a/src/network_inspectors/appid/test/appid_mock_inspector.h b/src/network_inspectors/appid/test/appid_mock_inspector.h index b6b4564e4..2452a89c1 100644 --- a/src/network_inspectors/appid/test/appid_mock_inspector.h +++ b/src/network_inspectors/appid/test/appid_mock_inspector.h @@ -23,7 +23,6 @@ #include "appid_inspector.h" -typedef uint64_t Trace; class Value; namespace snort diff --git a/src/protocols/packet_manager.cc b/src/protocols/packet_manager.cc index f8a97964a..7d70d9133 100644 --- a/src/protocols/packet_manager.cc +++ b/src/protocols/packet_manager.cc @@ -156,7 +156,7 @@ void PacketManager::decode( // loop until the protocol id is no longer valid while (CodecManager::s_protocols[mapped_prot]->decode(raw, codec_data, p->ptrs)) { - trace_logf(decode, "Codec %s (protocol_id: %hu) " + debug_logf(decode_trace, "Codec %s (protocol_id: %hu) " "ip header starts at: %p, length is %d\n", CodecManager::s_protocols[mapped_prot]->get_name(), static_cast(codec_data.next_prot_id), pkt, codec_data.lyr_len); @@ -246,7 +246,7 @@ void PacketManager::decode( codec_data.proto_bits = 0; } - trace_logf(decode, "Codec %s (protocol_id: %hu) ip header" + debug_logf(decode_trace, "Codec %s (protocol_id: %hu) ip header" " starts at: %p, length is %lu\n", CodecManager::s_protocols[mapped_prot]->get_name(), static_cast(prev_prot_id), pkt, (unsigned long)codec_data.lyr_len); diff --git a/src/search_engines/test/hyperscan_test.cc b/src/search_engines/test/hyperscan_test.cc index 2146529de..c27035d1a 100644 --- a/src/search_engines/test/hyperscan_test.cc +++ b/src/search_engines/test/hyperscan_test.cc @@ -29,6 +29,7 @@ #include "framework/mpse.h" #include "framework/mpse_batch.h" #include "main/snort_config.h" +#include "main/trace.h" #include "utils/stats.h" // must appear after snort_config.h to avoid broken c++ map include @@ -132,6 +133,13 @@ unsigned get_instance_id() { return 0; } } + +Trace::Trace(const char*, const TraceOptionString*, size_t) {} +Trace::Trace(const char*) {} +bool Trace::set(const snort::Value&) { return true; } +void Trace::reset() {} +void Trace::enable() {} + void show_stats(PegCount*, const PegInfo*, unsigned, const char*) { } void show_stats(PegCount*, const PegInfo*, const IndexVec&, const char*, FILE*) { } diff --git a/src/service_inspectors/dce_rpc/dce_smb2.cc b/src/service_inspectors/dce_rpc/dce_smb2.cc index bf6dad521..724a452a7 100644 --- a/src/service_inspectors/dce_rpc/dce_smb2.cc +++ b/src/service_inspectors/dce_rpc/dce_smb2.cc @@ -70,7 +70,7 @@ static inline DCE2_Ret DCE2_Smb2InsertTid(DCE2_SmbSsnData* ssd, const uint32_t t (ssd->max_file_depth == -1 and DCE2_ScSmbFileDepth((dce2SmbProtoConf*)ssd->sd.config) == -1) ) { - trace_logf(dce_smb, "Not inserting TID (%u) for DISK share type" + debug_logf(dce_smb_trace, "Not inserting TID (%u) for DISK share type" "as mandatory configuration max_file_depth is not present." "This will result in non-inspection of file data.\n", tid); return ret; @@ -679,7 +679,7 @@ static void DCE2_Smb2Inspect(DCE2_SmbSsnData* ssd, const Smb2Hdr* smb_hdr, const } else { - trace_logf(dce_smb, "Not handling create request for IPC with TID (%u)\n", + debug_logf(dce_smb_trace, "Not handling create request for IPC with TID (%u)\n", Smb2Tid(smb_hdr)); } break; diff --git a/src/service_inspectors/dce_rpc/dce_smb_module.cc b/src/service_inspectors/dce_rpc/dce_smb_module.cc index 8f1907fa9..1ae5a23c1 100644 --- a/src/service_inspectors/dce_rpc/dce_smb_module.cc +++ b/src/service_inspectors/dce_rpc/dce_smb_module.cc @@ -33,7 +33,7 @@ using namespace snort; using namespace std; -Trace TRACE_NAME(dce_smb); +Trace dce_smb_trace(DCE2_SMB_NAME); static const PegInfo dce2_smb_pegs[] = { @@ -190,7 +190,7 @@ static const RuleMap dce2_smb_rules[] = { 0, nullptr } }; -Dce2SmbModule::Dce2SmbModule() : Module(DCE2_SMB_NAME, DCE2_SMB_HELP, s_params, false, &TRACE_NAME(dce_smb)) +Dce2SmbModule::Dce2SmbModule() : Module(DCE2_SMB_NAME, DCE2_SMB_HELP, s_params, false, &dce_smb_trace) { memset(&config, 0, sizeof(config)); } diff --git a/src/service_inspectors/dce_rpc/dce_smb_module.h b/src/service_inspectors/dce_rpc/dce_smb_module.h index 5b1a6dde2..1b9141528 100644 --- a/src/service_inspectors/dce_rpc/dce_smb_module.h +++ b/src/service_inspectors/dce_rpc/dce_smb_module.h @@ -61,7 +61,7 @@ struct dce2SmbProtoConf bool legacy_mode; }; -extern Trace TRACE_NAME(dce_smb); +extern snort::Trace dce_smb_trace; class Dce2SmbModule : public snort::Module { diff --git a/src/service_inspectors/dce_rpc/dce_smb_transaction.cc b/src/service_inspectors/dce_rpc/dce_smb_transaction.cc index ad0143087..a8ab1a138 100644 --- a/src/service_inspectors/dce_rpc/dce_smb_transaction.cc +++ b/src/service_inspectors/dce_rpc/dce_smb_transaction.cc @@ -526,8 +526,7 @@ static DCE2_Ret DCE2_SmbUpdateTransRequest(DCE2_SmbSsnData* ssd, if (DCE2_SsnIsWindowsPolicy(&ssd->sd) && ssd->cur_rtracker->ftracker->fp_byte_mode) { - trace_log(dce_smb, "Pipe is in byte " - "mode - TRANS_TRANSACT_NMPIPE won't work\n"); + debug_log(dce_smb_trace, "Pipe is in byte mode - TRANS_TRANSACT_NMPIPE won't work\n"); return DCE2_RET__ERROR; } data_params = DCE2_SMB_TRANS__DATA; @@ -587,8 +586,7 @@ static DCE2_Ret DCE2_SmbUpdateTransRequest(DCE2_SmbSsnData* ssd, && (DCE2_SmbTransactionGetName(nb_ptr, nb_len, byte_count, SmbUnicode(smb_hdr)) != DCE2_RET__SUCCESS)) { - trace_log(dce_smb, "Failed to validate " - "pipe name for Samba.\n"); + debug_log(dce_smb_trace, "Failed to validate pipe name for Samba.\n"); return DCE2_RET__ERROR; } break; @@ -1071,7 +1069,7 @@ DCE2_Ret DCE2_SmbTransaction(DCE2_SmbSsnData* ssd, const SmbNtHdr* smb_hdr, if (DCE2_ComInfoIsRequest(com_info) && !DCE2_SmbIsTransactionComplete(ttracker)) { - trace_log(dce_smb, "Got new transaction request " + debug_log(dce_smb_trace, "Got new transaction request " "that matches an in progress transaction - not inspecting.\n"); return DCE2_RET__ERROR; } @@ -1080,7 +1078,7 @@ DCE2_Ret DCE2_SmbTransaction(DCE2_SmbSsnData* ssd, const SmbNtHdr* smb_hdr, if (DCE2_ComInfoIsRequest(com_info) && (DCE2_ComInfoWordCount(com_info) != 16)) { - trace_log(dce_smb, "\\PIPE\\LANMAN request - not inspecting\n"); + debug_log(dce_smb_trace, "\\PIPE\\LANMAN request - not inspecting\n"); return DCE2_RET__IGNORE; } @@ -1192,7 +1190,7 @@ DCE2_Ret DCE2_SmbTransaction2(DCE2_SmbSsnData* ssd, const SmbNtHdr* smb_hdr, if (DCE2_ComInfoIsRequest(com_info) && !DCE2_SmbIsTransactionComplete(ttracker)) { - trace_log(dce_smb, "Got new transaction request " + debug_log(dce_smb_trace, "Got new transaction request " "that matches an in progress transaction - not inspecting.\n"); return DCE2_RET__ERROR; } @@ -1450,7 +1448,7 @@ DCE2_Ret DCE2_SmbNtTransact(DCE2_SmbSsnData* ssd, const SmbNtHdr* smb_hdr, if (DCE2_ComInfoIsRequest(com_info) && !DCE2_SmbIsTransactionComplete(ttracker)) { - trace_log(dce_smb, "Got new transaction request " + debug_log(dce_smb_trace, "Got new transaction request " "that matches an in progress transaction - not inspecting.\n"); return DCE2_RET__ERROR; } diff --git a/src/service_inspectors/dce_rpc/dce_smb_utils.cc b/src/service_inspectors/dce_rpc/dce_smb_utils.cc index 5c6998535..e370a2f70 100644 --- a/src/service_inspectors/dce_rpc/dce_smb_utils.cc +++ b/src/service_inspectors/dce_rpc/dce_smb_utils.cc @@ -837,9 +837,8 @@ void DCE2_SmbInsertTid(DCE2_SmbSsnData* ssd, if ( !is_ipc and ssd->max_file_depth == -1 and DCE2_ScSmbFileDepth((dce2SmbProtoConf*)ssd->sd.config) == -1 ) { - trace_logf(dce_smb, "Not inserting TID (%hu) " - "because it's not IPC and not inspecting normal file " - "data.\n", tid); + debug_logf(dce_smb_trace, "Not inserting TID (%hu) " + "because it's not IPC and not inspecting normal file data.\n", tid); return; } @@ -1534,8 +1533,8 @@ static DCE2_Ret DCE2_SmbFileAPIProcess(DCE2_SmbSsnData* ssd, if (!file_flows->file_process(p, data_ptr, (int)data_len, position, upload, DCE2_SmbIsVerdictSuspend(upload, position))) { - trace_logf(dce_smb, "File API returned FAILURE " - "for (0x%02X) %s\n", ftracker->fid_v1, upload ? "UPLOAD" : "DOWNLOAD"); + debug_logf(dce_smb_trace, "File API returned FAILURE for (0x%02X) %s\n", + ftracker->fid_v1, upload ? "UPLOAD" : "DOWNLOAD"); // Failure. Abort tracking this file under file API return DCE2_RET__ERROR; @@ -1781,7 +1780,7 @@ void DCE2_SmbProcessFileData(DCE2_SmbSsnData* ssd, } else if (ftracker->ff_file_offset < ftracker->ff_bytes_processed) { - trace_logf(dce_smb, "File offset %" PRIu64 " is " + debug_logf(dce_smb_trace, "File offset %" PRIu64 " is " "less than bytes processed %" PRIu64 " - aborting.\n", ftracker->ff_file_offset, ftracker->ff_bytes_processed); diff --git a/src/service_inspectors/dce_rpc/dce_udp_module.cc b/src/service_inspectors/dce_rpc/dce_udp_module.cc index da026da36..cd649f742 100644 --- a/src/service_inspectors/dce_rpc/dce_udp_module.cc +++ b/src/service_inspectors/dce_rpc/dce_udp_module.cc @@ -31,7 +31,7 @@ using namespace snort; using namespace std; -Trace TRACE_NAME(dce_udp); +Trace dce_udp_trace(DCE2_UDP_NAME); static const Parameter s_params[] = { @@ -84,7 +84,7 @@ static const PegInfo dce2_udp_pegs[] = { CountType::END, nullptr, nullptr } }; -Dce2UdpModule::Dce2UdpModule() : Module(DCE2_UDP_NAME, DCE2_UDP_HELP, s_params, false, &TRACE_NAME(dce_udp)) +Dce2UdpModule::Dce2UdpModule() : Module(DCE2_UDP_NAME, DCE2_UDP_HELP, s_params, false, &dce_udp_trace) { } diff --git a/src/service_inspectors/dce_rpc/dce_udp_module.h b/src/service_inspectors/dce_rpc/dce_udp_module.h index cdf46e41e..d44a05bbe 100644 --- a/src/service_inspectors/dce_rpc/dce_udp_module.h +++ b/src/service_inspectors/dce_rpc/dce_udp_module.h @@ -44,7 +44,7 @@ struct dce2UdpProtoConf dce2CommonProtoConf common; }; -extern Trace TRACE_NAME(dce_udp); +extern snort::Trace dce_udp_trace; class Dce2UdpModule : public snort::Module { diff --git a/src/service_inspectors/dce_rpc/dce_udp_processing.cc b/src/service_inspectors/dce_rpc/dce_udp_processing.cc index 7ac8fb4e3..d1ce5fa63 100644 --- a/src/service_inspectors/dce_rpc/dce_udp_processing.cc +++ b/src/service_inspectors/dce_rpc/dce_udp_processing.cc @@ -154,7 +154,7 @@ void DCE2_ClProcess(DCE2_SsnData* sd, DCE2_ClTracker* clt) case DCERPC_PDU_TYPE__RESPONSE: { - trace_log(dce_udp, "Response from client. Changing stream direction.\n"); + debug_log(dce_udp_trace, "Response from client. Changing stream direction.\n"); ip::IpApi* ip_api = &p->ptrs.ip_api; p->flow->session->update_direction(SSN_DIR_FROM_SERVER, diff --git a/src/service_inspectors/dce_rpc/smb_message.cc b/src/service_inspectors/dce_rpc/smb_message.cc index c711c25b6..25e09d839 100644 --- a/src/service_inspectors/dce_rpc/smb_message.cc +++ b/src/service_inspectors/dce_rpc/smb_message.cc @@ -806,7 +806,7 @@ static void DCE2_SmbProcessCommand(DCE2_SmbSsnData* ssd, const SmbNtHdr* smb_hdr com_info.cmd_size = 0; com_info.byte_count = 0; DCE2_SmbCheckCommand(ssd, smb_hdr, smb_com, nb_ptr, nb_len, com_info); - trace_logf(dce_smb, "Processing command: %s (0x%02X)\n", + debug_logf(dce_smb_trace, "Processing command: %s (0x%02X)\n", get_smb_com_string(smb_com), smb_com); // Note that even if the command shouldn't be processed, some of @@ -831,8 +831,7 @@ static void DCE2_SmbProcessCommand(DCE2_SmbSsnData* ssd, const SmbNtHdr* smb_hdr if (smb_com2 == SMB_COM_NO_ANDX_COMMAND) break; - trace_logf(dce_smb, "Chained SMB command: %s\n", - get_smb_com_string(smb_com2)); + debug_logf(dce_smb_trace, "Chained SMB command: %s\n", get_smb_com_string(smb_com2)); num_chained++; if (DCE2_ScSmbMaxChain((dce2SmbProtoConf*)ssd->sd.config) && @@ -1033,8 +1032,7 @@ static DCE2_SmbRequestTracker* DCE2_SmbInspect(DCE2_SmbSsnData* ssd, const SmbNt { int smb_com = SmbCom(smb_hdr); - trace_logf(dce_smb, "SMB command: %s (0x%02X)\n", - get_smb_com_string(smb_com), smb_com); + debug_logf(dce_smb_trace, "SMB command: %s (0x%02X)\n", get_smb_com_string(smb_com), smb_com); if (smb_com_funcs[smb_com] == nullptr) { @@ -1629,7 +1627,7 @@ static void DCE2_Smb1Process(DCE2_SmbSsnData* ssd) rtracker = DCE2_SmbInspect(ssd, smb_hdr); if (rtracker == nullptr) { - trace_log(dce_smb, "Not inspecting SMB packet.\n"); + debug_log(dce_smb_trace, "Not inspecting SMB packet.\n"); if (DCE2_BufferIsEmpty(*seg_buf)) { diff --git a/src/service_inspectors/gtp/gtp_module.cc b/src/service_inspectors/gtp/gtp_module.cc index baed7b024..79fd04783 100644 --- a/src/service_inspectors/gtp/gtp_module.cc +++ b/src/service_inspectors/gtp/gtp_module.cc @@ -32,7 +32,8 @@ using namespace snort; -Trace TRACE_NAME(gtp_inspect); +Trace gtp_inspect_trace(GTP_NAME); + THREAD_LOCAL ProfileStats gtp_inspect_prof; #define GTP_EVENT_BAD_MSG_LEN_STR "message length is invalid" @@ -124,7 +125,7 @@ static const Parameter gtp_params[] = }; GtpInspectModule::GtpInspectModule() : - Module(GTP_NAME, GTP_HELP, gtp_params, true, &TRACE_NAME(gtp_inspect)) + Module(GTP_NAME, GTP_HELP, gtp_params, true, >p_inspect_trace) { } bool GtpInspectModule::set(const char* fqn, Value& v, SnortConfig* c) diff --git a/src/service_inspectors/gtp/gtp_module.h b/src/service_inspectors/gtp/gtp_module.h index 39148da29..3152b2d46 100644 --- a/src/service_inspectors/gtp/gtp_module.h +++ b/src/service_inspectors/gtp/gtp_module.h @@ -35,7 +35,7 @@ #define GTP_HELP "gtp control channel inspection" extern THREAD_LOCAL snort::ProfileStats gtp_inspect_prof; -extern Trace TRACE_NAME(gtp_inspect); +extern snort::Trace gtp_inspect_trace; struct GtpStuff { diff --git a/src/service_inspectors/gtp/gtp_parser.cc b/src/service_inspectors/gtp/gtp_parser.cc index a6c7bb927..c576e4005 100644 --- a/src/service_inspectors/gtp/gtp_parser.cc +++ b/src/service_inspectors/gtp/gtp_parser.cc @@ -110,7 +110,7 @@ static void printInfoElements(GTP_IEData* info_elements, GTPMsg* msg) char buf[STD_BUF]; convertToHex( (char*)buf, sizeof(buf), msg->gtp_header + info_elements[i].shift, info_elements[i].length); - trace_logf(gtp_inspect, "Info type: %.3d, content: %s\n", i, buf); + debug_logf(gtp_inspect_trace, "Info type: %.3d, content: %s\n", i, buf); } } } diff --git a/src/service_inspectors/http_inspect/test/http_module_test.cc b/src/service_inspectors/http_inspect/test/http_module_test.cc index f5f1e86ce..1c47d0cf9 100644 --- a/src/service_inspectors/http_inspect/test/http_module_test.cc +++ b/src/service_inspectors/http_inspect/test/http_module_test.cc @@ -47,6 +47,12 @@ void Value::get_bits(std::bitset<256ul>&) const {} int DetectionEngine::queue_event(unsigned int, unsigned int, Actions::Type) { return 0; } } +Trace::Trace(const char*, const TraceOptionString*, size_t) {} +Trace::Trace(const char*) {} +bool Trace::set(const snort::Value&) { return true; } +void Trace::reset() {} +void Trace::enable() {} + void show_stats(PegCount*, const PegInfo*, unsigned, const char*) { } void show_stats(PegCount*, const PegInfo*, const IndexVec&, const char*, FILE*) { } diff --git a/src/service_inspectors/http_inspect/test/http_uri_norm_test.cc b/src/service_inspectors/http_inspect/test/http_uri_norm_test.cc index 5d095a146..69e20f6e4 100644 --- a/src/service_inspectors/http_inspect/test/http_uri_norm_test.cc +++ b/src/service_inspectors/http_inspect/test/http_uri_norm_test.cc @@ -42,6 +42,12 @@ void Value::get_bits(std::bitset<256ul>&) const {} int DetectionEngine::queue_event(unsigned int, unsigned int, Actions::Type) { return 0; } } +Trace::Trace(const char*, const TraceOptionString*, size_t) {} +Trace::Trace(const char*) {} +bool Trace::set(const snort::Value&) { return true; } +void Trace::reset() {} +void Trace::enable() {} + void show_stats(PegCount*, const PegInfo*, unsigned, const char*) { } void show_stats(PegCount*, const PegInfo*, const IndexVec&, const char*, FILE*) { } diff --git a/src/service_inspectors/wizard/wiz_module.cc b/src/service_inspectors/wizard/wiz_module.cc index 67db6f5ba..2106c384e 100644 --- a/src/service_inspectors/wizard/wiz_module.cc +++ b/src/service_inspectors/wizard/wiz_module.cc @@ -30,6 +30,8 @@ using namespace snort; using namespace std; +Trace wizard_trace(WIZ_NAME); + //------------------------------------------------------------------------- // wizard module //------------------------------------------------------------------------- @@ -104,7 +106,7 @@ static const Parameter s_params[] = { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } }; -WizardModule::WizardModule() : Module(WIZ_NAME, WIZ_HELP, s_params) +WizardModule::WizardModule() : Module(WIZ_NAME, WIZ_HELP, s_params, false, &wizard_trace) { c2s_hexes = nullptr; s2c_hexes = nullptr; @@ -127,7 +129,7 @@ WizardModule::~WizardModule() ProfileStats* WizardModule::get_profile() const { return &wizPerfStats; } -bool WizardModule::set(const char*, Value& v, SnortConfig*) +bool WizardModule::set(const char* fqn, Value& v, SnortConfig* sc) { if ( v.is("service") ) service = v.get_string(); @@ -149,7 +151,7 @@ bool WizardModule::set(const char*, Value& v, SnortConfig*) curses->add_curse(v.get_string()); else - return false; + return Module::set(fqn, v, sc); return true; } diff --git a/src/service_inspectors/wizard/wiz_module.h b/src/service_inspectors/wizard/wiz_module.h index 2df118ff3..f3c7d68ab 100644 --- a/src/service_inspectors/wizard/wiz_module.h +++ b/src/service_inspectors/wizard/wiz_module.h @@ -73,5 +73,7 @@ private: CurseBook* curses; }; +extern snort::Trace wizard_trace; + #endif diff --git a/src/service_inspectors/wizard/wizard.cc b/src/service_inspectors/wizard/wizard.cc index 9fe223626..72a378230 100644 --- a/src/service_inspectors/wizard/wizard.cc +++ b/src/service_inspectors/wizard/wizard.cc @@ -169,7 +169,10 @@ StreamSplitter::Status MagicSplitter::scan( count_scan(pkt->flow); if ( wizard->cast_spell(wand, pkt->flow, data, len) ) + { + trace_logf(wizard_trace, "service set to %s\n", pkt->flow->service); count_hit(pkt->flow); + } else if ( wizard->finished(wand) ) return ABORT; @@ -244,7 +247,10 @@ void Wizard::eval(Packet* p) reset(wand, false, p->is_from_client()); if ( cast_spell(wand, p->flow, p->data, p->dsize) ) + { + trace_logf(wizard_trace, "service set to %s\n", p->flow->service); ++tstats.udp_hits; + } ++tstats.udp_scans; } diff --git a/src/side_channel/test/side_channel_module_test.cc b/src/side_channel/test/side_channel_module_test.cc index 5d67e18e4..e12dfe54c 100644 --- a/src/side_channel/test/side_channel_module_test.cc +++ b/src/side_channel/test/side_channel_module_test.cc @@ -56,6 +56,12 @@ void SideChannelManager::instantiate(const SCConnectors*, const PortBitSet* port port_1_set = ports->test(1); } +Trace::Trace(const char*, const TraceOptionString*, size_t) {} +Trace::Trace(const char*) {} +bool Trace::set(const snort::Value&) { return true; } +void Trace::reset() {} +void Trace::enable() {} + void show_stats(PegCount*, const PegInfo*, unsigned, const char*) { } void show_stats(PegCount*, const PegInfo*, const IndexVec&, const char*, FILE*) { } diff --git a/src/stream/base/stream_module.cc b/src/stream/base/stream_module.cc index 56e5cf5d0..c0096e5d8 100644 --- a/src/stream/base/stream_module.cc +++ b/src/stream/base/stream_module.cc @@ -37,7 +37,7 @@ using namespace std; //------------------------------------------------------------------------- // stream module //------------------------------------------------------------------------- -Trace TRACE_NAME(stream); +Trace stream_trace(MOD_NAME); #define FLOW_TYPE_PARAMS(name, idle, weight) \ static const Parameter name[] = \ @@ -99,7 +99,7 @@ static const RuleMap stream_rules[] = }; StreamModule::StreamModule() : - Module(MOD_NAME, MOD_HELP, s_params, false, &TRACE_NAME(stream)) + Module(MOD_NAME, MOD_HELP, s_params, false, &stream_trace) { } const PegInfo* StreamModule::get_pegs() const diff --git a/src/stream/base/stream_module.h b/src/stream/base/stream_module.h index 8bded5983..acba5f112 100644 --- a/src/stream/base/stream_module.h +++ b/src/stream/base/stream_module.h @@ -38,7 +38,7 @@ struct SnortConfig; //------------------------------------------------------------------------- // stream module //------------------------------------------------------------------------- -extern Trace TRACE_NAME(stream); +extern snort::Trace stream_trace; #define MOD_NAME "stream" #define MOD_HELP "common flow tracking" diff --git a/src/stream/ip/ip_defrag.cc b/src/stream/ip/ip_defrag.cc index 6e3094018..73f694207 100644 --- a/src/stream/ip/ip_defrag.cc +++ b/src/stream/ip/ip_defrag.cc @@ -308,7 +308,7 @@ static inline int FragCheckFirstLast( { ft->frag_flags |= FRAG_GOT_FIRST; - trace_log(stream_ip, "Got first frag\n"); + debug_log(stream_ip_trace,"Got first frag\n"); } else if ((!(p->ptrs.decode_flags & DECODE_MF)) && (frag_offset > 0)) /* set for last frag too */ @@ -323,7 +323,7 @@ static inline int FragCheckFirstLast( if (ft->frag_flags & FRAG_GOT_LAST) { - trace_log(stream_ip, "Got last frag again!\n"); + debug_log(stream_ip_trace,"Got last frag again!\n"); switch (ft->frag_policy) { case FRAG_POLICY_BSD: @@ -388,10 +388,8 @@ static inline int FragCheckFirstLast( { ft->calculated_size = endOfThisFrag; - trace_logf(stream_ip, "Got last frag, Bytes: %u, " - "Calculated size: %u\n", - ft->frag_bytes, - ft->calculated_size); + debug_logf(stream_ip_trace,"Got last frag, Bytes: %u, Calculated size: %u\n", + ft->frag_bytes, ft->calculated_size); } } @@ -400,7 +398,7 @@ static inline int FragCheckFirstLast( ft->frag_flags |= FRAG_NO_BSD_VULN; } - trace_logf(stream_ip, "Frag Status: %s:%s\n", + debug_logf(stream_ip_trace,"Frag Status: %s:%s\n", (ft->frag_flags&FRAG_GOT_FIRST) ? "FIRST" : "No FIRST", (ft->frag_flags&FRAG_GOT_LAST) ? "LAST" : "No LAST"); return retVal; @@ -507,7 +505,7 @@ static inline int checkTinyFragments( { if (p->dsize <= engine->min_fragment_length) { - trace_logf(stream_ip, + debug_logf(stream_ip_trace, "Frag: Received fragment size(%d) is not more than configured min_fragment_length (%u)\n", p->dsize, engine->min_fragment_length); EventTinyFragments(engine); @@ -517,7 +515,7 @@ static inline int checkTinyFragments( ///detect tiny fragments after processing overlaps. if (trimmedLength <= engine->min_fragment_length) { - trace_logf(stream_ip, + debug_logf(stream_ip_trace, "Frag: # of New octets in Received fragment(%u) is not more than configured min_fragment_length (%u)\n", trimmedLength, engine->min_fragment_length); EventTinyFragments(engine); @@ -540,8 +538,7 @@ static inline int checkTinyFragments( */ static inline int FragIsComplete(FragTracker* ft) { - trace_log(stream_ip, - "[$] Checking completion criteria\n"); + debug_log(stream_ip_trace, "[$] Checking completion criteria\n"); /* * check to see if the first and last frags have arrived @@ -549,8 +546,7 @@ static inline int FragIsComplete(FragTracker* ft) if ((ft->frag_flags & FRAG_GOT_FIRST) && (ft->frag_flags & FRAG_GOT_LAST)) { - trace_log(stream_ip, - " Got First and Last frags\n"); + debug_log(stream_ip_trace, " Got First and Last frags\n"); /* * if we've accumulated enough data to match the calculated size @@ -558,8 +554,7 @@ static inline int FragIsComplete(FragTracker* ft) */ if (ft->frag_bytes == ft->calculated_size) { - trace_log(stream_ip, - " [!] frag_bytes = calculated_size!\n"); + debug_log(stream_ip_trace, " [!] frag_bytes = calculated_size!\n"); ip_stats.trackers_completed++; @@ -568,16 +563,14 @@ static inline int FragIsComplete(FragTracker* ft) if (ft->frag_bytes > ft->calculated_size) { - trace_log(stream_ip, - " [!] frag_bytes > calculated_size!\n"); + debug_log(stream_ip_trace, " [!] frag_bytes > calculated_size!\n"); ip_stats.trackers_completed++; return 1; } - trace_logf(stream_ip, - " Calc size (%u) != frag bytes (%u)\n", + debug_logf(stream_ip_trace, " Calc size (%u) != frag bytes (%u)\n", ft->calculated_size, ft->frag_bytes); /* @@ -586,8 +579,7 @@ static inline int FragIsComplete(FragTracker* ft) return 0; } - trace_logf(stream_ip, - " Missing First or Last frags (frag_flags: 0x%X)\n", + debug_logf(stream_ip_trace, " Missing First or Last frags (frag_flags: 0x%X)\n", ft->frag_flags); return 0; @@ -620,8 +612,7 @@ static void FragRebuild(FragTracker* ft, Packet* p) /* Adjust the IP header size in pseudo packet for the new length */ uint8_t new_ip_hlen = ip::IP4_HEADER_LEN + ft->ip_options_len; - trace_logf(stream_ip, - "Adjusting IP Header to %d bytes\n", + debug_logf(stream_ip_trace, "Adjusting IP Header to %d bytes\n", new_ip_hlen); iph->set_hlen(new_ip_hlen >> 2); @@ -642,8 +633,7 @@ static void FragRebuild(FragTracker* ft, Packet* p) iph->ip_off = 0x0000; dpkt->ptrs.decode_flags &= ~DECODE_FRAG; - trace_log(stream_ip, - "[^^] Walking fraglist:\n"); + debug_log(stream_ip_trace, "[^^] Walking fraglist:\n"); } /* @@ -651,7 +641,7 @@ static void FragRebuild(FragTracker* ft, Packet* p) */ for ( Fragment* frag = ft->fraglist; frag; frag = frag->next ) { - trace_logf(stream_ip, + debug_logf(stream_ip_trace, " frag: %p\n" " frag->data: %p\n" " frag->offset: %d\n" @@ -729,8 +719,7 @@ static void FragRebuild(FragTracker* ft, Packet* p) /* * process the packet through the detection engine */ - trace_log(stream_ip, - "Processing rebuilt packet:\n"); + debug_log(stream_ip_trace, "Processing rebuilt packet:\n"); ip_stats.reassembles++; ip_stats.reassembled_bytes += dpkt->pktlen; @@ -749,7 +738,7 @@ static void FragRebuild(FragTracker* ft, Packet* p) Analyzer::get_local_analyzer()->process_rebuilt_packet(dpkt, dpkt->pkth, dpkt->pkt, dpkt->pktlen); de.set_encode_packet(nullptr); - trace_log(stream_ip, "Done with rebuilt packet, marking rebuilt...\n"); + debug_log(stream_ip_trace,"Done with rebuilt packet, marking rebuilt...\n"); ft->frag_flags |= FRAG_REBUILT; } @@ -791,7 +780,7 @@ static inline void add_node(FragTracker* ft, Fragment* prev, Fragment* node) static inline void delete_node(FragTracker* ft, Fragment* node) { - trace_logf(stream_ip, "Deleting list node %p (p %p n %p)\n", + debug_logf(stream_ip_trace,"Deleting list node %p (p %p n %p)\n", (void*) node, (void*) node->prev, (void*) node->next); if (node->prev) @@ -824,8 +813,7 @@ static void delete_tracker(FragTracker* ft) Fragment* idx = ft->fraglist; /* pointer to the fraglist to delete */ Fragment* dump_me = nullptr; /* ptr to the Fragment element to drop */ - trace_logf(stream_ip, - "delete_tracker %d nodes to dump\n", ft->fraglist_count); + debug_logf(stream_ip_trace, "delete_tracker %d nodes to dump\n", ft->fraglist_count); /* * delete all the nodes in a fraglist @@ -924,7 +912,7 @@ void Defrag::process(Packet* p, FragTracker* ft) #ifdef DEBUG_MSGS if ( p->is_ip4() ) { - trace_logf(stream_ip, + debug_logf(stream_ip_trace, "[FRAG] Fragment discarded due to low TTL " "[0x%X->0x%X], TTL: %d " "Offset: %d Length: %hu\n", ntohl(p->ptrs.ip_api.get_ip4h()->get_src()), @@ -985,8 +973,8 @@ void Defrag::process(Packet* p, FragTracker* ft) switch (insert_return) { case FRAG_INSERT_FAILED: - trace_logf(stream_ip, "WARNING: Insert into Fraglist failed, " - "(offset: %hu).\n", frag_offset); + debug_logf(stream_ip_trace,"WARNING: Insert into Fraglist failed, (offset: %hu).\n", + frag_offset); return; case FRAG_INSERT_TTL: @@ -994,7 +982,7 @@ void Defrag::process(Packet* p, FragTracker* ft) #ifdef DEBUG_MSGS if ( p->is_ip4() ) { - trace_logf(stream_ip, + debug_logf(stream_ip_trace, "[FRAG] Fragment discarded due to large TTL Delta " "[0x%X->0x%X], TTL: %d orig TTL: %d " "Offset: %hu Length: %hu\n", @@ -1013,12 +1001,12 @@ void Defrag::process(Packet* p, FragTracker* ft) return; case FRAG_INSERT_TIMEOUT: - trace_logf(stream_ip, "WARNING: Insert into Fraglist failed due to timeout, " + debug_logf(stream_ip_trace,"WARNING: Insert into Fraglist failed due to timeout, " "(offset: %hu).\n", frag_offset); return; case FRAG_INSERT_OVERLAP_LIMIT: - trace_logf(stream_ip, + debug_logf(stream_ip_trace, "WARNING: Excessive IP fragment overlap, " "(More: %d, offset: %d, offsetSize: %hu).\n", (p->ptrs.decode_flags & DECODE_MF), @@ -1036,7 +1024,7 @@ void Defrag::process(Packet* p, FragTracker* ft) */ if (FragIsComplete(ft)) { - trace_log(stream_ip, "[*] Fragment is complete, rebuilding!\n"); + debug_log(stream_ip_trace,"[*] Fragment is complete, rebuilding!\n"); /* * if the frag completes but it's bad we're just going to drop it @@ -1129,7 +1117,7 @@ int Defrag::insert(Packet* p, FragTracker* ft, FragEngine* fe) if (IP_MAXPACKET - frag_offset < fragLength) { - trace_log(stream_ip, "[..] Oversize frag!\n"); + debug_log(stream_ip_trace,"[..] Oversize frag!\n"); EventAnomBadsizeLg(fe); ft->frag_flags |= FRAG_BAD; return FRAG_INSERT_ANOMALY; @@ -1163,8 +1151,7 @@ int Defrag::insert(Packet* p, FragTracker* ft, FragEngine* fe) /* * bonk/boink/jolt/etc attack... */ - trace_log(stream_ip, - "[..] Short frag (Bonk, etc) attack!\n"); + debug_log(stream_ip_trace, "[..] Short frag (Bonk, etc) attack!\n"); EventAnomShortFrag(fe); @@ -1187,8 +1174,7 @@ int Defrag::insert(Packet* p, FragTracker* ft, FragEngine* fe) if (ft->frag_flags & FRAG_GOT_LAST) { /* oversize frag attack */ - trace_log(stream_ip, - "[..] Oversize frag pkt!\n"); + debug_log(stream_ip_trace, "[..] Oversize frag pkt!\n"); EventAnomOversize(fe); @@ -1203,8 +1189,7 @@ int Defrag::insert(Packet* p, FragTracker* ft, FragEngine* fe) /* * zero size frag... */ - trace_log(stream_ip, - "[..] Zero size frag!\n"); + debug_log(stream_ip_trace, "[..] Zero size frag!\n"); EventAnomZeroFrag(fe); @@ -1221,8 +1206,7 @@ int Defrag::insert(Packet* p, FragTracker* ft, FragEngine* fe) ft->frag_pkts++; - trace_logf(stream_ip, - "Walking frag list (%d nodes), new frag %d@%d\n", + debug_logf(stream_ip_trace, "Walking frag list (%d nodes), new frag %d@%d\n", ft->fraglist_count, fragLength, frag_offset); /* @@ -1234,8 +1218,7 @@ int Defrag::insert(Packet* p, FragTracker* ft, FragEngine* fe) i++; right = idx; - trace_logf(stream_ip, - "%d right o %d s %d ptr %p prv %p nxt %p\n", + debug_logf(stream_ip_trace, "%d right o %d s %d ptr %p prv %p nxt %p\n", i, right->offset, right->size, (void*) right, (void*) right->prev, (void*) right->next); @@ -1258,8 +1241,7 @@ int Defrag::insert(Packet* p, FragTracker* ft, FragEngine* fe) */ if (left) { - trace_logf(stream_ip, - "Dealing with previous (left) frag %d@%d\n", + debug_logf(stream_ip_trace, "Dealing with previous (left) frag %d@%d\n", left->size, left->offset); /* @@ -1285,8 +1267,7 @@ int Defrag::insert(Packet* p, FragTracker* ft, FragEngine* fe) /* * teardrop attack... */ - trace_log(stream_ip, - "[..] Teardrop attack!\n"); + debug_log(stream_ip_trace, "[..] Teardrop attack!\n"); EventAttackTeardrop(fe); @@ -1315,25 +1296,23 @@ int Defrag::insert(Packet* p, FragTracker* ft, FragEngine* fe) frag_offset += (int16_t)overlap; slide = (int16_t)overlap; - trace_logf(stream_ip, - "left overlap, new frag moves: %d bytes, " - "slide: %d\n", overlap, slide); + debug_logf(stream_ip_trace, "left overlap, new frag moves: %d bytes, slide: %d\n", + overlap, slide); if (frag_end <= frag_offset) { /* * zero size frag */ - trace_log(stream_ip, - "zero size frag\n"); + debug_log(stream_ip_trace, "zero size frag\n"); EventAnomZeroFrag(fe); return FRAG_INSERT_ANOMALY; } - trace_logf(stream_ip, "left overlap, " - "truncating new pkt (slide: %d)\n", slide); + debug_logf(stream_ip_trace,"left overlap, truncating new pkt (slide: %d)\n", + slide); break; @@ -1387,16 +1366,14 @@ int Defrag::insert(Packet* p, FragTracker* ft, FragEngine* fe) } left_overlap_last: - trace_logf(stream_ip, "[!!] left overlap, " - "truncating old pkt (offset: %d overlap: %d)\n", - left->offset, overlap); + debug_logf(stream_ip_trace,"[!!] left overlap, " + "truncating old pkt (offset: %d overlap: %d)\n", left->offset, overlap); if (left->size == 0) { dump_me = left; - trace_logf(stream_ip, "retrans, " - "dumping old frag (offset: %d overlap: %d)\n", + debug_logf(stream_ip_trace,"retrans, dumping old frag (offset: %d overlap: %d)\n", dump_me->offset, overlap); left = left->prev; @@ -1412,8 +1389,7 @@ left_overlap_last: */ if (frag_end < frag_offset) { - trace_log(stream_ip, - "frag_end < frag_offset!"); + debug_log(stream_ip_trace, "frag_end < frag_offset!"); EventAnomBadsizeSm(fe); @@ -1422,14 +1398,13 @@ left_overlap_last: } else { - trace_log(stream_ip, "No left overlap!\n"); + debug_log(stream_ip_trace,"No left overlap!\n"); } } if ((uint16_t)fragLength > SnortConfig::get_conf()->daq_config->get_mru_size()) { - trace_logf(stream_ip, - "Overly large fragment %d 0x%x 0x%x %d\n", + debug_logf(stream_ip_trace, "Overly large fragment %d 0x%x 0x%x %d\n", fragLength, p->ptrs.ip_api.dgram_len(), p->ptrs.ip_api.off(), net_frag_offset); return FRAG_INSERT_FAILED; @@ -1443,8 +1418,7 @@ left_overlap_last: */ while (right && (right->offset < frag_end) && !done) { - trace_logf(stream_ip, - "Next (right)fragment %d@%d\n", + debug_logf(stream_ip_trace, "Next (right)fragment %d@%d\n", right->size, right->offset); trunc = 0; @@ -1461,8 +1435,7 @@ left_overlap_last: /* * teardrop attack... */ - trace_log(stream_ip, - "[..] Teardrop attack!\n"); + debug_log(stream_ip_trace, "[..] Teardrop attack!\n"); EventAttackTeardrop(fe); @@ -1481,8 +1454,7 @@ left_overlap_last: ip_stats.overlaps++; ft->overlap_count++; - trace_logf(stream_ip, - "Right-side overlap %d bytes\n", overlap); + debug_logf(stream_ip_trace, "Right-side overlap %d bytes\n", overlap); /* * once again, engine-based policy processing @@ -1508,17 +1480,15 @@ left_overlap_last: right->size -= (int16_t)overlap; ft->frag_bytes -= (int16_t)overlap; } - trace_logf(stream_ip, "[!!] right overlap, " + debug_logf(stream_ip_trace,"[!!] right overlap, " "truncating old frag (offset: %d, " "overlap: %d)\n", right->offset, overlap); - trace_log(stream_ip, - "Exiting right overlap loop...\n"); + debug_log(stream_ip_trace, "Exiting right overlap loop...\n"); if (right->size == 0) { dump_me = right; - trace_logf(stream_ip, "retrans, " - "dumping old frag (offset: %d overlap: %d)\n", + debug_logf(stream_ip_trace,"retrans, dumping old frag (offset: %d overlap: %d)\n", dump_me->offset, overlap); right = right->next; @@ -1535,12 +1505,9 @@ left_overlap_last: case FRAG_POLICY_SOLARIS: case FRAG_POLICY_BSD_RIGHT: trunc = (int16_t)overlap; - trace_logf(stream_ip, "[!!] right overlap, " - "truncating new frag (offset: %d " - "overlap: %d)\n", - right->offset, overlap); - trace_log(stream_ip, - "Exiting right overlap loop...\n"); + debug_logf(stream_ip_trace,"[!!] right overlap, " + "truncating new frag (offset: %d overlap: %d)\n", right->offset, overlap); + debug_log(stream_ip_trace, "Exiting right overlap loop...\n"); break; } @@ -1588,8 +1555,7 @@ left_overlap_last: dump_me = right; ft->frag_bytes -= right->size; - trace_logf(stream_ip, "retrans, " - "dumping old frag (offset: %d overlap: %d)\n", + debug_logf(stream_ip_trace,"retrans, dumping old frag (offset: %d overlap: %d)\n", dump_me->offset, overlap); right = right->next; @@ -1636,8 +1602,7 @@ left_overlap_last: trunc = (int16_t)overlap; } - trace_logf(stream_ip, "right overlap, " - "rejecting new overlap data (overlap: %d, " + debug_logf(stream_ip_trace,"right overlap, rejecting new overlap data (overlap: %d, " "trunc: %d)\n", overlap, trunc); if (frag_end - trunc <= frag_offset) @@ -1645,8 +1610,7 @@ left_overlap_last: /* * zero size frag */ - trace_logf(stream_ip, - "zero size frag (len: %d overlap: %d)\n", + debug_logf(stream_ip_trace, "zero size frag (len: %d overlap: %d)\n", fragLength, overlap); ip_stats.discards++; @@ -1732,8 +1696,7 @@ right_overlap_last: dump_me = right; ft->frag_bytes -= right->size; - trace_logf(stream_ip, "retrans, " - "dumping old frag (offset: %d overlap: %d)\n", + debug_logf(stream_ip_trace,"retrans, dumping old frag (offset: %d overlap: %d)\n", dump_me->offset, overlap); right = right->next; @@ -1752,7 +1715,7 @@ right_overlap_last: (ft->overlap_count >= fe->max_overlaps)) { // overlap limit exceeded. Raise event on all subsequent fragments - trace_log(stream_ip, "Reached overlap limit.\n"); + debug_log(stream_ip_trace,"Reached overlap limit.\n"); EventExcessiveOverlap(fe); @@ -1766,12 +1729,10 @@ right_overlap_last: } else { - trace_log(stream_ip, - "Fully truncated right overlap\n"); + debug_log(stream_ip_trace, "Fully truncated right overlap\n"); } - trace_log(stream_ip, - "insert(): returning normally\n"); + debug_log(stream_ip_trace, "insert(): returning normally\n"); return ret; } @@ -1803,8 +1764,7 @@ int Defrag::new_tracker(Packet* p, FragTracker* ft) /* Just to double check */ if (!fragLength or fragLength > SnortConfig::get_conf()->daq_config->get_mru_size()) { - trace_logf(stream_ip, - "Bad fragment length:%d(0x%x) off:0x%x(%d)\n", + debug_logf(stream_ip_trace, "Bad fragment length:%d(0x%x) off:0x%x(%d)\n", fragLength, p->ptrs.ip_api.dgram_len(), p->ptrs.ip_api.off(), p->ptrs.ip_api.off()); @@ -1870,8 +1830,7 @@ int Defrag::new_tracker(Packet* p, FragTracker* ft) /* * bonk/boink/jolt/etc attack... */ - trace_log(stream_ip, - "[..] Short frag (Bonk, etc) attack!\n"); + debug_log(stream_ip_trace, "[..] Short frag (Bonk, etc) attack!\n"); EventAnomShortFrag(&engine); @@ -1943,7 +1902,7 @@ int Defrag::add_frag_node( /* * zero size frag */ - trace_logf(stream_ip, + debug_logf(stream_ip_trace, "zero size frag after left & right trimming " "(len: %d slide: %d trunc: %d)\n", len, slide, trunc); @@ -1954,7 +1913,7 @@ int Defrag::add_frag_node( newfrag = ft->fraglist; while (newfrag) { - trace_logf(stream_ip, + debug_logf(stream_ip_trace, "Size: %d, offset: %d, len %d, " "Prev: 0x%p, Next: 0x%p, This: 0x%p, Ord: %d, %s\n", newfrag->size, newfrag->offset, @@ -1978,7 +1937,7 @@ int Defrag::add_frag_node( newfrag->offset = frag_offset; newfrag->last = lastfrag; - trace_logf(stream_ip, + debug_logf(stream_ip_trace, "[+] Adding new frag, offset %d, size %d\n" " nf->data = nf->fptr(%p) + slide (%d)\n" " nf->size = len(%d) - slide(%d) - trunc(%d)\n", @@ -1990,8 +1949,7 @@ int Defrag::add_frag_node( */ add_node(ft, left, newfrag); - trace_logf(stream_ip, - "[*] Inserted new frag %d@%d ptr %p data %p prv %p nxt %p\n", + debug_logf(stream_ip_trace, "[*] Inserted new frag %d@%d ptr %p data %p prv %p nxt %p\n", newfrag->size, newfrag->offset, (void*) newfrag, newfrag->data, (void*) newfrag->prev, (void*) newfrag->next); @@ -2000,9 +1958,8 @@ int Defrag::add_frag_node( */ ft->frag_bytes += newfrag->size; - trace_logf(stream_ip, - "[#] accumulated bytes on FragTracker %u, count" - " %d\n", ft->frag_bytes, ft->fraglist_count); + debug_logf(stream_ip_trace, "[#] accumulated bytes on FragTracker %u, count %d\n", + ft->frag_bytes, ft->fraglist_count); *retFrag = newfrag; return FRAG_INSERT_OK; @@ -2025,7 +1982,7 @@ int Defrag::dup_frag_node( FragTracker* ft, Fragment* left, Fragment** retFrag) add_node(ft, left, newfrag); - trace_logf(stream_ip, + debug_logf(stream_ip_trace, "[*] Inserted new frag %d@%d ptr %p data %p prv %p nxt %p\n", newfrag->size, newfrag->offset, (void*) newfrag, newfrag->data, (void*) newfrag->prev, (void*) newfrag->next); @@ -2035,9 +1992,8 @@ int Defrag::dup_frag_node( FragTracker* ft, Fragment* left, Fragment** retFrag) */ ft->frag_bytes += newfrag->size; - trace_logf(stream_ip, - "[#] accumulated bytes on FragTracker %u, count" - " %d\n", ft->frag_bytes, ft->fraglist_count); + debug_logf(stream_ip_trace, "[#] accumulated bytes on FragTracker %u, count %d\n", + ft->frag_bytes, ft->fraglist_count); *retFrag = newfrag; return FRAG_INSERT_OK; diff --git a/src/stream/ip/ip_module.cc b/src/stream/ip/ip_module.cc index d159337cd..662c29849 100644 --- a/src/stream/ip/ip_module.cc +++ b/src/stream/ip/ip_module.cc @@ -81,7 +81,7 @@ FragEngine::FragEngine() // stream_ip module //------------------------------------------------------------------------- -Trace TRACE_NAME(stream_ip); +Trace stream_ip_trace(MOD_NAME); static const RuleMap stream_ip_rules[] = { @@ -124,7 +124,7 @@ static const Parameter s_params[] = }; StreamIpModule::StreamIpModule() : - Module(MOD_NAME, MOD_HELP, s_params, false, &TRACE_NAME(stream_ip)) + Module(MOD_NAME, MOD_HELP, s_params, false, &stream_ip_trace) { config = nullptr; } StreamIpModule::~StreamIpModule() @@ -183,11 +183,6 @@ bool StreamIpModule::begin(const char*, int, SnortConfig*) return true; } -bool StreamIpModule::end(const char*, int, SnortConfig*) -{ - return true; -} - const PegInfo* StreamIpModule::get_pegs() const { return ip_pegs; } diff --git a/src/stream/ip/ip_module.h b/src/stream/ip/ip_module.h index 375c2facd..bebf45abe 100644 --- a/src/stream/ip/ip_module.h +++ b/src/stream/ip/ip_module.h @@ -83,7 +83,7 @@ struct IpStats extern const PegInfo ip_pegs[]; extern THREAD_LOCAL snort::ProfileStats ip_perf_stats; -extern Trace TRACE_NAME(stream_ip); +extern snort::Trace stream_ip_trace; //------------------------------------------------------------------------- // stream_ip module @@ -102,7 +102,6 @@ public: bool set(const char*, snort::Value&, snort::SnortConfig*) override; bool begin(const char*, int, snort::SnortConfig*) override; - bool end(const char*, int, snort::SnortConfig*) override; const snort::RuleMap* get_rules() const override; snort::ProfileStats* get_profile() const override; diff --git a/src/stream/stream.cc b/src/stream/stream.cc index c2f873394..b017e9d76 100644 --- a/src/stream/stream.cc +++ b/src/stream/stream.cc @@ -217,7 +217,7 @@ void Stream::stop_inspection( { assert(flow && flow->session); - trace_logf(stream, "stop inspection on flow, dir %s \n", + debug_logf(stream_trace, "stop inspection on flow, dir %s \n", dir == SSN_DIR_BOTH ? "BOTH" : ((dir == SSN_DIR_FROM_CLIENT) ? "FROM_CLIENT" : "FROM_SERVER")); diff --git a/src/stream/user/user_module.cc b/src/stream/user/user_module.cc index 5319e3f26..1d54be688 100644 --- a/src/stream/user/user_module.cc +++ b/src/stream/user/user_module.cc @@ -28,7 +28,7 @@ using namespace snort; using namespace std; -Trace TRACE_NAME(stream_user); +Trace stream_user_trace(MOD_NAME); //------------------------------------------------------------------------- // stream_user module @@ -43,7 +43,7 @@ static const Parameter s_params[] = }; StreamUserModule::StreamUserModule() : - Module(MOD_NAME, MOD_HELP, s_params, false, &TRACE_NAME(stream_user)) + Module(MOD_NAME, MOD_HELP, s_params, false, &stream_user_trace) { config = nullptr; } @@ -80,8 +80,3 @@ bool StreamUserModule::begin(const char*, int, SnortConfig*) return true; } -bool StreamUserModule::end(const char*, int, SnortConfig*) -{ - return true; -} - diff --git a/src/stream/user/user_module.h b/src/stream/user/user_module.h index 10ea2e390..cc4c46296 100644 --- a/src/stream/user/user_module.h +++ b/src/stream/user/user_module.h @@ -29,7 +29,7 @@ struct SnortConfig; extern THREAD_LOCAL snort::ProfileStats user_perf_stats; -extern Trace TRACE_NAME(stream_user); +extern snort::Trace stream_user_trace; //------------------------------------------------------------------------- // stream_user module @@ -48,7 +48,6 @@ public: bool set(const char*, snort::Value&, snort::SnortConfig*) override; bool begin(const char*, int, snort::SnortConfig*) override; - bool end(const char*, int, snort::SnortConfig*) override; Usage get_usage() const override { return INSPECT; } diff --git a/src/stream/user/user_session.cc b/src/stream/user/user_session.cc index b7ba6ea49..73094beb3 100644 --- a/src/stream/user/user_session.cc +++ b/src/stream/user/user_session.cc @@ -165,7 +165,7 @@ void UserTracker::detect( up->packet_flags |= (p->packet_flags & (PKT_FROM_CLIENT|PKT_FROM_SERVER)); up->packet_flags |= (p->packet_flags & (PKT_STREAM_EST|PKT_STREAM_UNEST_UNI)); - trace_logf(stream_user, "detect[%d]\n", up->dsize); + debug_logf(stream_user_trace, "detect[%d]\n", up->dsize); Analyzer::get_local_analyzer()->inspect_rebuilt(up); } @@ -185,7 +185,7 @@ int UserTracker::scan(Packet* p, uint32_t& flags) flags = p->packet_flags & (PKT_FROM_CLIENT|PKT_FROM_SERVER); unsigned len = us->get_unused_len(); - trace_logf(stream_user, "scan[%d]\n", len); + debug_logf(stream_user_trace, "scan[%d]\n", len); int32_t flush_amt = paf_check( splitter, &paf_state, p, us->get_unused_data(), len, @@ -210,7 +210,7 @@ int UserTracker::scan(Packet* p, uint32_t& flags) void UserTracker::flush(Packet* p, unsigned flush_amt, uint32_t flags) { unsigned bytes_flushed = 0; - trace_logf(stream_user, "flush[%d]\n", flush_amt); + debug_logf(stream_user_trace, "flush[%d]\n", flush_amt); uint32_t rflags = flags & ~PKT_PDU_TAIL; Packet* up = DetectionEngine::set_next_packet(p); @@ -230,7 +230,7 @@ void UserTracker::flush(Packet* p, unsigned flush_amt, uint32_t flags) len = flush_amt; } - trace_logf(stream_user, "reassemble[%d]\n", len); + debug_logf(stream_user_trace, "reassemble[%d]\n", len); StreamBuffer sb = splitter->reassemble( p->flow, flush_amt, bytes_flushed, data, len, rflags, bytes_copied); @@ -275,7 +275,7 @@ void UserTracker::process(Packet* p) void UserTracker::add_data(Packet* p) { - trace_logf(stream_user, "add[%d]\n", p->dsize); + debug_logf(stream_user_trace, "add[%d]\n", p->dsize); unsigned avail = 0; if ( !seg_list.empty() )