From e375b1b744ddcf24d2418bc86c05f9b9b09c0fed Mon Sep 17 00:00:00 2001 From: Karol Bucek Date: Mon, 6 Apr 2020 12:34:44 +0200 Subject: [PATCH 1/8] Test: samples when syntax is invalid --- spec/filters/ruby_spec.rb | 37 +++++++++++++++++++++++++++++++++++++ spec/fixtures/invalid.rb | 8 ++++++++ 2 files changed, 45 insertions(+) create mode 100644 spec/fixtures/invalid.rb diff --git a/spec/filters/ruby_spec.rb b/spec/filters/ruby_spec.rb index c3e5b7d..75908e7 100644 --- a/spec/filters/ruby_spec.rb +++ b/spec/filters/ruby_spec.rb @@ -114,6 +114,26 @@ expect(subject.get("mydate")).to eq("2014-09-23T00:00:00-0800"); 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 +187,22 @@ expect {|b| filter.filter(incoming_event, &b) }.to yield_control.exactly(3).times 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 From fa79e96ab24f0356471bb3f3743432664af1ac04 Mon Sep 17 00:00:00 2001 From: Karol Bucek Date: Mon, 6 Apr 2020 14:50:59 +0200 Subject: [PATCH 2/8] Fix: scripts that go wild with constants ... by using a plain-old method definition we're effectively restricting "dynamic constant" assigns --- lib/logstash/filters/ruby.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/logstash/filters/ruby.rb b/lib/logstash/filters/ruby.rb index 9457e61..403ccbc 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 From 13109208366dac85bf4ddd8cd39a9b7826d43f8f Mon Sep 17 00:00:00 2001 From: Karol Bucek Date: Mon, 6 Apr 2020 14:51:41 +0200 Subject: [PATCH 3/8] Test: script raising standard error behavior --- lib/logstash/filters/ruby.rb | 29 +++++++++++++++-------------- spec/filters/ruby_spec.rb | 34 ++++++++++++++++++++++++++++++++++ spec/fixtures/raising.rb | 7 +++++++ 3 files changed, 56 insertions(+), 14 deletions(-) create mode 100644 spec/fixtures/raising.rb diff --git a/lib/logstash/filters/ruby.rb b/lib/logstash/filters/ruby.rb index 403ccbc..d8aaa17 100644 --- a/lib/logstash/filters/ruby.rb +++ b/lib/logstash/filters/ruby.rb @@ -93,11 +93,8 @@ def inline_script(event, &block) filter_method(event, &block) filter_matched(event) rescue Exception => e - @logger.error("Ruby exception occurred: #{e}") - if @tag_with_exception_message - event.tag("#{@tag_on_exception}: #{e}") - end - event.tag(@tag_on_exception) + @logger.error("Ruby exception occurred:", :message => e.message, :exception => e.class, :backtrace => e.backtrace) + tag_exception(event, e) end def file_script(event) @@ -107,21 +104,16 @@ def file_script(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) + @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 @@ -132,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/spec/filters/ruby_spec.rb b/spec/filters/ruby_spec.rb index 75908e7..47ed507 100644 --- a/spec/filters/ruby_spec.rb +++ b/spec/filters/ruby_spec.rb @@ -115,6 +115,23 @@ end end + describe "code raising" do + subject(:filter) { ::LogStash::Filters::Ruby.new('code' => 'raise "an_error"') } + before(:each) { filter.register } + + it "should handle (standard) error" do + expect( filter.logger ).to receive(:error). + with('Ruby exception occurred:', hash_including(:message => 'an_error', :exception => RuntimeError)). + and_call_original + + event = LogStash::Event.new "message" => "hello world" + 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 + end + describe "invalid script" do let(:filter_params) { { 'code' => code } } subject(:filter) { ::LogStash::Filters::Ruby.new(filter_params) } @@ -188,6 +205,23 @@ 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' } 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 From aca0669149cd8d143a7e807e91a3192ae258f578 Mon Sep 17 00:00:00 2001 From: Karol Bucek Date: Mon, 6 Apr 2020 20:35:23 +0200 Subject: [PATCH 4/8] bump + fill in changelog --- CHANGELOG.md | 3 +++ logstash-filter-ruby.gemspec | 2 +- 2 files changed, 4 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 2ee0116..1d0bfc4 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,6 @@ +## 3.2.0 + - Breaking: restrict unintended user constant usage [#56](https://github.com/logstash-plugins/logstash-filter-ruby/pull/56) + ## 3.1.5 - Fixed path based scripting not calling filter\_matched [#45](https://github.com/logstash-plugins/logstash-filter-ruby/issues/45) diff --git a/logstash-filter-ruby.gemspec b/logstash-filter-ruby.gemspec index 510f113..9c39e3b 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.5' + s.version = '3.2.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" From 180b6c73f76f3b6e54e8bfe0115ab9bb99313ba3 Mon Sep 17 00:00:00 2001 From: kares Date: Tue, 11 May 2021 11:56:59 +0200 Subject: [PATCH 5/8] Test: adjust assert after merge with master --- spec/filters/ruby_spec.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/spec/filters/ruby_spec.rb b/spec/filters/ruby_spec.rb index 655510a..01a2335 100644 --- a/spec/filters/ruby_spec.rb +++ b/spec/filters/ruby_spec.rb @@ -121,7 +121,7 @@ it "should handle (standard) error" do expect( filter.logger ).to receive(:error). - with('Ruby exception occurred:', hash_including(:message => 'an_error', :exception => RuntimeError)). + with('Ruby exception occurred: an_error', hash_including(:exception => RuntimeError)). and_call_original event = LogStash::Event.new "message" => "hello world" From 39cf9ee5db2f0c63a2f53856842f7090fd4118ed Mon Sep 17 00:00:00 2001 From: kares Date: Tue, 11 May 2021 11:57:31 +0200 Subject: [PATCH 6/8] Deps: drop insist gem usage --- logstash-filter-ruby.gemspec | 1 - spec/filters/ruby_spec.rb | 12 ++++++------ spec/spec_helper.rb | 1 - 3 files changed, 6 insertions(+), 8 deletions(-) diff --git a/logstash-filter-ruby.gemspec b/logstash-filter-ruby.gemspec index 9c39e3b..6515214 100644 --- a/logstash-filter-ruby.gemspec +++ b/logstash-filter-ruby.gemspec @@ -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 01a2335..29a79f2 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 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" From 69c84a16cc1b47b5dee03a65adde33d39e1e84c1 Mon Sep 17 00:00:00 2001 From: kares Date: Tue, 11 May 2021 12:37:44 +0200 Subject: [PATCH 7/8] Chore: let's make this 4.0 (target LS 8.0) --- CHANGELOG.md | 2 +- logstash-filter-ruby.gemspec | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index ce2c14e..16f9079 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,4 +1,4 @@ -## 3.2.0 +## 4.0.0 - Breaking: restrict unintended user constant usage [#56](https://github.com/logstash-plugins/logstash-filter-ruby/pull/56) ## 3.1.7 diff --git a/logstash-filter-ruby.gemspec b/logstash-filter-ruby.gemspec index 6515214..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.2.0' + 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" From 58f2d1f8caeeb6aa1076c389635333c152b09a87 Mon Sep 17 00:00:00 2001 From: kares Date: Tue, 11 May 2021 12:38:45 +0200 Subject: [PATCH 8/8] Fix: do not rescue everything from inline scripts also aligned what we rescue for inline and path scripts --- CHANGELOG.md | 1 + lib/logstash/filters/ruby.rb | 8 ++++---- spec/filters/ruby_spec.rb | 20 +++++++++++++++++--- 3 files changed, 22 insertions(+), 7 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 16f9079..cdf6379 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,6 @@ ## 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 64893fc..1dc77d7 100644 --- a/lib/logstash/filters/ruby.rb +++ b/lib/logstash/filters/ruby.rb @@ -92,8 +92,8 @@ 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}", :exception => e.class, :backtrace => e.backtrace) + rescue StandardError, ScriptError, java.lang.Exception => e + @logger.error("Exception occurred: #{e.message}", :exception => e.class, :backtrace => e.backtrace) tag_exception(event, e) end @@ -103,9 +103,9 @@ def file_script(event) filter_matched(event) self.class.check_result_events!(results) - rescue => e + 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,) + :script_path => @path) tag_exception(event, e) return event end diff --git a/spec/filters/ruby_spec.rb b/spec/filters/ruby_spec.rb index 29a79f2..45aded3 100644 --- a/spec/filters/ruby_spec.rb +++ b/spec/filters/ruby_spec.rb @@ -116,20 +116,34 @@ end describe "code raising" do - subject(:filter) { ::LogStash::Filters::Ruby.new('code' => 'raise "an_error"') } + + 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('Ruby exception occurred: an_error', hash_including(:exception => RuntimeError)). + with('Exception occurred: an_error', hash_including(:exception => RuntimeError)). and_call_original - event = LogStash::Event.new "message" => "hello world" 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