500 Server Error accessing session after executing test

[jerstlouis]

Describe the bug
Getting a 500 server error after executing an OGC API - Features test

https://cite.opengeospatial.org/te2/viewSessionLog.jsp?session=s0004

To Reproduce
Executed OGC API - Features tests for https://maps.ecere.com/ogcapi in a new session

Expected behavior
Seeing the session log rather than a 500 error

Additional context
HTTP Status 500 - javax.servlet.ServletException: net.sf.saxon.trans.XPathException: org.xml.sax.SAXParseException; lineNumber: 2; columnNumber: 2; The markup in the document preceding the root element must be well-formed.
type Exception report

message javax.servlet.ServletException: net.sf.saxon.trans.XPathException: org.xml.sax.SAXParseException; lineNumber: 2; columnNumber: 2; The markup in the document preceding the root element must be well-formed.

description The server encountered an internal error that prevented it from fulfilling this request.

exception

org.apache.jasper.JasperException: javax.servlet.ServletException: net.sf.saxon.trans.XPathException: org.xml.sax.SAXParseException; lineNumber: 2; columnNumber: 2; The markup in the document preceding the root element must be well-formed.
org.apache.jasper.servlet.JspServletWrapper.handleJspException(JspServletWrapper.java:556)
org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:462)
org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:395)
org.apache.jasper.servlet.JspServlet.service(JspServlet.java:339)
javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
root cause

javax.servlet.ServletException: net.sf.saxon.trans.XPathException: org.xml.sax.SAXParseException; lineNumber: 2; columnNumber: 2; The markup in the document preceding the root element must be well-formed.
org.apache.jasper.runtime.PageContextImpl.doHandlePageException(PageContextImpl.java:916)
org.apache.jasper.runtime.PageContextImpl.handlePageException(PageContextImpl.java:845)
org.apache.jsp.viewSessionLog_jsp._jspService(viewSessionLog_jsp.java:437)
org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:439)
org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:395)
org.apache.jasper.servlet.JspServlet.service(JspServlet.java:339)
javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
root cause

net.sf.saxon.trans.XPathException: org.xml.sax.SAXParseException; lineNumber: 2; columnNumber: 2; The markup in the document preceding the root element must be well-formed.
net.sf.saxon.event.Sender.sendSAXSource(Sender.java:379)
net.sf.saxon.event.Sender.send(Sender.java:185)
net.sf.saxon.IdentityTransformer.transform(IdentityTransformer.java:29)
com.occamlab.te.util.LogUtils.readLog(LogUtils.java:122)
com.occamlab.te.util.LogUtils.makeTestListElement(LogUtils.java:213)
com.occamlab.te.util.LogUtils.makeTestList(LogUtils.java:310)
com.occamlab.te.util.LogUtils.makeTestList(LogUtils.java:342)
com.occamlab.te.ViewLog.view_log(ViewLog.java:104)
com.occamlab.te.ViewLog.view_log(ViewLog.java:52)
org.apache.jsp.viewSessionLog_jsp._jspService(viewSessionLog_jsp.java:285)
org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:439)
org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:395)
org.apache.jasper.servlet.JspServlet.service(JspServlet.java:339)
javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
root cause

org.xml.sax.SAXParseException; lineNumber: 2; columnNumber: 2; The markup in the document preceding the root element must be well-formed.
org.apache.xerces.util.ErrorHandlerWrapper.createSAXParseException(Unknown Source)
org.apache.xerces.util.ErrorHandlerWrapper.fatalError(Unknown Source)
org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source)
org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source)
org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source)
org.apache.xerces.impl.XMLScanner.reportFatalError(Unknown Source)
org.apache.xerces.impl.XMLDocumentScannerImpl$PrologDispatcher.dispatch(Unknown Source)
org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source)
org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
org.apache.xerces.parsers.XMLParser.parse(Unknown Source)
org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source)
org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser.parse(Unknown Source)
net.sf.saxon.event.Sender.sendSAXSource(Sender.java:371)
net.sf.saxon.event.Sender.send(Sender.java:185)
net.sf.saxon.IdentityTransformer.transform(IdentityTransformer.java:29)
com.occamlab.te.util.LogUtils.readLog(LogUtils.java:122)
com.occamlab.te.util.LogUtils.makeTestListElement(LogUtils.java:213)
com.occamlab.te.util.LogUtils.makeTestList(LogUtils.java:310)
com.occamlab.te.util.LogUtils.makeTestList(LogUtils.java:342)
com.occamlab.te.ViewLog.view_log(ViewLog.java:104)
com.occamlab.te.ViewLog.view_log(ViewLog.java:52)
org.apache.jsp.viewSessionLog_jsp._jspService(viewSessionLog_jsp.java:285)
org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:439)
org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:395)
org.apache.jasper.servlet.JspServlet.service(JspServlet.java:339)
javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
note The full stack trace of the root cause is available in the Apache Tomcat/7.0.63 logs.

[dstenger]

Thank you for reporting.
I am able to reproduce the error.
We will do further analysis.

[dstenger]

@jerstlouis Can you please check if the problem is still occurring? It might have been related to problems with the environment back then which are solved by now.

[jerstlouis]

@dstenger I still get that error right after clicking that first link in this issue once I'm logged in:

https://cite.opengeospatial.org/te2/viewSessionLog.jsp?session=s0004

[dstenger]

@jerstlouis Thank you for reporting back. Is this error occurring with all your sessions? Did you also try out other test suites than OGC API Features tests?
Can you please try to re-run the test and check if the error is gone then?

[jerstlouis]

@dstenger It does not happen with all sessions. It happens with https://cite.opengeospatial.org/te2/viewSessionLog.jsp?session=s0004 and https://cite.opengeospatial.org/te2/viewSessionLog.jsp?session=s0005.

https://cite.opengeospatial.org/te2/viewSessionLog.jsp?session=s0006 is fine. (Note: clicking sessions list here gives a 500 error)

https://cite.opengeospatial.org/te2/viewSessionLog.jsp?session=s0007 has a different error:

HTTP Status 500 - javax.servlet.ServletException: org.xml.sax.SAXParseException; Premature end of file.

and https://cite.opengeospatial.org/te2/viewSessionLog.jsp?session=s0008 yet another:

HTTP Status 500 - java.io.FileNotFoundException: /srv/local/teamengine-te2/TE_BASE/users/jerstlouis4/s0008/session.xml (No such file or directory)

Iit seems to me that there is an opportunity to fix the specific code pathways leading to these 500 errors if you are able to reproduce the 500 errors.

HTTP Status 500 - javax.servlet.ServletException: net.sf.saxon.trans.XPathException: org.xml.sax.SAXParseException; lineNumber: 2; columnNumber: 2; The markup in the document preceding the root element must be well-formed.

I also get a 500 errors at https://cite.opengeospatial.org/te2/viewSessionLog.jsp:

HTTP Status 500 - java.lang.NullPointerException

These are unhandled exceptions that really should never happen and should be fixed, regardless of whether the problem leading to them happening was already fixed or not. Clients should get a 4xx errors if it did something wrong.

I did not try other test suites as currently it is the only one we support (I do plan to test Processes once it is available).

[ghobona]

@jerstlouis I agree with catching the Exception so that the message presented to the client can be more useful. I would also like to avoid the system returning file paths (e.g. /srv/local/teamengine-te2/TE_BASE/….)

Regarding the status codes, the examples on your post were most likely because of an Internal Server. Remember that we have been carrying out infrastructure updates this past month. The sessions were most likely not completed during execution because the server ran out of storage space. We have since increased the server's storage space. So ideally, any corrupted sessions should be deleted by the user.

[ghobona]

Today I confirmed that new session logs can be retrieved after executing the test.

This GitHub Issue will be closed on 2022-02-21.

[dstenger]

We created a new issue for the errors reported in #485 (comment): #502