util-profiling.c util-profiling.h \
util-profiling-locks.c util-profiling-locks.h \
util-profiling-rules.c \
+util-profiling-keywords.c \
util-proto-name.c util-proto-name.h \
util-radix-tree.c util-radix-tree.h \
util-random.c util-random.h \
#include "util-unittest.h"
#include "util-unittest-helper.h"
+#include "util-profiling.h"
/**
* \brief Run the actual payload match functions
uint8_t inspection_mode, void *data)
{
SCEnter();
+ KEYWORD_PROFILING_START;
det_ctx->inspection_recursion_counter++;
if (det_ctx->inspection_recursion_counter == de_ctx->inspection_recursion_limit) {
det_ctx->discontinue_matching = 1;
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 0);
SCReturnInt(0);
}
if (sm == NULL || buffer_len == 0) {
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 0);
SCReturnInt(0);
}
}
SCLogDebug("content %"PRIu32, cd->id);
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 1);
/* see if the next buffer keywords match. If not, we will
* search for another occurence of this content and see
SCLogDebug("no relative match coming up, so this is a match");
goto match;
}
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 1);
/* save it, in case we need to do a pcre match once again */
prev_offset = det_ctx->pcre_match_start_offset;
}
no_match:
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 0);
SCReturnInt(0);
match:
/* this sigmatch matched, inspect the next one. If it was the last,
* the buffer portion of the signature matched. */
if (sm->next != NULL) {
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 1);
int r = DetectEngineContentInspection(de_ctx, det_ctx, s, sm->next, f, buffer, buffer_len, stream_start_offset, inspection_mode, data);
SCReturnInt(r);
} else {
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 1);
SCReturnInt(1);
}
}
#include "util-unittest.h"
#include "util-unittest-helper.h"
#include "util-print.h"
+#include "util-profiling.h"
#ifdef OS_WIN32
#include <winsock.h>
while (sm != NULL) {
BUG_ON(!(sigmatch_table[sm->type].flags & SIGMATCH_IPONLY_COMPAT));
-
+ KEYWORD_PROFILING_START;
if (sigmatch_table[sm->type].Match(tv, det_ctx, p, s, sm) > 0) {
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 1);
sm = sm->next;
continue;
}
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 0);
return 0;
}
SCLogDebug("running match functions, sm %p", sm);
for ( ; sm != NULL; sm = sm->next) {
+ KEYWORD_PROFILING_START;
(void)sigmatch_table[sm->type].Match(tv, det_ctx, p, s, sm);
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 1);
}
}
if (!(s->flags & SIG_FLAG_NOALERT)) {
if (alproto == ALPROTO_SMB || alproto == ALPROTO_SMB2) {
smb_state = (SMBState *)alstate;
if (smb_state->dcerpc_present) {
+ KEYWORD_PROFILING_START;
match = sigmatch_table[sm->type].
AppLayerMatch(tv, det_ctx, f, flags, &smb_state->dcerpc, s, sm);
+ KEYWORD_PROFILING_END(det_ctx, sm->type, (match > 0));
}
} else {
+ KEYWORD_PROFILING_START;
match = sigmatch_table[sm->type].
AppLayerMatch(tv, det_ctx, f, flags, alstate, s, sm);
+ KEYWORD_PROFILING_END(det_ctx, sm->type, (match > 0));
}
if (match == 0)
if (alproto == ALPROTO_SMB || alproto == ALPROTO_SMB2) {
smb_state = (SMBState *)alstate;
if (smb_state->dcerpc_present) {
+ KEYWORD_PROFILING_START;
match = sigmatch_table[sm->type].
AppLayerMatch(tv, det_ctx, f, flags, &smb_state->dcerpc, s, sm);
+ KEYWORD_PROFILING_END(det_ctx, sm->type, (match > 0));
}
} else {
+ KEYWORD_PROFILING_START;
match = sigmatch_table[sm->type].
AppLayerMatch(tv, det_ctx, f, flags, alstate, s, sm);
+ KEYWORD_PROFILING_END(det_ctx, sm->type, (match > 0));
}
if (match == 0)
/* init iprep... ignore errors for now */
(void)SRepInit(de_ctx);
+#ifdef PROFILING
+ SCProfilingKeywordInitCounters(de_ctx);
+#endif
+
return de_ctx;
error:
return NULL;
SCProfilingRuleDestroyCtx(de_ctx->profile_ctx);
de_ctx->profile_ctx = NULL;
}
+ if (de_ctx->profile_keyword_ctx != NULL) {
+ SCProfilingKeywordDestroyCtx(de_ctx->profile_keyword_ctx);
+ de_ctx->profile_keyword_ctx = NULL;
+ }
#endif
/* Normally the hashes are freed elsewhere, but
DetectEngineThreadCtxInitKeywords(de_ctx, det_ctx);
#ifdef PROFILING
SCProfilingRuleThreadSetup(de_ctx->profile_ctx, det_ctx);
+ SCProfilingKeywordThreadSetup(de_ctx->profile_keyword_ctx, det_ctx);
#endif
SC_ATOMIC_INIT(det_ctx->so_far_used_by_detect);
#ifdef PROFILING
SCProfilingRuleThreadCleanup(det_ctx);
+ SCProfilingKeywordThreadCleanup(det_ctx);
#endif
DetectEngineIPOnlyThreadDeinit(&det_ctx->io_ctx);
SCLogDebug("running match functions, sm %p", sm);
for ( ; sm != NULL; sm = sm->next) {
+ KEYWORD_PROFILING_START;
(void)sigmatch_table[sm->type].Match(tv, det_ctx, p, s, sm);
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 1);
}
}
SCLogDebug("running match functions, sm %p", sm);
for ( ; sm != NULL; sm = sm->next) {
+ KEYWORD_PROFILING_START;
if (sigmatch_table[sm->type].Match(th_v, det_ctx, p, s, sm) <= 0) {
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 0);
goto next;
}
+ KEYWORD_PROFILING_END(det_ctx, sm->type, 1);
}
}
#ifdef PROFILING
struct SCProfileDetectCtx_ *profile_ctx;
+ struct SCProfileKeywordDetectCtx_ *profile_keyword_ctx;
#endif
} DetectEngineCtx;
#ifdef PROFILING
struct SCProfileData_ *rule_perf_data;
int rule_perf_data_size;
+ struct SCProfileKeywordData_ *keyword_perf_data;
#endif
} DetectEngineThreadCtx;
}
#ifdef PROFILING
SCProfilingRulesGlobalInit();
+ SCProfilingKeywordsGlobalInit();
SCProfilingInit();
#endif /* PROFILING */
SCReputationInitCtx();
--- /dev/null
+/* Copyright (C) 2007-2013 Open Information Security Foundation
+ *
+ * You can copy, redistribute or modify this Program under the terms of
+ * the GNU General Public License version 2 as published by the Free
+ * Software Foundation.
+ *
+ * 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
+ * version 2 along with this program; if not, write to the Free Software
+ * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
+ * 02110-1301, USA.
+ */
+
+/**
+ * \file
+ *
+ * \author Endace Technology Limited.
+ * \author Victor Julien <victor@inliniac.net>
+ *
+ * An API for rule profiling operations.
+ */
+
+#include "suricata-common.h"
+#include "decode.h"
+#include "detect.h"
+#include "conf.h"
+
+#include "tm-threads.h"
+
+#include "util-unittest.h"
+#include "util-byte.h"
+#include "util-profiling.h"
+#include "util-profiling-locks.h"
+
+#ifdef PROFILING
+
+#ifndef MIN
+#define MIN(a, b) (((a) < (b)) ? (a) : (b))
+#endif
+
+/**
+ * Extra data for rule profiling.
+ */
+typedef struct SCProfileKeywordData_ {
+ uint64_t checks;
+ uint64_t matches;
+ uint64_t max;
+ uint64_t ticks_match;
+ uint64_t ticks_no_match;
+} SCProfileKeywordData;
+
+typedef struct SCProfileKeywordDetectCtx_ {
+ uint32_t id;
+ SCProfileKeywordData *data;
+ pthread_mutex_t data_m;
+} SCProfileKeywordDetectCtx;
+
+static int profiling_keywords_output_to_file = 0;
+int profiling_keyword_enabled = 1;
+__thread int profiling_keyword_entered = 0;
+static char *profiling_file_name = "";
+static const char *profiling_file_mode = "a";
+
+void SCProfilingKeywordsGlobalInit(void) {
+ ConfNode *conf;
+
+ conf = ConfGetNode("profiling.keywords");
+ if (conf != NULL) {
+ if (ConfNodeChildValueIsTrue(conf, "enabled")) {
+ profiling_keyword_enabled = 1;
+ const char *filename = ConfNodeLookupChildValue(conf, "filename");
+ if (filename != NULL) {
+
+ char *log_dir;
+ log_dir = ConfigGetLogDirectory();
+
+ profiling_file_name = SCMalloc(PATH_MAX);
+ if (unlikely(profiling_file_name == NULL)) {
+ SCLogError(SC_ERR_MEM_ALLOC, "can't duplicate file name");
+ exit(EXIT_FAILURE);
+ }
+ snprintf(profiling_file_name, PATH_MAX, "%s/%s", log_dir, filename);
+
+ const char *v = ConfNodeLookupChildValue(conf, "append");
+ if (v == NULL || ConfValIsTrue(v)) {
+ profiling_file_mode = "a";
+ } else {
+ profiling_file_mode = "w";
+ }
+
+ profiling_keywords_output_to_file = 1;
+ }
+ }
+ }
+}
+
+void
+SCProfilingKeywordDump(SCProfileKeywordDetectCtx *rules_ctx)
+{
+ int i;
+ FILE *fp;
+
+ if (rules_ctx == NULL)
+ return;
+
+ struct timeval tval;
+ struct tm *tms;
+ if (profiling_keywords_output_to_file == 1) {
+SCLogInfo("file %s mode %s", profiling_file_name, profiling_file_mode);
+
+ fp = fopen(profiling_file_name, profiling_file_mode);
+
+ if (fp == NULL) {
+ SCLogError(SC_ERR_FOPEN, "failed to open %s: %s", profiling_file_name,
+ strerror(errno));
+ return;
+ }
+ } else {
+ fp = stdout;
+ }
+
+ gettimeofday(&tval, NULL);
+ struct tm local_tm;
+ tms = SCLocalTime(tval.tv_sec, &local_tm);
+
+ fprintf(fp, " ----------------------------------------------"
+ "----------------------------\n");
+ fprintf(fp, " Date: %" PRId32 "/%" PRId32 "/%04d -- "
+ "%02d:%02d:%02d\n", tms->tm_mon + 1, tms->tm_mday, tms->tm_year + 1900,
+ tms->tm_hour,tms->tm_min, tms->tm_sec);
+ fprintf(fp, " ----------------------------------------------"
+ "----------------------------\n");
+ fprintf(fp, " %-16s %-11s %-8s %-8s %-11s %-11s %-11s %-11s\n", "Keyword", "Ticks", "Checks", "Matches", "Max Ticks", "Avg", "Avg Match", "Avg No Match");
+ fprintf(fp, " ---------------- "
+ "----------- "
+ "-------- "
+ "-------- "
+ "----------- "
+ "----------- "
+ "----------- "
+ "----------- "
+ "\n");
+ for (i = 0; i < DETECT_TBLSIZE; i++) {
+ SCProfileKeywordData *d = &rules_ctx->data[i];
+ if (d == NULL || d->checks == 0)
+ continue;
+
+ uint64_t ticks = d->ticks_match + d->ticks_no_match;
+ double avgticks = 0;
+ double avgticks_match = 0;
+ double avgticks_no_match = 0;
+ if (ticks && d->checks) {
+ avgticks = (ticks / d->checks);
+
+ if (d->ticks_match && d->matches)
+ avgticks_match = (d->ticks_match / d->matches);
+ if (d->ticks_no_match && (d->checks - d->matches) != 0)
+ avgticks_no_match = (d->ticks_no_match / (d->checks - d->matches));
+ }
+
+ fprintf(fp,
+ " %-16s %-11"PRIu64" %-8"PRIu64" %-8"PRIu64" %-11"PRIu64" %-11.2f %-11.2f %-11.2f\n",
+ sigmatch_table[i].name,
+ ticks,
+ d->checks,
+ d->matches,
+ d->max,
+ avgticks,
+ avgticks_match,
+ avgticks_no_match);
+ }
+
+ fprintf(fp,"\n");
+ if (fp != stdout)
+ fclose(fp);
+
+ SCLogInfo("Done dumping keyword profiling data.");
+}
+
+/**
+ * \brief Update a rule counter.
+ *
+ * \param id The ID of this counter.
+ * \param ticks Number of CPU ticks for this rule.
+ * \param match Did the rule match?
+ */
+void
+SCProfilingKeywordUpdateCounter(DetectEngineThreadCtx *det_ctx, int id, uint64_t ticks, int match)
+{
+ if (det_ctx != NULL && det_ctx->keyword_perf_data != NULL && id < DETECT_TBLSIZE) {
+ SCProfileKeywordData *p = &det_ctx->keyword_perf_data[id];
+
+ p->checks++;
+ p->matches += match;
+ if (ticks > p->max)
+ p->max = ticks;
+ if (match == 1)
+ p->ticks_match += ticks;
+ else
+ p->ticks_no_match += ticks;
+ }
+}
+
+SCProfileKeywordDetectCtx *SCProfilingKeywordInitCtx(void) {
+ SCProfileKeywordDetectCtx *ctx = SCMalloc(sizeof(SCProfileKeywordDetectCtx));
+ if (ctx != NULL) {
+ memset(ctx, 0x00, sizeof(SCProfileKeywordDetectCtx));
+
+ if (pthread_mutex_init(&ctx->data_m, NULL) != 0) {
+ SCLogError(SC_ERR_MUTEX,
+ "Failed to initialize hash table mutex.");
+ exit(EXIT_FAILURE);
+ }
+ }
+
+ return ctx;
+}
+
+void SCProfilingKeywordDestroyCtx(SCProfileKeywordDetectCtx *ctx) {
+ SCLogInfo("ctx %p", ctx);
+ if (ctx != NULL) {
+ SCProfilingKeywordDump(ctx);
+ if (ctx->data != NULL)
+ SCFree(ctx->data);
+ pthread_mutex_destroy(&ctx->data_m);
+ SCFree(ctx);
+ }
+}
+
+void SCProfilingKeywordThreadSetup(SCProfileKeywordDetectCtx *ctx, DetectEngineThreadCtx *det_ctx) {
+ if (ctx == NULL)
+ return;
+
+ SCProfileKeywordData *a = SCMalloc(sizeof(SCProfileKeywordData) * DETECT_TBLSIZE);
+ if (a != NULL) {
+ memset(a, 0x00, sizeof(SCProfileKeywordData) * DETECT_TBLSIZE);
+ det_ctx->keyword_perf_data = a;
+ }
+}
+
+static void SCProfilingKeywordThreadMerge(DetectEngineCtx *de_ctx, DetectEngineThreadCtx *det_ctx) {
+ if (de_ctx == NULL || de_ctx->profile_keyword_ctx == NULL ||
+ de_ctx->profile_keyword_ctx->data == NULL || det_ctx == NULL ||
+ det_ctx->keyword_perf_data == NULL)
+ return;
+
+ int i;
+ for (i = 0; i < DETECT_TBLSIZE; i++) {
+ de_ctx->profile_keyword_ctx->data[i].checks += det_ctx->keyword_perf_data[i].checks;
+ de_ctx->profile_keyword_ctx->data[i].matches += det_ctx->keyword_perf_data[i].matches;
+ de_ctx->profile_keyword_ctx->data[i].ticks_match += det_ctx->keyword_perf_data[i].ticks_match;
+ de_ctx->profile_keyword_ctx->data[i].ticks_no_match += det_ctx->keyword_perf_data[i].ticks_no_match;
+ if (det_ctx->keyword_perf_data[i].max > de_ctx->profile_keyword_ctx->data[i].max)
+ de_ctx->profile_keyword_ctx->data[i].max = det_ctx->keyword_perf_data[i].max;
+ }
+}
+
+void SCProfilingKeywordThreadCleanup(DetectEngineThreadCtx *det_ctx) {
+ if (det_ctx == NULL || det_ctx->de_ctx == NULL || det_ctx->keyword_perf_data == NULL)
+ return;
+
+ pthread_mutex_lock(&det_ctx->de_ctx->profile_keyword_ctx->data_m);
+ SCProfilingKeywordThreadMerge(det_ctx->de_ctx, det_ctx);
+ pthread_mutex_unlock(&det_ctx->de_ctx->profile_keyword_ctx->data_m);
+
+ SCFree(det_ctx->keyword_perf_data);
+ det_ctx->keyword_perf_data = NULL;
+}
+
+/**
+ * \brief Register the keyword profiling counters.
+ *
+ * \param de_ctx The active DetectEngineCtx, used to get at the loaded rules.
+ */
+void
+SCProfilingKeywordInitCounters(DetectEngineCtx *de_ctx)
+{
+ de_ctx->profile_keyword_ctx = SCProfilingKeywordInitCtx();
+ BUG_ON(de_ctx->profile_keyword_ctx == NULL);
+
+ de_ctx->profile_keyword_ctx->data = SCMalloc(sizeof(SCProfileKeywordData) * DETECT_TBLSIZE);
+ BUG_ON(de_ctx->profile_keyword_ctx->data == NULL);
+ memset(de_ctx->profile_keyword_ctx->data, 0x00, sizeof(SCProfileKeywordData) * DETECT_TBLSIZE);
+
+ SCLogInfo("Registered %"PRIu32" keyword profiling counters.", DETECT_TBLSIZE);
+}
+
+#endif /* PROFILING */
profiling_rules_entered--; \
}
+extern int profiling_keyword_enabled;
+extern __thread int profiling_keyword_entered;
+
+#define KEYWORD_PROFILING_START \
+ uint64_t profile_keyword_start_ = 0; \
+ uint64_t profile_keyword_end_ = 0; \
+ if (profiling_keyword_enabled) { \
+ if (profiling_keyword_entered > 0) { \
+ SCLogError(SC_ERR_FATAL, "Re-entered profiling, exiting."); \
+ abort(); \
+ } \
+ profiling_keyword_entered++; \
+ profile_keyword_start_ = UtilCpuGetTicks(); \
+ }
+
+/* we allow this macro to be called if profiling_keyword_entered == 0,
+ * so that we don't have to refactor some of the detection code. */
+#define KEYWORD_PROFILING_END(ctx, type, m) \
+ if (profiling_keyword_enabled && profiling_keyword_entered) { \
+ profile_keyword_end_ = UtilCpuGetTicks(); \
+ SCProfilingKeywordUpdateCounter((ctx),(type),(profile_keyword_end_ - profile_keyword_start_),(m)); \
+ profiling_keyword_entered--; \
+ }
+
#define PACKET_PROFILING_START(p) \
if (profiling_packets_enabled) { \
(p)->profile.ticks_start = UtilCpuGetTicks(); \
void SCProfilingRuleDestroyCtx(struct SCProfileDetectCtx_ *);
void SCProfilingRuleInitCounters(DetectEngineCtx *);
void SCProfilingRuleUpdateCounter(DetectEngineThreadCtx *, uint16_t, uint64_t, int);
-
void SCProfilingRuleThreadSetup(struct SCProfileDetectCtx_ *, DetectEngineThreadCtx *);
void SCProfilingRuleThreadCleanup(DetectEngineThreadCtx *);
+void SCProfilingKeywordsGlobalInit(void);
+void SCProfilingKeywordDestroyCtx(struct SCProfileKeywordDetectCtx_ *);
+void SCProfilingKeywordInitCounters(DetectEngineCtx *);
+void SCProfilingKeywordUpdateCounter(DetectEngineThreadCtx *det_ctx, int id, uint64_t ticks, int match);
+void SCProfilingKeywordThreadSetup(struct SCProfileKeywordDetectCtx_ *, DetectEngineThreadCtx *);
+void SCProfilingKeywordThreadCleanup(DetectEngineThreadCtx *);
+
void SCProfilingInit(void);
void SCProfilingDestroy(void);
void SCProfilingRegisterTests(void);
#define RULE_PROFILING_START
#define RULE_PROFILING_END(a,b,c)
+#define KEYWORD_PROFILING_START
+#define KEYWORD_PROFILING_END(a,b,c)
+
#define PACKET_PROFILING_START(p)
#define PACKET_PROFILING_END(p)
# Limit the number of items printed at exit.
limit: 100
+ # per keyword profiling
+ keywords:
+ enabled: yes
+ filename: keyword_perf.log
+ append: yes
+
# packet profiling
packets: