Filebeat panic and exit?

Hello, I got the following from stderr while running filebeat, and filebeat just exited.
any idea on why filebeat just dies?

goroutine 74 [select, 1 minutes]:*subOutlet).OnEvent(0xc00030f830, 0xc6ba485ad0, 0xbf528e77afb98100)
/go/src/ +0x1d9*Forwarder).Send(0xc0001d3dc8, 0xc6ba485ad0, 0x0, 0x0)
/go/src/ +0x41*Harvester).sendEvent(0xc00019d900, 0xc6ba485ad0, 0xc0001d3dc8, 0x7)
/go/src/ +0x77*Harvester).Run(0xc00019d900, 0x0, 0x0)
/go/src/ +0x4a2*Registry).Start.func1(0xc000086c80, 0x1cc1760, 0xc00019d900)
/go/src/ +0x73
created by*Registry).Start
/go/src/ +0x128

Hi @filebeater,

Thanks for reporting this. What version of filebeat are you using? Could you share your configuration?

it is filebeat version 7.2 & 7.3.1. config file is copied below:

registry.flush: 1
  events: 524288
  flush.min_events: 262144
  flush.timeout: 1s

filebeat.max_procs: 3

- type: log
    - logs/reader-logs/*

  close_removed: true
  clean_removed: true
  symlinks: true

  multiline.pattern: '^[[:digit:]]{4,}[[:punct:]][[:digit:]]{2,}|^[I|W|E|F|D|T][[:digit:]]{4,}'
  multiline.negate: true
  multiline.match: after

   hosts: [""]
   topic: 'graph-log'
     hash: ['beat.hostname', 'source']
     random: true # if false non-hashable events will be dropped

   required_acks: 1
   compression: gzip
   max_message_bytes: 1000000
   ssl.certificate_authorities: ["/etc/riddler/ca-bundle.crt"]
   ssl.certificate: "/export/home../secure/identity.cert"
   ssl.key: "/export/home../secure/identity.key"
  bulk_max_size: 262144
  worker: 1
  client_id: in-beat-lor1-app042833
  channel_buffer_size: 26222400

@filebeater thanks, I have edit your last comment to reformat the configuration, you can use the preformatted text option (</>) from the toolbar to format configuration and logs next time.

Regarding the logs, could you paste the whole logs? The ones you posted don't seem to contain the original error.

I found out it is due to "run out of the memory", Here are the logs:

fatal error: runtime: out of memory

runtime stack:

runtime.throw(0x1ae16ae, 0x16)

/usr/local/go/src/runtime/panic.go:617 +0x72

runtime.sysMap(0xe988000000, 0x4000000, 0x2bece38)

/usr/local/go/src/runtime/mem_linux.go:170 +0xc7

runtime.(*mheap).sysAlloc(0x2bd38c0, 0xa2000, 0x2bd38d0, 0x51)

/usr/local/go/src/runtime/malloc.go:633 +0x1cd

runtime.(*mheap).grow(0x2bd38c0, 0x51, 0x0)

/usr/local/go/src/runtime/mheap.go:1232 +0x42

runtime.(*mheap).allocSpanLocked(0x2bd38c0, 0x51, 0x2bece48, 0x2bd38d0)

/usr/local/go/src/runtime/mheap.go:1150 +0x3a7

runtime.(*mheap).alloc_m(0x2bd38c0, 0x51, 0x7f868d5a0100, 0x7f868d5aaa88)

/usr/local/go/src/runtime/mheap.go:977 +0xc2


/usr/local/go/src/runtime/mheap.go:1048 +0x4c

runtime.(*mheap).alloc(0x2bd38c0, 0x51, 0x7f87d3010100, 0xc3c5adc300)

/usr/local/go/src/runtime/mheap.go:1047 +0x8a

runtime.largeAlloc(0xa0510, 0xc406a10001, 0x1)

/usr/local/go/src/runtime/malloc.go:1055 +0x99


/usr/local/go/src/runtime/malloc.go:950 +0x46


/usr/local/go/src/runtime/asm_amd64.s:351 +0x66



goroutine 580 [running]:


/usr/local/go/src/runtime/asm_amd64.s:311 fp=0xc0038c56f8 sp=0xc0038c56f0 pc=0xb16040

runtime.mallocgc(0xa0510, 0x1989580, 0xe97ee4f701, 0x0)

/usr/local/go/src/runtime/malloc.go:949 +0x872 fp=0xc0038c5798 sp=0xc0038c56f8 pc=0xac7052

runtime.newobject(0x1989580, 0xc0038c5800)

/usr/local/go/src/runtime/malloc.go:1068 +0x38 fp=0xc0038c57c8 sp=0xc0038c5798 pc=0xac7358

compress/flate.NewWriter(0x1c9ff80, 0xe986d365d0, 0x4, 0xa, 0xa, 0x0)

/usr/local/go/src/compress/flate/deflate.go:667 +0x31 fp=0xc0038c5810 sp=0xc0038c57c8 pc=0xe3fe01

compress/gzip.(*Writer).Write(0xe987900d10, 0xe98746aa80, 0xa67, 0xa67, 0x0, 0x0, 0x14acc34)

/usr/local/go/src/compress/gzip/gzip.go:191 +0x2f7 fp=0xc0038c5860 sp=0xc0038c5810 pc=0xe4a247, 0x4, 0xe98746aa80, 0xa67, 0xa67, 0x0, 0x0, 0x0, 0x0, 0x0)

/go/src/ +0x1e6 fp=0xc0038c5910 sp=0xc0038c5860 pc=0x14a1376*RecordBatch).encodeRecords(0xe97c24bb80, 0x1cea400, 0xe981955f20, 0x0, 0x0)

/go/src/ +0xf1 fp=0xc0038c5980 sp=0xc0038c5910 pc=0x14c6711*RecordBatch).encode(0xe97c24bb80, 0x1cea400, 0xe981955f20, 0x193fb20, 0xe97df19c50)

/go/src/ +0x374 fp=0xc0038c59e8 sp=0xc0038c5980 pc=0x14c5c64*Records).encode(0xc0038c5b10, 0x1cea400, 0xe981955f20, 0x0, 0x0)

/go/src/ +0xc4 fp=0xc0038c5a50 sp=0xc0038c59e8 pc=0x14c69a4*ProduceRequest).encode(0xe981955ee0, 0x1cea400, 0xe981955f20, 0x0, 0x0)

/go/src/ +0x2a4 fp=0xc0038c5bf8 sp=0xc0038c5a50 pc=0x14be444*request).encode(0xe986d365a0, 0x1cea400, 0xe981955f20, 0xe97f310d20, 0xf0)

/go/src/ +0x13c fp=0xc0038c5c30 sp=0xc0038c5bf8 pc=0x14c75cc, 0xe986d365a0, 0x1cdd0c0, 0xc0002a21b0, 0x0, 0xb, 0x0, 0x0, 0xc0038c5d01)

/go/src/ +0x90 fp=0xc0038c5ca8 sp=0xc0038c5c30 pc=0x14acaa0*Broker).send(0xc002d81080, 0x1cd2260, 0xe981955ee0, 0xe981955f01, 0x0, 0x0, 0x0)

/go/src/ +0x26b fp=0xc0038c5e00 sp=0xc0038c5ca8 pc=0x149829b*Broker).sendAndReceive(0xc002d81080, 0x1cd2260, 0xe981955ee0, 0x1ca1000, 0xe981955f00, 0x2000107, 0x0)

/go/src/ +0x72 fp=0xc0038c5ee8 sp=0xc0038c5e00 pc=0x14987c2*Broker).Produce(0xc002d81080, 0xe981955ee0, 0xe979057601, 0x0, 0x0)

/go/src/ +0xe8 fp=0xc0038c5f38 sp=0xc0038c5ee8 pc=0x1496bb8*asyncProducer).newBrokerProducer.func1()

/go/src/ +0xb1 fp=0xc0038c5fb8 sp=0xc0038c5f38 pc=0x14cbe71

/go/src/ +0x43 fp=0xc0038c5fd8 sp=0xc0038c5fb8 pc=0x14ca863


/usr/local/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0038c5fe0 sp=0xc0038c5fd8 pc=0xb18111

created by*asyncProducer).newBrokerProducer

/go/src/ +0x1f6

One thing We find really surprising is that: filebeat consumed much more memory than expected:
we set "channel_buffer_size: 26222400" and we have 512 kafka partitions, which is ~13G in total,
however, it consumes up to 91G runtime: It quickly ramped up to using 91G of memory in a couple of minutes after filebeat restarted. BEATSVERSION=7.3.1 GOVERSION=1.12.9.
hmm, looking up filebeat documentation again, I am confused whether channel_buffer_size is per kafka partition or per kafka broker. If it was per kafka broker, it makes even less sense now, since filoebeat is only connected to "45" kafka brokers per filebeat log:

2019-09-04T20:52:15.672Z INFO kafka/log.go:53 client/brokers registered new broker #38457 at [hostname:port]

an earlier version of filebeat and GO (BEATSVERSION=6.1.3. GOVERSION=1.8.3) consumes up to 43G of memory, still much more than what we expected, but much less than a newer version of filebeat/go). Disclaimer: we did not have chance to verify whether the upgrade is due to GO version upgrade or Filebeat version upgrade or a combo of both.

Timestamp, VSZ, RSS, %MEM

2019/09/03 17:44:37 420912 17424 0.01
2019/09/03 17:44:57 422476 17680 0.01
2019/09/03 17:45:17 83626024 6637376 2.52
2019/09/03 17:45:37 139713048 22859348 8.67
2019/09/03 17:45:57 148985864 39280920 14.90
2019/09/03 17:46:17  172069584 57875380  21.96
2019/09/03 17:46:37 194879332 75969164 28.82
2019/09/03 17:46:57 210748936 91502184 34.72

@filebeater could you upload a memory profile?

You can enable profiling adding the -httpprof localhost:6060 flag to filebeat, and get a memory profile downloading http://localhost:6060/debug/pprof/heap.

1 Like

btw, the above memory usage is observed in our production running. Since that incident, we have since rolled back the filebeat from 7.3 to 6.1.3, we have not observed in production since.
This is not readily repro in our experiment setup, i will keep an eye on this..
On a related note, this is from our experiment: filebeat existed right after start, complaining about:
out of memory: cannot allocate 209715200-byte block (9326067712 in use)
fatal error: out of memory

filebeat-7.2/filebeat -c filebeat-7.2/filebeat.yml ./data -path.logs ./logs
runtime: out of memory: cannot allocate 209715200-byte block (9326067712 in use)
fatal error: out of memory

runtime stack:
runtime.throw(0x1ad4851, 0xd)
	/usr/local/go/src/runtime/panic.go:617 +0x72
runtime.largeAlloc(0xc800000, 0x7f5700000001, 0xc0004a6c00)
	/usr/local/go/src/runtime/malloc.go:1057 +0x16b
	/usr/local/go/src/runtime/malloc.go:950 +0x46
	/usr/local/go/src/runtime/asm_amd64.s:351 +0x66

goroutine 113 [running]:
	/usr/local/go/src/runtime/asm_amd64.s:311 fp=0xc0043b7da0 sp=0xc0043b7d98 pc=0xb16040
runtime.mallocgc(0xc800000, 0x1929d20, 0x1, 0xc1193f1ee8)
	/usr/local/go/src/runtime/malloc.go:949 +0x872 fp=0xc0043b7e40 sp=0xc0043b7da0 pc=0xac7052
runtime.makechan(0x189d3c0, 0x1900000, 0xc000000200)
	/usr/local/go/src/runtime/chan.go:106 +0x156 fp=0xc0043b7e88 sp=0xc0043b7e40 pc=0xabfd36*asyncProducer).newPartitionProducer(0xc0002850a0, 0xc00013cfe0, 0x9, 0x1d2, 0xc01bfd6ea0)
	/go/src/ +0x46 fp=0xc0043b7ee0 sp=0xc0043b7e88 pc=0x1490e36*topicProducer).dispatch(0xc008093380)
	/go/src/ +0x135 fp=0xc0043b7fa0 sp=0xc0043b7ee0 pc=0x1490a35*topicProducer).dispatch-fm()
	/go/src/ +0x2a fp=0xc0043b7fb8 sp=0xc0043b7fa0 pc=0x14d360a
	/go/src/ +0x43 fp=0xc0043b7fd8 sp=0xc0043b7fb8 pc=0x14ca863
	/usr/local/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0043b7fe0 sp=0xc0043b7fd8 pc=0xb18111
created by*asyncProducer).newTopicProducer
	/go/src/ +0x1ab

goroutine 1 [chan receive]:*signalWait).Wait(...)
	/go/src/*Filebeat).Run(0xc0003e4320, 0xc00046bd40, 0x0, 0x0)
	/go/src/ +0xe9e*Beat).launch(0xc00046bd40, 0x1ace7c0, 0x8, 0x1ace7c0, 0x8, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/ +0x61d, 0x8, 0x1ace7c0, 0x8, 0x0, 0x0, 0x1ace7c0, 0x8, 0x1ace7c0, 0x8, ...)
	/go/src/ +0x51d, 0x8, 0x1ace7c0, 0x8, 0x0, 0x0, 0x0, 0x0, 0x0, 0xc000464000, ...)
	/go/src/ +0xbe, 0xc00045c100, 0x0, 0x8)
	/go/src/ +0x9a*Command).execute(0xc000462280, 0xc00003c0a0, 0x8, 0x8, 0xc000462280, 0xc00003c0a0)
	/go/src/ +0x289*Command).ExecuteC(0xc000462280, 0x1784259, 0xc0004e1f88, 0xc0000a2058)
	/go/src/ +0x2ca*Command).Execute(...)
	/go/src/ +0x30

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.