DO NOT REPLY TO THIS EMAIL, BUT PLEASE POST YOUR BUG RELATED COMMENTS THROUGH THE WEB INTERFACE AVAILABLE AT <http://nagoya.apache.org/bugzilla/show_bug.cgi?id=9334>. ANY REPLY MADE TO THIS MESSAGE WILL NOT BE COLLECTED AND INSERTED IN THE BUG DATABASE.
http://nagoya.apache.org/bugzilla/show_bug.cgi?id=9334 Intermittent parsing error in Ajp13Request Summary: Intermittent parsing error in Ajp13Request Product: Tomcat 4 Version: 4.0.3 Final Platform: PC OS/Version: Linux Status: NEW Severity: Normal Priority: Other Component: Connector:JK/AJP (deprecated) AssignedTo: [EMAIL PROTECTED] ReportedBy: [EMAIL PROTECTED] Hi, We use Tomcat 4.0.3, with Apache 1.3.24 and mod_jk, all in a loadbalanced setup. We experience an intermittent bug in Tomcat that I fixed by changing the server code. I would like to describe the problem in the following by hoping someone can tell me what this is about. The problem is in the Ajp13Processor class. Once a processor is taken from the pool the AJP details are read with status = ajp13.receiveNextRequest(ajpRequest); Then later it is assigned to the supposedly recycled Ajp13Request from the previous use // set up request request.setAjpRequest(ajpRequest); So far so good. What happens for us is that at least 5 times every minute (up to 20-30 times) the flag "parsed" in Ajp13Request (the "request" instance variable of the Ajp13Processor class) is suddenly set to "true"! This causes the following problem. The incoming query string is not parsed anymore because the request thinks it had done this already. Therefore in our code when we use getParamXXXX() methods they all return "null" or an empty map. This of course means ours servlets assume that no parameters have been provided and they do whatever they should do in this case - which of course fails what the customer expects. What I did to quickly fix this problem is to add the following lines into Ajp13Request.java void setAjpRequest(BaseRequest ajp) throws UnsupportedEncodingException { // XXX make this guy wrap AjpRequest so // we're more efficient (that's the whole point of // all of the MessageBytes in AjpRequest) /** @todo DEBUG */ if (parsed == true) { parsed = false; System.err.println("!!! parsed was true in recycled request !!!"); } /** @todo DEBUG */ setMethod(ajp.method().toString()); setProtocol(ajp.protocol().toString()); .... Note the DEBUG lines above, when I detect that, although the request should have been recycled, that the "parsed" flag is already set before even anything is assigned to it I reset the flag to "false" and everything is working fine. The error message I print out above is the one that shows up in our catalina.out the specified number of times (see above). I then went on and added this to the HttpRequestBase.java public void setQueryString(String query) { /** @todo DEBUG */ if (parsed) { System.err.println("### reassigned query string ###\nqueryString: " + queryString + "\nnew value: " + query); } /** @todo DEBUG */ this.queryString = query; } Although this should never happen - or am I wrong here - this is what I see in the catalina.out ### reassigned query string ### queryString: null new value: wl_srclang=ES&wl_trglang=FR&wl_gloss=7&wl_text=Provinc% EDa+de+la+direcci%F3n+destino+de+la+mercanc%EDa !!! parsed was true in recycled request !!! Clearly, the request gets some values assigned twice somehow. But what puzzles me is that "parsed" is only set to "true" when someone calls any of the getParameterXXXX() methods. But because userland code hasn't been executed so far this is impossible. This all happens within a single thread and within two classes of Tomcat source code. What is going on? I also had some debug code in the "recycle" method to check - assuming that recycle is called fine - if everything gets cleared, including the "parsed" flag. This shows the correct behaviour during all my testing, ie. everything is cleared fine. Also I wrapped the call to "recycle" in Ajp13Request with a try/catch to see if maybe an error is thrown that would prevent a "recycle" being called - again, I never had any errors showing up at this point. Also when dumping the values from the request instance it looks like it is always cleared correctly; I have never seen some sort of "left overs" from a previous request, so recycling the request does not seem to be the issue. The only explanation I have so far is that somehow HttpRequestBase.parseParameters is called before the BaseRequest values (from the Ajp13 connection) are assigned to it. But having one single thread running through the Ajp13Processor and no trace of someone calling getParamXXXX(), how whould that happen? Just to explain, we use three servers that all show the same problem. Two are running Sun JDK 1.3.0_02 and one the newest Sun JDK 1.3.1_03, again to note, all show this behaviour. Tomcat was built with the Sun JDK 1.3.1_03 version for all of them. I recompiled Tomcat heaps of times with different debug output to find the problem and this has not changed anything, so it does not look like the infamous Heisenberg uncertainty, ie. recompiling or monitoring the code does not make the problem go away. Always the same problem, same spot. It does not seem to be load related as the number of errors just increases proportionally with the load; and even minor load causes the problem to show up. I am at the end of my wisdom here as to what this is related to or caused by. I appreciate any comments, ideas, suggestions etc. to clarify this issue. Yours faithfully, Lars -- To unsubscribe, e-mail: <mailto:[EMAIL PROTECTED]> For additional commands, e-mail: <mailto:[EMAIL PROTECTED]>
