# Filebeat is losing events due to file rotate

**URL:** <https://discuss.elastic.co/t/filebeat-is-losing-events-due-to-file-rotate/52436>\
**Category:** Beats\
**Tags:** filebeat\
**Created:** [June 10, 2016, 11:31am UTC](https://discuss.elastic.co/t/filebeat-is-losing-events-due-to-file-rotate/52436 "2016-06-10T11:31:10Z")\
**Posts on this page:** 6\
**Page:** 1

<div class="post-metadata">

**Author:** ![mostolog](https://avatars.discourse-cdn.com/v4/letter/m/858c86/32.png) [@mostolog](https://discuss.elastic.co/u/mostolog)\
**Post date:** [June 10, 2016, 11:31am UTC](https://discuss.elastic.co/t/filebeat-is-losing-events-due-to-file-rotate/52436/1 "2016-06-10T11:31:10Z")

</div>

_Hi!_

_I'm opening this topic before opening an issue on github._  
_I hope not made any mistakes, cause it took me quite a long to test it and to report it in here._  
_Thanks in advance for your kind help._

_Regards_

## Scenario

- Logstash event generator writing to file "generator.log"
- FilebeatA _reading_ from "generator.log" and _writing_ to "filebeat.log", rotating files each 1MB
- FilebeatB _reading_ from "filebeat.log" _writing_ to "final.log", rotating each 3MB (really, rotation on this file can be disabled, but the problem persist)

**Please, notice that** :

- If rotation renames file appending _.X_ (eg: file.X) and FilebeatB is listening to _file\*_, most events will be re-procesed (ie: processed twice)
- If rotation creates a new file named with a timestamp (eg: file.YYYY.MM.dd.hh.mm.ss) and FilebeatB is listening to _file\*_, most events will be re-procesed (ie: processed twice)

## Result

FilebeatB seems to be losing events registered on FilebeatA due to rotation.  
Events registered on filebeat.log.X doesn't exists on final.log\*

**Seems FilebeatA rotates file before filebeatB can read _last file events_.**

## Details

- logstash 5.0.0-alpha2 (**PS: docker pull logstash:5.0.0-alpha3-1 -\> Tag 5.0.0-alpha3-1 not found in repository [docker.io/library/logstash](http://docker.io/library/logstash)** 🙂)
- filebeat version 1.2.3 (amd64)

## Configuration files

**logstash.yml**

```auto
input {
    generator{
        add_field => { "from" => "${HOSTNAME}" }
    }
}
filter {}
output {
    stdout {}
    file {
        path => "/tmp/generator.log"
        flush_interval => 0
    }
}

```

**filebeatA.yml**

```auto
filebeat:
  prospectors:
    -
      paths:
        - /tmp/log*
      input_type: log
      scan_frequency: 0s
output:
  file:
    path: "/tmp"
    filename: filebeat.log
    rotate_every_kb: 1000
    number_of_files: 100
  console:
shipper:
  name: filebeatA
  tags: ["service-X", "web-tier"]
logging:
  to_syslog: false
  to_files: false
  level: info

```

**filebeatB.yml**

```auto
filebeat:
  prospectors:
    -
      paths:
        - /tmp/filebeat.log
      input_type: log
      scan_frequency: 0s
output:
  file:
    path: "/tmp"
    filename: final.log
    rotate_every_kb: 3000
    number_of_files: 10
  console:
shipper:
  name: filebeatB
  tags: ["service-X", "web-tier"]
logging:
  to_syslog: false
  to_files: false
  level: info

```

## Verification

**This command checks for _gaps_ on sequence numbers used by logstash generator.**  
`ls -v filebeat.log* | xargs -i grep generator '{}' | sed 's/.*sequence\\\"://g' | sed 's/,.*//g' | sort -n | awk -v "p=1" '(p==1){p=$1-1}($1!=p+1){print p+1"-"$1-1}{p=$1}END{print "ok"}`

**This command checks for _gaps_ on sequence number received from filebeat.**  
`ls -v final.log* | xargs -i grep generator '{}' | sed 's/.*sequence\\\\\\"://g' | sed 's/,.*//g' | sort -n | awk -v "p=1" '(p==1){p=$1-1}($1!=p+1){print p+1"-"$1-1}{p=$1}END{print "ok"}'`

_If the above last command returns at least a pair of numbers, you can check those exists on \_filebeat\_ but doesn't exists on \_final_\_.\*\*

For example, if printed _344356-352529_:  
`grep -H generator filebeat.log* | grep 344356` prints one line.  
`grep -H generator final.log* | grep 344356` doesn't print anything.

**In fact, doing the query for the previous sequence value (344355), shows the filebeat.log.X filename (grep -H) is different (just truncated).**

## Proposed solution

- Each FilebeatA file is created with creation timestamp (eg: filebeat.log.YY-MM-dd-hh-mm-ss), hence FilebeatB will be able to read it until rotation happens.
- _At the moment of rotation_, a new file is created with the creation timestamp, but the previous one **still exists to be processed** by FilebeatB, which will close it after a certain timeout.

---

<div class="post-metadata">

**Author:** ![ruflin](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ruflin/32/3116_2.png) [@ruflin](https://discuss.elastic.co/u/ruflin)\
**Post date:** [June 13, 2016, 7:18am UTC](https://discuss.elastic.co/t/filebeat-is-losing-events-due-to-file-rotate/52436/2 "2016-06-13T07:18:36Z")

</div>

@mostolog Thanks a lot for the effort to write down all the details. This helps a lot in investigating and reproducing. I will have a closer look later.

One thing I spotted which started me worrying, is that you use scan\_frequency: 0. This should be at least 1s, as it can lead to very high CPU usage and lead to unexpected behaviour. Could you retry it with 1s? Also it would be interesting to see if your issue persists in 5.0.0-alpha3.

---

<div class="post-metadata">

**Author:** ![mostolog](https://avatars.discourse-cdn.com/v4/letter/m/858c86/32.png) [@mostolog](https://discuss.elastic.co/u/mostolog)\
**Post date:** [June 14, 2016, 7:37am UTC](https://discuss.elastic.co/t/filebeat-is-losing-events-due-to-file-rotate/52436/3 "2016-06-14T07:37:34Z")

</div>

I have modified _scan\_frequency_ to 1s in both FilebeatA and FilebeatB. As documentation doesn't say anything about "unexpected behaviour", should I open a bug to fix that?

Same behaviour with 5.0.0-alpha3-1: FilebeatB is missing events.

Any other test I could do? Should I fill the issue now?

---

<div class="post-metadata">

**Author:** ![mostolog](https://avatars.discourse-cdn.com/v4/letter/m/858c86/32.png) [@mostolog](https://discuss.elastic.co/u/mostolog)\
**Post date:** [June 15, 2016, 7:53am UTC](https://discuss.elastic.co/t/filebeat-is-losing-events-due-to-file-rotate/52436/4 "2016-06-15T07:53:48Z")

</div>

Just created [Issue #5503](https://github.com/elastic/logstash/issues/5503)

---

<div class="post-metadata">

**Author:** ![ruflin](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ruflin/32/3116_2.png) [@ruflin](https://discuss.elastic.co/u/ruflin)\
**Post date:** [June 15, 2016, 7:54am UTC](https://discuss.elastic.co/t/filebeat-is-losing-events-due-to-file-rotate/52436/5 "2016-06-15T07:54:50Z")

</div>

I'm currently looking into it and will let you know when I find more details.

Note about the docker images: Be aware that these are no official images from Elastic.

---

<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:** [July 1, 2016, 11:31am UTC](https://discuss.elastic.co/t/filebeat-is-losing-events-due-to-file-rotate/52436/6 "2016-07-01T11:31:44Z")

</div>

This topic was automatically closed after 21 days. New replies are no longer allowed.