tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Mark Thomas <>
Subject Re: Single POST request being handled twice
Date Thu, 17 Nov 2011 07:53:45 GMT
On 17/11/2011 01:29, Jeremy wrote:
> OK, I know this seems crazy, but I've looked long and hard and cannot
> explain this as other than a Tomcat bug.  I'm more than willing to dig up
> extra information where I can, but this is a very rare problem seen in
> production and not reproducible at will.  Also, because this is in
> production, there is very little I can change, and even if I did change it,
> it would take a month or more to verify that it is really a fix.  So what
> I'm really looking for is a detailed understanding of the problem so we can
> detect it when it happens and clean up the after-effects.
> What we are seeing is one POST request being handled twice by our web app.
>  It looks as though somehow the request is duplicated by Tomcat.  Here's
> our setup:
> Apache 2.2.14 using APR 1.3.8 and mod_jk 1.2.28 running on Ubuntu 10.04.3
> as front end, load balancing.
> Tomcat 6.0.29 using built-in AJP/1.3 connector running on Ubuntu 9.04 with
> 64-bit Sun Java 1.5.0_19.  Tomcat is not using APR.
> Tomcat mod_jk connector has keepAliveTimeout=5000 and
> connectionTimeout=60000 (60 seconds).
> Here is a simplified timeline of what we see in various logs.  I'm going to
> leave some fields out and change others to protect confidentiality and make
> it easier to follow, but I'll try to keep from changing anything important.
>  Timestamps are just minutes and seconds.
> 51:48 POST request received by Apache over SSL.  We see the request logged
> in Apache's access.log with this timestamp, but the log entry is actually
> written at 52:08 (or seems to be, since that is the time stamp of the next
> entry in the access.log, though the entries immediately before this one
> have timestamps of 52:02).
> 51:48 log4j application logs show processing of the request by the
> application in thread TP-Processor18.   Processing continues with updates
> to database and external systems until:
> 51:55 last application log entry from TP-Processor18 shows normal
> completion of processing, which should then return from handleRequest().
>  The database and three external systems the app communicates with all show
> normal processing.
> 51:55 log4j application log entries from TP-Processor6 show it beginning to
> handle the request.  Processing continues normally, just as it did in
> TP-Processor18 until:
> 52:08 last application log entry from TP-Processor6.  Again external
> systems show normal processing.
> 52:08 Tomcat access log shows entry for post request stating it was handled
> by TP-Processor6 in 7283ms
> 52:08 mod_jk.log: loadbalancer 19.400742
> 53:06 Tomcat access log shows entry for post request stating it was handled
> by TP-Processor18 in 77440ms
> How is it possible that Tomcat has 2 threads handling the same request?

Because I think there are two requests here, rather than one.

My guess as to what is happening is as follows:
- httpd sends request to Tomcat
- Tomcat processes it
- network glitch or similar means httpd never receives the response
- httpd resends request to Tomcat
- Tomcat processes it
- httpd receives the response
- httpd sends response to user

Examining the mod_jk logs on httpd should show this although I don't
know what level of logging you'll need to see it.

The only hitch with the above is that I'd expect httpd to take longer to
realise that there is a problem before re-trying the request.

> How can we detect this as opposed to the user legitimately sending the same
> request twice?

Use mod_unique_id with mod_rewrite to add the unique ID as a url
parameter and then include this in Tomcat's access log and/or write a
filter that checks for duplicates.

> Thanks for your help!

The situation you describe could also be triggered by a Tomcat bug. You
might want to try protocol="org.apache.coyote.ajp.AjpProtocol" on the
connector to switch the the Coyote AJP BIO implementation.


> =Jeremy=

To unsubscribe, e-mail:
For additional commands, e-mail:

View raw message