Basic rule profiling even though the results may be skewed by a bad rule in a grouping of rules.

remotes/origin/master-1.0.x
Jason Ish 15 years ago committed by Victor Julien
parent b629b7c5c1
commit 18e5ac8cde

@ -750,6 +750,14 @@ AC_CHECK_HEADER(pcap.h,,[AC_ERROR(pcap.h not found ...)])
echo
fi
AC_ARG_ENABLE(profiling,
[ --enable-profiling Enable performance profiling],
[ enable_profiling=yes
])
if test "$enable_profiling" = "yes"; then
CFLAGS="${CFLAGS} -DPROFILING"
fi
AC_SUBST(CFLAGS)
AC_SUBST(LDFLAGS)
AC_SUBST(CPPFLAGS)

@ -194,7 +194,8 @@ defrag.c defrag.h \
output.c output.h \
win32-misc.c win32-misc.h \
util-action.c util-action.h \
win32-syslog.h
win32-syslog.h \
util-profiling.c util-profiling.h
# set the include path found by configure
INCLUDES= $(all_includes)

@ -479,6 +479,28 @@ ConfNodeLookupChildValue(ConfNode *node, const char *name)
return NULL;
}
/**
* \brief Test if a configuration node has a true value.
*
* \param node The parent configuration node.
* \param name The name of the child node to test.
*
* \retval 1 if the child node has a true value, otherwise 0 is
* returned, even if the child node does not exist.
*/
int
ConfNodeChildValueIsTrue(ConfNode *node, const char *key)
{
const char *val;
val = ConfNodeLookupChildValue(node, key);
if (val != NULL) {
if ((strcasecmp(val, "yes") == 0) || (strcasecmp(val, "true") == 0))
return 1;
}
return 0;
}
#ifdef UNITTESTS
/**

@ -65,5 +65,6 @@ ConfNode *ConfNodeLookupChild(ConfNode *node, const char *key);
const char *ConfNodeLookupChildValue(ConfNode *node, const char *key);
void ConfNodeRemove(ConfNode *);
void ConfRegisterTests();
int ConfNodeChildValueIsTrue(ConfNode *node, const char *key);
#endif /* ! __CONF_H__ */

@ -139,7 +139,7 @@
#include "util-mpm-b2g-cuda.h"
#include "util-cuda.h"
#include "util-privs.h"
#include "util-profiling.h"
SigMatch *SigMatchAlloc(void);
void DetectExitPrintStats(ThreadVars *tv, void *data);
@ -608,6 +608,7 @@ int SigMatchSignatures(ThreadVars *th_v, DetectEngineCtx *de_ctx, DetectEngineTh
/* inspect the sigs against the packet */
for (idx = 0; idx < det_ctx->sgh->sig_cnt; idx++) {
//for (idx = 0; idx < det_ctx->pmq.sig_id_array_cnt; idx++) {
PROFILING_START;
sig = det_ctx->sgh->match_array[idx];
//sig = det_ctx->pmq.sig_id_array[idx];
s = de_ctx->sig_array[sig];
@ -618,7 +619,7 @@ int SigMatchSignatures(ThreadVars *th_v, DetectEngineCtx *de_ctx, DetectEngineTh
no payload inspection flag is set*/
if ((p->flags & PKT_NOPAYLOAD_INSPECTION) && (s->flags & SIG_FLAG_PAYLOAD)) {
SCLogDebug("no payload inspection enabled and sig has payload portion.");
continue;
goto next;
}
if (s->flags & SIG_FLAG_MPM) {
@ -628,7 +629,7 @@ int SigMatchSignatures(ThreadVars *th_v, DetectEngineCtx *de_ctx, DetectEngineTh
if (!(det_ctx->pmq.pattern_id_bitarray[(s->mpm_pattern_id / 8)] & (1<<(s->mpm_pattern_id % 8))) &&
(s->flags & SIG_FLAG_MPM) && !(s->flags & SIG_FLAG_MPM_NEGCONTENT)) {
SCLogDebug("mpm sig without matches (pat id check in content).");
continue;
goto next;
}
}
@ -641,7 +642,7 @@ int SigMatchSignatures(ThreadVars *th_v, DetectEngineCtx *de_ctx, DetectEngineTh
(s->flags & SIG_FLAG_MPM_URI) && !(s->flags & SIG_FLAG_MPM_URI_NEG)) {
SCLogDebug("mpm sig without matches (pat id %"PRIu32
" check in uri).", s->mpm_uripattern_id);
continue;
goto next;
}
}
}
@ -649,7 +650,7 @@ int SigMatchSignatures(ThreadVars *th_v, DetectEngineCtx *de_ctx, DetectEngineTh
/* if the sig has alproto and the session as well they should match */
if (s->alproto != ALPROTO_UNKNOWN && alproto != ALPROTO_UNKNOWN) {
if (s->alproto != alproto) {
continue;
goto next;
}
}
@ -659,14 +660,14 @@ int SigMatchSignatures(ThreadVars *th_v, DetectEngineCtx *de_ctx, DetectEngineTh
DetectPort *dport = DetectPortLookupGroup(s->dp,p->dp);
if (dport == NULL) {
SCLogDebug("dport didn't match.");
continue;
goto next;
}
}
if (!(s->flags & SIG_FLAG_SP_ANY)) {
DetectPort *sport = DetectPortLookupGroup(s->sp,p->sp);
if (sport == NULL) {
SCLogDebug("sport didn't match.");
continue;
goto next;
}
}
}
@ -676,7 +677,7 @@ int SigMatchSignatures(ThreadVars *th_v, DetectEngineCtx *de_ctx, DetectEngineTh
DetectAddress *saddr = DetectAddressLookupInHead(&s->src,&p->src);
if (saddr == NULL) {
SCLogDebug("src addr didn't match.");
continue;
goto next;
}
}
/* check the destination address */
@ -684,7 +685,7 @@ int SigMatchSignatures(ThreadVars *th_v, DetectEngineCtx *de_ctx, DetectEngineTh
DetectAddress *daddr = DetectAddressLookupInHead(&s->dst,&p->dst);
if (daddr == NULL) {
SCLogDebug("dst addr didn't match.");
continue;
goto next;
}
}
@ -692,13 +693,13 @@ int SigMatchSignatures(ThreadVars *th_v, DetectEngineCtx *de_ctx, DetectEngineTh
* to here, we've had at least one of the patterns match */
if (s->pmatch != NULL) {
if (DetectEngineInspectPacketPayload(de_ctx, det_ctx, s, p->flow, flags, alstate, p) != 1)
continue;
goto next;
}
/* Check the uricontent keywords here. */
if (s->umatch != NULL) {
if (DetectEngineInspectPacketUris(de_ctx, det_ctx, s, p->flow, flags, alstate, p) != 1)
continue;
goto next;
}
/* if we get here but have no sigmatches to match against,
@ -800,6 +801,8 @@ int SigMatchSignatures(ThreadVars *th_v, DetectEngineCtx *de_ctx, DetectEngineTh
SCLogDebug("match functions done, sm %p", sm);
}
}
next:
RULE_PROFILING_END(s, match);
}
end:

@ -275,6 +275,9 @@ typedef struct Signature_ {
uint32_t mpm_pattern_id;
uint32_t mpm_uripattern_id;
#ifdef PROFILING
uint16_t profiling_id;
#endif
} Signature;
typedef struct DetectEngineIPOnlyThreadCtx_ {

@ -107,6 +107,7 @@
#include "util-rule-vars.h"
#include "util-classification-config.h"
#include "util-threshold-config.h"
#include "util-profiling.h"
#include "defrag.h"
@ -649,6 +650,9 @@ int main(int argc, char **argv)
SigParsePrepare();
//PatternMatchPrepare(mpm_ctx, MPM_B2G);
SCPerfInitCounterApi();
#ifdef PROFILING
SCProfilingInit();
#endif /* PROFILING */
SCReputationInitCtx();
TmModuleReceiveNFQRegister();
@ -759,6 +763,9 @@ int main(int argc, char **argv)
SCCudaRegisterTests();
#endif
PayloadRegisterTests();
#ifdef PROFILING
SCProfilingRegisterTests();
#endif
if (list_unittests) {
UtListTests(regex_arg);
}
@ -864,6 +871,10 @@ int main(int argc, char **argv)
exit(EXIT_FAILURE);
}
#ifdef PROFILING
SCProfilingInitRuleCounters(de_ctx);
#endif /* PROFILING */
AppLayerHtpRegisterExtraCallbacks();
SCThresholdConfInitContext(de_ctx,NULL);
@ -1045,6 +1056,12 @@ int main(int argc, char **argv)
OutputDeregisterAll();
TimeDeinit();
#ifdef PROFILING
if (profiling_rules_enabled)
SCProfilingDump(stdout);
SCProfilingDestroy();
#endif
#ifdef __SC_CUDA_SUPPORT__
/* all cuda contexts attached to any threads should be free by now.
* if any host_thread is still attached to any cuda_context, they need

@ -174,3 +174,21 @@ void UtilCpuPrintSummary() {
"system info and check util-cpu.{c,h}");
}
/**
* Get the current number of ticks from the CPU.
*/
uint64_t UtilCpuGetTicks(void)
{
uint64_t val;
#if defined(__GNUC__) && (defined(__x86_64) || defined(__i386))
uint32_t a, d;
__asm__ __volatile__ ("rdtsc" : "=a" (a), "=d" (d));
val = ((uint64_t)a) | (((uint64_t)d) << 32);
#else
#warning Using inferior version of UtilCpuGetTicks
struct timeval now;
gettimeofday(&now, NULL);
val = (now.tv_sec * 1000000) + now.tv_usec;
#endif
return val;
}

@ -34,4 +34,6 @@ uint16_t UtilCpuGetNumProcessorsMax();
void UtilCpuPrintSummary();
uint64_t UtilCpuGetTicks(void);
#endif /* __UTIL_CPU_H__ */

@ -0,0 +1,352 @@
/* Copyright (c) 2010 Open Information Security Foundation */
/**
* \file
* \author Endace Technology Limited.
*
* An API for profiling operations.
*
* Really just a wrapper around the existing perf counters.
*/
#include "suricata-common.h"
#include "detect.h"
#include "counters.h"
#include "conf.h"
#include "util-unittest.h"
#include "util-byte.h"
#include "util-profiling.h"
#ifdef PROFILING
#define MIN(a, b) (((a) < (b)) ? (a) : (b))
/**
* Sort orders for dumping profiled rules.
*/
enum {
SC_PROFILING_RULES_SORT_BY_TICKS = 0,
SC_PROFILING_RULES_SORT_BY_AVG_TICKS,
SC_PROFILING_RULES_SORT_BY_CHECKS,
SC_PROFILING_RULES_SORT_BY_MATCHES,
};
static int profiling_rules_sort_order = SC_PROFILING_RULES_SORT_BY_TICKS;
/**
* Maximum number of rules to dump.
*/
static uint32_t profiling_rules_limit = UINT32_MAX;
static SCPerfContext rules_ctx;
static SCPerfCounterArray *rules_pca;
/**
* Extra data for rule profiling.
*/
typedef struct SCProfileData_ {
uint64_t matches;
} SCProfileData;
SCProfileData rules_profile_data[0xffff];
/**
* Used for generating the summary data to print.
*/
typedef struct SCProfileSummary_ {
char *name;
uint64_t ticks;
double avgticks;
uint64_t checks;
uint64_t matches;
} SCProfileSummary;
int profiling_rules_enabled = 0;
/**
* \brief Initialize profiling.
*/
void
SCProfilingInit(void)
{
ConfNode *conf;
const char *val;
conf = ConfGetNode("profiling.rules");
if (conf == NULL) {
return;
}
if (ConfNodeChildValueIsTrue(conf, "enabled")) {
memset(rules_profile_data, 0, sizeof(rules_profile_data));
memset(&rules_ctx, 0, sizeof(rules_ctx));
rules_pca = SCPerfGetAllCountersArray(NULL);
if (SCMutexInit(&rules_ctx.m, NULL) != 0) {
SCLogError(SC_ERR_MEM_ALLOC,
"Failed to initialize hash table mutex.");
exit(EXIT_FAILURE);
}
profiling_rules_enabled = 1;
val = ConfNodeLookupChildValue(conf, "sort");
if (val != NULL) {
if (strcmp(val, "ticks") == 0) {
profiling_rules_sort_order =
SC_PROFILING_RULES_SORT_BY_TICKS;
}
else if (strcmp(val, "avgticks") == 0) {
profiling_rules_sort_order =
SC_PROFILING_RULES_SORT_BY_AVG_TICKS;
}
else if (strcmp(val, "checks") == 0) {
profiling_rules_sort_order =
SC_PROFILING_RULES_SORT_BY_CHECKS;
}
else if (strcmp(val, "matches") == 0) {
profiling_rules_sort_order =
SC_PROFILING_RULES_SORT_BY_MATCHES;
}
}
val = ConfNodeLookupChildValue(conf, "limit");
if (val != NULL) {
if (ByteExtractStringUint32(&profiling_rules_limit, 10,
(uint16_t)strlen(val), val) <= 0) {
SCLogError(SC_ERR_INVALID_ARGUMENT, "Invalid limit: %s", val);
exit(EXIT_FAILURE);
}
}
}
}
/**
* \brief Free resources used by profiling.
*/
void
SCProfilingDestroy(void)
{
if (profiling_rules_enabled) {
SCPerfReleasePerfCounterS(rules_ctx.head);
SCPerfReleasePCA(rules_pca);
}
}
/**
* \brief Qsort comparison function to sort by ticks.
*/
static int
SCProfileSummarySortByTicks(const void *a, const void *b)
{
const SCProfileSummary *s0 = a;
const SCProfileSummary *s1 = b;
return s1->ticks - s0->ticks;
}
/**
* \brief Qsort comparison function to sort by average ticks.
*/
static int
SCProfileSummarySortByAvgTicks(const void *a, const void *b)
{
const SCProfileSummary *s0 = a;
const SCProfileSummary *s1 = b;
return s1->avgticks - s0->avgticks;
}
/**
* \brief Qsort comparison function to sort by checks.
*/
static int
SCProfileSummarySortByChecks(const void *a, const void *b)
{
const SCProfileSummary *s0 = a;
const SCProfileSummary *s1 = b;
return s1->checks - s0->checks;
}
/**
* \brief Qsort comparison function to sort by matches.
*/
static int
SCProfileSummarySortByMatches(const void *a, const void *b)
{
const SCProfileSummary *s0 = a;
const SCProfileSummary *s1 = b;
return s1->matches - s0->matches;
}
void
SCProfilingDump(FILE *output)
{
uint32_t i;
SCProfileSummary summary[rules_pca->size];
uint32_t count = rules_pca->size;
SCLogInfo("Dumping profiling data.");
memset(summary, 0, sizeof(summary));
for (i = 1; i < count + 1; i++) {
summary[i - 1].name = rules_pca->head[i].pc->name->cname;
summary[i - 1].ticks = rules_pca->head[i].ui64_cnt;
if (rules_pca->head[i].ui64_cnt)
summary[i - 1].avgticks = (long double)rules_pca->head[i].ui64_cnt /
(long double)rules_pca->head[i].syncs;
summary[i - 1].checks = rules_pca->head[i].syncs;
summary[i - 1].matches = rules_profile_data[i].matches;
}
switch (profiling_rules_sort_order) {
case SC_PROFILING_RULES_SORT_BY_TICKS:
qsort(summary, count, sizeof(SCProfileSummary),
SCProfileSummarySortByTicks);
break;
case SC_PROFILING_RULES_SORT_BY_AVG_TICKS:
qsort(summary, count, sizeof(SCProfileSummary),
SCProfileSummarySortByAvgTicks);
break;
case SC_PROFILING_RULES_SORT_BY_CHECKS:
qsort(summary, count, sizeof(SCProfileSummary),
SCProfileSummarySortByChecks);
break;
case SC_PROFILING_RULES_SORT_BY_MATCHES:
qsort(summary, count, sizeof(SCProfileSummary),
SCProfileSummarySortByMatches);
break;
}
fprintf(output, " %-12s %-12s %-8s %-8s %-11s\n", "Rule", "Ticks", "Checks", "Matches", "Avg Ticks");
fprintf(output, " ------------ "
"------------ "
"-------- "
"-------- "
"----------- "
"\n");
for (i = 0; i < MIN(count, profiling_rules_limit); i++) {
fprintf(output, " %-12s %-12"PRIu64" %-8"PRIu64" %-8"PRIu64" %-8.2f\n",
summary[i].name,
summary[i].ticks,
summary[i].checks,
summary[i].matches,
summary[i].avgticks);
}
SCLogInfo("Done dumping profiling data.");
}
/**
* \brief Register a rule profiling counter.
*
* \param gid The GID of the rule.
* \param sid The SID of the rule.
*
* \retval Returns the ID of the counter on success, 0 on failure.
*/
static uint16_t
SCProfilingRegisterRuleCounter(Signature *sig)
{
char name[12];
uint16_t id;
/* Don't use GID right now... */
//snprintf(name, sizeof(name), "%"PRIu32":%"PRIu32, gid, sid);
snprintf(name, sizeof(name), "%"PRIu32, sig->id);
id = SCPerfRegisterCounter(name, "profiler", SC_PERF_TYPE_UINT64, NULL,
&rules_ctx);
return id;
}
/**
* \brief Register the rule profiling counters.
*
* \param de_ctx The active DetectEngineCtx, used to get at the loaded rules.
*/
void
SCProfilingInitRuleCounters(DetectEngineCtx *de_ctx)
{
Signature *sig = de_ctx->sig_list;
uint32_t count = 0;
while (sig != NULL) {
sig->profiling_id = SCProfilingRegisterRuleCounter(sig);
sig = sig->next;
count++;
}
rules_pca = SCPerfGetAllCountersArray(&rules_ctx);
SCLogInfo("Registered %"PRIu32" rule profiling counters.\n", count);
}
/**
* \brief Add a uint64_t value to the current value of the rule
* counter ID.
*
* \param id The ID of the rule profiling counter.
* \paral val The value to add to the counter.
*/
void
SCProfilingCounterAddUI64(uint16_t id, uint64_t val)
{
SCPerfCounterAddUI64(id, rules_pca, val);
}
/**
* \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
SCProfilingUpdateRuleCounter(uint16_t id, uint64_t ticks, int match)
{
SCMutexLock(&rules_ctx.m);
SCProfilingCounterAddUI64(id, ticks);
rules_profile_data[id].matches += match;
SCMutexUnlock(&rules_ctx.m);
}
#ifdef UNITTESTS
static int
ProfilingTest01(void)
{
uint16_t counter1;
Signature sig;
sig.gid = 1;
sig.id = 1;
SCProfilingInit();
counter1 = SCProfilingRegisterRuleCounter(&sig);
if (counter1 == 0)
return 0;
rules_pca = SCPerfGetAllCountersArray(&rules_ctx);
if (rules_pca == NULL)
return 0;
SCProfilingCounterAddUI64(counter1, 64);
if (rules_pca->head[counter1].ui64_cnt != 64)
return 0;
if (rules_pca->head[counter1].syncs != 1)
return 0;
SCProfilingCounterAddUI64(counter1, 64);
if (rules_pca->head[counter1].ui64_cnt != 128)
return 0;
if (rules_pca->head[counter1].syncs != 2)
return 0;
if (rules_pca->head[counter1].wrapped_syncs != 0)
return 0;
SCProfilingDump(stdout);
SCProfilingDestroy();
return 1;
}
#endif /* UNITTESTS */
void
SCProfilingRegisterTests(void)
{
#ifdef UNITTESTS
UtRegisterTest("ProfilingTest01", ProfilingTest01, 1);
#endif /* UNITTESTS */
}
#endif /* PROFILING */

@ -0,0 +1,39 @@
#ifndef __UTIL_PROFILE_H__
#define __UTIL_PROFILE_H__
#ifdef PROFILING
#include "util-cpu.h"
extern int profiling_rules_enabled;
#define PROFILING_START \
uint64_t profile_start_ = 0; \
uint64_t profile_end_ = 0; \
if (profiling_rules_enabled) { \
profile_start_ = UtilCpuGetTicks(); \
}
#define RULE_PROFILING_END(r, m) \
if (profiling_rules_enabled) { \
profile_end_ = UtilCpuGetTicks(); \
SCProfilingUpdateRuleCounter(r->profiling_id, \
profile_end_ - profile_start_, m); \
}
void SCProfilingInit(void);
void SCProfilingDestroy(void);
void SCProfilingInitRuleCounters(DetectEngineCtx *);
void SCProfilingCounterAddUI64(uint16_t, uint64_t);
void SCProfilingRegisterTests(void);
void SCProfilingDump(FILE *);
void SCProfilingUpdateRuleCounter(uint16_t, uint64_t, int);
#else
#define PROFILING_START
#define RULE_PROFILING_END(r, m)
#endif /* PROFILING */
#endif /* ! __UTIL_PROFILE_H__ */

@ -444,3 +444,16 @@ libhtp:
- 192.168.10.0/24
personality: IIS_7_0
profiling:
rules:
# Profiling can be disabled here, but it will still have a
# performance impact if compiled in.
enabled: yes
# Sort options: ticks, avgticks, checks, matches
sort: avgticks
# Limit the number of items printed at exit.
limit: 100

Loading…
Cancel
Save