diff --git a/CHANGELOG.md b/CHANGELOG.md index cfe170b..cdf6379 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,7 @@ +## 4.0.0 + - Breaking: restrict unintended user constant usage [#56](https://github.com/logstash-plugins/logstash-filter-ruby/pull/56) + - Fix: do not handle potential fatal (Java) errors - let them propagate out + ## 3.1.7 - [DOC] Added docs to help people avoid concurrency issues (often caused by accidentally relying on shared state with global variables, constants, or unguarded overwriting of instance variables) [#58](https://github.com/logstash-plugins/logstash-filter-ruby/issues/58) diff --git a/lib/logstash/filters/ruby.rb b/lib/logstash/filters/ruby.rb index ff190f1..1dc77d7 100644 --- a/lib/logstash/filters/ruby.rb +++ b/lib/logstash/filters/ruby.rb @@ -60,7 +60,7 @@ def initialize(*params) def register if @code && @path.nil? eval(@init, binding, "(ruby filter init)") if @init - eval("define_singleton_method :filter_method do |event, &new_event_block|\n #{@code} \nend", binding, "(ruby filter code)") + eval("def self.filter_method(event, &new_event_block); #{@code} \nend", binding, "(ruby filter code)", 0) elsif @path && @code.nil? @script.register else @@ -92,14 +92,9 @@ def filter(event, &block) def inline_script(event, &block) filter_method(event, &block) filter_matched(event) - rescue Exception => e - @logger.error("Ruby exception occurred: #{e.message}", - :class => e.class.name, - :backtrace => e.backtrace) - if @tag_with_exception_message - event.tag("#{@tag_on_exception}: #{e}") - end - event.tag(@tag_on_exception) + rescue StandardError, ScriptError, java.lang.Exception => e + @logger.error("Exception occurred: #{e.message}", :exception => e.class, :backtrace => e.backtrace) + tag_exception(event, e) end def file_script(event) @@ -108,22 +103,17 @@ def file_script(event) filter_matched(event) self.class.check_result_events!(results) - rescue => e - if @tag_with_exception_message - event.tag("#{@tag_on_exception}: #{e}") - end - event.tag(@tag_on_exception) - message = "Could not process event: " + e.message - @logger.error(message, :script_path => @path, - :class => e.class.name, - :backtrace => e.backtrace) + rescue StandardError, ScriptError, java.lang.Exception => e + @logger.error("Could not process event:", :message => e.message, :exception => e.class, :backtrace => e.backtrace, + :script_path => @path) + tag_exception(event, e) return event end returned_original = false results.each do |r_event| # If the user has generated a new event we yield that for them here - if event == r_event + if event.equal? r_event returned_original = true else yield r_event @@ -134,4 +124,13 @@ def file_script(event) event.cancel unless returned_original end + + private + + def tag_exception(event, e) + if @tag_with_exception_message + event.tag("#{@tag_on_exception}: #{e}") + end + event.tag(@tag_on_exception) + end end diff --git a/logstash-filter-ruby.gemspec b/logstash-filter-ruby.gemspec index 5c6a38f..45bef0f 100644 --- a/logstash-filter-ruby.gemspec +++ b/logstash-filter-ruby.gemspec @@ -1,7 +1,7 @@ Gem::Specification.new do |s| s.name = 'logstash-filter-ruby' - s.version = '3.1.7' + s.version = '4.0.0' s.licenses = ['Apache License (2.0)'] s.summary = "Executes arbitrary Ruby code" s.description = "This gem is a Logstash plugin required to be installed on top of the Logstash core pipeline using $LS_HOME/bin/logstash-plugin install gemname. This gem is not a stand-alone program" @@ -23,6 +23,5 @@ Gem::Specification.new do |s| s.add_runtime_dependency "logstash-core-plugin-api", ">= 1.60", "<= 2.99" s.add_development_dependency 'logstash-filter-date' s.add_development_dependency 'logstash-devutils' - s.add_development_dependency 'insist' end diff --git a/spec/filters/ruby_spec.rb b/spec/filters/ruby_spec.rb index 1806f82..45aded3 100644 --- a/spec/filters/ruby_spec.rb +++ b/spec/filters/ruby_spec.rb @@ -27,9 +27,9 @@ sample("message" => "hello world", "mydate" => "2014-09-23T00:00:00-0800") do # json is rendered in pretty json since the JSON.pretty_generate created json from the event hash # pretty json contains \n - insist { subject.get("pretty").count("\n") } == 5 + expect( subject.get("pretty").count("\n") ).to eql 5 # usage of JSON.parse here is to avoid parser-specific order assertions - insist { JSON.parse(subject.get("pretty")) } == JSON.parse("{\n \"message\": \"hello world\",\n \"mydate\": \"2014-09-23T00:00:00-0800\",\n \"@version\": \"1\",\n \"@timestamp\": \"2014-09-23T08:00:00.000Z\"\n}") + expect( JSON.parse(subject.get("pretty")) ).to eql JSON.parse("{\n \"message\": \"hello world\",\n \"mydate\": \"2014-09-23T00:00:00-0800\",\n \"@version\": \"1\",\n \"@timestamp\": \"2014-09-23T08:00:00.000Z\"\n}") end end @@ -54,9 +54,9 @@ sample("message" => "hello world", "mydate" => "2014-09-23T00:00:00-0800") do # if this eventually breaks because we removed the custom to_json and/or added pretty support to JrJackson then all is good :) # non-pretty json does not contain \n - insist { subject.get("pretty").count("\n") } == 0 + expect( subject.get("pretty").count("\n") ).to eql 0 # usage of JSON.parse here is to avoid parser-specific order assertions - insist { JSON.parse(subject.get("pretty")) } == JSON.parse("{\"message\":\"hello world\",\"mydate\":\"2014-09-23T00:00:00-0800\",\"@version\":\"1\",\"@timestamp\":\"2014-09-23T08:00:00.000Z\"}") + expect( JSON.parse(subject.get("pretty")) ).to eql JSON.parse("{\"message\":\"hello world\",\"mydate\":\"2014-09-23T00:00:00-0800\",\"@version\":\"1\",\"@timestamp\":\"2014-09-23T08:00:00.000Z\"}") end end @@ -79,8 +79,8 @@ CONFIG sample("message" => "hello world", "mydate" => "2014-09-23T00:00:00-0800") do - insist { subject.get("mydate") } == "2014-09-23T00:00:00-0800" - insist { subject.get("tags") } == ["_rubyexception"] + expect( subject.get("mydate") ).to eql "2014-09-23T00:00:00-0800" + expect( subject.get("tags") ).to eql ["_rubyexception"] end end @@ -114,6 +114,57 @@ expect(subject.get("mydate")).to eq("2014-09-23T00:00:00-0800"); end end + + describe "code raising" do + + let(:event) { LogStash::Event.new "message" => "hello world" } + let(:code) { 'raise "an_error"' } + + subject(:filter) { ::LogStash::Filters::Ruby.new('code' => code) } + before(:each) { filter.register } + + it "should handle (standard) error" do + expect( filter.logger ).to receive(:error). + with('Exception occurred: an_error', hash_including(:exception => RuntimeError)). + and_call_original + + new_events = filter.multi_filter([event]) + expect(new_events.length).to eq 1 + expect(new_events[0]).to equal(event) + expect( event.get('tags') ).to eql [ '_rubyexception' ] + end + + context 'fatal error' do + + let(:code) { 'raise java.lang.AssertionError.new("TEST")' } + + it "should not rescue Java errors" do + expect( filter.logger ).to_not receive(:error) + + expect { filter.multi_filter([event]) }.to raise_error(java.lang.AssertionError) + end + end + end + + describe "invalid script" do + let(:filter_params) { { 'code' => code } } + subject(:filter) { ::LogStash::Filters::Ruby.new(filter_params) } + + let(:code) { 'sample do syntax error' } + + it "should error out during register" do + expect { filter.register }.to raise_error(SyntaxError) + end + + it "reports correct error line" do + begin + filter.register + fail('syntax error expected') + rescue SyntaxError => e + expect( e.message ).to match /\(ruby filter code\):1.*? unexpected end-of-file/ + end + end + end end context "when using file based script" do @@ -167,5 +218,39 @@ expect {|b| filter.filter(incoming_event, &b) }.to yield_control.exactly(3).times end end + + describe "script that raises" do + let(:script_filename) { 'raising.rb' } + + before(:each) do + filter.register + incoming_event.set('error', 'ERR-MSG') + end + + it "should handle (standard) error" do + expect( filter.logger ).to receive(:error). + with('Could not process event:', hash_including(:message => 'ERR-MSG', :exception => NameError)). + and_call_original + filter.filter(incoming_event) + expect( incoming_event.get('tags') ).to eql [ '_rubyexception' ] + end + end + + describe "invalid .rb script" do + let(:script_filename) { 'invalid.rb' } + + it "should error out during register" do + expect { filter.register }.to raise_error(SyntaxError) + end + + it "should report correct line number" do + begin + filter.register + fail('syntax error expected') + rescue SyntaxError => e + expect( e.message ).to match /invalid\.rb\:7/ + end + end + end end end diff --git a/spec/fixtures/invalid.rb b/spec/fixtures/invalid.rb new file mode 100644 index 0000000..43718d9 --- /dev/null +++ b/spec/fixtures/invalid.rb @@ -0,0 +1,8 @@ +# 1 +def register(params) + @params = params +end +# 5 +def invalid_syntax + Foo = :foo # on line 7 +end \ No newline at end of file diff --git a/spec/fixtures/raising.rb b/spec/fixtures/raising.rb new file mode 100644 index 0000000..0fd4c19 --- /dev/null +++ b/spec/fixtures/raising.rb @@ -0,0 +1,7 @@ +def register(params) +end + +def filter(event) + raise NameError, event.get('error') if event.get('error') + event +end \ No newline at end of file diff --git a/spec/spec_helper.rb b/spec/spec_helper.rb index c95e15c..dc64aba 100644 --- a/spec/spec_helper.rb +++ b/spec/spec_helper.rb @@ -1,3 +1,2 @@ # encoding: utf-8 require "logstash/devutils/rspec/spec_helper" -require "insist"