# Filebeat truncates output data

**URL:** <https://discuss.elastic.co/t/filebeat-truncates-output-data/210645>\
**Category:** Beats\
**Tags:** filebeat\
**Created:** [December 5, 2019, 8:40am UTC](https://discuss.elastic.co/t/filebeat-truncates-output-data/210645 "2019-12-05T08:40:25Z")\
**Posts on this page:** 9\
**Page:** 1

<div class="post-metadata">

**Author:** ![gappa](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/gappa/32/58815_2.png) [@gappa](https://discuss.elastic.co/u/gappa)\
**Post date:** [December 5, 2019, 8:40am UTC](https://discuss.elastic.co/t/filebeat-truncates-output-data/210645/1 "2019-12-05T08:40:25Z")

</div>

I'm using Filebeat 7.4.2 in order to read files from a directory. Each file contains valid json data line by line. Each json row within the file is read from filebeat then sent to a logstash (v7.4.2) instance that will send data to Elasticsearch (v7.4.2).

It comes that logstash prints every how an error log like the following:

```auto
[2019-12-05T09:05:16,378][WARN][logstash.filters.json][main] Error parsing json {:source=>"message", :raw=>"/www.super-bike.ch/it/caschi-modulari/21111-165734-ls2-ff313-vortex-solid-matt-carbon.html#/2-taglia-s?SubmitCurrency=1&id_currency=1\",\"image_path_locale\":\"wasabi_dragon/images_normalized/9430/73be873540f797cf0855ccb2c03b23575f46762df5e9b0cfb7b0f832fd2bd1a8.jpg\",\"image_path_cdn\":\"wasabi_dragon/images/9430/73be873540f797cf0855ccb2c03b23575f46762df5e9b0cfb7b0f832fd2bd1a8.jpg\"}", :exception=>#<LogStash::Json::ParserError: Unexpected character ('/' (code 47)): maybe a (non-standard) comment? (not recognized as one since Feature 'ALLOW_COMMENTS' not enabled for parser)

```

**It seems that the json is not valid because it has been truncated somewhere from someone.**  
Investigating, I found the original file that contains the line that causes the error. The file contains these two rows:

```
{"url":"https://www.demon-tweeks.com/uk/mishimoto-weighted-shift-knob-1147808/","image_path_locale":"wasabi_dragon/images_normalized/330763/f05af6261cf450c191e8740c677007e41d290d162eec3bf25ca0ce607b149603.jpg","image_path_cdn":"wasabi_dragon/images/330763/f05af6261cf450c191e8740c677007e41d290d162eec3bf25ca0ce607b149603.jpg"}
{"url":"https://www.super-bike.ch/it/caschi-modulari/21111-165734-ls2-ff313-vortex-solid-matt-carbon.html#/2-taglia-s?SubmitCurrency=1&id_currency=1","image_path_locale":"wasabi_dragon/images_normalized/9430/73be873540f797cf0855ccb2c03b23575f46762df5e9b0cfb7b0f832fd2bd1a8.jpg","image_path_cdn":"wasabi_dragon/images/9430/73be873540f797cf0855ccb2c03b23575f46762df5e9b0cfb7b0f832fd2bd1a8.jpg"}

```

Those rows are well formatted and the strange part is that if now I rename the file and put it in the Filebeat directory everything will work perfectly and data will reach Elasticsearch.

I have enabled debug mode for Filebeat and I found that the published message is wrong:

```
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: 2019-12-05T09:05:15.335+0100#011DEBUG#011[processors]#011processing/processors.go:183#011Publish event: {
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "@timestamp": "2019-12-05T08:05:15.335Z",
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "@metadata": {
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "beat": "filebeat",
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "type": "_doc",
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "version": "7.4.2"
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: },
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "message": "/www.super-bike.ch/it/caschi-modulari/21111-165734-ls2-ff313-vortex-solid-matt-carbon.html#/2-taglia-s?SubmitCurrency=1&id_currency=1\",\"image_path_locale\":\"wasabi_dragon/images_normalized/9430/73be873540f797cf0855ccb2c03b23575f46762df5e9b0cfb7b0f832fd2bd1a8.jpg\",\"image_path_cdn\":\"wasabi_dragon/images/9430/73be873540f797cf0855ccb2c03b23575f46762df5e9b0cfb7b0f832fd2bd1a8.jpg\"}",
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "log": {
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "offset": 367,
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "file": {
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "path": "/path/to/json/2019_12_5_9_5_25624.json"
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: }
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: },
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "fields": {
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "log_type": "stalker"
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: },
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "input": {
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "type": "log"
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: },
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "ecs": {
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "version": "1.1.0"
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: },
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "host": {
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "name": "ES-NVMe1"
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: },
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "agent": {
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "id": "651bec87-4a0e-4edb-b5e3-795d8fd54031",
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "version": "7.4.2",
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "type": "filebeat",
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "ephemeral_id": "92a2cfde-bb87-4cce-8ae6-8642e183b427",
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: "hostname": "ES-NVMe1"
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: }
Dec 5 09:05:15 ES-NVMe1 filebeat[1327]: }

```

So there is something wrong with Filebeat but it is not deterministic.  
Here the `filebeat.yml`:

```
filebeat.inputs:
- type: log
  close_eof: true
  paths:
    - /path/to/json/*
  fields: {log_type: stalker}

output.logstash:
  hosts: ["127.0.0.1:5043"]

logging.level: debug
logging.to_files: true
logging.to_syslog: false
logging.files:
  path: /var/log/filebeat
  name: mybeat.log
  keepfiles: 7

```

I cannot reproduce the error, it happens every how and I don't know why.  
Do you have any idea that helps me?  
Any other test to do?

Thanks  
Marco

---

<div class="post-metadata">

**Author:** ![Shaoranlaos](https://avatars.discourse-cdn.com/v4/letter/s/c57346/32.png) [@Shaoranlaos](https://discuss.elastic.co/u/Shaoranlaos)\
**Post date:** [December 5, 2019, 9:53am UTC](https://discuss.elastic.co/t/filebeat-truncates-output-data/210645/2 "2019-12-05T09:53:05Z")

</div>

I think the cullprit could be the config option `close_eof: true`. This option aborts the reading of the file when filebeat reaches an EOF (which happens continously when the file is written to live).  
Could you remove that one and try again?

---

<div class="post-metadata">

**Author:** ![gappa](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/gappa/32/58815_2.png) [@gappa](https://discuss.elastic.co/u/gappa)\
**Post date:** [December 5, 2019, 10:14am UTC](https://discuss.elastic.co/t/filebeat-truncates-output-data/210645/3 "2019-12-05T10:14:31Z")

</div>

thank you @Shaoranlaos for the answer.

I forgot to mention that each file is written and closed then moved to the filebeat's directory.  
Those files won't be opened again.

I have sat the `close_eof: true` yesterday in order to try this new option hoping that will solve my problem but it did not solve it.  
So that option does not cause the problem.

Before `close_eof` I used to have `close_inactive: 2m` option.

---

<div class="post-metadata">

**Author:** ![Shaoranlaos](https://avatars.discourse-cdn.com/v4/letter/s/c57346/32.png) [@Shaoranlaos](https://discuss.elastic.co/u/Shaoranlaos)\
**Post date:** [December 5, 2019, 10:23am UTC](https://discuss.elastic.co/t/filebeat-truncates-output-data/210645/4 "2019-12-05T10:23:27Z")

</div>

How are your files named?  
I had a similar Problem when the coping of the files reused the inode number of an older logfile which was not yet deleted from the filebeat registry and had the same name.  
I am not total sure which of the clean\_\* options had helped for me there (it was a year ago and the server has since than changed). I think it was `clean_inactive:` logrotation time e.g. 12h.

Info: Because the inode number is found in the registry filebeat infers it was only renamed and continues on the saved offset which can lead to such head truncated messages

---

<div class="post-metadata">

**Author:** ![Shaoranlaos](https://avatars.discourse-cdn.com/v4/letter/s/c57346/32.png) [@Shaoranlaos](https://discuss.elastic.co/u/Shaoranlaos)\
**Post date:** [December 5, 2019, 10:52am UTC](https://discuss.elastic.co/t/filebeat-truncates-output-data/210645/5 "2019-12-05T10:52:59Z")

</div>

P.S.: you can use `ls -i` to show the inode number of files to compare them before and after the copying  
P.S.2: Filebeat also compares the current saved offset with the length of the read file and if the file is shorter then the saved offset it will read the file from the beginning  
P.S.3: All of this would implie that all lines that come before this truncated line should be missing in your elasticsearch data.

---

<div class="post-metadata">

**Author:** ![gappa](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/gappa/32/58815_2.png) [@gappa](https://discuss.elastic.co/u/gappa)\
**Post date:** [December 5, 2019, 11:48am UTC](https://discuss.elastic.co/t/filebeat-truncates-output-data/210645/6 "2019-12-05T11:48:57Z")

</div>

The filename is formed like this:

`20191205081900492920-3019-IT-buffer.json => year/month/day/hours/minutes/seconds/milliseconds/randomNumber-country-buffer.json`

where randomNumber is something like this: `Math.floor(Math.random() * Math.floor(1000))`

any idea?

---

<div class="post-metadata">

**Author:** ![Shaoranlaos](https://avatars.discourse-cdn.com/v4/letter/s/c57346/32.png) [@Shaoranlaos](https://discuss.elastic.co/u/Shaoranlaos)\
**Post date:** [December 5, 2019, 12:11pm UTC](https://discuss.elastic.co/t/filebeat-truncates-output-data/210645/7 "2019-12-05T12:11:14Z")

</div>

Are you deleting logs in the folder? If yes could you compare the inode numbers of the deleted files with the inode number of the newly copied files? If they are the same a configuration of

```auto
ignore_older: 8h
clean_inactive: 12h

```

could solve it.  
You should change the timespans to something that is within the time of your deletion timespan, e.g.:  
deletion timespan: 18h  
ignore\_older: 8h  
clean\_inactive: 12h

see [https://www.elastic.co/guide/en/beats/filebeat/current/inode-reuse-issue.html](https://www.elastic.co/guide/en/beats/filebeat/current/inode-reuse-issue.html)

---

<div class="post-metadata">

**Author:** ![gappa](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/gappa/32/58815_2.png) [@gappa](https://discuss.elastic.co/u/gappa)\
**Post date:** [December 5, 2019, 1:25pm UTC](https://discuss.elastic.co/t/filebeat-truncates-output-data/210645/8 "2019-12-05T13:25:00Z")

</div>

thank you very much for all those information!

Actually, every day we remove the yesterday's files.  
I will give a try to your configuration and I have high expectations on that

Thank you 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:** [January 2, 2020, 1:25pm UTC](https://discuss.elastic.co/t/filebeat-truncates-output-data/210645/9 "2020-01-02T13:25:03Z")

</div>

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