# Filebeat sending the whole log again after stoping and starting filebeat container

**URL:** <https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846>\
**Category:** Beats\
**Tags:** filebeat\
**Created:** [October 3, 2018, 9:04am UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846 "2018-10-03T09:04:30Z")\
**Posts on this page:** 16\
**Page:** 1

<div class="post-metadata">

**Author:** ![elk11](https://avatars.discourse-cdn.com/v4/letter/e/45deac/32.png) [@elk11](https://discuss.elastic.co/u/elk11)\
**Post date:** [October 3, 2018, 9:04am UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/1 "2018-10-03T09:04:30Z")

</div>

Hi,

When I stop filebeat container for a while to do some maintenance work on elasticsearch (output) and then start it again, the whole log is being sent again. because of this along with the new info which was written into log while the filebeat was down, the old content which was already sent to elasticsearch, is being sent again.

because of this i'm ending up with duplicate data in ES.

How to avoid it and make filebeat to read only new content written after stopping and starting it again.

Here's the config I'm using:

```
filebeat.prospectors:
- type: log
  enabled: true
  paths:
    - /usr/share/filebeat/logs/zuul/log/50lk_1cr_lines.log
  encoding: plain
  include_lines: ['\d{4}\-\d{2}\-\d{2}']
  multiline.pattern: '^\d{4}\-\d{2}\-\d{2}'
  multiline.negate: false
  multiline.match: after
  fields:
    document_type: zuul_log
  clean_removed: true
  registry: /usr/share/filebeat/data/registry

setup.template:
  name: "filebeat"
  pattern: "filebeat-*"
  settings:
    index.number_of_shards: 1
    index.number_of_replicas: 1

output.elasticsearch:
  hosts: ["xxx:9200"]
  index: "%{[fields.document_type]}-%{[beat.version]}-%{+yyyy.MM.dd}"

```

Thanks for the help

---

<div class="post-metadata">

**Author:** ![kvch](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kvch/32/72058_2.png) [@kvch](https://discuss.elastic.co/u/kvch)\
**Post date:** [October 3, 2018, 9:39am UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/2 "2018-10-03T09:39:50Z")

</div>

Filebeat has a registry file to track the events it has already sent to outputs.  
Are you sure Filebeat has access to it? Or does it get deleted between container runs?  
Could you please share the debug logs of filebeat?

---

<div class="post-metadata">

**Author:** ![elk11](https://avatars.discourse-cdn.com/v4/letter/e/45deac/32.png) [@elk11](https://discuss.elastic.co/u/elk11)\
**Post date:** [October 3, 2018, 9:50am UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/3 "2018-10-03T09:50:14Z")

</div>

Here's is the log:

```
2018/10/03 09:43:26.387184 beat.go:268: INFO filebeat stopped.
2018/10/03 09:44:26.630278 beat.go:426: INFO Home path: [/usr/share/filebeat] Config path: [/usr/share/filebeat] Data path: [/usr/share/filebeat/data] Logs path: [/usr/share/filebeat/logs]
2018/10/03 09:44:26.630446 beat.go:433: INFO Beat UUID: 9ce44b4f-8f6e-4513-94bc-3f8c498b5d93
2018/10/03 09:44:26.630442 metrics.go:23: INFO Metrics logging every 30s
2018/10/03 09:44:26.630485 beat.go:192: INFO Setup Beat: filebeat; Version: 6.0.1
2018/10/03 09:44:26.631019 client.go:123: INFO Elasticsearch url: http://swamy-ansiblenode1.vse.rdlabs.hpecorp.net:9200
2018/10/03 09:44:26.631743 module.go:80: INFO Beat name: 442bba24eabf
2018/10/03 09:44:26.632518 beat.go:260: INFO filebeat start running.
2018/10/03 09:44:26.632630 registrar.go:88: INFO Registry file set to: /usr/share/filebeat/data/registry
2018/10/03 09:44:26.632705 registrar.go:108: INFO Loading registrar data from /usr/share/filebeat/data/registry
2018/10/03 09:44:26.633133 registrar.go:119: INFO States Loaded from registrar: 1
2018/10/03 09:44:26.633207 crawler.go:44: INFO Loading Prospectors: 1
2018/10/03 09:44:26.633430 registrar.go:150: INFO Starting Registrar
2018/10/03 09:44:26.634141 prospector.go:103: INFO Starting prospector of type: log; id: 11640557023490740795
2018/10/03 09:44:26.634175 crawler.go:78: INFO Loading and starting Prospectors completed. Enabled prospectors: 1
2018/10/03 09:44:26.637768 harvester.go:207: INFO Harvester started for file: /usr/share/filebeat/logs/zuul/log/50lk_1cr_lines.log
2018/10/03 09:44:27.670319 client.go:651: INFO Connected to Elasticsearch version 5.6.2
2018/10/03 09:44:27.673102 load.go:73: INFO Template already exists and will not be overwritten.
2018/10/03 09:44:52.472795 registrar.go:233: ERR Failed to create tempfile (/usr/share/filebeat/data/registry.new) for writing: open /usr/share/filebeat/data/registry.new: permission denied
2018/10/03 09:44:52.472845 registrar.go:217: ERR Writing of registry returned error: open /usr/share/filebeat/data/registry.new: permission denied. Continuing...
2018/10/03 09:44:56.631574 metrics.go:39: INFO Non-zero metrics in the last 30s: beat.memstats.gc_next=88511696 beat.memstats.memory_alloc=52551160 beat.memstats.memory_total=3012819400 filebeat.events.active=19170 filebeat.events.added=1030463 filebeat.events.done=1011293 filebeat.harvester.open_files=1 filebeat.harvester.running=1 filebeat.harvester.started=1 libbeat.config.module.running=0 libbeat.output.read.bytes=201695 libbeat.output.type=elasticsearch libbeat.output.write.bytes=39799570 libbeat.pipeline.clients=1 libbeat.pipeline.events.active=382 libbeat.pipeline.events.filtered=1009452 libbeat.pipeline.events.published=21009 libbeat.pipeline.events.retry=50 libbeat.pipeline.events.total=1030461 libbeat.pipeline.queue.acked=20627 registrar.states.cleanup=1 registrar.states.current=1 registrar.states.update=1011293 registrar.writes=437
2018/10/03 09:44:57.375991 registrar.go:233: ERR Failed to create tempfile (/usr/share/filebeat/data/registry.new) for writing: open /usr/share/filebeat/data/registry.new: permission denied
2018/10/03 09:44:57.376033 registrar.go:217: ERR Writing of registry returned error: open /usr/share/filebeat/data/registry.new: permission denied. Continuing...
2018/10/03 09:45:06.905293 registrar.go:233: ERR Failed to create tempfile (/usr/share/filebeat/data/registry.new) for writing: open /usr/share/filebeat/data/registry.new: permission denied
2018/10/03 09:45:06.905332 registrar.go:217: ERR Writing of registry returned error: open /usr/share/filebeat/data/registry.new: permission denied. Continuing...
2018/10/03 09:45:11.474269 helper_other.go:14: ERR Rotate error: rename /usr/share/filebeat/data/registry.new /usr/share/filebeat/data/registry: no such file or directory
2018/10/03 09:45:11.474332 registrar.go:217: ERR Writing of registry returned error: rename /usr/share/filebeat/data/registry.new /usr/share/filebeat/data/registry: no such file or directory. Continuing...

```

I think filebeat has access to registry file but there's some permission error ? I'm not sure.

---

<div class="post-metadata">

**Author:** ![kvch](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kvch/32/72058_2.png) [@kvch](https://discuss.elastic.co/u/kvch)\
**Post date:** [October 4, 2018, 9:27am UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/4 "2018-10-04T09:27:45Z")

</div>

Yes, there is a permission problem. Filebeat is not able to write its registry.  
`Writing of registry returned error: open /usr/share/filebeat/data/registry.new: permission denied. Continuing...`

Before writing to `data/registry`, Filebeat first creates a temp file `registry.new` and then renames it to `registry`. So it seems your instance is able to read from `data/registry`, but does not have the correct permissions to write to a new file under `data`.

---

<div class="post-metadata">

**Author:** ![elk11](https://avatars.discourse-cdn.com/v4/letter/e/45deac/32.png) [@elk11](https://discuss.elastic.co/u/elk11)\
**Post date:** [October 4, 2018, 1:02pm UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/5 "2018-10-04T13:02:25Z")

</div>

But I'm not sure how is that the cause for re-sending entire log again after stopping and starting. Do you think fixing the permission error would fix the problem of re-sending the log? If it does, how? because filebeat still has access to registry file and has permission to read the registry file!

---

<div class="post-metadata">

**Author:** ![elk11](https://avatars.discourse-cdn.com/v4/letter/e/45deac/32.png) [@elk11](https://discuss.elastic.co/u/elk11)\
**Post date:** [October 4, 2018, 1:22pm UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/6 "2018-10-04T13:22:15Z")

</div>

I changed permission of registry file (0755), but the issue still persists. addition of a single new line to log is resulting in sending the whole log to ES instead of just that one line!

---

<div class="post-metadata">

**Author:** ![kvch](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kvch/32/72058_2.png) [@kvch](https://discuss.elastic.co/u/kvch)\
**Post date:** [October 4, 2018, 1:30pm UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/7 "2018-10-04T13:30:28Z")

</div>

Filebeat tracks progress of reading from input files, so it does not reread anything. It persist the state information of files by writing it to the registry. Thus, when Filebeat restarts, it reads the states and knows where it needs to continue reading.  
If it cannot access the registry file, it does not have any information on the states of the files. If there is no information on a file, it means that Filebeat has not encountered it before, so it starts to read it from the beginning. According to the logs you have provided, Filebeat is unable to write the state information to disk, because of permission problems.

Could you share the debug logs again? Is it possible that Filebeat still does not have the proper access to the folder, so it is not able to write the temporary file?

---

<div class="post-metadata">

**Author:** ![elk11](https://avatars.discourse-cdn.com/v4/letter/e/45deac/32.png) [@elk11](https://discuss.elastic.co/u/elk11)\
**Post date:** [October 4, 2018, 1:38pm UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/8 "2018-10-04T13:38:53Z")

</div>

Yes, here's the debug log.

```
2018/10/04 13:35:29.433676 registrar.go:150: INFO Starting Registrar
2018/10/04 13:35:29.433770 processor.go:49: DBG Processors:
2018/10/04 13:35:29.434239 config.go:174: DBG recursive glob disabled
2018/10/04 13:35:29.434588 prospector.go:109: DBG exclude_files: []
2018/10/04 13:35:29.434611 state.go:81: DBG New state added for /usr/share/filebeat/logs/zuul/log/50lk_1cr_lines.log
2018/10/04 13:35:29.434643 prospector.go:130: DBG Prospector with previous states loaded: 1
2018/10/04 13:35:29.434659 prospector.go:100: DBG File Configs: [/usr/share/filebeat/logs/zuul/log/50lk_1cr_lines.log /usr/share/filebeat/logs/zuul/log/50lk_1cr_lines.log]
2018/10/04 13:35:29.434672 prospector.go:103: INFO Starting prospector of type: log; id: 11640557023490740795
2018/10/04 13:35:29.434688 crawler.go:78: INFO Loading and starting Prospectors completed. Enabled prospectors: 1
2018/10/04 13:35:29.434734 prospector.go:136: DBG Start next scan
2018/10/04 13:35:29.434828 prospector.go:350: DBG Check file for harvesting: /usr/share/filebeat/logs/zuul/log/50lk_1cr_lines.log
2018/10/04 13:35:29.434818 registrar.go:200: DBG Processing 1 events
2018/10/04 13:35:29.434880 registrar.go:195: DBG Registrar states cleaned up. Before: 1, After: 1
2018/10/04 13:35:29.434895 registrar.go:228: DBG Write registry file: /usr/share/filebeat/data/registry
2018/10/04 13:35:29.434848 prospector.go:436: DBG Update existing file for harvesting: /usr/share/filebeat/logs/zuul/log/50lk_1cr_lines.log, offset: 343298048
2018/10/04 13:35:29.434973 prospector.go:490: DBG File didn't change: /usr/share/filebeat/logs/zuul/log/50lk_1cr_lines.log
2018/10/04 13:35:29.434986 prospector.go:157: DBG Prospector states cleaned up. Before: 1, After: 1
2018/10/04 13:35:29.442743 registrar.go:253: DBG Registry file updated. 1 states written.
2018/10/04 13:35:39.435377 prospector.go:140: DBG Run prospector
2018/10/04 13:35:39.435432 prospector.go:136: DBG Start next scan
2018/10/04 13:35:39.435550 prospector.go:350: DBG Check file for harvesting: /usr/share/filebeat/logs/zuul/log/50lk_1cr_lines.log
2018/10/04 13:35:39.435575 prospector.go:436: DBG Update existing file for harvesting: /usr/share/filebeat/logs/zuul/log/50lk_1cr_lines.log, offset: 343298048
2018/10/04 13:35:39.435588 prospector.go:490: DBG File didn't change: /usr/share/filebeat/logs/zuul/log/50lk_1cr_lines.log
2018/10/04 13:35:39.435602 prospector.go:157: DBG Prospector states cleaned up. Before: 1, After: 1

```

> If it cannot access the registry file, it does not have any information on the states of the files. If there is no information on a file, it means that Filebeat has not encountered it before, so it starts to read it from the beginning. According to the logs you have provided, Filebeat is unable to write the state information to disk, because of permission problems.

But if that was the case, it should have re read the whole log after restarting also. In the case when there are no new contents and the filebeat is restarted, it correctly does the job of not sending anything to ES as it has already sent the old log info.

---

<div class="post-metadata">

**Author:** ![kvch](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kvch/32/72058_2.png) [@kvch](https://discuss.elastic.co/u/kvch)\
**Post date:** [October 4, 2018, 1:58pm UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/9 "2018-10-04T13:58:37Z")

</div>

When do you see this behavoiur exactly? When does Filebeat reread everything? In your initial post you have written: "How to avoid it and make filebeat to read only new content written after stopping and starting it again." To me it means that Filebeat rereads everything after restarting it.

---

<div class="post-metadata">

**Author:** ![elk11](https://avatars.discourse-cdn.com/v4/letter/e/45deac/32.png) [@elk11](https://discuss.elastic.co/u/elk11)\
**Post date:** [October 4, 2018, 2:02pm UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/10 "2018-10-04T14:02:06Z")

</div>

I'm very sorry that i wasn't clear before.

The issue occurs:

1. when the new content is written to log and filebeat is running.
2. when the new content was written when filebeat was in stop mode, on starting  
filebeat whole content was re-read.

So basically, the whole log is being re-read everytime when a new content is written to log.

---

<div class="post-metadata">

**Author:** ![kvch](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kvch/32/72058_2.png) [@kvch](https://discuss.elastic.co/u/kvch)\
**Post date:** [October 5, 2018, 9:58am UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/11 "2018-10-05T09:58:58Z")

</div>

Could you please share the debug logs of the following scenario: Filebeat is started again after finishing reading a file. Then please add one more line to the file, so it triggers the reread of the full file?

---

<div class="post-metadata">

**Author:** ![elk11](https://avatars.discourse-cdn.com/v4/letter/e/45deac/32.png) [@elk11](https://discuss.elastic.co/u/elk11)\
**Post date:** [October 7, 2018, 5:45am UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/12 "2018-10-07T05:45:01Z")

</div>

> Could you please share the debug logs of the following scenario: Filebeat is started again after finishing reading a file.

In this scenario, log is not sent again (Assuming no new content was written when filebeat was down). The debug log of this scenario is already send in previous message (8/11). It correctly recognizes that:  
` 2018/10/04 13:35:39.435588 prospector.go:490: DBG File didn't change: /usr/share/filebeat/logs/zuul/log/50lk_1cr_lines.log`

> Then please add one more line to the file, so it triggers the reread of the full file?

Yes, exactly. Addition of any new content triggers re-sending of whole log instead of just the new content.

Am i missing some config item in my configuration file here?

---

<div class="post-metadata">

**Author:** ![elk11](https://avatars.discourse-cdn.com/v4/letter/e/45deac/32.png) [@elk11](https://discuss.elastic.co/u/elk11)\
**Post date:** [October 9, 2018, 9:24am UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/13 "2018-10-09T09:24:54Z")

</div>

Can someone please help?

---

<div class="post-metadata">

**Author:** ![elk11](https://avatars.discourse-cdn.com/v4/letter/e/45deac/32.png) [@elk11](https://discuss.elastic.co/u/elk11)\
**Post date:** [October 9, 2018, 7:47pm UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/14 "2018-10-09T19:47:38Z")

</div>

> how exactly do you modify the file. Have you tried `$ echo 'new line' >> /usr/src/app/log.log` ? filebeat tries to detect if file is new or not based on meta-data. some tools/editors do create a completely new file on save and unlink the old one. This is detected by filebeat as new file forcing it to resend all content.

I was using vi editor to edit file manually. so the issue. The above solved problem.

---

<div class="post-metadata">

**Author:** ![edwinknox](https://avatars.discourse-cdn.com/v4/letter/e/e56c9b/32.png) [@edwinknox](https://discuss.elastic.co/u/edwinknox)\
**Post date:** [October 17, 2018, 10:18am UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/15 "2018-10-17T10:18:57Z")

</div>

Yet, if that was the situation, it ought to have re perused the entire log in the wake of restarting moreover. For the situation when there are no new substance and the filebeat is restarted, it effectively does the activity of not sending anything to ES as it has officially sent the old log information.  
[https://www.assignmentprofs.co.uk/](https://www.assignmentprofs.co.uk/)

---

<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:** [November 14, 2018, 10:19am UTC](https://discuss.elastic.co/t/filebeat-sending-the-whole-log-again-after-stoping-and-starting-filebeat-container/150846/16 "2018-11-14T10:19:01Z")

</div>

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