logstash-plugins/logstash-filter-xml

filter stops processing after xpath error

hp197 opened this issue · 1 comments

hp197 commented

Hi,

Every day (at exact the same time), my logstash stalls and doesnt parse any events anymore.
Stack dump shows the input queue is full and the xml filter is stuck in processing.

logstash.err shows a nice error, on exact the moment the processing stops:

{
    :timestamp  =>  "2015-10-29T18:46:31.016000+0100",
    :message    =>  "Exception in filterworker",
    "exception" =>  #<Nokogiri::XML::XPath::SyntaxError: /SOAP-ENV:Envelope/SOAP-ENV:Body/cwmp:Inform/DeviceId/Manufacturer/text()>,
    "backtrace" =>  [
        "nokogiri/XmlXpathContext.java:169:in 'evaluate'",
        "/opt/logstash/vendor/bundle/jruby/1.9/gems/nokogiri-1.6.6.2-java/lib/nokogiri/xml/searchable.rb:165:in 'xpath'",
        "org/jruby/RubyArray.java:2412:in 'map'",
        "/opt/logstash/vendor/bundle/jruby/1.9/gems/nokogiri-1.6.6.2-java/lib/nokogiri/xml/searchable.rb:156:in 'xpath'",
        "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-xml-1.0.0/lib/logstash/filters/xml.rb:106:in 'filter'",
        "org/jruby/RubyHash.java:1341:in 'each'",
        "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-xml-1.0.0/lib/logstash/filters/xml.rb:105:in 'filter'",
        "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.4-java/lib/logstash/filters/base.rb:163:in 'multi_filter'",
        "org/jruby/RubyArray.java:1613:in 'each'",
        "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.4-java/lib/logstash/filters/base.rb:160:in 'multi_filter'",
        "(eval):4935:in 'cond_func_209'",
        "org/jruby/RubyArray.java:1613:in 'each'",
        "(eval):4932:in 'cond_func_209'",
        "(eval):5016:in 'cond_func_207'",
        "org/jruby/RubyArray.java:1613:in 'each'",
        "(eval):5009:in 'cond_func_207'",
        "(eval):1316:in 'filter_func'",
        "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.4-java/lib/logstash/pipeline.rb:219:in 'filterworker'",
        "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.4-java/lib/logstash/pipeline.rb:157:in 'start_filters'"
    ],
    :level=>:error
}

Note: logstash ran fine for a day with that xpath and after restarting the service, it continues to.

I know, this is a weird condition, and it might be a bug in nokogiri itself. Though I think the product would be better if we work around this by adding a catch to the xpath evaluation.

I made a change for this issue and im currently testing it, see: hp197/logstash-filter-xml@55f5783
When it works, i'll open up a pull request.

Cheers,

hp197 commented

I can confirm that the workaround works and logstash havent crashed anymore for several weeks. Though it still is a nasty hack and doesnt resolve the original problem.