cleesmith / unifiedbeat

Unifiedbeat reads records from Unified2 binary files generated by network intrusion detection software and indexes the records in Elasticsearch.
MIT License
30 stars 14 forks source link

Out of memory error #9

Closed dajoen closed 8 years ago

dajoen commented 8 years ago

My snort.log file is only 6,8 Megabytes in size. Still getting out of memory errors. Is there a way to prevent those?

2016/06/09 11:24:08.717281 u2beat.go:123: INFO Setup: Rules warnings: 0 multiple line rules rejected, 9441 duplicate rules rejected 2016/06/09 11:24:08.717306 u2beat.go:124: INFO Setup: Rules stats: 122 rule files read, 8756 rules created 2016/06/09 11:24:08.717513 u2beat.go:140: INFO Setup: registrar: registry file: "/usr/lib/golang/src/github.com/cleesmith/unifiedbeat/.unifiedbeat" 2016/06/09 11:24:08.717534 u2beat.go:141: INFO Setup: registrar: file source: "/var/log/snort/snort.log" 2016/06/09 11:24:08.717546 u2beat.go:142: INFO Setup: registrar: file offset: 4828701 2016/06/09 11:24:08.717742 beat.go:267: INFO unifiedbeat sucessfully setup. Start running. 2016/06/09 11:24:08.717783 u2beat.go:148: INFO Run: start spooling and publishing... 2016/06/09 11:24:08.717795 u2spoolandpublish.go:52: INFO U2SpoolAndPublish: spooling and publishing... fatal error: runtime: out of memory

runtime stack: runtime.throw(0xb60390, 0x16) /usr/local/go/src/runtime/panic.go:547 +0x90 runtime.sysMap(0xc822800000, 0x3e5d0000, 0x0, 0x13c8818) /usr/local/go/src/runtime/mem_linux.go:206 +0x9b runtime.(_mheap).sysAlloc(0xe9a120, 0x3e5d0000, 0x17e479870) /usr/local/go/src/runtime/malloc.go:429 +0x191 runtime.(_mheap).grow(0xe9a120, 0x1f2e8, 0x0) /usr/local/go/src/runtime/mheap.go:651 +0x63 runtime.(_mheap).allocSpanLocked(0xe9a120, 0x1f2e3, 0xc820018dc0) /usr/local/go/src/runtime/mheap.go:553 +0x4f6 runtime.(_mheap).alloc_m(0xe9a120, 0x1f2e3, 0xffffff0100000000, 0x7f2e77e95dd0) /usr/local/go/src/runtime/mheap.go:437 +0x119 runtime.(_mheap).alloc.func1() /usr/local/go/src/runtime/mheap.go:502 +0x41 runtime.systemstack(0x7f2e77e95de8) /usr/local/go/src/runtime/asm_amd64.s:307 +0xab runtime.(_mheap).alloc(0xe9a120, 0x1f2e3, 0x10100000000, 0x41496c) /usr/local/go/src/runtime/mheap.go:503 +0x63 runtime.largeAlloc(0x3e5c5759, 0x7f2e00000001, 0x7f2e00000002) /usr/local/go/src/runtime/malloc.go:766 +0xb3 runtime.mallocgc.func3() /usr/local/go/src/runtime/malloc.go:664 +0x33 runtime.systemstack(0xc820018000) /usr/local/go/src/runtime/asm_amd64.s:291 +0x79 runtime.mstart() /usr/local/go/src/runtime/proc.go:1051

goroutine 19 [running]: runtime.systemstack_switch() /usr/local/go/src/runtime/asm_amd64.s:245 fp=0xc8211cb7d0 sp=0xc8211cb7c8 runtime.mallocgc(0x3e5c5759, 0x8ea100, 0x1, 0x0) /usr/local/go/src/runtime/malloc.go:665 +0x9eb fp=0xc8211cb8a8 sp=0xc8211cb7d0 runtime.newarray(0x8ea100, 0x3e5c5759, 0x13c6210) /usr/local/go/src/runtime/malloc.go:798 +0xc9 fp=0xc8211cb8e8 sp=0xc8211cb8a8 runtime.makeslice(0x8d3ae0, 0x3e5c5759, 0x3e5c5759, 0x0, 0x0, 0x0) /usr/local/go/src/runtime/slice.go:32 +0x165 fp=0xc8211cb938 sp=0xc8211cb8e8 github.com/cleesmith/unifiedbeat/vendor/github.com/cleesmith/go-unified2.ReadRawRecord(0x7f2e76e55c70, 0xc8200240f0, 0x0, 0x0, 0x0) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/cleesmith/go-unified2/unified2.go:149 +0x1fc fp=0xc8211cb9e8 sp=0xc8211cb938 github.com/cleesmith/unifiedbeat/vendor/github.com/cleesmith/go-unified2.ReadRecord(0x7f2e76e55c70, 0xc8200240f0, 0x0, 0x0, 0x0, 0x0) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/cleesmith/go-unified2/unified2.go:180 +0x4d fp=0xc8211cba48 sp=0xc8211cb9e8 github.com/cleesmith/unifiedbeat/vendor/github.com/cleesmith/go-unified2.(_RecordReader).Next(0xc8200240f8, 0x0, 0x0, 0x0, 0x0) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/cleesmith/go-unified2/recordreader.go:71 +0x5d fp=0xc8211cba90 sp=0xc8211cba48 github.com/cleesmith/unifiedbeat/vendor/github.com/cleesmith/go-unified2.(_SpoolRecordReader).Next(0xc8211cbcc0, 0x0, 0x0, 0x0, 0x0) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/cleesmith/go-unified2/spoolrecordreader.go:177 +0xab fp=0xc8211cbb70 sp=0xc8211cba90 github.com/cleesmith/unifiedbeat/beat.(_Unifiedbeat).U2SpoolAndPublish(0xc8200be0c0) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/beat/u2spoolandpublish.go:86 +0x244 fp=0xc8211cbd88 sp=0xc8211cbb70 github.com/cleesmith/unifiedbeat/beat.(_Unifiedbeat).Run(0xc8200be0c0, 0xc8211a2000, 0x0, 0x0) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/beat/u2beat.go:169 +0x6f fp=0xc8211cbe00 sp=0xc8211cbd88 github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/beat.(_Beat).Run(0xc8211a2000, 0x0, 0x0) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/beat/beat.go:271 +0x361 fp=0xc8211cbeb0 sp=0xc8211cbe00 github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/beat.(_Beat).Start(0xc8211a2000, 0x0, 0x0) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/beat/beat.go:174 +0x126 fp=0xc8211cbef8 sp=0xc8211cbeb0 github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/beat.Run.func1(0xc8211a2000) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/beat/beat.go:121 +0x42 fp=0xc8211cbf98 sp=0xc8211cbef8 runtime.goexit() /usr/local/go/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc8211cbfa0 sp=0xc8211cbf98 created by github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/beat.Run /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/beat/beat.go:133 +0x8d

goroutine 1 [chan receive]: github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/beat.Run(0xafb530, 0xb, 0xac74e8, 0x5, 0x7f2e7e48c000, 0xc8200be0c0, 0x0, 0x0) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/beat/beat.go:137 +0xc2 main.main() /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/main.go:40 +0xa9

goroutine 17 [syscall, locked to thread]: runtime.goexit() /usr/local/go/src/runtime/asm_amd64.s:1998 +0x1

goroutine 5 [syscall]: os/signal.signal_recv(0x0) /usr/local/go/src/runtime/sigqueue.go:116 +0x132 os/signal.loop() /usr/local/go/src/os/signal/signal_unix.go:22 +0x18 created by os/signal.init.1 /usr/local/go/src/os/signal/signal_unix.go:28 +0x37

goroutine 26 [chan receive]: github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/service.HandleSignals.func1(0xc822392f00, 0xc820cdcb20, 0xc820cdcb00) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/service/service.go:29 +0x3a created by github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/service.HandleSignals /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/service/service.go:32 +0x21e

goroutine 25 [select, locked to thread]: runtime.gopark(0xc0f868, 0xc82001d728, 0xad3348, 0x6, 0x18, 0x2) /usr/local/go/src/runtime/proc.go:262 +0x163 runtime.selectgoImpl(0xc82001d728, 0x0, 0x18) /usr/local/go/src/runtime/select.go:392 +0xa67 runtime.selectgo(0xc82001d728) /usr/local/go/src/runtime/select.go:215 +0x12 runtime.ensureSigM.func1() /usr/local/go/src/runtime/signal1_unix.go:279 +0x358 runtime.goexit() /usr/local/go/src/runtime/asm_amd64.s:1998 +0x1

goroutine 23 [select]: github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/publisher.(_messageWorker).run(0xc8211c2600) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/publisher/worker.go:61 +0x44a created by github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/publisher.(_messageWorker).init /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/publisher/worker.go:55 +0x11e

goroutine 24 [select]: github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/publisher.(*bulkWorker).run(0xc820050310) /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/publisher/bulk.go:58 +0x37d created by github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/publisher.newBulkWorker /usr/lib/golang/src/github.com/cleesmith/unifiedbeat/vendor/github.com/elastic/beats/libbeat/publisher/bulk.go:42 +0x223

cleesmith commented 8 years ago

I can not reproduce this on a Mac/osx or Ubuntu. Does it index any unified2 records into ElasticSearch, or just stop immediately ?

Can you provide more details like:

Did you compile it from source or use the binary release ? You said you were on CentOS, so I would try compiling it from source on that OS. Be sure you build it using Go 1.6, and see the supported goos and goarch.

dajoen commented 8 years ago

It does index unified2 records. The beat just seems to be resouce hungry on memory.

I'm running this on a CentOS 7 machine in Azure. It's an A2 VM with 2 cpu's and 3,5 GB memory.

[root@QAH-VM-MON01 unifiedbeat]# cat /proc/meminfo MemTotal: 3523796 kB MemFree: 405484 kB MemAvailable: 1078300 kB Buffers: 48040 kB Cached: 743376 kB SwapCached: 0 kB Active: 2356992 kB Inactive: 420132 kB Active(anon): 1999336 kB Inactive(anon): 34592 kB Active(file): 357656 kB Inactive(file): 385540 kB Unevictable: 0 kB Mlocked: 0 kB SwapTotal: 0 kB SwapFree: 0 kB Dirty: 1336 kB Writeback: 0 kB AnonPages: 1985804 kB Mapped: 57536 kB Shmem: 48220 kB Slab: 218408 kB SReclaimable: 183024 kB SUnreclaim: 35384 kB KernelStack: 9136 kB PageTables: 38772 kB NFS_Unstable: 0 kB Bounce: 0 kB WritebackTmp: 0 kB CommitLimit: 1761896 kB Committed_AS: 4004964 kB VmallocTotal: 34359738367 kB VmallocUsed: 56656 kB VmallocChunk: 34359679476 kB HardwareCorrupted: 0 kB AnonHugePages: 915456 kB HugePages_Total: 0 HugePages_Free: 0 HugePages_Rsvd: 0 HugePages_Surp: 0 Hugepagesize: 2048 kB DirectMap4k: 67520 kB DirectMap2M: 3602432 kB

I did compile it from source. Using latest golang version. The binary release was even quicker in running out of memory.

Goos and goarch seem te be correct.

file unifiedbeat

unifiedbeat: ELF 64-bit LSB executable, x86-64, version 1 (SYSV), dynamically linked (uses shared libs), not stripped

Even with 1,1 GB of free memory, the beat runs out of memory.

cleesmith commented 8 years ago

After you run it, can you provide these files:

cleesmith commented 8 years ago

I performed a test using a Security Onion (Ubuntu 14.04, I think) sensor with ElasticSearch on another server (also Ubuntu) with the typical maximum sized Snort unified2 log file (128Mb before it rolls over to a new file) ...

sudo rm .unifiedbeat ... so it doesn't resume where it left off last time
sudo ./unifiedbeat -c unifiedbeat.yml

After about 8 minutes, it takes a while to index a 128M unified2 file ... typically you would not be doing this except for the first time you run unifiedbeat as after that it stays in sync with snort/suricata's log files ... in order to provide near real-time events in ElasticSearch:

ls -la /nsm/sensor_data/seconion-eth1/snort-1
-rw------- 1 sguil sguil 134215552 Jun 11 14:16 indexed_1465655244.snort.unified2.1465650596
-rw------- 1 sguil sguil   8442450 Jun 11 14:33 snort.unified2.1465654580

cat /var/log/unifiedbeat/unifiedbeat
. . .
2016-06-11T14:19:30Z INFO U2SpoolAndPublish: spooling and publishing...
2016-06-11T14:27:24Z INFO Indexed file: '/nsm/sensor_data/seconion-eth1/snort-1/snort.unified2.1465650596' renamed: '/nsm/sensor_data/seconion-eth1/snort-1/indexed_1465655244.snort.unified2.1465650596'
. . .
i.e. it renames the processed unified2 log file and proceeds to the latest/newest/next file

Watching memory while running unifiedbeat shows it never uses more than 300MB or so:

ps aux | grep unifiedbeat
root     13878  0.0  0.0  92888  4916 pts/3    S+   14:19   0:00 sudo ./unifiedbeat -c unifiedbeat.yml
root     13879 11.1  3.0 295760 249724 pts/3   Sl+  14:19   1:41 ./unifiedbeat -c unifiedbeat.yml

or:

cat /proc/13879/status
. . .
VmPeak:   295760 kB
. . .

The most memory that unifiedbeat is holding will be for loading the GeoIP2 database into memory, as the unified2 records are read and processed in small batches (i.e. bulk_max_size). So while running it does not use very much memory.

Perhaps your memory issue is from another process on your server ... are you running ElasticSearch on the same server as unifiedbeat ? The Beats are intended as lightweight shippers to ElasticSearch or more commonly to LogStash servers and then to ElasticSearch. Unifiedbeat is intended to be used as near real-time shipper directly to a remote ElasticSearch server. After all, you wouldn't want to bog down your Snort/Suricata sensor server with a heavy process like ElasticSearch, as you may drop important security events.

I am closing this issue as I am unable to reproduce your out of memory exception.