Plugin crashes on empty response body

dmaasland commented 3 years ago

If a web service responds with HTTP/1.0 204 No Content and an empty response body the plugin crashes. This is due to the invocation of body.strip on this line.

[2020-10-15T09:39:51,324][DEBUG][logstash.filters.http    ][main][bccba3b61c91111734d8fbaddeef151ae2e9d3ff77dae9376279dd322eb0bac6] success received {:code=>204, :body=>nil}
[2020-10-15T09:39:51,352][ERROR][logstash.javapipeline    ][main] Pipeline worker error, the pipeline will be stopped {:pipeline_id=>"main", :error=>"(NoMethodError) undefined method `strip' for nil:NilClass", :exception=>Java::OrgJrubyExceptions::NoMethodError, :backtrace=>["usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_filter_minus_http_minus_1_dot_0_dot_2.lib.logstash.filters.http.process_response(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-filter-http-1.0.2/lib/logstash/filters/http.rb:116)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_filter_minus_http_minus_1_dot_0_dot_2.lib.logstash.filters.http.filter(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-filter-http-1.0.2/lib/logstash/filters/http.rb:76)", "usr.share.logstash.logstash_minus_core.lib.logstash.filters.base.do_filter(/usr/share/logstash/logstash-core/lib/logstash/filters/base.rb:159)", "usr.share.logstash.logstash_minus_core.lib.logstash.filters.base.multi_filter(/usr/share/logstash/logstash-core/lib/logstash/filters/base.rb:178)", "org.jruby.RubyArray.each(org/jruby/RubyArray.java:1809)", "usr.share.logstash.logstash_minus_core.lib.logstash.filters.base.multi_filter(/usr/share/logstash/logstash-core/lib/logstash/filters/base.rb:175)", "org.logstash.config.ir.compiler.AbstractFilterDelegatorExt.multi_filter(org/logstash/config/ir/compiler/AbstractFilterDelegatorExt.java:134)", "usr.share.logstash.logstash_minus_core.lib.logstash.java_pipeline.start_workers(/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:293)"], :thread=>"#<Thread:0x30e761f3 sleep>"}
[2020-10-15T09:39:51,513][DEBUG][logstash.filters.http    ][main] Closing {:plugin=>"LogStash::Filters::Http"}
[2020-10-15T09:39:51,531][DEBUG][logstash.filters.http    ][main] Closing {:plugin=>"LogStash::Filters::Http"}
[2020-10-15T09:39:51,532][DEBUG][logstash.filters.http    ][main] Closing {:plugin=>"LogStash::Filters::Http"}
[2020-10-15T09:39:51,939][INFO ][logstash.runner          ] Logstash shut down.

kares commented 3 years ago

Thanks Donny, nice catch - seems like this would be worth a quick PR.

TheVastyDeep commented 3 years ago

There is a closely related issue... If you use verb => "HEAD" and the response headers set the content type to application/json then body is nil and it blows up a few lines earlier in the other branch of the content-type test. The error logged is "JSON parsing error {:message=>"class org.jruby.RubyNil cannot be cast to class org.jruby.RubyIO"

kares commented 2 years ago

^^^ is correct, the plugin is not handling HEAD requests (or simply nil bodies) gracefully. in those cases the whole logic should be skipped e.g.

  def process_response(body, headers, event)
    content_type, _ = headers.fetch("content-type", "").split(";")
    event.set(@target_headers, headers)
    return if body.nil? # new line added
    if content_type == "application/json"
    # ...

this would need some tests - worth a PR if anyone is up for one.

dayotoro commented 2 years ago

Duplicate #39 I will close my issue

pdbogen commented 1 year ago

Hi! Would it be unseemly of me to "bump" this issue?

We're experiencing that this plugin crashes with an exception (crashing logstash) when we make an http request that returns an HTTP 204. It seems that Ruby does not populate the response body in this case, but the plugin unconditionally accesses the response body in process_response, which is called for all HTTP statuses in the 200 to 299 range.

sl45sms commented 1 year ago

Just for reference, a workaround for those who stuck, is to use ruby plugin like this example

ruby {
  # POST http://bonita:8080/bonita/loginservice
  # returns 204 empty body and X-Bonita-API-Token and JSESSIONID cookies
  code => "
  require 'uri'
  require 'net/http'
  uri = URI('http://bonita:8080/bonita/loginservice')
  res = Net::HTTP.post_form(uri, 'username' => 'admin', 'password' => 'admin')
  cookies = res['set-cookie'].split(';')
  cookies.each do |cookie|
    if cookie.include? 'JSESSIONID'
      event.set('[@metadata][JSESSIONID]', cookie.split('=')[2])
    end
    if cookie.include? 'X-Bonita-API-Token'
      event.set('[@metadata][X-Bonita-API-Token]', cookie.split('=')[2])
    end
  end
  "
}

TheVastyDeep commented 1 year ago

the plugin is not handling HEAD requests (or simply nil bodies) gracefully. in those cases the whole logic should be skipped e.g.

This was implemented in PR 40.

asymmetricia commented 1 year ago

Hi! Sorry, but PR #40 does not address the issue described. The PR skips attempting to process the response body when the request verb is HEAD. However, there are other situations in the HTTP protocol where we do not expect a response body, for example, HTTP 204.

If a GET is performed and the response is HTTP 204, the code will continue to try and access the response body, which causes an unhandled exception in ruby.

TheVastyDeep commented 1 year ago

You are right, PR 40 implements "return if @verb == 'HEAD'", which handles one case, but "return if body.nil?" which @kares suggested would handle more. It is a one line change if anyone wants to do it...

logstash-plugins / logstash-filter-http

Plugin crashes on empty response body #25