# To use Rule or Preprocessor profiling, you must build snort using the
# --enable-perfprofiling option to configure.

# Rule Profiling Configuration
#
# syntax:
# config profile_rules: print [all | num], sort sort_option, filename file_option [append]
#  - where num is the number of rules to print
#  - where sort_option is one of:
#     checks, matches, nomatches, avg_ticks,
#     avg_ticks_per_match, avg_ticks_per_nomatch, total_ticks
#  - where file_option is the output filename
#  - where append dictates that the output will go to the same file each time (optional)
#
# examples:
#
# 1) Print all rules, sort by avg_ticks (default configuration
#    if option is turned on)
# config profile_rules
#
# 2) Print the top 10 rules, based on highest average time
# config profile_rules: print 10, sort avg_ticks
#
# 3) Print all rules, sorted by number of checks
# config profile_rules: print all, sort checks
#
# 4) Print top 100 rules, based on total time
# config profile_rules: print 100, sort total_ticks
#
# 5) Print with default options, save results to performance.txt each time
# config profile_rules: filename performance.txt append
#
# 6) Print top 20 rules, save results to perf.txt with timestamp in filename
# config profile_rules: print 20, filename perf.txt

When you use this (see configuration info with example output),
snort will print the following table at exit.  The column info
is:
- Number (rank)
- Sig ID
- Generator ID
- Checks (number of times rule was evaludated after fast pattern match
  within portgroup or ANY->ANY rules)
- Matches (number of times ALL rule options matched, will be high for
  rules that have no options)
- Alerts (number of alerts generated from this rule)
- CPU Ticks
- Avg Ticks per Check
- Avg Ticks per Match
- Avg Ticks per Nonmatch

Example, using config profile_rules: print 4, sort total_ticks
Rule Profile Statistics (worst 4 rules)
==========================================================
   Num      SID GID Rev     Checks   Matches    Alerts               Ticks Avg/Check  Avg/Match Avg/Nonmatch
   ===      === === ===     ======   =======    ======               ===== =========  ========= ============
     1     2389   1  12          1         1         1              385698  385698.0   385698.0          0.0
     2     2178   1  17          2         0         0              107822   53911.0        0.0      53911.0
     3     2179   1   8          2         0         0               92458   46229.0        0.0      46229.0
     4     1734   1  37          2         0         0               90054   45027.0        0.0      45027.0

Interpreting this info is the key... The Ticks column is important
because that is the total time spent evaluating a given rule.  But,
if that rule is causing alerts, it makes sense to leave it alone.

A high Avg/Check is a poor performing rule, most likely contains PCRE.
High Checks and low Avg/Check is usually an ANY->ANY rule with few rule
options and no content.  Quick to check, the few options may or may not
match.  We are looking at moving some of these into code... Especially
those with low SIDs.

By default, this information will be printed to the console when Snort
exits. You can use the "filename" option in snort.conf to specify a
file where this will be written. If "append" is not specified, a new
file will be created each time Snort is run. The filenames will have
timestamps appended to them. These files will be found in the logging
directory.

# Preprocessor Profiling Configuration
#
# syntax:
# config profile_preprocs: print [all | num], sort sort_option, filename file_option [append]
#  - where num is the number of rules to print
#  - where sort_option is one of:
#     checks, avg_ticks, total_ticks
#  - where file_option is the output filename
#  - where append dictates that the output will go to the same file each time (optional)
#
# examples:
#
# 1) Print all preprocessors, sort by avg_ticks (default configuration
#    if option is turned on)
# config profile_preprocs
#
# 2) Print the top 10 preprocessors, based on highest average time
# config profile_preprocs: print 10, sort avg_ticks
#
# 3) Print all preprocessors, sorted by number of checks
# config profile_preprocs: print all, sort checks
#
# When printing a specific number of preprocessors all subtasks info
# is printed for each layer 0 preprocessor stat.

When you use this (see configuration info with example output),
snort will print the following table at exit.  The column info
is:
- Number (rank)
  The number is indented for each layer.  Layer 1 preprocessors are
  listed under their respective caller (and sorted similarly).
- Preprocessor Name
- Layer
- Checks (number of times preprocessor decided to look at a packet,
  ports matched, app layer header was correct, etc)
- Exits  (number of corresponding exits -- just to verify code is
  instrumented correctly, should ALWAYS match Checks, unless an
  exception was trapped)
- CPU Ticks
- Avg Ticks per Check
- Percent of caller
  For non layer 0 preprocessors -- ie, subroutines within preprocessors,
  this identifies the percent of the caller's ticks that is spent for
  this subtask.

Example, using config profile_preprocs: print 10, sort total_ticks
Preprocessor Profile Statistics (worst 10)
==========================================================
 Num            Preprocessor Layer     Checks      Exits           Microsecs  Avg/Check Pct of Caller Pct of Total
 ===            ============ =====     ======      =====           =========  ========= ============= ============
  1                   detect     0     338181     338181             9054573      26.77         64.62        64.62
   1               rule eval     1     256978     256978             2570596      10.00         28.39        18.35
    1         rule tree eval     2     399860     399860             2520629       6.30         98.06        17.99
     1                  pcre     3      51328      51328              505636       9.85         20.06         3.61
     2             byte_jump     3          6          6                   7       1.30          0.00         0.00
     3               content     3    1077588    1077588             1123373       1.04         44.57         8.02
     4            uricontent     3     106498     106498               79685       0.75          3.16         0.57
     5             byte_test     3       9951       9951                5709       0.57          0.23         0.04
     6              isdataat     3       8486       8486                3192       0.38          0.13         0.02
     7              flowbits     3     135739     135739               35365       0.26          1.40         0.25
     8                 flags     3          2          2                   0       0.20          0.00         0.00
     9  preproc_rule_options     3      15499      15499                1939       0.13          0.08         0.01
    10                  flow     3     394817     394817               36420       0.09          1.44         0.26
    11             file_data     3      15957      15957                1264       0.08          0.05         0.01
    12                   ack     3          4          4                   0       0.07          0.00         0.00
    2               rtn eval     2      36928      36928               17500       0.47          0.68         0.12
   2                    mpse     1     646528     646528             5840244       9.03         64.50        41.68
  2                       s5     0     310080     310080             3270702      10.55         23.34        23.34
   1                   s5tcp     1     310080     310080             2993020       9.65         91.51        21.36
    1             s5TcpState     2     304484     304484             2559085       8.40         85.50        18.26
     1            s5TcpFlush     3      22148      22148               70681       3.19          2.76         0.50
      1  s5TcpProcessRebuilt     4      22132      22132             2018748      91.21       2856.11        14.41
      2     s5TcpBuildPacket     4      22132      22132               34965       1.58         49.47         0.25
     2             s5TcpData     3     184186     184186              120794       0.66          4.72         0.86
      1       s5TcpPktInsert     4      46249      46249               89299       1.93         73.93         0.64
    2           s5TcpNewSess     2       5777       5777               37958       6.57          1.27         0.27
  3              httpinspect     0     204751     204751             1814731       8.86         12.95        12.95
  4                      ssl     0      10780      10780               16283       1.51          0.12         0.12
  5                   decode     0     312638     312638              437860       1.40          3.12         3.12
  6               DceRpcMain     0     155358     155358              186061       1.20          1.33         1.33
   1           DceRpcSession     1     155358     155358              156193       1.01         83.95         1.11
  7              backorifice     0         77         77                  42       0.55          0.00         0.00
  8                     smtp     0      45197      45197               17126       0.38          0.12         0.12
  9                      ssh     0      26453      26453                7195       0.27          0.05         0.05
 10                      dns     0         28         28                   5       0.18          0.00         0.00
 total                 total     0     311202     311202            14011946      45.03          0.00         0.00

Because of task swapping, non-instrumented code, and other factors, the
Percent of caller field will not add up to 100% of the caller's time.
It does give a reasonable indication of how much relative time is
spent within each subtask.
