suricata
util-profiling.c
Go to the documentation of this file.
1 /* Copyright (C) 2007-2021 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 profiling operations.
25  *
26  * Really just a wrapper around the existing perf counters.
27  */
28 
29 #include "suricata-common.h"
30 #include "util-profiling.h"
31 
32 #ifdef PROFILING
33 #include "tm-threads.h"
34 #include "conf.h"
35 #include "util-unittest.h"
36 #include "util-byte.h"
37 #include "util-profiling-locks.h"
38 #include "util-conf.h"
39 
40 #ifndef MIN
41 #define MIN(a, b) (((a) < (b)) ? (a) : (b))
42 #endif
43 
44 #define DEFAULT_LOG_FILENAME "profile.log"
45 #define DEFAULT_LOG_MODE_APPEND "yes"
46 
47 static pthread_mutex_t packet_profile_lock;
48 static FILE *packet_profile_csv_fp = NULL;
49 
50 extern int profiling_locks_enabled;
52 extern char *profiling_locks_file_name;
53 extern const char *profiling_locks_file_mode;
54 
55 typedef struct SCProfilePacketData_ {
56  uint64_t min;
57  uint64_t max;
58  uint64_t tot;
59  uint64_t cnt;
60 #ifdef PROFILE_LOCKING
61  uint64_t lock;
62  uint64_t ticks;
63  uint64_t contention;
64 
65  uint64_t slock;
66  uint64_t sticks;
67  uint64_t scontention;
68 #endif
70 SCProfilePacketData packet_profile_data4[257]; /**< all proto's + tunnel */
71 SCProfilePacketData packet_profile_data6[257]; /**< all proto's + tunnel */
72 
73 /* each module, each proto */
76 
79 
82 
85 
88 
92 };
93 
95 
98 
99 static int profiling_packets_csv_enabled = 0;
100 static int profiling_packets_output_to_file = 0;
101 static char *profiling_file_name;
102 static char profiling_packets_file_name[PATH_MAX];
103 static char *profiling_csv_file_name;
104 static const char *profiling_packets_file_mode = "a";
105 
106 static int rate = 1;
107 static SC_ATOMIC_DECLARE(uint64_t, samples);
108 
109 /**
110  * Used as a check so we don't double enter a profiling run.
111  */
112 thread_local int profiling_rules_entered = 0;
113 
114 void SCProfilingDumpPacketStats(void);
117 static void PrintCSVHeader(void);
118 
119 static void FormatNumber(uint64_t num, char *str, size_t size)
120 {
121  if (num < 1000UL)
122  snprintf(str, size, "%"PRIu64, num);
123  else if (num < 1000000UL)
124  snprintf(str, size, "%3.1fk", (float)num/1000UL);
125  else if (num < 1000000000UL)
126  snprintf(str, size, "%3.1fm", (float)num/1000000UL);
127  else
128  snprintf(str, size, "%3.1fb", (float)num/1000000000UL);
129 }
130 
131 /**
132  * \brief Initialize profiling.
133  */
134 void
136 {
137  ConfNode *conf;
138 
139  SC_ATOMIC_INIT(samples);
140 
141  intmax_t rate_v = 0;
142  (void)ConfGetInt("profiling.sample-rate", &rate_v);
143  if (rate_v > 0 && rate_v < INT_MAX) {
144  rate = (int)rate_v;
145  if (rate != 1)
146  SCLogInfo("profiling runs for every %dth packet", rate);
147  else
148  SCLogInfo("profiling runs for every packet");
149  }
150 
151  conf = ConfGetNode("profiling.packets");
152  if (conf != NULL) {
153  if (ConfNodeChildValueIsTrue(conf, "enabled")) {
155 
156  if (pthread_mutex_init(&packet_profile_lock, NULL) != 0) {
157  FatalError("Failed to initialize packet profiling mutex.");
158  }
159  memset(&packet_profile_data4, 0, sizeof(packet_profile_data4));
160  memset(&packet_profile_data6, 0, sizeof(packet_profile_data6));
172 
173  const char *filename = ConfNodeLookupChildValue(conf, "filename");
174  if (filename != NULL) {
175  const char *log_dir;
176  log_dir = ConfigGetLogDirectory();
177 
178  snprintf(profiling_packets_file_name, sizeof(profiling_packets_file_name),
179  "%s/%s", log_dir, filename);
180 
181  const char *v = ConfNodeLookupChildValue(conf, "append");
182  if (v == NULL || ConfValIsTrue(v)) {
183  profiling_packets_file_mode = "a";
184  } else {
185  profiling_packets_file_mode = "w";
186  }
187 
188  profiling_packets_output_to_file = 1;
189  }
190  }
191 
192  conf = ConfGetNode("profiling.packets.csv");
193  if (conf != NULL) {
194  if (ConfNodeChildValueIsTrue(conf, "enabled")) {
195  const char *filename = ConfNodeLookupChildValue(conf, "filename");
196  if (filename == NULL) {
197  filename = "packet_profile.csv";
198  }
199 
200  const char *log_dir = ConfigGetLogDirectory();
201 
202  profiling_csv_file_name = SCMalloc(PATH_MAX);
203  if (unlikely(profiling_csv_file_name == NULL)) {
204  FatalError("out of memory");
205  }
206  snprintf(profiling_csv_file_name, PATH_MAX, "%s/%s", log_dir, filename);
207 
208  packet_profile_csv_fp = fopen(profiling_csv_file_name, "w");
209  if (packet_profile_csv_fp == NULL) {
210  SCFree(profiling_csv_file_name);
211  profiling_csv_file_name = NULL;
212  return;
213  }
214 
215  PrintCSVHeader();
216 
217  profiling_packets_csv_enabled = 1;
218  }
219  }
220  }
221 
222  conf = ConfGetNode("profiling.locks");
223  if (conf != NULL) {
224  if (ConfNodeChildValueIsTrue(conf, "enabled")) {
225 #ifndef PROFILE_LOCKING
226  SCLogWarning(
227  "lock profiling not compiled in. Add --enable-profiling-locks to configure.");
228 #else
230 
232 
233  const char *filename = ConfNodeLookupChildValue(conf, "filename");
234  if (filename != NULL) {
235  const char *log_dir = ConfigGetLogDirectory();
236 
238  if (unlikely(profiling_locks_file_name == NULL)) {
239  FatalError("can't duplicate file name");
240  }
241 
242  snprintf(profiling_locks_file_name, PATH_MAX, "%s/%s", log_dir, filename);
243 
244  const char *v = ConfNodeLookupChildValue(conf, "append");
245  if (v == NULL || ConfValIsTrue(v)) {
247  } else {
249  }
250 
252  }
253 #endif
254  }
255  }
256 
257 }
258 
259 /**
260  * \brief Free resources used by profiling.
261  */
262 void
264 {
266  pthread_mutex_destroy(&packet_profile_lock);
267  }
268 
269  if (profiling_packets_csv_enabled) {
270  if (packet_profile_csv_fp != NULL)
271  fclose(packet_profile_csv_fp);
272  packet_profile_csv_fp = NULL;
273  }
274 
275  if (profiling_csv_file_name != NULL)
276  SCFree(profiling_csv_file_name);
277  profiling_csv_file_name = NULL;
278 
279  if (profiling_file_name != NULL)
280  SCFree(profiling_file_name);
281  profiling_file_name = NULL;
282 
283 #ifdef PROFILE_LOCKING
285 #endif
286 }
287 
288 void
290 {
292  SCLogPerf("Done dumping profiling data.");
293 }
294 
295 static void DumpFlowWorkerIP(FILE *fp, int ipv, uint64_t total)
296 {
297  char totalstr[256];
298 
299  enum ProfileFlowWorkerId fwi;
300  for (fwi = 0; fwi < PROFILE_FLOWWORKER_SIZE; fwi++) {
302  for (int p = 0; p < 257; p++) {
303  SCProfilePacketData *pd = ipv == 4 ? &r->records4[p] : &r->records6[p];
304  if (pd->cnt == 0) {
305  continue;
306  }
307 
308  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
309  double percent = (long double)pd->tot /
310  (long double)total * 100;
311 
312  fprintf(fp, "%-20s IPv%d %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %-6.2f\n",
313  ProfileFlowWorkerIdToString(fwi), ipv, p, pd->cnt,
314  pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
315  }
316  }
317 }
318 
319 static void DumpFlowWorker(FILE *fp)
320 {
321  uint64_t total = 0;
322 
323  enum ProfileFlowWorkerId fwi;
324  for (fwi = 0; fwi < PROFILE_FLOWWORKER_SIZE; fwi++) {
326  for (int p = 0; p < 257; p++) {
327  SCProfilePacketData *pd = &r->records4[p];
328  total += pd->tot;
329  pd = &r->records6[p];
330  total += pd->tot;
331  }
332  }
333 
334  fprintf(fp, "\n%-20s %-6s %-5s %-12s %-12s %-12s %-12s\n",
335  "Flow Worker", "IP ver", "Proto", "cnt", "min", "max", "avg");
336  fprintf(fp, "%-20s %-6s %-5s %-12s %-12s %-12s %-12s\n",
337  "--------------------", "------", "-----", "----------", "------------", "------------", "-----------");
338  DumpFlowWorkerIP(fp, 4, total);
339  DumpFlowWorkerIP(fp, 6, total);
340  fprintf(fp, "Note: %s includes app-layer for TCP\n",
342 }
343 
345 {
346  FILE *fp;
347  char totalstr[256];
348  uint64_t total;
349 
350  if (profiling_packets_enabled == 0)
351  return;
352 
353  if (profiling_packets_output_to_file == 1) {
354  fp = fopen(profiling_packets_file_name, profiling_packets_file_mode);
355 
356  if (fp == NULL) {
357  SCLogError("failed to open %s: %s", profiling_packets_file_name, strerror(errno));
358  return;
359  }
360  } else {
361  fp = stdout;
362  }
363 
364  fprintf(fp, "\n\nPacket profile dump:\n");
365 
366  fprintf(fp, "\n%-6s %-5s %-12s %-12s %-12s %-12s %-12s %-3s\n",
367  "IP ver", "Proto", "cnt", "min", "max", "avg", "tot", "%%");
368  fprintf(fp, "%-6s %-5s %-12s %-12s %-12s %-12s %-12s %-3s\n",
369  "------", "-----", "----------", "------------", "------------", "-----------", "-----------", "---");
370  total = 0;
371  for (int i = 0; i < 257; i++) {
373  total += pd->tot;
374  pd = &packet_profile_data6[i];
375  total += pd->tot;
376  }
377 
378  for (int i = 0; i < 257; i++) {
380  if (pd->cnt == 0) {
381  continue;
382  }
383 
384  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
385  double percent = (long double)pd->tot /
386  (long double)total * 100;
387 
388  fprintf(fp, " IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %6.2f\n", i, pd->cnt,
389  pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
390  }
391 
392  for (int i = 0; i < 257; i++) {
394  if (pd->cnt == 0) {
395  continue;
396  }
397 
398  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
399  double percent = (long double)pd->tot /
400  (long double)total * 100;
401 
402  fprintf(fp, " IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %6.2f\n", i, pd->cnt,
403  pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
404  }
405  fprintf(fp, "Note: Protocol 256 tracks pseudo/tunnel packets.\n");
406 
407  fprintf(fp, "\nPer Thread module stats:\n");
408 
409  fprintf(fp, "\n%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s %-3s",
410  "Thread Module", "IP ver", "Proto", "cnt", "min", "max", "avg", "tot", "%%");
411 #ifdef PROFILE_LOCKING
412  fprintf(fp, " %-10s %-10s %-12s %-12s %-10s %-10s %-12s %-12s\n",
413  "locks", "ticks", "cont.", "cont.avg", "slocks", "sticks", "scont.", "scont.avg");
414 #else
415  fprintf(fp, "\n");
416 #endif
417  fprintf(fp, "%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s %-3s",
418  "------------------------", "------", "-----", "----------", "------------", "------------", "-----------", "-----------", "---");
419 #ifdef PROFILE_LOCKING
420  fprintf(fp, " %-10s %-10s %-12s %-12s %-10s %-10s %-12s %-12s\n",
421  "--------", "--------", "----------", "-----------", "--------", "--------", "------------", "-----------");
422 #else
423  fprintf(fp, "\n");
424 #endif
425  total = 0;
426  for (int m = 0; m < TMM_SIZE; m++) {
428  continue;
429 
430  for (int p = 0; p < 257; p++) {
432  total += pd->tot;
433 
434  pd = &packet_profile_tmm_data6[m][p];
435  total += pd->tot;
436  }
437  }
438 
439  for (int m = 0; m < TMM_SIZE; m++) {
441  continue;
442 
443  for (int p = 0; p < 257; p++) {
445  if (pd->cnt == 0) {
446  continue;
447  }
448 
449  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
450  double percent = (long double)pd->tot /
451  (long double)total * 100;
452 
453  fprintf(fp, "%-24s IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %6.2f",
454  TmModuleTmmIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
455 #ifdef PROFILE_LOCKING
456  fprintf(fp, " %10.2f %12"PRIu64" %12"PRIu64" %10.2f %10.2f %12"PRIu64" %12"PRIu64" %10.2f\n",
457  (float)pd->lock/pd->cnt, (uint64_t)pd->ticks/pd->cnt, pd->contention, (float)pd->contention/pd->cnt, (float)pd->slock/pd->cnt, (uint64_t)pd->sticks/pd->cnt, pd->scontention, (float)pd->scontention/pd->cnt);
458 #else
459  fprintf(fp, "\n");
460 #endif
461  }
462  }
463 
464  for (int m = 0; m < TMM_SIZE; m++) {
466  continue;
467 
468  for (int p = 0; p < 257; p++) {
470  if (pd->cnt == 0) {
471  continue;
472  }
473 
474  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
475  double percent = (long double)pd->tot /
476  (long double)total * 100;
477 
478  fprintf(fp, "%-24s IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %6.2f\n",
479  TmModuleTmmIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
480  }
481  }
482 
483  DumpFlowWorker(fp);
484 
485  fprintf(fp, "\nPer App layer parser stats:\n");
486 
487  fprintf(fp, "\n%-20s %-6s %-5s %-12s %-12s %-12s %-12s\n",
488  "App Layer", "IP ver", "Proto", "cnt", "min", "max", "avg");
489  fprintf(fp, "%-20s %-6s %-5s %-12s %-12s %-12s %-12s\n",
490  "--------------------", "------", "-----", "----------", "------------", "------------", "-----------");
491 
492  total = 0;
493  for (AppProto a = 0; a < ALPROTO_MAX; a++) {
494  for (int p = 0; p < 257; p++) {
496  total += pd->tot;
497 
498  pd = &packet_profile_app_data6[a][p];
499  total += pd->tot;
500  }
501  }
502  for (AppProto a = 0; a < ALPROTO_MAX; a++) {
503  for (int p = 0; p < 257; p++) {
505  if (pd->cnt == 0) {
506  continue;
507  }
508 
509  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
510  double percent = (long double)pd->tot /
511  (long double)total * 100;
512 
513  fprintf(fp,
514  "%-20s IPv4 %3d %12" PRIu64 " %12" PRIu64 " %12" PRIu64
515  " %12" PRIu64 " %12s %-6.2f\n",
516  AppProtoToString(a), p, pd->cnt, pd->min, pd->max,
517  (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
518  }
519  }
520 
521  for (AppProto a = 0; a < ALPROTO_MAX; a++) {
522  for (int p = 0; p < 257; p++) {
524  if (pd->cnt == 0) {
525  continue;
526  }
527 
528  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
529  double percent = (long double)pd->tot /
530  (long double)total * 100;
531 
532  fprintf(fp,
533  "%-20s IPv6 %3d %12" PRIu64 " %12" PRIu64 " %12" PRIu64
534  " %12" PRIu64 " %12s %-6.2f\n",
535  AppProtoToString(a), p, pd->cnt, pd->min, pd->max,
536  (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
537  }
538  }
539 
540  /* proto detect output */
541  {
542  for (int p = 0; p < 257; p++) {
544  if (pd->cnt == 0) {
545  continue;
546  }
547 
548  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
549  fprintf(fp, "%-20s IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s\n",
550  "Proto detect", p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr);
551  }
552 
553  for (int p = 0; p < 257; p++) {
555  if (pd->cnt == 0) {
556  continue;
557  }
558 
559  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
560  fprintf(fp, "%-20s IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s\n",
561  "Proto detect", p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr);
562  }
563  }
564 
565  total = 0;
566  for (int m = 0; m < PROF_DETECT_SIZE; m++) {
567  for (int p = 0; p < 257; p++) {
569  total += pd->tot;
570 
571  pd = &packet_profile_detect_data6[m][p];
572  total += pd->tot;
573  }
574  }
575 
576  fprintf(fp, "\n%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s %-3s",
577  "Log Thread Module", "IP ver", "Proto", "cnt", "min", "max", "avg", "tot", "%%");
578 #ifdef PROFILE_LOCKING
579  fprintf(fp, " %-10s %-10s %-12s %-12s %-10s %-10s %-12s %-12s\n",
580  "locks", "ticks", "cont.", "cont.avg", "slocks", "sticks", "scont.", "scont.avg");
581 #else
582  fprintf(fp, "\n");
583 #endif
584  fprintf(fp, "%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s %-3s",
585  "------------------------", "------", "-----", "----------", "------------", "------------", "-----------", "-----------", "---");
586 #ifdef PROFILE_LOCKING
587  fprintf(fp, " %-10s %-10s %-12s %-12s %-10s %-10s %-12s %-12s\n",
588  "--------", "--------", "----------", "-----------", "--------", "--------", "------------", "-----------");
589 #else
590  fprintf(fp, "\n");
591 #endif
592  total = 0;
593  for (int m = 0; m < TMM_SIZE; m++) {
595  continue;
596 
597  for (int p = 0; p < 257; p++) {
599  total += pd->tot;
600 
601  pd = &packet_profile_tmm_data6[m][p];
602  total += pd->tot;
603  }
604  }
605 
606  for (int m = 0; m < TMM_SIZE; m++) {
608  continue;
609 
610  for (int p = 0; p < 257; p++) {
612  if (pd->cnt == 0) {
613  continue;
614  }
615 
616  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
617  double percent = (long double)pd->tot /
618  (long double)total * 100;
619 
620  fprintf(fp, "%-24s IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %6.2f",
621  TmModuleTmmIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
622 #ifdef PROFILE_LOCKING
623  fprintf(fp, " %10.2f %12"PRIu64" %12"PRIu64" %10.2f %10.2f %12"PRIu64" %12"PRIu64" %10.2f\n",
624  (float)pd->lock/pd->cnt, (uint64_t)pd->ticks/pd->cnt, pd->contention, (float)pd->contention/pd->cnt, (float)pd->slock/pd->cnt, (uint64_t)pd->sticks/pd->cnt, pd->scontention, (float)pd->scontention/pd->cnt);
625 #else
626  fprintf(fp, "\n");
627 #endif
628  }
629  }
630 
631  for (int m = 0; m < TMM_SIZE; m++) {
633  continue;
634 
635  for (int p = 0; p < 257; p++) {
637  if (pd->cnt == 0) {
638  continue;
639  }
640 
641  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
642  double percent = (long double)pd->tot /
643  (long double)total * 100;
644 
645  fprintf(fp, "%-24s IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %6.2f\n",
646  TmModuleTmmIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
647  }
648  }
649 
650  fprintf(fp, "\nLogger/output stats:\n");
651 
652  total = 0;
653  for (int m = 0; m < LOGGER_SIZE; m++) {
654  for (int p = 0; p < 256; p++) {
656  total += pd->tot;
657  pd = &packet_profile_log_data6[m][p];
658  total += pd->tot;
659  }
660  }
661 
662  fprintf(fp, "\n%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s\n",
663  "Logger", "IP ver", "Proto", "cnt", "min", "max", "avg", "tot");
664  fprintf(fp, "%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s\n",
665  "------------------------", "------", "-----", "----------", "------------", "------------", "-----------", "-----------");
666  for (int m = 0; m < LOGGER_SIZE; m++) {
667  for (int p = 0; p < 256; p++) {
669  if (pd->cnt == 0) {
670  continue;
671  }
672 
673  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
674  double percent = (long double)pd->tot /
675  (long double)total * 100;
676 
677  fprintf(fp, "%-24s IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %-6.2f\n",
678  PacketProfileLoggertIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
679  }
680  }
681  for (int m = 0; m < LOGGER_SIZE; m++) {
682  for (int p = 0; p < 256; p++) {
684  if (pd->cnt == 0) {
685  continue;
686  }
687 
688  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
689  double percent = (long double)pd->tot /
690  (long double)total * 100;
691 
692  fprintf(fp, "%-24s IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %-6.2f\n",
693  PacketProfileLoggertIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
694  }
695  }
696 
697  fprintf(fp, "\nGeneral detection engine stats:\n");
698 
699  total = 0;
700  for (int m = 0; m < PROF_DETECT_SIZE; m++) {
701  for (int p = 0; p < 257; p++) {
703  total += pd->tot;
704  pd = &packet_profile_detect_data6[m][p];
705  total += pd->tot;
706  }
707  }
708 
709  fprintf(fp, "\n%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s\n",
710  "Detection phase", "IP ver", "Proto", "cnt", "min", "max", "avg", "tot");
711  fprintf(fp, "%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s\n",
712  "------------------------", "------", "-----", "----------", "------------", "------------", "-----------", "-----------");
713  for (int m = 0; m < PROF_DETECT_SIZE; m++) {
714  for (int p = 0; p < 257; p++) {
716  if (pd->cnt == 0) {
717  continue;
718  }
719 
720  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
721  double percent = (long double)pd->tot /
722  (long double)total * 100;
723 
724  fprintf(fp, "%-24s IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %-6.2f\n",
725  PacketProfileDetectIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
726  }
727  }
728  for (int m = 0; m < PROF_DETECT_SIZE; m++) {
729  for (int p = 0; p < 257; p++) {
731  if (pd->cnt == 0) {
732  continue;
733  }
734 
735  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
736  double percent = (long double)pd->tot /
737  (long double)total * 100;
738 
739  fprintf(fp, "%-24s IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %-6.2f\n",
740  PacketProfileDetectIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
741  }
742  }
743  fclose(fp);
744 }
745 
746 static void PrintCSVHeader(void)
747 {
748  fprintf(packet_profile_csv_fp, "pcap_cnt,total,receive,decode,flowworker,");
749  fprintf(packet_profile_csv_fp, "threading,");
750  fprintf(packet_profile_csv_fp, "proto detect,");
751 
752  for (enum ProfileFlowWorkerId fwi = 0; fwi < PROFILE_FLOWWORKER_SIZE; fwi++) {
753  fprintf(packet_profile_csv_fp, "%s,", ProfileFlowWorkerIdToString(fwi));
754  }
755  fprintf(packet_profile_csv_fp, "loggers,");
756 
757  /* detect stages */
758  for (int i = 0; i < PROF_DETECT_SIZE; i++) {
759  fprintf(packet_profile_csv_fp, "%s,", PacketProfileDetectIdToString(i));
760  }
761 
762  /* individual loggers */
763  for (LoggerId i = 0; i < LOGGER_SIZE; i++) {
764  fprintf(packet_profile_csv_fp, "%s,", PacketProfileLoggertIdToString(i));
765  }
766 
767  fprintf(packet_profile_csv_fp, "\n");
768 }
769 
771 {
772  if (profiling_packets_csv_enabled == 0 || p == NULL ||
773  packet_profile_csv_fp == NULL || p->profile == NULL) {
774  return;
775  }
776 
777  uint64_t tmm_total = 0;
778  uint64_t receive = 0;
779  uint64_t decode = 0;
780 
781  /* total cost from acquisition to return to packetpool */
782  uint64_t delta = p->profile->ticks_end - p->profile->ticks_start;
783  fprintf(packet_profile_csv_fp, "%"PRIu64",%"PRIu64",",
784  p->pcap_cnt, delta);
785 
786  for (int i = 0; i < TMM_SIZE; i++) {
787  const PktProfilingTmmData *pdt = &p->profile->tmm[i];
788  uint64_t tmm_delta = pdt->ticks_end - pdt->ticks_start;
789 
791  if (tmm_delta) {
792  receive = tmm_delta;
793  }
794  continue;
795 
796  } else if (tmm_modules[i].flags & TM_FLAG_DECODE_TM) {
797  if (tmm_delta) {
798  decode = tmm_delta;
799  }
800  continue;
801  }
802 
803  tmm_total += tmm_delta;
804  }
805  fprintf(packet_profile_csv_fp, "%"PRIu64",", receive);
806  fprintf(packet_profile_csv_fp, "%"PRIu64",", decode);
808  fprintf(packet_profile_csv_fp, "%"PRIu64",", fw_pdt->ticks_end - fw_pdt->ticks_start);
809  fprintf(packet_profile_csv_fp, "%"PRIu64",", delta - tmm_total);
810 
811  /* count ticks for app layer */
812  uint64_t app_total = 0;
813  for (AppProto i = 1; i < ALPROTO_FAILED; i++) {
814  const PktProfilingAppData *pdt = &p->profile->app[i];
815 
816  if (p->proto == IPPROTO_TCP) {
817  app_total += pdt->ticks_spent;
818  }
819  }
820 
821  fprintf(packet_profile_csv_fp, "%"PRIu64",", p->profile->proto_detect);
822 
823  /* print flowworker steps */
824  for (enum ProfileFlowWorkerId fwi = 0; fwi < PROFILE_FLOWWORKER_SIZE; fwi++) {
825  const PktProfilingData *pd = &p->profile->flowworker[fwi];
826  uint64_t ticks_spent = pd->ticks_end - pd->ticks_start;
827  if (fwi == PROFILE_FLOWWORKER_STREAM) {
828  ticks_spent -= app_total;
829  } else if (fwi == PROFILE_FLOWWORKER_APPLAYERUDP && app_total) {
830  ticks_spent = app_total;
831  }
832 
833  fprintf(packet_profile_csv_fp, "%"PRIu64",", ticks_spent);
834  }
835 
836  /* count loggers cost and print as a single cost */
837  uint64_t loggers = 0;
838  for (LoggerId i = 0; i < LOGGER_SIZE; i++) {
839  const PktProfilingLoggerData *pd = &p->profile->logger[i];
840  loggers += pd->ticks_spent;
841  }
842  fprintf(packet_profile_csv_fp, "%"PRIu64",", loggers);
843 
844  /* detect steps */
845  for (int i = 0; i < PROF_DETECT_SIZE; i++) {
846  const PktProfilingDetectData *pdt = &p->profile->detect[i];
847 
848  fprintf(packet_profile_csv_fp,"%"PRIu64",", pdt->ticks_spent);
849  }
850 
851  /* print individual loggers */
852  for (LoggerId i = 0; i < LOGGER_SIZE; i++) {
853  const PktProfilingLoggerData *pd = &p->profile->logger[i];
854  fprintf(packet_profile_csv_fp, "%"PRIu64",", pd->ticks_spent);
855  }
856 
857  fprintf(packet_profile_csv_fp,"\n");
858 }
859 
860 static void SCProfilingUpdatePacketDetectRecord(PacketProfileDetectId id, uint8_t ipproto, PktProfilingDetectData *pdt, int ipver)
861 {
862  if (pdt == NULL) {
863  return;
864  }
865 
867  if (ipver == 4)
868  pd = &packet_profile_detect_data4[id][ipproto];
869  else
870  pd = &packet_profile_detect_data6[id][ipproto];
871 
872  if (pd->min == 0 || pdt->ticks_spent < pd->min) {
873  pd->min = pdt->ticks_spent;
874  }
875  if (pd->max < pdt->ticks_spent) {
876  pd->max = pdt->ticks_spent;
877  }
878 
879  pd->tot += pdt->ticks_spent;
880  pd->cnt ++;
881 }
882 
883 static void SCProfilingUpdatePacketDetectRecords(Packet *p)
884 {
886  for (i = 0; i < PROF_DETECT_SIZE; i++) {
887  PktProfilingDetectData *pdt = &p->profile->detect[i];
888 
889  if (pdt->ticks_spent > 0) {
890  if (PKT_IS_IPV4(p)) {
891  SCProfilingUpdatePacketDetectRecord(i, p->proto, pdt, 4);
892  } else {
893  SCProfilingUpdatePacketDetectRecord(i, p->proto, pdt, 6);
894  }
895  }
896  }
897 }
898 
899 static void SCProfilingUpdatePacketAppPdRecord(uint8_t ipproto, uint32_t ticks_spent, int ipver)
900 {
902  if (ipver == 4)
903  pd = &packet_profile_app_pd_data4[ipproto];
904  else
905  pd = &packet_profile_app_pd_data6[ipproto];
906 
907  if (pd->min == 0 || ticks_spent < pd->min) {
908  pd->min = ticks_spent;
909  }
910  if (pd->max < ticks_spent) {
911  pd->max = ticks_spent;
912  }
913 
914  pd->tot += ticks_spent;
915  pd->cnt ++;
916 }
917 
918 static void SCProfilingUpdatePacketAppRecord(int alproto, uint8_t ipproto, PktProfilingAppData *pdt, int ipver)
919 {
920  if (pdt == NULL) {
921  return;
922  }
923 
925  if (ipver == 4)
926  pd = &packet_profile_app_data4[alproto][ipproto];
927  else
928  pd = &packet_profile_app_data6[alproto][ipproto];
929 
930  if (pd->min == 0 || pdt->ticks_spent < pd->min) {
931  pd->min = pdt->ticks_spent;
932  }
933  if (pd->max < pdt->ticks_spent) {
934  pd->max = pdt->ticks_spent;
935  }
936 
937  pd->tot += pdt->ticks_spent;
938  pd->cnt ++;
939 }
940 
941 static void SCProfilingUpdatePacketAppRecords(Packet *p)
942 {
943  int i;
944  for (i = 0; i < ALPROTO_MAX; i++) {
945  PktProfilingAppData *pdt = &p->profile->app[i];
946 
947  if (pdt->ticks_spent > 0) {
948  if (PKT_IS_IPV4(p)) {
949  SCProfilingUpdatePacketAppRecord(i, p->proto, pdt, 4);
950  } else {
951  SCProfilingUpdatePacketAppRecord(i, p->proto, pdt, 6);
952  }
953  }
954  }
955 
956  if (p->profile->proto_detect > 0) {
957  if (PKT_IS_IPV4(p)) {
958  SCProfilingUpdatePacketAppPdRecord(p->proto, p->profile->proto_detect, 4);
959  } else {
960  SCProfilingUpdatePacketAppPdRecord(p->proto, p->profile->proto_detect, 6);
961  }
962  }
963 }
964 
965 static void SCProfilingUpdatePacketTmmRecord(int module, uint8_t proto, PktProfilingTmmData *pdt, int ipver)
966 {
967  if (pdt == NULL) {
968  return;
969  }
970 
972  if (ipver == 4)
973  pd = &packet_profile_tmm_data4[module][proto];
974  else
975  pd = &packet_profile_tmm_data6[module][proto];
976 
977  uint32_t delta = (uint32_t)pdt->ticks_end - pdt->ticks_start;
978  if (pd->min == 0 || delta < pd->min) {
979  pd->min = delta;
980  }
981  if (pd->max < delta) {
982  pd->max = delta;
983  }
984 
985  pd->tot += (uint64_t)delta;
986  pd->cnt ++;
987 
988 #ifdef PROFILE_LOCKING
989  pd->lock += pdt->mutex_lock_cnt;
990  pd->ticks += pdt->mutex_lock_wait_ticks;
991  pd->contention += pdt->mutex_lock_contention;
992  pd->slock += pdt->spin_lock_cnt;
993  pd->sticks += pdt->spin_lock_wait_ticks;
994  pd->scontention += pdt->spin_lock_contention;
995 #endif
996 }
997 
998 static void SCProfilingUpdatePacketTmmRecords(Packet *p)
999 {
1000  int i;
1001  for (i = 0; i < TMM_SIZE; i++) {
1002  PktProfilingTmmData *pdt = &p->profile->tmm[i];
1003 
1004  if (pdt->ticks_start == 0 || pdt->ticks_end == 0 || pdt->ticks_start > pdt->ticks_end) {
1005  continue;
1006  }
1007 
1008  if (PKT_IS_IPV4(p)) {
1009  SCProfilingUpdatePacketTmmRecord(i, p->proto, pdt, 4);
1010  } else {
1011  SCProfilingUpdatePacketTmmRecord(i, p->proto, pdt, 6);
1012  }
1013  }
1014 }
1015 
1016 static inline void SCProfilingUpdatePacketGenericRecord(PktProfilingData *pdt,
1017  SCProfilePacketData *pd)
1018 {
1019  if (pdt == NULL || pd == NULL) {
1020  return;
1021  }
1022 
1023  uint64_t delta = pdt->ticks_end - pdt->ticks_start;
1024  if (pd->min == 0 || delta < pd->min) {
1025  pd->min = delta;
1026  }
1027  if (pd->max < delta) {
1028  pd->max = delta;
1029  }
1030 
1031  pd->tot += delta;
1032  pd->cnt ++;
1033 }
1034 
1035 static void SCProfilingUpdatePacketGenericRecords(Packet *p, PktProfilingData *pd,
1036  struct ProfileProtoRecords *records, int size)
1037 {
1038  int i;
1039  for (i = 0; i < size; i++) {
1040  PktProfilingData *pdt = &pd[i];
1041 
1042  if (pdt->ticks_start == 0 || pdt->ticks_end == 0 || pdt->ticks_start > pdt->ticks_end) {
1043  continue;
1044  }
1045 
1046  struct ProfileProtoRecords *r = &records[i];
1047  SCProfilePacketData *store = NULL;
1048 
1049  if (PKT_IS_IPV4(p)) {
1050  store = &(r->records4[p->proto]);
1051  } else {
1052  store = &(r->records6[p->proto]);
1053  }
1054 
1055  SCProfilingUpdatePacketGenericRecord(pdt, store);
1056  }
1057 }
1058 
1059 static void SCProfilingUpdatePacketLogRecord(LoggerId id,
1060  uint8_t ipproto, PktProfilingLoggerData *pdt, int ipver)
1061 {
1062  if (pdt == NULL) {
1063  return;
1064  }
1065 
1066  SCProfilePacketData *pd;
1067  if (ipver == 4)
1068  pd = &packet_profile_log_data4[id][ipproto];
1069  else
1070  pd = &packet_profile_log_data6[id][ipproto];
1071 
1072  if (pd->min == 0 || pdt->ticks_spent < pd->min) {
1073  pd->min = pdt->ticks_spent;
1074  }
1075  if (pd->max < pdt->ticks_spent) {
1076  pd->max = pdt->ticks_spent;
1077  }
1078 
1079  pd->tot += pdt->ticks_spent;
1080  pd->cnt++;
1081 }
1082 
1083 static void SCProfilingUpdatePacketLogRecords(Packet *p)
1084 {
1085  for (LoggerId i = 0; i < LOGGER_SIZE; i++) {
1086  PktProfilingLoggerData *pdt = &p->profile->logger[i];
1087 
1088  if (pdt->ticks_spent > 0) {
1089  if (PKT_IS_IPV4(p)) {
1090  SCProfilingUpdatePacketLogRecord(i, p->proto, pdt, 4);
1091  } else {
1092  SCProfilingUpdatePacketLogRecord(i, p->proto, pdt, 6);
1093  }
1094  }
1095  }
1096 }
1097 
1099 {
1100  if (p == NULL || p->profile == NULL ||
1101  p->profile->ticks_start == 0 || p->profile->ticks_end == 0 ||
1103  return;
1104 
1105  pthread_mutex_lock(&packet_profile_lock);
1106  {
1107 
1108  if (PKT_IS_IPV4(p)) {
1110 
1111  uint64_t delta = p->profile->ticks_end - p->profile->ticks_start;
1112  if (pd->min == 0 || delta < pd->min) {
1113  pd->min = delta;
1114  }
1115  if (pd->max < delta) {
1116  pd->max = delta;
1117  }
1118 
1119  pd->tot += delta;
1120  pd->cnt ++;
1121 
1122  if (IS_TUNNEL_PKT(p)) {
1123  pd = &packet_profile_data4[256];
1124 
1125  if (pd->min == 0 || delta < pd->min) {
1126  pd->min = delta;
1127  }
1128  if (pd->max < delta) {
1129  pd->max = delta;
1130  }
1131 
1132  pd->tot += delta;
1133  pd->cnt ++;
1134  }
1135 
1136  SCProfilingUpdatePacketGenericRecords(p, p->profile->flowworker,
1138 
1139  SCProfilingUpdatePacketTmmRecords(p);
1140  SCProfilingUpdatePacketAppRecords(p);
1141  SCProfilingUpdatePacketDetectRecords(p);
1142  SCProfilingUpdatePacketLogRecords(p);
1143 
1144  } else if (PKT_IS_IPV6(p)) {
1146 
1147  uint64_t delta = p->profile->ticks_end - p->profile->ticks_start;
1148  if (pd->min == 0 || delta < pd->min) {
1149  pd->min = delta;
1150  }
1151  if (pd->max < delta) {
1152  pd->max = delta;
1153  }
1154 
1155  pd->tot += delta;
1156  pd->cnt ++;
1157 
1158  if (IS_TUNNEL_PKT(p)) {
1159  pd = &packet_profile_data6[256];
1160 
1161  if (pd->min == 0 || delta < pd->min) {
1162  pd->min = delta;
1163  }
1164  if (pd->max < delta) {
1165  pd->max = delta;
1166  }
1167 
1168  pd->tot += delta;
1169  pd->cnt ++;
1170  }
1171 
1172  SCProfilingUpdatePacketGenericRecords(p, p->profile->flowworker,
1174 
1175  SCProfilingUpdatePacketTmmRecords(p);
1176  SCProfilingUpdatePacketAppRecords(p);
1177  SCProfilingUpdatePacketDetectRecords(p);
1178  SCProfilingUpdatePacketLogRecords(p);
1179  }
1180 
1181  if (profiling_packets_csv_enabled)
1183 
1184  }
1185  pthread_mutex_unlock(&packet_profile_lock);
1186 }
1187 
1189 {
1190  uint64_t sample = SC_ATOMIC_ADD(samples, 1);
1191  if (sample % rate == 0)
1192  return SCCalloc(1, sizeof(PktProfiling));
1193  else
1194  return NULL;
1195 }
1196 
1197 /* see if we want to profile rules for this packet */
1199 {
1200 #ifdef PROFILE_LOCKING
1201  if (p->profile != NULL) {
1202  p->flags |= PKT_PROFILE;
1203  return 1;
1204  }
1205 #else
1206  uint64_t sample = SC_ATOMIC_ADD(samples, 1);
1207  if (sample % rate == 0) {
1208  p->flags |= PKT_PROFILE;
1209  return 1;
1210  }
1211 #endif
1212  if (p->flags & PKT_PROFILE)
1213  return 1;
1214  return 0;
1215 }
1216 
1217 #define CASE_CODE(E) case E: return #E
1219 /**
1220  * \brief Maps the PacketProfileDetectId, to its string equivalent
1221  *
1222  * \param id PacketProfileDetectId id
1223  *
1224  * \retval string equivalent for the PacketProfileDetectId id
1225  */
1227 {
1228  switch (id) {
1244  default:
1245  return "UNKNOWN";
1246  }
1247 }
1248 
1249 /**
1250  * \brief Maps the LoggerId's to its string equivalent for profiling output.
1251  *
1252  * \param id LoggerId id
1253  *
1254  * \retval string equivalent for the LoggerId id
1255  */
1257 {
1258  switch (id) {
1282 
1283  case LOGGER_SIZE:
1284  return "UNKNOWN";
1285  }
1286  return "UNKNOWN";
1287 }
1288 
1289 #ifdef UNITTESTS
1290 
1291 static int
1292 ProfilingGenericTicksTest01(void)
1293 {
1294 #define TEST_RUNS 1024
1295  uint64_t ticks_start = 0;
1296  uint64_t ticks_end = 0;
1297  void *ptr[TEST_RUNS];
1298  unsigned int i;
1299 
1300  ticks_start = UtilCpuGetTicks();
1301  for (i = 0; i < TEST_RUNS; i++) {
1302  ptr[i] = SCMalloc(1024);
1303  }
1304  ticks_end = UtilCpuGetTicks();
1305  printf("malloc(1024) %"PRIu64"\n", (ticks_end - ticks_start)/TEST_RUNS);
1306 
1307  ticks_start = UtilCpuGetTicks();
1308  for (i = 0; i < TEST_RUNS; i++) {
1309  SCFree(ptr[i]);
1310  }
1311  ticks_end = UtilCpuGetTicks();
1312  printf("SCFree(1024) %"PRIu64"\n", (ticks_end - ticks_start)/TEST_RUNS);
1313 
1314  SCMutex m[TEST_RUNS];
1315 
1316  ticks_start = UtilCpuGetTicks();
1317  for (i = 0; i < TEST_RUNS; i++) {
1318  SCMutexInit(&m[i], NULL);
1319  }
1320  ticks_end = UtilCpuGetTicks();
1321  printf("SCMutexInit() %"PRIu64"\n", (ticks_end - ticks_start)/TEST_RUNS);
1322 
1323  ticks_start = UtilCpuGetTicks();
1324  for (i = 0; i < TEST_RUNS; i++) {
1325  SCMutexLock(&m[i]);
1326  }
1327  ticks_end = UtilCpuGetTicks();
1328  printf("SCMutexLock() %"PRIu64"\n", (ticks_end - ticks_start)/TEST_RUNS);
1329 
1330  ticks_start = UtilCpuGetTicks();
1331  for (i = 0; i < TEST_RUNS; i++) {
1332  SCMutexUnlock(&m[i]);
1333  }
1334  ticks_end = UtilCpuGetTicks();
1335  printf("SCMutexUnlock() %"PRIu64"\n", (ticks_end - ticks_start)/TEST_RUNS);
1336 
1337  ticks_start = UtilCpuGetTicks();
1338  for (i = 0; i < TEST_RUNS; i++) {
1339  SCMutexDestroy(&m[i]);
1340  }
1341  ticks_end = UtilCpuGetTicks();
1342  printf("SCMutexDestroy() %"PRIu64"\n", (ticks_end - ticks_start)/TEST_RUNS);
1343 
1344  SCSpinlock s[TEST_RUNS];
1345 
1346  ticks_start = UtilCpuGetTicks();
1347  for (i = 0; i < TEST_RUNS; i++) {
1348  SCSpinInit(&s[i], 0);
1349  }
1350  ticks_end = UtilCpuGetTicks();
1351  printf("SCSpinInit() %"PRIu64"\n", (ticks_end - ticks_start)/TEST_RUNS);
1352 
1353  ticks_start = UtilCpuGetTicks();
1354  for (i = 0; i < TEST_RUNS; i++) {
1355  SCSpinLock(&s[i]);
1356  }
1357  ticks_end = UtilCpuGetTicks();
1358  printf("SCSpinLock() %"PRIu64"\n", (ticks_end - ticks_start)/TEST_RUNS);
1359 
1360  ticks_start = UtilCpuGetTicks();
1361  for (i = 0; i < TEST_RUNS; i++) {
1362  SCSpinUnlock(&s[i]);
1363  }
1364  ticks_end = UtilCpuGetTicks();
1365  printf("SCSpinUnlock() %"PRIu64"\n", (ticks_end - ticks_start)/TEST_RUNS);
1366 
1367  ticks_start = UtilCpuGetTicks();
1368  for (i = 0; i < TEST_RUNS; i++) {
1369  SCSpinDestroy(&s[i]);
1370  }
1371  ticks_end = UtilCpuGetTicks();
1372  printf("SCSpinDestroy() %"PRIu64"\n", (ticks_end - ticks_start)/TEST_RUNS);
1373 
1374  SC_ATOMIC_DECL_AND_INIT(unsigned int, test);
1375  ticks_start = UtilCpuGetTicks();
1376  for (i = 0; i < TEST_RUNS; i++) {
1377  (void) SC_ATOMIC_ADD(test,1);
1378  }
1379  ticks_end = UtilCpuGetTicks();
1380  printf("SC_ATOMIC_ADD %"PRIu64"\n", (ticks_end - ticks_start)/TEST_RUNS);
1381 
1382  ticks_start = UtilCpuGetTicks();
1383  for (i = 0; i < TEST_RUNS; i++) {
1384  SC_ATOMIC_CAS(&test,i,i+1);
1385  }
1386  ticks_end = UtilCpuGetTicks();
1387  printf("SC_ATOMIC_CAS %"PRIu64"\n", (ticks_end - ticks_start)/TEST_RUNS);
1388  return 1;
1389 }
1390 
1391 #endif /* UNITTESTS */
1392 
1393 void
1395 {
1396 #ifdef UNITTESTS
1397  UtRegisterTest("ProfilingGenericTicksTest01", ProfilingGenericTicksTest01);
1398 #endif /* UNITTESTS */
1399 }
1400 
1401 #endif /* PROFILING */
SCProfilePacketData
struct SCProfilePacketData_ SCProfilePacketData
util-byte.h
tm-threads.h
ConfGetInt
int ConfGetInt(const char *name, intmax_t *val)
Retrieve a configuration value as an integer.
Definition: conf.c:397
Packet_::proto
uint8_t proto
Definition: decode.h:450
PROF_DETECT_GETSGH
@ PROF_DETECT_GETSGH
Definition: suricata-common.h:430
SCSpinDestroy
#define SCSpinDestroy
Definition: threads-debug.h:239
PktProfilingData_::ticks_end
uint64_t ticks_end
Definition: decode.h:347
ConfNodeChildValueIsTrue
int ConfNodeChildValueIsTrue(const ConfNode *node, const char *key)
Test if a configuration node has a true value.
Definition: conf.c:853
LockRecordInitHash
int LockRecordInitHash(void)
profiling_locks_file_mode
const char * profiling_locks_file_mode
SC_ATOMIC_INIT
#define SC_ATOMIC_INIT(name)
wrapper for initializing an atomic variable.
Definition: util-atomic.h:315
PKT_IS_IPV6
#define PKT_IS_IPV6(p)
Definition: decode.h:246
PktProfiling_
Per pkt stats storage.
Definition: decode.h:376
TmModuleTmmIdToString
const char * TmModuleTmmIdToString(TmmId id)
Maps the TmmId, to its string equivalent.
Definition: tm-modules.c:204
unlikely
#define unlikely(expr)
Definition: util-optimize.h:35
PktProfilingTmmData_
Per TMM stats storage.
Definition: decode.h:326
SCProfilePacketData_::max
uint64_t max
Definition: util-profiling.c:57
PROF_DETECT_PF_PAYLOAD
@ PROF_DETECT_PF_PAYLOAD
Definition: suricata-common.h:435
ProfileFlowWorkerIdToString
const char * ProfileFlowWorkerIdToString(enum ProfileFlowWorkerId fwi)
Definition: flow-worker.c:634
UtRegisterTest
void UtRegisterTest(const char *name, int(*TestFn)(void))
Register unit test.
Definition: util-unittest.c:103
LOGGER_ALERT_SYSLOG
@ LOGGER_ALERT_SYSLOG
Definition: suricata-common.h:467
packet_profile_flowworker_data
struct ProfileProtoRecords packet_profile_flowworker_data[PROFILE_FLOWWORKER_SIZE]
Definition: util-profiling.c:94
LOGGER_FILEDATA
@ LOGGER_FILEDATA
Definition: suricata-common.h:458
LOGGER_JSON_STATS
@ LOGGER_JSON_STATS
Definition: suricata-common.h:477
Packet_::pcap_cnt
uint64_t pcap_cnt
Definition: decode.h:594
PktProfiling_::ticks_end
uint64_t ticks_end
Definition: decode.h:378
AppProto
uint16_t AppProto
Definition: app-layer-protos.h:80
Packet_::flags
uint32_t flags
Definition: decode.h:463
ConfGetNode
ConfNode * ConfGetNode(const char *name)
Get a ConfNode by name.
Definition: conf.c:181
LOGGER_JSON_ALERT
@ LOGGER_JSON_ALERT
Definition: suricata-common.h:468
ProfileProtoRecords
Definition: util-profiling.c:89
PROF_DETECT_ALERT
@ PROF_DETECT_ALERT
Definition: suricata-common.h:441
LoggerId
LoggerId
Definition: suricata-common.h:449
AppProtoToString
const char * AppProtoToString(AppProto alproto)
Maps the ALPROTO_*, to its string equivalent.
Definition: app-layer-protos.c:30
SC_ATOMIC_ADD
#define SC_ATOMIC_ADD(name, val)
add a value to our atomic variable
Definition: util-atomic.h:333
PacketProfileLoggertIdToString
const char * PacketProfileLoggertIdToString(LoggerId id)
Maps the LoggerId's to its string equivalent for profiling output.
Definition: util-profiling.c:1256
PROF_DETECT_SIZE
@ PROF_DETECT_SIZE
Definition: suricata-common.h:445
packet_profile_data6
SCProfilePacketData packet_profile_data6[257]
Definition: util-profiling.c:71
PktProfilingTmmData_::ticks_end
uint64_t ticks_end
Definition: decode.h:328
PROF_DETECT_PF_TX
@ PROF_DETECT_PF_TX
Definition: suricata-common.h:436
SC_ATOMIC_CAS
#define SC_ATOMIC_CAS(name, cmpval, newval)
atomic Compare and Switch
Definition: util-atomic.h:368
PROF_DETECT_CLEANUP
@ PROF_DETECT_CLEANUP
Definition: suricata-common.h:443
SCMutexLock
#define SCMutexLock(mut)
Definition: threads-debug.h:117
SCSpinLock
#define SCSpinLock
Definition: threads-debug.h:235
packet_profile_log_data6
SCProfilePacketData packet_profile_log_data6[LOGGER_SIZE][256]
Definition: util-profiling.c:87
SCProfileRuleStart
int SCProfileRuleStart(Packet *p)
Definition: util-profiling.c:1198
SCProfilingAddPacket
void SCProfilingAddPacket(Packet *p)
Definition: util-profiling.c:1098
packet_profile_app_pd_data4
SCProfilePacketData packet_profile_app_pd_data4[257]
Definition: util-profiling.c:80
proto
uint8_t proto
Definition: decode-template.h:0
m
SCMutex m
Definition: flow-hash.h:6
LOGGER_STATS
@ LOGGER_STATS
Definition: suricata-common.h:476
PROFILE_FLOWWORKER_STREAM
@ PROFILE_FLOWWORKER_STREAM
Definition: flow-worker.h:23
SCProfilingDestroy
void SCProfilingDestroy(void)
Free resources used by profiling.
Definition: util-profiling.c:263
ALPROTO_MAX
@ ALPROTO_MAX
Definition: app-layer-protos.h:75
PktProfiling_::app
PktProfilingAppData app[ALPROTO_MAX]
Definition: decode.h:382
PktProfiling_::ticks_start
uint64_t ticks_start
Definition: decode.h:377
profiling_locks_output_to_file
int profiling_locks_output_to_file
util-unittest.h
TEST_RUNS
#define TEST_RUNS
ConfValIsTrue
int ConfValIsTrue(const char *val)
Check if a value is true.
Definition: conf.c:531
PROF_DETECT_PF_SORT2
@ PROF_DETECT_PF_SORT2
Definition: suricata-common.h:439
PktProfilingAppData_::ticks_spent
uint64_t ticks_spent
Definition: decode.h:357
UtilCpuGetTicks
uint64_t UtilCpuGetTicks(void)
Definition: util-cpu.c:194
PROF_DETECT_PF_SORT1
@ PROF_DETECT_PF_SORT1
Definition: suricata-common.h:438
PROF_DETECT_TX_UPDATE
@ PROF_DETECT_TX_UPDATE
Definition: suricata-common.h:442
Packet_::profile
PktProfiling * profile
Definition: decode.h:638
LOGGER_JSON_FLOW
@ LOGGER_JSON_FLOW
Definition: suricata-common.h:474
LOGGER_HTTP
@ LOGGER_HTTP
Definition: suricata-common.h:453
lock
HRLOCK_TYPE lock
Definition: host.h:0
SCProfilingPrintPacketProfile
void SCProfilingPrintPacketProfile(Packet *p)
Definition: util-profiling.c:770
ProfileProtoRecords::records4
SCProfilePacketData records4[257]
Definition: util-profiling.c:90
packet_profile_tmm_data6
SCProfilePacketData packet_profile_tmm_data6[TMM_SIZE][257]
Definition: util-profiling.c:75
packet_profile_detect_data4
SCProfilePacketData packet_profile_detect_data4[PROF_DETECT_SIZE][257]
Definition: util-profiling.c:83
LOGGER_TCP_DATA
@ LOGGER_TCP_DATA
Definition: suricata-common.h:473
packet_profile_tmm_data4
SCProfilePacketData packet_profile_tmm_data4[TMM_SIZE][257]
Definition: util-profiling.c:74
ProfileProtoRecords::records6
SCProfilePacketData records6[257]
Definition: util-profiling.c:91
LOGGER_JSON_FILE
@ LOGGER_JSON_FILE
Definition: suricata-common.h:472
packet_profile_app_data6
SCProfilePacketData packet_profile_app_data6[TMM_SIZE][257]
Definition: util-profiling.c:78
PacketProfileDetectId
enum PacketProfileDetectId_ PacketProfileDetectId
SCMutexUnlock
#define SCMutexUnlock(mut)
Definition: threads-debug.h:119
ProfileFlowWorkerId
ProfileFlowWorkerId
Definition: flow-worker.h:21
PROF_DETECT_PF_PKT
@ PROF_DETECT_PF_PKT
Definition: suricata-common.h:434
LOGGER_UNDEFINED
@ LOGGER_UNDEFINED
Definition: suricata-common.h:450
PktProfilingData_
Definition: decode.h:345
packet_profile_log_data4
SCProfilePacketData packet_profile_log_data4[LOGGER_SIZE][256]
Definition: util-profiling.c:86
PktProfiling_::logger
PktProfilingLoggerData logger[LOGGER_SIZE]
Definition: decode.h:384
SCSpinUnlock
#define SCSpinUnlock
Definition: threads-debug.h:237
PROFILE_FLOWWORKER_APPLAYERUDP
@ PROFILE_FLOWWORKER_APPLAYERUDP
Definition: flow-worker.h:24
PktProfilingDetectData_
Definition: decode.h:350
SCLogWarning
#define SCLogWarning(...)
Macro used to log WARNING messages.
Definition: util-debug.h:249
LOGGER_TLS
@ LOGGER_TLS
Definition: suricata-common.h:455
util-profiling.h
LOGGER_SIZE
@ LOGGER_SIZE
Definition: suricata-common.h:481
SC_ATOMIC_DECLARE
#define SC_ATOMIC_DECLARE(type, name)
wrapper for declaring atomic variables.
Definition: util-atomic.h:281
SCProfilePacketData_
Definition: util-profiling.c:55
profiling_packets_enabled
int profiling_packets_enabled
Definition: util-profiling.c:96
packet_profile_app_pd_data6
SCProfilePacketData packet_profile_app_pd_data6[257]
Definition: util-profiling.c:81
Packet_
Definition: decode.h:428
LOGGER_JSON_NETFLOW
@ LOGGER_JSON_NETFLOW
Definition: suricata-common.h:475
TM_FLAG_DECODE_TM
#define TM_FLAG_DECODE_TM
Definition: tm-modules.h:32
tmm_modules
TmModule tmm_modules[TMM_SIZE]
Definition: tm-modules.c:33
conf.h
TMM_SIZE
@ TMM_SIZE
Definition: tm-threads-common.h:79
PROF_DETECT_IPONLY
@ PROF_DETECT_IPONLY
Definition: suricata-common.h:431
IS_TUNNEL_PKT
#define IS_TUNNEL_PKT(p)
Definition: decode.h:797
TM_FLAG_LOGAPI_TM
#define TM_FLAG_LOGAPI_TM
Definition: tm-modules.h:35
SCLogInfo
#define SCLogInfo(...)
Macro used to log INFORMATIONAL messages.
Definition: util-debug.h:224
PacketProfileDetectIdToString
const char * PacketProfileDetectIdToString(PacketProfileDetectId id)
Maps the PacketProfileDetectId, to its string equivalent.
Definition: util-profiling.c:1226
SCMutexInit
#define SCMutexInit(mut, mutattrs)
Definition: threads-debug.h:116
TM_FLAG_RECEIVE_TM
#define TM_FLAG_RECEIVE_TM
Definition: tm-modules.h:31
PktProfilingData_::ticks_start
uint64_t ticks_start
Definition: decode.h:346
SCProfilePacketData_::tot
uint64_t tot
Definition: util-profiling.c:58
TMM_FLOWWORKER
@ TMM_FLOWWORKER
Definition: tm-threads-common.h:34
PktProfiling_::detect
PktProfilingDetectData detect[PROF_DETECT_SIZE]
Definition: decode.h:383
util-conf.h
LOGGER_PCAP
@ LOGGER_PCAP
Definition: suricata-common.h:478
LOGGER_JSON_METADATA
@ LOGGER_JSON_METADATA
Definition: suricata-common.h:479
flags
uint8_t flags
Definition: decode-gre.h:0
suricata-common.h
SC_ATOMIC_DECL_AND_INIT
#define SC_ATOMIC_DECL_AND_INIT(type, name)
wrapper for declaring an atomic variable and initializing it.
Definition: util-atomic.h:309
PROF_DETECT_PF_RECORD
@ PROF_DETECT_PF_RECORD
Definition: suricata-common.h:437
PROFILE_FLOWWORKER_SIZE
@ PROFILE_FLOWWORKER_SIZE
Definition: flow-worker.h:29
LOGGER_JSON_DROP
@ LOGGER_JSON_DROP
Definition: suricata-common.h:470
SCLogPerf
#define SCLogPerf(...)
Definition: util-debug.h:230
PROF_DETECT_SETUP
@ PROF_DETECT_SETUP
Definition: suricata-common.h:429
LOGGER_ALERT_DEBUG
@ LOGGER_ALERT_DEBUG
Definition: suricata-common.h:465
FatalError
#define FatalError(...)
Definition: util-debug.h:502
SCProfilingDump
void SCProfilingDump(void)
Definition: util-profiling.c:289
packet_profile_app_data4
SCProfilePacketData packet_profile_app_data4[TMM_SIZE][257]
Definition: util-profiling.c:77
packet_profile_detect_data6
SCProfilePacketData packet_profile_detect_data6[PROF_DETECT_SIZE][257]
Definition: util-profiling.c:84
SCSpinInit
#define SCSpinInit
Definition: threads-debug.h:238
LOGGER_FILE
@ LOGGER_FILE
Definition: suricata-common.h:457
SCMalloc
#define SCMalloc(sz)
Definition: util-mem.h:47
ConfigGetLogDirectory
const char * ConfigGetLogDirectory(void)
Definition: util-conf.c:37
PROF_DETECT_RULES
@ PROF_DETECT_RULES
Definition: suricata-common.h:432
LOGGER_JSON_TX
@ LOGGER_JSON_TX
Definition: suricata-common.h:456
PROF_DETECT_NONMPMLIST
@ PROF_DETECT_NONMPMLIST
Definition: suricata-common.h:440
str
#define str(s)
Definition: suricata-common.h:280
SCLogError
#define SCLogError(...)
Macro used to log ERROR messages.
Definition: util-debug.h:261
SCFree
#define SCFree(p)
Definition: util-mem.h:61
ConfNode_
Definition: conf.h:32
packet_profile_data4
SCProfilePacketData packet_profile_data4[257]
Definition: util-profiling.c:70
profiling_locks_file_name
char * profiling_locks_file_name
PktProfilingLoggerData_
Definition: decode.h:360
PktProfiling_::tmm
PktProfilingTmmData tmm[TMM_SIZE]
Definition: decode.h:380
PKT_PROFILE
#define PKT_PROFILE
Definition: decode.h:1029
LockRecordFreeHash
void LockRecordFreeHash(void)
ALPROTO_FAILED
@ ALPROTO_FAILED
Definition: app-layer-protos.h:70
SCSpinlock
#define SCSpinlock
Definition: threads-debug.h:234
LOGGER_FILE_STORE
@ LOGGER_FILE_STORE
Definition: suricata-common.h:471
SCProfilePacketData_::min
uint64_t min
Definition: util-profiling.c:56
LOGGER_JSON_FRAME
@ LOGGER_JSON_FRAME
Definition: suricata-common.h:480
profiling_output_to_file
int profiling_output_to_file
Definition: util-profiling.c:97
SCProfilingDumpPacketStats
void SCProfilingDumpPacketStats(void)
Definition: util-profiling.c:344
PROF_DETECT_TX
@ PROF_DETECT_TX
Definition: suricata-common.h:433
PktProfilingTmmData_::ticks_start
uint64_t ticks_start
Definition: decode.h:327
LOGGER_TLS_STORE
@ LOGGER_TLS_STORE
Definition: suricata-common.h:454
PktProfilingLoggerData_::ticks_spent
uint64_t ticks_spent
Definition: decode.h:363
SCProfilingRegisterTests
void SCProfilingRegisterTests(void)
Definition: util-profiling.c:1394
SCProfilePacketData_::cnt
uint64_t cnt
Definition: util-profiling.c:59
CASE_CODE
#define CASE_CODE(E)
Definition: util-profiling.c:1217
PktProfiling_::flowworker
PktProfilingData flowworker[PROFILE_FLOWWORKER_SIZE]
Definition: decode.h:381
util-profiling-locks.h
PktProfilingAppData_
Definition: decode.h:356
SCCalloc
#define SCCalloc(nm, sz)
Definition: util-mem.h:53
SCMutexDestroy
#define SCMutexDestroy
Definition: threads-debug.h:120
PktProfiling_::proto_detect
uint64_t proto_detect
Definition: decode.h:385
profiling_rules_entered
thread_local int profiling_rules_entered
Definition: util-profiling.c:112
PKT_IS_IPV4
#define PKT_IS_IPV4(p)
Definition: decode.h:245
LOGGER_ALERT_FAST
@ LOGGER_ALERT_FAST
Definition: suricata-common.h:466
SCMutex
#define SCMutex
Definition: threads-debug.h:114
SCProfilingInit
void SCProfilingInit(void)
Initialize profiling.
Definition: util-profiling.c:135
SCProfilePacketStart
PktProfiling * SCProfilePacketStart(void)
Definition: util-profiling.c:1188
PktProfilingDetectData_::ticks_spent
uint64_t ticks_spent
Definition: decode.h:353
profiling_locks_enabled
int profiling_locks_enabled
LOGGER_JSON_ANOMALY
@ LOGGER_JSON_ANOMALY
Definition: suricata-common.h:469
ConfNodeLookupChildValue
const char * ConfNodeLookupChildValue(const ConfNode *node, const char *name)
Lookup the value of a child configuration node by name.
Definition: conf.c:808