Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

restarting prior to clean_inactive threshold breach results in errors: ERR State for ****** should have been dropped #2818

Closed
jb4x opened this issue Oct 20, 2016 · 7 comments
Closed

restarting prior to clean_inactive threshold breach results in errors: ERR State for ****** should have been dropped #2818

jb4x opened this issue Oct 20, 2016 · 7 comments
Labels
bug Filebeat Filebeat

Comments

@jb4x
Copy link

jb4x commented Oct 20, 2016 •
edited
Loading

Please post all questions and issues on https://discuss.elastic.co/c/beats
before opening a Github Issue. Your questions will reach a wider audience there,
and if we confirm that there is a bug, then you can open a new issue.

For confirmed bugs, please report:

  • Version: filebeat-5.0.0-beta1
  • Operating System: os/x and redhat
  • Steps to Reproduce:

A. populate this data(or something else, presumably) into some files :

Oct 19 08:31:02 server4 snort: alert_multiple_requests: ACTIVE
Oct 19 08:31:02 server4 snort: telnet_decode arguments:
Oct 19 08:31:02 server4 snort: snort startup succeeded
Oct 19 08:31:02 server4 snort: Ports to decode telnet on: 21 23 25 119
Oct 19 08:31:03 server4 snort: Snort initialization completed successfully

My files were like this, and the timestamp of course changed to current time for filebeat_test_1.log - filebeat_test_3.log.

B. Process these files with filebeat using a yml similar to this(change the paths):


filebeat:
  prospectors:
    -
      paths:
        - /input/filebeat_test*.log
      tags: ["filebeat"]
      scan_frequency: 10s
      close_inactive: 1m
      ignore_older: 2m
      clean_inactive: 3m
      document_type: "feed_filebeat_test"  

registry_file: /path/to/my_registry

output:

  file:
    path: "/path/to/output"
    filename: filebeat
    rotate_every_kb: 1000
    number_of_files: 7

  to_files: true

    path: /var/log 
    rotateeverybytes: 104857600
    keepfiles: 7
  level: debug

C. Wait a bit, until you see we've still got state, but have breached ignore_older. Like these lines:

2016-10-20T09:55:44-07:00 DBG  Check file for harvesting: /input/filebeat_test_1.log
2016-10-20T09:55:44-07:00 DBG  Ignore file because ignore_older reached: /input/filebeat_test_1.log
2016-10-20T09:55:44-07:00 DBG  Check file for harvesting: /input/filebeat_test_2.log
2016-10-20T09:55:44-07:00 DBG  Ignore file because ignore_older reached: /input/filebeat_test_2.log
2016-10-20T09:55:44-07:00 DBG  Check file for harvesting: /input/filebeat_test_3.log
2016-10-20T09:55:44-07:00 DBG  Ignore file because ignore_older reached: /input/filebeat_test_3.log
2016-10-20T09:55:44-07:00 DBG  Prospector states cleaned up. Before: 3, After: 3

D. Stop filebeat

E. Add a new file like filebeat_test_4.log, same as 1-3.

F. Start filebeat, and on startup in the log, we should see:

2016-10-20T10:06:51-07:00 ERR State for /input/filebeat_test_1.log should have been dropped, but couldn't as state is not finished.
2016-10-20T10:06:51-07:00 ERR State for /input/filebeat_test_2.log should have been dropped, but couldn't as state is not finished.
2016-10-20T10:06:51-07:00 ERR State for /input/filebeat_test_3.log should have been dropped, but couldn't as state is not finished.

It doesn't seem to stop any data from flowing or do anything other than generating this message, but should probably be corrected.
@tsg tsg added bug Filebeat Filebeat labels Oct 20, 2016
@alexef
Copy link

alexef commented Oct 24, 2016

We're also seeing this, after upgrading from 1.2 to 5.0-beta, with an inconsistent registry file.

@ruflin
Copy link
Contributor

ruflin commented Oct 24, 2016

I managed to create a test to reproduce this. Step E. is the one that causes it. Now investigating on what exactly is happening. Will keep you posted.

ruflin added a commit to ruflin/beats that referenced this issue Oct 24, 2016
@ruflin
Fix state loading in case a state falls under ignore_older after restart
336c189 
Filebeat sets all states by default to Finished: false. On loading states during restart from the registry file, all prospector states are set to Finished: true on setup. These initial updates were not propagated to the registry file which had the effect, that the registry file was having a states with Finished: false until an update came from the prospector. This is now changed in the way that on Init each prospector sends an update to the registry for all states read. To be on the save side for the TTL which could have experied during a restart or that the clean_* config option was changed during restart, the TTL is reset and only overwritten afterwards again in updateState of the propsector before sending the event.

Closes elastic#2818
@ruflin ruflin mentioned this issue Oct 24, 2016
Merged
@ruflin
Copy link
Contributor

ruflin commented Oct 24, 2016

@alexef @jb4x A fix for this issue is provided here: #2830

ruflin added a commit to ruflin/beats that referenced this issue Oct 24, 2016
@ruflin
Fix state loading in case a state falls under ignore_older after restart
e196e57 
Filebeat sets all states by default to Finished: false. On loading states during restart from the registry file, all prospector states are set to Finished: true on setup. These initial updates were not propagated to the registry file which had the effect, that the registry file was having a states with Finished: false until an update came from the prospector. This is now changed in the way that on Init each prospector sends an update to the registry for all states read. To be on the save side for the TTL which could have experied during a restart or that the clean_* config option was changed during restart, the TTL is reset and only overwritten afterwards again in updateState of the propsector before sending the event.

Closes elastic#2818

(cherry picked from commit 336c189)
tsg pushed a commit that referenced this issue Oct 24, 2016
@ruflin @tsg
Fix state loading in case a state falls under ignore_older after rest…
287f851 
…art (#2832)

Filebeat sets all states by default to Finished: false. On loading states during restart from the registry file, all prospector states are set to Finished: true on setup. These initial updates were not propagated to the registry file which had the effect, that the registry file was having a states with Finished: false until an update came from the prospector. This is now changed in the way that on Init each prospector sends an update to the registry for all states read. To be on the save side for the TTL which could have experied during a restart or that the clean_* config option was changed during restart, the TTL is reset and only overwritten afterwards again in updateState of the propsector before sending the event.

Closes #2818

(cherry picked from commit 336c189)
@tsg tsg closed this as completed in #2830 Oct 24, 2016
tsg pushed a commit that referenced this issue Oct 24, 2016
@ruflin @tsg
Fix state loading in case a state falls under ignore_older after rest…
d6ddf66 
…art (#2830)

Filebeat sets all states by default to Finished: false. On loading states during restart from the registry file, all prospector states are set to Finished: true on setup. These initial updates were not propagated to the registry file which had the effect, that the registry file was having a states with Finished: false until an update came from the prospector. This is now changed in the way that on Init each prospector sends an update to the registry for all states read. To be on the save side for the TTL which could have experied during a restart or that the clean_* config option was changed during restart, the TTL is reset and only overwritten afterwards again in updateState of the propsector before sending the event.

Closes #2818
@ruflin
Copy link
Contributor

ruflin commented Oct 25, 2016

@jb4x @alexef It would be interesting to get your feedback on this change here as you both had issues with states in the past: #2840

@alexef
Copy link

alexef commented Oct 25, 2016

@ruflin any chance for a -rc2 binary release? it will really help with testing, as we don't have a proper go environment to build filebeat ourselves (yet).

@ruflin
Copy link
Contributor

ruflin commented Oct 25, 2016

@alexef You can try out the nightly builds here: https://beats-nightlies.s3.amazonaws.com/index.html?prefix=filebeat/ They are almost identical to the 5.0 release.

@ruflin
Copy link
Contributor

ruflin commented Oct 25, 2016

For the 5.0 builds:

https://snapshots.elastic.co/downloads/beats/filebeat/filebeat-5.0.0-SNAPSHOT-amd64.deb
https://snapshots.elastic.co/downloads/beats/filebeat/filebeat-5.0.0-SNAPSHOT-darwin-x86_64.tar.gz
https://snapshots.elastic.co/downloads/beats/filebeat/filebeat-5.0.0-SNAPSHOT-i386.deb
https://snapshots.elastic.co/downloads/beats/filebeat/filebeat-5.0.0-SNAPSHOT-i686.rpm
https://snapshots.elastic.co/downloads/beats/filebeat/filebeat-5.0.0-SNAPSHOT-linux-x86.tar.gz
https://snapshots.elastic.co/downloads/beats/filebeat/filebeat-5.0.0-SNAPSHOT-linux-x86_64.tar.gz
https://snapshots.elastic.co/downloads/beats/filebeat/filebeat-5.0.0-SNAPSHOT-windows-x86.zip
https://snapshots.elastic.co/downloads/beats/filebeat/filebeat-5.0.0-SNAPSHOT-windows-x86_64.zip
https://snapshots.elastic.co/downloads/beats/filebeat/filebeat-5.0.0-SNAPSHOT-x86_64.rpm

@tsg tsg mentioned this issue Nov 14, 2016
Merged
tsg pushed a commit to tsg/beats that referenced this issue Nov 15, 2016
Fix changelog for 5.0.1/5.0.0
8b69c02 
The elastic#2818 fix actually got in 5.0.0, so move the changelog entry around.
ruflin pushed a commit that referenced this issue Nov 15, 2016
@tsg @ruflin
Fix changelog for 5.0.1/5.0.0 (#2992)
0f28859 
The #2818 fix actually got in 5.0.0, so move the changelog entry around.
leweafan pushed a commit to leweafan/beats that referenced this issue Apr 28, 2023
@ruflin @tsg
Fix state loading in case a state falls under ignore_older after rest…
0954905 
…art (elastic#2832)

Filebeat sets all states by default to Finished: false. On loading states during restart from the registry file, all prospector states are set to Finished: true on setup. These initial updates were not propagated to the registry file which had the effect, that the registry file was having a states with Finished: false until an update came from the prospector. This is now changed in the way that on Init each prospector sends an update to the registry for all states read. To be on the save side for the TTL which could have experied during a restart or that the clean_* config option was changed during restart, the TTL is reset and only overwritten afterwards again in updateState of the propsector before sending the event.

Closes elastic#2818

(cherry picked from commit 336c189)
leweafan pushed a commit to leweafan/beats that referenced this issue Apr 28, 2023
@tsg @ruflin
Fix changelog for 5.0.1/5.0.0 (elastic#2992)
90c2362 
The elastic#2818 fix actually got in 5.0.0, so move the changelog entry around.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Filebeat Filebeat
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@tsg @ruflin @alexef @jb4x