Plugin crashes on empty response body

[dmaasland]

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]

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

[TheVastyDeep]

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]

^^^ 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]

Duplicate #39
I will close my issue

[pdbogen]

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]

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]

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]

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]

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...