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  }
165  memset(&packet_profile_data4, 0, sizeof(packet_profile_data4));
166  memset(&packet_profile_data6, 0, sizeof(packet_profile_data6));
178 
179  const char *filename = ConfNodeLookupChildValue(conf, "filename");
180  if (filename != NULL) {
181  const char *log_dir;
182  log_dir = ConfigGetLogDirectory();
183 
184  snprintf(profiling_packets_file_name, sizeof(profiling_packets_file_name),
185  "%s/%s", log_dir, filename);
186 
187  const char *v = ConfNodeLookupChildValue(conf, "append");
188  if (v == NULL || ConfValIsTrue(v)) {
189  profiling_packets_file_mode = "a";
190  } else {
191  profiling_packets_file_mode = "w";
192  }
193 
194  profiling_packets_output_to_file = 1;
195  }
196  }
197 
198  conf = ConfGetNode("profiling.packets.csv");
199  if (conf != NULL) {
200  if (ConfNodeChildValueIsTrue(conf, "enabled")) {
201  const char *filename = ConfNodeLookupChildValue(conf, "filename");
202  if (filename == NULL) {
203  filename = "packet_profile.csv";
204  }
205 
206  const char *log_dir = ConfigGetLogDirectory();
207 
208  profiling_csv_file_name = SCMalloc(PATH_MAX);
209  if (unlikely(profiling_csv_file_name == NULL)) {
210  FatalError(SC_ERR_FATAL, "out of memory");
211  }
212  snprintf(profiling_csv_file_name, PATH_MAX, "%s/%s", log_dir, filename);
213 
214  packet_profile_csv_fp = fopen(profiling_csv_file_name, "w");
215  if (packet_profile_csv_fp == NULL) {
216  SCFree(profiling_csv_file_name);
217  profiling_csv_file_name = NULL;
218  return;
219  }
220 
221  PrintCSVHeader();
222 
223  profiling_packets_csv_enabled = 1;
224  }
225  }
226  }
227 
228  conf = ConfGetNode("profiling.locks");
229  if (conf != NULL) {
230  if (ConfNodeChildValueIsTrue(conf, "enabled")) {
231 #ifndef PROFILE_LOCKING
232  SCLogWarning(SC_WARN_PROFILE, "lock profiling not compiled in. Add --enable-profiling-locks to configure.");
233 #else
235 
237 
238  const char *filename = ConfNodeLookupChildValue(conf, "filename");
239  if (filename != NULL) {
240  const char *log_dir = ConfigGetLogDirectory();
241 
243  if (unlikely(profiling_locks_file_name == NULL)) {
244  FatalError(SC_ERR_FATAL, "can't duplicate file name");
245  }
246 
247  snprintf(profiling_locks_file_name, PATH_MAX, "%s/%s", log_dir, filename);
248 
249  const char *v = ConfNodeLookupChildValue(conf, "append");
250  if (v == NULL || ConfValIsTrue(v)) {
252  } else {
254  }
255 
257  }
258 #endif
259  }
260  }
261 
262 }
263 
264 /**
265  * \brief Free resources used by profiling.
266  */
267 void
269 {
271  pthread_mutex_destroy(&packet_profile_lock);
272  }
273 
274  if (profiling_packets_csv_enabled) {
275  if (packet_profile_csv_fp != NULL)
276  fclose(packet_profile_csv_fp);
277  packet_profile_csv_fp = NULL;
278  }
279 
280  if (profiling_csv_file_name != NULL)
281  SCFree(profiling_csv_file_name);
282  profiling_csv_file_name = NULL;
283 
284  if (profiling_file_name != NULL)
285  SCFree(profiling_file_name);
286  profiling_file_name = NULL;
287 
288 #ifdef PROFILE_LOCKING
290 #endif
291 }
292 
293 void
295 {
297  SCLogPerf("Done dumping profiling data.");
298 }
299 
300 static void DumpFlowWorkerIP(FILE *fp, int ipv, uint64_t total)
301 {
302  char totalstr[256];
303 
304  enum ProfileFlowWorkerId fwi;
305  for (fwi = 0; fwi < PROFILE_FLOWWORKER_SIZE; fwi++) {
307  for (int p = 0; p < 257; p++) {
308  SCProfilePacketData *pd = ipv == 4 ? &r->records4[p] : &r->records6[p];
309  if (pd->cnt == 0) {
310  continue;
311  }
312 
313  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
314  double percent = (long double)pd->tot /
315  (long double)total * 100;
316 
317  fprintf(fp, "%-20s IPv%d %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %-6.2f\n",
318  ProfileFlowWorkerIdToString(fwi), ipv, p, pd->cnt,
319  pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
320  }
321  }
322 }
323 
324 static void DumpFlowWorker(FILE *fp)
325 {
326  uint64_t total = 0;
327 
328  enum ProfileFlowWorkerId fwi;
329  for (fwi = 0; fwi < PROFILE_FLOWWORKER_SIZE; fwi++) {
331  for (int p = 0; p < 257; p++) {
332  SCProfilePacketData *pd = &r->records4[p];
333  total += pd->tot;
334  pd = &r->records6[p];
335  total += pd->tot;
336  }
337  }
338 
339  fprintf(fp, "\n%-20s %-6s %-5s %-12s %-12s %-12s %-12s\n",
340  "Flow Worker", "IP ver", "Proto", "cnt", "min", "max", "avg");
341  fprintf(fp, "%-20s %-6s %-5s %-12s %-12s %-12s %-12s\n",
342  "--------------------", "------", "-----", "----------", "------------", "------------", "-----------");
343  DumpFlowWorkerIP(fp, 4, total);
344  DumpFlowWorkerIP(fp, 6, total);
345  fprintf(fp, "Note: %s includes app-layer for TCP\n",
347 }
348 
350 {
351  int i;
352  FILE *fp;
353  char totalstr[256];
354  uint64_t total;
355 
356  if (profiling_packets_enabled == 0)
357  return;
358 
359  if (profiling_packets_output_to_file == 1) {
360  fp = fopen(profiling_packets_file_name, profiling_packets_file_mode);
361 
362  if (fp == NULL) {
363  SCLogError(SC_ERR_FOPEN, "failed to open %s: %s",
364  profiling_packets_file_name, strerror(errno));
365  return;
366  }
367  } else {
368  fp = stdout;
369  }
370 
371  fprintf(fp, "\n\nPacket profile dump:\n");
372 
373  fprintf(fp, "\n%-6s %-5s %-12s %-12s %-12s %-12s %-12s %-3s\n",
374  "IP ver", "Proto", "cnt", "min", "max", "avg", "tot", "%%");
375  fprintf(fp, "%-6s %-5s %-12s %-12s %-12s %-12s %-12s %-3s\n",
376  "------", "-----", "----------", "------------", "------------", "-----------", "-----------", "---");
377  total = 0;
378  for (i = 0; i < 257; i++) {
380  total += pd->tot;
381  pd = &packet_profile_data6[i];
382  total += pd->tot;
383  }
384 
385  for (i = 0; i < 257; i++) {
387 
388  if (pd->cnt == 0) {
389  continue;
390  }
391 
392  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
393  double percent = (long double)pd->tot /
394  (long double)total * 100;
395 
396  fprintf(fp, " IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %6.2f\n", i, pd->cnt,
397  pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
398  }
399 
400  for (i = 0; i < 257; i++) {
402 
403  if (pd->cnt == 0) {
404  continue;
405  }
406 
407  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
408  double percent = (long double)pd->tot /
409  (long double)total * 100;
410 
411  fprintf(fp, " IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %6.2f\n", i, pd->cnt,
412  pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
413  }
414  fprintf(fp, "Note: Protocol 256 tracks pseudo/tunnel packets.\n");
415 
416  fprintf(fp, "\nPer Thread module stats:\n");
417 
418  fprintf(fp, "\n%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s %-3s",
419  "Thread Module", "IP ver", "Proto", "cnt", "min", "max", "avg", "tot", "%%");
420 #ifdef PROFILE_LOCKING
421  fprintf(fp, " %-10s %-10s %-12s %-12s %-10s %-10s %-12s %-12s\n",
422  "locks", "ticks", "cont.", "cont.avg", "slocks", "sticks", "scont.", "scont.avg");
423 #else
424  fprintf(fp, "\n");
425 #endif
426  fprintf(fp, "%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s %-3s",
427  "------------------------", "------", "-----", "----------", "------------", "------------", "-----------", "-----------", "---");
428 #ifdef PROFILE_LOCKING
429  fprintf(fp, " %-10s %-10s %-12s %-12s %-10s %-10s %-12s %-12s\n",
430  "--------", "--------", "----------", "-----------", "--------", "--------", "------------", "-----------");
431 #else
432  fprintf(fp, "\n");
433 #endif
434  int m;
435  total = 0;
436  for (m = 0; m < TMM_SIZE; m++) {
438  continue;
439 
440  int p;
441  for (p = 0; p < 257; p++) {
443  total += pd->tot;
444 
445  pd = &packet_profile_tmm_data6[m][p];
446  total += pd->tot;
447  }
448  }
449 
450  for (m = 0; m < TMM_SIZE; m++) {
452  continue;
453 
454  int p;
455  for (p = 0; p < 257; p++) {
457 
458  if (pd->cnt == 0) {
459  continue;
460  }
461 
462  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
463  double percent = (long double)pd->tot /
464  (long double)total * 100;
465 
466  fprintf(fp, "%-24s IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %6.2f",
467  TmModuleTmmIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
468 #ifdef PROFILE_LOCKING
469  fprintf(fp, " %10.2f %12"PRIu64" %12"PRIu64" %10.2f %10.2f %12"PRIu64" %12"PRIu64" %10.2f\n",
470  (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);
471 #else
472  fprintf(fp, "\n");
473 #endif
474  }
475  }
476 
477  for (m = 0; m < TMM_SIZE; m++) {
479  continue;
480 
481  int p;
482  for (p = 0; p < 257; p++) {
484 
485  if (pd->cnt == 0) {
486  continue;
487  }
488 
489  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
490  double percent = (long double)pd->tot /
491  (long double)total * 100;
492 
493  fprintf(fp, "%-24s IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %6.2f\n",
494  TmModuleTmmIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
495  }
496  }
497 
498  DumpFlowWorker(fp);
499 
500  fprintf(fp, "\nPer App layer parser stats:\n");
501 
502  fprintf(fp, "\n%-20s %-6s %-5s %-12s %-12s %-12s %-12s\n",
503  "App Layer", "IP ver", "Proto", "cnt", "min", "max", "avg");
504  fprintf(fp, "%-20s %-6s %-5s %-12s %-12s %-12s %-12s\n",
505  "--------------------", "------", "-----", "----------", "------------", "------------", "-----------");
506 
507  total = 0;
508  for (m = 0; m < ALPROTO_MAX; m++) {
509  int p;
510  for (p = 0; p < 257; p++) {
512  total += pd->tot;
513 
514  pd = &packet_profile_app_data6[m][p];
515  total += pd->tot;
516  }
517  }
518  for (m = 0; m < ALPROTO_MAX; m++) {
519  int p;
520  for (p = 0; p < 257; p++) {
522 
523  if (pd->cnt == 0) {
524  continue;
525  }
526 
527  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
528  double percent = (long double)pd->tot /
529  (long double)total * 100;
530 
531  fprintf(fp, "%-20s IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %-6.2f\n",
532  AppProtoToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
533  }
534  }
535 
536  for (m = 0; m < ALPROTO_MAX; m++) {
537  int p;
538  for (p = 0; p < 257; p++) {
540 
541  if (pd->cnt == 0) {
542  continue;
543  }
544 
545  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
546  double percent = (long double)pd->tot /
547  (long double)total * 100;
548 
549  fprintf(fp, "%-20s IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %-6.2f\n",
550  AppProtoToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
551  }
552  }
553 
554  /* proto detect output */
555  {
556  int p;
557  for (p = 0; p < 257; p++) {
559 
560  if (pd->cnt == 0) {
561  continue;
562  }
563 
564  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
565  fprintf(fp, "%-20s IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s\n",
566  "Proto detect", p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr);
567  }
568 
569  for (p = 0; p < 257; p++) {
571 
572  if (pd->cnt == 0) {
573  continue;
574  }
575 
576  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
577  fprintf(fp, "%-20s IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s\n",
578  "Proto detect", p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr);
579  }
580  }
581 
582  total = 0;
583  for (m = 0; m < PROF_DETECT_SIZE; m++) {
584  int p;
585  for (p = 0; p < 257; p++) {
587  total += pd->tot;
588 
589  pd = &packet_profile_detect_data6[m][p];
590  total += pd->tot;
591  }
592  }
593 
594 
595  fprintf(fp, "\n%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s %-3s",
596  "Log Thread Module", "IP ver", "Proto", "cnt", "min", "max", "avg", "tot", "%%");
597 #ifdef PROFILE_LOCKING
598  fprintf(fp, " %-10s %-10s %-12s %-12s %-10s %-10s %-12s %-12s\n",
599  "locks", "ticks", "cont.", "cont.avg", "slocks", "sticks", "scont.", "scont.avg");
600 #else
601  fprintf(fp, "\n");
602 #endif
603  fprintf(fp, "%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s %-3s",
604  "------------------------", "------", "-----", "----------", "------------", "------------", "-----------", "-----------", "---");
605 #ifdef PROFILE_LOCKING
606  fprintf(fp, " %-10s %-10s %-12s %-12s %-10s %-10s %-12s %-12s\n",
607  "--------", "--------", "----------", "-----------", "--------", "--------", "------------", "-----------");
608 #else
609  fprintf(fp, "\n");
610 #endif
611  total = 0;
612  for (m = 0; m < TMM_SIZE; m++) {
614  continue;
615 
616  int p;
617  for (p = 0; p < 257; p++) {
619  total += pd->tot;
620 
621  pd = &packet_profile_tmm_data6[m][p];
622  total += pd->tot;
623  }
624  }
625 
626  for (m = 0; m < TMM_SIZE; m++) {
628  continue;
629 
630  int p;
631  for (p = 0; p < 257; p++) {
633 
634  if (pd->cnt == 0) {
635  continue;
636  }
637 
638  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
639  double percent = (long double)pd->tot /
640  (long double)total * 100;
641 
642  fprintf(fp, "%-24s IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %6.2f",
643  TmModuleTmmIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
644 #ifdef PROFILE_LOCKING
645  fprintf(fp, " %10.2f %12"PRIu64" %12"PRIu64" %10.2f %10.2f %12"PRIu64" %12"PRIu64" %10.2f\n",
646  (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);
647 #else
648  fprintf(fp, "\n");
649 #endif
650  }
651  }
652 
653  for (m = 0; m < TMM_SIZE; m++) {
655  continue;
656 
657  int p;
658  for (p = 0; p < 257; p++) {
660 
661  if (pd->cnt == 0) {
662  continue;
663  }
664 
665  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
666  double percent = (long double)pd->tot /
667  (long double)total * 100;
668 
669  fprintf(fp, "%-24s IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %6.2f\n",
670  TmModuleTmmIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
671  }
672  }
673 
674  fprintf(fp, "\nLogger/output stats:\n");
675 
676  total = 0;
677  for (m = 0; m < LOGGER_SIZE; m++) {
678  int p;
679  for (p = 0; p < 256; p++) {
681  total += pd->tot;
682  pd = &packet_profile_log_data6[m][p];
683  total += pd->tot;
684  }
685  }
686 
687  fprintf(fp, "\n%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s\n",
688  "Logger", "IP ver", "Proto", "cnt", "min", "max", "avg", "tot");
689  fprintf(fp, "%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s\n",
690  "------------------------", "------", "-----", "----------", "------------", "------------", "-----------", "-----------");
691  for (m = 0; m < LOGGER_SIZE; m++) {
692  int p;
693  for (p = 0; p < 256; p++) {
695 
696  if (pd->cnt == 0) {
697  continue;
698  }
699 
700  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
701  double percent = (long double)pd->tot /
702  (long double)total * 100;
703 
704  fprintf(fp, "%-24s IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %-6.2f\n",
705  PacketProfileLoggertIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
706  }
707  }
708  for (m = 0; m < LOGGER_SIZE; m++) {
709  int p;
710  for (p = 0; p < 256; p++) {
712 
713  if (pd->cnt == 0) {
714  continue;
715  }
716 
717  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
718  double percent = (long double)pd->tot /
719  (long double)total * 100;
720 
721  fprintf(fp, "%-24s IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %-6.2f\n",
722  PacketProfileLoggertIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
723  }
724  }
725 
726  fprintf(fp, "\nGeneral detection engine stats:\n");
727 
728  total = 0;
729  for (m = 0; m < PROF_DETECT_SIZE; m++) {
730  int p;
731  for (p = 0; p < 257; p++) {
733  total += pd->tot;
734  pd = &packet_profile_detect_data6[m][p];
735  total += pd->tot;
736  }
737  }
738 
739  fprintf(fp, "\n%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s\n",
740  "Detection phase", "IP ver", "Proto", "cnt", "min", "max", "avg", "tot");
741  fprintf(fp, "%-24s %-6s %-5s %-12s %-12s %-12s %-12s %-12s\n",
742  "------------------------", "------", "-----", "----------", "------------", "------------", "-----------", "-----------");
743  for (m = 0; m < PROF_DETECT_SIZE; m++) {
744  int p;
745  for (p = 0; p < 257; p++) {
747 
748  if (pd->cnt == 0) {
749  continue;
750  }
751 
752  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
753  double percent = (long double)pd->tot /
754  (long double)total * 100;
755 
756  fprintf(fp, "%-24s IPv4 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %-6.2f\n",
757  PacketProfileDetectIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
758  }
759  }
760  for (m = 0; m < PROF_DETECT_SIZE; m++) {
761  int p;
762  for (p = 0; p < 257; p++) {
764 
765  if (pd->cnt == 0) {
766  continue;
767  }
768 
769  FormatNumber(pd->tot, totalstr, sizeof(totalstr));
770  double percent = (long double)pd->tot /
771  (long double)total * 100;
772 
773  fprintf(fp, "%-24s IPv6 %3d %12"PRIu64" %12"PRIu64" %12"PRIu64" %12"PRIu64" %12s %-6.2f\n",
774  PacketProfileDetectIdToString(m), p, pd->cnt, pd->min, pd->max, (uint64_t)(pd->tot / pd->cnt), totalstr, percent);
775  }
776  }
777  fclose(fp);
778 }
779 
780 static void PrintCSVHeader(void)
781 {
782  fprintf(packet_profile_csv_fp, "pcap_cnt,total,receive,decode,flowworker,");
783  fprintf(packet_profile_csv_fp, "threading,");
784  fprintf(packet_profile_csv_fp, "proto detect,");
785 
786  for (enum ProfileFlowWorkerId fwi = 0; fwi < PROFILE_FLOWWORKER_SIZE; fwi++) {
787  fprintf(packet_profile_csv_fp, "%s,", ProfileFlowWorkerIdToString(fwi));
788  }
789  fprintf(packet_profile_csv_fp, "loggers,");
790 
791  /* detect stages */
792  for (int i = 0; i < PROF_DETECT_SIZE; i++) {
793  fprintf(packet_profile_csv_fp, "%s,", PacketProfileDetectIdToString(i));
794  }
795 
796  /* individual loggers */
797  for (LoggerId i = 0; i < LOGGER_SIZE; i++) {
798  fprintf(packet_profile_csv_fp, "%s,", PacketProfileLoggertIdToString(i));
799  }
800 
801  fprintf(packet_profile_csv_fp, "\n");
802 }
803 
805 {
806  if (profiling_packets_csv_enabled == 0 || p == NULL ||
807  packet_profile_csv_fp == NULL || p->profile == NULL) {
808  return;
809  }
810 
811  uint64_t tmm_total = 0;
812  uint64_t receive = 0;
813  uint64_t decode = 0;
814 
815  /* total cost from acquisition to return to packetpool */
816  uint64_t delta = p->profile->ticks_end - p->profile->ticks_start;
817  fprintf(packet_profile_csv_fp, "%"PRIu64",%"PRIu64",",
818  p->pcap_cnt, delta);
819 
820  for (int i = 0; i < TMM_SIZE; i++) {
821  const PktProfilingTmmData *pdt = &p->profile->tmm[i];
822  uint64_t tmm_delta = pdt->ticks_end - pdt->ticks_start;
823 
825  if (tmm_delta) {
826  receive = tmm_delta;
827  }
828  continue;
829 
830  } else if (tmm_modules[i].flags & TM_FLAG_DECODE_TM) {
831  if (tmm_delta) {
832  decode = tmm_delta;
833  }
834  continue;
835  }
836 
837  tmm_total += tmm_delta;
838  }
839  fprintf(packet_profile_csv_fp, "%"PRIu64",", receive);
840  fprintf(packet_profile_csv_fp, "%"PRIu64",", decode);
842  fprintf(packet_profile_csv_fp, "%"PRIu64",", fw_pdt->ticks_end - fw_pdt->ticks_start);
843  fprintf(packet_profile_csv_fp, "%"PRIu64",", delta - tmm_total);
844 
845  /* count ticks for app layer */
846  uint64_t app_total = 0;
847  for (AppProto i = 1; i < ALPROTO_FAILED; i++) {
848  const PktProfilingAppData *pdt = &p->profile->app[i];
849 
850  if (p->proto == IPPROTO_TCP) {
851  app_total += pdt->ticks_spent;
852  }
853  }
854 
855  fprintf(packet_profile_csv_fp, "%"PRIu64",", p->profile->proto_detect);
856 
857  /* print flowworker steps */
858  for (enum ProfileFlowWorkerId fwi = 0; fwi < PROFILE_FLOWWORKER_SIZE; fwi++) {
859  const PktProfilingData *pd = &p->profile->flowworker[fwi];
860  uint64_t ticks_spent = pd->ticks_end - pd->ticks_start;
861  if (fwi == PROFILE_FLOWWORKER_STREAM) {
862  ticks_spent -= app_total;
863  } else if (fwi == PROFILE_FLOWWORKER_APPLAYERUDP && app_total) {
864  ticks_spent = app_total;
865  }
866 
867  fprintf(packet_profile_csv_fp, "%"PRIu64",", ticks_spent);
868  }
869 
870  /* count loggers cost and print as a single cost */
871  uint64_t loggers = 0;
872  for (LoggerId i = 0; i < LOGGER_SIZE; i++) {
873  const PktProfilingLoggerData *pd = &p->profile->logger[i];
874  loggers += pd->ticks_spent;
875  }
876  fprintf(packet_profile_csv_fp, "%"PRIu64",", loggers);
877 
878  /* detect steps */
879  for (int i = 0; i < PROF_DETECT_SIZE; i++) {
880  const PktProfilingDetectData *pdt = &p->profile->detect[i];
881 
882  fprintf(packet_profile_csv_fp,"%"PRIu64",", pdt->ticks_spent);
883  }
884 
885  /* print individual loggers */
886  for (LoggerId i = 0; i < LOGGER_SIZE; i++) {
887  const PktProfilingLoggerData *pd = &p->profile->logger[i];
888  fprintf(packet_profile_csv_fp, "%"PRIu64",", pd->ticks_spent);
889  }
890 
891  fprintf(packet_profile_csv_fp,"\n");
892 }
893 
894 static void SCProfilingUpdatePacketDetectRecord(PacketProfileDetectId id, uint8_t ipproto, PktProfilingDetectData *pdt, int ipver)
895 {
896  if (pdt == NULL) {
897  return;
898  }
899 
901  if (ipver == 4)
902  pd = &packet_profile_detect_data4[id][ipproto];
903  else
904  pd = &packet_profile_detect_data6[id][ipproto];
905 
906  if (pd->min == 0 || pdt->ticks_spent < pd->min) {
907  pd->min = pdt->ticks_spent;
908  }
909  if (pd->max < pdt->ticks_spent) {
910  pd->max = pdt->ticks_spent;
911  }
912 
913  pd->tot += pdt->ticks_spent;
914  pd->cnt ++;
915 }
916 
917 static void SCProfilingUpdatePacketDetectRecords(Packet *p)
918 {
920  for (i = 0; i < PROF_DETECT_SIZE; i++) {
921  PktProfilingDetectData *pdt = &p->profile->detect[i];
922 
923  if (pdt->ticks_spent > 0) {
924  if (PKT_IS_IPV4(p)) {
925  SCProfilingUpdatePacketDetectRecord(i, p->proto, pdt, 4);
926  } else {
927  SCProfilingUpdatePacketDetectRecord(i, p->proto, pdt, 6);
928  }
929  }
930  }
931 }
932 
933 static void SCProfilingUpdatePacketAppPdRecord(uint8_t ipproto, uint32_t ticks_spent, int ipver)
934 {
936  if (ipver == 4)
937  pd = &packet_profile_app_pd_data4[ipproto];
938  else
939  pd = &packet_profile_app_pd_data6[ipproto];
940 
941  if (pd->min == 0 || ticks_spent < pd->min) {
942  pd->min = ticks_spent;
943  }
944  if (pd->max < ticks_spent) {
945  pd->max = ticks_spent;
946  }
947 
948  pd->tot += ticks_spent;
949  pd->cnt ++;
950 }
951 
952 static void SCProfilingUpdatePacketAppRecord(int alproto, uint8_t ipproto, PktProfilingAppData *pdt, int ipver)
953 {
954  if (pdt == NULL) {
955  return;
956  }
957 
959  if (ipver == 4)
960  pd = &packet_profile_app_data4[alproto][ipproto];
961  else
962  pd = &packet_profile_app_data6[alproto][ipproto];
963 
964  if (pd->min == 0 || pdt->ticks_spent < pd->min) {
965  pd->min = pdt->ticks_spent;
966  }
967  if (pd->max < pdt->ticks_spent) {
968  pd->max = pdt->ticks_spent;
969  }
970 
971  pd->tot += pdt->ticks_spent;
972  pd->cnt ++;
973 }
974 
975 static void SCProfilingUpdatePacketAppRecords(Packet *p)
976 {
977  int i;
978  for (i = 0; i < ALPROTO_MAX; i++) {
979  PktProfilingAppData *pdt = &p->profile->app[i];
980 
981  if (pdt->ticks_spent > 0) {
982  if (PKT_IS_IPV4(p)) {
983  SCProfilingUpdatePacketAppRecord(i, p->proto, pdt, 4);
984  } else {
985  SCProfilingUpdatePacketAppRecord(i, p->proto, pdt, 6);
986  }
987  }
988  }
989 
990  if (p->profile->proto_detect > 0) {
991  if (PKT_IS_IPV4(p)) {
992  SCProfilingUpdatePacketAppPdRecord(p->proto, p->profile->proto_detect, 4);
993  } else {
994  SCProfilingUpdatePacketAppPdRecord(p->proto, p->profile->proto_detect, 6);
995  }
996  }
997 }
998 
999 static void SCProfilingUpdatePacketTmmRecord(int module, uint8_t proto, PktProfilingTmmData *pdt, int ipver)
1000 {
1001  if (pdt == NULL) {
1002  return;
1003  }
1004 
1005  SCProfilePacketData *pd;
1006  if (ipver == 4)
1007  pd = &packet_profile_tmm_data4[module][proto];
1008  else
1009  pd = &packet_profile_tmm_data6[module][proto];
1010 
1011  uint32_t delta = (uint32_t)pdt->ticks_end - pdt->ticks_start;
1012  if (pd->min == 0 || delta < pd->min) {
1013  pd->min = delta;
1014  }
1015  if (pd->max < delta) {
1016  pd->max = delta;
1017  }
1018 
1019  pd->tot += (uint64_t)delta;
1020  pd->cnt ++;
1021 
1022 #ifdef PROFILE_LOCKING
1023  pd->lock += pdt->mutex_lock_cnt;
1024  pd->ticks += pdt->mutex_lock_wait_ticks;
1025  pd->contention += pdt->mutex_lock_contention;
1026  pd->slock += pdt->spin_lock_cnt;
1027  pd->sticks += pdt->spin_lock_wait_ticks;
1028  pd->scontention += pdt->spin_lock_contention;
1029 #endif
1030 }
1031 
1032 static void SCProfilingUpdatePacketTmmRecords(Packet *p)
1033 {
1034  int i;
1035  for (i = 0; i < TMM_SIZE; i++) {
1036  PktProfilingTmmData *pdt = &p->profile->tmm[i];
1037 
1038  if (pdt->ticks_start == 0 || pdt->ticks_end == 0 || pdt->ticks_start > pdt->ticks_end) {
1039  continue;
1040  }
1041 
1042  if (PKT_IS_IPV4(p)) {
1043  SCProfilingUpdatePacketTmmRecord(i, p->proto, pdt, 4);
1044  } else {
1045  SCProfilingUpdatePacketTmmRecord(i, p->proto, pdt, 6);
1046  }
1047  }
1048 }
1049 
1050 static inline void SCProfilingUpdatePacketGenericRecord(PktProfilingData *pdt,
1051  SCProfilePacketData *pd)
1052 {
1053  if (pdt == NULL || pd == NULL) {
1054  return;
1055  }
1056 
1057  uint64_t delta = pdt->ticks_end - pdt->ticks_start;
1058  if (pd->min == 0 || delta < pd->min) {
1059  pd->min = delta;
1060  }
1061  if (pd->max < delta) {
1062  pd->max = delta;
1063  }
1064 
1065  pd->tot += delta;
1066  pd->cnt ++;
1067 }
1068 
1069 static void SCProfilingUpdatePacketGenericRecords(Packet *p, PktProfilingData *pd,
1070  struct ProfileProtoRecords *records, int size)
1071 {
1072  int i;
1073  for (i = 0; i < size; i++) {
1074  PktProfilingData *pdt = &pd[i];
1075 
1076  if (pdt->ticks_start == 0 || pdt->ticks_end == 0 || pdt->ticks_start > pdt->ticks_end) {
1077  continue;
1078  }
1079 
1080  struct ProfileProtoRecords *r = &records[i];
1081  SCProfilePacketData *store = NULL;
1082 
1083  if (PKT_IS_IPV4(p)) {
1084  store = &(r->records4[p->proto]);
1085  } else {
1086  store = &(r->records6[p->proto]);
1087  }
1088 
1089  SCProfilingUpdatePacketGenericRecord(pdt, store);
1090  }
1091 }
1092 
1093 static void SCProfilingUpdatePacketLogRecord(LoggerId id,
1094  uint8_t ipproto, PktProfilingLoggerData *pdt, int ipver)
1095 {
1096  if (pdt == NULL) {
1097  return;
1098  }
1099 
1100  SCProfilePacketData *pd;
1101  if (ipver == 4)
1102  pd = &packet_profile_log_data4[id][ipproto];
1103  else
1104  pd = &packet_profile_log_data6[id][ipproto];
1105 
1106  if (pd->min == 0 || pdt->ticks_spent < pd->min) {
1107  pd->min = pdt->ticks_spent;
1108  }
1109  if (pd->max < pdt->ticks_spent) {
1110  pd->max = pdt->ticks_spent;
1111  }
1112 
1113  pd->tot += pdt->ticks_spent;
1114  pd->cnt++;
1115 }
1116 
1117 static void SCProfilingUpdatePacketLogRecords(Packet *p)
1118 {
1119  for (LoggerId i = 0; i < LOGGER_SIZE; i++) {
1120  PktProfilingLoggerData *pdt = &p->profile->logger[i];
1121 
1122  if (pdt->ticks_spent > 0) {
1123  if (PKT_IS_IPV4(p)) {
1124  SCProfilingUpdatePacketLogRecord(i, p->proto, pdt, 4);
1125  } else {
1126  SCProfilingUpdatePacketLogRecord(i, p->proto, pdt, 6);
1127  }
1128  }
1129  }
1130 }
1131 
1133 {
1134  if (p == NULL || p->profile == NULL ||
1135  p->profile->ticks_start == 0 || p->profile->ticks_end == 0 ||
1137  return;
1138 
1139  pthread_mutex_lock(&packet_profile_lock);
1140  {
1141 
1142  if (PKT_IS_IPV4(p)) {
1144 
1145  uint64_t delta = p->profile->ticks_end - p->profile->ticks_start;
1146  if (pd->min == 0 || delta < pd->min) {
1147  pd->min = delta;
1148  }
1149  if (pd->max < delta) {
1150  pd->max = delta;
1151  }
1152 
1153  pd->tot += delta;
1154  pd->cnt ++;
1155 
1156  if (IS_TUNNEL_PKT(p)) {
1157  pd = &packet_profile_data4[256];
1158 
1159  if (pd->min == 0 || delta < pd->min) {
1160  pd->min = delta;
1161  }
1162  if (pd->max < delta) {
1163  pd->max = delta;
1164  }
1165 
1166  pd->tot += delta;
1167  pd->cnt ++;
1168  }
1169 
1170  SCProfilingUpdatePacketGenericRecords(p, p->profile->flowworker,
1172 
1173  SCProfilingUpdatePacketTmmRecords(p);
1174  SCProfilingUpdatePacketAppRecords(p);
1175  SCProfilingUpdatePacketDetectRecords(p);
1176  SCProfilingUpdatePacketLogRecords(p);
1177 
1178  } else if (PKT_IS_IPV6(p)) {
1180 
1181  uint64_t delta = p->profile->ticks_end - p->profile->ticks_start;
1182  if (pd->min == 0 || delta < pd->min) {
1183  pd->min = delta;
1184  }
1185  if (pd->max < delta) {
1186  pd->max = delta;
1187  }
1188 
1189  pd->tot += delta;
1190  pd->cnt ++;
1191 
1192  if (IS_TUNNEL_PKT(p)) {
1193  pd = &packet_profile_data6[256];
1194 
1195  if (pd->min == 0 || delta < pd->min) {
1196  pd->min = delta;
1197  }
1198  if (pd->max < delta) {
1199  pd->max = delta;
1200  }
1201 
1202  pd->tot += delta;
1203  pd->cnt ++;
1204  }
1205 
1206  SCProfilingUpdatePacketGenericRecords(p, p->profile->flowworker,
1208 
1209  SCProfilingUpdatePacketTmmRecords(p);
1210  SCProfilingUpdatePacketAppRecords(p);
1211  SCProfilingUpdatePacketDetectRecords(p);
1212  SCProfilingUpdatePacketLogRecords(p);
1213  }
1214 
1215  if (profiling_packets_csv_enabled)
1217 
1218  }
1219  pthread_mutex_unlock(&packet_profile_lock);
1220 }
1221 
1223 {
1224  uint64_t sample = SC_ATOMIC_ADD(samples, 1);
1225  if (sample % rate == 0)
1226  return SCCalloc(1, sizeof(PktProfiling));
1227  else
1228  return NULL;
1229 }
1230 
1231 /* see if we want to profile rules for this packet */
1233 {
1234 #ifdef PROFILE_LOCKING
1235  if (p->profile != NULL) {
1236  p->flags |= PKT_PROFILE;
1237  return 1;
1238  }
1239 #else
1240  uint64_t sample = SC_ATOMIC_ADD(samples, 1);
1241  if (sample % rate == 0) {
1242  p->flags |= PKT_PROFILE;
1243  return 1;
1244  }
1245 #endif
1246  return 0;
1247 }
1248 
1249 #define CASE_CODE(E) case E: return #E
1251 /**
1252  * \brief Maps the PacketProfileDetectId, to its string equivalent
1253  *
1254  * \param id PacketProfileDetectId id
1255  *
1256  * \retval string equivalent for the PacketProfileDetectId id
1257  */
1259 {
1260  switch (id) {
1275  default:
1276  return "UNKNOWN";
1277  }
1278 }
1279 
1280 /**
1281  * \brief Maps the LoggerId's to its string equivalent for profiling output.
1282  *
1283  * \param id LoggerId id
1284  *
1285  * \retval string equivalent for the LoggerId id
1286  */
1288 {
1289  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:436
Packet_::proto
uint8_t proto
Definition: decode.h:436
PROF_DETECT_GETSGH
@ PROF_DETECT_GETSGH
Definition: suricata-common.h:421
LOGGER_JSON_HTTP2
@ LOGGER_JSON_HTTP2
Definition: suricata-common.h:471
SCSpinDestroy
#define SCSpinDestroy
Definition: threads-debug.h:239
PktProfilingData_::ticks_end
uint64_t ticks_end
Definition: decode.h:351
ConfNodeChildValueIsTrue
int ConfNodeChildValueIsTrue(const ConfNode *node, const char *key)
Test if a configuration node has a true value.
Definition: conf.c:887
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
LOGGER_JSON_DNP3_TS
@ LOGGER_JSON_DNP3_TS
Definition: suricata-common.h:456
PKT_IS_IPV6
#define PKT_IS_IPV6(p)
Definition: decode.h:258
PktProfiling_
Per pkt stats storage.
Definition: decode.h:380
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:330
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:592
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:476
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:487
Packet_::pcap_cnt
uint64_t pcap_cnt
Definition: decode.h:570
PktProfiling_::ticks_end
uint64_t ticks_end
Definition: decode.h:382
AppProto
uint16_t AppProto
Definition: app-layer-protos.h:73
Packet_::flags
uint32_t flags
Definition: decode.h:449
ConfGetNode
ConfNode * ConfGetNode(const char *name)
Get a ConfNode by name.
Definition: conf.c:175
LOGGER_JSON_ALERT
@ LOGGER_JSON_ALERT
Definition: suricata-common.h:478
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:333
LOGGER_JSON_MQTT
@ LOGGER_JSON_MQTT
Definition: suricata-common.h:467
PacketProfileLoggertIdToString
const char * PacketProfileLoggertIdToString(LoggerId id)
Maps the LoggerId's to its string equivalent for profiling output.
Definition: util-profiling.c:1287
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:332
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:368
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:1232
LOGGER_JSON_DNS_TC
@ LOGGER_JSON_DNS_TC
Definition: suricata-common.h:449
SCProfilingAddPacket
void SCProfilingAddPacket(Packet *p)
Definition: util-profiling.c:1132
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:6
LOGGER_DNS_TC
@ LOGGER_DNS_TC
Definition: suricata-common.h:444
LOGGER_STATS
@ LOGGER_STATS
Definition: suricata-common.h:486
PROFILE_FLOWWORKER_STREAM
@ PROFILE_FLOWWORKER_STREAM
Definition: flow-worker.h:23
SCProfilingDestroy
void SCProfilingDestroy(void)
Free resources used by profiling.
Definition: util-profiling.c:268
ALPROTO_MAX
@ ALPROTO_MAX
Definition: app-layer-protos.h:68
LOGGER_JSON_TLS
@ LOGGER_JSON_TLS
Definition: suricata-common.h:452
PktProfiling_::app
PktProfilingAppData app[ALPROTO_MAX]
Definition: decode.h:386
PktProfiling_::ticks_start
uint64_t ticks_start
Definition: decode.h:381
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:565
PROF_DETECT_PF_SORT2
@ PROF_DETECT_PF_SORT2
Definition: suricata-common.h:429
PktProfilingAppData_::ticks_spent
uint64_t ticks_spent
Definition: decode.h:361
UtilCpuGetTicks
uint64_t UtilCpuGetTicks(void)
Definition: util-cpu.c:190
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:475
PROF_DETECT_TX_UPDATE
@ PROF_DETECT_TX_UPDATE
Definition: suricata-common.h:432
Packet_::profile
PktProfiling * profile
Definition: decode.h:611
LOGGER_JSON_FLOW
@ LOGGER_JSON_FLOW
Definition: suricata-common.h:484
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:804
LOGGER_JSON_RDP
@ LOGGER_JSON_RDP
Definition: suricata-common.h:469
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:468
LOGGER_TCP_DATA
@ LOGGER_TCP_DATA
Definition: suricata-common.h:483
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:482
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:349
packet_profile_log_data4
SCProfilePacketData packet_profile_log_data4[LOGGER_SIZE][256]
Definition: util-profiling.c:91
PktProfiling_::logger
PktProfilingLoggerData logger[LOGGER_SIZE]
Definition: decode.h:388
SCSpinUnlock
#define SCSpinUnlock
Definition: threads-debug.h:237
LOGGER_JSON_DCERPC
@ LOGGER_JSON_DCERPC
Definition: suricata-common.h:470
PROFILE_FLOWWORKER_APPLAYERUDP
@ PROFILE_FLOWWORKER_APPLAYERUDP
Definition: flow-worker.h:24
PktProfilingDetectData_
Definition: decode.h:354
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:491
SC_ATOMIC_DECLARE
#define SC_ATOMIC_DECLARE(type, name)
wrapper for declaring atomic variables.
Definition: util-atomic.h:281
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:414
LOGGER_JSON_NETFLOW
@ LOGGER_JSON_NETFLOW
Definition: suricata-common.h:485
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:75
PROF_DETECT_IPONLY
@ PROF_DETECT_IPONLY
Definition: suricata-common.h:422
IS_TUNNEL_PKT
#define IS_TUNNEL_PKT(p)
Definition: decode.h:894
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:1258
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:350
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:387
LOGGER_JSON_NFS
@ LOGGER_JSON_NFS
Definition: suricata-common.h:453
LOGGER_PCAP
@ LOGGER_PCAP
Definition: suricata-common.h:489
LOGGER_JSON_METADATA
@ LOGGER_JSON_METADATA
Definition: suricata-common.h:490
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
PROFILE_FLOWWORKER_SIZE
@ PROFILE_FLOWWORKER_SIZE
Definition: flow-worker.h:29
LOGGER_JSON_DROP
@ LOGGER_JSON_DROP
Definition: suricata-common.h:480
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:473
FatalError
#define FatalError(x,...)
Definition: util-debug.h:532
SCProfilingDump
void SCProfilingDump(void)
Definition: util-profiling.c:294
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:35
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
SC_ERR_FATAL
@ SC_ERR_FATAL
Definition: util-error.h:203
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:364
PktProfiling_::tmm
PktProfilingTmmData tmm[TMM_SIZE]
Definition: decode.h:384
PKT_PROFILE
#define PKT_PROFILE
Definition: decode.h:1126
LockRecordFreeHash
void LockRecordFreeHash(void)
ALPROTO_FAILED
@ ALPROTO_FAILED
Definition: app-layer-protos.h:63
SCSpinlock
#define SCSpinlock
Definition: threads-debug.h:234
LOGGER_FILE_STORE
@ LOGGER_FILE_STORE
Definition: suricata-common.h:481
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:349
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:331
LOGGER_TLS_STORE
@ LOGGER_TLS_STORE
Definition: suricata-common.h:446
PktProfilingLoggerData_::ticks_spent
uint64_t ticks_spent
Definition: decode.h:367
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:488
CASE_CODE
#define CASE_CODE(E)
Definition: util-profiling.c:1249
PktProfiling_::flowworker
PktProfilingData flowworker[PROFILE_FLOWWORKER_SIZE]
Definition: decode.h:385
util-profiling-locks.h
PktProfilingAppData_
Definition: decode.h:360
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:389
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:257
LOGGER_ALERT_FAST
@ LOGGER_ALERT_FAST
Definition: suricata-common.h:474
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:1222
LOGGER_DROP
@ LOGGER_DROP
Definition: suricata-common.h:477
LOGGER_JSON_IKEV2
@ LOGGER_JSON_IKEV2
Definition: suricata-common.h:460
PktProfilingDetectData_::ticks_spent
uint64_t ticks_spent
Definition: decode.h:357
profiling_locks_enabled
int profiling_locks_enabled
LOGGER_JSON_ANOMALY
@ LOGGER_JSON_ANOMALY
Definition: suricata-common.h:479
ConfNodeLookupChildValue
const char * ConfNodeLookupChildValue(const ConfNode *node, const char *name)
Lookup the value of a child configuration node by name.
Definition: conf.c:842