Filebeat will output dumplication when logrotate happened


(叶善茂) #1

Hi, when I use filebeat to collect the log data. I found that the output file have many dumplications of a log entry. The log data is generated by a python script. Every log entry has a unique number and every 300 entries will trigger a logrotate. First, I start the filebeat, then run the script to generate the log. At last, I found that the 1-300 entries occuer once, 300-600 entries occure twice, 600-900 entries occure three times and so on.

following is my test data:
python script: https://github.com/shanmaoye/filebeat-test/blob/master/logrotate_test.py
filebeat debug level log: https://raw.githubusercontent.com/shanmaoye/filebeat-test/master/beat.log
the output of the filebeat: https://raw.githubusercontent.com/shanmaoye/filebeat-test/master/filebeat
filebeat configuation:

    filebeat:
        prospectors:
            -
                paths:
                    - /var/log/shanmao/shanmao.log
                    - /var/log/shanmao/shanmao.log.1
                input_type: log
                exclude_lines: ["^$"]
    output:
        file:
            path: "/tmp/filebeat"
            filename: filebeat
            rotate_every_kb: 100000
            number_of_files: 7
    shipper:

    logging:
        level: debug
        to_files: true
        files:
            path: /var/log/mybeat
            name: beat.log
            rotateeverybytes: 10485760

logrotate configuration:
/var/log/shanmao/shanmao.log
{
rotate 40
size 15k
missingok
notifempty
compress
delaycompress
}

my system info: ubuntu_14.04_64bit, version of the filebeat is 1.2.3


I wonder why does this happen? Is my configuration wrong? Thanks.

(ruflin) #2

Could you check fi you see the same behaviour with the most recent snapshot? https://beats-nightlies.s3.amazonaws.com/index.html?prefix=filebeat/ It can happen in the 1.x release that under heavy load and heavy file rotation some race conditions occur.


#3

Hi,
Just to be accurate - filebeat should not duplicate entries after log rotation happens? We are starting with ELK, have everything set up and sending the logs to ES and at the moment we are trying to log rotate every week. We are using Centos 7 logrotate with similar conf to OP. The only worrying part is if we rotate log and then tell filebeat to track both logs for 5 minutes to not loose any entries, will filebeat treat the rotate file production.log1 as a new log and will resend all the data to ES?


(Steffen Siering) #4

filebeat uses inodes to keep track if file identity. It will detect production.log1 being a renamed file (if inode didn't change, check with ls command) and will continue processing where it left of in case anything was missing. The newly created production.log should be processed from the very beginning.


(叶善茂) #5

I use filebeat-6.0.0-alpha1-SNAPSHOT-linux-x86_64.tar.gz to check as the above. But, I still see the same behaviour.


(叶善茂) #6

I think it will not resend the production.log.1 as a new log if you don't add it to the configuration of the filebeat. Because you can see the same source of the dumplication in the beat.log.


(ruflin) #7

As Steffen wrote, filebeat does track files by inode and not name. So if a file is rotated, data will not be resent as it still the same file.

@haha I'm still trying to figure out what goes wrong in your case especially that you mention you also see this under the 5.0 alpha snapshot. Any chance to post the debug log of the 5.0 run? How do you exactly start filebeat?


(叶善茂) #8

I'm sorry. I think my python script cause this problem. I use python logging module to write the log. At first, the filebeat get the right output with the logrotate. But the script write all log in the production.log.1. That, I think is a wrong way to use logging and logrotate. So , I change my script to close filehandler before logrotate and open a new filehandler after logrotate and get the above problem. Today, I try to use copytruncate in the logrotate and don't refresh the filehandler when logrotate. Then, I get the correct filebeat output.

So, I think my way to use logrotate and logging may not be suitable. Thank you for you help.


(ruflin) #9

We use Python for some of our system tests and use the internal Python log rotation feature: https://github.com/elastic/beats/blob/master/filebeat/tests/system/test_load.py#L40 This should automatically do the right thing. I didn't check your script in detail but you can check ours to see if there are some difference. If not needed, I would stick with rotation instead of copytruncate as this can lead to data loss (as mentioned in the logrotate docs).


(system) #10

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