[Filebeat] Prevent 'log' sending duplicate messages due to renaming by williamd67 · Pull Request #21911 · elastic/beats

williamd67 · 2020-10-16T15:26:55Z

Input:Log: Reset TTL of registry state when a file is renamed. In some
rare cases the registry state is marked for removal (TTL is set to 0)
while the file is only renamed. Log detects the renaming of the file
and updates the name of the file. As the file still exists it should
also update the TTL of the renamed file.

filebeat.yml.txt

I tried to add label 'bug' but have no idea how to do that.

What does this PR do?

This PR prevents in some rare cases that messages are resent by filebeat:input:log. The scenarios are written in the 'why is it important'-section. It copies the TTL of the registry state of a renamed file from newState to oldState as is done with the name.

Why is it important?

In some rare cases a log-file is marked as removed (TTL is set 0) while in fact the file is renamed.

This issue has been noticed in two similar yet different scenarios:

harvester is inactive and file is renamed; which means that registry state is marked as 'Finished'
harvester was and has been active since the renaming the file; which means that source of registry state still points to the original file name

Issue 1
In case renaming of the log-file happens after scanning but before removal-test, and the original file is not recreated yet, the registry state is marked for removal (TTL is set to 0) as the harvester is finished and the file pointed to by the source of the registry state (the original file) does not exist.

Issue 2
In this case the source of the registry state still points to the original file (updating the registry state has been postponed). In case the close-event of the harvester (per example inactive or timeout) happens after scanning but before removal-test, the registry state is marked for removal (TTL is set to 0) as the harvester is finished, and the file pointed by source of the registry state (original file) does not match the registry state itself (as the content points to the already renamed file).

In both cases will the renaming of the file be detected in the next 'run' and the source of the registry state will be updated. Unfortunately is TTL (= 0) not updated. This results in the deletion of the registry state. In the 'run' after that the renamed file will be detected again by filebeat and seen as a new file (no registry state exists) and all messages will be resent.

This can be fixed by (re)setting the TTL of the renamed file (next to the name of the source). Also from a technical point-of-view this makes sense as the file does exists as it is just found in the scan.

Checklist

My code follows the style guidelines of this project
I have commented my code, particularly in hard-to-understand areas
I have made corresponding changes to the documentation
I have made corresponding change to the default configuration files
I have added tests that prove my fix is effective or that my feature works
I have added an entry in CHANGELOG.next.asciidoc or CHANGELOG-developer.next.asciidoc.

How to test this PR locally

The easiest way to test this is adjusting the code and adding a sleep (per example 4 seconds) between scan and the removal-test (Run-method of input.go) as that increases the chance that this will happen tremendously. Let filebeat scan a directory where files are constantly created and rotated. In that way I can reproduce this in 100% of the cases. I have attached my configuration file used for this test.

Use cases

In some rare cases prevent filebeat:input:log to resend logs while files are renamed (rotated).

Input:Log: Reset TTL of registry state when a file is renamed. In some rare cases the registry state is marked for removal (TTL is set to 0) while the file is only renamed. Log detects the renaming of the file and updates the name of the file. As the file still exists it should also update the TTL of the renamed file.

elasticmachine · 2020-10-16T15:26:57Z

Since this is a community submitted pull request, a Jenkins build has not been kicked off automatically. Can an Elastic organization member please verify the contents of this patch and then kick off a build manually?

elasticmachine · 2020-10-16T15:26:57Z

Since this is a community submitted pull request, a Jenkins build has not been kicked off automatically. Can an Elastic organization member please verify the contents of this patch and then kick off a build manually?

cla-checker-service · 2020-10-16T15:26:59Z

💚 CLA has been signed

elasticmachine · 2020-10-16T15:31:22Z

💚 Build Succeeded

the below badges are clickable and redirect to their specific view in the CI or DOCS

Expand to view the summary

Build stats

Build Cause: [kvch commented: jenkins run tests]
Start Time: 2020-10-21T10:28:40.991+0000
Duration: 63 min 17 sec

Test stats 🧪

Test	Results
Failed	0
Passed	4474
Skipped	561
Total	5035

elasticmachine · 2020-10-17T10:41:12Z

Pinging @elastic/integrations-services (Team:Services)

kvch · 2020-10-21T10:28:11Z

jenkins run tests

…ter-commit * upstream/master: [Ingest Manager] Use ML_SYSTEM to detect if agent is running as a service (elastic#21884) Prevent log input from sending duplicate messages due to file renaming (elastic#21911)

* upstream/master: (27 commits) chore: use ubuntu 18 as linux agent (elastic#22084) docs: Prepare Changelog for 7.9.3 (elastic#22073) (elastic#22075) docs: Prepare Changelog for 6.8.13 (elastic#22072) (elastic#22079) [build][packaging] Add resilience when docker build (elastic#22050) Fix the url of reviewdog (elastic#21981) revert WSS process reporting for windows (elastic#22055) Fix typo (elastic#19585) (elastic#22061) [Ingest Manager] Use ML_SYSTEM to detect if agent is running as a service (elastic#21884) Prevent log input from sending duplicate messages due to file renaming (elastic#21911) feat: package aliases for snapshots (elastic#21960) [DOC] Add firewall as possible troubleshooting issue (elastic#21743) [Filebeat] Add max_number_of_messages config parameter for S3 input (elastic#21993) [Elastic Agent] Fix missing elastic_agent event data (elastic#21994) Document auditbeat system process module config (elastic#21766) Update links (elastic#22012) dynamically find librpm (elastic#21936) Fix Istio docs (elastic#22019) [beats-tester][packaging] store packages in another location (elastic#21903) [Kubernetes] Remove redundant dockersock volume mount (elastic#22009) [Ingest Manager] Always try snapshot repo for agent upgrade (elastic#21951) ...

elastic#21911) Input:Log: Reset TTL of registry state when a file is renamed. In some rare cases the registry state is marked for removal (TTL is set to 0) while the file is only renamed. Log detects the renaming of the file and updates the name of the file. As the file still exists it should also update the TTL of the renamed file. (cherry picked from commit bb50d32)

#21911) (#23743) Input:Log: Reset TTL of registry state when a file is renamed. In some rare cases the registry state is marked for removal (TTL is set to 0) while the file is only renamed. Log detects the renaming of the file and updates the name of the file. As the file still exists it should also update the TTL of the renamed file. (cherry picked from commit bb50d32) Co-authored-by: William Deurwaarder <william.git@xs4all.nl>

#21911) (#23744) Input:Log: Reset TTL of registry state when a file is renamed. In some rare cases the registry state is marked for removal (TTL is set to 0) while the file is only renamed. Log detects the renaming of the file and updates the name of the file. As the file still exists it should also update the TTL of the renamed file. (cherry picked from commit bb50d32) Co-authored-by: William Deurwaarder <william.git@xs4all.nl>

#21911) (#23745) Input:Log: Reset TTL of registry state when a file is renamed. In some rare cases the registry state is marked for removal (TTL is set to 0) while the file is only renamed. Log detects the renaming of the file and updates the name of the file. As the file still exists it should also update the TTL of the renamed file. (cherry picked from commit bb50d32) Co-authored-by: William Deurwaarder <william.git@xs4all.nl>

elastic#21911) (elastic#23745) Input:Log: Reset TTL of registry state when a file is renamed. In some rare cases the registry state is marked for removal (TTL is set to 0) while the file is only renamed. Log detects the renaming of the file and updates the name of the file. As the file still exists it should also update the TTL of the renamed file. (cherry picked from commit 7d6c6fe) Co-authored-by: William Deurwaarder <william.git@xs4all.nl>

botelastic bot added the needs_team Indicates that the issue/PR needs a Team:* label label Oct 16, 2020

andresrc added the Team:Services (Deprecated) Label for the former Integrations-Services team label Oct 17, 2020

botelastic bot removed the needs_team Indicates that the issue/PR needs a Team:* label label Oct 17, 2020

andresrc assigned kvch Oct 20, 2020

kvch approved these changes Oct 21, 2020

View reviewed changes

kvch merged commit bb50d32 into elastic:master Oct 21, 2020

kvch added the needs_backport PR is waiting to be backported to other branches. label Oct 21, 2020

jsoriano mentioned this pull request Jan 28, 2021

Cherry-pick #21911 to 7.x: [Filebeat] Prevent 'log' sending duplicate messages due to renaming #23743

Merged

6 tasks

jsoriano added v7.12.0 and removed needs_backport PR is waiting to be backported to other branches. labels Jan 28, 2021

jsoriano mentioned this pull request Jan 28, 2021

Cherry-pick #21911 to 7.11: [Filebeat] Prevent 'log' sending duplicate messages due to renaming #23744

Merged

6 tasks

jsoriano added the v7.11.0 label Jan 28, 2021

jsoriano mentioned this pull request Jan 28, 2021

Cherry-pick #21911 to 7.10: [Filebeat] Prevent 'log' sending duplicate messages due to renaming #23745

Merged

6 tasks

jsoriano added the v7.10.3 label Jan 28, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Filebeat] Prevent 'log' sending duplicate messages due to renaming#21911

[Filebeat] Prevent 'log' sending duplicate messages due to renaming#21911
kvch merged 1 commit intoelastic:masterfrom
williamd67:filebeat-log-prevent-duplicate-messages

williamd67 commented Oct 16, 2020 •

edited

Loading

Uh oh!

elasticmachine commented Oct 16, 2020

Uh oh!

elasticmachine commented Oct 16, 2020

Uh oh!

cla-checker-service bot commented Oct 16, 2020 •

edited

Loading

Uh oh!

elasticmachine commented Oct 16, 2020 •

edited by jenkins-beats-ci bot

Loading

Build stats

Test stats 🧪

Uh oh!

elasticmachine commented Oct 17, 2020

Uh oh!

kvch commented Oct 21, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

Conversation

williamd67 commented Oct 16, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

What does this PR do?

Why is it important?

Checklist

How to test this PR locally

Use cases

Uh oh!

elasticmachine commented Oct 16, 2020

Uh oh!

elasticmachine commented Oct 16, 2020

Uh oh!

cla-checker-service bot commented Oct 16, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

elasticmachine commented Oct 16, 2020 • edited by jenkins-beats-ci bot Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

💚 Build Succeeded

Build stats

Test stats 🧪

Uh oh!

elasticmachine commented Oct 17, 2020

Uh oh!

kvch commented Oct 21, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

williamd67 commented Oct 16, 2020 •

edited

Loading

cla-checker-service bot commented Oct 16, 2020 •

edited

Loading

elasticmachine commented Oct 16, 2020 •

edited by jenkins-beats-ci bot

Loading