Subsections
Snort can provide statistics on rule and preprocessor performance. Each
require only a simple config option to snort.conf and Snort
will print statistics on the worst (or all) performers on exit. When a file
name is provided in profile_rules or profile_preprocs, the
statistics will be saved in these files. 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.
To use this feature, you must build snort with the -enable-perfprofiling
option to the configure script.
2.5.1 Rule Profiling
config profile_rules: \
print [all | <num>], \
sort <sort_option> \
[,filename <filename> [append]]
- Print all rules, sort by avg_ticks (default configuration if option is turned on)
config profile_rules
- Print all rules, sort by avg_ticks, and append to file rules_stats.txt
config profile_rules: filename rules_stats.txt append
- Print the top 10 rules, based on highest average time
config profile_rules: print 10, sort avg_ticks
- Print all rules, sorted by number of checks
config profile_rules: print all, sort checks
- Print top 100 rules, based on total time
config profile_rules: print 100, sort total_ticks
- Print with default options, save results to performance.txt each time
config profile_rules: filename performance.txt append
- Print top 20 rules, save results to perf.txt with timestamp in filename
config profile_rules: print 20, filename perf.txt
Snort will print a table much like the following at exit.
Figure:
Rule Profiling Example Output
25#25 |
Configuration line used to print the above table:
config profile_rules: print 4, sort total_ticks
The columns represent:
- Number (rank)
- Sig ID
- Generator ID
- Checks (number of times rule was evaluated after fast pattern match
within portgroup or any-3#3any 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
Interpreting this info is the key. The Microsecs (or 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, that most likely contains PCRE.
High Checks and low Avg/Check is usually an any-3#3any 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.
2.5.2 Preprocessor Profiling
config profile_preprocs: \
print [all | <num>], \
sort <sort_option> \
[, filename <filename> [append]]
- <num> is the number of preprocessors to print
- <sort_option> is one of:
checks
avg_ticks
total_ticks
- <filename> is the output filename
- [append] dictates that the output will go to the same file each time (optional)
- Print all preprocessors, sort by avg_ticks (default configuration if
option is turned on)
config profile_preprocs
- Print all preprocessors, sort by avg_ticks, and append to file
preprocs_stats.txt
config profile_preprocs: filename preprocs_stats.txt append
- Print the top 10 preprocessors, based on highest average time
config profile_preprocs: print 10, sort avg_ticks
- Print all preprocessors, sorted by number of checks
config profile_preprocs: print all, sort checks
Snort will print a table much like the following at exit.
Figure:
Preprocessor Profiling Example Output
26#26 |
Configuration line used to print the above table:
config profile_preprocs: \
print 10, sort total_ticks
The columns represent:
- Number (rank) - The number is indented for each layer. Layer 1
preprocessors are listed under their respective caller (and sorted similarly).
- Preprocessor Name
- Layer - When printing a specific number of preprocessors all subtasks
info for a particular preprocessor is printed for each layer 0 preprocessor
stat.
- 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, i.e. subroutines
within preprocessors, this identifies the percent of the caller's ticks that is
spent for this subtask.
Because of task swapping, non-instrumented code, and other factors, the Pct 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.
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.
2.5.3 Packet Performance Monitoring (PPM)
PPM provides thresholding mechanisms that can be used to provide a basic
level of latency control for snort. It does not provide a hard and fast
latency guarantee but should in effect provide a good average latency
control. Both rules and packets can be checked for latency. The action
taken upon detection of excessive latency is configurable. The following
sections describe configuration, sample output, and some implementation
details worth noting.
To use PPM, you must build with the -enable-ppm or the -enable-sourcefire
option to configure.
PPM is configured as follows:
# Packet configuration:
config ppm: max-pkt-time <micro-secs>, \
fastpath-expensive-packets, \
pkt-log, \
debug-pkts
# Rule configuration:
config ppm: max-rule-time <micro-secs>, \
threshold count, \
suspend-expensive-rules, \
suspend-timeout <seconds>, \
rule-log [log] [alert]
Packets and rules can be configured separately, as above, or together in just
one config ppm statement. Packet and rule monitoring is independent, so one or
both or neither may be enabled.
Packet Configuration Options
max-pkt-time <micro-secs>
- enables packet latency thresholding using 'micros-secs' as the limit.
- default is 0 (packet latency thresholding disabled)
- reasonable starting defaults: 100/250/1000 for 1G/100M/5M nets
fastpath-expensive-packets
- enables stopping further inspection of a packet if the max time is
exceeded
- default is off
pkt-log
- enables logging packet event if packet exceeds max-pkt-time
- default is no logging
- if no option is given for 'pkt-log', 'pkt-log log' is implied
- the log option enables output to syslog or console depending
upon snort configuration
debug-pkts
- must build with the -enable-debug option to configure
- enables per packet timing stats to be printed after each packet
- default is off
Rule Configuration Options
max-rule-time <micro-secs>
- enables rule latency thresholding using 'micros-secs' as the limit.
- default is 0 (rule latency thresholding disabled)
- reasonable starting defaults: 100/250/1000 for 1G/100M/5M nets
threshold <count>
- sets the number of cumulative rule time excesses before disabling
a rule
- default is 5
suspend-expensive-rules
- enables suspending rule inspection if the max rule time is exceeded
- default is off
suspend-timeout <seconds>
- rule suspension time in seconds
- default is 60 seconds
- set to zero to permanently disable expensive rules
rule-log [log] [alert]
- enables event logging output for rules
- default is no logging
- one or both of the options 'log' and 'alert' must be used with
'rule-log'
- the log option enables output to syslog or console depending
upon snort configuration
Example 1:
The following enables packet tracking:
config ppm: max-pkt-time 100
The following enables rule tracking:
config ppm: max-rule-time 50, threshold 5
If fastpath-expensive-packets or suspend-expensive-rules is not used, then
no action is taken other than to increment the count of the number of
packets that should be fastpath'd or the rules that should be suspended. A
summary of this information is printed out when snort exits.
Example 2:
The following suspends rules and aborts packet inspection. These rules were
used to generate the sample output that follows.
config ppm: \
max-pkt-time 50, fastpath-expensive-packets, \
pkt-log, debug-pkts
config ppm: \
max-rule-time 50, threshold 5, suspend-expensive-rules, \
suspend-timeout 300, rule-log log alert
Sample Snort Startup Output
Packet Performance Monitor Config:
ticks per usec : 1600 ticks
max packet time : 50 usecs
packet action : fastpath-expensive-packets
packet logging : log
debug-pkts : disabled
Rule Performance Monitor Config:
ticks per usec : 1600 ticks
max rule time : 50 usecs
rule action : suspend-expensive-rules
rule threshold : 5
suspend timeout : 300 secs
rule logging : alert log
Sample Snort Run-time Output
...
PPM: Process-BeginPkt[61] caplen=60
PPM: Pkt[61] Used= 8.15385 usecs
PPM: Process-EndPkt[61]
PPM: Process-BeginPkt[62] caplen=342
PPM: Pkt[62] Used= 65.3659 usecs
PPM: Process-EndPkt[62]
PPM: Pkt-Event Pkt[63] used=56.0438 usecs, 0 rules, 1 nc-rules tested, packet fastpathed
(10.4.12.224:0 -> 10.4.14.108:54321).
PPM: Process-BeginPkt[63] caplen=60
PPM: Pkt[63] Used= 8.394 usecs
PPM: Process-EndPkt[63]
PPM: Process-BeginPkt[64] caplen=60
PPM: Pkt[64] Used= 8.21764 usecs
PPM: Process-EndPkt[64]
...
Sample Snort Exit Output
Packet Performance Summary:
max packet time : 50 usecs
packet events : 1
avg pkt time : 0.633125 usecs
Rule Performance Summary:
max rule time : 50 usecs
rule events : 0
avg nc-rule time : 0.2675 usecs
- Enforcement of packet and rule processing times is done after processing
each rule. Latency control is not enforced after each preprocessor.
- This implementation is software based and does not use an interrupt
driven timing mechanism and is therefore subject to the granularity of the
software based timing tests. Due to the granularity of the timing measurements
any individual packet may exceed the user specified packet or rule processing
time limit. Therefore this implementation cannot implement a precise latency
guarantee with strict timing guarantees. Hence the reason this is considered a
best effort approach.
- Since this implementation depends on hardware based high performance
frequency counters, latency thresholding is presently only available on Intel
and PPC platforms.
- Time checks are made based on the total system time, not processor usage
by Snort. This was a conscious design decision because when a system is
loaded, the latency for a packet is based on the total system time, not just
the processor time the Snort application receives. Therefore, it is
recommended that you tune your thresholding to operate optimally when your
system is under load.