About clean_removed in Filebeat 5.0.0-alpha5


#1

Filebeat config:

filebeat:
prospectors:
-
paths:
- /var/log/applog/app_*.log
input_type: log
document_type: applog
ignore_older: 2m
close_eof: true
clean_inactive: 5m
close_removed: true
clean_removed: true

After I created app_0.log in /var/log/applog/ , I could see log:

2016-09-07T19:52:18+08:00 INFO End of file reached: /var/log/applog/app_0.log. Closing because close_eof is enabled.

Then I deleted app_0.log, but app_0.log was still in registry file.
I guess it's affected by close_eof config. So in this case how can I clean the state of removed file?

And more, when I created many file like app_0.log again and then deleted them , these ERR log appeared continuously:

2016-09-07T20:08:48+08:00 ERR State for /var/log/applog/app_0.log should have been dropped, but couldn't as state is not finished.

And there's also log like this:

2016-09-07T20:25:40+08:00 ERR File is falling under ignore_older before harvesting is finished. Adjust your close_* settings

Shouldn't these ERR logs stop printing again and again ?


#2

About this ERR log:

2016-09-07T20:25:40+08:00 ERR File is falling under ignore_older before harvesting is finished. Adjust your close_* settings

I got your explain at Filebeat Stop Cleaning Registry :

The first error is shown, in case a file did not finish harvesting yet but already falls under ignore_older. This can for example happen when a file is not updated anymore, but the harvester can't finish reading it as the output is not available or too slow. As soon as the output catches up, the file will be closed and ignored.

But in my case, the ERR log is appeared when start filebeat, the file should not begin harvesting, not "in case a file did not finish harvesting yet " .


#3

After I delete clean_removed config from filebeat:

filebeat:
prospectors:

paths:

  • /var/log/applog/app_*.log
    input_type: log
    document_type: applog
    ignore_older: 2m
    close_eof: true
    clean_inactive: 5m

clean_inactive worked as expected, but when file state is cleaned from registry, these ERR log begin be printed continusly:

2016-09-07T23:16:17+08:00 ERR File is falling under ignore_older before harvesting is finished. Adjust your close_* settings:

After I deleted the file which was already cleaned from registry, the ERR log never appeared.


(ruflin) #4

Thanks for all the details. Some comments

  • ignore_older applies to the modification date of the file. So if you file is 1:59 minutes last modified on startup, harvester will open it and start harvesting it, then ignore_older is going to start complain the next second. As soon as close_eof is reached, it should be ignored in the next scan
  • You mention that it should have never started harvesting. So on startup the file was already older then ignore_older? Strangely on startup all files are (should) be set to finished. Can you share some more log outputs (all lines?)
  • What is the way your logs are rotated?
  • What do you mean by you deleted it from the registry? You manually edited the registry?
  • Could you check the nightly build if you still see the same issue? https://beats-nightlies.s3.amazonaws.com/index.html?prefix=filebeat/

If you find a way to reliably reproduce the above that would be great.


#5

•You mention that it should have never started harvesting. So on startup the file was already older then ignore_older? --yes. Strangely on startup all files are (should) be set to finished. --I have lots of history files, and I just need lastest 2h files. Can you share some more log outputs (all lines?) --Filebeat log file was full of ERR log like this:

2016-09-07T23:16:17+08:00 ERR File is falling under ignore_older before harvesting is finished. Adjust your close_* settings:

•What is the way your logs are rotated?
--It's just lots of 10M size files. All the files are only written once and not updated from time to time.

•What do you mean by you deleted it from the registry? You manually edited the registry?
--I mean I deleted the log file, not deleted the state of file from registry.

The problem I most want to solve is why so many ERR logs in /var/log/filebeat/filebeat and how should I avoid it?

I'm re describing the problem :
Filebeat Config:

filebeat:
prospectors:

paths:

  • /var/log/applog/app_*.log
    input_type: log
    document_type: applog
    ignore_older: 2h
    close_inactive: 5m
    clean_inactive: 4h

Under /var/log/applog/ there were lots of history files, most were modified before 2h.
And I deleted /var/lib/filebeat/registry before start filebeat.
As a result, /var/log/filebeat/filebeat was full of these ERR logs:

2016-09-07T23:16:17+08:00 ERR File is falling under ignore_older before harvesting is finished. Adjust your close_* settings:


(Marc MAURICE) #6

Hello,
I'm getting the same Error, with a prospector with similar config:

paths:
- /var/www/magento/var/report/*
input_type: log
document_type: magento_report
fields:
environment: test
fields_under_root: true
ignore_older: 24h
clean_inactive: 25h

Log sending seems to work fine though. just my filebeat.log being a few megas because of this error.


(ruflin) #7

The error both of you mentioned happens in the following case:

  • Prospector or harvester detected that a file meets one of the close_* criterias and marks the state to be removed
  • Registrar tries to remove the state but harvester is still running, so state is not removed as otherwise the file would be started reading again from the beginning

@vin Do you see this problem only when you startup with old files and the errors disappear after some time or the errors are constant? I'm thinking if perhaps at the first run filebeat somehow opens also ignore_older files somehow (which should not be the case). I'm currently investigating this.

@dooblem What is the exact version you are using? Can you also share some more details on your log rotation?


(ruflin) #8

As a heads up: I think I managed to reproduce the issue. So far it seems like mainly a logging issue but I need to do some more investigations. I keep you posted.


(ruflin) #9

Here is the PR to fix this issue: https://github.com/elastic/beats/pull/2517 It seems like the issue was only related to logging. Thanks a lot for helping to find this issue. I will ping you as soon as a snapshot build with the fix is available.

@vin In your first post you also mentioned you have issue with the following error:

ERR State for /var/log/applog/app_0.log should have been dropped, but couldn't as state is not finished.

Is this error also printed again and again or does it disappear after the first time?


(Marc MAURICE) #10

Hello @ruflin .
Thanks a lot.
I' using Filebeat 5.0.0-alpha5. Remember Can Filebeat watch for new files created in a directory? :slight_smile: ?

Log files are created but not removed. I just want old files to be ignored.
Let me know if you need more info.

It will be hard for me to test, unless you release another alpha6 .deb...

Thanks in advance !


#11

@ruflin
I reproduced the issue I mentioned in my first post, it happend in this situation:

  1. The state of app_0.log and app_1.log was exist in registry file, but app_0.log was deleted.(Indeed I upgraded filebeat from 1.2.3)

  2. I started filebeat and these ERR logs came out: (which u already confirmed as a logging issue)

ERR File is falling under ignore_older before harvesting is finished. Adjust your close_* settings:

  1. With the config clean_removed: true , the state of removed file was still in registry.

  2. And after clean_inactive(which is 5m), the state of inactive file was still in registry.

  3. Then I created a file app_2.log , these logs occured:

INFO Harvester started for file: /var/log/app_2.log
...
ERR State for /var/log/app_0.log should have been dropped, but couldn't as state is not finished.


(ruflin) #12

Fix should be available in the next hours in the snapshot build as it got merged: https://beats-nightlies.s3.amazonaws.com/index.html?prefix=filebeat/

@dooblem No chance to remember all names with filebeat versions :wink:


(ruflin) #13

@vin Can you try to do the same again with filebeat 5.0 only from the latest snapshot to see if this still happens?


#14

@ruflin It's not easy for me to do the test with the nightly build filebeat, I can't open the url from my domain network. sorry...


(ruflin) #15

@vin I see. Alternative would be to build it from source yourself but that would require a Golang environment? Or you wait until we push beta1?


(system) #16

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