[Snort-devel] Unified2 logging bug in snort

elof at ...969... elof at ...969...
Sat Mar 23 08:53:18 EDT 2013


Just another update:

I've updated snort to:
    ,,_     -*> Snort! <*-
   o"  )~   Version 2.9.4.1 GRE (Build 69) FreeBSD
    ''''    By Martin Roesch & The Snort Team: http://www.snort.org/snort/snort-team
            Copyright (C) 1998-2013 Sourcefire, Inc., et al.
            Using libpcap version 1.3.0
            Using PCRE version: 8.32 2012-11-30
            Using ZLIB version: 1.2.7

Unfortunetly, the problem with missing packet data in the unified2 file 
still exist. :-/

/Elof


> Just an update:
>
> The reduction of the bpf.maxbufsize didn't help.
> It must have been the general decrease in traffic on the friday evening
> that resulted in less missing packets in the unified2 file.
>
>
> So, I've restored the net.bpf.maxbufsize to my initial value of 1067630080
> and increased kern.ipc.nmbclusters to 80000.
>
>
> This didn't help either. There's still missing packet data in unified2.
>
>
> PS:
> I learned from Beenph (barnyard2 developer) that barnyard2 doesn't
> complain about missing packets in the unified2 file immediately. It start
> logging Event Type 7 Packet 0x0 warnings after its event cache is full
> (default 2048 events). So if one want to see the warnings from barnyard2
> sooner one can set a lower cache value.
> ...or just use u2spewfoo to see them directly in the unified2 file.
>
>
>
> So... The problem has to be in snort itself, not in FreeBSD.
>
>
> Most of the missing packet data seem to be related to web-rules.
> Perhaps the data was pruned before it could be logged to unified2.
>
> (Snort Version 2.9.4 GRE (Build 40))
>
> /Elof
>
>
>
>> Well, my conclusion so far is that not using a huge bpf/daq buffer lowered
>> the amount of missing packets in unified2.
>>
>> I will let this run as this until monday.
>> On monday I will increase the kern.ipc.nmbclusters to see if the
>> "missing-packets-in-unified2-problem" goes away.
>
>
> On Fri, 15 Mar 2013, elof at ...969... wrote:
>
>>
>> Hi Bhagya.
>>
>> I have tried to get a pcap which can reproduce the error.
>> I sniffed millions of packets and waited for a missing packet in the
>> unified2 file, then I terminated the tcpdump process.
>>
>> When replaying the tcpdump file to snort (using the exact same config) it
>> does NOT show any issue.
>>
>>
>> However, I *think* I've found the cause of the bug. I don't know if it is
>> FreeBSD or snort that is to blame though.
>>
>>
>> Here's the environment:
>> I'm running FreeBSD 9.1 amd64 on a machine with 8192 MB RAM.
>>
>> CPU: Intel(R) Xeon(R) CPU E3-1230 V2 @ 3.30GHz (3300.10-MHz K8-class CPU)
>> FreeBSD/SMP: Multiprocessor System Detected: 8 CPUs
>> FreeBSD/SMP: 1 package(s) x 4 core(s) x 2 SMT threads
>>
>> It has 4 em NICs and 4 igb NICs.
>>
>> igb0: Bound queue 0 to cpu 0
>> igb0: Bound queue 1 to cpu 1
>> igb0: Bound queue 2 to cpu 2
>> igb0: Bound queue 3 to cpu 3
>> igb0: Bound queue 4 to cpu 4
>> igb0: Bound queue 5 to cpu 5
>> igb0: Bound queue 6 to cpu 6
>> igb0: Bound queue 7 to cpu 7
>> igb1: Bound queue 0 to cpu 0
>> igb1: Bound queue 1 to cpu 1
>> igb1: Bound queue 2 to cpu 2
>> igb1: Bound queue 3 to cpu 3
>> igb1: Bound queue 4 to cpu 4
>> igb1: Bound queue 5 to cpu 5
>> igb1: Bound queue 6 to cpu 6
>> igb1: Bound queue 7 to cpu 7
>> igb2: Bound queue 0 to cpu 0
>> igb2: Bound queue 1 to cpu 1
>> igb2: Bound queue 2 to cpu 2
>> igb2: Bound queue 3 to cpu 3
>> igb2: Bound queue 4 to cpu 4
>> igb2: Bound queue 5 to cpu 5
>> igb2: Bound queue 6 to cpu 6
>> igb2: Bound queue 7 to cpu 7
>> igb3: Bound queue 0 to cpu 0
>> igb3: Bound queue 1 to cpu 1
>> igb3: Bound queue 2 to cpu 2
>> igb3: Bound queue 3 to cpu 3
>> igb3: Bound queue 4 to cpu 4
>> igb3: Bound queue 5 to cpu 5
>> igb3: Bound queue 6 to cpu 6
>> igb3: Bound queue 7 to cpu 7
>>
>> I've read that FreeBSD + many cores + many igb NICs exhaust the mbufs (or
>> something), so I've increased the kern.ipc.nmbclusters=40000 a little bit.
>>
>>
>> Now, the *real* change I did was this:
>> When snort were missing packet data in the unified2 file, I had a huge
>> bpf-buffer and identical daq buffer size:
>>
>> /etc/sysctl.conf:
>> net.bpf.maxbufsize=1067630080
>>
>> snort.conf:
>> config daq: pcap
>> config daq_var: buffer_size=1067630080
>>
>>
>>
>> The only change I did a few hours ago was to reduce the bpf.maxbufsize and
>> reboot the machine:
>>
>> /etc/sysctl.conf:
>> net.bpf.maxbufsize=67630080
>>
>> Snort daq still ask for 1067630080 but only get 67630080 bytes from the
>> system.
>>
>> During these hours, there has been no missing packet data in the unified2
>> file according to barnyard2. There are normally a couple of warnings every
>> hour.
>>
>> Now that I run u2spewfoo on the unified2 file I see three events without
>> any packet data (out of 330 events in total). In /var/log/ I *don't* see
>> any complaint from barnyard2 even though there are missing packet data.
>> Strange!
>>
>>
>> Well, my conclusion so far is that not using a huge bpf/daq buffer lowered
>> the amount of missing packets in unified2.
>>
>> I will let this run as this until monday.
>> On monday I will increase the kern.ipc.nmbclusters to see if the
>> "missing-packets-in-unified2-problem" goes away.
>>
>> /Elof
>>
>>
>> On Wed, 13 Mar 2013, Bhagya Bantwal wrote:
>>
>>> Thank you for reporting this issue. We did recently fix an issue
>>> similar to this. If you send us your pcap and conf, we can confirm
>>> that it is the same issue.
>>>
>>> On Wed, Mar 13, 2013 at 9:25 AM,  <elof at ...969...> wrote:
>>>> Hi!
>>>>
>>>> I found a bug in my snort (Version 2.9.4 GRE (Build 40)) and wonder if you
>>>> need more data about it, or if it is already reported or being fixed.
>>>>
>>>> I don't want to waste lots of hours creating a bug report for something that
>>>> is already known... :-)
>>>>
>>>>
>>>>
>>>> Issue:
>>>> snort don't always log the event packet data to unified2, only the event
>>>> itself.
>>>>
>>>>
>>>> Example:
>>>> snort.conf:output unified2: filename snort.unified2
>>>> snort.conf:output alert_fast: snort.alert
>>>>
>>>> Snort logs all events to both snort.alert (ascii) and to unified2.
>>>>
>>>>
>>>> * I start snort (no logfiles exists prior to this)
>>>> * 9 events are triggered
>>>> * I terminate snort
>>>>
>>>> snort.alert show these 9 lines:
>>>> 1 03/12/13-18:29:02.090781  [**] [1:2008066:6]  <mon0> ET USER_AGENTS
>>>> Suspicious Blank User-Agent (descriptor but no string) [**] [Classification:
>>>> A Network Trojan was detected] [Priority: 1] {TCP} 10.100.3.139:57261 ->
>>>> 10.23.16.22:80
>>>> 2 03/12/13-18:30:05.160641  [**] [1:2008066:6]  <mon0> ET USER_AGENTS
>>>> Suspicious Blank User-Agent (descriptor but no string) [**] [Classification:
>>>> A Network Trojan was detected] [Priority: 1] {TCP} 212.188.183.73:56842 ->
>>>> 193.189.143.34:80
>>>> 3 03/12/13-18:30:05.160515  [**] [1:2008066:6]  <mon0> ET USER_AGENTS
>>>> Suspicious Blank User-Agent (descriptor but no string) [**] [Classification:
>>>> A Network Trojan was detected] [Priority: 1] {TCP} 10.100.3.139:57168 ->
>>>> 193.189.143.34:80
>>>> 4 03/12/13-18:31:05.167982  [**] [1:2008066:6]  <mon0> ET USER_AGENTS
>>>> Suspicious Blank User-Agent (descriptor but no string) [**] [Classification:
>>>> A Network Trojan was detected] [Priority: 1] {TCP} 212.188.183.73:56842 ->
>>>> 193.189.143.34:80
>>>> 5 03/12/13-18:31:05.167859  [**] [1:2008066:6]  <mon0> ET USER_AGENTS
>>>> Suspicious Blank User-Agent (descriptor but no string) [**] [Classification:
>>>> A Network Trojan was detected] [Priority: 1] {TCP} 10.100.3.139:57168 ->
>>>> 193.189.143.34:80
>>>> 6 03/12/13-18:32:05.176776  [**] [1:2008066:6]  <mon0> ET USER_AGENTS
>>>> Suspicious Blank User-Agent (descriptor but no string) [**] [Classification:
>>>> A Network Trojan was detected] [Priority: 1] {TCP} 212.188.183.73:56842 ->
>>>> 193.189.143.34:80
>>>> 7 03/12/13-18:32:05.176652  [**] [1:2008066:6]  <mon0> ET USER_AGENTS
>>>> Suspicious Blank User-Agent (descriptor but no string) [**] [Classification:
>>>> A Network Trojan was detected] [Priority: 1] {TCP} 10.100.3.139:57168 ->
>>>> 193.189.143.34:80
>>>> 8 03/12/13-18:35:05.226355  [**] [1:2008066:6]  <mon0> ET USER_AGENTS
>>>> Suspicious Blank User-Agent (descriptor but no string) [**] [Classification:
>>>> A Network Trojan was detected] [Priority: 1] {TCP} 212.188.183.73:60351 ->
>>>> 193.189.143.34:80
>>>> 9 03/12/13-18:35:05.226230  [**] [1:2008066:6]  <mon0> ET USER_AGENTS
>>>> Suspicious Blank User-Agent (descriptor but no string) [**] [Classification:
>>>> A Network Trojan was detected] [Priority: 1] {TCP} 10.100.3.139:57388 ->
>>>> 193.189.143.34:80
>>>>
>>>>
>>>> 'u2spewfoo snort.unified2.1363109305' show this in the unified2 file:
>>>> (Event)
>>>>         sensor id: 0    event id: 1     event second: 1363109342 event
>>>> microsecond: 90781
>>>>         sig id: 2008066 gen id: 1       revision: 6      classification: 21
>>>>         priority: 1     ip source: 10.100.3.139 ip destination: 10.23.16.22
>>>>         src port: 57261 dest port: 80   protocol: 6     impact_flag: 0
>>>> blocked: 0
>>>>
>>>> Packet
>>>>         sensor id: 0    event id: 1     event second: 1363109342
>>>>         packet second: 1363109342       packet microsecond: 90781
>>>>         linktype: 1     packet_length: 415
>>>> [    0] 00 00 5E 00 01 10 3C D9 2B 6A 5D 60 08 00 45 00  ..^...<.+j]`..E.
>>>> [   16] 01 91 18 7C 40 00 80 06 B8 CF 0A 64 03 8B 0A 17  ...|@......d....
>>>> [   32] 10 16 DF AD 00 50 91 5B 61 9C D4 A9 E5 7A 50 18  .....P.[a....zP.
>>>> [   48] 01 04 08 2D 00 00 47 45 54 20 2F 67 6F 2F 68 6F  ...-..GET /go/ho
>>>> [   64] 6D 65 20 48 54 54 50 2F 31 2E 31 0D 0A 48 6F 73  me HTTP/1.1..Hos
>>>> ...snip...
>>>>
>>>> (Event)
>>>>         sensor id: 0    event id: 2     event second: 1363109405 event
>>>> microsecond: 160641
>>>>         sig id: 2008066 gen id: 1       revision: 6      classification: 21
>>>>         priority: 1     ip source: 212.188.183.73       ip destination:
>>>> 193.189.143.34
>>>>         src port: 56842 dest port: 80   protocol: 6     impact_flag: 0
>>>> blocked: 0
>>>>
>>>> (Event)
>>>>         sensor id: 0    event id: 3     event second: 1363109405 event
>>>> microsecond: 160515
>>>>         sig id: 2008066 gen id: 1       revision: 6      classification: 21
>>>>         priority: 1     ip source: 10.100.3.139 ip destination:
>>>> 193.189.143.34
>>>>         src port: 57168 dest port: 80   protocol: 6     impact_flag: 0
>>>> blocked: 0
>>>>
>>>> (Event)
>>>>         sensor id: 0    event id: 4     event second: 1363109465 event
>>>> microsecond: 167982
>>>>         sig id: 2008066 gen id: 1       revision: 6      classification: 21
>>>>         priority: 1     ip source: 212.188.183.73       ip destination:
>>>> 193.189.143.34
>>>>         src port: 56842 dest port: 80   protocol: 6     impact_flag: 0
>>>> blocked: 0
>>>>
>>>> (Event)
>>>>         sensor id: 0    event id: 5     event second: 1363109465 event
>>>> microsecond: 167859
>>>>         sig id: 2008066 gen id: 1       revision: 6      classification: 21
>>>>         priority: 1     ip source: 10.100.3.139 ip destination:
>>>> 193.189.143.34
>>>>         src port: 57168 dest port: 80   protocol: 6     impact_flag: 0
>>>> blocked: 0
>>>>
>>>> (Event)
>>>>         sensor id: 0    event id: 6     event second: 1363109525 event
>>>> microsecond: 176776
>>>>         sig id: 2008066 gen id: 1       revision: 6      classification: 21
>>>>         priority: 1     ip source: 212.188.183.73       ip destination:
>>>> 193.189.143.34
>>>>         src port: 56842 dest port: 80   protocol: 6     impact_flag: 0
>>>> blocked: 0
>>>>
>>>> (Event)
>>>>         sensor id: 0    event id: 7     event second: 1363109525 event
>>>> microsecond: 176652
>>>>         sig id: 2008066 gen id: 1       revision: 6      classification: 21
>>>>         priority: 1     ip source: 10.100.3.139 ip destination:
>>>> 193.189.143.34
>>>>         src port: 57168 dest port: 80   protocol: 6     impact_flag: 0
>>>> blocked: 0
>>>>
>>>> (Event)
>>>>         sensor id: 0    event id: 8     event second: 1363109705 event
>>>> microsecond: 226355
>>>>         sig id: 2008066 gen id: 1       revision: 6      classification: 21
>>>>         priority: 1     ip source: 212.188.183.73       ip destination:
>>>> 193.189.143.34
>>>>         src port: 60351 dest port: 80   protocol: 6     impact_flag: 0
>>>> blocked: 0
>>>>
>>>> Packet
>>>>         sensor id: 0    event id: 8     event second: 1363109705
>>>>         packet second: 1363109705       packet microsecond: 226355
>>>>         linktype: 1     packet_length: 1066
>>>> [    0] 00 00 0C 07 AC 01 90 E2 BA 1A 4B 98 08 00 45 00  ..........K...E.
>>>> [   16] 04 1C 26 5B 40 00 7F 06 F4 9A D4 BC B7 49 C1 BD  ..&[@........I..
>>>> [   32] 8F 22 EB BF 00 50 36 9D 09 53 4E FC 08 31 50 18  ."...P6..SN..1P.
>>>> [   48] 01 00 57 3E 00 00 50 4F 53 54 20 2F 61 70 69 2F  ..W>..POST /api/
>>>> ...snip...
>>>>
>>>> (Event)
>>>>         sensor id: 0    event id: 9     event second: 1363109705 event
>>>> microsecond: 226230
>>>>         sig id: 2008066 gen id: 1       revision: 6      classification: 21
>>>>         priority: 1     ip source: 10.100.3.139 ip destination:
>>>> 193.189.143.34
>>>>         src port: 57388 dest port: 80   protocol: 6     impact_flag: 0
>>>> blocked: 0
>>>>
>>>> Packet
>>>>         sensor id: 0    event id: 9     event second: 1363109705
>>>>         packet second: 1363109705       packet microsecond: 226230
>>>>         linktype: 1     packet_length: 1066
>>>> [    0] 00 00 5E 00 01 10 3C D9 2B 6A 5D 60 08 00 45 00  ..^...<.+j]`..E.
>>>> [   16] 04 1C 26 5B 40 00 80 06 71 B2 0A 64 03 8B C1 BD  ..&[@...q..d....
>>>> [   32] 8F 22 E0 2C 00 50 36 9D 09 53 4E FC 08 31 50 18  .".,.P6..SN..1P.
>>>> [   48] 01 00 E0 E8 00 00 50 4F 53 54 20 2F 61 70 69 2F  ......POST /api/
>>>> ...snip...
>>>>
>>>>
>>>>
>>>> Where did the packet data for events 2-7 go???
>>>> In event 1, 8 and 9 the packet data is logged correctly but events 2-7 have
>>>> no packet data logged even though it is the same signature that trigger.
>>>> Strange!
>>>>
>>>>
>>>>
>>>>
>>>> Having a snort that don't log security events properly is quite bad...
>>>> A 'MAJOR' bug imho.
>>>>
>>>>
>>>> Anyhow, this happen a few times every day, but not in such a manner that I
>>>> can easily tcpdump the traffic and create a test-pcap.
>>>>
>>>> /Elof
>>>
>>> ------------------------------------------------------------------------------
>>> Everyone hates slow websites. So do we.
>>> Make your web apps faster with AppDynamics
>>> Download AppDynamics Lite for free today:
>>> http://p.sf.net/sfu/appdyn_d2d_mar
>>> _______________________________________________
>>> Snort-devel mailing list
>>> Snort-devel at lists.sourceforge.net
>>> https://lists.sourceforge.net/lists/listinfo/snort-devel
>>> Archive:
>>> http://sourceforge.net/mailarchive/forum.php?forum_name=snort-devel
>>>
>>> Please visit http://blog.snort.org for the latest news about Snort!
>>>
>>
>> ------------------------------------------------------------------------------
>> Everyone hates slow websites. So do we.
>> Make your web apps faster with AppDynamics
>> Download AppDynamics Lite for free today:
>> http://p.sf.net/sfu/appdyn_d2d_mar
>> _______________________________________________
>> Snort-devel mailing list
>> Snort-devel at lists.sourceforge.net
>> https://lists.sourceforge.net/lists/listinfo/snort-devel
>> Archive:
>> http://sourceforge.net/mailarchive/forum.php?forum_name=snort-devel
>>
>> Please visit http://blog.snort.org for the latest news about Snort!
>>
>
> ------------------------------------------------------------------------------
> Everyone hates slow websites. So do we.
> Make your web apps faster with AppDynamics
> Download AppDynamics Lite for free today:
> http://p.sf.net/sfu/appdyn_d2d_mar
> _______________________________________________
> Snort-devel mailing list
> Snort-devel at lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/snort-devel
> Archive:
> http://sourceforge.net/mailarchive/forum.php?forum_name=snort-devel
>
> Please visit http://blog.snort.org for the latest news about Snort!
>




More information about the Snort-devel mailing list