Periodically updated log file

ahirri · January 26, 2018, 3:42pm

Hello

We're using FileBeat 5.6.5 to handle a specific application logs. This log file is updated every 15 minutes using SSH mirror: every 15 minutes, the file is replaced with a new one from a remote server.
FileBeat do not detect any change on the file, even that the FB logs show "Harvester started for file..." few seconds after the file is updated.
I've tried to set inactive close to 20 minutes, but it didn't fix the problem!
Could you give any help please?

BR

lauea · January 26, 2018, 3:48pm

@ahirri
Could you help provide below:

Detailed log of filebeat
Register file of filebeart, generally in: /var/lib/filebeat/register
The log file attribute between pre-updated and updated. like : ls -ltr file.log

ahirri · January 26, 2018, 4:09pm

@lauea thank you for your quick answer.

Filebeat logs: see below (I've changed the file name in the logs)
Register file: I do not have an access on this file! if it's required I can ask the to get an access on it
Log file attributes remains the same after the update: -rw-r--r-- 1 logs logs 62925330 Jan 26 16:44 wsAccess.log (Filebeat is started by the root user)

2018-01-26T16:45:06+01:00 INFO Harvester started for file: /home/logs/wsAccess.log 2018-01-26T16:45:36+01:00 INFO Non-zero metrics in the last 30s: filebeat.harvester.open_files=1 filebeat.harvester.running=1 filebeat.harvester.started=1 libbeat.logstash.call_count.Publ ishEvents=5 libbeat.logstash.publish.read_bytes=30 libbeat.logstash.publish.write_bytes=93978 libbeat.logstash.published_and_acked_events=193 libbeat.publisher.published_events=193 publis h.events=313 registrar.states.update=313 registrar.writes=5 2018-01-26T16:46:06+01:00 INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=4 libbeat.logstash.publish.read_bytes=24 libbeat.logstash.publish.write_bytes=14 13 libbeat.logstash.published_and_acked_events=5 libbeat.publisher.published_events=5 publish.events=5 registrar.states.update=5 registrar.writes=4 2018-01-26T16:46:36+01:00 INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=4 libbeat.logstash.publish.read_bytes=24 libbeat.logstash.publish.write_bytes=14 42 libbeat.logstash.published_and_acked_events=5 libbeat.publisher.published_events=5 publish.events=5 registrar.states.update=5 registrar.writes=4 2018-01-26T16:47:06+01:00 INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=5 libbeat.logstash.publish.read_bytes=30 libbeat.logstash.publish.write_bytes=17 46 libbeat.logstash.published_and_acked_events=6 libbeat.publisher.published_events=6 publish.events=6 registrar.states.update=6 registrar.writes=5 2018-01-26T16:47:36+01:00 INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=3 libbeat.logstash.publish.read_bytes=18 libbeat.logstash.publish.write_bytes=10 35 libbeat.logstash.published_and_acked_events=3 libbeat.publisher.published_events=3 publish.events=3 registrar.states.update=3 registrar.writes=3 2018-01-26T16:48:06+01:00 INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=4 libbeat.logstash.publish.read_bytes=24 libbeat.logstash.publish.write_bytes=13 42 libbeat.logstash.published_and_acked_events=5 libbeat.publisher.published_events=5 publish.events=5 registrar.states.update=5 registrar.writes=4 2018-01-26T16:48:06+01:00 INFO Stopping 0 runners ... 2018-01-26T16:48:06+01:00 INFO Starting 0 runners ... 2018-01-26T16:48:36+01:00 INFO Non-zero metrics in the last 30s: libbeat.config.reloads=1 libbeat.logstash.call_count.PublishEvents=5 libbeat.logstash.publish.read_bytes=30 libbeat.logsta sh.publish.write_bytes=1899 libbeat.logstash.published_and_acked_events=8 libbeat.publisher.published_events=8 publish.events=8 registrar.states.update=8 registrar.writes=5 2018-01-26T16:49:06+01:00 INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=4 libbeat.logstash.publish.read_bytes=24 libbeat.logstash.publish.write_bytes=14 25 libbeat.logstash.published_and_acked_events=5 libbeat.publisher.published_events=5 publish.events=5 registrar.states.update=5 registrar.writes=4 2018-01-26T16:49:36+01:00 INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=4 libbeat.logstash.publish.read_bytes=24 libbeat.logstash.publish.write_bytes=1455 libbeat.logstash.published_and_acked_events=5 libbeat.publisher.published_events=5 publish.events=5 registrar.states.update=5 registrar.writes=4 2018-01-26T16:50:06+01:00 INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=5 libbeat.logstash.publish.read_bytes=30 libbeat.logstash.publish.write_bytes=1760 libbeat.logstash.published_and_acked_events=6 libbeat.publisher.published_events=6 publish.events=6 registrar.states.update=6 registrar.writes=5 2018-01-26T16:50:11+01:00 INFO File is inactive: /home/logs/wsAccess.log. Closing because close_inactive of 5m0s reached. 2018-01-26T16:50:36+01:00 INFO Non-zero metrics in the last 30s: filebeat.harvester.closed=1 filebeat.harvester.open_files=-1 filebeat.harvester.running=-1 libbeat.logstash.call_count.PublishEvents=3 libbeat.logstash.publish.read_bytes=18 libbeat.logstash.publish.write_bytes=1044 libbeat.logstash.published_and_acked_events=3 libbeat.publisher.published_events=3 publish.events=4 registrar.states.update=4 registrar.writes=4

BR

lauea · January 26, 2018, 4:16pm

@ahirri

Seems the log is related to log pre-updated. After wxAcess.log updated, what detailed FB log output?

By the way, for the register file, you can run below command :

sudo su -

to change current permission to get if you have sudo permission.

ahirri · January 26, 2018, 4:50pm

The logs I've shared occured just after the file update (16:45:00)
I do not have a permission to get the register file, I'm waiting to get it

BR

lauea · January 26, 2018, 4:57pm

@ahirri

Seem ignore_older(https://www.elastic.co/guide/en/beats/filebeat/5.6/configuration-filebeat-options.html#ignore-older) was not mentioned by you.
As you mentioned, update frequency should be 15 mins. so you can set configuration like below:

ignore_older: 40m
close_inactive: 20m

ahirri · January 30, 2018, 2:41pm

After adding the ignore_older and some other configurations, I managed to get it work. Now I can find my beats in the ES index.

However, the whole file is parsed and submitted every time the file is synchronized! I'm still working to fix this and I will try to share the solution (if I found one)

BR

steffens · January 30, 2018, 3:00pm

Please format logs, configs and terminal input/output using the </>-Button or markdown code fences. This forum uses Markdown to format posts. Without proper formatting, it can be very hard to read your posts.

The file is not synchronized, it is replaced with a very new file. The new files meta-data (e.g. inode) is different from the old file and filebeat assume it being a new file. As it is log-files you are processing, the sync should only append lines to an existing file. For syncing consider some tool like rsync+ssh (with --append or --append-verify args).

ahirri · January 31, 2018, 2:00pm

Thank you for your help. Indeed the file was replaced with a new one everytime.
We've managed the fix this by adding --inplace to the resync commande (I do not have the details, it has been done by unix guys)

BR

system · February 28, 2018, 2:03pm

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