Filebeat is not send enough log to elasticsearch

AkatsukiPain · November 4, 2020, 2:38am

My filebeat sending not enough logs to elasticsearch.
Graph suddenly went down

This is filebeat.yml

filebeat.inputs:


#============================= Filebeat modules ===============================

filebeat.config.modules:
  # Glob pattern for configuration loading
  path: ${path.config}/modules.d/*.yml

  # Set to true to enable config reloading
  reload.enabled: false

#============================= Elastic Cloud ==================================
filebeat.spool_size: 8192
bulk_max_size: 8192
compression_level: 3
worker: 4
#force_close_files: true
#close_older: 10m
#close_inactive: 10m

setup.template.name: "nginx-7.3.2"

setup.template.pattern: "nginx-7.3.2-*"

setup.template.enabled: true

setup.template.overwrite: false

setup.ilm.enabled: auto

setup.ilm.rollover_alias: "nginx-7.3.2"

setup.ilm.pattern: "{now/d}-000001"

This is filebeat log:

There are some logs (from 5-20 documents per min) but it's actually more than thousands.

I have check data.json and meta.json in the registry folder ( 2 files' size are just 4K )

The log size of the system that is getting by filebeat is about 100MB-1GB.

warkolm · November 4, 2020, 5:35am

Please don't post pictures of text, they are difficult to read, impossible to search and replicate (if it's code), and some people may not be even able to see them

AkatsukiPain · November 4, 2020, 2:06pm

It just a normal log so I didn't post text. I have posted configuration in text ^^!

AkatsukiPain · November 7, 2020, 1:40am

I update some information about my problem:
-I will rotate every 5 mins (200MB for each) (using logrotate)
-the rate of the log when in rush hour is: more than 2 millions log row per 15 mins (My log reach 300MB in about 7~10 mins)
-Filebeat is working fine when the rate below 800k~ 1,5 million log row per 15 mins

AkatsukiPain · November 9, 2020, 10:03am

Can you help me check this issue? I have changed many settings but didn't work

warkolm · November 9, 2020, 8:46pm

I cannot read your Filebeat log as it's an image, please post the text from the log as code.

AkatsukiPain · November 10, 2020, 2:11am

Yeah, I upload my log as text so you can see. There is no strange thing.

Blockquote
2020-11-10T02:01:09.046Z INFO [monitoring] log/log.go:145 Non-zero metrics in the last 3s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":386630,"time":{"ms":16}},"total":{"ticks":2297780,"time":{"ms":72},"value":2297780},"user":{"ticks":1911150,"time":{"ms":56}}},"handles":{"limit":{"hard":4096,"soft":1024},"open":10},"info":{"ephemeral_id":"a0cac716-6d52-4284-9d24-6daa9e83785c","uptime":{"ms":32283024}},"memstats":{"gc_next":41015136,"memory_alloc":34127544,"memory_total":303418373712},"runtime":{"goroutines":74}},"filebeat":{"events":{"active":-189,"added":546,"done":735},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":735,"batches":16,"total":735},"read":{"bytes":13185},"write":{"bytes":686131}},"pipeline":{"clients":8,"events":{"active":0,"published":546,"total":546},"queue":{"acked":735}}},"registrar":{"states":{"current":7,"update":735},"writes":{"success":16,"total":16}},"system":{"load":{"1":0.47,"15":0.06,"5":0.18,"norm":{"1":0.0588,"15":0.0075,"5":0.0225}}}}}}
2020-11-10T02:01:12.046Z INFO [monitoring] log/log.go:145 Non-zero metrics in the last 3s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":386630,"time":{"ms":6}},"total":{"ticks":2297840,"time":{"ms":60},"value":2297840},"user":{"ticks":1911210,"time":{"ms":54}}},"handles":{"limit":{"hard":4096,"soft":1024},"open":10},"info":{"ephemeral_id":"a0cac716-6d52-4284-9d24-6daa9e83785c","uptime":{"ms":32286023}},"memstats":{"gc_next":48891792,"memory_alloc":26198408,"memory_total":303428492848},"runtime":{"goroutines":74}},"filebeat":{"events":{"active":177,"added":536,"done":359},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":359,"batches":8,"total":359},"read":{"bytes":6565},"write":{"bytes":333504}},"pipeline":{"clients":8,"events":{"active":177,"published":536,"total":536},"queue":{"acked":359}}},"registrar":{"states":{"current":7,"update":359},"writes":{"success":8,"total":8}},"system":{"load":{"1":0.47,"15":0.06,"5":0.18,"norm":{"1":0.0588,"15":0.0075,"5":0.0225}}}}}}
2020-11-10T02:01:15.046Z INFO [monitoring] log/log.go:145 Non-zero metrics in the last 3s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":386630,"time":{"ms":1}},"total":{"ticks":2297890,"time":{"ms":51},"value":2297890},"user":{"ticks":1911260,"time":{"ms":50}}},"handles":{"limit":{"hard":4096,"soft":1024},"open":10},"info":{"ephemeral_id":"a0cac716-6d52-4284-9d24-6daa9e83785c","uptime":{"ms":32289023}},"memstats":{"gc_next":48891792,"memory_alloc":43499952,"memory_total":303445794392},"runtime":{"goroutines":74}},"filebeat":{"events":{"active":-177,"added":708,"done":885},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":885,"batches":19,"total":885},"read":{"bytes":15773},"write":{"bytes":821865}},"pipeline":{"clients":8,"events":{"active":0,"published":708,"total":708},"queue":{"acked":885}}},"registrar":{"states":{"current":7,"update":885},"writes":{"success":19,"total":19}},"system":{"load":{"1":0.44,"15":0.06,"5":0.18,"norm":{"1":0.055,"15":0.0075,"5":0.0225}}}}}}
2020-11-10T02:03:39.046Z INFO [monitoring] log/log.go:145 Non-zero metrics in the last 3s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":387080,"time":{"ms":17}},"total":{"ticks":2300490,"time":{"ms":66},"value":2300490},"user":{"ticks":1913410,"time":{"ms":49}}},"handles":{"limit":{"hard":4096,"soft":1024},"open":10},"info":{"ephemeral_id":"a0cac716-6d52-4284-9d24-6daa9e83785c","uptime":{"ms":32433023}},"memstats":{"gc_next":48765488,"memory_alloc":28073936,"memory_total":304061475928},"runtime":{"goroutines":75}},"filebeat":{"events":{"active":-57,"added":492,"done":549},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":549,"active":50,"batches":12,"total":599},"read":{"bytes":9341},"write":{"bytes":555746}},"pipeline":{"clients":8,"events":{"active":122,"published":492,"total":492},"queue":{"acked":549}}},"registrar":{"states":{"current":7,"update":549},"writes":{"success":11,"total":11}},"system":{"load":{"1":0.06,"15":0.06,"5":0.13,"norm":{"1":0.0075,"15":0.0075,"5":0.0163}}}}}}
2020-11-10T02:03:42.046Z INFO [monitoring] log/log.go:145 Non-zero metrics in the last 3s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":387080,"time":{"ms":3}},"total":{"ticks":2300520,"time":{"ms":30},"value":2300520},"user":{"ticks":1913440,"time":{"ms":27}}},"handles":{"limit":{"hard":4096,"soft":1024},"open":10},"info":{"ephemeral_id":"a0cac716-6d52-4284-9d24-6daa9e83785c","uptime":{"ms":32436023}},"memstats":{"gc_next":48765488,"memory_alloc":42731224,"memory_total":304076133216},"runtime":{"goroutines":74}},"filebeat":{"events":{"active":44,"added":511,"done":467},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":467,"active":-50,"batches":9,"total":417},"read":{"bytes":8296},"write":{"bytes":386811}},"pipeline":{"clients":8,"events":{"active":166,"published":511,"total":511},"queue":{"acked":467}}},"registrar":{"states":{"current":7,"update":467},"writes":{"success":10,"total":10}},"system":{"load":{"1":0.06,"15":0.06,"5":0.13,"norm":{"1":0.0075,"15":0.0075,"5":0.0163}}}}}}

And this is the view in elasticsearch:

Sometimes, Logs are delaying send to Elasticsearch, the number of logs in old columns keep increasing ( 5-10 mins later than the current time)

If you need more info, please tell me

AkatsukiPain · November 10, 2020, 2:51am

I have tried with this configuration but it seems still to be a bottleneck or something delay in the high throughput log

filebeat.inputs:
#============================= Filebeat modules ===============================
filebeat.config.modules:
  path: ${path.config}/modules.d/*.yml
  # Set to true to enable config reloading
  reload.enabled: false
  harvester_buffer_size: 300000000
  max_bytes: 10000000
#============================= Elastic Cloud ==================================
filebeat.spool_size: 8192
bulk_max_size: 3096
flush_interval: 1s
compression_level: 3
worker: 2
#force_close_files: true
#close_older: 10m
#close_inactive: 45m
#ignore_older: 30m
registry: /var/lib/filebeat/registry
cloud.id: xxxx
cloud.auth: xxx
setup.template.name: "nginx-7.3.2"
setup.template.pattern: "nginx-7.3.2-*"

setup.template.enabled: true
setup.template.overwrite: false
setup.ilm.enabled: auto
setup.ilm.rollover_alias: "nginx-7.3.2"
setup.ilm.pattern: "{now/d}-000001"
logging.metrics.period: 20s
#scan_frequency: 3s

AkatsukiPain · November 10, 2020, 9:17am

I have some idea that the filter when creating the graph causes the problem. I don't know why but I think it is ok now. Could you help me understand it clearly? It related to time problems.

Two graphs below are based on the same indices.

I Inform you about this issue.
Thanks for reading.

system · December 8, 2020, 11:17am

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