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

@@ -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}
 

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
 

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);

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);

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_* */

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);

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"
 
-/**
+#ifdef PROFILE_RULES
- * 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;
 
 /**
  * Used for generating the summary data to print.

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 */

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__ */