firnsy / barnyard2

Barnyard2 is a dedicated spooler for Snort's unified2 binary output format.
GNU General Public License v2.0
346 stars 190 forks source link

Segfault in dbProcessEventInformation() #63

Closed reedloden closed 11 years ago

reedloden commented 11 years ago

Getting a fairly consistent segfault with latest barnyard2 using the database output plugin connected to mysql.

Compile options: ./configure --prefix=/usr --sysconfdir=/etc/barnyard2 --with-mysql-libraries=/usr/lib/x86_64-linux-gnu --enable-mysql-ssl-support --enable-debug

Startup arguments: -D -c /etc/barnyard2/barnyard.conf -d /var/log/barnyard2 -w /var/log/barnyard2/barnyard2.waldo -l /var/log/barnyard2 -f unified2.alert -i eth1

$ barnyard2 -V

  ______   -*> Barnyard2 <*-
 / ,,_  \  Version 2.1.11 (Build 318) DEBUG
 |o"  )~|  By Ian Firns (SecurixLive): http://www.securixlive.com/
 + '''' +  (C) Copyright 2008-2012 Ian Firns <firnsy@securixlive.com>

Output from gdb:

0x000000000043953a in dbProcessEventInformation (data=0x7ffff7f87010, p=0x3a79cc0, event=0x3a78760, event_type=7, i_sig_id=375) at spo_database.c:2001
2001    spo_database.c: No such file or directory.
(gdb) bt full
#0  0x000000000043953a in dbProcessEventInformation (data=0x7ffff7f87010, p=0x3a79cc0, event=0x3a78760, event_type=7, i_sig_id=375) at spo_database.c:2001
        SQLQueryPtr = 0x33e4400 ""
        i = 0
        __FUNCTION__ = "dbProcessEventInformation"
#1  0x000000000043a4bc in Database (p=0x3a79cc0, event=0x3a78760, event_type=7, arg=0x7ffff7f87010) at spo_database.c:2494
        data = 0x7ffff7f87010
        CurrentQuery = 0x0
        sig_id = 375
        itr = 0
        SQLMaxQuery = 0
        __FUNCTION__ = "Database"
        sid = 2200035
        gid = 1
        revision = 1
        event_id = 2473594
        event_second = 1357679520
        event_microsecond = 25801
#2  0x000000000041d9ac in CallOutputPlugins (out_type=OUTPUT_TYPE__SPECIAL, packet=0x3a79cc0, event=0x3a78760, event_type=7) at plugbase.c:573
        idx = 0xb4c540
#3  0x000000000041ebf3 in spoolerProcessRecord (spooler=0x2caa0f0, fire_output=1) at spooler.c:701
        event_id = 2473594
        pkth = {ts = {tv_sec = 1357679520, tv_usec = 25801}, caplen = 136, len = 136}
        type = 2
        ernCache = 0x3a78650
#4  0x000000000041e731 in ProcessContinuous (dirpath=0x6bbacc "/var/log/barnyard2", filebase=0x6bbecc "unified2.alert", record_start=0, timestamp=1357678214) at spooler.c:533
        spooler = 0x2caa0f0
        ret = 0
        pc_ret = 0
        new_file_available = 0
        waiting_logged = 0
        skipped = 0
        extension = 1357678213
        waldo_timestamp = 1357621019
#5  0x000000000041e956 in ProcessContinuousWithWaldo (waldo=0x6bb6c4) at spooler.c:621
No locals.
#6  0x0000000000403d62 in Barnyard2Main (argc=14, argv=0x7fffffffe178) at barnyard2.c:374
No locals.
#7  0x0000000000403b8a in main (argc=14, argv=0x7fffffffe178) at barnyard2.c:285
No locals.

Rule that is causing the problem:

alert pkthdr any any -> any any (msg:"SURICATA TCP invalid option length"; decode-event:tcp.invalid_optlen; sid:2200035; rev:1;)

Assistance getting this resolved would be appreciated.

reedloden commented 11 years ago
(gdb) print *p
$12 = {pkth = 0x7fffffffdf50, pkt = 0x3a787bc "\324\256R\255z\223(\300\332z\024\023\b", ah = 0x0, eh = 0x3a787bc, vh = 0x0, ehllc = 0x0, ehllcother = 0x0, greh = 0x0, mpls = 0x0, iph = 0x3a787ca,
  orig_iph = 0x0, inner_iph = 0x3a787ca, outer_iph = 0x0, tcph = 0x0, orig_tcph = 0x0, udph = 0x0, orig_udph = 0x0, icmph = 0x0, orig_icmph = 0x0, data = 0x0,
  ip_data = 0x3a787de "\305\232\001\273]\234\210G\001\v\005\004\001\003", outer_ip_data = 0x0, ip_frag_start = 0x0, ip_options_data = 0x0, tcp_options_data = 0x0, ssnptr = 0x0, fragtracker = 0x0,
  flow = 0x0, streamptr = 0x0, ip4h = 0x0, orig_ip4h = 0x0, ip6h = 0x0, orig_ip6h = 0x0, icmp6h = 0x0, orig_icmp6h = 0x0, iph_api = 0x0, orig_iph_api = 0x0, outer_iph_api = 0x0,
  outer_orig_iph_api = 0x0, inner_ip4h = {ip_verhl = 0 '\000', ip_tos = 0 '\000', ip_len = 0, ip_id = 0, ip_off = 0, ip_ttl = 0 '\000', ip_proto = 0 '\000', ip_csum = 0, ip_src = {family = 0,
      bits = 0, ip = {u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}, ip_dst = {family = 0, bits = 0, ip = {
        u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}}, inner_orig_ip4h = {ip_verhl = 0 '\000', ip_tos = 0 '\000', ip_len = 0, ip_id = 0,
    ip_off = 0, ip_ttl = 0 '\000', ip_proto = 0 '\000', ip_csum = 0, ip_src = {family = 0, bits = 0, ip = {u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0,
          0, 0, 0}}}, ip_dst = {family = 0, bits = 0, ip = {u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}}, inner_ip6h = {vcl = 0, len = 0,
    next = 0 '\000', hop_lmt = 0 '\000', ip_src = {family = 0, bits = 0, ip = {u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}, ip_dst = {
      family = 0, bits = 0, ip = {u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}}, inner_orig_ip6h = {vcl = 0, len = 0, next = 0 '\000',
    hop_lmt = 0 '\000', ip_src = {family = 0, bits = 0, ip = {u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}, ip_dst = {family = 0, bits = 0,
      ip = {u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}}, outer_ip4h = {ip_verhl = 0 '\000', ip_tos = 0 '\000', ip_len = 0, ip_id = 0,
    ip_off = 0, ip_ttl = 0 '\000', ip_proto = 0 '\000', ip_csum = 0, ip_src = {family = 0, bits = 0, ip = {u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0,
          0, 0, 0}}}, ip_dst = {family = 0, bits = 0, ip = {u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}}, outer_orig_ip4h = {
    ip_verhl = 0 '\000', ip_tos = 0 '\000', ip_len = 0, ip_id = 0, ip_off = 0, ip_ttl = 0 '\000', ip_proto = 0 '\000', ip_csum = 0, ip_src = {family = 0, bits = 0, ip = {
        u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}, ip_dst = {family = 0, bits = 0, ip = {u6_addr8 = '\000' <repeats 15 times>,
        u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}}, outer_ip6h = {vcl = 0, len = 0, next = 0 '\000', hop_lmt = 0 '\000', ip_src = {family = 0, bits = 0, ip = {
        u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}, ip_dst = {family = 0, bits = 0, ip = {u6_addr8 = '\000' <repeats 15 times>,
        u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}}, outer_orig_ip6h = {vcl = 0, len = 0, next = 0 '\000', hop_lmt = 0 '\000', ip_src = {family = 0, bits = 0, ip = {
        u6_addr8 = '\000' <repeats 15 times>, u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}, ip_dst = {family = 0, bits = 0, ip = {u6_addr8 = '\000' <repeats 15 times>,
        u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}}, mplsHdr = {label = 0, exp = 0 '\000', bos = 0 '\000', ttl = 0 '\000'}, family = 0, orig_family = 0, outer_family = 0,
  bytes_to_inspect = 0, preprocessor_bits = 0, preproc_reassembly_pkt_bits = 0, caplen = 0, http_pipeline_count = 0, packet_flags = 0, proto_bits = 0, dsize = 0, ip_dsize = 102, alt_dsize = 0,
  actual_ip_len = 122, outer_ip_dsize = 0, frag_offset = 0, ip_frag_len = 0, ip_options_len = 0, tcp_options_len = 0, sp = 0, dp = 0, orig_sp = 0, orig_dp = 0, application_protocol_ordinal = 0,
  frag_flag = 0 '\000', mf = 0 '\000', df = 1 '\001', rf = 0 '\000', uri_count = 0 '\000', csum_flags = 0 '\000', encapsulated = 0 '\000', ip_option_count = 0 '\000', tcp_option_count = 0 '\000',
  ip6_extension_count = 0 '\000', ip6_frag_index = 0 '\000', ip_lastopt_bad = 0 '\000', tcp_lastopt_bad = 0 '\000', fddihdr = 0x0, fddisaps = 0x0, fddisna = 0x0, fddiiparp = 0x0, fddiother = 0x0,
  trh = 0x0, trhllc = 0x0, trhmr = 0x0, pf1h = 0x0, pf2h = 0x0, pf3h = 0x0, sllh = 0x0, wifih = 0x0, pppoeh = 0x0, eplh = 0x0, eaph = 0x0, eaptype = 0x0, eapolk = 0x0, ip_options = {{code = 0 '\000',
      len = 0 '\000', data = 0x0} <repeats 40 times>}, tcp_options = {{code = 0 '\000', len = 0 '\000', data = 0x0} <repeats 40 times>}, ip6_extensions = {{type = 0 '\000',
      data = 0x0} <repeats 40 times>}, configPolicyId = 0, linktype = 1}
binf commented 11 years ago

Are you able to process your unified2 file with u2spewfoo? What is your segmentation fault message?

By the later i @ which line does it segfault?

Also whats the impact of the following suricata keyword in event logging data "pkthdr".

/* Addmentum */ I actually reformated the comment you left (localy) and i had some of the previously requested information (IE didin't seem to render it correctly width wise so i was missing some information.

seem's like the decoder is not able to decode the packet but the packet is tagged as tcp packet (from the decoded ip header) but if you look at your second message, there is no tcph pointer defined in the payload which lead to the segfault.

Its mainly due to the way the decoder work for now, it probably bails and does not return any error since their all void returning functions.

I would still be curious to see what u2spewfoo prints and see the offending packet in a pcap, you can probably also use u2boat to extract the packets them self from the unified2 file.

reedloden commented 11 years ago

Sadly, I needed to move forward (as this was blocking progress), and before your comment came in yesterday, I disabled all the suricata decoder (http://rules.emergingthreats.net/open/suricata/rules/decoder-events.rules) and stream (http://rules.emergingthreats.net/open/suricata/rules/stream-events.rules) rules and removed all the faulty unified2 files. Barnyard2 is working fine now, but I still have it running under gdb for the time being in case it segfaults again.

I'll be spinning up some new sensors soon, and when I do, I'll re-enable those rules to see if I can get it to segfault again.

binf commented 11 years ago

Ok.

You could also set a large enough ulimit and use the coredump for backtracing a potential crash instead of running under gdb.

If you even happen to have a unified2 file you could share with a event that cause a crahs i would also like to see it if possible.

s-takehana commented 11 years ago

I've been getting same issue when using Suricata ET rules(http://rules.emergingthreats.net/open/suricata/emerging.rules.tar.gz).

Output from Barnyard2:

        --== Initialization Complete ==--
  ______   -*> Barnyard2 <*-
 / ,,_  \  Version 2.1.11 (Build 318) DEBUG
 |o"  )~|  By Ian Firns (SecurixLive): http://www.securixlive.com/
 + '''' +  (C) Copyright 2008-2012 Ian Firns 
Using waldo file '/etc/suricata/bylog.waldo':
    spool directory = /var/log/suricata
    spool filebase  = unified2.alert
    time_stamp      = 1358335191
    record_idx      = 159
Opened spool file '/var/log/suricata/unified2.alert.1358335191'
01/16-21:06:38.701717  [**] [1:2200035:1] SURICATA TCP invalid option length [**] [Classification ID: (null)] [Priority ID: 3] {TCP} ***.***.***.***:0 -> ***.***.***.***:0
INFO [dbProcessSignatureInformation()]: [Event: 80] with [gid: 1] [sid: 2200035] [rev: 1] [classification: 0] [priority: 3] Signature Message -> "[SURICATA TCP invalid option length]"
         was not found in barnyard2 signature cache, this could mean its is the first time the signature is processed, and will be inserted
         in the database with the above information, this message should only be printed once for each signature that is not  present in the database
         The new inserted signature will not have its information present in the sig_reference table,it should be present on restart
         if the information is present in the sid-msg.map file.
         You can allways update the message via a SQL query if you want it to be displayed correctly by your favorite interface
Segmentation fault (core dumped)

Output from syslog:

kernel: barnyard2[30469]: segfault at 12 ip 00000000004380d9 sp 00007fffc1b46ee0 error 4 in barnyard2[400000+5e000]

Output from gdb:

(gdb) bt
#0  0x00000000004380d9 in dbProcessEventInformation (data=0x7f7402fe9010, p=0x3eb2c40, event=0x39daf70, event_type=7, i_sig_id=1996) at spo_database.c:2001
#1  0x000000000043903e in Database (p=0x3eb2c40, event=0x39daf70, event_type=7, arg=0x7f7402fe9010) at spo_database.c:2494
#2  0x000000000041ce8c in CallOutputPlugins (out_type=OUTPUT_TYPE__SPECIAL, packet=0x3eb2c40, event=0x39daf70, event_type=7) at plugbase.c:573
#3  0x000000000041e0d3 in spoolerProcessRecord (spooler=0x3ba1880, fire_output=1) at spooler.c:701
#4  0x000000000041dc11 in ProcessContinuous (dirpath=0x15beabc "/var/log/suricata", filebase=0x15beebc "unified2.alert", record_start=0, timestamp=1358335192) at spooler.c:533
#5  0x000000000041de36 in ProcessContinuousWithWaldo (waldo=0x15be6b4) at spooler.c:621
#6  0x0000000000403882 in Barnyard2Main (argc=7, argv=0x7fffc1b472e8) at barnyard2.c:374
#7  0x00000000004036aa in main (argc=7, argv=0x7fffc1b472e8) at barnyard2.c:285
#0  0x00000000004380d9 in dbProcessEventInformation (data=0x7f7402fe9010, p=0x3eb2c40, event=0x39daf70, event_type=7, i_sig_id=1996) at spo_database.c:2001
2001                                           ntohs(p->tcph->th_urp))) != SNORT_SNPRINTF_SUCCESS)
(gdb) p p->tcph->th_urp
Cannot access memory at address 0x12

Output from u2spewfoo:

(Event)
    sensor id: 0    event id: 80    event second: 1358337998    event microsecond: 701717
    sig id: 2200035 gen id: 1   revision: 1  classification: 0
    priority: 3 ip source: ***.***.***.***  ip destination: ***.***.***.***
    src port: 0 dest port: 0    protocol: 6 impact_flag: 0  blocked: 0
Packet
    sensor id: 0    event id: 80    event second: 1358337998
    packet second: 1358337998   packet microsecond: 701717
    linktype: 1 packet_length: 66
[    0] 00 A0 DE 67 28 D9 00 12 F2 92 1A 00 81 00 00 5F  ...g(.........._
[   16] 08 00 45 00 00 30 E3 C1 40 00 6F 06 2B 4B 32 12  ..E..0..@.o.+K2.
[   32] 75 B8 CB B2 89 3E 00 00 00 00 55 C3 69 82 00 00  u....>....U.i...
[   48] 00 00 04 28 1F 90 91 39 00 00 99 02 97 05 00 00  ...(...9........
[   64] 00 00                                            ..

This isuue happened with below alert too.

SURICATA UDP packet too small
ET RBN Known Russian Business Network IP (423)

Could you resolve?

binf commented 11 years ago

On Tue, Jan 29, 2013 at 11:44 PM, s-takehana notifications@github.com wrote:

I've been getting same issue when using Suricata ET rules(http://rules.emergingthreats.net/open/suricata/emerging.rules.tar.gz).

Output from u2spewfoo:

(Event) sensor id: 0 event id: 80 event second: 1358337998 event microsecond: 701717 sig id: 2200035 gen id: 1 revision: 1 classification: 0 priority: 3 ip source: _..**._ ip destination: .**._._ src port: 0 dest port: 0 protocol: 6 impact_flag: 0 blocked: 0

Packet sensor id: 0 event id: 80 event second: 1358337998 packet second: 1358337998 packet microsecond: 701717 linktype: 1 packetlength: 66 [ 0] 00 A0 DE 67 28 D9 00 12 F2 92 1A 00 81 00 00 5F ...g(.......... [ 16] 08 00 45 00 00 30 E3 C1 40 00 6F 06 2B 4B 32 12 ..E..0..@.o.+K2. [ 32] 75 B8 CB B2 89 3E 00 00 00 00 55 C3 69 82 00 00 u....>....U.i... [ 48] 00 00 04 28 1F 90 91 39 00 00 99 02 97 05 00 00 ...(...9........ [ 64] 00 00 ..

This isuue happened with below alert too.

SURICATA UDP packet too small ET RBN Known Russian Business Network IP (423)

Could you resolve?

Yes its resolvable by adding a extra check for null transport protocol header presence before inserting its information in the query.

Should issue a bug-fix commit somewhere tomorow.

-elz

s-takehana commented 11 years ago

How about bug-fix. Could you tell me, how long will it take?

binf commented 11 years ago

Sorry for the delay , i honestly forgot about it.

The branch containing the fix can be found there -> https://github.com/binf/barnyard2/tree/bug-fix

Let us know how its goes and again, sorry for the delay.

s-takehana commented 11 years ago

I've updated to bug-fix and tried again. I've confirmed writting to database whithout segfault.

Thank you very much for your help.

reedloden commented 11 years ago

I assume you will do a PR to upstream to get this included so I won't need to locally patch?

~reed

binf commented 11 years ago

Why would you need to localy patch? Just pull the branch if you want to test.

bug-fix in my tree is the same as firnsy master + some patch.

But you do as you want, if you want to patch over it, you can also do it like that.

On Mon, Feb 4, 2013 at 11:06 PM, Reed Loden notifications@github.comwrote:

I assume you will do a PR to upstream to get this included so I won't need to locally patch?

~reed

— Reply to this email directly or view it on GitHubhttps://github.com/firnsy/barnyard2/issues/63#issuecomment-13113761.

reedloden commented 11 years ago

Going to close this out...