[Snort-users] Performance monitoring issues

Lee Saunders lee.saunders at ...16528...
Fri Sep 6 09:20:38 EDT 2013


Attached document for the preprocessor, this has the below and various 
other runs included.

As stated doing a performance monitoring run for specific rules and will 
add those in due course. I have the blacklist rules activated and these 
are swamping the results so will be removing these to test impact of 
other rules, and then look to add these back in but running as IDS so do 
not believe the reputation preprocessor will help from what I've been 
reading.

However, the two initial questions I have is:

1) From perfmon preprocessor output, I was seeing around 10% pattern 
matching, but filtered out a lot of background noise (safe upload 
packets) and now seeing patmatch_percent values routinely of well over 
100% (200 or 300% in some periods)> I don't understand how this is 
possible - a little in terms of fragmentation and reconstruction from 
other preprocessors but was not expecting values of this order - is it 
normal, if not where should I look to mitigate.

2) As I said the rtn eval looks very high from what I've seen looking 
around other discussions, is it something to worry about? Indeed is it 
reporting correctly, it looks likes rule eval has two child modules rule 
tree eval (with % of parent as 99.66% and rtn eval % of parent as 82.75 
which does not make a whole lot of sense as considerably > 100% of caller)

On 06/09/13 13:59, Joel Esler wrote:
> Not sure what is causing the lines to wrap like that, but it's fairly
> impossible to read, if you want to attach that as a plaintext word
> document that would be beneficial, that says, do some rule profiling
> as well, that way we can see what rules are causing problems, if any.
>
> On Fri, Sep 6, 2013 at 6:45 AM, Lee Saunders <lee.saunders at ...16528...> wrote:
>> I've been starting performance monitoring on my setup, as there is
>> unexpected drops appearing at one single installation (virtualized
>> configuration so traffic profile pretty similar to other installation).
>>
>> The bandwidth is pre-filtered so is relatively small, certainly small
>> enough to that drops are not currently expected. The first perculiarity
>> is looking at perfmon I see patmatch-percent numbers in the range 70 -
>> 300%, very high and not what I'd expect.
>>
>> Looking then at profile monitoring, I can't find much on how to read and
>> act on the values. I'm currently running a test for the rules profiling,
>> but a preprocessor profile based on total ticks sorting has raised a
>> couple of queries. The output of a short run is repeated below. However,
>> the rtn eval value, when looked at against other outputs on the web
>> looks very high, at 622810 ms, but not clear this represents or how to
>> improve it. There is also the implication from the output that this and
>> rule tree eval are siblings of rule eval, but the % of parent then does
>> not add up, with a value of around 170% - is there a known problem with
>> how these are reported and a red herring?
>>
>> I'm at the outset of the tuning exercise, but its proving difficult to
>> find resources which outline how to interpret these values and how to
>> mitigate them. I'm assuming the top offending detect is influenced
>> primarily by the rule definitions hence the rules profiling I'm
>> currently doing, but some insight into minimizing the subtasks would be
>> useful, and if any of the other preprocessors can influence.
>>
>> timestamp: 1378398556
>> Preprocessor Profile Statistics (all)
>> ==========================================================
>>    Num            Preprocessor Layer     Checks      Exits Microsecs
>> Avg/Check Pct of Caller Pct of Total
>>    ===            ============ =====     ======      ===== =========
>> ========= ============= ============
>>     1                   detect     0      10553 10553
>> 873142      82.74         83.64        83.64
>>      1               rule eval     1      10427 10427
>> 752623      72.18         86.20        72.09
>>       1         rule tree eval     2      21935 21935
>> 750099      34.20         99.66        71.85
>>        1               content     3       4836 4836
>> 1449       0.30          0.19         0.14
>>        2                  pcre     3         19 19
>> 1438      75.71          0.19         0.14
>>        3                 flags     3       8970 8970
>> 656       0.07          0.09         0.06
>>        4             byte_test     3       2929 2929
>> 517       0.18          0.07         0.05
>>        5              dsize_eq     3       3987 3987
>> 402       0.10          0.05         0.04
>>        6                  flow     3       2021 2021
>> 172       0.09          0.02         0.02
>>        7  preproc_rule_options     3       1256 1256
>> 88       0.07          0.01         0.01
>>        8            uricontent     3        168 168
>> 64       0.38          0.01         0.01
>>        9                 itype     3        318 318
>> 40       0.13          0.01         0.00
>>       10              flowbits     3        212 212
>> 32       0.15          0.00         0.00
>>       11                 icode     3        285 285
>> 14       0.05          0.00         0.00
>>       12             file_data     3        123 123
>> 5       0.04          0.00         0.00
>>       13          byte_extract     3          6 6
>> 3       0.52          0.00         0.00
>>       14              isdataat     3          8 8
>> 1       0.20          0.00         0.00
>>       15                window     3          4 4
>> 0       0.15          0.00         0.00
>>       2               rtn eval     2    1039167 1039167
>> 622810       0.60         82.75        59.66
>>      2                    mpse     1      10212 10212
>> 87608       8.58         10.03         8.39
>>     2                       s5     0       9321 9321
>> 86594       9.29          8.29         8.29
>>      1                   s5tcp     1       8062 6651
>> 64012       7.94         73.92         6.1310
>>       1             s5TcpState     2       6651 6651
>> 46814       7.04         73.13         4.48
>>        1             s5TcpData     3       1606 1606
>> 5624       3.50         12.01         0.54
>>         1       s5TcpPktInsert     4       1406 1406
>> 4829       3.43         85.86         0.46
>>        2            s5TcpFlush     3       1037 1037
>> 2863       2.76          6.12         0.27
>>         1  s5TcpProcessRebuilt     4        892 892
>> 50297      56.39       1756.44         4.82
>>         2     s5TcpBuildPacket     4        892 892
>> 665       0.75         23.25         0.06
>>       2           s5TcpNewSess     2        197 197
>> 1075       5.46          1.68         0.10
>>     3                      ssl     0       2090 2090
>> 20935      10.02          2.01         2.01
>>     4                   decode     0       9853 9853
>> 20088       2.04          1.92         1.92
>>     5           sensitive_data     0        162 162
>> 14964      92.37          1.43         1.43
>>     6                   eventq     0      20562 20562
>> 6610       0.32          0.63         0.63
>>     7                     smtp     0       3748 3748
>> 5387       1.44          0.52         0.52
>>     8              httpinspect     0       3782 3782
>> 5162       1.36          0.49         0.49
>>     9               DceRpcMain     0       2865 2865
>> 3518       1.23          0.34         0.34
>>      1           DceRpcSession     1       2865 2865
>> 2745       0.96         78.01         0.26
>>       1       DceRpcNewSession     2       2865 2865
>> 1584       0.55         57.72         0.15
>>    10                  perfmon     0      10721 10721
>> 3119       0.29          0.30         0.30
>>    11                      ssh     0       2433 2116
>> 1805       0.74          0.17         0.17
>>    12                      pop     0       3707 3707
>> 1434       0.39          0.14         0.14
>>    13                     imap     0       3707 3707
>> 1254       0.34          0.12         0.12
>>    14                      sip     0       3692 3692
>> 842       0.23          0.08         0.08
>>    15                   modbus     0       3707 3707
>> 692       0.19          0.07         0.07
>>    16                     dnp3     0       1259 1259
>> 572       0.46          0.05         0.05
>>    17              backorifice     0       1259 1259
>> 437       0.35          0.04         0.04
>>    18                      dns     0        820 820
>> 164       0.20          0.02         0.02
>>    total                 total     0       9835       9835 1043957
>> 106.15          0.00         0.00
>>
>> ------------------------------------------------------------------------------
>> Learn the latest--Visual Studio 2012, SharePoint 2013, SQL 2012, more!
>> Discover the easy way to master current and previous Microsoft technologies
>> and advance your career. Get an incredible 1,500+ hours of step-by-step
>> tutorial videos with LearnDevNow. Subscribe today and save!
>> http://pubads.g.doubleclick.net/gampad/clk?id=58041391&iu=/4140/ostg.clktrk
>> _______________________________________________
>> Snort-users mailing list
>> Snort-users at lists.sourceforge.net
>> Go to this URL to change user options or unsubscribe:
>> https://lists.sourceforge.net/lists/listinfo/snort-users
>> Snort-users list archive:
>> http://sourceforge.net/mailarchive/forum.php?forum_name=snort-users
>>
>> Please visit http://blog.snort.org to stay current on all the latest Snort news!
>
>

-------------- next part --------------

timestamp: 1378398556
Preprocessor Profile Statistics (all)
==========================================================
 Num            Preprocessor Layer     Checks      Exits           Microsecs  Avg/Check Pct of Caller Pct of Total
 ===            ============ =====     ======      =====           =========  ========= ============= ============
  1                   detect     0      10553      10553              873142      82.74         83.64        83.64
   1               rule eval     1      10427      10427              752623      72.18         86.20        72.09
    1         rule tree eval     2      21935      21935              750099      34.20         99.66        71.85
     1               content     3       4836       4836                1449       0.30          0.19         0.14
     2                  pcre     3         19         19                1438      75.71          0.19         0.14
     3                 flags     3       8970       8970                 656       0.07          0.09         0.06
     4             byte_test     3       2929       2929                 517       0.18          0.07         0.05
     5              dsize_eq     3       3987       3987                 402       0.10          0.05         0.04
     6                  flow     3       2021       2021                 172       0.09          0.02         0.02
     7  preproc_rule_options     3       1256       1256                  88       0.07          0.01         0.01
     8            uricontent     3        168        168                  64       0.38          0.01         0.01
     9                 itype     3        318        318                  40       0.13          0.01         0.00
    10              flowbits     3        212        212                  32       0.15          0.00         0.00
    11                 icode     3        285        285                  14       0.05          0.00         0.00
    12             file_data     3        123        123                   5       0.04          0.00         0.00
    13          byte_extract     3          6          6                   3       0.52          0.00         0.00
    14              isdataat     3          8          8                   1       0.20          0.00         0.00
    15                window     3          4          4                   0       0.15          0.00         0.00
    2               rtn eval     2    1039167    1039167              622810       0.60         82.75        59.66
   2                    mpse     1      10212      10212               87608       8.58         10.03         8.39
  2                       s5     0       9321       9321               86594       9.29          8.29         8.29
   1                   s5tcp     1       8062       6651               64012       7.94         73.92         6.13
    1             s5TcpState     2       6651       6651               46814       7.04         73.13         4.48
     1             s5TcpData     3       1606       1606                5624       3.50         12.01         0.54
      1       s5TcpPktInsert     4       1406       1406                4829       3.43         85.86         0.46
     2            s5TcpFlush     3       1037       1037                2863       2.76          6.12         0.27
      1  s5TcpProcessRebuilt     4        892        892               50297      56.39       1756.44         4.82
      2     s5TcpBuildPacket     4        892        892                 665       0.75         23.25         0.06
    2           s5TcpNewSess     2        197        197                1075       5.46          1.68         0.10
  3                      ssl     0       2090       2090               20935      10.02          2.01         2.01
  4                   decode     0       9853       9853               20088       2.04          1.92         1.92
  5           sensitive_data     0        162        162               14964      92.37          1.43         1.43
  6                   eventq     0      20562      20562                6610       0.32          0.63         0.63
  7                     smtp     0       3748       3748                5387       1.44          0.52         0.52
  8              httpinspect     0       3782       3782                5162       1.36          0.49         0.49
  9               DceRpcMain     0       2865       2865                3518       1.23          0.34         0.34
   1           DceRpcSession     1       2865       2865                2745       0.96         78.01         0.26
    1       DceRpcNewSession     2       2865       2865                1584       0.55         57.72         0.15
 10                  perfmon     0      10721      10721                3119       0.29          0.30         0.30
 11                      ssh     0       2433       2116                1805       0.74          0.17         0.17
 12                      pop     0       3707       3707                1434       0.39          0.14         0.14
 13                     imap     0       3707       3707                1254       0.34          0.12         0.12
 14                      sip     0       3692       3692                 842       0.23          0.08         0.08
 15                   modbus     0       3707       3707                 692       0.19          0.07         0.07
 16                     dnp3     0       1259       1259                 572       0.46          0.05         0.05
 17              backorifice     0       1259       1259                 437       0.35          0.04         0.04
 18                      dns     0        820        820                 164       0.20          0.02         0.02
 total                 total     0       9835       9835             1043957     106.15          0.00         0.00

timestamp: 1378465786
Preprocessor Profile Statistics (all)
==========================================================
 Num            Preprocessor Layer     Checks      Exits           Microsecs  Avg/Check Pct of Caller Pct of Total
 ===            ============ =====     ======      =====           =========  ========= ============= ============
  1                   detect     0      36892      36892              847723      22.98         65.75        65.75
   1               rule eval     1      11237      11237              662255      58.94         78.12        51.37
    1         rule tree eval     2      49330      49330              656999      13.32         99.21        50.96
     1                 flags     3      35372      35372                2646       0.07          0.40         0.21
     2               content     3       4920       4920                1734       0.35          0.26         0.13
     3                  pcre     3         17         17                1263      74.32          0.19         0.10
     4             byte_test     3       2826       2826                 461       0.16          0.07         0.04
     5              dsize_eq     3       3811       3811                 380       0.10          0.06         0.03
     6                  flow     3       2369       2369                 204       0.09          0.03         0.02
     7  preproc_rule_options     3       2064       2064                 121       0.06          0.02         0.01
     8            uricontent     3        191        191                  71       0.38          0.01         0.01
     9              flowbits     3        241        241                  39       0.16          0.01         0.00
    10                 itype     3        410        410                  27       0.07          0.00         0.00
    11                 icode     3        373        373                  16       0.05          0.00         0.00
    12              isdataat     3         32         32                   6       0.20          0.00         0.00
    13             file_data     3        119        119                   6       0.05          0.00         0.00
    14          byte_extract     3          5          5                   2       0.45          0.00         0.00
    15                window     3         18         18                   1       0.10          0.00         0.00
    2               rtn eval     2     891538     891538              532943       0.60         80.47        41.34
   2                    mpse     1      15056      15056              116538       7.74         13.75         9.04
  2                       s5     0      35407      35407              201664       5.70         15.64        15.64
   1                   s5tcp     1      34298      24530              133841       3.90         66.37        10.38
    1             s5TcpState     2      24514      24514               73683       3.01         55.05         5.72
     1             s5TcpData     3       2061       2061                5742       2.79          7.79         0.45
      1       s5TcpPktInsert     4       1741       1741                4789       2.75         83.40         0.37
     2            s5TcpFlush     3       1113       1113                2955       2.66          4.01         0.23
      1  s5TcpProcessRebuilt     4       1041       1041               59137      56.81       2001.01         4.59
      2     s5TcpBuildPacket     4       1041       1041                 687       0.66         23.25         0.05
    2           s5TcpNewSess     2        153        153                 789       5.16          0.59         0.06
  3                   decode     0      36082      36082               65428       1.81          5.07         5.07
  4           sensitive_data     0        289        289               19853      68.70          1.54         1.54
  5                   eventq     0      73161      73161               18525       0.25          1.44         1.44
  6                      ssl     0       2443       2443               15465       6.33          1.20         1.20
  7                  perfmon     0      37101      37101               10560       0.28          0.82         0.82
  8                     smtp     0       6441       6441               10423       1.62          0.81         0.81
  9              httpinspect     0       6480       6480                7677       1.18          0.60         0.60
 10               DceRpcMain     0       2158       2158                2674       1.24          0.21         0.21
   1           DceRpcSession     1       2158       2158                2058       0.95         76.96         0.16
    1       DceRpcNewSession     2       2158       2158                1146       0.53         55.71         0.09
 11                      pop     0       6316       6316                2134       0.34          0.17         0.17
 12                     imap     0       6316       6316                1989       0.31          0.15         0.15
 13                      ssh     0       4619       3200                1624       0.35          0.13         0.13
 14                      sip     0       5728       5728                1046       0.18          0.08         0.08
 15                   modbus     0       6316       6316                1019       0.16          0.08         0.08
 16                     dnp3     0       1109       1109                 473       0.43          0.04         0.04
 17              backorifice     0       1109       1109                 405       0.37          0.03         0.03
 18                      dns     0        789        789                 139       0.18          0.01         0.01
 total                 total     0      36060      36060             1289297      35.75          0.00         0.00

timestamp: 1378468221
Preprocessor Profile Statistics (all)
==========================================================
 Num            Preprocessor Layer     Checks      Exits           Microsecs  Avg/Check Pct of Caller Pct of Total
 ===            ============ =====     ======      =====           =========  ========= ============= ============
  1                   detect     0      96420      96420             2839627      29.45         70.22        70.22
   1               rule eval     1      34423      34423             2202923      64.00         77.58        54.47
    1         rule tree eval     2     134987     134987             2187882      16.21         99.32        54.10
     1                 flags     3      91481      91481                7711       0.08          0.35         0.19
     2               content     3      16907      16907                6096       0.36          0.28         0.15
     3                  pcre     3        124        124                3850      31.05          0.18         0.10
     4             byte_test     3      10076      10076                1699       0.17          0.08         0.04
     5              dsize_eq     3      11635      11635                1079       0.09          0.05         0.03
     6                  flow     3       6891       6891                 513       0.07          0.02         0.01
     7  preproc_rule_options     3       8118       8118                 472       0.06          0.02         0.01
     8            uricontent     3        502        502                 187       0.37          0.01         0.00
     9              flowbits     3        861        861                 121       0.14          0.01         0.00
    10                 itype     3       1114       1114                  96       0.09          0.00         0.00
    11                 icode     3       1007       1007                  51       0.05          0.00         0.00
    12             file_data     3        583        583                  23       0.04          0.00         0.00
    13              isdataat     3         88         88                  18       0.21          0.00         0.00
    14          byte_extract     3         14         14                   7       0.50          0.00         0.00
    15                window     3         56         56                   5       0.09          0.00         0.00
    2               rtn eval     2    3003508    3003508             1785259       0.59         81.04        44.14
   2                    mpse     1      45506      45506              391442       8.60         13.78         9.68
  2                       s5     0      92923      92923              603634       6.50         14.93        14.93
   1                   s5tcp     1      89098      52694              397223       4.46         65.81         9.82
    1             s5TcpState     2      52548      52548              256598       4.88         64.60         6.34
     1             s5TcpData     3       5467       5467               14740       2.70          5.74         0.36
      1       s5TcpPktInsert     4       4572       4572               11939       2.61         81.00         0.30
     2            s5TcpFlush     3       2475       2475                6628       2.68          2.58         0.16
      1  s5TcpProcessRebuilt     4       2295       2295              226258      98.59       3413.54         5.59
      2     s5TcpBuildPacket     4       2325       2325                1562       0.67         23.57         0.04
    2           s5TcpNewSess     2        376        376                2034       5.41          0.51         0.05
  3                   decode     0      94812      94812              176721       1.86          4.37         4.37
  4           sensitive_data     0        994        994              110954     111.62          2.74         2.74
  5                   eventq     0     191819     191819               50079       0.26          1.24         1.24
  6                      ssl     0       5335       5335               40489       7.59          1.00         1.00
  7                     smtp     0      18434      18434               34928       1.89          0.86         0.86
  8                  perfmon     0      97054      97054               29011       0.30          0.72         0.72
  9              httpinspect     0      18539      18539               22745       1.23          0.56         0.56
 10               DceRpcMain     0       6771       6771                8751       1.29          0.22         0.22
   1           DceRpcSession     1       6771       6771                6522       0.96         74.53         0.16
    1       DceRpcNewSession     2       6771       6771                3655       0.54         56.04         0.09
 11                      pop     0      17982      17982                7216       0.40          0.18         0.18
 12                     imap     0      17982      17982                6446       0.36          0.16         0.16
 13                      ssh     0      13534      11265                5257       0.39          0.13         0.13
 14                      sip     0      17359      17359                3368       0.19          0.08         0.08
 15                   modbus     0      17982      17982                3157       0.18          0.08         0.08
 16                     dnp3     0       3825       3825                1654       0.43          0.04         0.04
 17              backorifice     0       3825       3825                1353       0.35          0.03         0.03
 18                      dns     0       2711       2711                 550       0.20          0.01         0.01
 total                 total     0      94762      94762             4044132      42.68          0.00         0.00


More information about the Snort-users mailing list