Strange Echo3 Problem
Tue, 02/10/2009 - 11:49 — wordybird123
From time to time I get an error like this in the error logs:
It seems totally unrelated to anything I am doing and unrelated to a particular action.
Anyone have any ideas.
2009-02-10 11:44:13,099 ERROR [STDERR] [Fatal Error] :1:1: Content is not allowed in prolog. 2009-02-10 11:44:13,099 ERROR [STDERR] nextapp.echo.webcontainer.util.XmlRequestParser$1: Provided InputStream cannot be parsed. 2009-02-10 11:44:13,100 ERROR [STDERR] at nextapp.echo.webcontainer.util.XmlRequestParser.parse(XmlRequestParser.java:109) 2009-02-10 11:44:13,100 ERROR [STDERR] at nextapp.echo.webcontainer.InputProcessor.process(InputProcessor.java:149) 2009-02-10 11:44:13,100 ERROR [STDERR] at nextapp.echo.webcontainer.Synchronization.process(Synchronization.java:106) 2009-02-10 11:44:13,100 ERROR [STDERR] at nextapp.echo.webcontainer.service.SynchronizeService.service(SynchronizeService.java:78) 2009-02-10 11:44:13,100 ERROR [STDERR] at nextapp.echo.webcontainer.WebContainerServlet.process(WebContainerServlet.java:404) 2009-02-10 11:44:13,100 ERROR [STDERR] at backoffice.backofficeServlet.process(backofficeServlet.java:26) 2009-02-10 11:44:13,100 ERROR [STDERR] at nextapp.echo.webcontainer.WebContainerServlet.doPost(WebContainerServlet.java:311) 2009-02-10 11:44:13,100 ERROR [STDERR] at javax.servlet.http.HttpServlet.service(HttpServlet.java:710) 2009-02-10 11:44:13,100 ERROR [STDERR] at javax.servlet.http.HttpServlet.service(HttpServlet.java:803) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:179) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:437) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:366) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446) 2009-02-10 11:44:13,100 ERROR [STDERR] at java.lang.Thread.run(Thread.java:595) 2009-02-10 11:44:13,100 ERROR [STDERR] Caused by: org.xml.sax.SAXParseException: Content is not allowed in prolog. 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.xerces.parsers.DOMParser.parse(Unknown Source) 2009-02-10 11:44:13,100 ERROR [STDERR] at org.apache.xerces.jaxp.DocumentBuilderImpl.parse(Unknown Source) 2009-02-10 11:44:13,101 ERROR [STDERR] at javax.xml.parsers.DocumentBuilder.parse(DocumentBuilder.java:98) 2009-02-10 11:44:13,101 ERROR [STDERR] at nextapp.echo.webcontainer.util.XmlRequestParser.parse(XmlRequestParser.java:107) 2009-02-10 11:44:13,101 ERROR [STDERR] ... 26 more 2009-02-10 11:44:13,101 ERROR [org.apache.catalina.core.ContainerBase.[jboss.web].[localhost].[/backoffice].[backofficeServlet]] Servlet.service() for servlet backofficeServlet threw exception java.io.IOException at backoffice.backofficeServlet.process(backofficeServlet.java:29) at nextapp.echo.webcontainer.WebContainerServlet.doPost(WebContainerServlet.java:311) at javax.servlet.http.HttpServlet.service(HttpServlet.java:710) at javax.servlet.http.HttpServlet.service(HttpServlet.java:803) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175) at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:179) at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262) at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:437) at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:366) at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446) at java.lang.Thread.run(Thread.java:595)
Thanks.
Don't believe I've seen that
Don't believe I've seen that before. Sounds like the client is sending a non-XML message (or maybe even zero length) message to the server, or perhaps something is corrupted.
Any firewall software in the mix that might be doing it? Could you try and see if it occurs with different browsers, i.e., something with a fundamentally different rendering engine (e.g. MSIE vs. Firefox, rather than Firefox vs. Epiphany).
If that doesn't shed any light on the problem, my next step may be to write a patch for you to log the last outgoing XML message on the client and then display it in the event of the error.
The error is totally random.
The error is totally random. It does not seem to be effecting us in any substantial way. It shows up maybe once a day. So I would say that it is a fairly low priority item. I will investigate a bit and see if I come up with anything. If I do I will let you know. No need, I would think, for you to write a custom patch though.
I *really* don't like seeing
I *really* don't like seeing stuff like this though, so please keep me apprised. Something, somewhere is getting corrupted. I don't think it's necessarily Echo3 that's the cause, but it may be where it needs to be worked around. If this is some random corruption occurring in servlet container, or perhaps due to some overzealous firewall/security/AV software, one solution might be to add a capability to RemoteClient to deal with it. The RemoteClient could store the last sent ClientMessage. If the server receives a corrupted message, it would send back some type of "try again" error. The RemoteClient would then send it again. The cycle would repeat until it went through or some max-retry count were hit.
OK. I will put in some
OK. I will put in some counters for this error and let you know how often it happens. As it happens randomly--at least I have not been able to identify the source--It is extremely difficult to debug. But I will watch it and let you know. Maybe then something more can be done.
As an FYI, I am running Echo3 with Sun Java 5, on JBoss 4.2.3 AS
Thanks.
Its definitely malformed
Its definitely malformed XML. I've seen the same issue with a missing end tag, or start tag in XML. I would check any of your XML files which your app creates/reads.
Oro.
My app does not create or
My app does not create or read any XML (with exception of that which is created by the Echo3 product).
You may want to check your
You may want to check your server's classpath jar files, like in common/lib, common/endorsed in tomcat.
May be something is getting loaded as an older version.
Regards,
Pawan
It has happened 9 additional
It has happened 9 additional times since last I posted this. Never in the same place and never by the same client. Multiple browser types also.
It has been suggested that I check my libs for the most recent. Any ideas what libs I should be checking for?
Here are some more state traces in case they help:
Strange errors. I would
Strange errors. I would check a couple of things:
- If you are on windows, run "chkdsk c: /f" if your disk is C, or change it to whatever disk your app is on. Filesystem errors could be the cause. (not likely the issue, but its happened to me before when I used to use windoze).
- Your files may be corrupted (more likely). Re-download your app server and Echo libs and see if the issue still occurs.
Oroborous
I am on Linux. And I don't
I am on Linux. And I don't think that the issue is a corruption issue else it would be happening a lot more often. I will however try and re-download the echo libs and see if it makes a difference. Just because I am skeptical doesn't mean you are not right : )
Quote: [Fatal Error] :1:1:
Are you running it via ipv6 ?
Nope.
Nope.
prolog is *not* the root cause
we saw that the ajax connection begins to stall after manually hitting it for 1/2 hr.
Sequence of events
1. Tried sending the same request again and again by repeating an operation from IE 8
2. After the 98th request, the server delay msg comes up and remains
3. No logs/errors in server log
4. After 5 min, guess the conn time-out and an invalid req given to Echo Server
5. Echo server fails parsing (invlaid content in prolog error) and sends a 500 back
6. Client shows an alert "Application error occured"
7. page is reloaded
i am cross posting this here (this is also happening in echo 2)
Happens both in IE 7 and 8
We have seen this with IE8 and Apache
We see (by using the TCP proxy from the Grinder project) that IE sends the client message in 2 parts - the header, then the content.
Apache for some reason closes the connection from the IE8 client to Apache (maybe a timeout - keepalive timeout?).
IE8 is told that the connection is closed when it tries to send a client message. It then opens a new connection on a different port and tries to send the message again. However - it only sends the header. The server then times out waiting for the rest of the content.
Does anyone know about this feature?
Wrap the request InputStream
You could wrap the request InputStream that records all bytes that pass through and dump them to a log file when the actual parse fails. Unfortunately, this requires some extra memory, but it might take the guesswork out of the loop.
Niels
Now that is an idea I can
Now that is an idea I can run with. I will do that and let you know what I find.
Sorry if you mentioned
Sorry if you mentioned before, but are you using Apache or something similar which is connecting to the web server. If yes then try different connector. May be the request is getting corrupted in between connector.
Regards,
Pawan
I've updated Echo3 as of SVN
I've updated Echo3 as of SVN 2264 to catch such XML parsing errors and send a 400 (bad request) to the client. It additionally won't reset the server-side state (nothing has been done to the app state at the time of these happening, so it's quite safe to do so).