# Filebeat performance stall sometimes

**URL:** <https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207>\
**Category:** Beats\
**Tags:** filebeat\
**Created:** [March 5, 2020, 6:35am UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207 "2020-03-05T06:35:46Z")\
**Posts on this page:** 18\
**Page:** 1

<div class="post-metadata">

**Author:** ![GhOsTMZ](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ghostmz/32/63856_2.png) [@GhOsTMZ](https://discuss.elastic.co/u/GhOsTMZ)\
**Post date:** [March 5, 2020, 6:35am UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/1 "2020-03-05T06:35:46Z")

</div>

Hello anyone!  
I have a some problems with a Filebeat. I collecting logs from a 2 files and send it to a Logstash. Events rate decreasing after a few hours of work. Events rate becomes normal after restart filebeat or connection to Logstash was reset. Normal event rate is a 250 e/s, stalled - ~50 e/s.

Environment:

- CentOS 8
- Filebeat 7.6.0

Filebeat configuration:

```auto
filebeat.inputs:
- type: log
  enabled: true
  paths:
    - /var/log/nginx/access.log*
  exclude_files: ['.gz$']
  fields_under_root: true
  fields:
    source_type: nginx_access
filebeat.config.modules:
  path: ${path.config}/modules.d/*.yml
  reload.enabled: false
setup.template.settings:
  index.number_of_shards: 1
setup.kibana:
output.logstash:
  hosts: ["elk.local:5043"]
monitoring.enabled: true
monitoring.cluster_uuid: "a7Povx8cTK-IN_uQpDC8kA"
monitoring.elasticsearch:
  hosts: ["elk.local:9200"]

```

Event rate with comments:

 ![filebeat_event_rate_1](https://us1.discourse-cdn.com/elastic/original/3X/8/2/82f5960264090a04f190042e81b1a782cd60545f.png)

Memory usage with comments:

 ![filebeat_memory_1](https://us1.discourse-cdn.com/elastic/original/3X/7/c/7c953ddacbb71b51c5e7e83567826659b8d80d5c.png)

Memory usage and event rate in a connection reset:

 ![filebeat_1](https://us1.discourse-cdn.com/elastic/original/3X/5/a/5af69e1351ef9e6d6aabe502f173311625382e86.png)

---

<div class="post-metadata">

**Author:** ![jsoriano](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jsoriano/32/27920_2.png) [@jsoriano](https://discuss.elastic.co/u/jsoriano)\
**Post date:** [March 5, 2020, 12:28pm UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/2 "2020-03-05T12:28:27Z")

</div>

Hi @GhOsTMZ, welcome to discuss 🙂

Do you see any error in filebeat or logstash logs?

---

<div class="post-metadata">

**Author:** ![GhOsTMZ](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ghostmz/32/63856_2.png) [@GhOsTMZ](https://discuss.elastic.co/u/GhOsTMZ)\
**Post date:** [March 5, 2020, 12:49pm UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/3 "2020-03-05T12:49:15Z")

</div>

Hello @jsoriano!  
Unfortunately, logs are clear, only metrics in a log and no one error.

---

<div class="post-metadata">

**Author:** ![jsoriano](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jsoriano/32/27920_2.png) [@jsoriano](https://discuss.elastic.co/u/jsoriano)\
**Post date:** [March 5, 2020, 5:47pm UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/4 "2020-03-05T17:47:26Z")

</div>

Could you share your filebeat configuration?

---

<div class="post-metadata">

**Author:** ![GhOsTMZ](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ghostmz/32/63856_2.png) [@GhOsTMZ](https://discuss.elastic.co/u/GhOsTMZ)\
**Post date:** [March 5, 2020, 7:07pm UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/5 "2020-03-05T19:07:43Z")

</div>

Filebeat configuration in a first message. But I can duplicate it here:

```auto
filebeat.inputs:
- type: log
  enabled: true
  paths:
    - /var/log/nginx/access.log*
  exclude_files: ['.gz$']
  fields_under_root: true
  fields:
    source_type: nginx_access
filebeat.config.modules:
  path: ${path.config}/modules.d/*.yml
  reload.enabled: false
setup.template.settings:
  index.number_of_shards: 1
setup.kibana:
output.logstash:
  hosts: ["elk.local:5043"]
monitoring.enabled: true
monitoring.cluster_uuid: "a7Povx8cTK-IN_uQpDC8kA"
monitoring.elasticsearch:
  hosts: ["elk.local:9200"]

```

In additional: it so strange, early filebeat worked properly not more than 6 hours. But it works more than 12 hours after last incident. I'll try to reproduce this behavior and get a syscalls by a strace. I hope it will be useful.

---

<div class="post-metadata">

**Author:** ![GhOsTMZ](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ghostmz/32/63856_2.png) [@GhOsTMZ](https://discuss.elastic.co/u/GhOsTMZ)\
**Post date:** [March 6, 2020, 8:39am UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/6 "2020-03-06T08:39:30Z")

</div>

Filebeat worked properly only 1 hour after restarted. I collected syscalls for a normal and stalled working.

strace outputs: [Normal](https://ufile.io/6jwfukn8), [Stalled](https://ufile.io/demskpyb)

---

<div class="post-metadata">

**Author:** ![jsoriano](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jsoriano/32/27920_2.png) [@jsoriano](https://discuss.elastic.co/u/jsoriano)\
**Post date:** [March 6, 2020, 9:47am UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/7 "2020-03-06T09:47:58Z")

</div>

> [@GhOsTMZ](#):
>
> Filebeat configuration in a first message. But I can duplicate it here:

Oops sorry 🤦‍♂️ thanks for sending it again, along with the strace outputs. Could you also send the debug logs of filebeat?

---

<div class="post-metadata">

**Author:** ![jsoriano](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jsoriano/32/27920_2.png) [@jsoriano](https://discuss.elastic.co/u/jsoriano)\
**Post date:** [March 6, 2020, 10:13am UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/8 "2020-03-06T10:13:55Z")

</div>

I have found this issue reported in Github that could lead to similar synthoms, it might be the same issue [https://github.com/elastic/beats/issues/16335](https://github.com/elastic/beats/issues/16335).

@GhOsTMZ what version of logstash are you using?

---

<div class="post-metadata">

**Author:** ![GhOsTMZ](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ghostmz/32/63856_2.png) [@GhOsTMZ](https://discuss.elastic.co/u/GhOsTMZ)\
**Post date:** [March 6, 2020, 12:14pm UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/9 "2020-03-06T12:14:59Z")

</div>

> [@jsoriano](#):
>
> @GhOsTMZ what version of logstash are you using?

Version 7.4.2.

> [@jsoriano](#):
>
> Could you also send the debug logs of filebeat?

Isn't a problem but I should wait when issue will be reproduced.

I'll try to update logstash to actual version. Maybe issue will gone. Or no chance?

---

<div class="post-metadata">

**Author:** ![GhOsTMZ](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ghostmz/32/63856_2.png) [@GhOsTMZ](https://discuss.elastic.co/u/GhOsTMZ)\
**Post date:** [March 9, 2020, 8:33am UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/10 "2020-03-09T08:33:49Z")

</div>

> [@jsoriano](#):
>
> Could you also send the debug logs of filebeat?

Hello,  
Debug logs [here](https://ufile.io/rikr1ucn). This logs covers too much period. Interesting period from 2020-08-03 09:30 to 2020-08-03 11:09. I can remove unactual lines. Let me know if you want it.

Also log file is filtered by `egrep -h '^[0-9]+.*[A-Z]{4,}' filebeat{.1,} | grep -v 'Publish event'`. I think you don't needs a events in this log file.

---

<div class="post-metadata">

**Author:** ![jsoriano](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jsoriano/32/27920_2.png) [@jsoriano](https://discuss.elastic.co/u/jsoriano)\
**Post date:** [March 9, 2020, 12:55pm UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/11 "2020-03-09T12:55:09Z")

</div>

Thanks for sending the debug logs.

I don't see anything specially bad, but something called my attention. Starting on ~9:30, there are many batches sent with 2048 events:

```auto
2020-03-08T09:30:05.370Z	DEBUG	[logstash]	logstash/async.go:159	2048 events out of 2048 events sent to logstash host elk.local:5043. Continue sending

```

2048 is the default maximum batch size. Is it possible that starting on 9:30 your nginx server is generating more logs? It could be that something in the pipeline cannot cope with this load and gets saturated, affecting perfomance.

You could try to increase the [max bulk size](https://www.elastic.co/guide/en/beats/filebeat/7.6/logstash-output.html#_bulk_max_size_2) and the [in-memory queue size](https://www.elastic.co/guide/en/beats/filebeat/7.6/configuring-internal-queue.html#_events) and see if there is any improvement.

```auto
...
queue.mem:
  events: 16384
output.logstash:
  hosts: ["elk.local:5043"]
  bulk_max_size: 4096
...

```

If you are also monitoring logstash, please also check its metrics to see if it could be constrained of some resource. You may also need to increase the number of workers or max batch size in logstash.

If you are monitoring Elasticsearch, it could be also interesting to see the ingest rate during the periods when filebeat is having low performance.

---

<div class="post-metadata">

**Author:** ![GhOsTMZ](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ghostmz/32/63856_2.png) [@GhOsTMZ](https://discuss.elastic.co/u/GhOsTMZ)\
**Post date:** [March 9, 2020, 3:34pm UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/12 "2020-03-09T15:34:22Z")

</div>

> [@jsoriano](#):
>
> Is it possible that starting on 9:30 your nginx server is generating more logs?

Yes, it is. Sometimes (every 10 minutes) we have a request rate spikes (1500-4000k RPS). But not all times performance is affected. Before using filebeat we made some tests and got more than 6k event/sec performance in a default configuration.

So, I found interesting things in my debug logs:

> **Some stats**
>
> ```auto
> grep async.go beat.debug | sed -r 's/:[0-9]{2}\.[0-9]{3}Z//' | awk '{print $1}' | uniq -c
> # Normal working
> 15 2020-03-08T08:55
> 25 2020-03-08T08:56
> 35 2020-03-08T08:57
> 34 2020-03-08T08:58
> 37 2020-03-08T08:59
> 42 2020-03-08T09:00
> 26 2020-03-08T09:01
> 33 2020-03-08T09:02
> 29 2020-03-08T09:03
> 26 2020-03-08T09:04
> 36 2020-03-08T09:05
> 25 2020-03-08T09:06
> 35 2020-03-08T09:07
> 30 2020-03-08T09:08
> 37 2020-03-08T09:09
> 36 2020-03-08T09:10
> 32 2020-03-08T09:11
> 24 2020-03-08T09:12
> 31 2020-03-08T09:13
> 29 2020-03-08T09:14
> 32 2020-03-08T09:15
> 28 2020-03-08T09:16
> 33 2020-03-08T09:17
> 30 2020-03-08T09:18
> 27 2020-03-08T09:19
> 39 2020-03-08T09:20
> 22 2020-03-08T09:21
> 30 2020-03-08T09:22
> 28 2020-03-08T09:23
> 32 2020-03-08T09:24
> 35 2020-03-08T09:25
> 27 2020-03-08T09:26
> 34 2020-03-08T09:27
> 37 2020-03-08T09:28
> 37 2020-03-08T09:29
> # Look here
> 10 2020-03-08T09:30
> 4 2020-03-08T09:31
> 3 2020-03-08T09:32
> 2 2020-03-08T09:33
> 3 2020-03-08T09:34
> 1 2020-03-08T09:35
> 3 2020-03-08T09:36
> 2 2020-03-08T09:37
> 1 2020-03-08T09:38
> 3 2020-03-08T09:39
> 2 2020-03-08T09:40
> 2 2020-03-08T09:41
> 
> ```

It's a normal behavior?

> [@jsoriano](#):
>
> If you are also monitoring logstash, please also check its metrics to see if it could be constrained of some resource. You may also need to increase the number of workers or max batch size in logstash.

Yes, I monitoring logstash too. And I don't see anomalies in a graphs. But I'll try to increase workers count.

PS: thank you for helping!

---

<div class="post-metadata">

**Author:** ![GhOsTMZ](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ghostmz/32/63856_2.png) [@GhOsTMZ](https://discuss.elastic.co/u/GhOsTMZ)\
**Post date:** [March 25, 2020, 6:50am UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/13 "2020-03-25T06:50:56Z")

</div>

> [@jsoriano](#):
>
> You could try to increase the [max bulk size](https://www.elastic.co/guide/en/beats/filebeat/7.6/logstash-output.html#_bulk_max_size_2) and the [in-memory queue size](https://www.elastic.co/guide/en/beats/filebeat/7.6/configuring-internal-queue.html#_events) and see if there is any improvement.

> [@jsoriano](#):
>
> You may also need to increase the number of workers or max batch size in logstash.

Unfortunately, no changes after using this. I think my final solution is restarting filebeat every hour...

---

<div class="post-metadata">

**Author:** ![GhOsTMZ](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ghostmz/32/63856_2.png) [@GhOsTMZ](https://discuss.elastic.co/u/GhOsTMZ)\
**Post date:** [March 27, 2020, 2:50pm UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/14 "2020-03-27T14:50:42Z")

</div>

Curious thing. I tried to compare nginx log size with a filebeat registy. I used this command for it:

```auto
while true; do clear; (LANG=C date; cat /var/lib/filebeat/registry/filebeat/data.json | jq '.[] as $src | ($src.source, $src.offset)' | tr -d '"' | awk 'BEGIN{cnt=-1}{if(NR%2==1){cnt++;fname[cnt]=$0}else{cmd="ls -la " fname[cnt] " | cut -f5 -d\" \""; while((cmd | getline line)>0){fsize[cnt]=line}close(cmd);offset[cnt]=$0}}END{for(i=0;i<=cnt;i++){if(match(fname[i],".gz$")==0){printf("\t%s\n\t\tPosition: %d\n\t\tFile size: %s\n\t\tUnreaded: %d\n\n",fname[i],offset[i],fsize[i],fsize[i]-offset[i])}}}') | tee -a ~/filebeat_pos.log; sleep 1; done

```

When filebeat becomes stall I see this:

```auto
Fri Mar 27 14:48:58 GMT 2020                                                                                                                                                                                                                 
        /var/log/nginx/access.log-20200327                                                                                                                                                                                                   
                Position: 17186877614                                                                                                                                                                                                        
                File size: 17186877614                                                                                                                                                                                                       
                Unreaded: 0                                                                                                                                                                                                                  
                                                                                                                                                                                                                                             
        /var/log/nginx/access.log                                                                                                                                                                                                            
                Position: 5027051158                                                                                                                                                                                                         
                File size: 5071950384                                                                                                                                                                                                        
                Unreaded: 44899226

```

File size and position (offset in a filebeat registry) is equal (or difference is no more than 1M) in a normal working.

---

<div class="post-metadata">

**Author:** ![GhOsTMZ](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ghostmz/32/63856_2.png) [@GhOsTMZ](https://discuss.elastic.co/u/GhOsTMZ)\
**Post date:** [March 31, 2020, 8:13am UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/15 "2020-03-31T08:13:29Z")

</div>

I still trying to resolve issue without restarting beats every hour and I found next curious thing. This command shows events sent and acked events by a logstash:

```auto
egrep 'async|acker' beat.debug | awk '{if($3=="[logstash]"){print "Sent: " $5 "/" $9}else{sub("}", "", $8); print "Acked: " $8 "\n"}}'

```

And what I watching there:

> **Output**
>
> ```auto
> # Normal working
> Sent: 454/454
> Acked: 454
> 
> Sent: 231/231
> Acked: 231
> 
> Sent: 459/459
> Acked: 459
> 
> Sent: 232/232
> Acked: 232
> 
> Sent: 699/699
> Acked: 699
> 
> # Issue started here
> Sent: 2048/2048
> Sent: 1806/1806
> Sent: 242/242
> Acked: 2048
> 
> Sent: 2048/2048
> Acked: 1806
> 
> Sent: 1806/1806
> Acked: 242
> 
> Sent: 242/242
> Acked: 2048
> 
> Sent: 2048/2048
> Acked: 1806
> 
> Sent: 1806/1806
> Acked: 242
> 
> ```

This is a logstash or beats issue?

PS: this logs from [here](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/10)

---

<div class="post-metadata">

**Author:** ![jsoriano](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jsoriano/32/27920_2.png) [@jsoriano](https://discuss.elastic.co/u/jsoriano)\
**Post date:** [April 3, 2020, 9:42am UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/16 "2020-04-03T09:42:24Z")

</div>

```
# Issue started here
Sent: 2048/2048
Sent: 1806/1806
Sent: 242/242
Acked: 2048

```

Yes, this is why I suggested to try to increase the `bulk_max_size`, that could be involved here, and suspiciously defaults to 2048. Did you see any difference in these values after increasing `bulk_max_size`?

There is a possible bug in the logstash output that can make a beat to continuously retry to send the same batch of events if any of the events is rejected. I created an issue for that some time ago, but we are not sure of the conditions when it happens [https://github.com/elastic/beats/issues/11732](https://github.com/elastic/beats/issues/11732). In any case if this is the issue we should see something about failed events in filebeat or logstash logs.

Would it be an option for you to try to send events directly from filebeat to Elasticsearch? Without logstash? So we can confirm if this is an issue with filebeat, or with logstash or the logstash output.

---

<div class="post-metadata">

**Author:** ![GhOsTMZ](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ghostmz/32/63856_2.png) [@GhOsTMZ](https://discuss.elastic.co/u/GhOsTMZ)\
**Post date:** [April 3, 2020, 10:04am UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/17 "2020-04-03T10:04:06Z")

</div>

> [@jsoriano](#):
>
> Yes, this is why I suggested to try to increase the `bulk_max_size` , that could be involved here, and suspiciously defaults to 2048. Did you see any difference in these values after increasing `bulk_max_size` ?

No changes. I tried to increase `bulk_max_size` to 4096 and no changes.

> [@jsoriano](#):
>
> Would it be an option for you to try to send events directly from filebeat to Elasticsearch? Without logstash? So we can confirm if this is an issue with filebeat, or with logstash or the logstash output.

Unfortunately I cannot do it because I using ClickHouse instead of ES.

But I found a curious thing again. I disabled compression (I tried to capture traffic) in filebeat on one of my servers and problem is gone. 4 days without problems.

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [May 1, 2020, 10:04am UTC](https://discuss.elastic.co/t/filebeat-performance-stall-sometimes/222207/18 "2020-05-01T10:04:10Z")

</div>

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