# Registry writes slowing down filebeat

**URL:** <https://discuss.elastic.co/t/registry-writes-slowing-down-filebeat/353092>\
**Category:** Beats\
**Tags:** filebeat\
**Created:** [February 12, 2024, 5:15pm UTC](https://discuss.elastic.co/t/registry-writes-slowing-down-filebeat/353092 "2024-02-12T17:15:47Z")\
**Posts on this page:** 6\
**Page:** 1

<div class="post-metadata">

**Author:** ![pces](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pces/32/126636_2.png) [@pces](https://discuss.elastic.co/u/pces)\
**Post date:** [February 12, 2024, 5:15pm UTC](https://discuss.elastic.co/t/registry-writes-slowing-down-filebeat/353092/1 "2024-02-12T17:15:47Z")

</div>

Hello,

During a performance test, we put ~30000 files of 2.8mb each in the folder from where filebeat reads.

Over a period of time, the indexing rate slowed down. All best practices followed, like index refresh set to 30s, auto-generated document id used, tuned workers, harvester\_buffer\_size & bulk\_max\_size.

Checked a few things to confirm that elastic nodes were not a bottleneck. Set replicas to 0 but no improvement which confirmed the same.

On further investigation, found that log level was set to info. Changed it to error and that helped somewhat because it was writing some info and one warning very frequently. But still the performance was not so good at~2-3k/s.

On further investigation, we found that it was writing thousands of lines to the registry every now and then. And whenever it would write, that is when the indexing rate would drop. So changed registry.flush to 60s and close\_eof to true. That helped further. But still the performance was not so good at 4-5k/s.

Q1. Can someone help understand why was it writing thousands of lines to the registry? Even after changing the flush interval, it would not write for 60s, but then it would write for 20-30 seconds and the writes amounted to 50-80mb. I realized that it was something to do with the fact that we had placed ~30k files in the input folder, but we weren't sure which ones could be deleted to help bring down the registry.

Q2. Is there a way to know which files are uploaded, so that those could be moved/deleted?

Q3. Even after all files were uploaded, and we cleaned those up, the registry size did not reduce. We deleted the registry folder (like a hack). When will the registry size be reduced? But still the performance is poor. Any suggestions what else can we look for?

Q4. Instead of thousands of small files, believe less number of bigger files will help have a smaller registry, but will it help improve performance?

Thanks

---

<div class="post-metadata">

**Author:** ![leandrojmp](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/leandrojmp/32/107231_2.png) [@leandrojmp](https://discuss.elastic.co/u/leandrojmp)\
**Post date:** [February 12, 2024, 6:31pm UTC](https://discuss.elastic.co/t/registry-writes-slowing-down-filebeat/353092/2 "2024-02-12T18:31:33Z")

</div>

Which version of filebeat did you use, also did you use the `filestream` input or the deprecated `log` input?

Please share the `filebeat.yml` you used.

---

<div class="post-metadata">

**Author:** ![pces](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pces/32/126636_2.png) [@pces](https://discuss.elastic.co/u/pces)\
**Post date:** [February 12, 2024, 8:15pm UTC](https://discuss.elastic.co/t/registry-writes-slowing-down-filebeat/353092/3 "2024-02-12T20:15:45Z")

</div>

Thanks

The filebeat version is 8.9.2. We are using the log input. I saw that input is deprecated but wasn't motivated to change because came across some bugs which affected the filestream but not log input type, especially related t registry/harvester/close\ __/clean\__ or something (dont recollect exactly, but I can dig out).

[filebeat.yml](https://gist.github.com/pchovgh/47d96ad199f5794e7a23f57aa492ac79#file-filebeat-yml)

---

<div class="post-metadata">

**Author:** ![leandrojmp](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/leandrojmp/32/107231_2.png) [@leandrojmp](https://discuss.elastic.co/u/leandrojmp)\
**Post date:** [February 12, 2024, 9:28pm UTC](https://discuss.elastic.co/t/registry-writes-slowing-down-filebeat/353092/4 "2024-02-12T21:28:11Z")

</div>

> [@pces](#):
>
> We are using the log input.

Yeah, I'm not sure that you can improve this without changing to the `filestream` input.

The `filestream` inputs has a couple of improvements related to how the registry file is written, mainly:

> Only the most recent updates are serialized to the registry. In contrast, the `log` input has to serialize the complete registry on each ACK from the outputs. This makes the registry updates much quicker with this input.

And

> The input ensures that only offsets updates are written to the registry append only log. The `log` writes the complete file state.

Not sure what bugs you are referring to, but I would recommend you to test this using the `filestream` input and a newer version.

---

<div class="post-metadata">

**Author:** ![pces](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pces/32/126636_2.png) [@pces](https://discuss.elastic.co/u/pces)\
**Post date:** [February 14, 2024, 8:36am UTC](https://discuss.elastic.co/t/registry-writes-slowing-down-filebeat/353092/5 "2024-02-14T08:36:43Z")

</div>

thanks @leandrojmp

I looked through filestream and all enhancements seem to be exactly for the problems that we observed 🙂

btw, the bugs were related to configuration parameters (close\ __, clean\__ , harvester\_limit, etc.) that are relevant when there are a huge number of files like was the case in our env. I could recall a few:

> <https://github.com/elastic/beats/issues/34342>
>
> \- Version: \`main\`, \`8.6.0\`, probably affects older versions as well
> \- Operating… System: Linux
> 
> When \`harvester\_limit\` is set, the limit is respected, but only \`harvester\_limit\` files are ingested, the others are not ingested unless data is appended to them.
> 
> 
> The problem seems to be related to two facts:
> 1. The startHarvester error is ignored according to the TastGroup configuration.
> https://github.com/elastic/beats/blob/69ebd98fc41aa268acd7f99c429a44f2833c8dd3/filebeat/input/filestream/internal/input-logfile/harvester.go#L147
>     
> https://github.com/elastic/beats/blob/69ebd98fc41aa268acd7f99c429a44f2833c8dd3/filebeat/input/filestream/internal/input-logfile/input.go#L74
> 
> 2. The file watcher is unaware of the harvester status and only send the "createEvent" once
> https://github.com/elastic/beats/blob/69ebd98fc41aa268acd7f99c429a44f2833c8dd3/filebeat/input/filestream/fswatch.go#L138-L211
> 
> 
> Another thing to notice is lack of any log informing about harvesters not beings started. There is a log entry stating the harvester is starting, but no followup on its success/error.
> https://github.com/elastic/beats/blob/69ebd98fc41aa268acd7f99c429a44f2833c8dd3/filebeat/input/filestream/internal/input-logfile/harvester.go#L145
> 
> 
> \## Workaround
> Currently there is no workaround for filestream input, however the \[log input\](https://www.elastic.co/guide/en/beats/filebeat/current/filebeat-input-log.html), even though deprecated, will work as expected when setting \`harvester\_limit\`

> <https://github.com/elastic/beats/issues/36761>
>
> Even with \`clean\_removed: true\` in the filestream configuration, registry entrie…s are never removed from the in-memory store.
> 
> \## How to reproduce
> 1. Create the following \`filebeat.yml\`
> \`\`\`yaml
> filebeat.inputs:
> - type: filestream
> id: test-clean-removed
> enabled: true
> clean\_removed: true
> close.on\_state\_change.inactive: 1s
> prospector.scanner.check\_interval: 1s
> paths:
> - /tmp/log.log
> 
> filebeat.registry:
> file\_permissions: 0600
> cleanup\_interval: 5s
> flush: 0s
> 
> queue.mem:
> flush.min\_events: 8
> flush.timeout: 0.1s
> 
> output.file:
> path: ${path.home}
> filename: "output-file"
> rotate\_every\_kb: 10000
> 
> logging:
> level: debug
> selectors: \["\*"\]
> \`\`\`
> 2. Start Filebeat
> \`\`\`
> ./filebeat &
> \`\`\`
> 3. Create the log file
> \`\`\`
> echo "fist file"\>\> /tmp/log.log
> \`\`\`
> 4. Wait a few seconds, like 10s, for the file to be harvested (you can check the output file and/or logs)
> 5. Delete the file
> \`\`\`
> rm /tmp/log.log
> \`\`\`
> 6. Wait a few more seconds, like 10s
> 7. Look the logs for the store clean up messages
> \`\`\`
> {"log.level":"debug","@timestamp":"2023-10-05T12:18:46.854+0200","log.logger":"input","log.origin":{"file.name":"input-logfile/clean.go","file.line":66},"message":"Start store cleanup","service.name":"filebeat","input\_type":"filestream","ecs.version":"1.6.0"}
> {"log.level":"debug","@timestamp":"2023-10-05T12:18:46.854+0200","log.logger":"input","log.origin":{"file.name":"input-logfile/clean.go","file.line":79},"message":"No entries to remove were found","service.name":"filebeat","input\_type":"filestream","ecs.version":"1.6.0"}
> {"log.level":"debug","@timestamp":"2023-10-05T12:18:46.854+0200","log.logger":"input","log.origin":{"file.name":"input-logfile/clean.go","file.line":80},"message":"Done store cleanup","service.name":"filebeat","input\_type":"filestream","ecs.version":"1.6.0"}
> {"log.level":"debug","@timestamp":"2023-10-05T12:18:51.854+0200","log.logger":"input","log.origin":{"file.name":"input-logfile/clean.go","file.line":66},"message":"Start store cleanup","service.name":"filebeat","input\_type":"filestream","ecs.version":"1.6.0"}
> {"log.level":"debug","@timestamp":"2023-10-05T12:18:51.854+0200","log.logger":"input","log.origin":{"file.name":"input-logfile/clean.go","file.line":79},"message":"No entries to remove were found","service.name":"filebeat","input\_type":"filestream","ecs.version":"1.6.0"}
> {"log.level":"debug","@timestamp":"2023-10-05T12:18:51.854+0200","log.logger":"input","log.origin":{"file.name":"input-logfile/clean.go","file.line":80},"message":"Done store cleanup","service.name":"filebeat","input\_type":"filestream","ecs.version":"1.6.0"}
> {"log.level":"debug","@timestamp":"2023-10-05T12:18:56.854+0200","log.logger":"input","log.origin":{"file.name":"input-logfile/clean.go","file.line":66},"message":"Start store cleanup","service.name":"filebeat","input\_type":"filestream","ecs.version":"1.6.0"}
> {"log.level":"debug","@timestamp":"2023-10-05T12:18:56.854+0200","log.logger":"input","log.origin":{"file.name":"input-logfile/clean.go","file.line":79},"message":"No entries to remove were found","service.name":"filebeat","input\_type":"filestream","ecs.version":"1.6.0"}
> {"log.level":"debug","@timestamp":"2023-10-05T12:18:56.854+0200","log.logger":"input","log.origin":{"file.name":"input-logfile/clean.go","file.line":80},"message":"Done store cleanup","service.name":"filebeat","input\_type":"filestream","ecs.version":"1.6.0"}
> \`\`\`
> You will see that entries were never removed.
> 
> \## Possible cause
> I did a bit of investigation for the possible cause and I found that the resource containing the state of the file is never fully released, even after it's deletion.
> 
> Applying the following patch and the running the steps described above will show that the resource is never fully released.
> \`\`\`
> diff --git a/filebeat/input/filestream/internal/input-logfile/store.go b/filebeat/input/filestream/internal/input-logfile/store.go
> index 2b5b272..835654d 100644
> \--- a/filebeat/input/filestream/internal/input-logfile/store.go
> +++ b/filebeat/input/filestream/internal/input-logfile/store.go
> @@ -459,13 +459,20 @@ func (r \*resource) isDeleted() bool {
> // Retain is used to indicate that 'resource' gets an additional 'owner'.
> // Owners of an resource can be active inputs or pending update operations
> // not yet written to disk.
> \-func (r \*resource) Retain() { r.pending.Inc() }
> +func (r \*resource) Retain() {
> +	fmt.Println("========== RETAIN")
> +	r.pending.Inc()
> +}
>  
> // Release reduced the owner ship counter of the resource.
> \-func (r \*resource) Release() { r.pending.Dec() }
> +func (r \*resource) Release() {
> +	fmt.Println("========== RELEASE")
> +	r.pending.Dec()
> +}
>  
> // UpdatesReleaseN is used to release ownership of N pending update operations.
> func (r \*resource) UpdatesReleaseN(n uint) {
> +	fmt.Println("========== RELEASE", n)
> r.pending.Sub(uint64(n))
> }
> \`\`\`
> 
> On my tests I saw
> \- 3 retain calls
> \- 2 release calls
> \- the file was deleted
> \- 1 retain call
> 
> This makes calls to \[\`Finished()\`\](https://github.com/elastic/beats/blob/2988148e3ea5b34b076f6eb72dde8a9f16060152/filebeat/input/filestream/internal/input-logfile/store.go#L474) never to return \`true\`, so those states are never cleaned.
> 
> \## Related issues
> This issue is likely the same described in https://github.com/elastic/beats/issues/36056, but because of the focus on \`clean\_removed\` and the in-memory store rather than the registry files, I decided to open a different issue.

> <https://github.com/elastic/beats/issues/16076>
>
> \_Sorry for somewhat vague problem description. I was working on the problem in p…anic mode and had no time to preserve details like exact log snippets.\_
> 
> I use filebeat to scrap logs from machines where i have PLENTY of log files. Numbers vary, but having a few thousands new files every day is normal and sth like 50 thousands happens (in general: a lot of small apps running, each app opens new log on each restart and after each midnight, old logs are moved out by name, log names contain date…). After some initial tuning (harvester limit adapted to system capacity, time limits tuned to abandon inactive files at reasonable rate, etc) filebeat handles those setups without problems. 
> 
> Well, handled until I reconfigured. Today I split some inputs into a few sections, more or less it was change from
> \`\`\`
> \- type: log
> enabled: true
> paths:
> - /some/path/\*.log
> - /other/path/\*.log
> - …
> # and other settings
> \`\`\` 
> into
> \`\`\`
> \- type: log
> enabled: true
> paths:
> - /some/path/\*.log
> # and other settings
> \- type: log
> enabled: true
> paths:
> - /other/path/\*.log
> # and other settings
> \- type: log
> enabled: true
> paths:
> - …remaining …
> # and other settings
> \`\`\`
> where „other settings” were the same everywhere except I added some custom fields in each section (this was the reason for the change), and reduced harvester limits so they summed up to the original value.
> 
> After restart, filebeat practically stopped working. It either didn't forward anything, or handled only one section (depending on the machine, I saw the problem on a few). After I enabled debug logging it only logged myriads of notes about reading and writing data.json with some statistics („XYZV before, XYZV after”) and later started to put some notes about finding or adding state of individual files (~ 1 such note per second). On the machine I fixed last it remained in such a state for about 2 hours, without noticeable change.  
> 
> I recovered from that by stopping filebeat, erasing \`\`/var/lib/filebeat/registry\`\`, and starting filebeat again – then it simply started to work and seems to work properly (of course it republished all old logs according to my age settings and introduced lag caused by old data processing).
> 
> I suppose there is sth wrong in the way state is migrated/interpreted/checked after input sections change. This is somewhat unexpected, I didn't think that changing alocation of files to sections impacts state handling.
> 
> Tested on filebeat 7.5.1
> 
> PS My \`\`/var/lib/filebeat/registry/data.json\`\` have 3-8MB, if that is of any interest.

Since it was mentioned on some of those that the bugs did not apply for "log", we tried avoiding the study of filestream. But now that you suggest it, we are looking at it. Probably the bugs may also have been fixed in the latest version.

We are checking but it would help if you can just confirm that we simply replace log with filestream leaving the cfg (eg harvestor\_buffer\_size, close\_eof) as is or more changes will be required.

Thanks again!

---

<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:** [March 13, 2024, 10:37am UTC](https://discuss.elastic.co/t/registry-writes-slowing-down-filebeat/353092/6 "2024-03-13T10:37:18Z")

</div>

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