Filebeat doesn't start any harvesters

Elastic Stack Beats
1

hi, all

Debian 10, Filebeat 7.12,

filebeat.yml

logging.level: info
logging.to_files: true
logging.files:
  path: /var/log/filebeat
  name: filebeat
  keepfiles: 2
  permissions: 0644
filebeat.inputs:
  - type: log
    enabled: true
    clean_inactive: 720h
    ignore_older: 6h
    close_inactive: 30m
    harvester_limit: 10000
    paths:
      - /var/www/casafari/web/storage/logs/central_app_errors*
      - /var/www/casafari/web/storage/parsed/*/*/*/*/logstash.log
      - /var/www/casafari/web/storage/sandbox_processing/*/logstash.log
      - /var/www/casafari/web/storage/logs/load_photos.log
      - /var/www/casafari/web/storage/source_fast_processing/*/logstash.log
      - /var/www/casafari/web/storage/source_fast_processing/*/processor_logstash.log
output.logstash:
  enabled: true
  hosts: ["10.32.20.33:5043"]

After systemctl restart filebeat - no harvesters started, in log file i see only metrics.

root@parserx001:/etc/filebeat# tail -f /var/log/filebeat/filebeat
2021-04-02T13:13:04.071+0200	INFO	[monitoring]	log/log.go:144	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cgroup":{"memory":{"mem":{"usage":{"bytes":-3424256}}}},"cpu":{"system":{"ticks":65620,"time":{"ms":4255}},"total":{"ticks":447580,"time":{"ms":29549},"value":447580},"user":{"ticks":381960,"time":{"ms":25294}}},"handles":{"limit":{"hard":100000,"soft":100000},"open":12},"info":{"ephemeral_id":"995e16d1-97fd-41a3-8d00-6eaf94bcb15f","uptime":{"ms":450084}},"memstats":{"gc_next":72848160,"memory_alloc":40757624,"memory_total":29928768256,"rss":165888000},"runtime":{"goroutines":20}},"filebeat":{"events":{"added":50,"done":50},"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"active":0}},"pipeline":{"clients":1,"events":{"active":1,"filtered":50,"total":50}}},"registrar":{"states":{"current":13117,"update":50},"writes":{"success":50,"total":50}},"system":{"load":{"1":30.67,"15":17.66,"5":14.44,"norm":{"1":0.3195,"15":0.184,"5":0.1504}}}}}}
2021-04-02T13:13:34.071+0200	INFO	[monitoring]	log/log.go:144	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cgroup":{"memory":{"mem":{"usage":{"bytes":-5472256}}}},"cpu":{"system":{"ticks":69600,"time":{"ms":3981}},"total":{"ticks":474650,"time":{"ms":27071},"value":474650},"user":{"ticks":405050,"time":{"ms":23090}}},"handles":{"limit":{"hard":100000,"soft":100000},"open":11},"info":{"ephemeral_id":"995e16d1-97fd-41a3-8d00-6eaf94bcb15f","uptime":{"ms":480088}},"memstats":{"gc_next":72859472,"memory_alloc":39626840,"memory_total":31919098032,"rss":165945344},"runtime":{"goroutines":20}},"filebeat":{"events":{"added":47,"done":47},"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"active":0}},"pipeline":{"clients":1,"events":{"active":1,"filtered":47,"total":47}}},"registrar":{"states":{"current":13117,"update":47},"writes":{"success":47,"total":47}},"system":{"load":{"1":30.83,"15":18.22,"5":16.38,"norm":{"1":0.3211,"15":0.1898,"5":0.1706}}}}}}
2021-04-02T13:14:04.071+0200	INFO	[monitoring]	log/log.go:144	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cgroup":{"memory":{"mem":{"usage":{"bytes":-1343488}}}},"cpu":{"system":{"ticks":73650,"time":{"ms":4052}},"total":{"ticks":503150,"time":{"ms":28505},"value":503150},"user":{"ticks":429500,"time":{"ms":24453}}},"handles":{"limit":{"hard":100000,"soft":100000},"open":11},"info":{"ephemeral_id":"995e16d1-97fd-41a3-8d00-6eaf94bcb15f","uptime":{"ms":510086}},"memstats":{"gc_next":72110240,"memory_alloc":61973640,"memory_total":33958928008,"rss":165969920},"runtime":{"goroutines":20}},"filebeat":{"events":{"added":49,"done":49},"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"active":0}},"pipeline":{"clients":1,"events":{"active":1,"filtered":49,"total":49}}},"registrar":{"states":{"current":13117,"update":49},"writes":{"success":49,"total":49}},"system":{"load":{"1":20.35,"15":17.78,"5":15.21,"norm":{"1":0.212,"15":0.1852,"5":0.1584}}}}}}
2021-04-02T13:14:34.070+0200	INFO	[monitoring]	log/log.go:144	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cgroup":{"memory":{"mem":{"usage":{"bytes":-1155072}}}},"cpu":{"system":{"ticks":77590,"time":{"ms":3936}},"total":{"ticks":527940,"time":{"ms":24790},"value":527940},"user":{"ticks":450350,"time":{"ms":20854}}},"handles":{"limit":{"hard":100000,"soft":100000},"open":11},"info":{"ephemeral_id":"995e16d1-97fd-41a3-8d00-6eaf94bcb15f","uptime":{"ms":540084}},"memstats":{"gc_next":73285248,"memory_alloc":65147784,"memory_total":35885802408,"rss":166035456},"runtime":{"goroutines":20}},"filebeat":{"events":{"added":45,"done":45},"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"active":0}},"pipeline":{"clients":1,"events":{"active":1,"filtered":45,"total":45}}},"registrar":{"states":{"current":13117,"update":45},"writes":{"success":45,"total":45}},"system":{"load":{"1":14.36,"15":17.38,"5":14.27,"norm":{"1":0.1496,"15":0.181,"5":0.1486}}}}}}
2021-04-02T13:15:04.071+0200	INFO	[monitoring]	log/log.go:144	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cgroup":{"memory":{"mem":{"usage":{"bytes":9703424}}}},"cpu":{"system":{"ticks":81810,"time":{"ms":4225}},"total":{"ticks":557370,"time":{"ms":29435},"value":557370},"user":{"ticks":475560,"time":{"ms":25210}}},"handles":{"limit":{"hard":100000,"soft":100000},"open":12},"info":{"ephemeral_id":"995e16d1-97fd-41a3-8d00-6eaf94bcb15f","uptime":{"ms":570087}},"memstats":{"gc_next":71657792,"memory_alloc":66050792,"memory_total":38011936328,"rss":166039552},"runtime":{"goroutines":20}},"filebeat":{"events":{"added":50,"done":50},"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"active":0}},"pipeline":{"clients":1,"events":{"active":1,"filtered":50,"total":50}}},"registrar":{"states":{"current":13117,"update":50},"writes":{"success":50,"total":50}},"system":{"load":{"1":9.63,"15":16.9,"5":13.13,"norm":{"1":0.1003,"15":0.176,"5":0.1368}}}}}}
2021-04-02T13:15:34.071+0200	INFO	[monitoring]	log/log.go:144	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cgroup":{"memory":{"mem":{"usage":{"bytes":2244608}}}},"cpu":{"system":{"ticks":85910,"time":{"ms":4099}},"total":{"ticks":585820,"time":{"ms":28444},"value":585820},"user":{"ticks":499910,"time":{"ms":24345}}},"handles":{"limit":{"hard":100000,"soft":100000},"open":12},"info":{"ephemeral_id":"995e16d1-97fd-41a3-8d00-6eaf94bcb15f","uptime":{"ms":600084}},"memstats":{"gc_next":72188672,"memory_alloc":55657992,"memory_total":40057594976,"rss":166039552},"runtime":{"goroutines":20}},"filebeat":{"events":{"added":49,"done":49},"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"active":0}},"pipeline":{"clients":1,"events":{"active":1,"filtered":49,"total":49}}},"registrar":{"states":{"current":13117,"update":49},"writes":{"success":49,"total":49}},"system":{"load":{"1":7.87,"15":16.55,"5":12.42,"norm":{"1":0.082,"15":0.1724,"5":0.1294}}}}}}
2021-04-02T13:16:04.072+0200	INFO	[monitoring]	log/log.go:144	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cgroup":{"memory":{"mem":{"usage":{"bytes":-2981888}}}},"cpu":{"system":{"ticks":90650,"time":{"ms":4740}},"total":{"ticks":616790,"time":{"ms":30972},"value":616790},"user":{"ticks":526140,"time":{"ms":26232}}},"handles":{"limit":{"hard":100000,"soft":100000},"open":12},"info":{"ephemeral_id":"995e16d1-97fd-41a3-8d00-6eaf94bcb15f","uptime":{"ms":630084}},"memstats":{"gc_next":71499088,"memory_alloc":66643968,"memory_total":42199706928,"rss":166064128},"runtime":{"goroutines":20}},"filebeat":{"events":{"added":51,"done":51},"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"active":0}},"pipeline":{"clients":1,"events":{"active":1,"filtered":51,"total":51}}},"registrar":{"states":{"current":13117,"update":51},"writes":{"success":51,"total":51}},"system":{"load":{"1":5.76,"15":16.1,"5":11.47,"norm":{"1":0.06,"15":0.1677,"5":0.1195}}}}}}
2021-04-02T13:16:34.072+0200	INFO	[monitoring]	log/log.go:144	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cgroup":{"memory":{"mem":{"usage":{"bytes":-4673536}}}},"cpu":{"system":{"ticks":94420,"time":{"ms":3774}},"total":{"ticks":644410,"time":{"ms":27622},"value":644410},"user":{"ticks":549990,"time":{"ms":23848}}},"handles":{"limit":{"hard":100000,"soft":100000},"open":11},"info":{"ephemeral_id":"995e16d1-97fd-41a3-8d00-6eaf94bcb15f","uptime":{"ms":660085}},"memstats":{"gc_next":73550192,"memory_alloc":38463656,"memory_total":44090758816,"rss":166064128},"runtime":{"goroutines":20}},"filebeat":{"events":{"added":44,"done":44},"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"active":0}},"pipeline":{"clients":1,"events":{"active":1,"filtered":44,"total":44}}},"registrar":{"states":{"current":13117,"update":44},"writes":{"success":44,"total":44}},"system":{"load":{"1":6.32,"15":15.84,"5":11.12,"norm":{"1":0.0658,"15":0.165,"5":0.1158}}}}}}
2021-04-02T13:17:04.079+0200	INFO	[monitoring]	log/log.go:144	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cgroup":{"memory":{"mem":{"usage":{"bytes":-520192}}}},"cpu":{"system":{"ticks":98720,"time":{"ms":4294}},"total":{"ticks":672440,"time":{"ms":28030},"value":672440},"user":{"ticks":573720,"time":{"ms":23736}}},"handles":{"limit":{"hard":100000,"soft":100000},"open":11},"info":{"ephemeral_id":"995e16d1-97fd-41a3-8d00-6eaf94bcb15f","uptime":{"ms":690087}},"memstats":{"gc_next":71491296,"memory_alloc":69022576,"memory_sys":262144,"memory_total":46147781224,"rss":166080512},"runtime":{"goroutines":20}},"filebeat":{"events":{"added":49,"done":49},"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"active":0}},"pipeline":{"clients":1,"events":{"active":1,"filtered":49,"total":49}}},"registrar":{"states":{"current":13117,"update":49},"writes":{"success":49,"total":49}},"system":{"load":{"1":5.03,"15":15.43,"5":10.35,"norm":{"1":0.0524,"15":0.1607,"5":0.1078}}}}}}
2021-04-02T13:17:34.071+0200	INFO	[monitoring]	log/log.go:144	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cgroup":{"memory":{"mem":{"usage":{"bytes":-1802240}}}},"cpu":{"system":{"ticks":102920,"time":{"ms":4200}},"total":{"ticks":700390,"time":{"ms":27945},"value":700390},"user":{"ticks":597470,"time":{"ms":23745}}},"handles":{"limit":{"hard":100000,"soft":100000},"open":11},"info":{"ephemeral_id":"995e16d1-97fd-41a3-8d00-6eaf94bcb15f","uptime":{"ms":720087}},"memstats":{"gc_next":71943264,"memory_alloc":62386160,"memory_total":48167739152,"rss":166080512},"runtime":{"goroutines":20}},"filebeat":{"events":{"added":48,"done":48},"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"active":0}},"pipeline":{"clients":1,"events":{"active":1,"filtered":48,"total":48}}},"registrar":{"states":{"current":13117,"update":48},"writes":{"success":48,"total":48}},"system":{"load":{"1":7.32,"15":15.34,"5":10.54,"norm":{"1":0.0763,"15":0.1598,"5":0.1098}}}}}}

Sometimes - i do restart again and see in log something like Harvester started.
My question is when does filebeat start harvesting, what internal locks can block harvesters from starting, i didn't find any related debug in log even with logging.level = debug.

1 Like
2

More debug info. Filebeat is running more than 2 days, but it doen't open log files.

root@parserx004:~# ps aux | grep fileb
root     13277  0.0  0.0   6076   828 pts/0    S+   14:33   0:00 grep fileb
root     14974 39.7  0.6 4027592 452600 ?      Ssl  Apr01 1736:22 /usr/share/filebeat/bin/filebeat --environment systemd -c /etc/filebeat/filebeat.yml --path.home /usr/share/filebeat --path.config /etc/filebeat --path.data /var/lib/filebeat --path.logs /var/log/filebeat
root@parserx004:~#
root@parserx004:~# la -la /proc/14974/fd
-bash: la: command not found
root@parserx004:~# ls -l /proc/14974/fd
total 0
lr-x------ 1 root root 64 Apr  2 08:09 0 -> /dev/null
lrwx------ 1 root root 64 Apr  2 08:09 1 -> 'socket:[448834727]'
lrwx------ 1 root root 64 Apr  2 08:09 2 -> 'socket:[448834727]'
lrwx------ 1 root root 64 Apr  2 08:09 3 -> 'anon_inode:[eventpoll]'
lr-x------ 1 root root 64 Apr  2 08:09 4 -> 'pipe:[448836695]'
l-wx------ 1 root root 64 Apr  2 08:09 5 -> 'pipe:[448836695]'
lrwx------ 1 root root 64 Apr  2 08:09 6 -> 'socket:[448808639]'
lr-x------ 1 root root 64 Apr  2 08:09 7 -> /var/lib/filebeat/filebeat.lock
lrwx------ 1 root root 64 Apr  2 08:09 8 -> /var/lib/filebeat/registry/filebeat/log.json
lrwx------ 1 root root 64 Apr  2 08:09 9 -> /var/lib/filebeat/registry/filebeat/checkpoint.new

But it consumes CPU, working with registry.

3

I found solution, probably it will be useful for others.
This problem related to issues with registry size and it's performance.

solution is to set registry flush Configure general settings | Filebeat Reference [7.12] | Elastic to 60s like this:

filebeat.registry.flush: 60s

filebeat stops locking on syncing registry on disk and starts harvestes.
also i recommend to increase amount of open files, for Debian 10 use

systemctl edit filebeat

push in config such values:

[Service]
LimitNOFILE=65536

save and do

systemctl restart filebeat

4

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