From 020cfbcd6145bf4ac4d2ac37c4730e5449eec04c Mon Sep 17 00:00:00 2001 From: Eric Leblond Date: Sun, 22 Aug 2021 23:55:42 +0200 Subject: [PATCH] profiling: introduce rules profiling Performance measurement of rules is important on live Suricata as bad rules can cause severe performance regression. This patch introduces the --enable-profiling-rules that activate profiling for the rules. This reduces the performance impact of full profiling and provide visiblity on the rules performance at the same time. --- configure.ac | 9 ++++ src/detect-engine-build.c | 3 +- src/detect-engine.c | 12 +++-- src/detect.c | 4 +- src/detect.h | 10 ++-- src/suricata.c | 8 +++- src/util-profiling-rules.c | 22 +-------- src/util-profiling.c | 49 +++++++++++++++++++ src/util-profiling.h | 97 +++++++++++++++++++++++++++----------- 9 files changed, 155 insertions(+), 59 deletions(-) diff --git a/configure.ac b/configure.ac index 0d8a717141..4d66c55d0a 100644 --- a/configure.ac +++ b/configure.ac @@ -506,6 +506,7 @@ ;; *) AC_DEFINE([PROFILING],[1],[Enable performance profiling]) + AC_DEFINE([PROFILE_RULES],[1],[Enable performance profiling for rules]) ;; esac ]) @@ -518,6 +519,13 @@ AC_DEFINE([PROFILE_LOCKING],[1],[Enable performance profiling for locks]) ]) + # profiling support, rules + AC_ARG_ENABLE(profiling-rules, + AS_HELP_STRING([--enable-profiling-rules], [Enable performance profiling for rules (enabled by global profiling too)]),[enable_profiling_rules=$enableval],[enable_profiling_rules=no]) + AS_IF([test "x$enable_profiling_rules" = "xyes"], [ + AC_DEFINE([PROFILE_RULES],[1],[Enable performance profiling for rules]) + ]) + # enable support for IPFW AC_ARG_ENABLE(ipfw, AS_HELP_STRING([--enable-ipfw], [Enable FreeBSD IPFW support for inline IDP]),[enable_ipfw=$enableval],[enable_ipfw=no]) @@ -2618,6 +2626,7 @@ SURICATA_BUILD_CONF="Suricata Configuration: Profiling enabled: ${enable_profiling} Profiling locks enabled: ${enable_profiling_locks} + Profiling rules enabled: ${enable_profiling_rules} Plugin support (experimental): ${plugin_support} diff --git a/src/detect-engine-build.c b/src/detect-engine-build.c index 73b1d2a111..f6e064387c 100644 --- a/src/detect-engine-build.c +++ b/src/detect-engine-build.c @@ -1987,7 +1987,8 @@ int SigGroupBuild(DetectEngineCtx *de_ctx) intmax_t v = 0; if (ConfGetInt("detect.profiling.inspect-logging-threshold", &v) == 1) de_ctx->profile_match_logging_threshold = (uint32_t)v; - +#endif +#ifdef PROFILE_RULES SCProfilingRuleInitCounters(de_ctx); #endif diff --git a/src/detect-engine.c b/src/detect-engine.c index 4b266f779b..4eb9acf749 100644 --- a/src/detect-engine.c +++ b/src/detect-engine.c @@ -2591,11 +2591,13 @@ void DetectEngineCtxFree(DetectEngineCtx *de_ctx) if (de_ctx == NULL) return; -#ifdef PROFILING +#ifdef PROFILE_RULES if (de_ctx->profile_ctx != NULL) { SCProfilingRuleDestroyCtx(de_ctx->profile_ctx); de_ctx->profile_ctx = NULL; } +#endif +#ifdef PROFILING if (de_ctx->profile_keyword_ctx != NULL) { SCProfilingKeywordDestroyCtx(de_ctx);//->profile_keyword_ctx); // de_ctx->profile_keyword_ctx = NULL; @@ -3265,8 +3267,10 @@ static TmEcode ThreadCtxDoInit (DetectEngineCtx *de_ctx, DetectEngineThreadCtx * DetectEngineThreadCtxInitKeywords(de_ctx, det_ctx); DetectEngineThreadCtxInitGlobalKeywords(det_ctx); -#ifdef PROFILING +#ifdef PROFILE_RULES SCProfilingRuleThreadSetup(de_ctx->profile_ctx, det_ctx); +#endif +#ifdef PROFILING SCProfilingKeywordThreadSetup(de_ctx->profile_keyword_ctx, det_ctx); SCProfilingPrefilterThreadSetup(de_ctx->profile_prefilter_ctx, det_ctx); SCProfilingSghThreadSetup(de_ctx->profile_sgh_ctx, det_ctx); @@ -3428,8 +3432,10 @@ static void DetectEngineThreadCtxFree(DetectEngineThreadCtx *det_ctx) det_ctx->tenant_array = NULL; } -#ifdef PROFILING +#ifdef PROFILE_RULES SCProfilingRuleThreadCleanup(det_ctx); +#endif +#ifdef PROFILING SCProfilingKeywordThreadCleanup(det_ctx); SCProfilingPrefilterThreadCleanup(det_ctx); SCProfilingSghThreadCleanup(det_ctx); diff --git a/src/detect.c b/src/detect.c index 5d75ebd61b..2648ad74b9 100644 --- a/src/detect.c +++ b/src/detect.c @@ -751,7 +751,7 @@ static inline void DetectRulePacketRules( while (match_cnt--) { RULE_PROFILING_START(p); uint8_t alert_flags = 0; -#ifdef PROFILING +#ifdef PROFILE_RULES bool smatch = false; /* signature match */ #endif s = next_s; @@ -797,7 +797,7 @@ static inline void DetectRulePacketRules( goto next; } -#ifdef PROFILING +#ifdef PROFILE_RULES smatch = true; #endif DetectRunPostMatch(tv, det_ctx, p, s); diff --git a/src/detect.h b/src/detect.h index ba82dd1a77..828428521e 100644 --- a/src/detect.h +++ b/src/detect.h @@ -596,7 +596,7 @@ typedef struct Signature_ { /** port settings for this signature */ DetectPort *sp, *dp; -#ifdef PROFILING +#ifdef PROFILE_RULES uint16_t profiling_id; #endif @@ -912,8 +912,10 @@ typedef struct DetectEngineCtx_ { uint32_t content_inspect_window; } filedata_config[ALPROTO_MAX]; -#ifdef PROFILING +#ifdef PROFILE_RULES struct SCProfileDetectCtx_ *profile_ctx; +#endif +#ifdef PROFILING struct SCProfileKeywordDetectCtx_ *profile_keyword_ctx; struct SCProfilePrefilterDetectCtx_ *profile_prefilter_ctx; struct SCProfileKeywordDetectCtx_ **profile_keyword_ctx_per_list; @@ -1183,9 +1185,11 @@ typedef struct DetectEngineThreadCtx_ { uint64_t stream_persig_cnt; uint64_t stream_persig_size; #endif -#ifdef PROFILING +#ifdef PROFILE_RULES struct SCProfileData_ *rule_perf_data; int rule_perf_data_size; +#endif +#ifdef PROFILING struct SCProfileKeywordData_ *keyword_perf_data; struct SCProfileKeywordData_ **keyword_perf_data_per_list; int keyword_perf_list; /**< list we're currently inspecting, DETECT_SM_LIST_* */ diff --git a/src/suricata.c b/src/suricata.c index 4be4238ac4..007ca7b329 100644 --- a/src/suricata.c +++ b/src/suricata.c @@ -2228,13 +2228,17 @@ void PreRunInit(const int runmode) return; StatsInit(); -#ifdef PROFILING +#ifdef PROFILE_RULES SCProfilingRulesGlobalInit(); +#endif +#ifdef PROFILING SCProfilingKeywordsGlobalInit(); SCProfilingPrefilterGlobalInit(); SCProfilingSghsGlobalInit(); - SCProfilingInit(); #endif /* PROFILING */ +#ifdef PROFILE_RULES + SCProfilingInit(); +#endif DefragInit(); FlowInitConfig(FLOW_QUIET); IPPairInitConfig(FLOW_QUIET); diff --git a/src/util-profiling-rules.c b/src/util-profiling-rules.c index 6ad11cdc70..5f5dcc126d 100644 --- a/src/util-profiling-rules.c +++ b/src/util-profiling-rules.c @@ -27,31 +27,11 @@ #include "suricata-common.h" #include "util-profiling.h" -#ifdef PROFILING #include "util-byte.h" #include "util-conf.h" #include "util-time.h" -/** - * Extra data for rule profiling. - */ -typedef struct SCProfileData_ { - uint32_t sid; - uint32_t gid; - uint32_t rev; - uint64_t checks; - uint64_t matches; - uint64_t max; - uint64_t ticks_match; - uint64_t ticks_no_match; -} SCProfileData; - -typedef struct SCProfileDetectCtx_ { - uint32_t size; - uint16_t id; - SCProfileData *data; - pthread_mutex_t data_m; -} SCProfileDetectCtx; +#ifdef PROFILE_RULES /** * Used for generating the summary data to print. diff --git a/src/util-profiling.c b/src/util-profiling.c index 5ba36f9df2..818c2cc85d 100644 --- a/src/util-profiling.c +++ b/src/util-profiling.c @@ -1405,4 +1405,53 @@ SCProfilingRegisterTests(void) #endif /* UNITTESTS */ } +int SCProfileRuleStartCollection(void) +{ + SCReturnInt(TM_ECODE_OK); +} + +int SCProfileRuleStopCollection(void) +{ + SCReturnInt(TM_ECODE_OK); +} + +#elif PROFILE_RULES + +thread_local int profiling_rules_entered = 0; +int profiling_output_to_file = 0; +static SC_ATOMIC_DECLARE(uint64_t, samples); +static int rate = 1; + +/** + * \brief Initialize profiling. + */ +void SCProfilingInit(void) +{ + SC_ATOMIC_INIT(samples); + intmax_t rate_v = 0; + + (void)ConfGetInt("profiling.sample-rate", &rate_v); + if (rate_v > 0 && rate_v < INT_MAX) { + rate = (int)rate_v; + if (rate != 1) + SCLogInfo("profiling runs for every %dth packet", rate); + else + SCLogInfo("profiling runs for every packet"); + } +} + +/* see if we want to profile rules for this packet */ +int SCProfileRuleStart(Packet *p) +{ + uint64_t sample = SC_ATOMIC_ADD(samples, 1); + if (sample % rate == 0) { + p->flags |= PKT_PROFILE; + return 1; + } + + if (p->flags & PKT_PROFILE) + return 1; + return 0; +} + #endif /* PROFILING */ diff --git a/src/util-profiling.h b/src/util-profiling.h index c0f745f5f7..76c57ba09a 100644 --- a/src/util-profiling.h +++ b/src/util-profiling.h @@ -25,41 +25,21 @@ #ifndef __UTIL_PROFILE_H__ #define __UTIL_PROFILE_H__ -#ifdef PROFILING +#include "util-cpu.h" #include "detect.h" + +#ifdef PROFILING + #include "util-cpu.h" #include "util-profiling-locks.h" extern int profiling_rules_enabled; extern int profiling_packets_enabled; extern int profiling_sghs_enabled; -extern thread_local int profiling_rules_entered; void SCProfilingPrintPacketProfile(Packet *); void SCProfilingAddPacket(Packet *); -int SCProfileRuleStart(Packet *p); - -#define RULE_PROFILING_START(p) \ - uint64_t profile_rule_start_ = 0; \ - uint64_t profile_rule_end_ = 0; \ - if (profiling_rules_enabled && SCProfileRuleStart((p))) { \ - if (profiling_rules_entered > 0) { \ - SCLogError("Re-entered profiling, exiting."); \ - exit(1); \ - } \ - profiling_rules_entered++; \ - profile_rule_start_ = UtilCpuGetTicks(); \ - } - -#define RULE_PROFILING_END(ctx, r, m, p) \ - if (profiling_rules_enabled && ((p)->flags & PKT_PROFILE)) { \ - profile_rule_end_ = UtilCpuGetTicks(); \ - SCProfilingRuleUpdateCounter(ctx, r->profiling_id, \ - profile_rule_end_ - profile_rule_start_, m); \ - profiling_rules_entered--; \ - } - extern int profiling_keyword_enabled; extern thread_local int profiling_keyword_entered; @@ -346,9 +326,6 @@ void SCProfilingDump(void); #else -#define RULE_PROFILING_START(p) -#define RULE_PROFILING_END(a,b,c,p) - #define KEYWORD_PROFILING_SET_LIST(a,b) #define KEYWORD_PROFILING_START #define KEYWORD_PROFILING_END(a,b,c) @@ -387,4 +364,70 @@ void SCProfilingDump(void); #endif /* PROFILING */ +#ifdef PROFILE_RULES + +extern int profiling_rules_enabled; +extern thread_local int profiling_rules_entered; + +#ifndef PROFILING +void SCProfilingInit(void); +#endif +/** + * Extra data for rule profiling. + */ +typedef struct SCProfileData_ { + uint32_t sid; + uint32_t gid; + uint32_t rev; + uint64_t checks; + uint64_t matches; + uint64_t max; + uint64_t ticks_match; + uint64_t ticks_no_match; +} SCProfileData; + +typedef struct SCProfileDetectCtx_ { + uint32_t size; + uint32_t id; + SCProfileData *data; + pthread_mutex_t data_m; +} SCProfileDetectCtx; + +void SCProfilingRulesGlobalInit(void); +void SCProfilingRuleDestroyCtx(struct SCProfileDetectCtx_ *); +void SCProfilingRuleInitCounters(DetectEngineCtx *); +void SCProfilingRuleUpdateCounter(DetectEngineThreadCtx *, uint16_t, uint64_t, int); +void SCProfilingRuleThreadSetup(struct SCProfileDetectCtx_ *, DetectEngineThreadCtx *); +void SCProfilingRuleThreadCleanup(DetectEngineThreadCtx *); +int SCProfileRuleStart(Packet *p); +int SCProfileRuleTriggerDump(DetectEngineCtx *de_ctx); +void SCProfilingRuleThreatAggregate(DetectEngineThreadCtx *det_ctx); + +#define RULE_PROFILING_START(p) \ + uint64_t profile_rule_start_ = 0; \ + uint64_t profile_rule_end_ = 0; \ + if (profiling_rules_enabled && SCProfileRuleStart((p))) { \ + if (profiling_rules_entered > 0) { \ + SCLogError("Re-entered profiling, exiting."); \ + exit(1); \ + } \ + profiling_rules_entered++; \ + profile_rule_start_ = UtilCpuGetTicks(); \ + } + +#define RULE_PROFILING_END(ctx, r, m, p) \ + if (profiling_rules_enabled && ((p)->flags & PKT_PROFILE)) { \ + profile_rule_end_ = UtilCpuGetTicks(); \ + SCProfilingRuleUpdateCounter( \ + ctx, r->profiling_id, profile_rule_end_ - profile_rule_start_, m); \ + profiling_rules_entered--; \ + } + +#else /* PROFILE_RULES */ + +#define RULE_PROFILING_START(p) +#define RULE_PROFILING_END(a, b, c, p) + +#endif /* PROFILE_RULES */ + #endif /* ! __UTIL_PROFILE_H__ */