From: Russ Combs (rucombs) Date: Tue, 17 Nov 2015 22:41:02 +0000 (-0500) Subject: Merge pull request #135 in SNORT/snort3 from ~JOCORNET/snort3:mem_profiler to master X-Git-Tag: 3.0.0-233~724 X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=edc33d30a4d0b157c182dfb6d49bd171b4b86fdf;p=thirdparty%2Fsnort3.git Merge pull request #135 in SNORT/snort3 from ~JOCORNET/snort3:mem_profiler to master Squashed commit of the following: commit 3b843fdc2a341e22d63840d72900d90767df31c9 Author: Joel Cornett Date: Tue Nov 17 15:56:43 2015 -0500 hardened PERF_PROFILING commit 6eb3d6f8ab4d474344c5ff2143206f23e9c96aa4 Author: Joel Cornett Date: Tue Nov 17 13:47:30 2015 -0500 fixed typo commit 45c6d8816b00fdf793704e733f20c0f0d863708e Author: Joel Cornett Date: Mon Nov 16 18:03:38 2015 -0500 updated profiler unit tests commit 6a6bb3900277062d25b2c06b9c5cd9b246e09b68 Author: Joel Cornett Date: Mon Nov 16 17:00:45 2015 -0500 fluff commit ef2a51bcff9e5f59bd6087ad4356c1f64c5fa23a Author: Joel Cornett Date: Mon Nov 16 16:53:34 2015 -0500 updates commit 8f3563c3b3f2e6df894aa98d25390cd1f5c602d0 Author: Joel Cornett Date: Mon Nov 16 15:47:33 2015 -0500 added clock type definitions commit a426b1be454df278cefd65cf25f59af6247e57e2 Author: Joel Cornett Date: Mon Nov 16 15:43:53 2015 -0500 partial commit converted ticks to use high_resolution_clock duration commit ad22683e444641f954e57de6194174e5add8305f Author: Joel Cornett Date: Mon Nov 16 15:40:25 2015 -0500 partial commit, updated build system in preparation for memory profiling --- diff --git a/cmake/configure_options.cmake b/cmake/configure_options.cmake index 232faad8d..5dbb9192a 100644 --- a/cmake/configure_options.cmake +++ b/cmake/configure_options.cmake @@ -7,7 +7,6 @@ # convert cmake options into compiler defines -set_project_compiler_defines_if_true (ENABLE_PERFPROFILING "PERF_PROFILING") set_project_compiler_defines_if_true (ENABLE_DEBUG_MSGS "DEBUG_MSGS") set_project_compiler_defines_if_true (ENABLE_DEBUG "DEBUG") set_project_compiler_defines_if_true (BUILD_HA "ENABLE_HA") @@ -28,7 +27,6 @@ set_if_true (STATIC_CODECS STATIC_CODECS) set_if_true (ENABLE_VALGRIND VALGRIND_TESTING) set_if_true (ENABLE_PPM PPM_MGR) set_if_true (ENABLE_PPM_TEST PPM_TEST) -set_if_true (ENABLE_PERFPROFILING PERF_PROFILING) set_if_true (BUILD_HA ENABLE_HA ) set_if_true (ENABLE_LINUX_SMP_STATS LINUX_SMP) set_if_true (ENABLE_DEBUG DEBUG) diff --git a/cmake/create_options.cmake b/cmake/create_options.cmake index 7d2bc5f96..18600d20e 100644 --- a/cmake/create_options.cmake +++ b/cmake/create_options.cmake @@ -14,7 +14,6 @@ option (STATIC_SEARCH_ENGINES "include search engines in binary" ON) option (ENABLE_STATIC_DAQ "Link static DAQ modules" ON) option (ENABLE_VALGRIND "Only use if you are testing with valgrind" OFF) option (ENABLE_PPM "Disable packet/rule performance monitor" OFF) -option (ENABLE_PERFPROFILING "Disable preprocessor and rule performance profiling" OFF) option (ENABLE_LINUX_SMP_STATS "Enable statistics reporting through proc" OFF) option (ENABLE_PTHREAD "Disable pthread support" ON) option (ENABLE_DEBUG_MSGS "Enable debug printing options (bugreports and developers only)" OFF) diff --git a/config.cmake.h.in b/config.cmake.h.in index 1243cd000..e937d3135 100644 --- a/config.cmake.h.in +++ b/config.cmake.h.in @@ -57,9 +57,6 @@ /* build ppm manager for readback */ #cmakedefine PPM_TEST 1 -/* enable profiling */ -#cmakedefine PERF_PROFILING 1 - /* enable proc stats */ #cmakedefine LINUX_SMP 1 diff --git a/configure.ac b/configure.ac index 92c97b0cb..d7a26e02a 100644 --- a/configure.ac +++ b/configure.ac @@ -18,7 +18,7 @@ # if you add an AC_DEFINE() for a symbol that appears in an exported # header, you must also add that symbol to CPPFLAGS. This ensures that # external modules like those in examples can use pkg-config to get the -# same symbols Snort did. See PERF_PROFILING for an example. +# same symbols Snort did. See PPM for an example. #-------------------------------------------------------------------------- # initialization #-------------------------------------------------------------------------- @@ -350,17 +350,6 @@ if test "x$enable_ppm" = "xyes"; then AC_DEFINE(PPM_MGR, [1], [build ppm manager]) fi -AC_ARG_ENABLE(perf-profiling, - AC_HELP_STRING([--enable-perf-profiling],[enable module and rule performance profiling]), - enable_perf_profiling="$enableval", enable_perf_profiling="no") - -AM_CONDITIONAL(PERF_PROFILING, test "x$enable_perf_profiling" = "xyes") - -if test "x$enable_perf_profiling" = "xyes"; then - CPPFLAGS="$CPPFLAGS -DPERF_PROFILING" - AC_DEFINE(PERF_PROFILING, [1], [enable perf profiling]) -fi - AC_ARG_ENABLE(shell, AC_HELP_STRING([--enable-shell],[enable command line shell support]), enable_shell="$enableval", enable_shell="no") diff --git a/configure_cmake.sh b/configure_cmake.sh index 1c3d7dd35..e54b89b77 100755 --- a/configure_cmake.sh +++ b/configure_cmake.sh @@ -32,7 +32,6 @@ Optional Features: --disable-static-piglets do not include piglets in binary --enable-valgrind Only use if you are testing with valgrind. --enable-ppm Enable packet/rule performance monitor - --enable-perf-profiling Enable preprocessor and rule performance profiling --enable-shell enable command line shell support --enable-linux-smp-stats Enable statistics reporting through proc --enable-debug-msgs Enable debug printing options (bugreports and developers only) @@ -199,12 +198,6 @@ while [ $# -ne 0 ]; do --enable-ppm) append_cache_entry ENABLE_PPM BOOL true ;; - --disable-perf-profiling) - append_cache_entry ENABLE_PERFPROFILING BOOL false - ;; - --enable-perf-profiling) - append_cache_entry ENABLE_PERFPROFILING BOOL true - ;; --disable-linux-smp-stats) append_cache_entry ENABLE_LINUX_SMP_STATS BOOL false ;; diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt index aa0aae10b..5ec0481dc 100644 --- a/src/CMakeLists.txt +++ b/src/CMakeLists.txt @@ -79,10 +79,6 @@ if (ENABLE_PPM) add_subdirectory(ppm) endif (ENABLE_PPM) -if (ENABLE_PERFPROFILING) - set(PERFPROFILING_LIBRARIES profiler) -endif (ENABLE_PERFPROFILING) - # The main Snort executableRA add_executable( snort main.h @@ -133,7 +129,7 @@ target_link_libraries( snort framework time ${PPM_LIBRARIES} - ${PERFPROFILING_LIBRARIES} + profiler ips_actions events hash diff --git a/src/Makefile.am b/src/Makefile.am index 468d65d12..6de33c624 100644 --- a/src/Makefile.am +++ b/src/Makefile.am @@ -40,10 +40,6 @@ if PPM_MGR ppm_list = ppm/libppm.a endif -if PERF_PROFILING -profiler_list = profiler/libprofiler.a -endif - snort_LDFLAGS = -export-dynamic # order libs to avoid undefined symbols @@ -94,7 +90,7 @@ detection/libdetection.a \ framework/libframework.a \ time/libtime.a \ $(ppm_list) \ -$(profiler_list) \ +profiler/libprofiler.a \ actions/libips_actions.a \ events/libevents.a \ hash/libhash.a \ diff --git a/src/detection/detect.cc b/src/detection/detect.cc index 734f7a7e9..dc0bb6562 100644 --- a/src/detection/detect.cc +++ b/src/detection/detect.cc @@ -68,11 +68,9 @@ #define CHECK_SRC_PORT 0x08 #define CHECK_DST_PORT 0x10 -#ifdef PERF_PROFILING THREAD_LOCAL ProfileStats detectPerfStats; THREAD_LOCAL ProfileStats eventqPerfStats; THREAD_LOCAL ProfileStats rebuiltPacketPerfStats; -#endif THREAD_LOCAL int do_detect; THREAD_LOCAL int do_detect_content; diff --git a/src/detection/detect.h b/src/detection/detect.h index 5b7a75ee0..f054b4eca 100644 --- a/src/detection/detect.h +++ b/src/detection/detect.h @@ -34,15 +34,14 @@ #include "log/log.h" #include "events/event.h" +struct ProfileStats; + extern SO_PUBLIC THREAD_LOCAL int do_detect; extern SO_PUBLIC THREAD_LOCAL int do_detect_content; -#ifdef PERF_PROFILING -struct ProfileStats; extern THREAD_LOCAL ProfileStats eventqPerfStats; extern THREAD_LOCAL ProfileStats detectPerfStats; extern THREAD_LOCAL ProfileStats rebuiltPacketPerfStats; -#endif // main loop hooks void snort_ignore(Packet*); diff --git a/src/detection/detection_options.cc b/src/detection/detection_options.cc index c1df6a9b9..a1c587155 100644 --- a/src/detection/detection_options.cc +++ b/src/detection/detection_options.cc @@ -386,10 +386,8 @@ int detection_option_node_evaluate( dot_node_state_t* state = node->state + get_instance_id(); -#ifdef PERF_PROFILING auto& node_stats = *state; NODE_PERF_PROFILE(node_stats); -#endif int result = 0; int rval = DETECTION_OPTION_NO_MATCH; @@ -512,10 +510,8 @@ int detection_option_node_evaluate( if ( f_result ) { -#ifdef PERF_PROFILING - if (PROFILING_RULES) - otn->state[get_instance_id()].matches++; -#endif + otn->state[get_instance_id()].matches++; + if ( !eval_data->flowbit_noalert ) fpAddMatch((OTNX_MATCH_DATA*)pomd, pattern_size, otn); @@ -611,10 +607,10 @@ int detection_option_node_evaluate( { // bail if we exceeded time -#ifdef PERF_PROFILING + // FIXIT-M J this is unconditional (match or no match) since this + // block is guaranteed to return if ( result != DETECTION_OPTION_NO_MATCH ) NODE_PERF_PROFILE_STOP_MATCH(node_stats); -#endif state->last_check.result = result; return result; @@ -743,12 +739,10 @@ int detection_option_node_evaluate( else continue_loop = false; -#ifdef PERF_PROFILING // We're essentially checking this node again and it potentially // might match again - if ( continue_loop && PROFILING_RULES ) + if ( continue_loop ) state->checks++; -#endif loop_count++; } @@ -780,42 +774,42 @@ int detection_option_node_evaluate( return result; } -#ifdef PERF_PROFILING -typedef struct node_profile_stats +struct node_profile_stats { - uint64_t ticks; - uint64_t ticks_match; - uint64_t ticks_no_match; + // FIXIT-L J should be use factored out field from dot_node_state_t + hr_duration elapsed; + hr_duration elapsed_match; + hr_duration elapsed_no_match; uint64_t checks; uint64_t disables; -} node_profile_stats_t; +}; static void detection_option_node_update_otn_stats( detection_option_tree_node_t* node, - node_profile_stats_t* stats, uint64_t checks + node_profile_stats* stats, uint64_t checks #ifdef PPM_MGR , uint64_t disables #endif ) { int i; - node_profile_stats_t local_stats; /* cumulative stats for this node */ - node_profile_stats_t node_stats; /* sum of all instances */ + node_profile_stats local_stats; /* cumulative stats for this node */ + node_profile_stats node_stats; /* sum of all instances */ memset(&node_stats, 0, sizeof(node_stats)); for ( unsigned i = 0; i < get_instance_max(); ++i ) { - node_stats.ticks += node->state[i].ticks; - node_stats.ticks_match += node->state[i].ticks_match; - node_stats.ticks_no_match += node->state[i].ticks_no_match; + 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; } if (stats) { - local_stats.ticks = stats->ticks + node_stats.ticks; - local_stats.ticks_match = stats->ticks_match + node_stats.ticks_match; - local_stats.ticks_no_match = stats->ticks_no_match + node_stats.ticks_no_match; + 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 @@ -826,9 +820,9 @@ static void detection_option_node_update_otn_stats( } else { - local_stats.ticks = node_stats.ticks; - local_stats.ticks_match = node_stats.ticks_match; - local_stats.ticks_no_match = node_stats.ticks_no_match; + 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; #ifdef PPM_MGR local_stats.disables = disables; @@ -841,9 +835,9 @@ static void detection_option_node_update_otn_stats( // FIXIT-M should be sum of instances (only called from main thread) OptTreeNode* otn = (OptTreeNode*)node->option_data; OtnState* state = otn->state + get_instance_id(); - state->ticks += local_stats.ticks; - state->ticks_match += local_stats.ticks_match; - state->ticks_no_match += local_stats.ticks_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; #ifdef PPM_MGR @@ -904,7 +898,6 @@ void detection_option_tree_update_otn_stats(SFXHASH* doth) } } -#endif detection_option_tree_root_t* new_root() { diff --git a/src/detection/detection_options.h b/src/detection/detection_options.h index f0ad3b1d1..6d49a9e6c 100644 --- a/src/detection/detection_options.h +++ b/src/detection/detection_options.h @@ -38,6 +38,7 @@ #include #include "main/snort_types.h" #include "detection/rule_option_types.h" +#include "time/clock_defs.h" struct Packet; struct SFXHASH; @@ -57,31 +58,30 @@ struct dot_node_state_t char flowbit_failed; } last_check; -#ifdef PERF_PROFILING - uint64_t ticks; - uint64_t ticks_match; - uint64_t ticks_no_match; + // FIXIT-L J perf profiler stuff should be factored of the node state struct + hr_duration elapsed; + hr_duration elapsed_match; + hr_duration elapsed_no_match; uint64_t checks; uint64_t disables; -#endif + #ifdef PPM_MGR uint64_t ppm_disable_cnt; uint64_t ppm_enable_cnt; #endif -#ifdef PERF_PROFILING - void update(uint64_t elapsed, bool match) + // FIXIT-L J perf profiler stuff should be factored of the node state struct + void update(hr_duration delta, bool match) { - ticks += elapsed; + elapsed += delta;; if ( match ) - ticks_match += elapsed; + elapsed_match += delta; else - ticks_no_match += elapsed; + elapsed_no_match += delta; ++checks; } -#endif }; struct detection_option_tree_node_t @@ -138,9 +138,7 @@ void DetectionTreeHashTableFree(SFXHASH*); #ifdef DEBUG_OPTION_TREE void print_option_tree(detection_option_tree_node_t* node, int level); #endif -#ifdef PERF_PROFILING void detection_option_tree_update_otn_stats(SFXHASH*); -#endif detection_option_tree_root_t* new_root(); void free_detection_option_root(void** existing_tree); diff --git a/src/detection/fp_detect.cc b/src/detection/fp_detect.cc index ecfc29c24..6718002bc 100644 --- a/src/detection/fp_detect.cc +++ b/src/detection/fp_detect.cc @@ -77,12 +77,10 @@ #include "protocols/udp.h" #include "protocols/icmp4.h" -#ifdef PERF_PROFILING THREAD_LOCAL ProfileStats rulePerfStats; THREAD_LOCAL ProfileStats ruleRTNEvalPerfStats; THREAD_LOCAL ProfileStats ruleOTNEvalPerfStats; THREAD_LOCAL ProfileStats ruleNFPEvalPerfStats; -#endif THREAD_LOCAL uint64_t rule_eval_pkt_count = 0; @@ -246,9 +244,7 @@ int fpLogEvent(const RuleTreeNode* rtn, const OptTreeNode* otn, Packet* p) return 1; } -#ifdef PERF_PROFILING otn->state[get_instance_id()].alerts++; -#endif event_id++; action_execute((RuleType)action, p, otn, event_id); diff --git a/src/detection/fp_detect.h b/src/detection/fp_detect.h index 477bee25e..783fb084d 100644 --- a/src/detection/fp_detect.h +++ b/src/detection/fp_detect.h @@ -40,13 +40,12 @@ #define REBUILD_FLAGS (PKT_REBUILT_FRAG | PKT_REBUILT_STREAM) -#ifdef PERF_PROFILING struct ProfileStats; + extern THREAD_LOCAL ProfileStats rulePerfStats; extern THREAD_LOCAL ProfileStats ruleRTNEvalPerfStats; extern THREAD_LOCAL ProfileStats ruleOTNEvalPerfStats; extern THREAD_LOCAL ProfileStats ruleNFPEvalPerfStats; -#endif /* ** This is the only function that is needed to do an diff --git a/src/detection/treenodes.h b/src/detection/treenodes.h index eb77ca0c4..b4eef194c 100644 --- a/src/detection/treenodes.h +++ b/src/detection/treenodes.h @@ -30,6 +30,7 @@ #include "detection/signature.h" #include "detection/rule_option_types.h" #include "actions/actions.h" +#include "time/clock_defs.h" class IpsOption; struct Packet; @@ -56,15 +57,15 @@ struct OptFpList struct OtnState { // profiling -#ifdef PERF_PROFILING - uint64_t ticks; - uint64_t ticks_match; - uint64_t ticks_no_match; + // FIXIT-L J factor the profiling stuff out + hr_duration elapsed; + hr_duration elapsed_match; + hr_duration elapsed_no_match; + uint64_t checks; uint64_t matches; uint8_t noalerts; uint64_t alerts; -#endif // ppm uint64_t ppm_suspend_time; diff --git a/src/framework/mpse.cc b/src/framework/mpse.cc index e49eef7bc..b4459b7e2 100644 --- a/src/framework/mpse.cc +++ b/src/framework/mpse.cc @@ -32,9 +32,7 @@ using namespace std; // searches for the detection engine static THREAD_LOCAL uint64_t s_bcnt=0; -#ifdef PERF_PROFILING THREAD_LOCAL ProfileStats mpsePerfStats; -#endif //------------------------------------------------------------------------- // base stuff diff --git a/src/framework/mpse.h b/src/framework/mpse.h index 2f5e0da47..fb735f742 100644 --- a/src/framework/mpse.h +++ b/src/framework/mpse.h @@ -40,6 +40,7 @@ struct SnortConfig; struct MpseApi; +struct ProfileStats; class SO_PUBLIC Mpse { @@ -85,10 +86,7 @@ private: const MpseApi* api; }; -#ifdef PERF_PROFILING -struct ProfileStats; extern THREAD_LOCAL ProfileStats mpsePerfStats; -#endif typedef void (* MpseOptFunc)(SnortConfig*); typedef void (* MpseExeFunc)(); diff --git a/src/ips_options/ips_http.cc b/src/ips_options/ips_http.cc index 4bbbd0177..b29f2e3a9 100644 --- a/src/ips_options/ips_http.cc +++ b/src/ips_options/ips_http.cc @@ -74,8 +74,7 @@ static void opt_dtor(IpsOption* p) class HttpIpsOption : public IpsOption { public: - HttpIpsOption( - const char* s, PsIdx psi, CursorActionType c = CAT_SET_OTHER) : + HttpIpsOption(const char* s, PsIdx psi, CursorActionType c = CAT_SET_OTHER) : IpsOption(s), key(s), cat(c), idx(psi) {} CursorActionType get_cursor_type() const override diff --git a/src/main/modules.cc b/src/main/modules.cc index 3472ad517..bdd7ef09c 100644 --- a/src/main/modules.cc +++ b/src/main/modules.cc @@ -316,7 +316,6 @@ bool SearchEngineModule::set(const char*, Value& v, SnortConfig* sc) // profile module //------------------------------------------------------------------------- -#ifdef PERF_PROFILING static const Parameter profile_rule_params[] = { { "count", Parameter::PT_INT, "-1:", "-1", @@ -401,7 +400,6 @@ bool ProfileModule::set(const char* fqn, Value& v, SnortConfig* sc) return true; } -#endif //------------------------------------------------------------------------- // classification module @@ -2004,9 +2002,7 @@ void module_init() ModuleManager::add_module(new DetectionModule); ModuleManager::add_module(new PacketsModule); ModuleManager::add_module(new ProcessModule); -#ifdef PERF_PROFILING ModuleManager::add_module(new ProfileModule); -#endif ModuleManager::add_module(new ReferencesModule); ModuleManager::add_module(new RuleStateModule); ModuleManager::add_module(new SearchEngineModule); diff --git a/src/main/snort.cc b/src/main/snort.cc index de5ab7089..3efc19f63 100644 --- a/src/main/snort.cc +++ b/src/main/snort.cc @@ -124,7 +124,6 @@ static THREAD_LOCAL Packet* s_packet = nullptr; // FIXIT-M move these to appropriate modules //------------------------------------------------------------------------- -#ifdef PERF_PROFILING static ProfileStats* get_profile(const char* key) { if ( !strcmp(key, "detect") ) @@ -163,11 +162,8 @@ static ProfileStats* get_profile(const char* key) return nullptr; } -#endif - static void register_profiles() { -#ifdef PERF_PROFILING PerfProfilerManager::register_module("detect", nullptr, get_profile); PerfProfilerManager::register_module("mpse", "detect", get_profile); PerfProfilerManager::register_module("rebuilt_packet", "detect", get_profile); @@ -179,7 +175,6 @@ static void register_profiles() PerfProfilerManager::register_module("eventq", nullptr, get_profile); PerfProfilerManager::register_module("total", nullptr, get_profile); PerfProfilerManager::register_module("daq_meta", nullptr, get_profile); -#endif } //------------------------------------------------------------------------- @@ -672,9 +667,7 @@ void Snort::thread_term() DAQ_Delete(); -#ifdef PERF_PROFILING PerfProfilerManager::consolidate_stats(); -#endif otnx_match_data_term(); detection_filter_term(); diff --git a/src/main/snort_config.cc b/src/main/snort_config.cc index 56d7da1fd..740c1a8a8 100644 --- a/src/main/snort_config.cc +++ b/src/main/snort_config.cc @@ -170,10 +170,8 @@ SnortConfig::SnortConfig() num_slots = get_instance_max(); state = (SnortState*)SnortAlloc(sizeof(SnortState)*num_slots); -#ifdef PERF_PROFILING profile_rules = (ProfileConfig*)SnortAlloc(sizeof(*profile_rules)); profile_modules = (ProfileConfig*)SnortAlloc(sizeof(*profile_modules)); -#endif #ifdef PPM_MGR ppm_cfg = (ppm_cfg_t*)SnortAlloc(sizeof(*ppm_cfg)); diff --git a/src/main/snort_config.h b/src/main/snort_config.h index 92a9ebe0a..f362705a4 100644 --- a/src/main/snort_config.h +++ b/src/main/snort_config.h @@ -543,13 +543,13 @@ public: static long int get_pcre_match_limit_recursion() { return snort_conf->pcre_match_limit_recursion; } -#ifdef PERF_PROFILING + // FIXIT-H J No longer necessary, since this is always true + // or, we make it conditional on definition of table in lua static bool get_profile_modules() { return snort_conf->profile_modules; } static bool get_profile_rules() { return snort_conf->profile_rules; } -#endif static long int get_tagged_packet_limit() { return snort_conf->tagged_packet_limit; } diff --git a/src/managers/codec_manager.h b/src/managers/codec_manager.h index 6ce4e57ed..2f5daa009 100644 --- a/src/managers/codec_manager.h +++ b/src/managers/codec_manager.h @@ -44,13 +44,11 @@ struct CodecApi; class Codec; class Module; class PacketManager; +struct ProfileStats; //------------------------------------------------------------------------- -#ifdef PERF_PROFILING -struct ProfileStats; extern THREAD_LOCAL ProfileStats decodePerfStats; -#endif static const uint16_t max_protocol_id = 65535; diff --git a/src/managers/module_manager.cc b/src/managers/module_manager.cc index b53ec2cc0..ae42f53fc 100644 --- a/src/managers/module_manager.cc +++ b/src/managers/module_manager.cc @@ -784,9 +784,7 @@ void ModuleManager::add_module(Module* m, const BaseApi* b) ModHook* mh = new ModHook(m, b); s_modules.push_back(mh); -#ifdef PERF_PROFILING PerfProfilerManager::register_module(m); -#endif } Module* ModuleManager::get_module(const char* s) diff --git a/src/ppm/ppm.h b/src/ppm/ppm.h index 246150656..1f5e78b1b 100644 --- a/src/ppm/ppm.h +++ b/src/ppm/ppm.h @@ -29,6 +29,7 @@ #include "main/thread.h" #include "detection/detection_options.h" +#include "time/cpuclock.h" typedef uint64_t PPM_TICKS; typedef uint64_t PPM_USECS; diff --git a/src/profiler/CMakeLists.txt b/src/profiler/CMakeLists.txt index b53ced4eb..9b3113ddf 100644 --- a/src/profiler/CMakeLists.txt +++ b/src/profiler/CMakeLists.txt @@ -1,14 +1,10 @@ -set ( PROFILER_SOURCES profiler.cc ) set ( PROFILER_INCLUDES profiler.h ) +set ( PROFILER_SOURCES profiler.cc ) -if ( ENABLE_PERFPROFILING ) - - add_library ( profiler STATIC - ${PROFILER_SOURCES} - ${PROFILER_INCLUDES} - ) - -endif ( ENABLE_PERFPROFILING ) +add_library ( profiler STATIC + ${PROFILER_SOURCES} + ${PROFILER_INCLUDES} +) install (FILES ${PROFILER_INCLUDES} DESTINATION "${INCLUDE_INSTALL_PATH}/profiler" diff --git a/src/profiler/Makefile.am b/src/profiler/Makefile.am index d41d2f60e..e491fc115 100644 --- a/src/profiler/Makefile.am +++ b/src/profiler/Makefile.am @@ -1,13 +1,9 @@ -if PERF_PROFILING noinst_LIBRARIES = libprofiler.a -endif x_includedir = $(pkgincludedir)/profiler x_include_HEADERS = profiler.h -if PERF_PROFILING libprofiler_a_SOURCES = \ profiler.cc \ profiler.h -endif diff --git a/src/profiler/profiler.cc b/src/profiler/profiler.cc index 2dbf79a19..5146be594 100644 --- a/src/profiler/profiler.cc +++ b/src/profiler/profiler.cc @@ -102,22 +102,46 @@ public: std::set children; private: - ProfileStats stats { 0, 0 }; + ProfileStats stats; bool totalled = false; ModStatsFunctor getter; }; struct ModEntry { + using microseconds = std::chrono::microseconds; + std::string name; ModStatsNode* node; ProfileStats stats; - - double ticks_per_check; - double pct_of_parent; + ProfileStats caller_stats; std::vector entries; + + microseconds us() const + { + using std::chrono::duration_cast; + return duration_cast(stats.elapsed); + } + + double avg_check() const + { return stats.checks? double(us().count()) / double(stats.checks) : 0.0; } + + double pct_of(const ProfileStats& other) const + { + using std::chrono::duration_cast; + + auto other_us = duration_cast(other.elapsed).count(); + if ( other_us ) + return double(us().count()) / double(other_us) * 100.0; + + return 0.0; + } + + double pct_of_caller() const + { return pct_of(caller_stats); } + ModEntry(ModStatsNode*, const ProfileStats&); }; @@ -144,13 +168,41 @@ public: struct RuleEntry { - SigInfo sig_info; + using microseconds = std::chrono::microseconds; + SigInfo sig_info; OtnState state; - double ticks_per_check = 0.0; - double ticks_per_match = 0.0; - double ticks_per_nomatch = 0.0; + microseconds us() const + { + using std::chrono::duration_cast; + return duration_cast(state.elapsed); + } + + microseconds us_match() const + { + using std::chrono::duration_cast; + return duration_cast(state.elapsed_match); + } + + microseconds us_no_match() const + { + using std::chrono::duration_cast; + return duration_cast(state.elapsed_no_match); + } + + template + double us_per(microseconds t, T v) const + { return v ? double(t.count()) / double(v) : 0.0; } + + double avg_match() const + { return us_per(us_match(), state.matches); } + + double avg_no_match() const + { return us_per(us_no_match(), state.checks - state.matches); } + + double avg_check() const + { return us_per(us(), state.checks); } RuleEntry(const SigInfo&, const OtnState&); }; @@ -172,9 +224,9 @@ static ModStatsTree s_module_nodes; static inline OtnState& operator+=(OtnState& lhs, const OtnState& rhs) { - lhs.ticks += rhs.ticks; - lhs.ticks_match += rhs.ticks_match; - lhs.ticks_no_match += rhs.ticks_no_match; + lhs.elapsed += rhs.elapsed; + lhs.elapsed_match += rhs.elapsed_match; + lhs.elapsed_no_match += rhs.elapsed_no_match; lhs.checks += rhs.checks; lhs.matches += rhs.matches; lhs.noalerts += rhs.noalerts; @@ -182,15 +234,6 @@ static inline OtnState& operator+=(OtnState& lhs, const OtnState& rhs) return lhs; } -static double get_ticks_per_us() -{ - static double ticks_per_us = 0.0; - if ( ticks_per_us == 0.0 ) - ticks_per_us = get_ticks_per_usec(); - - return ticks_per_us; -} - template static void add_module(std::string name, const char* pname, T v) { @@ -235,14 +278,15 @@ static void get_mod_entries(ModEntry& parent, ModEntrySortFunc* sort_fn, int cou static void print_mod_entry(int layer, int num, const ModEntry& root, const ModEntry& cur) { unsigned indent = 6 - (5 - layer) + 2; + LogMessage("%*d%*s%*d" FMTu64("*") FMTu64("*") "%*.2f%*.2f%*.2f\n", indent, num, 28 - indent, cur.name.c_str(), 6, layer, 11, cur.stats.checks, - 20, uint64_t((double(cur.stats.ticks) / get_ticks_per_us())), - 11, cur.ticks_per_check / get_ticks_per_us(), - 10, cur.pct_of_parent, - 10, double(cur.stats.ticks) / double(root.stats.ticks) * 100.0); + 20, cur.us().count(), + 11, cur.avg_check(), + 10, cur.pct_of_caller(), + 10, cur.pct_of(root.stats)); int num2 = 0; for ( const auto& entry : cur.entries ) @@ -284,15 +328,16 @@ static void print_mod_entries(ModEntry& root, int count) for ( const auto& entry : root.entries ) print_mod_entry(0, ++num, root, entry); - int indent = root.name.size() + 1; + unsigned indent = root.name.size() + 1; + LogMessage("%*s%*s%*d" FMTu64("*") FMTu64("*") "%*.2f%*.2f%*.2f\n", indent, root.name.c_str(), 28 - indent, root.name.c_str(), 6, 0, 11, root.stats.checks, - 20, uint64_t(double(root.stats.ticks) / get_ticks_per_us()), - 11, root.ticks_per_check / get_ticks_per_us(), - 10, root.pct_of_parent, - 10, root.pct_of_parent); + 20, root.us().count(), + 11, root.avg_check(), + 10, root.pct_of_caller(), + 10, root.pct_of_caller()); } bool get_mod_sort_function(ProfileSort sort_mode, ModEntrySortFunc& sort_fn) @@ -306,12 +351,12 @@ bool get_mod_sort_function(ProfileSort sort_mode, ModEntrySortFunc& sort_fn) case PROFILE_SORT_TOTAL_TICKS: sort_fn = [](const ModEntry& a, const ModEntry& b) -> bool - { return a.stats.ticks > b.stats.ticks; }; + { return a.stats.elapsed > b.stats.elapsed; }; break; case PROFILE_SORT_AVG_TICKS: sort_fn = [](const ModEntry& a, const ModEntry& b) -> bool - { return a.ticks_per_check > b.ticks_per_check; }; + { return a.avg_check() > b.avg_check(); }; break; default: @@ -350,22 +395,22 @@ static void sort_rule_stats(std::vector& entries, ProfileSort sort_mo case PROFILE_SORT_AVG_TICKS_PER_MATCH: sort_fn = [](const RuleEntry& a, const RuleEntry& b) - { return a.ticks_per_match >= b.ticks_per_match; }; + { return a.avg_match() >= b.avg_match(); }; break; case PROFILE_SORT_AVG_TICKS_PER_NOMATCH: sort_fn = [](const RuleEntry& a, const RuleEntry& b) - { return a.ticks_per_nomatch >= b.ticks_per_nomatch; }; + { return a.avg_no_match() >= b.avg_no_match(); }; break; case PROFILE_SORT_TOTAL_TICKS: sort_fn = [](const RuleEntry& a, const RuleEntry& b) - { return a.state.ticks >= b.state.ticks; }; + { return a.state.elapsed >= b.state.elapsed; }; break; case PROFILE_SORT_AVG_TICKS: sort_fn = [](const RuleEntry& a, const RuleEntry& b) - { return a.ticks_per_check >= b.ticks_per_check; }; + { return a.avg_check() >= b.avg_check(); }; break; default: @@ -392,7 +437,7 @@ static void get_rule_stats_entries(std::vector& entries) consolidate_otn_states(states); - if ( !state.checks || !state.ticks ) + if ( !state.checks || (state.elapsed == hr_duration::zero()) ) continue; entries.emplace_back(otn->sigInfo, state); @@ -471,10 +516,10 @@ static void print_rule_stats(std::vector& entries, int num) 11, entry.state.checks, 10, entry.state.matches, 10, entry.state.alerts, - 20, uint64_t(double(entry.state.ticks) / get_ticks_per_us()), - 11, entry.ticks_per_check / get_ticks_per_us(), - 11, entry.ticks_per_match / get_ticks_per_us(), - 13, entry.ticks_per_nomatch / get_ticks_per_us() + 20, entry.us().count(), + 11, entry.avg_check(), + 11, entry.avg_match(), + 13, entry.avg_no_match() #ifdef PPM_MGR , 11, entry.state.ppm_disable_cnt #endif @@ -525,36 +570,12 @@ void ModStatsNode::accumulate() } ModEntry::ModEntry(ModStatsNode* node, const ProfileStats& caller_stats) : - name(node->name), node(node), stats(node->get_total()) -{ - assert(stats.ticks >= stats.checks); - assert(caller_stats.ticks >= stats.ticks); - - if ( stats.checks == 0.0 ) - ticks_per_check = 0.0; - else - ticks_per_check = double(stats.ticks) / double(stats.checks); - - if ( caller_stats.ticks == 0.0 ) - pct_of_parent = 0.0; - else - pct_of_parent = double(stats.ticks) / double(caller_stats.ticks) * 100.0; -} + name(node->name), node(node), stats(node->get_total()), caller_stats(caller_stats) +{ assert(caller_stats.elapsed >= stats.elapsed); } RuleEntry::RuleEntry(const SigInfo& si, const OtnState& os) : sig_info(si), state(os) -{ - ticks_per_check = double(state.ticks) / double(state.checks); - - state.checks = std::max(state.checks, state.matches); - - if ( state.matches ) - ticks_per_match = double(state.ticks_match) / double(state.matches); - - // can safely replace != with > - if ( state.checks != state.matches ) - ticks_per_nomatch = double(state.ticks_no_match) / double(state.checks - state.matches); -} +{ state.checks = std::max(state.checks, state.matches); } // ----------------------------------------------------------------------------- // public API @@ -682,6 +703,9 @@ void PerfProfilerManager::reset_all_stats() #ifdef UNIT_TEST +constexpr hr_duration operator "" _dur(unsigned long long v) +{ return hr_duration(v); } + struct ProfilePauseObserver { void start() @@ -701,18 +725,18 @@ struct ProfilePauseObserver TEST_CASE( "profile stats", "[profiler]" ) { - ProfileStats stats = { 1, 2 }; + ProfileStats stats = { 1_ticks , 2 }; SECTION( "operator bool()" ) { CHECK( stats ); - stats = { 0, 0 }; + stats = { 0_dur, 0 }; CHECK_FALSE( stats ); } SECTION( "operator==" ) { - ProfileStats compare = { 0, 0 }; + ProfileStats compare = { 0_ticks, 0 }; CHECK_FALSE( stats == compare ); compare = stats; CHECK( stats == compare ); @@ -726,8 +750,8 @@ TEST_CASE( "profile stats", "[profiler]" ) SECTION( "operator+=" ) { - ProfileStats inc = { 3, 4 }; - ProfileStats expected = { stats.ticks + inc.ticks, stats.checks + inc.checks }; + ProfileStats inc = { 3_ticks, 4 }; + ProfileStats expected = { stats.elapsed + inc.elapsed, stats.checks + inc.checks }; stats += inc; CHECK( stats == expected ); @@ -739,7 +763,7 @@ TEST_CASE( "stopwatch", "[profiler]" ) Stopwatch sw; REQUIRE_FALSE( sw.alive() ); - REQUIRE( sw.get() == 0 ); + REQUIRE( sw.get() == 0_ticks ); SECTION( "start" ) { @@ -752,7 +776,7 @@ TEST_CASE( "stopwatch", "[profiler]" ) SECTION( "running elapsed time should be non-zero" ) { - CHECK( sw.get() > 0 ); + CHECK( sw.get() > 0_ticks ); } SECTION( "start on running clock has no effect" ) @@ -797,7 +821,7 @@ TEST_CASE( "stopwatch", "[profiler]" ) { sw.reset(); CHECK_FALSE( sw.alive() ); - CHECK( sw.get() == 0 ); + CHECK( sw.get() == 0_ticks ); } SECTION( "reset on stopped clock" ) @@ -805,7 +829,7 @@ TEST_CASE( "stopwatch", "[profiler]" ) sw.stop(); sw.reset(); CHECK_FALSE( sw.alive() ); - CHECK( sw.get() == 0 ); + CHECK( sw.get() == 0_ticks ); } } @@ -816,7 +840,7 @@ TEST_CASE( "stopwatch", "[profiler]" ) { sw.cancel(); CHECK_FALSE( sw.alive() ); - CHECK( sw.get() == 0 ); + CHECK( sw.get() == 0_ticks ); } SECTION( "cancel on stopped clock that has lap time" ) @@ -836,7 +860,7 @@ TEST_CASE( "perf profiler base", "[profiler]" ) SECTION( "profiler is started on instantiation" ) { PerfProfilerBase prof; - CHECK( prof.get_delta() > 0 ); + CHECK( prof.get_delta() > 0_ticks ); } SECTION( "profiler evaluates to true" ) @@ -848,9 +872,9 @@ TEST_CASE( "perf profiler base", "[profiler]" ) TEST_CASE( "perf profiler", "[profiler]" ) { - ProfileStats stats = { 0, 0 }; + ProfileStats stats = { 0_ticks, 0 }; - REQUIRE( stats.ticks == 0 ); + REQUIRE( stats.elapsed == 0_ticks ); REQUIRE( stats.checks == 0 ); SECTION( "going out of scope causes profiler to update stats" ) @@ -859,7 +883,7 @@ TEST_CASE( "perf profiler", "[profiler]" ) PerfProfiler prof(stats); } - CHECK( stats.ticks > 0 ); + CHECK( stats.elapsed > 0_ticks ); CHECK( stats.checks == 1 ); } @@ -870,7 +894,7 @@ TEST_CASE( "perf profiler", "[profiler]" ) ProfileStats saved = stats; prof.stop(); - CHECK( saved.ticks == stats.ticks ); + CHECK( saved.elapsed == stats.elapsed ); CHECK( saved.checks == stats.checks ); } @@ -880,7 +904,7 @@ TEST_CASE( "perf profiler", "[profiler]" ) prof.pause(); prof.stop(); - CHECK( stats.ticks > 0 ); + CHECK( stats.elapsed > 0_ticks ); CHECK( stats.checks == 1 ); } @@ -890,12 +914,12 @@ TEST_CASE( "perf profiler", "[profiler]" ) prof.pause(); prof.start(); - CHECK( stats.ticks == 0 ); + CHECK( stats.elapsed == 0_ticks ); CHECK( stats.checks == 0 ); prof.stop(); - CHECK( stats.ticks > 0 ); + CHECK( stats.elapsed > 0_ticks ); CHECK( stats.checks == 1 ); } @@ -910,7 +934,7 @@ TEST_CASE( "perf profiler", "[profiler]" ) catch( int& ) { } - CHECK( stats.ticks > 0 ); + CHECK( stats.elapsed > 0_ticks ); CHECK( stats.checks == 1 ); } } @@ -926,12 +950,12 @@ TEST_CASE( "node perf profiler", "[profiler]" ) NodePerfProfiler prof(stats); } - CHECK( stats.ticks > 0 ); + CHECK( stats.elapsed > 0_ticks ); CHECK( stats.checks == 1 ); SECTION( "evaluates to NO MATCH by default" ) { - CHECK( stats.ticks_no_match > 0 ); + CHECK( stats.elapsed_no_match > 0_ticks ); } } @@ -942,13 +966,13 @@ TEST_CASE( "node perf profiler", "[profiler]" ) dot_node_state_t saved = stats; prof.stop(true); - CHECK( saved.ticks == stats.ticks ); + CHECK( saved.elapsed == stats.elapsed ); CHECK( saved.checks == stats.checks ); SECTION( "only one of match or no match is updated" ) { - CHECK( stats.ticks_no_match > 0 ); - CHECK( stats.ticks_match == 0 ); + CHECK( stats.elapsed_no_match > 0_ticks ); + CHECK( stats.elapsed_match == 0_ticks ); } } @@ -958,7 +982,7 @@ TEST_CASE( "node perf profiler", "[profiler]" ) prof.pause(); prof.stop(false); - CHECK( stats.ticks > 0 ); + CHECK( stats.elapsed > 0_ticks ); CHECK( stats.checks == 1 ); } @@ -968,12 +992,12 @@ TEST_CASE( "node perf profiler", "[profiler]" ) prof.pause(); prof.start(); - CHECK( stats.ticks == 0 ); + CHECK( stats.elapsed == 0_ticks ); CHECK( stats.checks == 0 ); prof.stop(false); - CHECK( stats.ticks > 0 ); + CHECK( stats.elapsed > 0_ticks ); CHECK( stats.checks == 1 ); } @@ -982,11 +1006,11 @@ TEST_CASE( "node perf profiler", "[profiler]" ) NodePerfProfiler prof(stats); prof.stop(true); - CHECK( stats.ticks_match > 0 ); + CHECK( stats.elapsed_match > 0_ticks ); SECTION( "and doesn't update NO MATCH" ) { - CHECK( stats.ticks_no_match == 0 ); + CHECK( stats.elapsed_no_match == 0_ticks ); } } @@ -1001,7 +1025,7 @@ TEST_CASE( "node perf profiler", "[profiler]" ) catch( int& ) { } - CHECK( stats.ticks > 0 ); + CHECK( stats.elapsed > 0_ticks ); CHECK( stats.checks == 1 ); } } @@ -1146,7 +1170,7 @@ TEST_CASE( "mod stats node", "[profiler]" ) SECTION( "copy-constructed node retains stats" ) { - mod_stats_test_stats = { 1, 2 }; + mod_stats_test_stats = { 1_ticks, 2 }; node.set(mock_get_profile_func); node.accumulate(); auto orig_stats = node.get_total(); @@ -1159,7 +1183,7 @@ TEST_CASE( "mod stats node", "[profiler]" ) SECTION( "accumulate() and get_total() correctly adds stats" ) { - mod_stats_test_stats = { 1, 2 }; + mod_stats_test_stats = { 1_ticks, 2 }; ProfileStats expected = mod_stats_test_stats; expected += mod_stats_test_stats; @@ -1191,8 +1215,8 @@ TEST_CASE( "mod stats tree", "[profiler]" ) TEST_CASE( "mod entry", "[profiler]" ) { - ProfileStats stats = { 2, 1 }; - ProfileStats caller_stats = { 20, 10 }; + ProfileStats stats = { 200_ticks, 1 }; + ProfileStats caller_stats = { 2000_ticks, 10 }; MockProfilerModule m(&stats); ModStatsNode node("a"); @@ -1205,21 +1229,29 @@ TEST_CASE( "mod entry", "[profiler]" ) SECTION( "ctor calculates percentages" ) { - CHECK( entry.ticks_per_check == 2.0 ); - CHECK( entry.pct_of_parent == 2.0 / 20.0 * 100.0 ); + using std::chrono::duration_cast; + using std::chrono::microseconds; + + const auto exp_avg_check = double(duration_cast(200_ticks).count()); + const auto exp_pct = double(duration_cast(200_ticks).count()) / + double(duration_cast(2000_ticks).count()) * 100.0; + + + CHECK( entry.avg_check() == exp_avg_check ); + CHECK( entry.pct_of_caller() == exp_pct ); } SECTION( "zeros" ) { - stats = { 0, 0 }; - caller_stats = { 0, 0 }; + stats = { 0_ticks, 0 }; + caller_stats = { 0_ticks, 0 }; node.reset(); node.accumulate(); ModEntry entry(&node, caller_stats); - CHECK( entry.ticks_per_check == 0.0 ); - CHECK( entry.pct_of_parent == 0.0 ); + CHECK( entry.avg_check() == 0.0 ); + CHECK( entry.pct_of_caller() == 0.0 ); } } diff --git a/src/profiler/profiler.h b/src/profiler/profiler.h index 63ae33049..45cf0dbba 100644 --- a/src/profiler/profiler.h +++ b/src/profiler/profiler.h @@ -30,7 +30,7 @@ #include "main/snort_types.h" #include "main/thread.h" -#include "time/cpuclock.h" +#include "time/stopwatch.h" class Module; @@ -48,105 +48,31 @@ enum ProfileSort struct ProfileStats { - uint64_t ticks; - uint64_t checks; + hr_duration elapsed = 0_ticks; + uint64_t checks = 0; - void update(uint64_t elapsed) - { ++checks; ticks += elapsed; } + void update(hr_duration delta) + { ++checks; elapsed += delta; } void reset() - { ticks = 0; checks = 0; } + { elapsed = 0_ticks; checks = 0; } bool operator==(const ProfileStats& rhs) - { return ticks == rhs.ticks && checks == rhs.checks; } + { return elapsed == rhs.elapsed && checks == rhs.checks; } operator bool() const - { return ticks || checks; } + { return (elapsed > hr_duration::zero()) || checks; } ProfileStats& operator+=(const ProfileStats& rhs) { - ticks += rhs.ticks; + elapsed += rhs.elapsed; checks += rhs.checks; return *this; } -}; - -struct RuleProfileStats : ProfileStats -{ - uint64_t ticks_match; - - void update(uint64_t elapsed, bool match) - { - ProfileStats::update(elapsed); - if ( match ) - ticks_match += elapsed; - } - - void reset() - { ProfileStats::reset(); ticks_match = 0; } - - RuleProfileStats& operator+=(const RuleProfileStats& o) - { - ticks += o.ticks; - checks += o.checks; - ticks_match += o.ticks_match; - return *this; - } -}; - -// FIXIT-L should go in its own module -class Stopwatch -{ -public: - Stopwatch() : - elapsed { 0 }, running { false } { } - - void start() - { - if ( running ) - return; - - get_clockticks(ticks_start); - running = true; - } - void stop() - { - if ( !running ) - return; - - elapsed += get_delta(); - running = false; - } - - uint64_t get() const - { - if ( running ) - return elapsed + get_delta(); - - return elapsed; - } - - bool alive() const - { return running; } - - void reset() - { running = false; elapsed = 0; } - - void cancel() - { running = false; } - -private: - uint64_t get_delta() const - { - uint64_t ticks_stop; - get_clockticks(ticks_stop); - return ticks_stop - ticks_start; - } - - uint64_t elapsed; - bool running; - uint64_t ticks_start; + ProfileStats() = default; + ProfileStats(hr_duration elapsed, uint64_t checks) : + elapsed(elapsed), checks(checks) { } }; class PerfProfilerBase @@ -165,7 +91,7 @@ public: operator bool() const { return true; } - uint64_t get_delta() const + hr_duration get_delta() const { return sw.get(); } private: @@ -244,15 +170,6 @@ struct ProfilerPause // thread local access method using get_profile_func = ProfileStats* (*)(const char*); -#ifdef PERF_PROFILING -#ifndef PROFILING_MODULES -#define PROFILING_MODULES SnortConfig::get_profile_modules() -#endif - -#ifndef PROFILING_RULES -#define PROFILING_RULES SnortConfig::get_profile_rules() -#endif - #define PERF_PROFILER_NAME(stats) \ stats ## _perf_profiler @@ -320,20 +237,5 @@ struct ProfileConfig extern THREAD_LOCAL ProfileStats totalPerfStats; extern THREAD_LOCAL ProfileStats metaPerfStats; -#else -#define PERF_PROFILER_NAME(stats) -#define PERF_PAUSE_NAME(stats) -#define PERF_PROFILE(stats) -#define PERF_PROFILE_THREAD_LOCAL(stats, idx) -#define PERF_PROFILE_BLOCK(stats) -#define PERF_PROFILE_THREAD_LOCAL_BLOCK(stats, idx) -#define NODE_PERF_PROFILE(stats) -#define NODE_PERF_PROFILE_BLOCK(stats) -#define NODE_PERF_PROFILE_STOP(stats, match) -#define NODE_PERF_PROFILE_STOP_MATCH(stats) -#define NODE_PERF_PROFILE_STOP_NO_MATCH(stats) -#define PERF_PAUSE_BLOCK(stats) - -#endif // PERF_PROFILING #endif diff --git a/src/protocols/packet_manager.cc b/src/protocols/packet_manager.cc index 00cea6f04..d6e004944 100644 --- a/src/protocols/packet_manager.cc +++ b/src/protocols/packet_manager.cc @@ -50,9 +50,7 @@ #include "packet_io/sfdaq.h" #include "packet_io/active.h" -#ifdef PERF_PROFILING THREAD_LOCAL ProfileStats decodePerfStats; -#endif // Decoding statistics diff --git a/src/service_inspectors/ftp_telnet/ft_main.cc b/src/service_inspectors/ftp_telnet/ft_main.cc index bf3a5136b..d87642d0f 100644 --- a/src/service_inspectors/ftp_telnet/ft_main.cc +++ b/src/service_inspectors/ftp_telnet/ft_main.cc @@ -68,7 +68,6 @@ #include "framework/data_bus.h" #include "sfip/sf_ip.h" -#ifdef PERF_PROFILING // FIXIT-M ftp, http, etc. should not be calling snort_detect() static THREAD_LOCAL int ftppDetectCalled = 0; static THREAD_LOCAL ProfileStats ftppDetectPerfStats; @@ -77,15 +76,13 @@ void ft_update_perf(ProfileStats& stats) { if (ftppDetectCalled) { - stats.ticks -= ftppDetectPerfStats.ticks; - /* And Reset ticks to 0 */ - ftppDetectPerfStats.ticks = 0; + stats.elapsed -= ftppDetectPerfStats.elapsed; + ftppDetectPerfStats.reset(); + // FIXIT-L J should be a bool ftppDetectCalled = 0; } } -#endif - void CleanupFTPCMDConf(void* ftpCmd) { FTP_CMD_CONF* FTPCmd = (FTP_CMD_CONF*)ftpCmd; @@ -262,8 +259,6 @@ void do_detection(Packet* p) get_data_bus().publish(PACKET_EVENT, p); DisableInspection(p); -#ifdef PERF_PROFILING ftppDetectCalled = 1; -#endif } diff --git a/src/service_inspectors/ftp_telnet/ft_main.h b/src/service_inspectors/ftp_telnet/ft_main.h index 0f82c9b18..aadf0d6e3 100644 --- a/src/service_inspectors/ftp_telnet/ft_main.h +++ b/src/service_inspectors/ftp_telnet/ft_main.h @@ -42,6 +42,8 @@ #define BUF_SIZE 1024 +struct ProfileStats; + extern int16_t ftp_data_app_id; void do_detection(Packet*); @@ -57,10 +59,7 @@ int FTPCheckConfigs(SnortConfig*, void*); FTP_CLIENT_PROTO_CONF* get_ftp_client(Packet*); FTP_SERVER_PROTO_CONF* get_ftp_server(Packet*); -#ifdef PERF_PROFILING -struct ProfileStats; void ft_update_perf(ProfileStats&); -#endif #endif diff --git a/src/service_inspectors/ftp_telnet/ftp.cc b/src/service_inspectors/ftp_telnet/ftp.cc index b3896fde7..a5cec6843 100644 --- a/src/service_inspectors/ftp_telnet/ftp.cc +++ b/src/service_inspectors/ftp_telnet/ftp.cc @@ -130,9 +130,7 @@ static int SnortFTP( do_detection(p); } -#ifdef PERF_PROFILING ft_update_perf(ftpPerfStats); -#endif return ret; } diff --git a/src/service_inspectors/ftp_telnet/telnet.cc b/src/service_inspectors/ftp_telnet/telnet.cc index a4dc5e00c..1cf7c0c35 100644 --- a/src/service_inspectors/ftp_telnet/telnet.cc +++ b/src/service_inspectors/ftp_telnet/telnet.cc @@ -97,9 +97,7 @@ static int SnortTelnet(TELNET_PROTO_CONF* telnet_config, TELNET_SESSION* Telnets else do_detection(p); -#ifdef PERF_PROFILING ft_update_perf(telnetPerfStats); -#endif return FTPP_SUCCESS; } diff --git a/src/service_inspectors/http_inspect/hi_main.cc b/src/service_inspectors/http_inspect/hi_main.cc index cb9e3ae78..61fdd72b7 100644 --- a/src/service_inspectors/http_inspect/hi_main.cc +++ b/src/service_inspectors/http_inspect/hi_main.cc @@ -613,9 +613,8 @@ int HttpInspectMain(HTTPINSPECT_CONF* conf, Packet* p) PERF_PROFILE_BLOCK(hiDetectPerfStats) { get_data_bus().publish(PACKET_EVENT, p); -#ifdef PERF_PROFILING + // FIXIT-L J should be a bool hiDetectCalled = 1; -#endif } return 0; @@ -1108,9 +1107,7 @@ int HttpInspectMain(HTTPINSPECT_CONF* conf, Packet* p) PERF_PROFILE_BLOCK(hiDetectPerfStats) { snort_detect(p); -#ifdef PERF_PROFILING hiDetectCalled = 1; -#endif } /* diff --git a/src/service_inspectors/http_inspect/hi_main.h b/src/service_inspectors/http_inspect/hi_main.h index 3e6ee4345..089635b9e 100644 --- a/src/service_inspectors/http_inspect/hi_main.h +++ b/src/service_inspectors/http_inspect/hi_main.h @@ -49,6 +49,8 @@ #define DEFLATE_WBITS 15 #define GZIP_WBITS 31 +struct ProfileStats; + enum HTTP_BUFFER { HTTP_BUFFER_NONE, @@ -76,11 +78,8 @@ extern SO_PUBLIC THREAD_LOCAL uint32_t http_mask; extern SO_PUBLIC THREAD_LOCAL HttpBuffer http_buffer[HTTP_BUFFER_MAX]; extern THREAD_LOCAL DataBuffer HttpDecodeBuf; -#ifdef PERF_PROFILING -struct ProfileStats; extern THREAD_LOCAL ProfileStats hiDetectPerfStats; extern THREAD_LOCAL int hiDetectCalled; -#endif typedef enum _HttpRespCompressType { diff --git a/src/service_inspectors/http_inspect/http_inspect.cc b/src/service_inspectors/http_inspect/http_inspect.cc index a97fa8bae..1379acbe3 100644 --- a/src/service_inspectors/http_inspect/http_inspect.cc +++ b/src/service_inspectors/http_inspect/http_inspect.cc @@ -338,15 +338,12 @@ void HttpInspect::eval(Packet* p) * spent in snort_detect(). * Subtract the ticks from this if iCallDetect == 0 */ -#ifdef PERF_PROFILING if (hiDetectCalled) { - hiPerfStats.ticks -= hiDetectPerfStats.ticks; - /* And Reset ticks to 0 */ - hiDetectPerfStats.ticks = 0; + hiPerfStats.elapsed -= hiDetectPerfStats.elapsed; + hiDetectPerfStats.reset(); hiDetectCalled = 0; } -#endif } //------------------------------------------------------------------------- diff --git a/src/time/CMakeLists.txt b/src/time/CMakeLists.txt index ee7b71cfa..bb4d7856c 100644 --- a/src/time/CMakeLists.txt +++ b/src/time/CMakeLists.txt @@ -8,6 +8,8 @@ set ( TIME_INTERNAL_SOURCES set ( TIME_INCLUDES cpuclock.h + clock_defs.h + stopwatch.h ) add_library ( time STATIC diff --git a/src/time/Makefile.am b/src/time/Makefile.am index 84f17f391..ee5ee0cda 100644 --- a/src/time/Makefile.am +++ b/src/time/Makefile.am @@ -3,11 +3,15 @@ noinst_LIBRARIES = libtime.a x_includedir = $(pkgincludedir)/time x_include_HEADERS = \ -cpuclock.h +cpuclock.h \ +clock_defs.h \ +stopwatch.h libtime_a_SOURCES = \ packet_time.cc \ packet_time.h \ periodic.cc \ periodic.h \ -timersub.h +timersub.h \ +clock_defs.h \ +stopwatch.h diff --git a/src/time/clock_defs.h b/src/time/clock_defs.h new file mode 100644 index 000000000..abbb1e457 --- /dev/null +++ b/src/time/clock_defs.h @@ -0,0 +1,32 @@ +//-------------------------------------------------------------------------- +// Copyright (C) 2015-2015 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. +//-------------------------------------------------------------------------- +// clock_defs.h author Joel Cornett + +#ifndef CLOCK_DEFS_H +#define CLOCK_DEFS_H + +#include + +using hr_clock = std::chrono::high_resolution_clock; +using hr_duration = hr_clock::duration; +using hr_time = hr_clock::time_point; + +inline constexpr hr_duration operator "" _ticks (unsigned long long int v) +{ return hr_duration(v); } + +#endif diff --git a/src/time/dev_notes.txt b/src/time/dev_notes.txt index 74870ed32..50fc3b240 100644 --- a/src/time/dev_notes.txt +++ b/src/time/dev_notes.txt @@ -5,3 +5,5 @@ This module provides miscellaneous utilities related to timing. * Packet time manages the updating and reading of a clock based on time values from acquired packets. + +* Stopwatch is a timekeeping utility that can be started and paused diff --git a/src/time/stopwatch.h b/src/time/stopwatch.h new file mode 100644 index 000000000..f6d633966 --- /dev/null +++ b/src/time/stopwatch.h @@ -0,0 +1,77 @@ +//-------------------------------------------------------------------------- +// Copyright (C) 2015-2015 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. +//-------------------------------------------------------------------------- +// stopwatch.h author Joel Cornett + +#ifndef STOPWATCH_H +#define STOPWATCH_H + +#include + +#include "clock_defs.h" + +class Stopwatch +{ +public: + Stopwatch() : + elapsed { hr_duration::zero() }, running { false } { } + + void start() + { + if ( running ) + return; + + start_time = hr_clock::now(); + running = true; + } + + void stop() + { + if ( !running ) + return; + + elapsed += get_delta(); + running = false; + } + + hr_duration get() const + { + if ( running ) + return elapsed + get_delta(); + + return elapsed; + } + + bool alive() const + { return running; } + + void reset() + { running = false; elapsed = hr_duration::zero(); } + + void cancel() + { running = false; } + +private: + hr_duration get_delta() const + { return hr_clock::now() - start_time; } + + hr_duration elapsed; + bool running; + hr_time start_time; +}; + +#endif diff --git a/src/utils/stats.cc b/src/utils/stats.cc index cbc82a31f..cfb17477a 100644 --- a/src/utils/stats.cc +++ b/src/utils/stats.cc @@ -350,8 +350,8 @@ void PrintStatistics(void) fpShowEventStats(snort_conf); print_thresholding(snort_conf->threshold_config, 1); -#ifdef PERF_PROFILING { + // FIXIT-L J can do flag saving with RAII (much cleaner) int save_quiet_flag = snort_conf->logging_flags & LOGGING_FLAG__QUIET; snort_conf->logging_flags &= ~LOGGING_FLAG__QUIET; @@ -360,7 +360,6 @@ void PrintStatistics(void) snort_conf->logging_flags |= save_quiet_flag; } -#endif } //-------------------------------------------------------------------------