You are viewing a plain text version of this content. The canonical link for it is here.
Posted to bugs@httpd.apache.org by bu...@apache.org on 2006/04/06 07:03:58 UTC
DO NOT REPLY [Bug 38227] - AJP proxy not thread-safe?
DO NOT REPLY TO THIS EMAIL, BUT PLEASE POST YOUR BUG�
RELATED COMMENTS THROUGH THE WEB INTERFACE AVAILABLE AT
<http://issues.apache.org/bugzilla/show_bug.cgi?id=38227>.
ANY REPLY MADE TO THIS MESSAGE WILL NOT BE COLLECTED AND�
INSERTED IN THE BUG DATABASE.
http://issues.apache.org/bugzilla/show_bug.cgi?id=38227
------- Additional Comments From jim.robinson@stanford.edu 2006-04-06 06:03 -------
Created an attachment (id=18031)
--> (http://issues.apache.org/bugzilla/attachment.cgi?id=18031&action=view)
Debugging output patch referenced in my comment.
I believe I'm seeing the same problem with my build of Apache 2.2.0
connecting to an instance of Tomcat 5.5.10.
THE SETUP
I'm running this on a dual cpu (Intel(R) Xeon(TM) CPU 2.80GHz) machine
running Linux 2.4.21-15.ELsmp. Apache server-info reveals:
-D APACHE_MPM_DIR="server/mpm/worker"
-D APR_HAS_SENDFILE -D APR_HAS_MMAP
-D APR_HAVE_IPV6 (IPv4-mapped addresses enabled)
-D APR_USE_SYSVSEM_SERIALIZE
-D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
-D APR_HAS_OTHER_CHILD
-D AP_HAVE_RELIABLE_PIPED_LOGS
-D HTTPD_ROOT="/usr/local/apache/2.2.0"
-D SUEXEC_BIN="/usr/local/apache/2.2.0/bin/suexec"
-D DEFAULT_ERRORLOG="logs/error_log"
-D AP_TYPES_CONFIG_FILE="conf/mime.types"
-D SERVER_CONFIG_FILE="conf/httpd.conf"
I'm using mod_proxy to balance incoming requests to an Apache
VirtualHost to a mounted Tomcat service via AJP. I think I've
included the important Apache configuration below:
<Proxy balancer://tomcat>
BalancerMember ajp://server.mydomain.org:8009 route=server.mydomain.org
</Proxy>
<VirtualHost vhost.mydomain.org:80>
RewriteEngine on
RewriteCond %{ENV:HTTPD_BASE}/logs/myapp.pause -f
RewriteRule .* - [forbidden,last]
RewriteRule ^(/+test(?:/.*)?)$ /myapp$1 [env=internal:yes]
RewriteCond %{ENV:internal} =yes
RewriteRule ^(/+myapp/.*) $1 [passthrough,last]
RewriteRule ^/+myapp/(.*) /$1 [redirect=permanent,last]
ProxyPass /myapp balancer://tomcat/myapp stickysession=JSESSIONID
nofailover=on
ProxyPassReverse / http://vhost.mydomain.org/myapp/
ProxyPassReverseCookiePath /myapp/ /
</VirtualHost>
My Tomcat Connector in server.xml is straightforward:
<Connector
protocol="AJP/1.3"
address="${catalina.hostname}"
port="8009"
enableLookups="false" />
So a user connects to
http://vhost.mydomain.org/test
and then mod_proxy will forward the request via AJP to
http://server.mydomain.org:8009/myapp/test
The 'test' servlet is a simple one. It computes a random number been
0 and 1000, and sleeps for that many milliseconds, before printing a
one line response to the client.
THE PROBLEM
Using this stripped down configuration, what I see when I use ab(1) to
load test the service, is that Tomcat is forced to keep creating new
threads to service incoming connections, and it leaves them in the
Keepalive state after ab(1) has finished. Tomcat also indicates it is
*using* those threads (perhaps polling on them?)
Every time I make a new request via mod_proxy, a new Thread is started
in Tomcat. However, when I query Tomcat directly, I see a thread get
created, the request gets serviced, and the thread is switch to the
Ready steady, indicating it is now able to to accept new requests.
If I run
netstat -t | egrep "^tcp.*:8009"
on the server, I see a constantly growing number of connections
between Apache and Tomcat. When I query Tomcat directly, I do not see
this growing pool of connections.
This lead me to believe the problem was mod_proxy keeping connections
open (perhaps the backend pooling code), but failing to either reuse
them, or perhaps failing to properly close them on cleanup.
THE DEBUGGING
First, I added some debugging to proxy_util.c. I've attached it to
this comment. Basically all I did was print out a stupid log message
when it first initializes, and then each time a connections is
acquired.
Now, starting up Apache I see this in the log:
[Wed Apr 05 21:09:35 2006] [error] 0: worker->hmax: 25, worker->cp->res: not
null
[Wed Apr 05 21:09:35 2006] [debug] proxy_util.c(1666): proxy: initialized
worker 0 in child 16610 for (server.mydomain.org) min=0 max=25 smax=25
[Wed Apr 05 21:09:35 2006] [error] 0: worker->hmax: 25, worker->cp->res: not
null
[Wed Apr 05 21:09:35 2006] [debug] proxy_util.c(1666): proxy: initialized
worker 2 in child 16610 for (*) min=0 max=25 smax=25
For my test I first see if any connections exist to Tomcat (there
should not be any):
; netstat -t | egrep "^tcp.*:8009" | tr -s " "
As I expect, no connections exist. Next, on a different machine, I
make a single request to my virtual host:
ab -n 1 http://vhost.mydomain.org/test
It completes, and tells me it was successful. I see a bunch of
debugging in the log indicating mod_proxy is working. In the chatter,
I see my own debugging lines:
[Wed Apr 05 21:09:43 2006] [error] 1: worker->hmax: 0, worker->cp->res: not
null
[Wed Apr 05 21:09:43 2006] [error] 2: called connection_constructor
This surprises me for two reasons. First of all, I was expecting
worker->hmax to be 25, not 0. The second reason is that I expected to
see that worker->cp->res have a value, not to be null.
[As an aside, subsequent testing showed that if I added 'max=25' to
the BalanceMember configuration directive, worker->hmax would be 25 in
requests; the null value for worker->cp->res did not change.]
Now, I check on my server to see if any connections exist (I expect a
connection, due to the connection pooling):
; netstat -t | egrep "^tcp.*:8009" | tr -s " "
tcp 0 0 server.mydomain.org:8009 server.mydomain.org:39642 ESTABLISHED
tcp 0 0 server.mydomain.org:39642 server.mydomain.org:8009 ESTABLISHED
Now, if I run a second request, I would have expected mod_proxy_ajp to
reuse the existing connection. But look what happens after I ran my
ab command a second time:
[Wed Apr 05 21:09:46 2006] [error] 1: worker->hmax: 0, worker->cp->res: null
[Wed Apr 05 21:09:46 2006] [error] 2: called connection_constructor
And netstat shows two *new* connections, for a total of four:
; netstat -t | egrep "^tcp.*:8009" | tr -s " "
tcp 0 0 server.mydomain.org:8009 server.mydomain.org:39753 ESTABLISHED
tcp 0 0 server.mydomain.org:8009 server.mydomain.org:39642 ESTABLISHED
tcp 0 0 server.mydomain.org:39753 server.mydomain.org:8009 ESTABLISHED
tcp 0 0 server.mydomain.org:39642 server.mydomain.org:8009 ESTABLISHED
I tried making a number of connections, and watched the connections
grow until it filled all available threads on my Tomcat container
(which was set to the default maxThreads of 200). First, I reset
everything:
; apachectl stop
; catalina.sh stop
; apachectl start
; catalina.sh start
; netstat -t | egrep "^tcp.*:8009" | tr -s " "|wc -l
0
And then on my test client I make 200 connections:
ab -n 200 http://vhost.mydomain.org/test
and then my server shows over 400 established connections:
; netstat -t | egrep "^tcp.*:8009" | tr -s " "|grep -c ESTABLISHED
466
Ack!
If I tweak the proxy code, setting one of these the 'close'
flags to true:
conn->close_on_recycle = 1;
conn->close = 1;
Then Apache cleans itself up, and Tomcat does not get overwhelmed.
What I'm unable to determine so far is if this is a problem with
mod_proxy(_(balance|ajp))?.c, a problem with Tomcat + Apache, a
problem with the APR utilities, etc. :(
Any insights from folks would be much appreciated!
Apologies for the long post...
Jim
--
Configure bugmail: http://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org