From e2d37fb93430b31817cb2ff9900612c14b8149dc Mon Sep 17 00:00:00 2001 From: Guy Boertje Date: Tue, 2 Feb 2016 09:30:42 +0000 Subject: [PATCH] change the order of the pause_until calls include travis build yml and badge (remove jenkins later perhaps) try kick off travis build try file mode "wb" instead of "a" try with rspec sequencing wtf jenkins travis suddenly start using devutils 0.0.8 ? split sequence into three sections refactor tests to use RSpec Sequencing update version and update changelog Fixes #99 --- .travis.yml | 8 ++ CHANGELOG.md | 3 + README.md | 8 +- logstash-input-file.gemspec | 5 +- spec/inputs/file_spec.rb | 259 ++++++++++++++++++++---------------- spec/spec_helper.rb | 6 + 6 files changed, 166 insertions(+), 123 deletions(-) create mode 100644 .travis.yml diff --git a/.travis.yml b/.travis.yml new file mode 100644 index 0000000..abaada5 --- /dev/null +++ b/.travis.yml @@ -0,0 +1,8 @@ +sudo: false +language: ruby +cache: bundler +rvm: + - jruby-1.7.23 +jdk: + - oraclejdk8 +script: bundle exec rspec spec --order rand diff --git a/CHANGELOG.md b/CHANGELOG.md index a23ea1b..22b6aef 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,6 @@ +## 2.2.1 + - Fix spec failures on CI Linux builds (not seen on local OSX and Linux) + ## 2.2.0 - Use ruby-filewatch 0.8.0, major rework of filewatch. See [Pull Request 74](https://github.com/jordansissel/ruby-filewatch/pull/74) - add max_open_files config option, defaults to 4095, the input will process much more than this but have this number of files open at any time - files are closed based on the close_older setting, thereby making others openable. diff --git a/README.md b/README.md index e4cf71a..25381e3 100644 --- a/README.md +++ b/README.md @@ -1,7 +1,9 @@ # Logstash Plugin +Travis Build +[![Travis Build Status](https://travis-ci.org/logstash-plugins/logstash-input-file.svg)](https://travis-ci.org/logstash-plugins/logstash-input-file) -[![Build -Status](http://build-eu-00.elastic.co/view/LS%20Plugins/view/LS%20Inputs/job/logstash-plugin-input-file-unit/badge/icon)](http://build-eu-00.elastic.co/view/LS%20Plugins/view/LS%20Inputs/job/logstash-plugin-input-file-unit/) +Jenkins Build +[![Build Status](http://build-eu-00.elastic.co/view/LS%20Plugins/view/LS%20Inputs/job/logstash-plugin-input-file-unit/badge/icon)](http://build-eu-00.elastic.co/view/LS%20Plugins/view/LS%20Inputs/job/logstash-plugin-input-file-unit/) This is a plugin for [Logstash](https://github.com/elastic/logstash). @@ -86,4 +88,4 @@ Programming is not a required skill. Whatever you've seen about open source and It is more important to the community that you are able to contribute. -For more information about contributing, see the [CONTRIBUTING](https://github.com/elastic/logstash/blob/master/CONTRIBUTING.md) file. \ No newline at end of file +For more information about contributing, see the [CONTRIBUTING](https://github.com/elastic/logstash/blob/master/CONTRIBUTING.md) file. diff --git a/logstash-input-file.gemspec b/logstash-input-file.gemspec index 45a3296..2646a07 100644 --- a/logstash-input-file.gemspec +++ b/logstash-input-file.gemspec @@ -1,7 +1,7 @@ Gem::Specification.new do |s| s.name = 'logstash-input-file' - s.version = '2.2.0' + s.version = '2.2.1' s.licenses = ['Apache License (2.0)'] s.summary = "Stream events from files." s.description = "This gem is a logstash plugin required to be installed on top of the Logstash core pipeline using $LS_HOME/bin/plugin install gemname. This gem is not a stand-alone program" @@ -28,7 +28,8 @@ Gem::Specification.new do |s| s.add_runtime_dependency 'logstash-codec-multiline', ['~> 2.0.7'] s.add_development_dependency 'stud', ['~> 0.0.19'] - s.add_development_dependency 'logstash-devutils' + s.add_development_dependency 'logstash-devutils', ['~> 0.0.18'] s.add_development_dependency 'logstash-codec-json' + s.add_development_dependency 'rspec-sequencing' end diff --git a/spec/inputs/file_spec.rb b/spec/inputs/file_spec.rb index 577fc23..19a5f8c 100644 --- a/spec/inputs/file_spec.rb +++ b/spec/inputs/file_spec.rb @@ -173,21 +173,23 @@ "codec" => mlcodec, "delimiter" => FILE_DELIMITER) subject.register - Thread.new { subject.run(events) } end it "reads the appended data only" do - sleep 0.1 - File.open(tmpfile_path, "a") do |fd| - fd.puts("hello") - fd.puts("world") - fd.fsync - end - # wait for one event, the last line is buffered - expect(pause_until{ events.size == 1 }).to be_truthy - subject.stop + RSpec::Sequencing + .run_after(0.1, "assert zero events then append two lines") do + expect(events.size).to eq(0) + File.open(tmpfile_path, "a") { |fd| fd.puts("hello"); fd.puts("world") } + end + .then_after(0.1, "only one event is created, the last line is buffered") do + expect(events.size).to eq(1) + end + .then_after(0.1, "quit") do + subject.stop + end + subject.run(events) # stop flushes the second event - expect(pause_until{ events.size == 2 }).to be_truthy + expect(events.size).to eq(2) event1 = events[0] expect(event1).not_to be_nil @@ -215,39 +217,44 @@ "sincedb_path" => sincedb_path, "stat_interval" => 0.02, "codec" => codec, - "close_older" => 1, + "close_older" => 0.5, "delimiter" => FILE_DELIMITER) subject.register - Thread.new { subject.run(events) } end it "having timed_out, the identity is evicted" do - sleep 0.1 - File.open("#{tmpdir_path}/a.log", "a") do |fd| - fd.puts(line) - fd.fsync - end - expect(pause_until{ subject.codec.identity_count == 1 }).to be_truthy - expect(codec).to receive_call_and_args(:accept, [true]) - # wait for expiry to kick in and close files. - expect(pause_until{ subject.codec.identity_count.zero? }).to be_truthy - expect(codec).to receive_call_and_args(:auto_flush, [true]) - subject.stop + RSpec::Sequencing + .run("create file") do + File.open("#{tmpdir_path}/a.log", "wb") { |file| file.puts(line) } + end + .then_after(0.3, "identity is mapped") do + expect(codec.trace_for(:accept)).to eq([true]) + expect(subject.codec.identity_count).to eq(1) + end + .then_after(0.3, "test for auto_flush") do + expect(codec.trace_for(:auto_flush)).to eq([true]) + expect(subject.codec.identity_count).to eq(0) + end + .then_after(0.1, "quit") do + subject.stop + end + subject.run(events) end end context "when ignore_older config is specified" do let(:line) { "line1.1-of-a" } + let(:tmp_dir_file) { "#{tmpdir_path}/a.log" } subject { described_class.new(conf) } before do - File.open("#{tmpdir_path}/a.log", "a") do |fd| + File.open(tmp_dir_file, "a") do |fd| fd.puts(line) fd.fsync end - sleep 1.1 # wait for file to age + FileInput.make_file_older(tmp_dir_file, 2) conf.update( "type" => "blah", "path" => "#{tmpdir_path}/*.log", @@ -262,7 +269,7 @@ end it "the file is not read" do - sleep 0.5 + sleep 0.1 subject.stop expect(codec).to receive_call_and_args(:accept, false) expect(codec).to receive_call_and_args(:auto_flush, false) @@ -272,22 +279,6 @@ context "when wildcard path and a multiline codec is specified" do subject { described_class.new(conf) } - let(:writer_proc) do - -> do - File.open("#{tmpdir_path}/a.log", "a") do |fd| - fd.puts("line1.1-of-a") - fd.puts(" line1.2-of-a") - fd.puts(" line1.3-of-a") - fd.fsync - end - File.open("#{tmpdir_path}/z.log", "a") do |fd| - fd.puts("line1.1-of-z") - fd.puts(" line1.2-of-z") - fd.puts(" line1.3-of-z") - fd.fsync - end - end - end before do mlconf.update("pattern" => "^\s", "what" => "previous") @@ -300,58 +291,76 @@ "delimiter" => FILE_DELIMITER) subject.register - Thread.new { subject.run(events) } - sleep 0.1 - writer_proc.call end it "collects separate multiple line events from each file" do - # wait for both paths to be mapped as identities - expect(pause_until{ subject.codec.identity_count == 2 }).to be_truthy - subject.stop - # stop flushes both events - expect(pause_until{ events.size == 2 }).to be_truthy - - e1, e2 = events - e1_message = e1["message"] - e2_message = e2["message"] - - # can't assume File A will be read first - if e1_message.start_with?('line1.1-of-z') - expect(e1["path"]).to match(/z.log/) - expect(e2["path"]).to match(/a.log/) - expect(e1_message).to eq("line1.1-of-z#{FILE_DELIMITER} line1.2-of-z#{FILE_DELIMITER} line1.3-of-z") - expect(e2_message).to eq("line1.1-of-a#{FILE_DELIMITER} line1.2-of-a#{FILE_DELIMITER} line1.3-of-a") - else - expect(e1["path"]).to match(/a.log/) - expect(e2["path"]).to match(/z.log/) - expect(e1_message).to eq("line1.1-of-a#{FILE_DELIMITER} line1.2-of-a#{FILE_DELIMITER} line1.3-of-a") - expect(e2_message).to eq("line1.1-of-z#{FILE_DELIMITER} line1.2-of-z#{FILE_DELIMITER} line1.3-of-z") - end - end - - context "if auto_flush is enabled on the multiline codec" do - let(:writer_proc) do - -> do - File.open("#{tmpdir_path}/a.log", "a") do |fd| + actions = RSpec::Sequencing + .run_after(0.1, "create files") do + File.open("#{tmpdir_path}/A.log", "wb") do |fd| fd.puts("line1.1-of-a") fd.puts(" line1.2-of-a") fd.puts(" line1.3-of-a") end + File.open("#{tmpdir_path}/z.log", "wb") do |fd| + fd.puts("line1.1-of-z") + fd.puts(" line1.2-of-z") + fd.puts(" line1.3-of-z") + end end - end - let(:mlconf) { { "auto_flush_interval" => 1 } } + .then_after(0.2, "assert both files are mapped as identities and stop") do + expect(subject.codec.identity_count).to eq(2) + end + .then_after(0.1, "stop") do + subject.stop + end + .then_after(0.2 , "stop flushes both events") do + expect(events.size).to eq(2) + e1, e2 = events + e1_message = e1["message"] + e2_message = e2["message"] + + # can't assume File A will be read first + if e1_message.start_with?('line1.1-of-z') + expect(e1["path"]).to match(/z.log/) + expect(e2["path"]).to match(/A.log/) + expect(e1_message).to eq("line1.1-of-z#{FILE_DELIMITER} line1.2-of-z#{FILE_DELIMITER} line1.3-of-z") + expect(e2_message).to eq("line1.1-of-a#{FILE_DELIMITER} line1.2-of-a#{FILE_DELIMITER} line1.3-of-a") + else + expect(e1["path"]).to match(/A.log/) + expect(e2["path"]).to match(/z.log/) + expect(e1_message).to eq("line1.1-of-a#{FILE_DELIMITER} line1.2-of-a#{FILE_DELIMITER} line1.3-of-a") + expect(e2_message).to eq("line1.1-of-z#{FILE_DELIMITER} line1.2-of-z#{FILE_DELIMITER} line1.3-of-z") + end + end + subject.run(events) + # wait for actions to complete + actions.value + end + + context "if auto_flush is enabled on the multiline codec" do + let(:mlconf) { { "auto_flush_interval" => 0.5 } } it "an event is generated via auto_flush" do - # wait for auto_flush - # without it lines are buffered and pause_until would time out i.e false - expect(pause_until{ events.size == 1 }).to be_truthy - subject.stop - - e1 = events.first - e1_message = e1["message"] - expect(e1["path"]).to match(/a.log/) - expect(e1_message).to eq("line1.1-of-a#{FILE_DELIMITER} line1.2-of-a#{FILE_DELIMITER} line1.3-of-a") + actions = RSpec::Sequencing + .run_after(0.1, "create files") do + File.open("#{tmpdir_path}/A.log", "wb") do |fd| + fd.puts("line1.1-of-a") + fd.puts(" line1.2-of-a") + fd.puts(" line1.3-of-a") + end + end + .then_after(0.75, "wait for auto_flush") do + e1 = events.first + e1_message = e1["message"] + expect(e1["path"]).to match(/a.log/) + expect(e1_message).to eq("line1.1-of-a#{FILE_DELIMITER} line1.2-of-a#{FILE_DELIMITER} line1.3-of-a") + end + .then("stop") do + subject.stop + end + subject.run(events) + # wait for actions to complete + actions.value end end end @@ -424,25 +433,30 @@ "start_position" => "beginning", "delimiter" => FILE_DELIMITER) subject.register - Thread.new { subject.run(events) } - sleep 0.1 end it "collects line events from only one file" do - # wait for one path to be mapped as identity - expect(pause_until{ subject.codec.identity_count == 1 }).to be_truthy - subject.stop - # stop flushes last event - expect(pause_until{ events.size == 2 }).to be_truthy - - e1, e2 = events - if Dir.glob("#{tmpdir_path}/*.log").first =~ %r{a\.log} - #linux and OSX have different retrieval order - expect(e1["message"]).to eq("line1-of-a") - expect(e2["message"]).to eq("line2-of-a") - else - expect(e1["message"]).to eq("line1-of-z") - expect(e2["message"]).to eq("line2-of-z") - end + actions = RSpec::Sequencing + .run_after(0.2, "assert one identity is mapped") do + expect(subject.codec.identity_count).to eq(1) + end + .then_after(0.1, "stop") do + subject.stop + end + .then_after(0.1, "stop flushes last event") do + expect(events.size).to eq(2) + e1, e2 = events + if Dir.glob("#{tmpdir_path}/*.log").first =~ %r{a\.log} + #linux and OSX have different retrieval order + expect(e1["message"]).to eq("line1-of-a") + expect(e2["message"]).to eq("line2-of-a") + else + expect(e1["message"]).to eq("line1-of-z") + expect(e2["message"]).to eq("line2-of-z") + end + end + subject.run(events) + # wait for actions future value + actions.value end end @@ -454,28 +468,37 @@ "sincedb_path" => sincedb_path, "stat_interval" => 0.1, "max_open_files" => 1, - "close_older" => 1, + "close_older" => 0.5, "start_position" => "beginning", "delimiter" => FILE_DELIMITER) subject.register - Thread.new { subject.run(events) } - sleep 0.1 end it "collects line events from both files" do - # close flushes last event of each identity - expect(pause_until{ events.size == 4 }).to be_truthy - subject.stop - if Dir.glob("#{tmpdir_path}/*.log").first =~ %r{a\.log} - #linux and OSX have different retrieval order - e1, e2, e3, e4 = events - else - e3, e4, e1, e2 = events - end - expect(e1["message"]).to eq("line1-of-a") - expect(e2["message"]).to eq("line2-of-a") - expect(e3["message"]).to eq("line1-of-z") - expect(e4["message"]).to eq("line2-of-z") + actions = RSpec::Sequencing + .run_after(0.2, "assert both identities are mapped and the first two events are built") do + expect(subject.codec.identity_count).to eq(2) + expect(events.size).to eq(2) + end + .then_after(0.8, "wait for close to flush last event of each identity") do + expect(events.size).to eq(4) + if Dir.glob("#{tmpdir_path}/*.log").first =~ %r{a\.log} + #linux and OSX have different retrieval order + e1, e2, e3, e4 = events + else + e3, e4, e1, e2 = events + end + expect(e1["message"]).to eq("line1-of-a") + expect(e2["message"]).to eq("line2-of-a") + expect(e3["message"]).to eq("line1-of-z") + expect(e4["message"]).to eq("line2-of-z") + end + .then_after(0.1, "stop") do + subject.stop + end + subject.run(events) + # wait for actions future value + actions.value end end diff --git a/spec/spec_helper.rb b/spec/spec_helper.rb index 4cbac66..3aa87c3 100644 --- a/spec/spec_helper.rb +++ b/spec/spec_helper.rb @@ -1,8 +1,14 @@ # encoding: utf-8 require "logstash/devutils/rspec/spec_helper" +require "rspec_sequencing" module FileInput + def self.make_file_older(path, seconds) + time = Time.now.to_f - seconds + File.utime(time, time, path) + end + class TracerBase def initialize() @tracer = []; end