[Snort-devel] Unified2 logging bug in snort

elof at ...969... elof at ...969...
Tue Mar 19 12:05:03 EDT 2013


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!
>




More information about the Snort-devel mailing list