logstash-plugins/logstash-input-file

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

jsvd opened this issue · 2 comments

jsvd commented

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 commented

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.

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