[Oisf-devel] suricata testing

rmkml rmkml at free.fr
Mon May 17 13:11:20 UTC 2010


Thx for reply Victor,
ok look tcpdump output please: (payload filled zero)
14:57:49.627192 IP (tos 0x0, ttl  10, id 29501, offset 0, flags [none], 
proto: UDP (17), length: 1442) 192.168.200.2.1024 > 192.168.199.2.1024: 
[udp sum ok] UDP, length 1414
         0x0000:  4500 05a2 733d 0000 0a11 27b8 c0a8 c802  E...s=....'.....
         0x0010:  c0a8 c702 0400 0400 058e dc7b 0000 0000  ...........{....
         0x0020:  0000 0000 0000 0000 0000 0000 0000 0000  ................
         0x0030:  0000 0000 0000 0000 0000 0000 0000 0000  ................
         0x0040:  0000 0000 0000 0000 0000 0000 0000 0000  ................
         0x0050:  0000 0000 0000 0000 0000 0000 0000 0000  ................
         0x0060:  0000 0000 0000 0000 0000 0000 0000 0000  ................
         0x0070:  0000 0000 0000 0000 0000 0000 0000 0000  ................
         0x0080:  0000 0000 0000 0000 0000 0000 0000 0000  ................
         0x0090:  0000 0000 0000 0000 0000 0000 0000 0000  ................
         0x00a0:  0000 0000 0000 0000 0000 0000 0000 0000  ................
         0x00b0:  0000 0000 0000 0000 0000 0000 0000 0000  ................
         0x00c0:  0000 0000 0000 0000 0000 0000 0000 0000  ................
...

before conf change:
   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
  6476 root      15   0  889m 637m 1340 S 1457.9  5.2   1:50.04 suricata

after conf change:
   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
  4842 root      15   0 1122m 870m 1356 S 1416.5  7.2  32:36.55 suricata
and same conf after two minutes:
   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
  4842 root      15   0 1122m 870m 1356 S 1366.9  7.2  50:22.58 suricata
and back to cpu ~1416...
Regards
Rmkml


On Mon, 17 May 2010, Victor Julien wrote:

> It's interesting to see that MpmVerifyMatch is called so often. The
> function name is a bit of a misnomer (due to recent changes) as when it
> is called the pattern matcher has already determined a pattern match. I
> suspect that the pattern that matches so often is something like "aa"
> and the payload is all "aaaaa"'s. Can you confirm a traffic pattern like
> this?
>
> Couple of things to try:
> - For the compiler, use -mtune=native and -march=native for better
> optimization.
> - in suricata.yaml under 'detect-engine' set profile to 'high'. Or even
> better, to 'custom' and increase all the values below it.
> - in 'pattern-matcher' set 'hash_size' to 'highest' and 'bf_size' to 'high'.
>
> rmkml wrote:
>> ok next test results with suricata (same today git/same sp][rent network
>> trafic) but compiled with:
>>  ./configure --with-libyaml-includes=/home/suricata/yaml-0.1.3/include
>> --with-libyaml-libraries=/home/suricata/yaml-0.1.3/src/.libs
>> --enable-gccprofile
>>  make
>> Joigned gprof output (gzip) results.
>>  ...
>>  Each sample counts as 0.01 seconds.
>>   %   cumulative   self                 self     total
>>  time   seconds   seconds      calls   s/call   s/call  name
>>  90.38   3359.34  3359.34     605708     0.01     0.01  B2gSearchBNDMq
>>   4.25   3517.28   157.94 1676293603     0.00     0.00  MpmVerifyMatch
>>   2.60   3614.10    96.82  931669013     0.00     0.00  B2gBloomHash
>>  ...
>>
>> Maybe already exist option in conf for better (performance) results?
>> Regards
>> Rmkml
>>
>>
>>
>> On Mon, 17 May 2010, rmkml wrote:
>>
>>> Hi,
>>> 1)ok, first I have replaying my last performance test with same result
>>> (~1597% cpu).
>>> 2)ok now test with 'CFLAGS="-O3 -march=i686 -mtune=i686"
>>> ./configure...': same performance result (~1597% cpu)
>>> 3)ok downloaded and compiled suricata today git
>>> (548a3b2c93aed79e39a34ee9dd4c68f43a27f363)
>>> small better (cpu) result: (~1597% cpu -> ~1458% cpu)
>>> stat.log output:
>>> decoder.pkts              | Decode1             | 6771890
>>> decoder.pkts_per_sec      | Decode1             | 15203.400000
>>> decoder.bytes             | Decode1             | 9859871840
>>> decoder.bytes_per_sec     | Decode1             | 22136150.400000
>>> decoder.mbit_per_sec      | Decode1             | 177.089203
>>> decoder.ipv4              | Decode1             | 6771890
>>> decoder.ethernet          | Decode1             | 6771890
>>> decoder.udp               | Decode1             | 6771890
>>> decoder.avg_pkt_size      | Decode1             | 1456.000000
>>> decoder.max_pkt_size      | Decode1             | 1456
>>> ...
>>> top output:
>>> top - 10:22:16 up 4 days, 17:45,  3 users, load average: 15.25, 14.12,
>>> 9.60
>>> Tasks: 237 total,   1 running, 236 sleeping,   0 stopped,   0 zombie
>>> Cpu0  : 12.0%us, 20.0%sy, 66.0%ni,  2.0%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu1  : 92.0%us,  0.0%sy,  0.0%ni,  8.0%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu2  : 87.1%us,  1.0%sy,  0.0%ni, 11.9%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu3  : 92.9%us,  0.0%sy,  0.0%ni,  7.1%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu4  : 90.0%us,  0.0%sy,  0.0%ni, 10.0%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu5  : 92.1%us,  1.0%sy,  0.0%ni,  6.9%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu6  : 89.0%us,  1.0%sy,  0.0%ni, 10.0%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu7  : 92.0%us,  0.0%sy,  0.0%ni,  8.0%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu8  : 88.1%us,  2.0%sy,  0.0%ni,  9.9%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu9  : 91.0%us,  1.0%sy,  0.0%ni,  8.0%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu10 : 88.0%us,  0.0%sy,  0.0%ni, 12.0%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu11 : 93.0%us,  1.0%sy,  0.0%ni,  6.0%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu12 : 89.0%us,  1.0%sy,  0.0%ni, 10.0%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu13 : 90.1%us,  1.0%sy,  0.0%ni,  8.9%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu14 : 90.9%us,  0.0%sy,  0.0%ni,  9.1%id,  0.0%wa, 0.0%hi, 0.0%si,
>>> 0.0%st
>>> Cpu15 : 86.1%us,  1.0%sy,  0.0%ni,  6.9%id,  0.0%wa, 0.0%hi, 5.9%si,
>>> 0.0%st
>>> Mem:  12464792k total, 12040092k used,   424700k free,   136468k buffers
>>> Swap: 10482404k total,     2232k used, 10480172k free,  7602164k cached
>>>   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
>>> 24508 root      15   0  495m 244m 1360 S 1458.9  2.0 177:09.86 suricata
>>>
>>> 4) next test: enable gcc profiling...
>>> Regards
>>> Rmkml
>>>
>>>
>>> On Fri, 14 May 2010, rmkml wrote:
>>>
>>>> Hi Gurvinder,
>>>> thx for comments,
>>>> sp$rent not sending icmp, only big udp packet (in this case).
>>>> sorry, tcp it's not possible at this time.
>>>> Regards
>>>> Rmkml
>>>>
>>>>
>>>> On Fri, 14 May 2010, Gurvinder Singh wrote:
>>>>
>>>>> Thanks rmkml for the interesting numbers. I just wonder if there
>>>>> were any ICMP packets with the UDP traffic or not. As there is a
>>>>> known issue on todo list to fix the slowdown when ICMP and UDP are
>>>>> together in the traffic. If possible can you also test the engine
>>>>> with TCP traffic or just UDP traffic, you can have ICMP with TCP, as
>>>>> ICMP handling with TCP traffic is fine.
>>>>> Cheers,
>>>>> Gurvinder
>>>>>
>>>>> rmkml wrote:
>>>>>> Thx Victor and Will for reply,
>>>>>> Im reply for victor question: no, 1) test it's ~150Mbit udp, then
>>>>>> 3) test it's ~1Gbit udp...
>>>>>>
>>>>>> and for Will question, I have created new test 4) with
>>>>>> emerging-threat rules (thx all and matt) at
>>>>>> 12.668/18.496.000octet/148MBit (15% sending possibility):
>>>>>> {today downloaded+unzip
>>>>>> http://www.emergingthreats.net/rules/emerging-all.rules.zip and use
>>>>>> on suricata engine without modification}
>>>>>> stats.log output:
>>>>>>   decoder.pkts              | Decode1             | 4946191
>>>>>>   decoder.pkts_per_sec      | Decode1             | 19003.333333
>>>>>>   decoder.bytes             | Decode1             | 7201654096
>>>>>>   decoder.bytes_per_sec     | Decode1             | 27668853.333333
>>>>>>   decoder.mbit_per_sec      | Decode1             | 221.350827
>>>>>>   decoder.ipv4              | Decode1             | 4946191
>>>>>>   decoder.ethernet          | Decode1             | 4946191
>>>>>>   decoder.udp               | Decode1             | 4946191
>>>>>>   decoder.avg_pkt_size      | Decode1             | 1456.000000
>>>>>>   decoder.max_pkt_size      | Decode1             | 1456
>>>>>>   ...
>>>>>> and top output:
>>>>>>   top - 16:21:44 up 1 day, 23:45,  5 users,  load average: 9.90,
>>>>>> 8.33, 6.15
>>>>>>   Tasks: 241 total,   1 running, 240 sleeping,   0 stopped,   0 zombie
>>>>>>   Cpu0  : 29.7%us, 29.7%sy, 23.8%ni, 16.8%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu1  : 48.5%us,  4.0%sy,  0.0%ni, 47.5%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu2  : 49.0%us,  2.9%sy,  0.0%ni, 48.0%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu3  : 49.0%us,  3.9%sy,  0.0%ni, 47.1%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu4  : 49.5%us,  3.0%sy,  0.0%ni, 47.5%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu5  : 48.0%us,  2.9%sy,  0.0%ni, 49.0%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu6  : 52.0%us,  2.0%sy,  0.0%ni, 46.0%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu7  : 52.5%us,  4.0%sy,  0.0%ni, 43.6%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu8  : 57.8%us,  2.0%sy,  0.0%ni, 40.2%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu9  : 47.5%us,  3.0%sy,  0.0%ni, 49.5%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu10 : 49.5%us,  4.0%sy,  0.0%ni, 46.5%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu11 : 49.5%us,  3.0%sy,  0.0%ni, 47.5%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu12 : 47.5%us,  3.0%sy,  0.0%ni, 49.5%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu13 : 49.5%us,  2.0%sy,  0.0%ni, 48.5%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu14 : 49.0%us,  3.0%sy,  0.0%ni, 48.0%id, 0.0%wa, 0.0%hi,
>>>>>> 0.0%si, 0.0%st
>>>>>>   Cpu15 : 37.6%us,  2.0%sy,  0.0%ni, 33.7%id, 0.0%wa, 0.0%hi,
>>>>>> 26.7%si, 0.0%st
>>>>>> Mem:  12464792k total, 12001688k used,   463104k free,   174304k
>>>>>> buffers
>>>>>> Swap: 10482404k total,     2144k used, 10480260k free,  9287904k
>>>>>> cached
>>>>>>    PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
>>>>>> 28321 root      15   0  380m 130m 1348 S 876.4  1.1  68:03.01 suricata
>>>>>> Regards
>>>>>> Rmkml
>>>>>>
>>>>>>
>>>>>> On Fri, 14 May 2010, Victor Julien wrote:
>>>>>>
>>>>>>> Interesting numbers rmkml, thanks. The pkts_per_sec, bytes_per_sec
>>>>>>> and
>>>>>>> mbit_per_sec counters are completely unreliable at this point, fixing
>>>>>>> them is still on our todo list.
>>>>>>>
>>>>>>> Did both test runs send the same amount of packets? I see that the
>>>>>>> sigs
>>>>>>> run did 4M packets, the bare run 27M.
>>>>>>>
>>>>>>> Cheers,
>>>>>>> Victor
>>>
>>
>> ------------------------------------------------------------------------
>>
>> _______________________________________________
>> Oisf-devel mailing list
>> Oisf-devel at openinfosecfoundation.org
>> http://lists.openinfosecfoundation.org/mailman/listinfo/oisf-devel
>
>
> -- 
> ---------------------------------------------
> Victor Julien
> http://www.inliniac.net/
> PGP: http://www.inliniac.net/victorjulien.asc
> ---------------------------------------------
>
>





More information about the Oisf-devel mailing list