Assertion failure, Tag.cc

Zeek
1

Hi All,

Has anyone encountered the assertion failure below with Bro 2.4.1? This is happening with live traffic at least a couple times a day since upgrading from Bro 2.3.2. I didn’t see anything the bug tracker, so thought I’d float it here first.

listening on zc:99@1, capture length 8192 bytes

1459786307.312525 processing suspended
1459786307.312525 processing continued
1459802619.911190 Failed to open GeoIP City database: /usr/share/GeoIP/GeoIPCity.dat
1459802619.911190 Fell back to GeoIP Country database
1459802619.911190 Failed to open GeoIP Cityv6 database: /usr/share/GeoIP/GeoIPCityv6.dat
bro: /home/mfry/dev/bro24/bro-2.4.1/src/Tag.cc:72: EnumVal* Tag::AsEnumVal(EnumType*) const: Assertion `type == 0 && subtype == 0’ failed.
/opt/bro/share/broctl/scripts/run-bro: line 100: 11312 Aborted (core dumped) nohup ${pin_command} $pin_cpu “$mybro” “$@”

Regards,
Michael

2

I've not seen that before. Are you running any custom local scripts?

Do you still have the core file that it dumped? There's a good chance gdb can be used to figure out what script triggered that assertion.

https://www.bro.org/support/reporting-problems.html outlines the process on how to use gdb against a bro core file.

3

Thanks for the response. We do have a custom script running that chooses files to extract based on mime type. Here is the stack trace that I’m seeing. It’s always the same.

Regards

#0 0x00007ffb28a680d5 in raise () from /lib/x86_64-linux-gnu/libc.so.6

#1 0x00007ffb28a6b83b in abort () from /lib/x86_64-linux-gnu/libc.so.6

#2 0x00007ffb28a60d9e in ?? () from /lib/x86_64-linux-gnu/libc.so.6

#3 0x00007ffb28a60e42 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6

#4 0x0000000000852850 in Tag::AsEnumVal (this=0x7fff27c7a8e0, etype=0x246a700) at /home/mfry/dev/bro24/bro-2.4.1/src/Tag.cc:72

#5 0x0000000000b51b7b in file_analysis::Tag::AsEnumVal (this=0x7fff27c7a8e0) at /home/mfry/dev/bro24/bro-2.4.1/src/file_analysis/Tag.cc:23

#6 0x0000000000b4d95b in file_analysis::AnalyzerSet::GetKey (this=0xb74e850, t=…, args=0xff59ca0) at /home/mfry/dev/bro24/bro-2.4.1/src/file_analysis/AnalyzerSet.cc:155

#7 0x0000000000b4d7c7 in file_analysis::AnalyzerSet::QueueRemove (this=0xb74e850, tag=…, args=0xff59ca0) at /home/mfry/dev/bro24/bro-2.4.1/src/file_analysis/AnalyzerSet.cc:140

#8 0x0000000000b4b3c9 in file_analysis::File::DeliverStream (this=0xb74e820,

data=0xc02f4f0 “\217\020\272\214\355\361\301\272p\200\371\355\f\301\305\066\247Bj\216\027v\217^\303\t\221.6Fgrv\250\347Clcc\264\212\224\210\230!\336;\271Y\336!\355ɩ\210\332$]\b\217l\372[\240\362O\261K’\234b\v\376”, len=1460)

at /home/mfry/dev/bro24/bro-2.4.1/src/file_analysis/File.cc:405

#9 0x0000000000b4c995 in file_analysis::FileReassembler::BlockInserted (this=0x10a0e400, start_block=0x11637850) at /home/mfry/dev/bro24/bro-2.4.1/src/file_analysis/FileReassembler.cc:66

#10 0x0000000000b4cabd in file_analysis::FileReassembler::Undelivered (this=0x10a0e400, up_to_seq=70713344) at /home/mfry/dev/bro24/bro-2.4.1/src/file_analysis/FileReassembler.cc:96

#11 0x0000000000806342 in Reassembler::TrimToSeq (this=0x10a0e400, seq=70713344) at /home/mfry/dev/bro24/bro-2.4.1/src/Reassem.cc:101

#12 0x0000000000b4c879 in file_analysis::FileReassembler::Flush (this=0x10a0e400) at /home/mfry/dev/bro24/bro-2.4.1/src/file_analysis/FileReassembler.cc:33

#13 0x0000000000b4b533 in file_analysis::File::DeliverChunk (this=0xb74e820, data=0xf0b2870 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, len=1460, offset=1147283)

at /home/mfry/dev/bro24/bro-2.4.1/src/file_analysis/File.cc:421

#14 0x0000000000b4b9dc in file_analysis::File::DataIn (this=0xb74e820, data=0xf0b2870 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, len=1460, offset=1147283)

at /home/mfry/dev/bro24/bro-2.4.1/src/file_analysis/File.cc:481

#15 0x0000000000b45722 in file_analysis::Manager::DataIn (this=0x246a440, data=0xf0b2870 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, len=1460, offset=1147283, tag=…,

conn=0x10fb36f0, is_orig=false, precomputed_id=…) at /home/mfry/dev/bro24/bro-2.4.1/src/file_analysis/Manager.cc:121

#16 0x00000000009bea07 in analyzer::http::HTTP_Entity::SubmitData (this=0xa3eb330, len=1460, buf=0xf0b2870 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/http/HTTP.cc:322

#17 0x0000000000a2140b in analyzer::mime::MIME_Entity::FlushData (this=0xa3eb330) at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/mime/MIME.cc:1217

#18 0x0000000000a20a97 in analyzer::mime::MIME_Entity::DecodeDataLine (this=0xa3eb330, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”,

trailing_CRLF=0) at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/mime/MIME.cc:1013

#19 0x0000000000a1fe3c in analyzer::mime::MIME_Entity::NewDataLine (this=0xa3eb330, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, trailing_CRLF=0)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/mime/MIME.cc:698

#20 0x0000000000a1fbd3 in analyzer::mime::MIME_Entity::Deliver (this=0xa3eb330, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, trailing_CRLF=0)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/mime/MIME.cc:617

#21 0x00000000009be2cb in analyzer::http::HTTP_Entity::DeliverBodyClear (this=0xa3eb330, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”,

trailing_CRLF=0) at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/http/HTTP.cc:217

#22 0x00000000009be218 in analyzer::http::HTTP_Entity::DeliverBody (this=0xa3eb330, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, trailing_CRLF=0)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/http/HTTP.cc:205

#23 0x00000000009be086 in analyzer::http::HTTP_Entity::Deliver (this=0xa3eb330, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, trailing_CRLF=0)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/http/HTTP.cc:159

#24 0x0000000000a1fe1a in analyzer::mime::MIME_Entity::NewDataLine (this=0x12b37890, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, trailing_CRLF=0)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/mime/MIME.cc:693

#25 0x0000000000a1fbd3 in analyzer::mime::MIME_Entity::Deliver (this=0x12b37890, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, trailing_CRLF=0)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/mime/MIME.cc:617

#26 0x00000000009be2cb in analyzer::http::HTTP_Entity::DeliverBodyClear (this=0x12b37890, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”,

trailing_CRLF=0) at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/http/HTTP.cc:217

#27 0x00000000009be218 in analyzer::http::HTTP_Entity::DeliverBody (this=0x12b37890, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, trailing_CRLF=0)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/http/HTTP.cc:205

#28 0x00000000009bddfe in analyzer::http::HTTP_Entity::Deliver (this=0x12b37890, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, trailing_CRLF=0)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/http/HTTP.cc:107

#29 0x00000000009c43ea in analyzer::mime::MIME_Message::Deliver (this=0xbbf60b0, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, trailing_CRLF=0)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/mime/MIME.h:207

#30 0x00000000009c10e0 in analyzer::http::HTTP_Analyzer::DeliverStream (this=0xaba9ed0, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”,

is_orig=false) at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/http/HTTP.cc:908

#31 0x0000000000b74c0b in analyzer::SupportAnalyzer::ForwardStream (this=0x96e9790, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, is_orig=false)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/Analyzer.cc:835

#32 0x0000000000adcd94 in analyzer::tcp::ContentLine_Analyzer::DoDeliver (this=0x96e9790, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/tcp/ContentLine.cc:168

#33 0x0000000000adcb44 in analyzer::tcp::ContentLine_Analyzer::DeliverStream (this=0x96e9790, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”,

is_orig=false) at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/tcp/ContentLine.cc:108

#34 0x0000000000b72383 in analyzer::Analyzer::NextStream (this=0x96e9790, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, is_orig=false)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/Analyzer.cc:245

#35 0x0000000000b7235e in analyzer::Analyzer::NextStream (this=0xaba9ed0, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, is_orig=false)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/Analyzer.cc:239

#36 0x0000000000b72784 in analyzer::Analyzer::ForwardStream (this=0x77aa210, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”, is_orig=false)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/Analyzer.cc:331

#37 0x0000000000adb93f in analyzer::tcp::TCP_Reassembler::Deliver (this=0xd8f75b0, seq=6422408, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/tcp/TCP_Reassembler.cc:457

#38 0x0000000000adc279 in analyzer::tcp::TCP_Reassembler::DeliverBlock (this=0xd8f75b0, seq=6422408, len=1460, data=0xc15aab0 “\030\\240\357\224\017\001<\207\n8\212\322W\273\023\034C<}@\210\242\031\245\206f’\212\367\254\211\213\227c\303\326k\341\305,\333\034\226\355y”)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/tcp/TCP_Reassembler.cc:647

#39 0x0000000000adb599 in analyzer::tcp::TCP_Reassembler::BlockInserted (this=0xd8f75b0, start_block=0x117aba30) at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/tcp/TCP_Reassembler.cc:393

#40 0x0000000000806256 in Reassembler::NewBlock (this=0xd8f75b0, t=1459362263.205771, seq=6422408, len=1460, data=0x7ffb2bd72536 <Address 0x7ffb2bd72536 out of bounds>) at /home/mfry/dev/bro24/bro-2.4.1/src/Reassem.cc:73

#41 0x0000000000adba48 in analyzer::tcp::TCP_Reassembler::DataSent (this=0xd8f75b0, t=1459362263.205771, seq=6422408, len=1460, data=0x7ffb2bd72536 <Address 0x7ffb2bd72536 out of bounds>, replaying=true)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/tcp/TCP_Reassembler.cc:492

#42 0x0000000000ad9eb1 in analyzer::tcp::TCP_Endpoint::DataSent (this=0xbd1a7f0, t=1459362263.205771, seq=6422408, len=1460, caplen=1460, data=0x7ffb2bd72536 <Address 0x7ffb2bd72536 out of bounds>, ip=0x7fff27c7bd60, tp=0x7ffb2bd72522)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/tcp/TCP_Endpoint.cc:205

#43 0x0000000000ad4eac in analyzer::tcp::TCP_Analyzer::DeliverData (this=0x77aa210, t=1459362263.205771, data=0x7ffb2bd72536 <Address 0x7ffb2bd72536 out of bounds>, len=1460, caplen=1460, ip=0x7fff27c7bd60, tp=0x7ffb2bd72522, endpoint=0xbd1a7f0, rel_data_seq=6422408,

is_orig=0, flags=…) at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/tcp/TCP.cc:982

#44 0x0000000000ad5f82 in analyzer::tcp::TCP_Analyzer::DeliverPacket (this=0x77aa210, len=1460, data=0x7ffb2bd72536 <Address 0x7ffb2bd72536 out of bounds>, is_orig=false, seq=18446744073709551615, ip=0x7fff27c7bd60, caplen=1460)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/protocol/tcp/TCP.cc:1382

#45 0x0000000000b7229e in analyzer::Analyzer::NextPacket (this=0x77aa210, len=1480, data=0x7ffb2bd72522 <Address 0x7ffb2bd72522 out of bounds>, is_orig=false, seq=18446744073709551615, ip=0x7fff27c7bd60, caplen=1480)

at /home/mfry/dev/bro24/bro-2.4.1/src/analyzer/Analyzer.cc:222

#46 0x000000000076c0c9 in Connection::NextPacket (this=0x10fb36f0, t=1459362263.205771, is_orig=0, ip=0x7fff27c7bd60, len=1480, caplen=1480, data=@0x7fff27c7b9a0: 0x7ffb2bd72522 <Address 0x7ffb2bd72522 out of bounds>, record_packet=@0x7fff27c7ba10: 1,

record_content=@0x7fff27c7ba14: 1, hdr=0x48d3bb8, pkt=0x7ffb2bd72500 <Address 0x7ffb2bd72500 out of bounds>, hdr_size=14) at /home/mfry/dev/bro24/bro-2.4.1/src/Conn.cc:260

#47 0x0000000000837be5 in NetSessions::DoNextPacket (this=0x5f2db20, t=1459362263.205771, hdr=0x48d3bb8, ip_hdr=0x7fff27c7bd60, pkt=0x7ffb2bd72500 <Address 0x7ffb2bd72500 out of bounds>, hdr_size=14, encapsulation=0x0)

at /home/mfry/dev/bro24/bro-2.4.1/src/Sessions.cc:760

#48 0x00000000008361e9 in NetSessions::NextPacket (this=0x5f2db20, t=1459362263.205771, hdr=0x48d3bb8, pkt=0x7ffb2bd72500 <Address 0x7ffb2bd72500 out of bounds>, hdr_size=14) at /home/mfry/dev/bro24/bro-2.4.1/src/Sessions.cc:231

#49 0x0000000000835ff7 in NetSessions::DispatchPacket (this=0x5f2db20, t=1459362263.205771, hdr=0x48d3bb8, pkt=0x7ffb2bd72500 <Address 0x7ffb2bd72500 out of bounds>, hdr_size=14, src_ps=0x48d3a70) at /home/mfry/dev/bro24/bro-2.4.1/src/Sessions.cc:187

#50 0x00000000007f2082 in net_packet_dispatch (t=1459362263.205771, hdr=0x48d3bb8, pkt=0x7ffb2bd72500 <Address 0x7ffb2bd72500 out of bounds>, hdr_size=14, src_ps=0x48d3a70) at /home/mfry/dev/bro24/bro-2.4.1/src/Net.cc:281

#51 0x0000000000b33fc2 in iosource::PktSrc::Process (this=0x48d3a70) at /home/mfry/dev/bro24/bro-2.4.1/src/iosource/PktSrc.cc:456

#52 0x00000000007f2290 in net_run () at /home/mfry/dev/bro24/bro-2.4.1/src/Net.cc:329

#53 0x000000000074815e in main (argc=18, argv=0x7fff27c7c628) at /home/mfry/dev/bro24/bro-2.4.1/src/main.cc:1190

4

I’ve been able to narrow down the circumstances where we see this core dump. In the dozens of times that I’ve seen it, the file being extracted is always delivered over HTTP via the BITS client.

  • I have set an extract limit of 20MB.
  • The last messages that I see logged from a bro worker before it crashes indicates that my file_extraction_limit() event handler is called twice with the same FUID. I would expect this event to be fired only once.
  • I have confirmed by examining a backtrace of a core file that the crashed Bro worker was analyzing the very same FUID mentioned above at the time of the crash.
  • Below is log output from a recent occurrence. The file FBzliCXoEipv0oEM8 appears in the log under 4 different connections with the same IPs within a couple of seconds. Note that seen_bytes is just a fraction of the total_bytes. I have confirmed that file_state_remove() is fired 4 times for the same FUID.
  • Since this activity originated from 4 different connections, I would expect 4 different FUIDs.
  • In some cases, Bro handles extraction of similar files just fine, but only if the activity occurs on a single connection (its FUID is logged exactly once in files.log). In these cases, seen_bytes=total_bytes, and the file_extraction_limit() event is called only once, and thus no core dump.
  • My script has a file_state_remove() handler that forwards the extracted file for additional external analysis.

Here is an example that led to a crash. Note the same FUID is logged multiple times with different connection UIDs.

root@redacted:/opt/cbts/log/bro/2016-06-28# zgrep FBzliCXoEipv0oEM8 *
files.2016-06-28-18-00-00.log.dz:1467138209.682287 FBzliCXoEipv0oEM8 13.107.4.50 10.100.162.133 CapHn31QDgLbeGCqIh HTTP 0 EXTRACT,SHA1,MD5 application/zip Microsoft.Getstarted_3.11.1.0_neutral_~8wekyb3d8bbwe.AppxBundle 0.010122 F F 22610 8811168 0 0 F - 02af20e0f97904b4c9da2c5a0071c324 b09760ed7e7f64e389eb709abf97cbbc395cd22a - HTTP-FBzliCXoEipv0oEM8-Microsoft.Getstarted_3.11.1.0_neutral~8wekyb3d8bbwe.AppxBundle.file
files.2016-06-28-18-00-00.log.dz:1467138211.315952 FBzliCXoEipv0oEM8 13.107.4.50 10.100.162.133 CbGwtH2ajMS3nq8oR9 HTTP 0 MD5,SHA1,EXTRACT application/zip Microsoft.Getstarted_3.11.1.0_neutral~8wekyb3d8bbwe.AppxBundle 0.007328 F F 13850 8811168 0 0 F - 7d8f20dc6941d42cb735bfbb1f5dee1d dccb1e3e513ab377ee909823c538ba196140a6df - HTTP-FBzliCXoEipv0oEM8-Microsoft.Getstarted_3.11.1.0_neutral~8wekyb3d8bbwe.AppxBundle.file
files.2016-06-28-18-00-00.log.dz:1467138211.234745 FBzliCXoEipv0oEM8 13.107.4.50 10.100.162.133 ClZAlx4VvTPCGXWnGf HTTP 0 SHA1,EXTRACT,MD5 application/zip Microsoft.Getstarted_3.11.1.0_neutral~8wekyb3d8bbwe.AppxBundle 0.010127 F F 22610 8811168 0 0 F - 02af20e0f97904b4c9da2c5a0071c324 b09760ed7e7f64e389eb709abf97cbbc395cd22a - HTTP-FBzliCXoEipv0oEM8-Microsoft.Getstarted_3.11.1.0_neutral~8wekyb3d8bbwe.AppxBundle.file
files.2016-06-28-18-00-00.log.dz:1467138211.395275 FBzliCXoEipv0oEM8 13.107.4.50 10.100.162.133 C1PiIFx6hRC32DES9 HTTP 0 SHA1,MD5,EXTRACT application/zip Microsoft.Getstarted_3.11.1.0_neutral~8wekyb3d8bbwe.AppxBundle 0.008257 F F 16770 8811168 0 0 F - c6c39cc6b8a6773a8b4b416a919cfca6 0ae53083b1fc02d7710e9c2b12ad930990e73c8e - HTTP-FBzliCXoEipv0oEM8-Microsoft.Getstarted_3.11.1.0_neutral~_8wekyb3d8bbwe.AppxBundle.file
http.2016-06-28-18-00-00.log.dz:1467138209.662449 CapHn31QDgLbeGCqIh 10.100.162.133 61074 13.107.4.50 80 2 GET tlu.dl.delivery.mp.microsoft.com /filestreamingservice/files/9f5dbc38-f074-45be-8346-ca45b940a576?P1=1467138990&P2=301&P3=2&P4=M61a7Qj+Xwl55JKMXfAzkJPsnDstij/KQXct1zwrcGI= - Microsoft BITS/7.8 0 22610 200 OK - – (empty) - - - - - FBzliCXoEipv0oEM8 application/zip
http.2016-06-28-18-00-00.log.dz:1467138209.748598 CalgEr4pL03r1nZKql 10.100.162.133 61075 13.107.4.50 80 1 GET tlu.dl.delivery.mp.microsoft.com /filestreamingservice/files/9f5dbc38-f074-45be-8346-ca45b940a576?P1=1467138990&P2=301&P3=2&P4=M61a7Qj+Xwl55JKMXfAzkJPsnDstij/KQXct1zwrcGI= - Microsoft BITS/7.8 0 94880 206 Partial Content - - - (empty) - - - - - FBzliCXoEipv0oEM8 -
http.2016-06-28-18-00-00.log.dz:1467138211.295292 CbGwtH2ajMS3nq8oR9 10.100.162.133 61077 13.107.4.50 80 1 GET tlu.dl.delivery.mp.microsoft.com /filestreamingservice/files/9f5dbc38-f074-45be-8346-ca45b940a576?P1=1467138990&P2=301&P3=2&P4=M61a7Qj+Xwl55JKMXfAzkJPsnDstij/KQXct1zwrcGI= - Microsoft BITS/7.8 0 13850 200 OK - – (empty) - - - - - FBzliCXoEipv0oEM8 application/zip
http.2016-06-28-18-00-00.log.dz:1467138211.214133 ClZAlx4VvTPCGXWnGf 10.100.162.133 61076 13.107.4.50 80 1 GET tlu.dl.delivery.mp.microsoft.com /filestreamingservice/files/9f5dbc38-f074-45be-8346-ca45b940a576?P1=1467138990&P2=301&P3=2&P4=M61a7Qj+Xwl55JKMXfAzkJPsnDstij/KQXct1zwrcGI= - Microsoft BITS/7.8 0 22610 200 OK - – (empty) - - - - - FBzliCXoEipv0oEM8 application/zip
http.2016-06-28-18-00-00.log.dz:1467138211.373513 C1PiIFx6hRC32DES9 10.100.162.133 61078 13.107.4.50 80 1 GET tlu.dl.delivery.mp.microsoft.com /filestreamingservice/files/9f5dbc38-f074-45be-8346-ca45b940a576?P1=1467138990&P2=301&P3=2&P4=M61a7Qj+Xwl55JKMXfAzkJPsnDstij/KQXct1zwrcGI= - Microsoft BITS/7.8 0 16770 200 OK - – (empty) - - - - - FBzliCXoEipv0oEM8 application/zip

Removing my file_extraction_limit() handler seems to have eliminated the crash, but since the file_state_remove() event is fired multiple times for the same FUID, and the extracted filename is the same, the content of the extracted file is suspect.

Is this a known issue? We’re using the Bro 2.4.1 Debian package built for Ubuntu 12.04.

Regards,
Mike

5

Could you send the script that you are using which causes this problem?

  .Seth

6

Apologies for the delay. Below is the minimal script that will reproduce the core dump. As described earlier, files.log shows the same FUID with different connections multiple times. This causes the file_extraction_limit() to be called multiple times for the same file. Removing my event handler side-steps the core dump.

redef FileExtract::prefix = “/tmp/bro”;

Files of sizes outside this range will be discarded

global min_file_size: count = 1024;

global max_file_size: count = 5000000;

event bro_init()

{

mkdir(FileExtract::prefix);

}

event file_sniff(f: fa_file, meta: fa_metadata)

{

if (f$source != “HTTP”)

return;

Files::add_analyzer(f, Files::ANALYZER_EXTRACT, [$extract_limit=max_file_size]);

Files::add_analyzer(f, Files::ANALYZER_MD5);

}

event file_state_remove(f: fa_file)

{

if (f$info?$extracted)

{

print(fmt(“Deleting %s, size=%s”, f$info$extracted, f$seen_bytes));

system(fmt(“rm “/tmp/bro/%s””, str_shell_escape(f$info$extracted)));

}

}

event file_extraction_limit(f: fa_file , args: any , limit: count , len: count)

{

print “file_extraction_limit():”, f;

flush_all();

}

Here is an example that led to a crash. Note the same FUID is logged multiple times with different connection UIDs.

root@redacted:/opt/cbts/log/bro/2016-06-28# zgrep FBzliCXoEipv0oEM8 *
files.2016-06-28-18-00-00.log.dz:1467138209.682287 FBzliCXoEipv0oEM8 13.107.4.50 10.100.162.133 CapHn31QDgLbeGCqIh HTTP 0 EXTRACT,SHA1,MD5 application/zip Microsoft.Getstarted_3.11.1.0_neutral_~8wekyb3d8bbwe.AppxBundle 0.010122 F F 22610 8811168 0 0 F - 02af20e0f97904b4c9da2c5a0071c324 b09760ed7e7f64e389eb709abf97cbbc395cd22a - HTTP-FBzliCXoEipv0oEM8-Microsoft.Getstarted_3.11.1.0_neutral~8wekyb3d8bbwe.AppxBundle.file
files.2016-06-28-18-00-00.log.dz:1467138211.315952 FBzliCXoEipv0oEM8 13.107.4.50 10.100.162.133 CbGwtH2ajMS3nq8oR9 HTTP 0 MD5,SHA1,EXTRACT application/zip Microsoft.Getstarted_3.11.1.0_neutral~8wekyb3d8bbwe.AppxBundle 0.007328 F F 13850 8811168 0 0 F - 7d8f20dc6941d42cb735bfbb1f5dee1d dccb1e3e513ab377ee909823c538ba196140a6df - HTTP-FBzliCXoEipv0oEM8-Microsoft.Getstarted_3.11.1.0_neutral~8wekyb3d8bbwe.AppxBundle.file
files.2016-06-28-18-00-00.log.dz:1467138211.234745 FBzliCXoEipv0oEM8 13.107.4.50 10.100.162.133 ClZAlx4VvTPCGXWnGf HTTP 0 SHA1,EXTRACT,MD5 application/zip Microsoft.Getstarted_3.11.1.0_neutral~8wekyb3d8bbwe.AppxBundle 0.010127 F F 22610 8811168 0 0 F - 02af20e0f97904b4c9da2c5a0071c324 b09760ed7e7f64e389eb709abf97cbbc395cd22a - HTTP-FBzliCXoEipv0oEM8-Microsoft.Getstarted_3.11.1.0_neutral~8wekyb3d8bbwe.AppxBundle.file
files.2016-06-28-18-00-00.log.dz:1467138211.395275 FBzliCXoEipv0oEM8 13.107.4.50 10.100.162.133 C1PiIFx6hRC32DES9 HTTP 0 SHA1,MD5,EXTRACT application/zip Microsoft.Getstarted_3.11.1.0_neutral~8wekyb3d8bbwe.AppxBundle 0.008257 F F 16770 8811168 0 0 F - c6c39cc6b8a6773a8b4b416a919cfca6 0ae53083b1fc02d7710e9c2b12ad930990e73c8e - HTTP-FBzliCXoEipv0oEM8-Microsoft.Getstarted_3.11.1.0_neutral~_8wekyb3d8bbwe.AppxBundle.file
http.2016-06-28-18-00-00.log.dz:1467138209.662449 CapHn31QDgLbeGCqIh 10.100.162.133 61074 13.107.4.50 80 2 GET tlu.dl.delivery.mp.microsoft.com /filestreamingservice/files/9f5dbc38-f074-45be-8346-ca45b940a576?P1=1467138990&P2=301&P3=2&P4=M61a7Qj+Xwl55JKMXfAzkJPsnDstij/KQXct1zwrcGI= - Microsoft BITS/7.8 0 22610 200 OK - – (empty) - - - - - FBzliCXoEipv0oEM8 application/zip
http.2016-06-28-18-00-00.log.dz:1467138209.748598 CalgEr4pL03r1nZKql 10.100.162.133 61075 13.107.4.50 80 1 GET tlu.dl.delivery.mp.microsoft.com /filestreamingservice/files/9f5dbc38-f074-45be-8346-ca45b940a576?P1=1467138990&P2=301&P3=2&P4=M61a7Qj+Xwl55JKMXfAzkJPsnDstij/KQXct1zwrcGI= - Microsoft BITS/7.8 0 94880 206 Partial Content - - - (empty) - - - - - FBzliCXoEipv0oEM8 -
http.2016-06-28-18-00-00.log.dz:1467138211.295292 CbGwtH2ajMS3nq8oR9 10.100.162.133 61077 13.107.4.50 80 1 GET tlu.dl.delivery.mp.microsoft.com /filestreamingservice/files/9f5dbc38-f074-45be-8346-ca45b940a576?P1=1467138990&P2=301&P3=2&P4=M61a7Qj+Xwl55JKMXfAzkJPsnDstij/KQXct1zwrcGI= - Microsoft BITS/7.8 0 13850 200 OK - – (empty) - - - - - FBzliCXoEipv0oEM8 application/zip
http.2016-06-28-18-00-00.log.dz:1467138211.214133 ClZAlx4VvTPCGXWnGf 10.100.162.133 61076 13.107.4.50 80 1 GET tlu.dl.delivery.mp.microsoft.com /filestreamingservice/files/9f5dbc38-f074-45be-8346-ca45b940a576?P1=1467138990&P2=301&P3=2&P4=M61a7Qj+Xwl55JKMXfAzkJPsnDstij/KQXct1zwrcGI= - Microsoft BITS/7.8 0 22610 200 OK - – (empty) - - - - - FBzliCXoEipv0oEM8 application/zip
http.2016-06-28-18-00-00.log.dz:1467138211.373513 C1PiIFx6hRC32DES9 10.100.162.133 61078 13.107.4.50 80 1 GET tlu.dl.delivery.mp.microsoft.com /filestreamingservice/files/9f5dbc38-f074-45be-8346-ca45b940a576?P1=1467138990&P2=301&P3=2&P4=M61a7Qj+Xwl55JKMXfAzkJPsnDstij/KQXct1zwrcGI= - Microsoft BITS/7.8 0 16770 200 OK - – (empty) - - - - - FBzliCXoEipv0oEM8 application/zip

Thanks,
Mike