logstash-plugins/logstash-filter-xml

XPath Parsing Fails

Grunticus03 opened this issue · 4 comments

Issue appears with Logstash 6.2.1 implementation of XML filter 4.0.5. This thread has some error discovery/research performed by MagnusBaeck. Below is the error message thrown by Logstash on attempting to parse xpath:

[2018-02-23T00:13:57,186][DEBUG][logstash.filters.xml ] Running xml filter {:event=>#<LogStash::Event:0x3035ec6c>} [2018-02-23T00:13:57,186][ERROR][logstash.pipeline ] Exception in pipelineworker, the pipeline stopped processing new events, please check your filter configuration and restart Logstash. {:pipeline_id=>"main", "exception"=>"ASCII-8BIT", "bac ktrace"=>["java.nio.charset.Charset.forName(Charset.java:531)", "nokogiri.internals.SaveContextVisitor.encodeStringToHtmlEntity(SaveContextVisitor.java:758)", "nokogiri.internals.SaveContextVisitor.enter(SaveContextVisitor.java:750)", "nokogiri.Xml Text.accept(XmlText.java:92)", "nokogiri.XmlNode.native_write_to(XmlNode.java:1272)", "C_3a_.logstash.vendor.bundle.jruby.$2_dot_3_dot_0.gems.nokogiri_minus_1_dot_8_dot_2_minus_java.lib.nokogiri.xml.node.RUBY$method$write_to$0(C:/logstash/vendor/bu ndle/jruby/2.3.0/gems/nokogiri-1.8.2-java/lib/nokogiri/xml/node.rb:697)", "C_3a_.logstash.vendor.bundle.jruby.$2_dot_3_dot_0.gems.nokogiri_minus_1_dot_8_dot_2_minus_java.lib.nokogiri.xml.node.RUBY$method$serialize$0(C:/logstash/vendor/bundle/jruby/ 2.3.0/gems/nokogiri-1.8.2-java/lib/nokogiri/xml/node.rb:629)", "C_3a_.logstash.vendor.bundle.jruby.$2_dot_3_dot_0.gems.nokogiri_minus_1_dot_8_dot_2_minus_java.lib.nokogiri.xml.node.RUBY$method$to_xml$0(C:/logstash/vendor/bundle/jruby/2.3.0/gems/nok ogiri-1.8.2-java/lib/nokogiri/xml/node.rb:652)", "C_3a_.logstash.vendor.bundle.jruby.$2_dot_3_dot_0.gems.nokogiri_minus_1_dot_8_dot_2_minus_java.lib.nokogiri.xml.node.RUBY$method$to_s$0(C:/logstash/vendor/bundle/jruby/2.3.0/gems/nokogiri-1.8.2-java /lib/nokogiri/xml/node.rb:513)", "C_3a_.logstash.vendor.bundle.jruby.$2_dot_3_dot_0.gems.logstash_minus_filter_minus_xml_minus_4_dot_0_dot_5.lib.logstash.filters.xml.RUBY$block$filter$2(C:/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-filter-xml -4.0.5/lib/logstash/filters/xml.rb:171)", "org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:156)", "org.jruby.runtime.BlockBody.yield(BlockBody.java:114)", "org.jruby.runtime.Block.yield(Block.java:165)", "org.jruby.ir.run time.IRRuntimeHelpers.yield(IRRuntimeHelpers.java:415)", "org.jruby.ir.targets.YieldSite.yield(YieldSite.java:87)", "C_3a_.logstash.vendor.bundle.jruby.$2_dot_3_dot_0.gems.nokogiri_minus_1_dot_8_dot_2_minus_java.lib.nokogiri.xml.node_set.RUBY$block $each$1(C:/logstash/vendor/bundle/jruby/2.3.0/gems/nokogiri-1.8.2-java/lib/nokogiri/xml/node_set.rb:190)", "org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:156)", "org.jruby.runtime.BlockBody.yield(BlockBody.java:114)", " org.jruby.runtime.Block.yield(Block.java:165)", "org.jruby.RubyInteger.fixnumUpto(RubyInteger.java:162)", "org.jruby.RubyInteger.upto(RubyInteger.java:134)", "C_3a_.logstash.vendor.bundle.jruby.$2_dot_3_dot_0.gems.nokogiri_minus_1_dot_8_dot_2_minus _java.lib.nokogiri.xml.node_set.RUBY$method$each$0(C:/logstash/vendor/bundle/jruby/2.3.0/gems/nokogiri-1.8.2-java/lib/nokogiri/xml/node_set.rb:189)", "C_3a_.logstash.vendor.bundle.jruby.$2_dot_3_dot_0.gems.logstash_minus_filter_minus_xml_minus_4_do t_0_dot_5.lib.logstash.filters.xml.RUBY$block$filter$1(C:/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-filter-xml-4.0.5/lib/logstash/filters/xml.rb:159)", "org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:156)", "org.j ruby.runtime.BlockBody.yield(BlockBody.java:114)", "org.jruby.runtime.Block.yield(Block.java:165)", "org.jruby.RubyHash$12.visit(RubyHash.java:1362)", "org.jruby.RubyHash$12.visit(RubyHash.java:1359)", "org.jruby.RubyHash.visitLimited(RubyHash.java :662)", "org.jruby.RubyHash.visitAll(RubyHash.java:647)", "org.jruby.RubyHash.iteratorVisitAll(RubyHash.java:1319)", "org.jruby.RubyHash.each_pairCommon(RubyHash.java:1354)", "org.jruby.RubyHash.each(RubyHash.java:1343)", "C_3a_.logstash.vendor.bun dle.jruby.$2_dot_3_dot_0.gems.logstash_minus_filter_minus_xml_minus_4_dot_0_dot_5.lib.logstash.filters.xml.RUBY$method$filter$0(C:/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-filter-xml-4.0.5/lib/logstash/filters/xml.rb:152)", "C_3a_.logstash. logstash_minus_core.lib.logstash.filters.base.RUBY$method$do_filter$0(C:/logstash/logstash-core/lib/logstash/filters/base.rb:145)", "C_3a_.logstash.logstash_minus_core.lib.logstash.filters.base.RUBY$block$multi_filter$1(C:/logstash/logstash-core/li b/logstash/filters/base.rb:164)", "org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:156)", "org.jruby.runtime.BlockBody.yield(BlockBody.java:114)", "org.jruby.runtime.Block.yield(Block.java:165)", "org.jruby.RubyArray.each (RubyArray.java:1734)", "C_3a_.logstash.logstash_minus_core.lib.logstash.filters.base.RUBY$method$multi_filter$0(C:/logstash/logstash-core/lib/logstash/filters/base.rb:161)", "C_3a_.logstash.logstash_minus_core.lib.logstash.filter_delegator.RUBY$me thod$multi_filter$0(C:/logstash/logstash-core/lib/logstash/filter_delegator.rb:47)", "org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:103)", "org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod .java:163)", "org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:200)", "org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:161)", "org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.jav a:314)", "org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:73)", "org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:132)", "org.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedMod eIRBlockBody.java:148)", "org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:73)", "org.jruby.runtime.Block.call(Block.java:124)", "org.jruby.RubyProc.call(RubyProc.java:289)", "org.jruby.internal.runtime.methods.ProcMethod.call(ProcMethod.java:63 )", "org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:204)", "org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:200)", "C_3a_.logstash.logstash_minus_core.lib.logstash.pipeline.RUBY$method$filter_batch $0(C:/logstash/logstash-core/lib/logstash/pipeline.rb:447)", "C_3a_.logstash.logstash_minus_core.lib.logstash.pipeline.RUBY$method$worker_loop$0(C:/logstash/logstash-core/lib/logstash/pipeline.rb:426)", "C_3a_.logstash.logstash_minus_core.lib.logst ash.pipeline.RUBY$method$worker_loop$0$__VARARGS__(C:/logstash/logstash-core/lib/logstash/pipeline.rb)", "org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:77)", "org.jruby.internal.runtime.methods.MixedModeIRMethod.cal l(MixedModeIRMethod.java:93)", "org.jruby.ir.targets.InvokeSite.invoke(InvokeSite.java:145)", "C_3a_.logstash.logstash_minus_core.lib.logstash.pipeline.RUBY$block$start_workers$2(C:/logstash/logstash-core/lib/logstash/pipeline.rb:385)", "org.jruby. runtime.CompiledIRBlockBody.callDirect(CompiledIRBlockBody.java:145)", "org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:71)", "org.jruby.runtime.Block.call(Block.java:124)", "org.jruby.RubyProc.call(RubyProc.java:289)", "org.jruby.RubyProc.call (RubyProc.java:246)", "org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:104)", "java.lang.Thread.run(Thread.java:748)"], :thread=>"#<Thread:0x3b8b70bd sleep>"}

Further discovered that the issue is related to Elastic Stack's persistent queueing (disk buffering). When disk buffering or xpath functions are used, the filter fails. Remove XPaths or disk buffering and it works.

For your information, root cause is tracked here => elastic/logstash#9167

Awesome, thanks for the root cause identification.

kares commented

this is expected to be resolved by now in LS >= 6.2.4