LogStash XMLFilter REXML::ParseException: No close tag

Sankalan_Banerjee · November 1, 2018, 9:24pm

Sample XML Doc :
<?xml-stylesheet type="text/xsl" encoding="UTF-8" href="..\stepDetail.xsl"?>

<tc_id>C608690E65444B3F8A3B9DA25BA1493E</tc_id>
D08B65929BEC48B5BB4B5FF2843CA3B5
<tc_name>EGBO_SANITY_02_AuthRes</tc_name>
SERVICE
<tc_start_time>10/15/2018 09:56:43 PM</tc_start_time>
<tc_end_time>10/15/2018 09:57:10 PM</tc_end_time>
<tc_status>PASSED</tc_status>
<exec_time_sec>26 sec</exec_time_sec>
<tc_desc></tc_desc>
false

<step_id>B6059B588D8D49F2A75B972720BF6B6C</step_id>
<tc_id>C608690E65444B3F8A3B9DA25BA1493E</tc_id>
<session_id>D08B65929BEC48B5BB4B5FF2843CA3B5</session_id>
<step_name>Subprocess Login - Login</step_name>
<step_desc></step_desc>
<execution_time_sec>1 sec</execution_time_sec>
<execution_status>PASSED</execution_status>
<step_request>RQ_STEP-1.txt</step_request>
<step_response>RS_STEP-1.txt</step_response>
<image_content></image_content>
<step_err></step_err>
<step_warn></step_warn>
false
<step_response_header></step_response_header>
<step_start_time>1969-12-31T18:00:00-06:00</step_start_time>

Check HTTP Response Code
PASSED

<tc_sequence>3</tc_sequence>

Logstash Code:-

input {
file {
	path => "//devcorp.deverac.local/dfsroot/NAS/data01_RQATtesting/ARS/Results/EMAGorilla/EGBO-RCQA/EGBO_Sanity_Suite/Run_10-15-2018_09-59-39-PM/EGBO_SANITY_02_AuthRes/Step_Detail_XML.xml"
	start_position => "beginning"
	sincedb_path => "NUL"
	type => "xml"
	codec => multiline {
		pattern => "^<testcase>"
		negate => "true"
		what => next
		auto_flush_interval => 1
	}

}
}

filter
{

xml {
source => "message"
target => "xmldata"
force_array => true
store_xml => true
remove_namespaces => true

}

mutate {
remove_field => [ "path","@timestamp","host","tags","@version","type","message"]
}

}

output {
stdout { codec => rubydebug }
}

Getting an Error while running the above Logstasg.conf file:-
[2018-11-01T16:16:02,423][WARN ][logstash.filters.xml ] Error parsing xml with XmlSimple {:source=>"message", :value=>" <execution_time_sec>< 1 sec</execution_time_sec>\n <execution_status>PASSED</execution_status>\n <step_request>RQ_STEP-17.txt</step_request>\n <step_response>RS_STEP-17.txt</step_response>\n <image_content></image_content>\n <step_err></step_err>\n <step_warn></step_warn>\n false\n <step_response_header></step_response_header>\n <step_start_time>1969-12-31T18:00:00-06:00</step_start_time>\n \n Check HTTP Response Code\n PASSED\n \n \n \n <step_id>4BD6A6C384F840209E30E1CAC2002D21</step_id>\n <tc_id>C608690E65444B3F8A3B9DA25BA1493E</tc_id>\n <session_id>D08B65929BEC48B5BB4B5FF2843CA3B5</session_id>\n <step_name>Subprocess Cancel_Reservation~1</step_name>\n <step_desc></step_desc>\n <execution_time_sec>< 1 sec</execution_time_sec>\n <execution_status>PASSED</execution_status>\n <step_request></step_request>\n <step_response></step_response>\n <image_content></image_content>\n <step_err></step_err>\n <step_warn></step_warn>\n false\n <step_response_header></step_response_header>\n <step_start_time>1969-12-31T18:00:00-06:00</step_start_time>\n \n Match Presence Of Error Code\n PASSED\n \n \n Match Presence Of Error Message\n PASSED\n \n \n <tc_sequence>3</tc_sequence>\n", :exception=>#<REXML::ParseException: #<RuntimeError: attempted adding second root element to document>
uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rexml/document.rb:96:in add' uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rexml/element.rb:880:inadd'
uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rexml/child.rb:22:in initialize' uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rexml/parent.rb:14:ininitialize'
uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rexml/element.rb:60:in initialize' uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rexml/element.rb:878:inadd'
uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rexml/element.rb:298:in add_element' uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rexml/document.rb:103:inadd_element'
uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rexml/parsers/treeparser.rb:34:in parse' uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rexml/document.rb:288:inbuild'
uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rexml/document.rb:45:in initialize' C:/ELK/logstash-6.4.2/vendor/bundle/jruby/2.3.0/gems/xml-simple-1.1.5/lib/xmlsimple.rb:971:inparse'
C:/ELK/logstash-6.4.2/vendor/bundle/jruby/2.3.0/gems/xml-simple-1.1.5/lib/xmlsimple.rb:164:in xml_in' C:/ELK/logstash-6.4.2/vendor/bundle/jruby/2.3.0/gems/xml-simple-1.1.5/lib/xmlsimple.rb:203:inxml_in'
C:/ELK/logstash-6.4.2/vendor/bundle/jruby/2.3.0/gems/logstash-filter-xml-4.0.5/lib/logstash/filters/xml.rb:187:in filter' C:/ELK/logstash-6.4.2/logstash-core/lib/logstash/filters/base.rb:143:indo_filter'
C:/ELK/logstash-6.4.2/logstash-core/lib/logstash/filters/base.rb:162:in block in multi_filter' org/jruby/RubyArray.java:1734:ineach'
C:/ELK/logstash-6.4.2/logstash-core/lib/logstash/filters/base.rb:159:in multi_filter' C:/ELK/logstash-6.4.2/logstash-core/lib/logstash/filter_delegator.rb:44:inmulti_filter'
(eval):67:in block in filter_func' C:/ELK/logstash-6.4.2/logstash-core/lib/logstash/pipeline.rb:341:infilter_batch'
C:/ELK/logstash-6.4.2/logstash-core/lib/logstash/pipeline.rb:320:in worker_loop' C:/ELK/logstash-6.4.2/logstash-core/lib/logstash/pipeline.rb:286:inblock in start_workers'
...
attempted adding second root element to document
Line: 2
Position: 112

humalog · November 2, 2018, 10:48am

Your pattern => "^<testcase>" is not part of your xml file, how should ES match something in from your file??
The other point is, is your xml file valid? Test it with an xml validator.

Sankalan_Banerjee · November 2, 2018, 3:09pm

Hi,
Thanks for your response.
I have changed the pattern to
input {
file {
path => "//devcorp.deverac.local/dfsroot/NAS/data01_RQATtesting/ARS/Results/EMAGorilla/EGBO-RCQA/EGBO_Sanity_Suite/Run_10-15-2018_09-59-39-PM/EGBO_SANITY_02_AuthRes/Step_Detail_XML.xml"
start_position => "beginning"
sincedb_path => "NUL"
type => "xml"
codec => multiline {
pattern => "^<?xml .*?>"
negate => "true"
what => previous
auto_flush_interval => 1
}
}
}

filter
{

xml {
source => "message"
target => "xmldata"
force_array => false
store_xml => true
remove_namespaces => true
}

mutate {
remove_field => [ "path","@timestamp","host","tags","@version","type","message","xmldata"]
}

}

output {
stdout { codec => rubydebug }
}

Still I am getting the #<REXML::ParseException: No close tag for /testCase/step[17]. I have validated my XML using online Tool, and its showing that my XML is valid. Unfortunately due to space constraint I am not able to share the complete XML. But if you can share your email id I can send you the XML File.

Small Snippet:-
<?xml-stylesheet type="text/xsl" encoding="UTF-8" href="..\stepDetail.xsl"?>

<tc_id>C608690E65444B3F8A3B9DA25BA1493E</tc_id>
D08B65929BEC48B5BB4B5FF2843CA3B5
<tc_name>EGBO_SANITY_02_AuthRes</tc_name>
SERVICE
<tc_start_time>10/15/2018 09:56:43 PM</tc_start_time>
<tc_end_time>10/15/2018 09:57:10 PM</tc_end_time>
<tc_status>PASSED</tc_status>
<exec_time_sec>26 sec</exec_time_sec>
<tc_desc></tc_desc>
false

<step_id>B6059B588D8D49F2A75B972720BF6B6C</step_id>
<tc_id>C608690E65444B3F8A3B9DA25BA1493E</tc_id>
<session_id>D08B65929BEC48B5BB4B5FF2843CA3B5</session_id>
<step_name>Subprocess Login - Login</step_name>
<step_desc></step_desc>
<execution_time_sec>1 sec</execution_time_sec>
<execution_status>PASSED</execution_status>
<step_request>RQ_STEP-1.txt</step_request>
<step_response>RS_STEP-1.txt</step_response>
<image_content></image_content>
<step_err></step_err>
<step_warn></step_warn>
false
<step_response_header></step_response_header>
<step_start_time>1969-12-31T18:00:00-06:00</step_start_time>

Check HTTP Response Code
PASSED

<tc_sequence>3</tc_sequence>

Looking forward to your response.

humalog · November 5, 2018, 8:53am

Did you read this entry: Problem in parsing xml files
and this one: REXML::Parse Exception

I'm not sure if this is a problem but there are entries in your XML file that don't belong to any element, for example:

false

and

Check HTTP Response Code
PASSED

Sankalan_Banerjee · November 5, 2018, 5:03pm

<?xml-stylesheet type="text/xsl" encoding="UTF-8" href="..\stepDetail.xsl"?>
<testCase>
<tc_id>C608690E65444B3F8A3B9DA25BA1493E</tc_id>
<sessionId>D08B65929BEC48B5BB4B5FF2843CA3B5</sessionId>
<tc_name>EGBO_SANITY_02_AuthRes</tc_name>
<testType>SERVICE</testType>
<tc_status>PASSED</tc_status>
<exec_time_sec>26 sec</exec_time_sec>
<tc_desc></tc_desc>
<step>
<step_name>Subprocess Login - Login</step_name>
<execution_time_sec>1 sec</execution_time_sec>
<execution_status>PASSED</execution_status>
<step_request>RQ_STEP-1.txt</step_request>
<step_response>RS_STEP-1.txt</step_response>
</step>
<step>
<step_name>Subprocess Login</step_name>
<execution_time_sec>1 sec</execution_time_sec>
<execution_status>PASSED</execution_status>
<step_request></step_request>
<step_response></step_response>
</step>
<step>
<step_name>Subprocess Initiate_Reservation - Initiate_Reservation</step_name>
<execution_time_sec>2 sec</execution_time_sec>
<execution_status>PASSED</execution_status>
<step_request>RQ_STEP-3.txt</step_request>
<step_response>RS_STEP-3.txt</step_response>
</step>
<step>
<step_name>Subprocess Initiate_Reservation</step_name>
<execution_time_sec>2 sec</execution_time_sec>
<execution_status>PASSED</execution_status>
<step_request></step_request>
<step_response></step_response>
</step>
<step>
<step_name>Subprocess Select_CarClass~1 - Select_CarClass</step_name>
<execution_time_sec>1 sec</execution_time_sec>
<execution_status>PASSED</execution_status>
<step_request>RQ_STEP-5.txt</step_request>
<step_response>RS_STEP-5.txt</step_response>
</step>
<step>
<step_name>Subprocess Select_CarClass~1</step_name>
<execution_time_sec>1 sec</execution_time_sec>
<execution_status>PASSED</execution_status>
<step_request></step_request>
<step_response></step_response>
</step>
<step>
<step_name>Subprocess Get_CarClass_Details - Get_CarClass_Details</step_name>
<execution_time_sec>1 sec</execution_time_sec>
<execution_status>PASSED</execution_status>
<step_request>RQ_STEP-7.txt</step_request>
<step_response>RS_STEP-7.txt</step_response>
</step>
<step>
<step_name>Subprocess Update_Extras - Update_Extras</step_name>
<step_desc></step_desc>
<execution_time_sec>< 1 sec</execution_time_sec>
<execution_status>PASSED</execution_status>
<step_request>RQ_STEP-8.txt</step_request>
<step_response>RS_STEP-8.txt</step_response>
</step>
<tc_sequence>3</tc_sequence>
</testCase>

Please ignore the XML provided in my earlier comment. Refer the above XML doc.
Not able to paste the complete XML due to space constraint. As I had mentioned in my earlier comment, that I have validated the XML Files but no issues were reported. So not sure why XML Filter is returned Parse Exceptions?

humalog · November 7, 2018, 10:56am

I am totally sure that you have the same problem like in this post

You're passing to the xml filter contains two XML documents (two consecutive "note" elements). The xml filter can only parse one document at a time. Each XML document has exactly one single root element. It encloses all the other elements and is therefore the sole parent element to all the other elements. ROOT elements are also called document elements.
I think your problem is the element which appers multiple but it's just allowed to put it one time in the whole file. Maybe put an selfmade element before the first <testCase> and after the last </testCase> to test this.

For me it worked because my xml file contains one root element (just one time <testCase> [your root element]), i used the xml file you posted at 5th november.

Best regards

system · December 5, 2018, 10:56am

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.