From 5686c673ec2207ea7b481b2b4a875f3b7ea02472 Mon Sep 17 00:00:00 2001 From: Victor Julien Date: Thu, 7 Nov 2013 11:30:17 +0100 Subject: [PATCH] profiling: per buffer profiling --- src/detect-engine-state.c | 4 + src/detect-engine.c | 4 +- src/detect.c | 5 +- src/detect.h | 3 + src/util-profiling-keywords.c | 150 ++++++++++++++++++++++++++-------- src/util-profiling.h | 7 +- 6 files changed, 134 insertions(+), 39 deletions(-) diff --git a/src/detect-engine-state.c b/src/detect-engine-state.c index 8def5a9fd2..39f615c91a 100644 --- a/src/detect-engine-state.c +++ b/src/detect-engine-state.c @@ -287,6 +287,7 @@ int DeStateDetectStartDetection(ThreadVars *tv, DetectEngineCtx *de_ctx, inspect_flags = 0; while (engine != NULL) { if (s->sm_lists[engine->sm_list] != NULL) { + KEYWORD_PROFILING_SET_LIST(det_ctx, engine->sm_list); match = engine->Callback(tv, de_ctx, det_ctx, s, f, flags, alstate, tx, tx_id); @@ -372,6 +373,7 @@ int DeStateDetectStartDetection(ThreadVars *tv, DetectEngineCtx *de_ctx, } sm = s->sm_lists[DETECT_SM_LIST_AMATCH]; + KEYWORD_PROFILING_SET_LIST(det_ctx, DETECT_SM_LIST_AMATCH); for (match = 0; sm != NULL; sm = sm->next) { match = 0; if (sigmatch_table[sm->type].AppLayerMatch != NULL) { @@ -587,6 +589,7 @@ void DeStateDetectContinueDetection(ThreadVars *tv, DetectEngineCtx *de_ctx, if (!(item->flags & engine->inspect_flags) && s->sm_lists[engine->sm_list] != NULL) { + KEYWORD_PROFILING_SET_LIST(det_ctx, engine->sm_list); match = engine->Callback(tv, de_ctx, det_ctx, s, f, flags, alstate, inspect_tx, inspect_tx_id); if (match == 1) { @@ -615,6 +618,7 @@ void DeStateDetectContinueDetection(ThreadVars *tv, DetectEngineCtx *de_ctx, FLOWLOCK_UNLOCK(f); } + KEYWORD_PROFILING_SET_LIST(det_ctx, DETECT_SM_LIST_AMATCH); for (sm = item->nm; sm != NULL; sm = sm->next) { if (sigmatch_table[sm->type].AppLayerMatch != NULL && (alproto == s->alproto || alproto == ALPROTO_SMB || alproto == ALPROTO_SMB2)) diff --git a/src/detect-engine.c b/src/detect-engine.c index 704a42ba7d..56a2cf9372 100644 --- a/src/detect-engine.c +++ b/src/detect-engine.c @@ -841,8 +841,8 @@ void DetectEngineCtxFree(DetectEngineCtx *de_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; + SCProfilingKeywordDestroyCtx(de_ctx);//->profile_keyword_ctx); +// de_ctx->profile_keyword_ctx = NULL; } #endif diff --git a/src/detect.c b/src/detect.c index 17b06d6b3b..0f065d9431 100644 --- a/src/detect.c +++ b/src/detect.c @@ -608,8 +608,9 @@ int SigMatchSignaturesRunPostMatch(ThreadVars *tv, { /* run the packet match functions */ if (s->sm_lists[DETECT_SM_LIST_POSTMATCH] != NULL) { - SigMatch *sm = s->sm_lists[DETECT_SM_LIST_POSTMATCH]; + KEYWORD_PROFILING_SET_LIST(det_ctx, DETECT_SM_LIST_POSTMATCH); + SigMatch *sm = s->sm_lists[DETECT_SM_LIST_POSTMATCH]; SCLogDebug("running match functions, sm %p", sm); for ( ; sm != NULL; sm = sm->next) { @@ -1391,6 +1392,7 @@ int SigMatchSignatures(ThreadVars *th_v, DetectEngineCtx *de_ctx, DetectEngineTh /* Check the payload keywords. If we are a MPM sig and we've made * to here, we've had at least one of the patterns match */ if (s->sm_lists[DETECT_SM_LIST_PMATCH] != NULL) { + KEYWORD_PROFILING_SET_LIST(det_ctx, DETECT_SM_LIST_PMATCH); /* if we have stream msgs, inspect against those first, * but not for a "dsize" signature */ if (s->flags & SIG_FLAG_REQUIRE_STREAM) { @@ -1467,6 +1469,7 @@ int SigMatchSignatures(ThreadVars *th_v, DetectEngineCtx *de_ctx, DetectEngineTh /* run the packet match functions */ if (s->sm_lists[DETECT_SM_LIST_MATCH] != NULL) { + KEYWORD_PROFILING_SET_LIST(det_ctx, DETECT_SM_LIST_MATCH); sm = s->sm_lists[DETECT_SM_LIST_MATCH]; SCLogDebug("running match functions, sm %p", sm); diff --git a/src/detect.h b/src/detect.h index df70845288..e1c24f68c6 100644 --- a/src/detect.h +++ b/src/detect.h @@ -731,6 +731,7 @@ typedef struct DetectEngineCtx_ { #ifdef PROFILING struct SCProfileDetectCtx_ *profile_ctx; struct SCProfileKeywordDetectCtx_ *profile_keyword_ctx; + struct SCProfileKeywordDetectCtx_ *profile_keyword_ctx_per_list[DETECT_SM_LIST_MAX]; #endif } DetectEngineCtx; @@ -863,6 +864,8 @@ typedef struct DetectionEngineThreadCtx_ { struct SCProfileData_ *rule_perf_data; int rule_perf_data_size; struct SCProfileKeywordData_ *keyword_perf_data; + struct SCProfileKeywordData_ *keyword_perf_data_per_list[DETECT_SM_LIST_MAX]; + int keyword_perf_list; /**< list we're currently inspecting, DETECT_SM_LIST_* */ #endif } DetectEngineThreadCtx; diff --git a/src/util-profiling-keywords.c b/src/util-profiling-keywords.c index 235ab3ff33..16ab105386 100644 --- a/src/util-profiling-keywords.c +++ b/src/util-profiling-keywords.c @@ -27,6 +27,7 @@ #include "suricata-common.h" #include "decode.h" #include "detect.h" +#include "detect-engine.h" #include "conf.h" #include "tm-threads.h" @@ -98,40 +99,11 @@ void SCProfilingKeywordsGlobalInit(void) { } } -void -SCProfilingKeywordDump(SCProfileKeywordDetectCtx *rules_ctx) -{ +void DoDump(SCProfileKeywordDetectCtx *rules_ctx, FILE *fp, const char *name) { 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, " Stats for: %s\n", name); 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"); @@ -173,6 +145,53 @@ SCLogInfo("file %s mode %s", profiling_file_name, profiling_file_mode); avgticks_match, avgticks_no_match); } +} + +void +SCProfilingKeywordDump(DetectEngineCtx *de_ctx) { + int i; + FILE *fp; + struct timeval tval; + struct tm *tms; + struct tm local_tm; + + gettimeofday(&tval, NULL); + tms = SCLocalTime(tval.tv_sec, &local_tm); + + 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; + } + + 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); + + /* global stats first */ + DoDump(de_ctx->profile_keyword_ctx, fp, "total"); + /* per buffer stats next, but only if there are stats to print */ + for (i = 0; i < DETECT_SM_LIST_MAX; i++) { + int j; + uint64_t checks = 0; + for (j = 0; j < DETECT_TBLSIZE; j++) { + checks += de_ctx->profile_keyword_ctx_per_list[i]->data[j].checks; + } + + if (checks) + DoDump(de_ctx->profile_keyword_ctx_per_list[i], fp, + DetectSigmatchListEnumToString(i)); + } fprintf(fp,"\n"); if (fp != stdout) @@ -202,6 +221,19 @@ SCProfilingKeywordUpdateCounter(DetectEngineThreadCtx *det_ctx, int id, uint64_t p->ticks_match += ticks; else p->ticks_no_match += ticks; + + /* store per list (buffer type) as well */ + if (det_ctx->keyword_perf_list >= 0 && det_ctx->keyword_perf_list < DETECT_SM_LIST_MAX) { + p = &det_ctx->keyword_perf_data_per_list[det_ctx->keyword_perf_list][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; + } } } @@ -220,10 +252,8 @@ SCProfileKeywordDetectCtx *SCProfilingKeywordInitCtx(void) { return ctx; } -void SCProfilingKeywordDestroyCtx(SCProfileKeywordDetectCtx *ctx) { - SCLogInfo("ctx %p", ctx); - if (ctx != NULL) { - SCProfilingKeywordDump(ctx); +static void DetroyCtx(SCProfileKeywordDetectCtx *ctx) { + if (ctx) { if (ctx->data != NULL) SCFree(ctx->data); pthread_mutex_destroy(&ctx->data_m); @@ -231,6 +261,18 @@ void SCProfilingKeywordDestroyCtx(SCProfileKeywordDetectCtx *ctx) { } } +void SCProfilingKeywordDestroyCtx(DetectEngineCtx *de_ctx) { + if (de_ctx != NULL) { + SCProfilingKeywordDump(de_ctx); + + DetroyCtx(de_ctx->profile_keyword_ctx); + int i; + for (i = 0; i < DETECT_SM_LIST_MAX; i++) { + DetroyCtx(de_ctx->profile_keyword_ctx_per_list[i]); + } + } +} + void SCProfilingKeywordThreadSetup(SCProfileKeywordDetectCtx *ctx, DetectEngineThreadCtx *det_ctx) { if (ctx == NULL) return; @@ -240,6 +282,16 @@ void SCProfilingKeywordThreadSetup(SCProfileKeywordDetectCtx *ctx, DetectEngineT memset(a, 0x00, sizeof(SCProfileKeywordData) * DETECT_TBLSIZE); det_ctx->keyword_perf_data = a; } + + int i; + for (i = 0; i < DETECT_SM_LIST_MAX; i++) { + SCProfileKeywordData *b = SCMalloc(sizeof(SCProfileKeywordData) * DETECT_TBLSIZE); + if (b != NULL) { + memset(b, 0x00, sizeof(SCProfileKeywordData) * DETECT_TBLSIZE); + det_ctx->keyword_perf_data_per_list[i] = b; + } + + } } static void SCProfilingKeywordThreadMerge(DetectEngineCtx *de_ctx, DetectEngineThreadCtx *det_ctx) { @@ -257,6 +309,18 @@ static void SCProfilingKeywordThreadMerge(DetectEngineCtx *de_ctx, DetectEngineT 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; } + + int j; + for (j = 0; j < DETECT_SM_LIST_MAX; j++) { + for (i = 0; i < DETECT_TBLSIZE; i++) { + de_ctx->profile_keyword_ctx_per_list[j]->data[i].checks += det_ctx->keyword_perf_data_per_list[j][i].checks; + de_ctx->profile_keyword_ctx_per_list[j]->data[i].matches += det_ctx->keyword_perf_data_per_list[j][i].matches; + de_ctx->profile_keyword_ctx_per_list[j]->data[i].ticks_match += det_ctx->keyword_perf_data_per_list[j][i].ticks_match; + de_ctx->profile_keyword_ctx_per_list[j]->data[i].ticks_no_match += det_ctx->keyword_perf_data_per_list[j][i].ticks_no_match; + if (det_ctx->keyword_perf_data_per_list[j][i].max > de_ctx->profile_keyword_ctx_per_list[j]->data[i].max) + de_ctx->profile_keyword_ctx_per_list[j]->data[i].max = det_ctx->keyword_perf_data_per_list[j][i].max; + } + } } void SCProfilingKeywordThreadCleanup(DetectEngineThreadCtx *det_ctx) { @@ -269,6 +333,13 @@ void SCProfilingKeywordThreadCleanup(DetectEngineThreadCtx *det_ctx) { SCFree(det_ctx->keyword_perf_data); det_ctx->keyword_perf_data = NULL; + + int i; + for (i = 0; i < DETECT_SM_LIST_MAX; i++) { + SCFree(det_ctx->keyword_perf_data_per_list[i]); + det_ctx->keyword_perf_data_per_list[i] = NULL; + } + } /** @@ -286,6 +357,15 @@ SCProfilingKeywordInitCounters(DetectEngineCtx *de_ctx) BUG_ON(de_ctx->profile_keyword_ctx->data == NULL); memset(de_ctx->profile_keyword_ctx->data, 0x00, sizeof(SCProfileKeywordData) * DETECT_TBLSIZE); + int i; + for (i = 0; i < DETECT_SM_LIST_MAX; i++) { + de_ctx->profile_keyword_ctx_per_list[i] = SCProfilingKeywordInitCtx(); + BUG_ON(de_ctx->profile_keyword_ctx_per_list[i] == NULL); + de_ctx->profile_keyword_ctx_per_list[i]->data = SCMalloc(sizeof(SCProfileKeywordData) * DETECT_TBLSIZE); + BUG_ON(de_ctx->profile_keyword_ctx_per_list[i]->data == NULL); + memset(de_ctx->profile_keyword_ctx_per_list[i]->data, 0x00, sizeof(SCProfileKeywordData) * DETECT_TBLSIZE); + } + SCLogInfo("Registered %"PRIu32" keyword profiling counters.", DETECT_TBLSIZE); } diff --git a/src/util-profiling.h b/src/util-profiling.h index 52243d66d7..08bee49c6a 100644 --- a/src/util-profiling.h +++ b/src/util-profiling.h @@ -60,6 +60,10 @@ void SCProfilingAddPacket(Packet *); extern int profiling_keyword_enabled; extern __thread int profiling_keyword_entered; +#define KEYWORD_PROFILING_SET_LIST(ctx, list) { \ + (ctx)->keyword_perf_list = (list); \ +} + #define KEYWORD_PROFILING_START \ uint64_t profile_keyword_start_ = 0; \ uint64_t profile_keyword_end_ = 0; \ @@ -228,7 +232,7 @@ void SCProfilingRuleThreadSetup(struct SCProfileDetectCtx_ *, DetectEngineThread void SCProfilingRuleThreadCleanup(DetectEngineThreadCtx *); void SCProfilingKeywordsGlobalInit(void); -void SCProfilingKeywordDestroyCtx(struct SCProfileKeywordDetectCtx_ *); +void SCProfilingKeywordDestroyCtx(DetectEngineCtx *);//struct SCProfileKeywordDetectCtx_ *); void SCProfilingKeywordInitCounters(DetectEngineCtx *); void SCProfilingKeywordUpdateCounter(DetectEngineThreadCtx *det_ctx, int id, uint64_t ticks, int match); void SCProfilingKeywordThreadSetup(struct SCProfileKeywordDetectCtx_ *, DetectEngineThreadCtx *); @@ -244,6 +248,7 @@ void SCProfilingDump(void); #define RULE_PROFILING_START #define RULE_PROFILING_END(a,b,c) +#define KEYWORD_PROFILING_SET_LIST(a,b) #define KEYWORD_PROFILING_START #define KEYWORD_PROFILING_END(a,b,c)