suricata
util-profiling-rulegroups.c
Go to the documentation of this file.
1 /* Copyright (C) 2007-2015 Open Information Security Foundation
2  *
3  * You can copy, redistribute or modify this Program under the terms of
4  * the GNU General Public License version 2 as published by the Free
5  * Software Foundation.
6  *
7  * This program is distributed in the hope that it will be useful,
8  * but WITHOUT ANY WARRANTY; without even the implied warranty of
9  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
10  * GNU General Public License for more details.
11  *
12  * You should have received a copy of the GNU General Public License
13  * version 2 along with this program; if not, write to the Free Software
14  * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
15  * 02110-1301, USA.
16  */
17 
18 /**
19  * \file
20  *
21  * \author Endace Technology Limited.
22  * \author Victor Julien <victor@inliniac.net>
23  *
24  * An API for rule profiling operations.
25  */
26 
27 #include "suricata-common.h"
28 #include "decode.h"
29 #include "detect.h"
30 #include "detect-engine.h"
31 #include "conf.h"
32 
33 #include "tm-threads.h"
34 
35 #include "util-unittest.h"
36 #include "util-byte.h"
37 #include "util-profiling.h"
38 #include "util-profiling-locks.h"
39 
40 #ifdef PROFILING
41 
42 /**
43  * Extra data for rule profiling.
44  */
45 typedef struct SCProfileSghData_ {
46  uint64_t checks;
47 
48  uint64_t non_mpm_generic;
49  uint64_t non_mpm_syn;
50 
53 
56 
58 
59 typedef struct SCProfileSghDetectCtx_ {
60  uint32_t cnt;
62  pthread_mutex_t data_m;
64 
65 static int profiling_sghs_output_to_file = 0;
67 static char profiling_file_name[PATH_MAX];
68 static const char *profiling_file_mode = "a";
69 #ifdef HAVE_LIBJANSSON
70 static int profiling_rulegroup_json = 0;
71 #endif
72 
74 {
75  ConfNode *conf;
76 
77  conf = ConfGetNode("profiling.rulegroups");
78  if (conf != NULL) {
79  if (ConfNodeChildValueIsTrue(conf, "enabled")) {
81  const char *filename = ConfNodeLookupChildValue(conf, "filename");
82  if (filename != NULL) {
83  const char *log_dir;
84  log_dir = ConfigGetLogDirectory();
85 
86  snprintf(profiling_file_name, sizeof(profiling_file_name),
87  "%s/%s", log_dir, filename);
88 
89  const char *v = ConfNodeLookupChildValue(conf, "append");
90  if (v == NULL || ConfValIsTrue(v)) {
91  profiling_file_mode = "a";
92  } else {
93  profiling_file_mode = "w";
94  }
95 
96  profiling_sghs_output_to_file = 1;
97  }
98  if (ConfNodeChildValueIsTrue(conf, "json")) {
99 #ifdef HAVE_LIBJANSSON
100  profiling_rulegroup_json = 1;
101 #else
102  SCLogWarning(SC_ERR_NO_JSON_SUPPORT, "no json support compiled in, using plain output");
103 #endif
104  }
105  }
106  }
107 }
108 
109 #ifdef HAVE_LIBJANSSON
110 static void DoDumpJSON(SCProfileSghDetectCtx *rules_ctx, FILE *fp, const char *name)
111 {
112  char timebuf[64];
113  uint32_t i;
114  struct timeval tval;
115 
116  json_t *js = json_object();
117  if (js == NULL)
118  return;
119  json_t *jsa = json_array();
120  if (jsa == NULL) {
121  json_decref(js);
122  return;
123  }
124 
125  gettimeofday(&tval, NULL);
126  CreateIsoTimeString(&tval, timebuf, sizeof(timebuf));
127  json_object_set_new(js, "timestamp", json_string(timebuf));
128 
129  for (i = 0; i < rules_ctx->cnt; i++) {
130  SCProfileSghData *d = &rules_ctx->data[i];
131  if (d == NULL || d->checks == 0)
132  continue;
133 
134  double avgsigs = 0;
135  double avgmpms = 0;
136 
137  if (d->post_prefilter_sigs_total && d->checks) {
138  avgsigs = (double)((double)d->post_prefilter_sigs_total / (double)d->checks);
139  }
140  if (d->mpm_match_cnt_total && d->checks) {
141  avgmpms = (double)((double)d->mpm_match_cnt_total / (double)d->checks);
142  }
143 
144  json_t *jsm = json_object();
145  if (jsm) {
146  json_object_set_new(jsm, "id", json_integer(i));
147  json_object_set_new(jsm, "checks", json_integer(d->checks));
148  json_object_set_new(jsm, "non_mpm_generic", json_integer(d->non_mpm_generic));
149  json_object_set_new(jsm, "non_mpm_syn", json_integer(d->non_mpm_syn));
150  json_object_set_new(jsm, "avgmpms", json_real(avgmpms));
151  json_object_set_new(jsm, "mpm_match_cnt_max", json_integer(d->mpm_match_cnt_max));
152  json_object_set_new(jsm, "avgsigs", json_real(avgsigs));
153  json_object_set_new(jsm, "post_prefilter_sigs_max", json_integer(d->post_prefilter_sigs_max));
154  json_array_append_new(jsa, jsm);
155  }
156  }
157  json_object_set_new(js, "rule_groups", jsa);
158 
159  char *js_s = json_dumps(js,
160  JSON_PRESERVE_ORDER|JSON_COMPACT|JSON_ENSURE_ASCII|
161  JSON_ESCAPE_SLASH);
162  if (likely(js_s != NULL)) {
163  fprintf(fp, "%s", js_s);
164  free(js_s);
165  }
166  json_decref(js);
167 }
168 #endif /* HAVE_LIBJANSSON */
169 
170 static void DoDump(SCProfileSghDetectCtx *rules_ctx, FILE *fp, const char *name)
171 {
172  uint32_t i;
173  struct timeval tval;
174  struct tm *tms;
175  struct tm local_tm;
176 
177  gettimeofday(&tval, NULL);
178  tms = SCLocalTime(tval.tv_sec, &local_tm);
179 
180  fprintf(fp, " ----------------------------------------------"
181  "------------------------------------------------------"
182  "----------------------------\n");
183  fprintf(fp, " Date: %" PRId32 "/%" PRId32 "/%04d -- "
184  "%02d:%02d:%02d\n", tms->tm_mon + 1, tms->tm_mday, tms->tm_year + 1900,
185  tms->tm_hour,tms->tm_min, tms->tm_sec);
186 
187  fprintf(fp, " ----------------------------------------------"
188  "------------------------------------------------------"
189  "----------------------------\n");
190  fprintf(fp, " Stats for: %s %u\n", name, rules_ctx->cnt);
191  fprintf(fp, " ----------------------------------------------"
192  "------------------------------------------------------"
193  "----------------------------\n");
194  fprintf(fp, " %-16s %-15s %-15s %-15s %-15s %-15s %-15s %-15s\n", "Sgh", "Checks", "Non-MPM(gen)", "Non-Mpm(syn)", "MPM Matches", "MPM Match Max", "Post-Filter", "Post-Filter Max");
195  fprintf(fp, " ---------------- "
196  "--------------- "
197  "--------------- "
198  "--------------- "
199  "--------------- "
200  "--------------- "
201  "--------------- "
202  "--------------- "
203  "\n");
204  for (i = 0; i < rules_ctx->cnt; i++) {
205  SCProfileSghData *d = &rules_ctx->data[i];
206  if (d == NULL || d->checks == 0)
207  continue;
208 
209  double avgsigs = 0;
210  double avgmpms = 0;
211 
212  if (d->post_prefilter_sigs_total && d->checks) {
213  avgsigs = (double)((double)d->post_prefilter_sigs_total / (double)d->checks);
214  }
215  if (d->mpm_match_cnt_total && d->checks) {
216  avgmpms = (double)((double)d->mpm_match_cnt_total / (double)d->checks);
217  }
218 
219  fprintf(fp,
220  " %-16u %-15"PRIu64" %-15"PRIu64" %-15"PRIu64" %-15.2f %-15"PRIu64" %-15.2f %-15"PRIu64"\n",
221  i,
222  d->checks,
223  d->non_mpm_generic,
224  d->non_mpm_syn,
225  avgmpms,
227  avgsigs,
229  }
230  fprintf(fp,"\n");
231 }
232 
233 static void
234 SCProfilingSghDump(DetectEngineCtx *de_ctx)
235 {
236  FILE *fp;
237 
238  if (profiling_sghs_enabled == 0)
239  return;
240 
241  if (profiling_sghs_output_to_file == 1) {
242  SCLogDebug("file %s mode %s", profiling_file_name, profiling_file_mode);
243 
244  fp = fopen(profiling_file_name, profiling_file_mode);
245 
246  if (fp == NULL) {
247  SCLogError(SC_ERR_FOPEN, "failed to open %s: %s", profiling_file_name,
248  strerror(errno));
249  return;
250  }
251  } else {
252  fp = stdout;
253  }
254 
255 #ifdef HAVE_LIBJANSSON
256  if (profiling_rulegroup_json) {
257  DoDumpJSON(de_ctx->profile_sgh_ctx, fp, "rule groups");
258  } else
259 #endif
260  {
261  DoDump(de_ctx->profile_sgh_ctx, fp, "rule groups");
262  }
263 
264  if (fp != stdout)
265  fclose(fp);
266 
267  SCLogPerf("Done dumping rulegroup profiling data.");
268 }
269 
270 /**
271  * \brief Update a rule counter.
272  *
273  * \param id The ID of this counter.
274  * \param ticks Number of CPU ticks for this rule.
275  * \param match Did the rule match?
276  */
277 void
279 {
280  if (det_ctx != NULL && det_ctx->sgh_perf_data != NULL && sgh->id < det_ctx->de_ctx->sgh_array_cnt) {
281  SCProfileSghData *p = &det_ctx->sgh_perf_data[sgh->id];
282  p->checks++;
283 
284  if (det_ctx->non_pf_store_cnt > 0) {
285  if (det_ctx->non_pf_store_ptr == sgh->non_pf_syn_store_array)
286  p->non_mpm_syn++;
287  else
288  p->non_mpm_generic++;
289  }
291  if (det_ctx->match_array_cnt > p->post_prefilter_sigs_max)
294  if (det_ctx->pmq.rule_id_array_cnt > p->mpm_match_cnt_max)
296  }
297 }
298 
299 static SCProfileSghDetectCtx *SCProfilingSghInitCtx(void)
300 {
302  if (ctx != NULL) {
303  if (pthread_mutex_init(&ctx->data_m, NULL) != 0) {
305  "Failed to initialize mutex.");
306  exit(EXIT_FAILURE);
307  }
308  }
309 
310  return ctx;
311 }
312 
313 static void DetroyCtx(SCProfileSghDetectCtx *ctx)
314 {
315  if (ctx) {
316  if (ctx->data != NULL)
317  SCFree(ctx->data);
318  pthread_mutex_destroy(&ctx->data_m);
319  SCFree(ctx);
320  }
321 }
322 
324 {
325  if (de_ctx != NULL) {
326  SCProfilingSghDump(de_ctx);
327 
328  DetroyCtx(de_ctx->profile_sgh_ctx);
329  }
330 }
331 
333 {
334  if (ctx == NULL)
335  return;
336 
337  uint32_t array_size = det_ctx->de_ctx->sgh_array_cnt;
338 
339  SCProfileSghData *a = SCCalloc(array_size, sizeof(SCProfileSghData));
340  if (a != NULL) {
341  det_ctx->sgh_perf_data = a;
342  }
343 }
344 
345 static void SCProfilingSghThreadMerge(DetectEngineCtx *de_ctx, const DetectEngineThreadCtx *det_ctx)
346 {
347  if (de_ctx == NULL || de_ctx->profile_sgh_ctx == NULL ||
348  de_ctx->profile_sgh_ctx->data == NULL || det_ctx == NULL ||
349  det_ctx->sgh_perf_data == NULL)
350  return;
351 
352 #define ADD(name) de_ctx->profile_sgh_ctx->data[i].name += det_ctx->sgh_perf_data[i].name
353  uint32_t i;
354  for (i = 0; i < de_ctx->sgh_array_cnt; i++) {
355  ADD(checks);
357  ADD(non_mpm_syn);
360 
365  }
366 #undef ADD
367 }
368 
370 {
371  if (det_ctx == NULL || det_ctx->de_ctx == NULL || det_ctx->sgh_perf_data == NULL)
372  return;
373 
374  pthread_mutex_lock(&det_ctx->de_ctx->profile_sgh_ctx->data_m);
375  SCProfilingSghThreadMerge(det_ctx->de_ctx, det_ctx);
376  pthread_mutex_unlock(&det_ctx->de_ctx->profile_sgh_ctx->data_m);
377 
378  SCFree(det_ctx->sgh_perf_data);
379  det_ctx->sgh_perf_data = NULL;
380 }
381 
382 /**
383  * \brief Register the keyword profiling counters.
384  *
385  * \param de_ctx The active DetectEngineCtx, used to get at the loaded rules.
386  */
387 void
389 {
390  if (profiling_sghs_enabled == 0)
391  return;
392 
393  de_ctx->profile_sgh_ctx = SCProfilingSghInitCtx();
394  BUG_ON(de_ctx->profile_sgh_ctx == NULL);
395 
396  de_ctx->profile_sgh_ctx->data = SCCalloc(de_ctx->sgh_array_cnt, sizeof(SCProfileSghData));
397  BUG_ON(de_ctx->profile_sgh_ctx->data == NULL);
398 
399  de_ctx->profile_sgh_ctx->cnt = de_ctx->sgh_array_cnt;
400 
401  SCLogPerf("Registered %"PRIu32" rulegroup profiling counters.", de_ctx->sgh_array_cnt);
402 }
403 
404 #endif /* PROFILING */
struct SCProfileSghData_ * sgh_perf_data
Definition: detect.h:1118
SignatureNonPrefilterStore * non_pf_syn_store_array
Definition: detect.h:1307
#define SCLogDebug(...)
Definition: util-debug.h:335
void SCProfilingSghThreadSetup(SCProfileSghDetectCtx *ctx, DetectEngineThreadCtx *det_ctx)
#define BUG_ON(x)
uint32_t non_pf_store_cnt
Definition: detect.h:1053
struct SCProfileSghData_ SCProfileSghData
void SCProfilingSghInitCounters(DetectEngineCtx *de_ctx)
Register the keyword profiling counters.
Container for matching data for a signature group.
Definition: detect.h:1295
uint32_t id
Definition: detect.h:1313
int ConfNodeChildValueIsTrue(const ConfNode *node, const char *key)
Test if a configuration node has a true value.
Definition: conf.c:888
main detection engine ctx
Definition: detect.h:720
uint32_t sgh_array_cnt
Definition: detect.h:802
#define SCCalloc(nm, a)
Definition: util-mem.h:205
const char * ConfNodeLookupChildValue(const ConfNode *node, const char *name)
Lookup the value of a child configuration node by name.
Definition: conf.c:843
void CreateIsoTimeString(const struct timeval *ts, char *str, size_t size)
Definition: util-time.c:179
struct tm * SCLocalTime(time_t timep, struct tm *result)
Definition: util-time.c:232
struct SCProfileSghDetectCtx_ SCProfileSghDetectCtx
struct SCProfileSghDetectCtx_ * profile_sgh_ctx
Definition: detect.h:844
int profiling_sghs_enabled
#define SCLogError(err_code,...)
Macro used to log ERROR messages.
Definition: util-debug.h:294
PrefilterRuleStore pmq
Definition: detect.h:1061
SigIntId match_array_cnt
Definition: detect.h:1047
#define SCLogWarning(err_code,...)
Macro used to log WARNING messages.
Definition: util-debug.h:281
int ConfValIsTrue(const char *val)
Check if a value is true.
Definition: conf.c:566
Definition: conf.h:32
const char * ConfigGetLogDirectory()
Definition: util-conf.c:36
DetectEngineCtx * de_ctx
Definition: detect.h:1086
#define SCFree(a)
Definition: util-mem.h:236
#define SCLogPerf(...)
Definition: util-debug.h:261
uint32_t rule_id_array_cnt
void SCProfilingSghDestroyCtx(DetectEngineCtx *de_ctx)
ConfNode * ConfGetNode(const char *name)
Get a ConfNode by name.
Definition: conf.c:176
#define ADD(name)
SignatureNonPrefilterStore * non_pf_store_ptr
Definition: detect.h:1052
#define likely(expr)
Definition: util-optimize.h:32
void SCProfilingSghUpdateCounter(DetectEngineThreadCtx *det_ctx, const SigGroupHead *sgh)
Update a rule counter.
void SCProfilingSghsGlobalInit(void)
void SCProfilingSghThreadCleanup(DetectEngineThreadCtx *det_ctx)