Skip to content

Read mode cleanup causes crash when sincedb_cleanup_after is low (under a second) #272

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
Closed
jsvd opened this issue May 13, 2020 · 2 comments · Fixed by #273
Closed

Read mode cleanup causes crash when sincedb_cleanup_after is low (under a second) #272

jsvd opened this issue May 13, 2020 · 2 comments · Fixed by #273
Assignees
@andsel
Labels
bug

Comments

@jsvd
Copy link
Member

jsvd commented May 13, 2020

Since file input 4.1.18 there seems to be an error in read mode related to cleanup:

[2020-05-08T15:20:38,216][ERROR][logstash.pipeline        ] A plugin had an unrecoverable error. Will restart this plugin.
  Pipeline_id:trend
  Plugin: <LogStash::Inputs::File mode=>"read", path=>["*REDACTED*"], codec=><LogStash::Codecs::JSON id=>"", enable_metric=>true, charset=>"UTF-8">, sincedb_clean_after=>1.0e-05, id=>"", sincedb_path=>"*REDACTED*", file_completed_action=>"log_and_delete", file_completed_log_path=>"*REDACTED*", enable_metric=>true, stat_interval=>1.0, discover_interval=>15, sincedb_write_interval=>15.0, start_position=>"end", delimiter=>"\n", close_older=>3600.0, file_chunk_size=>32768, file_chunk_count=>140737488355327, file_sort_by=>"last_modified", file_sort_direction=>"asc", exit_after_read=>false, check_archive_validity=>false>
  Error: undefined method `reading_completed' for nil:NilClass
  Exception: NoMethodError
  Stack: /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.0/lib/filewatch/sincedb_collection.rb:167:in `reading_completed'
/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.0/lib/filewatch/read_mode/handlers/read_file.rb:22:in `handle_specifically'
/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.0/lib/filewatch/read_mode/handlers/base.rb:26:in `handle'
/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.0/lib/filewatch/read_mode/processor.rb:21:in `read_file'
/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.0/lib/filewatch/read_mode/processor.rb:90:in `block in process_active'
org/jruby/RubyArray.java:1792:in `each'
/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.0/lib/filewatch/read_mode/processor.rb:73:in `process_active'
/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.0/lib/filewatch/read_mode/processor.rb:31:in `process_all_states'
/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.0/lib/filewatch/watch.rb:67:in `iterate_on_state'
/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.0/lib/filewatch/watch.rb:44:in `subscribe'
/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.0/lib/filewatch/observing_read.rb:12:in `subscribe'
/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.0/lib/logstash/inputs/file.rb:364:in `run'
/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:426:in `inputworker'
/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:420:in `block in start_input'
@jsvd jsvd added the bug label May 13, 2020
@andsel andsel self-assigned this May 13, 2020
@jsvd
Copy link
Member Author

jsvd commented May 13, 2020

This seems to occur only. when sincedb_clean_after is very low, likely triggering a race condition. Setting this to "1 second" or higher doesn't seem to reproduce, only in the millisecond range.

@jsvd jsvd changed the title Read mode cleanup causes crash since 4.1.18 Read mode cleanup causes crash when sincedb_cleanup_after is low (under a second) May 13, 2020
andsel added a commit to andsel/logstash-input-file that referenced this issue May 13, 2020
@andsel
Fix: avoid refering a SincedbValue when it's not present in SincedbCo…
f68075d 
…llection

If the value of the setting `sincedb_clean_after` is too short (1 ms) it happens that during the content reading loop (in read mode) the loops itself trigger the cleanup of the same value from the SincedbCollection and then it
also try to access it again creating an error.
This commit resolves the problem guarding against the presence in the sincebd_collection before accessing it.

Fixes: logstash-plugins#272
@andsel andsel mentioned this issue May 13, 2020
Merged
@andsel
Copy link
Contributor

andsel commented May 13, 2020

The problem is avoided if the sincedb_clean_after is greater than the time needed to read the file.

@jsvd jsvd mentioned this issue Jul 3, 2020
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@andsel andsel

Labels
bug
Projects
None yet
Milestone
No milestone
2 participants
@jsvd @andsel