From: Oleksii Shumeiko -X (oshumeik - SOFTSERVE INC at Cisco) Date: Thu, 27 Apr 2023 10:02:57 +0000 (+0000) Subject: Pull request #3815: profiler: add shell commands X-Git-Tag: 3.1.61.0~9 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=d6d2a025fc570c548f9a91c9d0053c89ae13bb79;p=thirdparty%2Fsnort3.git Pull request #3815: profiler: add shell commands Merge in SNORT/snort3 from ~ASERBENI/snort3:profiler_shell_commands to master Squashed commit of the following: commit 7c951114e3b54775c8f30e889f050f431e170842 Author: Anna Norokh Date: Tue Apr 11 13:16:59 2023 +0300 snort: add show_config_generation() command commit a12cf4ae89d500160412504e2c1c4a7aea38c665 Author: Anna Norokh Date: Tue Apr 11 13:15:46 2023 +0300 profiler: add shell commands commit 3d388c55ff0a35776413b41386e5db5b0378545f Author: vhorbato Date: Wed Feb 15 12:45:52 2023 +0200 profiler: move profiler module to separate files --- diff --git a/src/detection/detection_options.cc b/src/detection/detection_options.cc index d0d1c3a69..022372c36 100644 --- a/src/detection/detection_options.cc +++ b/src/detection/detection_options.cc @@ -733,109 +733,102 @@ int detection_option_node_evaluate( return result; } -struct node_profile_stats -{ - // FIXIT-L duplicated from dot_node_state_t and OtnState - hr_duration elapsed; - hr_duration elapsed_match; - hr_duration elapsed_no_match; - - uint64_t checks; - uint64_t latency_timeouts; - uint64_t latency_suspends; -}; - static void detection_option_node_update_otn_stats(detection_option_tree_node_t* node, - node_profile_stats* stats, uint64_t checks, uint64_t timeouts, uint64_t suspends) + const dot_node_state_t* stats, unsigned thread_id, std::unordered_map& entries) { - node_profile_stats local_stats; /* cumulative stats for this node */ - node_profile_stats node_stats; /* sum of all instances */ + dot_node_state_t local_stats(node->state[thread_id]); /* cumulative stats for this node */ - memset(&node_stats, 0, sizeof(node_stats)); - - for ( unsigned i = 0; i < ThreadConfig::get_instance_max(); ++i ) + if (stats) { - node_stats.elapsed += node->state[i].elapsed; - node_stats.elapsed_match += node->state[i].elapsed_match; - node_stats.elapsed_no_match += node->state[i].elapsed_no_match; - node_stats.checks += node->state[i].checks; - } + local_stats.elapsed += stats->elapsed; + local_stats.elapsed_match += stats->elapsed_match; + local_stats.elapsed_no_match += stats->elapsed_no_match; - if ( stats ) - { - local_stats.elapsed = stats->elapsed + node_stats.elapsed; - local_stats.elapsed_match = stats->elapsed_match + node_stats.elapsed_match; - local_stats.elapsed_no_match = stats->elapsed_no_match + node_stats.elapsed_no_match; - - if (node_stats.checks > stats->checks) - local_stats.checks = node_stats.checks; - else + if (stats->checks > local_stats.checks) local_stats.checks = stats->checks; - local_stats.latency_timeouts = timeouts; - local_stats.latency_suspends = suspends; - } - else - { - local_stats.elapsed = node_stats.elapsed; - local_stats.elapsed_match = node_stats.elapsed_match; - local_stats.elapsed_no_match = node_stats.elapsed_no_match; - local_stats.checks = node_stats.checks; - local_stats.latency_timeouts = timeouts; - local_stats.latency_suspends = suspends; + local_stats.latency_suspends += stats->latency_suspends; + local_stats.latency_timeouts += stats->latency_timeouts; } if ( node->option_type == RULE_OPTION_TYPE_LEAF_NODE ) { // Update stats for this otn - // FIXIT-L call from packet threads at exit or total *all* states by main thread - // Right now, it looks like we're missing out on some stats although it's possible - // that this is "corrected" in the profiler code auto* otn = (OptTreeNode*)node->option_data; - auto& state = otn->state[get_instance_id()]; + auto& state = otn->state[thread_id]; - state.elapsed += local_stats.elapsed; - state.elapsed_match += local_stats.elapsed_match; - state.elapsed_no_match += local_stats.elapsed_no_match; + state.elapsed = local_stats.elapsed; + state.elapsed_match = local_stats.elapsed_match; + state.elapsed_no_match = local_stats.elapsed_no_match; if (local_stats.checks > state.checks) state.checks = local_stats.checks; - state.latency_timeouts += local_stats.latency_timeouts; - state.latency_suspends += local_stats.latency_suspends; + state.latency_timeouts = local_stats.latency_timeouts; + state.latency_suspends = local_stats.latency_suspends; + + static std::mutex rule_prof_stats_mutex; + std::lock_guard lock(rule_prof_stats_mutex); + + // All threads totals + OtnState& totals = entries[&otn->sigInfo]; + + totals.elapsed += state.elapsed; + totals.elapsed_match += state.elapsed_match; + totals.elapsed_no_match += state.elapsed_no_match; + totals.checks += state.checks; + totals.latency_timeouts += state.latency_timeouts; + totals.latency_suspends += state.latency_suspends; + totals.matches += state.matches; + totals.alerts += state.alerts; } if ( node->num_children ) { for ( int i = 0; i < node->num_children; ++i ) - detection_option_node_update_otn_stats(node->children[i], &local_stats, checks, - timeouts, suspends); + detection_option_node_update_otn_stats(node->children[i], &local_stats, thread_id, entries); } } -void detection_option_tree_update_otn_stats(XHash* doth) +static void detection_option_node_reset_otn_stats(detection_option_tree_node_t* node, + unsigned thread_id) { - if ( !doth ) - return; + node->state[thread_id].reset_profiling(); + + if ( node->option_type == RULE_OPTION_TYPE_LEAF_NODE ) + { + auto& state = ((OptTreeNode*)node->option_data)->state[thread_id]; + state = OtnState(); + } - for ( auto hnode = doth->find_first_node(); hnode; hnode = doth->find_next_node() ) + if ( node->num_children ) + { + for ( int i = 0; i < node->num_children; ++i ) + detection_option_node_reset_otn_stats(node->children[i], thread_id); + } +} + +void detection_option_tree_update_otn_stats(std::vector& nodes, std::unordered_map& stats, unsigned thread_id) +{ + for ( auto hnode : nodes ) { auto* node = (detection_option_tree_node_t*)hnode->data; assert(node); - uint64_t checks = 0; - uint64_t timeouts = 0; - uint64_t suspends = 0; + if ( node->state[thread_id].checks ) + detection_option_node_update_otn_stats(node, nullptr, thread_id, stats); + } +} - for ( unsigned i = 0; i < ThreadConfig::get_instance_max(); ++i ) - { - checks += node->state[i].checks; - timeouts += node->state[i].latency_timeouts; - suspends += node->state[i].latency_suspends; - } +void detection_option_tree_reset_otn_stats(std::vector& nodes, unsigned thread_id) +{ + for ( auto hnode : nodes ) + { + auto* node = (detection_option_tree_node_t*)hnode->data; + assert(node); - if ( checks ) - detection_option_node_update_otn_stats(node, nullptr, checks, timeouts, suspends); + if ( node->state[thread_id].checks ) + detection_option_node_reset_otn_stats(node, thread_id); } } diff --git a/src/detection/detection_options.h b/src/detection/detection_options.h index 67fa85f53..7fcbb48b7 100644 --- a/src/detection/detection_options.h +++ b/src/detection/detection_options.h @@ -46,6 +46,8 @@ struct Packet; struct SnortConfig; } struct RuleLatencyState; +struct SigInfo; +struct OtnState; typedef int (* eval_func_t)(void* option_data, class Cursor&, snort::Packet*); @@ -88,6 +90,13 @@ struct dot_node_state_t ++checks; } + + void reset_profiling() + { + elapsed = elapsed_match = elapsed_no_match = 0_ticks; + checks = disables = 0; + latency_suspends = latency_timeouts = 0; + } }; struct detection_option_tree_node_t; @@ -158,7 +167,9 @@ int detection_option_node_evaluate( const detection_option_tree_node_t*, detection_option_eval_data_t&, const class Cursor&); void print_option_tree(detection_option_tree_node_t*, int level); -void detection_option_tree_update_otn_stats(snort::XHash*); +void detection_option_tree_update_otn_stats(std::vector&, + std::unordered_map&, unsigned); +void detection_option_tree_reset_otn_stats(std::vector&, unsigned); detection_option_tree_root_t* new_root(OptTreeNode*); void free_detection_option_root(void** existing_tree); diff --git a/src/main.cc b/src/main.cc index a97d34249..da07634e7 100644 --- a/src/main.cc +++ b/src/main.cc @@ -406,6 +406,13 @@ int main_rotate_stats(lua_State* L) return 0; } +int main_show_config_generation(lua_State* L) +{ + ControlConn* ctrlcon = ControlConn::query_from_lua(L); + LogRespond(ctrlcon, "== configuration id: %u\n", SnortConfig::get_conf()->get_reload_id()); + return 0; +} + int main_reload_config(lua_State* L) { ControlConn* ctrlcon = ControlConn::query_from_lua(L); diff --git a/src/main.h b/src/main.h index 927e4d2f4..8b6ca5040 100644 --- a/src/main.h +++ b/src/main.h @@ -37,6 +37,7 @@ int main_reload_config(lua_State* = nullptr); int main_reload_policy(lua_State* = nullptr); int main_reload_daq(lua_State* = nullptr); int main_reload_hosts(lua_State* = nullptr); +int main_show_config_generation(lua_State* = nullptr); int main_process(lua_State* = nullptr); int main_pause(lua_State* = nullptr); int main_resume(lua_State* = nullptr); diff --git a/src/main/analyzer.cc b/src/main/analyzer.cc index 59fc6267b..b03b15c44 100644 --- a/src/main/analyzer.cc +++ b/src/main/analyzer.cc @@ -629,6 +629,7 @@ void Analyzer::init_unprivileged() InspectorManager::thread_init(sc); PacketTracer::thread_init(); HostAttributesManager::initialize(); + RuleContext::set_enabled(sc->profiler->rule.show); // in case there are HA messages waiting, process them first HighAvailabilityManager::process_receive(); diff --git a/src/main/modules.cc b/src/main/modules.cc index 04716ac06..a964470a0 100644 --- a/src/main/modules.cc +++ b/src/main/modules.cc @@ -57,7 +57,7 @@ #include "parser/parser.h" #include "parser/vars.h" #include "payload_injector/payload_injector_module.h" -#include "profiler/profiler.h" +#include "profiler/profiler_module.h" #include "search_engines/pat_stats.h" #include "side_channel/side_channel_module.h" #include "sfip/sf_ipvar.h" @@ -319,165 +319,6 @@ bool SearchEngineModule::set(const char*, Value& v, SnortConfig* sc) return true; } -// ----------------------------------------------------------------------------- -// profiler module -// ----------------------------------------------------------------------------- - -static const Parameter profiler_time_params[] = -{ - { "show", Parameter::PT_BOOL, nullptr, "true", - "show module time profile stats" }, - - { "count", Parameter::PT_INT, "0:max32", "0", - "limit results to count items per level (0 = no limit)" }, - - { "sort", Parameter::PT_ENUM, - "none | checks | avg_check | total_time ", - "total_time", "sort by given field" }, - - { "max_depth", Parameter::PT_INT, "-1:255", "-1", - "limit depth to max_depth (-1 = no limit)" }, - - { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } -}; - -static const Parameter profiler_memory_params[] = -{ - { "show", Parameter::PT_BOOL, nullptr, "true", - "show module memory profile stats" }, - - { "count", Parameter::PT_INT, "0:max32", "0", - "limit results to count items per level (0 = no limit)" }, - - { "sort", Parameter::PT_ENUM, - "none | allocations | total_used | avg_allocation ", - "total_used", "sort by given field" }, - - { "max_depth", Parameter::PT_INT, "-1:255", "-1", - "limit depth to max_depth (-1 = no limit)" }, - - { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } -}; - -static const Parameter profiler_rule_params[] = -{ - { "show", Parameter::PT_BOOL, nullptr, "true", - "show rule time profile stats" }, - - { "count", Parameter::PT_INT, "0:max32", "0", - "print results to given level (0 = all)" }, - - { "sort", Parameter::PT_ENUM, - "none | checks | avg_check | total_time | matches | no_matches | " - "avg_match | avg_no_match", - "total_time", "sort by given field" }, - - { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } -}; - -static const Parameter profiler_params[] = -{ - { "modules", Parameter::PT_TABLE, profiler_time_params, nullptr, - "module time profiling" }, - - { "memory", Parameter::PT_TABLE, profiler_memory_params, nullptr, - "module memory profiling" }, - - { "rules", Parameter::PT_TABLE, profiler_rule_params, nullptr, - "rule time profiling" }, - - { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } -}; - -#define profiler_help \ - "configure profiling of rules and/or modules" - -template -static bool s_profiler_module_set_max_depth(T& config, Value& v) -{ config.max_depth = v.get_int16(); return true; } - -static bool s_profiler_module_set_max_depth(RuleProfilerConfig&, Value&) -{ return false; } - -template -static bool s_profiler_module_set(T& config, Value& v) -{ - if ( v.is("count") ) - config.count = v.get_uint32(); - - else if ( v.is("show") ) - config.show = v.get_bool(); - - else if ( v.is("sort") ) - config.sort = static_cast(v.get_uint8()); - - else if ( v.is("max_depth") ) - return s_profiler_module_set_max_depth(config, v); - - else - return false; - - return true; -} - -class ProfilerModule : public Module -{ -public: - ProfilerModule() : Module("profiler", profiler_help, profiler_params) { } - - bool set(const char*, Value&, SnortConfig*) override; - bool end(const char*, int, SnortConfig*) override; - - ProfileStats* get_profile(unsigned, const char*&, const char*&) const override; - - Usage get_usage() const override - { return GLOBAL; } -}; - -bool ProfilerModule::set(const char* fqn, Value& v, SnortConfig* sc) -{ - const char* spt = "profiler.modules"; - const char* spm = "profiler.memory"; - const char* spr = "profiler.rules"; - - if ( !strncmp(fqn, spt, strlen(spt)) ) - return s_profiler_module_set(sc->profiler->time, v); - - else if ( !strncmp(fqn, spm, strlen(spm)) ) - return s_profiler_module_set(sc->profiler->memory, v); - - else if ( !strncmp(fqn, spr, strlen(spr)) ) - return s_profiler_module_set(sc->profiler->rule, v); - - return false; -} - -bool ProfilerModule::end(const char*, int, SnortConfig* sc) -{ - TimeProfilerStats::set_enabled(sc->profiler->time.show); - RuleContext::set_enabled(sc->profiler->rule.show); - RuleContext::set_start_time(get_time_curr()); - return true; -} - -ProfileStats* ProfilerModule::get_profile( - unsigned index, const char*& name, const char*& parent) const -{ - switch ( index ) - { - case 0: - name = "total"; - parent = nullptr; - return &totalPerfStats; - - case 1: - name = "other"; - parent = nullptr; - return &otherPerfStats; - } - return nullptr; -} - //------------------------------------------------------------------------- // classification module //------------------------------------------------------------------------- diff --git a/src/main/snort_config.h b/src/main/snort_config.h index 5471d04f4..d0d87f4d0 100644 --- a/src/main/snort_config.h +++ b/src/main/snort_config.h @@ -661,6 +661,9 @@ public: void update_reload_id(); + unsigned get_reload_id() const + { return reload_id; } + bool get_default_rule_state() const; ConfigOutput* create_config_output() const; diff --git a/src/main/snort_module.cc b/src/main/snort_module.cc index 740a4a1ac..89c5b8b01 100644 --- a/src/main/snort_module.cc +++ b/src/main/snort_module.cc @@ -134,7 +134,8 @@ static const Command snort_cmds[] = { "reload_policy", main_reload_policy, s_reload, "reload part or all of the default policy" }, { "reload_daq", main_reload_daq, nullptr, "reload daq module" }, { "reload_hosts", main_reload_hosts, s_reload, "load a new hosts table" }, - { "log_command", main_log_command,main_log_command_param, "enabled or disable logging of a command"}, + { "log_command", main_log_command,main_log_command_param, "enable or disable command logging"}, + { "show_config_generation", main_show_config_generation, nullptr, "show loaded configuration ID"}, // FIXIT-M rewrite trough to permit updates on the fly //{ "process", main_process, nullptr, "process given pcap" }, diff --git a/src/main/test/distill_verdict_stubs.h b/src/main/test/distill_verdict_stubs.h index b21f6a78d..e7ea809c5 100644 --- a/src/main/test/distill_verdict_stubs.h +++ b/src/main/test/distill_verdict_stubs.h @@ -64,6 +64,7 @@ #include "utils/stats.h" THREAD_LOCAL DAQStats daq_stats; +THREAD_LOCAL bool RuleContext::enabled = false; void Profiler::start() { } void Profiler::stop(uint64_t) { } diff --git a/src/profiler/CMakeLists.txt b/src/profiler/CMakeLists.txt index dbd070548..fe47fd228 100644 --- a/src/profiler/CMakeLists.txt +++ b/src/profiler/CMakeLists.txt @@ -24,6 +24,8 @@ set ( PROFILER_SOURCES rule_profiler.h time_profiler.cc time_profiler.h + profiler_module.cc + profiler_module.h ) add_library ( profiler OBJECT diff --git a/src/profiler/profiler_module.cc b/src/profiler/profiler_module.cc new file mode 100644 index 000000000..51c5b0958 --- /dev/null +++ b/src/profiler/profiler_module.cc @@ -0,0 +1,406 @@ +//-------------------------------------------------------------------------- +// Copyright (C) 2015-2023 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. +//-------------------------------------------------------------------------- + +// profiler_module.cc author Russ Combs + +#ifdef HAVE_CONFIG_H +#include "config.h" +#endif + +#include "profiler_module.h" + +#include "control/control.h" +#include "hash/xhash.h" +#include "log/messages.h" +#include "main/analyzer_command.h" +#include "main/reload_tuner.h" +#include "main/snort.h" +#include "main/snort_config.h" +#include "managers/module_manager.h" + +#include "profiler/rule_profiler.h" +#include "profiler/rule_profiler_defs.h" + +using namespace snort; + +#define profiler_help \ + "configure profiling of rules and/or modules" + +struct SigInfo; +struct OtnState; + +//------------------------------------------------------------------------- +// commands +//------------------------------------------------------------------------- + +class ProfilerControl : public AnalyzerCommand +{ +public: + enum CommandType + { + ENABLE, + DISABLE + }; + + ProfilerControl(CommandType action) + : action(action) + {} + + bool execute(Analyzer&, void**) override + { + switch (action) + { + case ENABLE: + RuleContext::set_enabled(true); + break; + case DISABLE: + RuleContext::set_enabled(false); + break; + default: + return false; + } + return true; + } + + const char *stringify() override { return "PROFILER_CONTROL"; } + +private: + CommandType action; +}; + +class ProfilerRuleDump : public AnalyzerCommand +{ +public: + ProfilerRuleDump(ControlConn* conn) + : AnalyzerCommand(conn), nodes(), stats() + { + const SnortConfig* sc = SnortConfig::get_conf(); + assert(sc); + + auto doth = sc->detection_option_tree_hash_table; + + if (!doth) + return; + + for (HashNode* hnode = doth->find_first_node(); hnode; hnode = doth->find_next_node()) + { + nodes.emplace_back(hnode); + } + } + + ~ProfilerRuleDump() override + { + const auto* config = SnortConfig::get_conf()->get_profiler(); + assert(config); + + print_rule_profiler_stats(config->rule, stats, ctrlcon); + } + + bool execute(Analyzer&, void**) override + { + prepare_rule_profiler_stats(nodes, stats, get_instance_id()); + + return true; + } + + const char *stringify() override { return "PROFILER_RULE_DUMP"; } + +private: + std::vector nodes; + std::unordered_map stats; +}; + +class ProfilerRuleReset : public AnalyzerCommand +{ +public: + ProfilerRuleReset() : nodes() + { + const SnortConfig* sc = SnortConfig::get_conf(); + assert(sc); + + auto doth = sc->detection_option_tree_hash_table; + + if (!doth) + return; + + for (HashNode* hnode = doth->find_first_node(); hnode; hnode = doth->find_next_node()) + { + nodes.emplace_back(hnode); + } + } + + bool execute(Analyzer&, void**) override + { + reset_thread_rule_profiler_stats(nodes, get_instance_id()); + + return true; + } + + const char *stringify() override { return "PROFILER_RULE_RESET"; } + +private: + std::vector nodes; +}; + +static int rule_profiling_start(lua_State* L) +{ + ControlConn* ctrlcon = ControlConn::query_from_lua(L); + + if (RuleContext::is_enabled()) + { + LogRespond(ctrlcon, "Rule profiler is already running\n"); + return 0; + } + + RuleContext::set_enabled(true); + main_broadcast_command(new ProfilerControl(ProfilerControl::CommandType::ENABLE), ctrlcon); + main_broadcast_command(new ProfilerRuleReset(), ctrlcon); + LogRespond(ctrlcon, "Rule profiler started\n"); + LogRespond(ctrlcon, "Configuration reload id: %u\n", SnortConfig::get_conf()->get_reload_id()); + + return 0; +} + +static int rule_profiling_stop(lua_State* L) +{ + ControlConn* ctrlcon = ControlConn::query_from_lua(L); + + if (!RuleContext::is_enabled()) + { + LogRespond(ctrlcon, "Rule profiler is not running\n"); + return 0; + } + + RuleContext::set_enabled(false); + main_broadcast_command(new ProfilerControl(ProfilerControl::CommandType::DISABLE), ctrlcon); + LogRespond(ctrlcon, "Rule profiler stopped\n"); + + return 0; +} + +static int rule_profiling_status(lua_State* L) +{ + ControlConn* ctrlcon = ControlConn::query_from_lua(L); + + LogRespond(ctrlcon, "Rule profiler is %s\n", RuleContext::is_enabled() ? + "enabled" : "disabled"); + + return 0; +} + +static int rule_profiling_dump(lua_State* L) +{ + ControlConn* ctrlcon = ControlConn::query_from_lua(L); + + if (!RuleContext::is_enabled()) + { + LogRespond(ctrlcon, "Rule profiler is off\n"); + return 0; + } + + main_broadcast_command(new ProfilerRuleDump(ctrlcon), ctrlcon); + + return 0; +} + +static const Command profiler_cmds[] = +{ + { "rule_start", rule_profiling_start, + nullptr, "enable rule profiler" }, + + { "rule_stop", rule_profiling_stop, + nullptr, "disable rule profiler" }, + + { "rule_status", rule_profiling_status, + nullptr, "print rule profiler status" }, + + { "rule_dump", rule_profiling_dump, + nullptr, "print rule statistics" }, + + { nullptr, nullptr, nullptr, nullptr } +}; + +const Command* ProfilerModule::get_commands() const +{ return profiler_cmds; } + +static const Parameter profiler_time_params[] = +{ + { "show", Parameter::PT_BOOL, nullptr, "true", + "show module time profile stats" }, + + { "count", Parameter::PT_INT, "0:max32", "0", + "limit results to count items per level (0 = no limit)" }, + + { "sort", Parameter::PT_ENUM, + "none | checks | avg_check | total_time ", + "total_time", "sort by given field" }, + + { "max_depth", Parameter::PT_INT, "-1:255", "-1", + "limit depth to max_depth (-1 = no limit)" }, + + { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } +}; + +static const Parameter profiler_memory_params[] = +{ + { "show", Parameter::PT_BOOL, nullptr, "true", + "show module memory profile stats" }, + + { "count", Parameter::PT_INT, "0:max32", "0", + "limit results to count items per level (0 = no limit)" }, + + { "sort", Parameter::PT_ENUM, + "none | allocations | total_used | avg_allocation ", + "total_used", "sort by given field" }, + + { "max_depth", Parameter::PT_INT, "-1:255", "-1", + "limit depth to max_depth (-1 = no limit)" }, + + { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } +}; + +static const Parameter profiler_rule_params[] = +{ + { "show", Parameter::PT_BOOL, nullptr, "true", + "show rule time profile stats" }, + + { "count", Parameter::PT_INT, "0:max32", "0", + "print results to given level (0 = all)" }, + + { "sort", Parameter::PT_ENUM, + "none | checks | avg_check | total_time | matches | no_matches | " + "avg_match | avg_no_match", + "total_time", "sort by given field" }, + + { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } +}; + +static const Parameter profiler_params[] = +{ + { "modules", Parameter::PT_TABLE, profiler_time_params, nullptr, + "module time profiling" }, + + { "memory", Parameter::PT_TABLE, profiler_memory_params, nullptr, + "module memory profiling" }, + + { "rules", Parameter::PT_TABLE, profiler_rule_params, nullptr, + "rule time profiling" }, + + { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr } +}; + +class ProfilerReloadTuner : public snort::ReloadResourceTuner +{ +public: + explicit ProfilerReloadTuner(bool enable) : enable(enable) + {} + ~ProfilerReloadTuner() override = default; + + bool tinit() override + { + RuleContext::set_enabled(enable); + return false; + } + + bool tune_packet_context() override + { return true; } + + bool tune_idle_context() override + { return true; } + +private: + bool enable = false; +}; + +template +static bool s_profiler_module_set_max_depth(T& config, Value& v) +{ config.max_depth = v.get_int16(); return true; } + +static bool s_profiler_module_set_max_depth(RuleProfilerConfig&, Value&) +{ return false; } + +template +static bool s_profiler_module_set(T& config, Value& v) +{ + if ( v.is("count") ) + config.count = v.get_uint32(); + + else if ( v.is("show") ) + config.show = v.get_bool(); + + else if ( v.is("sort") ) + config.sort = static_cast(v.get_uint8()); + + else if ( v.is("max_depth") ) + return s_profiler_module_set_max_depth(config, v); + + else + return false; + + return true; +} + +ProfilerModule::ProfilerModule() : snort::Module("profiler", profiler_help, profiler_params) +{ } + +bool ProfilerModule::set(const char* fqn, Value& v, SnortConfig* sc) +{ + const char* spt = "profiler.modules"; + const char* spm = "profiler.memory"; + const char* spr = "profiler.rules"; + + if ( !strncmp(fqn, spt, strlen(spt)) ) + return s_profiler_module_set(sc->profiler->time, v); + + else if ( !strncmp(fqn, spm, strlen(spm)) ) + return s_profiler_module_set(sc->profiler->memory, v); + + else if ( !strncmp(fqn, spr, strlen(spr)) ) + return s_profiler_module_set(sc->profiler->rule, v); + + return false; +} + +bool ProfilerModule::end(const char* fqn, int, SnortConfig* sc) +{ + TimeProfilerStats::set_enabled(sc->profiler->time.show); + RuleContext::set_enabled(sc->profiler->rule.show); + + if ( Snort::is_reloading() && strcmp(fqn, "profiler") == 0 ) + sc->register_reload_handler(new ProfilerReloadTuner(sc->profiler->rule.show)); + + return true; +} + +ProfileStats* ProfilerModule::get_profile( + unsigned index, const char*& name, const char*& parent) const +{ + switch ( index ) + { + case 0: + name = "total"; + parent = nullptr; + return &totalPerfStats; + + case 1: + name = "other"; + parent = nullptr; + return &otherPerfStats; + } + return nullptr; +} diff --git a/src/profiler/profiler_module.h b/src/profiler/profiler_module.h new file mode 100644 index 000000000..d53add5f0 --- /dev/null +++ b/src/profiler/profiler_module.h @@ -0,0 +1,43 @@ +//-------------------------------------------------------------------------- +// Copyright (C) 2015-2023 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. +//-------------------------------------------------------------------------- + +// profiler_module.h author Russ Combs + +#ifndef PROFILER_MODULE_H +#define PROFILER_MODULE_H + +#include "framework/module.h" + +#include "profiler/profiler.h" + +class ProfilerModule : public snort::Module +{ +public: + ProfilerModule(); + + bool set(const char*, snort::Value&, snort::SnortConfig*) override; + bool end(const char*, int, snort::SnortConfig*) override; + + snort::ProfileStats* get_profile(unsigned, const char*&, const char*&) const override; + const snort::Command* get_commands() const override; + + Usage get_usage() const override + { return GLOBAL; } +}; + +#endif diff --git a/src/profiler/rule_profiler.cc b/src/profiler/rule_profiler.cc index 14220f0ea..c28508977 100644 --- a/src/profiler/rule_profiler.cc +++ b/src/profiler/rule_profiler.cc @@ -35,9 +35,10 @@ // 2. The left expression of the compound assignment is an uninitialized value. // The computed value will also be garbage (duration& operator+=(const duration& __d)) #include "detection/detection_options.h" // ... FIXIT-W - +#include "control/control.h" #include "detection/treenodes.h" #include "hash/ghash.h" +#include "hash/xhash.h" #include "main/snort_config.h" #include "main/thread_config.h" #include "parser/parser.h" @@ -57,21 +58,11 @@ using namespace snort; #define s_rule_table_title "rule profile" -bool RuleContext::enabled = false; +THREAD_LOCAL bool RuleContext::enabled = false; struct timeval RuleContext::start_time = {0, 0}; struct timeval RuleContext::end_time = {0, 0}; struct timeval RuleContext::total_time = {0, 0}; -static inline OtnState& operator+=(OtnState& lhs, const OtnState& rhs) -{ - lhs.elapsed += rhs.elapsed; - lhs.elapsed_match += rhs.elapsed_match; - lhs.checks += rhs.checks; - lhs.matches += rhs.matches; - lhs.alerts += rhs.alerts; - return lhs; -} - namespace rule_stats { @@ -199,44 +190,20 @@ static const ProfilerSorter sorters[] = } }; -static void consolidate_otn_states(OtnState* states) +static std::vector build_entries(const std::unordered_map& stats) { - for ( unsigned i = 1; i < ThreadConfig::get_instance_max(); ++i ) - states[0] += states[i]; -} - -static std::vector build_entries() -{ - const SnortConfig* sc = SnortConfig::get_conf(); - assert(sc); - - detection_option_tree_update_otn_stats(sc->detection_option_tree_hash_table); - auto* otn_map = sc->otn_map; - std::vector entries; - for ( auto* h = otn_map->find_first(); h; h = otn_map->find_next() ) - { - auto* otn = static_cast(h->data); - assert(otn); - - auto* states = otn->state; - - consolidate_otn_states(states); - auto& state = states[0]; - - if ( !state.is_active() ) - continue; - - // FIXIT-L should we assert(otn->sigInfo)? - entries.emplace_back(state, &otn->sigInfo); - } + for (auto stat : stats) + if (stat.second.is_active()) + entries.emplace_back(stat.second, stat.first); return entries; } // FIXIT-L logic duplicated from ProfilerPrinter -static void print_single_entry(const View& v, unsigned n, double total_time_usec) +static void print_single_entry(ControlConn* ctrlcon, const View& v, unsigned n, + double total_time_usec) { using std::chrono::duration_cast; using std::chrono::microseconds; @@ -268,11 +235,12 @@ static void print_single_entry(const View& v, unsigned n, double total_time_usec table << v.rule_time_per(total_time_usec); } - LogMessage("%s", ss.str().c_str()); + LogRespond(ctrlcon, "%s", ss.str().c_str()); } // FIXIT-L logic duplicated from ProfilerPrinter -static void print_entries(std::vector& entries, ProfilerSorter& sort, unsigned count) +static void print_entries(ControlConn* ctrlcon, std::vector& entries, + ProfilerSorter& sort, unsigned count) { std::ostringstream ss; RuleContext::set_end_time(get_time_curr()); @@ -300,7 +268,7 @@ static void print_entries(std::vector& entries, ProfilerSorter& sort table << StatsTable::HEADER; } - LogMessage("%s", ss.str().c_str()); + LogRespond(ctrlcon, "%s", ss.str().c_str()); if ( !count || count > entries.size() ) count = entries.size(); @@ -309,17 +277,15 @@ static void print_entries(std::vector& entries, ProfilerSorter& sort std::partial_sort(entries.begin(), entries.begin() + count, entries.end(), sort); for ( unsigned i = 0; i < count; ++i ) - print_single_entry(entries[i], i + 1, total_time_usec); + print_single_entry(ctrlcon, entries[i], i + 1, total_time_usec); } } -void show_rule_profiler_stats(const RuleProfilerConfig& config) +void print_rule_profiler_stats(const RuleProfilerConfig& config, const std::unordered_map& stats, + ControlConn* ctrlcon) { - if ( !config.show ) - return; - - auto entries = rule_stats::build_entries(); + auto entries = rule_stats::build_entries(stats); // if there aren't any eval'd rules, don't sort or print if ( entries.empty() ) @@ -328,32 +294,71 @@ void show_rule_profiler_stats(const RuleProfilerConfig& config) auto sort = rule_stats::sorters[config.sort]; // FIXIT-L do we eventually want to be able print rule totals, too? - print_entries(entries, sort, config.count); + print_entries(ctrlcon, entries, sort, config.count); } -void reset_rule_profiler_stats() +void show_rule_profiler_stats(const RuleProfilerConfig& config) { + if (!RuleContext::is_enabled()) + return; + const SnortConfig* sc = SnortConfig::get_conf(); assert(sc); - auto* otn_map = sc->otn_map; + auto doth = sc->detection_option_tree_hash_table; + + if (!doth) + return; - for ( auto* h = otn_map->find_first(); h; h = otn_map->find_next() ) + std::vector nodes; + std::unordered_map stats; + + for (HashNode* hnode = doth->find_first_node(); hnode; hnode = doth->find_next_node()) { - auto* otn = static_cast(h->data); - assert(otn); + nodes.push_back(hnode); + } + + for ( unsigned i = 0; i < ThreadConfig::get_instance_max(); ++i ) + prepare_rule_profiler_stats(nodes, stats, i); - auto* rtn = getRtnFromOtn(otn); + print_rule_profiler_stats(config, stats, nullptr); +} - if ( !rtn || !is_network_protocol(rtn->snort_protocol_id) ) - continue; +void prepare_rule_profiler_stats(std::vector& nodes, std::unordered_map& stats, unsigned thread_id) +{ + if (!RuleContext::is_enabled()) + return; - for ( unsigned i = 0; i < ThreadConfig::get_instance_max(); ++i ) - { - auto& state = otn->state[i]; - state = OtnState(); - } + detection_option_tree_update_otn_stats(nodes, stats, thread_id); +} + +void reset_rule_profiler_stats() +{ + const SnortConfig* sc = SnortConfig::get_conf(); + assert(sc); + + auto doth = sc->detection_option_tree_hash_table; + + if (!doth) + return; + + std::vector nodes; + + for (HashNode* hnode = doth->find_first_node(); hnode; hnode = doth->find_next_node()) + { + nodes.emplace_back(hnode); } + + for ( unsigned i = 0; i < ThreadConfig::get_instance_max(); ++i ) + reset_thread_rule_profiler_stats(nodes, i); +} + +void reset_thread_rule_profiler_stats(std::vector& nodes, unsigned thread_id) +{ + if (!RuleContext::is_enabled()) + return; + + detection_option_tree_reset_otn_stats(nodes, thread_id); } void RuleContext::stop(bool match) @@ -467,27 +472,6 @@ TEST_CASE( "otn state", "[profiler][rule_profiler]" ) state_a.noalerts = 3; state_a.alerts = 4; - SECTION( "incremental addition" ) - { - OtnState state_b; - - state_b.elapsed = 4_ticks; - state_b.elapsed_match = 5_ticks; - state_b.elapsed_no_match = 6_ticks; - state_b.checks = 5; - state_b.matches = 6; - state_b.noalerts = 7; - state_b.alerts = 8; - - state_a += state_b; - - CHECK( (state_a.elapsed == 5_ticks) ); - CHECK( (state_a.elapsed_match == 7_ticks) ); - CHECK( (state_a.checks == 6) ); - CHECK( (state_a.matches == 8) ); - CHECK( (state_a.alerts == 12) ); - } - SECTION( "reset" ) { state_a = OtnState(); diff --git a/src/profiler/rule_profiler.h b/src/profiler/rule_profiler.h index 48ff40be2..36b9d7601 100644 --- a/src/profiler/rule_profiler.h +++ b/src/profiler/rule_profiler.h @@ -21,9 +21,21 @@ #ifndef RULE_PROFILER_H #define RULE_PROFILER_H +#include "detection/treenodes.h" +#include +#include + struct RuleProfilerConfig; +class ControlConn; +namespace snort +{ + class HashNode; +} +void prepare_rule_profiler_stats(std::vector&, std::unordered_map&, unsigned); +void print_rule_profiler_stats(const RuleProfilerConfig&, const std::unordered_map&, ControlConn* = nullptr); void show_rule_profiler_stats(const RuleProfilerConfig&); void reset_rule_profiler_stats(); +void reset_thread_rule_profiler_stats(std::vector&, unsigned); #endif diff --git a/src/profiler/rule_profiler_defs.h b/src/profiler/rule_profiler_defs.h index 38aef0039..109276370 100644 --- a/src/profiler/rule_profiler_defs.h +++ b/src/profiler/rule_profiler_defs.h @@ -82,12 +82,15 @@ public: { return &total_time; } static void count_total_time(); + static bool is_enabled() + { return enabled; } private: dot_node_state_t& stats; Stopwatch sw; bool finished = false; - static bool enabled; + + static THREAD_LOCAL bool enabled; static struct timeval start_time; static struct timeval end_time; static struct timeval total_time;