profiling: add per lock location profiling

Add profiling per lock location in the code. Accounts how often a
lock is requested, how often it was contended, the max number of
ticks spent waiting for it, avg number of ticks waiting for it and
the total ticks for that location.

Added a new configure flag --enable-profiling-locks to enable this
feature.
remotes/origin/master
Victor Julien 14 years ago
parent 41e9dba20b
commit d908e707d7

@ -284,6 +284,13 @@ AC_INIT(configure.in)
CFLAGS="${CFLAGS} -DPROFILING" CFLAGS="${CFLAGS} -DPROFILING"
]) ])
# profiling support, locking
AC_ARG_ENABLE(profiling-locks,
AS_HELP_STRING([--enable-profiling-locks], [Enable performance profiling for locks]),,[enable_profiling_locks=no])
AS_IF([test "x$enable_profiling_locks" = "xyes"], [
CFLAGS="${CFLAGS} -DPROFILING -DPROFILE_LOCKING"
])
# enable support for IPFW # enable support for IPFW
AC_ARG_ENABLE(ipfw, AC_ARG_ENABLE(ipfw,
AS_HELP_STRING([--enable-ipfw], [Enable FreeBSD IPFW support for inline IDP]),,[enable_ipfw=no]) AS_HELP_STRING([--enable-ipfw], [Enable FreeBSD IPFW support for inline IDP]),,[enable_ipfw=no])
@ -1258,6 +1265,7 @@ Suricata Configuration:
Debug output enabled: ${enable_debug} Debug output enabled: ${enable_debug}
Debug validation enabled: ${enable_debug_validation} Debug validation enabled: ${enable_debug_validation}
Profiling enabled: ${enable_profiling} Profiling enabled: ${enable_profiling}
Profiling locks enabled: ${enable_profiling_locks}
Generic build parameters: Generic build parameters:
Installation prefix (--prefix): ${prefix} Installation prefix (--prefix): ${prefix}

@ -288,6 +288,7 @@ win32-service.c win32-service.h \
util-action.c util-action.h \ util-action.c util-action.h \
win32-syslog.h \ win32-syslog.h \
util-profiling.c util-profiling.h \ util-profiling.c util-profiling.h \
util-profiling-locks.c util-profiling-locks.h \
cuda-packet-batcher.c cuda-packet-batcher.h \ cuda-packet-batcher.c cuda-packet-batcher.h \
util-ioctl.h util-ioctl.c \ util-ioctl.h util-ioctl.c \
util-logopenfile.h util-logopenfile.c util-logopenfile.h util-logopenfile.c

@ -284,12 +284,20 @@ typedef struct PktVar_ {
typedef struct PktProfilingTmmData_ { typedef struct PktProfilingTmmData_ {
uint64_t ticks_start; uint64_t ticks_start;
uint64_t ticks_end; uint64_t ticks_end;
#ifdef PROFILE_LOCKING
uint64_t mutex_lock_cnt; uint64_t mutex_lock_cnt;
uint64_t mutex_lock_wait_ticks; uint64_t mutex_lock_wait_ticks;
uint64_t mutex_lock_contention; uint64_t mutex_lock_contention;
uint64_t spin_lock_cnt; uint64_t spin_lock_cnt;
uint64_t spin_lock_wait_ticks; uint64_t spin_lock_wait_ticks;
uint64_t spin_lock_contention; uint64_t spin_lock_contention;
uint64_t rww_lock_cnt;
uint64_t rww_lock_wait_ticks;
uint64_t rww_lock_contention;
uint64_t rwr_lock_cnt;
uint64_t rwr_lock_wait_ticks;
uint64_t rwr_lock_contention;
#endif
} PktProfilingTmmData; } PktProfilingTmmData;
typedef struct PktProfilingDetectData_ { typedef struct PktProfilingDetectData_ {

@ -30,8 +30,6 @@
#define DBG_PERF #define DBG_PERF
#endif #endif
//#define PROFILE_LOCKING
#define TRUE 1 #define TRUE 1
#define FALSE 0 #define FALSE 0

@ -559,6 +559,12 @@ void SCPrintBuildInfo(void) {
#endif #endif
#ifdef HAVE_NSS #ifdef HAVE_NSS
strlcat(features, "HAVE_NSS ", sizeof(features)); strlcat(features, "HAVE_NSS ", sizeof(features));
#endif
#ifdef PROFILING
strlcat(features, "PROFILING ", sizeof(features));
#endif
#ifdef PROFILE_LOCKING
strlcat(features, "PROFILE_LOCKING ", sizeof(features));
#endif #endif
if (strlen(features) == 0) { if (strlen(features) == 0) {
strlcat(features, "none", sizeof(features)); strlcat(features, "none", sizeof(features));

@ -29,6 +29,7 @@
#ifdef PROFILING #ifdef PROFILING
#include "util-cpu.h" #include "util-cpu.h"
#include "util-profiling-locks.h"
#endif #endif
#if defined OS_FREEBSD || __OpenBSD__ #if defined OS_FREEBSD || __OpenBSD__
@ -231,6 +232,19 @@ enum {
#define SCMutexInit(mut, mutattr ) pthread_mutex_init(mut, mutattr) #define SCMutexInit(mut, mutattr ) pthread_mutex_init(mut, mutattr)
#define SCMutexUnlock(mut) pthread_mutex_unlock(mut) #define SCMutexUnlock(mut) pthread_mutex_unlock(mut)
typedef struct ProfilingLock_ {
char *file;
char *func;
int line;
int type;
uint32_t cont;
uint64_t ticks;
} ProfilingLock;
extern __thread ProfilingLock locks[PROFILING_MAX_LOCKS];
extern __thread int locks_idx;
extern __thread int record_locks;
extern __thread uint64_t mutex_lock_contention; extern __thread uint64_t mutex_lock_contention;
extern __thread uint64_t mutex_lock_wait_ticks; extern __thread uint64_t mutex_lock_wait_ticks;
extern __thread uint64_t mutex_lock_cnt; extern __thread uint64_t mutex_lock_cnt;
@ -239,13 +253,25 @@ extern __thread uint64_t mutex_lock_cnt;
#define SCMutexLock_profile(mut) ({ \ #define SCMutexLock_profile(mut) ({ \
mutex_lock_cnt++; \ mutex_lock_cnt++; \
int retl = 0; \ int retl = 0; \
int cont = 0; \
uint64_t mutex_lock_start = UtilCpuGetTicks(); \ uint64_t mutex_lock_start = UtilCpuGetTicks(); \
if (pthread_mutex_trylock((mut)) != 0) { \ if (pthread_mutex_trylock((mut)) != 0) { \
mutex_lock_contention++; \ mutex_lock_contention++; \
cont = 1; \
retl = pthread_mutex_lock(mut); \ retl = pthread_mutex_lock(mut); \
} \ } \
uint64_t mutex_lock_end = UtilCpuGetTicks(); \ uint64_t mutex_lock_end = UtilCpuGetTicks(); \
mutex_lock_wait_ticks += (uint64_t)(mutex_lock_end - mutex_lock_start); \ mutex_lock_wait_ticks += (uint64_t)(mutex_lock_end - mutex_lock_start); \
\
if (locks_idx < PROFILING_MAX_LOCKS && record_locks) { \
locks[locks_idx].file = (char *)__FILE__; \
locks[locks_idx].func = (char *)__func__; \
locks[locks_idx].line = (int)__LINE__; \
locks[locks_idx].type = LOCK_MUTEX; \
locks[locks_idx].cont = cont; \
locks[locks_idx].ticks = (uint64_t)(mutex_lock_end - mutex_lock_start); \
locks_idx++; \
} \
retl; \ retl; \
}) })
@ -401,13 +427,25 @@ extern __thread uint64_t spin_lock_cnt;
#define SCSpinLock_profile(spin) ({ \ #define SCSpinLock_profile(spin) ({ \
spin_lock_cnt++; \ spin_lock_cnt++; \
int retl = 0; \ int retl = 0; \
int cont = 0; \
uint64_t spin_lock_start = UtilCpuGetTicks(); \ uint64_t spin_lock_start = UtilCpuGetTicks(); \
if (pthread_spin_trylock((spin)) != 0) { \ if (pthread_spin_trylock((spin)) != 0) { \
spin_lock_contention++; \ spin_lock_contention++; \
cont = 1; \
retl = pthread_spin_lock((spin)); \ retl = pthread_spin_lock((spin)); \
} \ } \
uint64_t spin_lock_end = UtilCpuGetTicks(); \ uint64_t spin_lock_end = UtilCpuGetTicks(); \
spin_lock_wait_ticks += (uint64_t)(spin_lock_end - spin_lock_start); \ spin_lock_wait_ticks += (uint64_t)(spin_lock_end - spin_lock_start); \
\
if (locks_idx < PROFILING_MAX_LOCKS && record_locks) { \
locks[locks_idx].file = (char *)__FILE__; \
locks[locks_idx].func = (char *)__func__; \
locks[locks_idx].line = (int)__LINE__; \
locks[locks_idx].type = LOCK_SPIN; \
locks[locks_idx].cont = cont; \
locks[locks_idx].ticks = (uint64_t)(spin_lock_end - spin_lock_start); \
locks_idx++; \
} \
retl; \ retl; \
}) })
@ -585,6 +623,73 @@ extern __thread uint64_t spin_lock_cnt;
#define SCRWLockTryWRLock(rwl) SCRWLockTryWRLock_dbg(rwl) #define SCRWLockTryWRLock(rwl) SCRWLockTryWRLock_dbg(rwl)
#define SCRWLockTryRDLock(rwl) SCRWLockTryRDLock_dbg(rwl) #define SCRWLockTryRDLock(rwl) SCRWLockTryRDLock_dbg(rwl)
#define SCRWLockUnlock(rwl) SCRWLockUnlock_dbg(rwl) #define SCRWLockUnlock(rwl) SCRWLockUnlock_dbg(rwl)
#elif defined PROFILE_LOCKING
#define SCRWLockInit(rwl, rwlattr ) pthread_rwlock_init(rwl, rwlattr)
#define SCRWLockUnlock(rwl) pthread_rwlock_unlock(rwl)
extern __thread uint64_t rww_lock_contention;
extern __thread uint64_t rww_lock_wait_ticks;
extern __thread uint64_t rww_lock_cnt;
#define SCRWLockWRLock_profile(mut) ({ \
rww_lock_cnt++; \
int retl = 0; \
int cont = 0; \
uint64_t rww_lock_start = UtilCpuGetTicks(); \
if (pthread_rwlock_trywrlock((mut)) != 0) { \
rww_lock_contention++; \
cont = 1; \
retl = pthread_rwlock_wrlock(mut); \
} \
uint64_t rww_lock_end = UtilCpuGetTicks(); \
rww_lock_wait_ticks += (uint64_t)(rww_lock_end - rww_lock_start); \
\
if (locks_idx < PROFILING_MAX_LOCKS && record_locks) { \
locks[locks_idx].file = (char *)__FILE__; \
locks[locks_idx].func = (char *)__func__; \
locks[locks_idx].line = (int)__LINE__; \
locks[locks_idx].type = LOCK_RWW; \
locks[locks_idx].cont = cont; \
locks[locks_idx].ticks = (uint64_t)(rww_lock_end - rww_lock_start); \
locks_idx++; \
} \
retl; \
})
extern __thread uint64_t rwr_lock_contention;
extern __thread uint64_t rwr_lock_wait_ticks;
extern __thread uint64_t rwr_lock_cnt;
#define SCRWLockRDLock_profile(mut) ({ \
rwr_lock_cnt++; \
int retl = 0; \
int cont = 0; \
uint64_t rwr_lock_start = UtilCpuGetTicks(); \
if (pthread_rwlock_tryrdlock((mut)) != 0) { \
rwr_lock_contention++; \
cont = 1; \
retl = pthread_rwlock_rdlock(mut); \
} \
uint64_t rwr_lock_end = UtilCpuGetTicks(); \
rwr_lock_wait_ticks += (uint64_t)(rwr_lock_end - rwr_lock_start); \
\
if (locks_idx < PROFILING_MAX_LOCKS && record_locks) { \
locks[locks_idx].file = (char *)__FILE__; \
locks[locks_idx].func = (char *)__func__; \
locks[locks_idx].line = (int)__LINE__; \
locks[locks_idx].type = LOCK_RWR; \
locks[locks_idx].cont = cont; \
locks[locks_idx].ticks = (uint64_t)(rwr_lock_end - rwr_lock_start); \
locks_idx++; \
} \
retl; \
})
#define SCRWLockWRLock(mut) SCRWLockWRLock_profile(mut)
#define SCRWLockRDLock(mut) SCRWLockRDLock_profile(mut)
#define SCRWLockTryWRLock(rwl) pthread_rwlock_trywrlock(rwl)
#define SCRWLockTryRDLock(rwl) pthread_rwlock_tryrdlock(rwl)
#else #else
#define SCRWLockInit(rwl, rwlattr ) pthread_rwlock_init(rwl, rwlattr) #define SCRWLockInit(rwl, rwlattr ) pthread_rwlock_init(rwl, rwlattr)
#define SCRWLockWRLock(rwl) pthread_rwlock_wrlock(rwl) #define SCRWLockWRLock(rwl) pthread_rwlock_wrlock(rwl)

@ -51,6 +51,14 @@ __thread uint64_t mutex_lock_cnt;
__thread uint64_t spin_lock_contention; __thread uint64_t spin_lock_contention;
__thread uint64_t spin_lock_wait_ticks; __thread uint64_t spin_lock_wait_ticks;
__thread uint64_t spin_lock_cnt; __thread uint64_t spin_lock_cnt;
__thread uint64_t rww_lock_contention;
__thread uint64_t rww_lock_wait_ticks;
__thread uint64_t rww_lock_cnt;
__thread uint64_t rwr_lock_contention;
__thread uint64_t rwr_lock_wait_ticks;
__thread uint64_t rwr_lock_cnt;
#endif #endif
#ifdef OS_FREEBSD #ifdef OS_FREEBSD

@ -222,6 +222,7 @@ const char * SCErrorToString(SCError err)
CASE_CODE (SC_ERR_PCAP_TRANSLATE); CASE_CODE (SC_ERR_PCAP_TRANSLATE);
CASE_CODE (SC_WARN_OUTDATED_LIBHTP); CASE_CODE (SC_WARN_OUTDATED_LIBHTP);
CASE_CODE (SC_WARN_DEPRECATED); CASE_CODE (SC_WARN_DEPRECATED);
CASE_CODE (SC_WARN_PROFILE);
default: default:
return "UNKNOWN_ERROR"; return "UNKNOWN_ERROR";

@ -237,6 +237,7 @@ typedef enum {
SC_ERR_PCAP_TRANSLATE, /* failed to translate ip to dev */ SC_ERR_PCAP_TRANSLATE, /* failed to translate ip to dev */
SC_WARN_OUTDATED_LIBHTP, SC_WARN_OUTDATED_LIBHTP,
SC_WARN_DEPRECATED, SC_WARN_DEPRECATED,
SC_WARN_PROFILE,
} SCError; } SCError;
const char *SCErrorToString(SCError); const char *SCErrorToString(SCError);

@ -0,0 +1,233 @@
/* Copyright (C) 2007-2012 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 Victor Julien <victor@inliniac.net>
*
* An API for profiling locks.
*
*/
#ifdef PROFILING
#ifdef PROFILE_LOCKING
#include "suricata-common.h"
#include "util-profiling-locks.h"
#include "util-hashlist.h"
__thread ProfilingLock locks[PROFILING_MAX_LOCKS];
__thread int locks_idx = 0;
__thread int record_locks = 0;
int profiling_locks_enabled = 0;
int profiling_locks_output_to_file = 0;
char *profiling_locks_file_name = NULL;
char *profiling_locks_file_mode = NULL;
typedef struct LockRecord_ {
char *file; // hash
char *func; // info
int type; // info
int line; // hash
uint32_t cont;
uint32_t ticks_cnt;
uint64_t ticks_total;
uint64_t ticks_max;
} LockRecord;
HashListTable *lock_records;
pthread_mutex_t lock_records_mutex;
static uint32_t LockRecordHash(HashListTable *ht, void *buf, uint16_t buflen) {
LockRecord *fn = (LockRecord *)buf;
uint32_t hash = strlen(fn->file) + fn->line;
uint16_t u;
for (u = 0; u < strlen(fn->file); u++) {
hash += fn->file[u];
}
return hash % ht->array_size;
}
static char LockRecordCompare(void *buf1, uint16_t len1, void *buf2, uint16_t len2) {
LockRecord *fn1 = (LockRecord *)buf1;
LockRecord *fn2 = (LockRecord *)buf2;
if (fn1->line != fn2->line)
return 0;
if (fn1->file == fn2->file)
return 1;
return 0;
}
static void LockRecordFree(void *data) {
LockRecord *fn = (LockRecord *)data;
if (fn == NULL)
return;
SCFree(fn);
}
int LockRecordInitHash() {
pthread_mutex_init(&lock_records_mutex, NULL);
pthread_mutex_lock(&lock_records_mutex);
lock_records = HashListTableInit(512, LockRecordHash, LockRecordCompare, LockRecordFree);
BUG_ON(lock_records == NULL);
pthread_mutex_unlock(&lock_records_mutex);
return 0;
}
void LockRecordAdd(ProfilingLock *l) {
LockRecord fn = { NULL, NULL, 0,0,0,0,0,0}, *ptr = &fn;
fn.file = l->file;
fn.line = l->line;
LockRecord *lookup_fn = (LockRecord *)HashListTableLookup(lock_records, (void *)ptr, 0);
if (lookup_fn == NULL) {
LockRecord *new = SCMalloc(sizeof(LockRecord));
BUG_ON(new == NULL);
new->file = l->file;
new->line = l->line;
new->type = l->type;
new->cont = l->cont;
new->func = l->func;
new->ticks_max = l->ticks;
new->ticks_total = l->ticks;
new->ticks_cnt = 1;
HashListTableAdd(lock_records, (void *)new, 0);
} else {
lookup_fn->ticks_total += l->ticks;
if (l->ticks > lookup_fn->ticks_max)
lookup_fn->ticks_max = l->ticks;
lookup_fn->ticks_cnt++;
lookup_fn->cont += l->cont;
}
return;
}
/** \param p void ptr to Packet struct */
void SCProfilingAddPacketLocks(void *p) {
int i;
for (i = 0; i < locks_idx; i++) {
pthread_mutex_lock(&lock_records_mutex);
LockRecordAdd(&locks[i]);
pthread_mutex_unlock(&lock_records_mutex);
}
}
void SCProfilingListLocks(void) {
FILE *fp = NULL;
if (profiling_locks_output_to_file == 1) {
if (strcasecmp(profiling_locks_file_mode, "yes") == 0) {
fp = fopen(profiling_locks_file_name, "a");
} else {
fp = fopen(profiling_locks_file_name, "w");
}
if (fp == NULL) {
SCLogError(SC_ERR_FOPEN, "failed to open %s: %s",
profiling_locks_file_name, strerror(errno));
return;
}
} else {
fp = stdout;
}
fprintf(fp, "\n\nLock Cnt Avg ticks Max ticks Total ticks Cont Func\n");
fprintf(fp, "------------------ ---------- --------- ------------ ------------ ------- ---------\n");
uint64_t total = 0;
uint32_t cont = 0;
uint64_t cnt = 0;
HashListTableBucket *b = HashListTableGetListHead(lock_records);
while (b) {
LockRecord *r = HashListTableGetListData(b);
char *lock;
switch (r->type) {
case LOCK_MUTEX:
lock = "mtx";
break;
case LOCK_SPIN:
lock = "spn";
break;
case LOCK_RWW:
lock = "rww";
break;
case LOCK_RWR:
lock = "rwr";
break;
default:
lock = "bug";
break;
}
char str[128] = "";
snprintf(str, sizeof(str), "(%s) %s:%d", lock,r->file, r->line);
fprintf(fp, "%-50s %-10u %-9u %-12"PRIu64" %-12"PRIu64" %-7u %-s\n",
str, r->ticks_cnt, (int)r->ticks_total/r->ticks_cnt, r->ticks_max, r->ticks_total, r->cont, r->func);
total += r->ticks_total;
cnt += r->ticks_cnt;
cont += r->cont;
b = HashListTableGetListNext(b);
}
fprintf(fp, "\nOverall: locks %"PRIu64", average cost %"PRIu64", contentions %"PRIu32", total ticks %"PRIu64"\n",
cnt, total/cnt, cont, total);
fclose(fp);
}
void LockRecordFreeHash() {
if (profiling_locks_enabled == 0)
return;
pthread_mutex_lock(&lock_records_mutex);
SCProfilingListLocks();
if (lock_records != NULL) {
HashListTableFree(lock_records);
lock_records = NULL;
}
pthread_mutex_unlock(&lock_records_mutex);
pthread_mutex_destroy(&lock_records_mutex);
}
#endif
#endif

@ -0,0 +1,45 @@
/* Copyright (C) 2007-2012 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 Victor Julien <victor@inliniac.net>
*/
#ifndef __UTIL_PROFILE_LOCKS_H__
#define __UTIL_PROFILE_LOCKS_H__
#ifdef PROFILING
#define PROFILING_MAX_LOCKS 64
enum {
LOCK_MUTEX,
LOCK_SPIN,
LOCK_RWW, /**< rwlock, writer */
LOCK_RWR, /**< rwlock, reader */
};
void SCProfilingAddPacketLocks(void *);
int LockRecordInitHash();
void LockRecordFreeHash();
#endif /* PROFILING */
#endif /* __UTIL_PROFILE_LOCKS_H__ */

@ -1,4 +1,4 @@
/* Copyright (C) 2007-2011 Open Information Security Foundation /* Copyright (C) 2007-2012 Open Information Security Foundation
* *
* You can copy, redistribute or modify this Program under the terms of * You can copy, redistribute or modify this Program under the terms of
* the GNU General Public License version 2 as published by the Free * the GNU General Public License version 2 as published by the Free
@ -27,7 +27,7 @@
*/ */
#include "suricata-common.h" #include "suricata-common.h"
#include "decode.h"
#include "detect.h" #include "detect.h"
#include "counters.h" #include "counters.h"
#include "conf.h" #include "conf.h"
@ -37,6 +37,7 @@
#include "util-unittest.h" #include "util-unittest.h"
#include "util-byte.h" #include "util-byte.h"
#include "util-profiling.h" #include "util-profiling.h"
#include "util-profiling-locks.h"
#ifdef PROFILING #ifdef PROFILING
@ -66,9 +67,14 @@ static uint32_t profiling_rules_limit = UINT32_MAX;
static SCPerfContext rules_ctx; static SCPerfContext rules_ctx;
static SCPerfCounterArray *rules_pca; static SCPerfCounterArray *rules_pca;
static SCMutex packet_profile_lock; static pthread_mutex_t packet_profile_lock;
static FILE *packet_profile_csv_fp = NULL; static FILE *packet_profile_csv_fp = NULL;
extern int profiling_locks_enabled;
extern int profiling_locks_output_to_file;
extern char *profiling_locks_file_name;
extern char *profiling_locks_file_mode;
/** /**
* Extra data for rule profiling. * Extra data for rule profiling.
*/ */
@ -166,7 +172,7 @@ SCProfilingInit(void)
memset(rules_profile_data, 0, sizeof(rules_profile_data)); memset(rules_profile_data, 0, sizeof(rules_profile_data));
memset(&rules_ctx, 0, sizeof(rules_ctx)); memset(&rules_ctx, 0, sizeof(rules_ctx));
rules_pca = SCPerfGetAllCountersArray(NULL); rules_pca = SCPerfGetAllCountersArray(NULL);
if (SCMutexInit(&rules_ctx.m, NULL) != 0) { if (pthread_mutex_init(&rules_ctx.m, NULL) != 0) {
SCLogError(SC_ERR_MUTEX, SCLogError(SC_ERR_MUTEX,
"Failed to initialize hash table mutex."); "Failed to initialize hash table mutex.");
exit(EXIT_FAILURE); exit(EXIT_FAILURE);
@ -242,7 +248,7 @@ SCProfilingInit(void)
if (ConfNodeChildValueIsTrue(conf, "enabled")) { if (ConfNodeChildValueIsTrue(conf, "enabled")) {
profiling_packets_enabled = 1; profiling_packets_enabled = 1;
if (SCMutexInit(&packet_profile_lock, NULL) != 0) { if (pthread_mutex_init(&packet_profile_lock, NULL) != 0) {
SCLogError(SC_ERR_MUTEX, SCLogError(SC_ERR_MUTEX,
"Failed to initialize packet profiling mutex."); "Failed to initialize packet profiling mutex.");
exit(EXIT_FAILURE); exit(EXIT_FAILURE);
@ -319,6 +325,36 @@ SCProfilingInit(void)
} }
} }
} }
conf = ConfGetNode("profiling.locks");
if (conf != NULL) {
if (ConfNodeChildValueIsTrue(conf, "enabled")) {
#ifndef PROFILE_LOCKING
SCLogWarning(SC_WARN_PROFILE, "lock profiling not compiled in. Add --enable-profiling-locks to configure.");
#else
profiling_locks_enabled = 1;
LockRecordInitHash();
const char *filename = ConfNodeLookupChildValue(conf, "filename");
if (filename != NULL) {
char *log_dir;
if (ConfGet("default-log-dir", &log_dir) != 1)
log_dir = DEFAULT_LOG_DIR;
profiling_locks_file_name = SCMalloc(PATH_MAX);
snprintf(profiling_locks_file_name, PATH_MAX, "%s/%s", log_dir, filename);
profiling_locks_file_mode = (char *)ConfNodeLookupChildValue(conf, "append");
if (profiling_locks_file_mode == NULL)
profiling_locks_file_mode = DEFAULT_LOG_MODE_APPEND;
profiling_locks_output_to_file = 1;
}
#endif
}
}
} }
/** /**
@ -330,11 +366,11 @@ SCProfilingDestroy(void)
if (profiling_rules_enabled) { if (profiling_rules_enabled) {
SCPerfReleasePerfCounterS(rules_ctx.head); SCPerfReleasePerfCounterS(rules_ctx.head);
SCPerfReleasePCA(rules_pca); SCPerfReleasePCA(rules_pca);
SCMutexDestroy(&rules_ctx.m); pthread_mutex_destroy(&rules_ctx.m);
} }
if (profiling_packets_enabled) { if (profiling_packets_enabled) {
SCMutexDestroy(&packet_profile_lock); pthread_mutex_destroy(&packet_profile_lock);
} }
if (profiling_packets_csv_enabled) { if (profiling_packets_csv_enabled) {
@ -347,6 +383,10 @@ SCProfilingDestroy(void)
if (profiling_file_name != NULL) if (profiling_file_name != NULL)
SCFree(profiling_file_name); SCFree(profiling_file_name);
#ifdef PROFILE_LOCKING
LockRecordFreeHash();
#endif
} }
/** /**
@ -651,7 +691,7 @@ SCProfilingCounterAddUI64(uint16_t id, uint64_t val)
void void
SCProfilingUpdateRuleCounter(uint16_t id, uint64_t ticks, int match) SCProfilingUpdateRuleCounter(uint16_t id, uint64_t ticks, int match)
{ {
SCMutexLock(&rules_ctx.m); pthread_mutex_lock(&rules_ctx.m);
SCProfilingCounterAddUI64(id, ticks); SCProfilingCounterAddUI64(id, ticks);
rules_profile_data[id].matches += match; rules_profile_data[id].matches += match;
if (ticks > rules_profile_data[id].max) if (ticks > rules_profile_data[id].max)
@ -661,7 +701,7 @@ SCProfilingUpdateRuleCounter(uint16_t id, uint64_t ticks, int match)
else else
rules_profile_data[id].ticks_no_match += ticks; rules_profile_data[id].ticks_no_match += ticks;
SCMutexUnlock(&rules_ctx.m); pthread_mutex_unlock(&rules_ctx.m);
} }
void SCProfilingDumpPacketStats(void) { void SCProfilingDumpPacketStats(void) {
@ -1074,7 +1114,7 @@ void SCProfilingAddPacket(Packet *p) {
if (p->profile.ticks_start == 0 || p->profile.ticks_end == 0 || p->profile.ticks_start > p->profile.ticks_end) if (p->profile.ticks_start == 0 || p->profile.ticks_end == 0 || p->profile.ticks_start > p->profile.ticks_end)
return; return;
SCMutexLock(&packet_profile_lock); pthread_mutex_lock(&packet_profile_lock);
{ {
if (profiling_packets_csv_enabled) if (profiling_packets_csv_enabled)
@ -1145,7 +1185,7 @@ void SCProfilingAddPacket(Packet *p) {
SCProfilingUpdatePacketDetectRecords(p); SCProfilingUpdatePacketDetectRecords(p);
} }
} }
SCMutexUnlock(&packet_profile_lock); pthread_mutex_unlock(&packet_profile_lock);
} }
#define CASE_CODE(E) case E: return #E #define CASE_CODE(E) case E: return #E
@ -1184,6 +1224,9 @@ const char * PacketProfileDetectIdToString(PacketProfileDetectId id)
return "UNKNOWN"; return "UNKNOWN";
} }
} }
#ifdef UNITTESTS #ifdef UNITTESTS
static int static int

@ -1,4 +1,4 @@
/* Copyright (C) 2007-2011 Open Information Security Foundation /* Copyright (C) 2007-2012 Open Information Security Foundation
* *
* You can copy, redistribute or modify this Program under the terms of * You can copy, redistribute or modify this Program under the terms of
* the GNU General Public License version 2 as published by the Free * the GNU General Public License version 2 as published by the Free
@ -27,6 +27,7 @@
#ifdef PROFILING #ifdef PROFILING
#include "util-profiling-locks.h"
#include "util-cpu.h" #include "util-cpu.h"
extern int profiling_rules_enabled; extern int profiling_rules_enabled;
@ -75,6 +76,14 @@ void SCProfilingAddPacket(Packet *);
spin_lock_cnt = 0; \ spin_lock_cnt = 0; \
spin_lock_wait_ticks = 0; \ spin_lock_wait_ticks = 0; \
spin_lock_contention = 0; \ spin_lock_contention = 0; \
rww_lock_cnt = 0; \
rww_lock_wait_ticks = 0; \
rww_lock_contention = 0; \
rwr_lock_cnt = 0; \
rwr_lock_wait_ticks = 0; \
rwr_lock_contention = 0; \
locks_idx = 0; \
record_locks = 1;\
} while (0) } while (0)
#define PACKET_PROFILING_COPY_LOCKS(p, id) do { \ #define PACKET_PROFILING_COPY_LOCKS(p, id) do { \
@ -84,6 +93,14 @@ void SCProfilingAddPacket(Packet *);
(p)->profile.tmm[(id)].spin_lock_cnt = spin_lock_cnt; \ (p)->profile.tmm[(id)].spin_lock_cnt = spin_lock_cnt; \
(p)->profile.tmm[(id)].spin_lock_wait_ticks = spin_lock_wait_ticks; \ (p)->profile.tmm[(id)].spin_lock_wait_ticks = spin_lock_wait_ticks; \
(p)->profile.tmm[(id)].spin_lock_contention = spin_lock_contention; \ (p)->profile.tmm[(id)].spin_lock_contention = spin_lock_contention; \
(p)->profile.tmm[(id)].rww_lock_cnt = rww_lock_cnt; \
(p)->profile.tmm[(id)].rww_lock_wait_ticks = rww_lock_wait_ticks; \
(p)->profile.tmm[(id)].rww_lock_contention = rww_lock_contention; \
(p)->profile.tmm[(id)].rwr_lock_cnt = rwr_lock_cnt; \
(p)->profile.tmm[(id)].rwr_lock_wait_ticks = rwr_lock_wait_ticks; \
(p)->profile.tmm[(id)].rwr_lock_contention = rwr_lock_contention; \
record_locks = 0;\
SCProfilingAddPacketLocks((p)); \
} while(0) } while(0)
#else #else
#define PACKET_PROFILING_RESET_LOCKS #define PACKET_PROFILING_RESET_LOCKS

@ -872,6 +872,13 @@ profiling:
enabled: no enabled: no
filename: packet_stats.csv filename: packet_stats.csv
# profiling of locking. Only available when Suricata was built with
# --enable-profiling-locks.
locks:
enabled: no
filename: lock_stats.log
append: yes
# Suricata core dump configuration. Limits the size of the core dump file to # Suricata core dump configuration. Limits the size of the core dump file to
# approximately max-dump. The actual core dump size will be a multiple of the # approximately max-dump. The actual core dump size will be a multiple of the
# page size. Core dumps that would be larger than max-dump are truncated. On # page size. Core dumps that would be larger than max-dump are truncated. On

Loading…
Cancel
Save