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