You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by "Anthony J. Biacco" <ab...@formatdynamics.com> on 2009/04/16 01:49:08 UTC
mod_jk ping_timeout revisit
A month or so ago I posted that I was having problems with mod_jk
(1.2.27) getting a pong response back from tomcat (6.0.18) in responses
to a ping. Apache is 2.2.11 with worker mpm.
I have a little more information now and am hoping with help I can solve
the problem so I can keep the ping timeout low and get rid of the error.
Error does not show up when ping timeout is >= 25000.
My tomcat connectionTimeout is set to 60000
My jkwatchdoginterval is set to 60
My relevant workers.properties is:
worker.template.connection_pool_timeout=60
worker.template.reply_timeout=20000
worker.template.socket_timeout=10
worker.template.socket_connect_timeout=5000
worker.template.ping_mode=A
worker.template.ping_timeout=10000
The mod_jk error is:
[Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
wc_maintain::jk_worker.c (339): Maintaining worker app-01
[Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
ajp_maintain::jk_ajp_common.c (3081): reached pool min size 13 from 25
cache slots
[Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1070): sending to
ajp13 pos=4 len=5 max=16
[Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1070): 0000 12 34
00 01 0A 00 00 00 00 00 00 00 00 00 00 00 - .4..............
[Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
jk_shutdown_socket::jk_connect.c (681): About to shutdown socket 52
[Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
jk_shutdown_socket::jk_connect.c (732): Shutdown socket 52 and read 0
lingering bytes
[Wed Apr 15 17:25:06 2009] [23222:1085466944] [info]
ajp_connection_tcp_get_message::jk_ajp_common.c (1143): (app-01) can't
receive the response header message from tomcat, tomcat
(10.10.10.16:8009) has forced a connection close for socket 52
[Wed Apr 15 17:25:06 2009] [23222:1085466944] [info]
ajp_handle_cping_cpong::jk_ajp_common.c (876): awaited reply cpong, not
received
[Wed Apr 15 17:25:06 2009] [23222:1085466944] [info]
ajp_maintain::jk_ajp_common.c (3101): (app-01) failed sending request,
socket -1 keepalive cping/cpong failure (errno=0)
[Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
ajp_reset_endpoint::jk_ajp_common.c (743): (app-01) resetting endpoint
with sd = 4294967295 (socket shutdown)
[Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
ajp_maintain::jk_ajp_common.c (3126): pinged 1 sockets in 0 seconds from
25 pool slots
I send a request to tomcat via apache/mod_jk. Request's mount is mapped
to worker, not loadbalancer.
After successful request, Tomcat manager status shows the socket in
stage 'R' and keeped alive socket count as 1.
After 60 seconds, Tomcat manager status shows keeped alive socket count
as 0, socket still in stage 'R'
Above error happens 2 minutes after a request is finished, I'm assuming
because the keep alive socket is not there anymore.
So I set tomcat's connectionTimeout to 0 and repeat request.
This time Tomcat (after 60 seconds) doesn't reset the keeped alive
socket count to 0 (as expected), socket still in stage 'R'.
2 minutes later from mod_jk I get:
[Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
wc_maintain::jk_worker.c (339): Maintaining worker app-01
[Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
ajp_maintain::jk_ajp_common.c (3081): reached pool min size 13 from 25
cache slots
[Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1070): sending to
ajp13 pos=4 len=5 max=16
[Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
ajp_connection_tcp_send_message::jk_ajp_common.c (1070): 0000 12 34
00 01 0A 00 00 00 00 00 00 00 00 00 00 00 - .4..............
[Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1259): received from
ajp13 pos=0 len=1 max=16
[Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1259): 0000 09 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 - ................
[Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
ajp_maintain::jk_ajp_common.c (3126): pinged 1 sockets in 0 seconds from
25 pool slots
At this point tomcat manager status shows the socket in stage 'P' and
keeped alive socket count is 0.
Above mod_jk log repeats every 2 minutes. Tomcat manager status doesn't
change.
Any help is appreciated.
-Tony
---------------------------
Manager, IT Operations
Format Dynamics, Inc.
303-573-1800x27
abiacco@formatdynamics.com
http://www.formatdynamics.com
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
RE: mod_jk ping_timeout revisit
Posted by "Anthony J. Biacco" <ab...@formatdynamics.com>.
> >>> So I set tomcat's connectionTimeout to 0 and repeat request.
> >>> This time Tomcat (after 60 seconds) doesn't reset the keeped alive
socket count to 0 (as expected), socket still > > >>> in stage 'R'.
> >>>
> >>> ...
> >>>
> >> We saw that. Since Cping/Cpong worked, we do not even have an info
> >> message, only debug messages.
> >>
> >>> At this point tomcat manager status shows the socket in stage 'P'
> >>> and
> >>> keeped alive socket count is 0.
> >>> Above mod_jk log repeats every 2 minutes. Tomcat manager status
> >>> doesn't
> >>> change.
> >
> > Is it me or is this a better situation to be in?
> > I'm not sure about the 'P' stage though, if it's suppose to be that
> way,
> > or if it should be back at 'R' at this point.
>
> Sorry, I'm to lazy (busy) at the moment to check, what exactly 'P' and
> 'R' for AJP connections in the Tomcat manager mean.
>
P is 'Parse and prepare request'
R is 'Ready' (which is the norm state it seems)
I haven't been able to find out any more meaning of these through
searching.
-Tony
---------------------------
Manager, IT Operations
Format Dynamics, Inc.
303-573-1800x27
abiacco@formatdynamics.com
http://www.formatdynamics.com
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: mod_jk ping_timeout revisit
Posted by Rainer Jung <ra...@kippdata.de>.
On 17.04.2009 01:30, Anthony J. Biacco wrote:
>> On 16.04.2009 01:49, Anthony J. Biacco wrote:
>>> worker.template.socket_timeout=10
>> I'm not very much in favor of the socket_timeout, but well, if you
>> think
>> you need it. Just for the sake of completeness, please check, whether
>> having no socket_timeout changes anything about your problem.
>>
>
> Confirmed same errors with socket_timeout commented out
Good to know.
>> (*) We failed to read the Cpoong response. Note that we are still in
>> the
>> same second, so the wait time did not expire. We must have had some
>> other failure.
>>
>> My expectation: Tomcat closed the connection due to connectionTimeout.
>> mod_jk didn't check the connection_pool_timeout for this connection,
>> because our pool is already small enough (13 conns).
>>
>> Try setting connection_pool_minsize to "0" and check, whether the
>> observation goes away. Even with minsize "0", it can happen rarely,
>> because Tomcat closes the connection at the moment the
>> connectionTimeout
>> is reached, whereas mod_jk needs to run the internal maintenance (once
>> a
>> minute) to check the idle connection timeouts.
>>
>
> With connection_pool_minsize=0 I can confirm the different event from
> mod_jk after the tomcat connectionTimeout.
All of the log lines were debug then. So with normal log level setting
info, you won't get any disturbing log output.
>> *But*: I don't fully understand, why the problem goes away by
> switching
>> to a ping timeout of 25000 milliseconds. Maybe the 10 second
>> socket_timeout hides the thing in this case [wild guess]. There is
> also
>> a relation between the ping_timeout and which connections do get
>> checked
>> during maintenance (the connection_ping_interval). So a longer
>> ping_timeout reduces also the frequency of ping checks, so it should
>> also reduce the frequency of the info messages. Not sure whether the
>> combination of all results in not getting them any longer.
>>
>
> If I increase the ping timeout to 20000 the maintaining worker process
> still executes 2 minutes (almost to the second) after the tomcat request
> finished. No error. The 3rd minute's process, same. It isn't until 4
> minutes after the tomcat request finished that I get the cpong error.
> If I set connection_ping_interval to something like 10 (with a 10000
> ping_timeout), the cpong error shows up 1 minute after the tomcat
> request finished instead of 2.
OK, so that explains why the cping/cpong info log depends on the
ping_timeout (via the relation to the inerval).
>> Go with connection_pool_minsize=0 and ignore very occasional info
> level
>> messages.
>>
>
> Will this affect my performance since it won't keep any connections in
> the pool and have to recreate one on every request?
No it won't. Connections will only be shut down, when they are idle for
more than a minute (the pool timeout xou configured). So if your site is
busy only very few of your connections (peak load connections) will be
closed, all other connections will stay open and be reused.
Testing with occasional clicks doesn't reveal that behaviour.
If the site is not busy, then the connection creation overhead will be
more frequent, but due to the small load on the system it will be no
problem at all for your system resources, and the latency you add in a
normal LAN will be in the single digit milliseconds range.
> As long as the ping without pong isn't going to break anything (like you
> said, it's info, not error (just sounds like a not-good thing)), i'm
> fine with it.
Right.
>> You could have a look at "netstat -an | grep 8009" on the Apache
> server
>> (or whatever your AJP port is) and see, how the status of the
>> connections changes, e.g. from ESTABLISHED to CLOSE_WAIT (remote side
>> has closed the connection) and TIME_WAIT (local side has also closed
>> the
>> connection).
>
> After a tomcat request I have:
> tcp 0 0 10.10.10.18:13597 10.10.10.16:8009
> ESTABLISHED
>
> After the tomcat connectiontimeout I have:
> tcp 1 0 10.10.10.18:13597 10.10.10.16:8009
> CLOSE_WAIT
Yes, so you can see Tomcat closed the connection, and mod_jk didn't yet
do the same.
> After the cpong error I have nothing/no connection
With minsize > 0 we might not close the connection although the idle
timeout has passed and the cping will detect the CLOSE_WAIT status and
as a result mod_jk will close it to. With minsize==0 we will already
close it because of idleness and there will be no need for the cping
test, since the connection doesn't exist any more.
> Because of the connectionTimeout in tomcat and the cpong failure, it
> seems like I'm defeating the purpose of a connection pool anyway, no?
> Since the tomcat socket close is minutes later causing the mod_jk socket
> close.
No, think about a busy situation. Then the most connections will not be
idle for a long time, nd thus neither tomcat nor mod_jk will have a
reason to close them.
>> We saw that. Since Cping/Cpong worked, we do not even have an info
>> message, only debug messages.
>>
>>> At this point tomcat manager status shows the socket in stage 'P'
> and
>>> keeped alive socket count is 0.
>>> Above mod_jk log repeats every 2 minutes. Tomcat manager status
>> doesn't
>>> change.
>
> Is it me or is this a better situation to be in?
> I'm not sure about the 'P' stage though, if it's suppose to be that way,
> or if it should be back at 'R' at this point.
Sorry, I'm to lazy (busy) at the moment to check, what exactly 'P' and
'R' for AJP connections in the Tomcat manager mean.
Regards,
Rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
RE: mod_jk ping_timeout revisit
Posted by "Anthony J. Biacco" <ab...@formatdynamics.com>.
Rainer thanx for the input, comments below.
>
> On 16.04.2009 01:49, Anthony J. Biacco wrote:
> > A month or so ago I posted that I was having problems with mod_jk
> > (1.2.27) getting a pong response back from tomcat (6.0.18) in
> responses
> > to a ping. Apache is 2.2.11 with worker mpm.
> >
> > I have a little more information now and am hoping with help I can
> solve
> > the problem so I can keep the ping timeout low and get rid of the
> error.
> > Error does not show up when ping timeout is >= 25000.
>
> It sounds like you can easily reproduce on a test system?
> If yes, despite what I'll write below, increasing the log level to
> trace
> presents even more info for us developers, so in case we do another
> test, please adjust the log level. But debug is fine for now.
>
Yes, this is a test system, so the requests I'm sending are the only
ones going into it.
>
> > worker.template.socket_timeout=10
>
> I'm not very much in favor of the socket_timeout, but well, if you
> think
> you need it. Just for the sake of completeness, please check, whether
> having no socket_timeout changes anything about your problem.
>
Confirmed same errors with socket_timeout commented out
>
> (*) We failed to read the Cpoong response. Note that we are still in
> the
> same second, so the wait time did not expire. We must have had some
> other failure.
>
> My expectation: Tomcat closed the connection due to connectionTimeout.
> mod_jk didn't check the connection_pool_timeout for this connection,
> because our pool is already small enough (13 conns).
>
> Try setting connection_pool_minsize to "0" and check, whether the
> observation goes away. Even with minsize "0", it can happen rarely,
> because Tomcat closes the connection at the moment the
> connectionTimeout
> is reached, whereas mod_jk needs to run the internal maintenance (once
> a
> minute) to check the idle connection timeouts.
>
With connection_pool_minsize=0 I can confirm the different event from
mod_jk after the tomcat connectionTimeout.
This is for a request finished at 16:42:12.
[Thu Apr 16 16:44:08 2009] [26891:1114327360] [debug]
wc_maintain::jk_worker.c (339): Maintaining worker app-01
[Thu Apr 16 16:44:08 2009] [26891:1114327360] [debug]
ajp_reset_endpoint::jk_ajp_common.c (743): (app-01) resetting endpoint
with sd = 52 (socket shutdown)
[Thu Apr 16 16:44:08 2009] [26891:1114327360] [debug]
jk_shutdown_socket::jk_connect.c (681): About to shutdown socket 52
[Thu Apr 16 16:44:08 2009] [26891:1114327360] [debug]
jk_shutdown_socket::jk_connect.c (732): Shutdown socket 52 and read 0
lingering bytes
[Thu Apr 16 16:44:08 2009] [26891:1114327360] [debug]
ajp_maintain::jk_ajp_common.c (3074): cleaning pool slot=0 elapsed 116
in 0
[Thu Apr 16 16:44:08 2009] [26891:1114327360] [debug]
ajp_maintain::jk_ajp_common.c (3081): reached pool min size 0 from 25
cache slots
[Thu Apr 16 16:44:08 2009] [26891:1114327360] [debug]
ajp_maintain::jk_ajp_common.c (3121): recycled 1 sockets in 0 seconds
from 25 pool slots
>
> *But*: I don't fully understand, why the problem goes away by
switching
> to a ping timeout of 25000 milliseconds. Maybe the 10 second
> socket_timeout hides the thing in this case [wild guess]. There is
also
> a relation between the ping_timeout and which connections do get
> checked
> during maintenance (the connection_ping_interval). So a longer
> ping_timeout reduces also the frequency of ping checks, so it should
> also reduce the frequency of the info messages. Not sure whether the
> combination of all results in not getting them any longer.
>
If I increase the ping timeout to 20000 the maintaining worker process
still executes 2 minutes (almost to the second) after the tomcat request
finished. No error. The 3rd minute's process, same. It isn't until 4
minutes after the tomcat request finished that I get the cpong error.
If I set connection_ping_interval to something like 10 (with a 10000
ping_timeout), the cpong error shows up 1 minute after the tomcat
request finished instead of 2.
> Go with connection_pool_minsize=0 and ignore very occasional info
level
> messages.
>
Will this affect my performance since it won't keep any connections in
the pool and have to recreate one on every request?
As long as the ping without pong isn't going to break anything (like you
said, it's info, not error (just sounds like a not-good thing)), i'm
fine with it.
> > I send a request to tomcat via apache/mod_jk. Request's mount is
> mapped
> > to worker, not loadbalancer.
> > After successful request, Tomcat manager status shows the socket in
> > stage 'R' and keeped alive socket count as 1.
> > After 60 seconds, Tomcat manager status shows keeped alive socket
> count
> > as 0, socket still in stage 'R'
> > Above error happens 2 minutes after a request is finished, I'm
> assuming
> > because the keep alive socket is not there anymore.
>
> You could have a look at "netstat -an | grep 8009" on the Apache
server
> (or whatever your AJP port is) and see, how the status of the
> connections changes, e.g. from ESTABLISHED to CLOSE_WAIT (remote side
> has closed the connection) and TIME_WAIT (local side has also closed
> the
> connection).
After a tomcat request I have:
tcp 0 0 10.10.10.18:13597 10.10.10.16:8009
ESTABLISHED
After the tomcat connectiontimeout I have:
tcp 1 0 10.10.10.18:13597 10.10.10.16:8009
CLOSE_WAIT
After the cpong error I have nothing/no connection
Because of the connectionTimeout in tomcat and the cpong failure, it
seems like I'm defeating the purpose of a connection pool anyway, no?
Since the tomcat socket close is minutes later causing the mod_jk socket
close.
>
> We saw that. Since Cping/Cpong worked, we do not even have an info
> message, only debug messages.
>
> > At this point tomcat manager status shows the socket in stage 'P'
and
> > keeped alive socket count is 0.
> > Above mod_jk log repeats every 2 minutes. Tomcat manager status
> doesn't
> > change.
Is it me or is this a better situation to be in?
I'm not sure about the 'P' stage though, if it's suppose to be that way,
or if it should be back at 'R' at this point.
Much thanx,
-Tony
---------------------------
Manager, IT Operations
Format Dynamics, Inc.
303-573-1800x27
abiacco@formatdynamics.com
http://www.formatdynamics.com
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: mod_jk ping_timeout revisit
Posted by Rainer Jung <ra...@kippdata.de>.
Hi Anthony,
On 16.04.2009 01:49, Anthony J. Biacco wrote:
> A month or so ago I posted that I was having problems with mod_jk
> (1.2.27) getting a pong response back from tomcat (6.0.18) in responses
> to a ping. Apache is 2.2.11 with worker mpm.
>
> I have a little more information now and am hoping with help I can solve
> the problem so I can keep the ping timeout low and get rid of the error.
> Error does not show up when ping timeout is >= 25000.
It sounds like you can easily reproduce on a test system?
If yes, despite what I'll write below, increasing the log level to trace
presents even more info for us developers, so in case we do another
test, please adjust the log level. But debug is fine for now.
> My tomcat connectionTimeout is set to 60000
> My jkwatchdoginterval is set to 60
> My relevant workers.properties is:
> worker.template.connection_pool_timeout=60
> worker.template.reply_timeout=20000
Not related to your ping observation, but if you really want to set your
reply_timeout that small, consider using max_reply_timeouts too.
Otherwise one single long running request will throw the whole worker
out of the balancing for some time (due to the reply_timeout indicating
a failed node).
> worker.template.socket_timeout=10
I'm not very much in favor of the socket_timeout, but well, if you think
you need it. Just for the sake of completeness, please check, whether
having no socket_timeout changes anything about your problem.
> worker.template.socket_connect_timeout=5000
> worker.template.ping_mode=A
> worker.template.ping_timeout=10000
>
> The mod_jk error is:
First of all, we note that the process id and thread id in all those log
lines is 23222:1085466944. So all lines come from the same thread. There
are no lines mixed between two or more concurrent things going on. The
log lines reflect some sequential thing going on.
> [Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
> wc_maintain::jk_worker.c (339): Maintaining worker app-01
We start doing internal maintenance, i.e. checking for idle connections,
doing ping (if it is the watchdog thread and interval ping is active -
it is for your config), adjust some load numbers etc.
> [Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
> ajp_maintain::jk_ajp_common.c (3081): reached pool min size 13 from 25
> cache slots
OK, our connection pool will not be checked for more idle connections,
because we already reached the configured (=default) minimum. I think
here's the culprit.
If connections would have been closed due to idleness
(connection_pool_timeout), there would have been a message of type
"cleaning pool slot=XX elapsed NN in MM". NN would be the idle time, MM
how long it took to close the connection.
Checking the idleness stopps as soon as we reach the allowed min pool
size, which is immediately the case here.
> [Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
> ajp_connection_tcp_send_message::jk_ajp_common.c (1070): sending to
> ajp13 pos=4 len=5 max=16
We are doing a Cping/Cpong test
> [Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
> ajp_connection_tcp_send_message::jk_ajp_common.c (1070): 0000 12 34
> 00 01 0A 00 00 00 00 00 00 00 00 00 00 00 - .4..............
Send the Cping packet over the wire
> [Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
> jk_shutdown_socket::jk_connect.c (681): About to shutdown socket 52
This is a consequence of the line marked with (*)
Shutting down the connection.
> [Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
> jk_shutdown_socket::jk_connect.c (732): Shutdown socket 52 and read 0
> lingering bytes
Yep, we shut it down.
> [Wed Apr 15 17:25:06 2009] [23222:1085466944] [info]
> ajp_connection_tcp_get_message::jk_ajp_common.c (1143): (app-01) can't
> receive the response header message from tomcat, tomcat
> (10.10.10.16:8009) has forced a connection close for socket 52
(*) We failed to read the Cpoong response. Note that we are still in the
same second, so the wait time did not expire. We must have had some
other failure.
My expectation: Tomcat closed the connection due to connectionTimeout.
mod_jk didn't check the connection_pool_timeout for this connection,
because our pool is already small enough (13 conns).
Try setting connection_pool_minsize to "0" and check, whether the
observation goes away. Even with minsize "0", it can happen rarely,
because Tomcat closes the connection at the moment the connectionTimeout
is reached, whereas mod_jk needs to run the internal maintenance (once a
minute) to check the idle connection timeouts.
On a more busy server this happens fewer times, because we try to reuse
the connections used most recently, so idle connections tend to not get
reused and then detecting them every now and then is enough.
> [Wed Apr 15 17:25:06 2009] [23222:1085466944] [info]
> ajp_handle_cping_cpong::jk_ajp_common.c (876): awaited reply cpong, not
> received
Yeah, we saw that in the debug lines.
> [Wed Apr 15 17:25:06 2009] [23222:1085466944] [info]
> ajp_maintain::jk_ajp_common.c (3101): (app-01) failed sending request,
> socket -1 keepalive cping/cpong failure (errno=0)
Yeah.
> [Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
> ajp_reset_endpoint::jk_ajp_common.c (743): (app-01) resetting endpoint
> with sd = 4294967295 (socket shutdown)
Yeah.
> [Wed Apr 15 17:25:06 2009] [23222:1085466944] [debug]
> ajp_maintain::jk_ajp_common.c (3126): pinged 1 sockets in 0 seconds from
> 25 pool slots
OK.
So all we can see is info level messages. Our usual rule is: as long as
you only see info, there's no problem. Any [error] should be analyzed
and understood, and the infos can be helpful then. Infos by themselves
should be harmless. If my analysis above is right, then yes, the ones
you get are harmless.
*But*: I don't fully understand, why the problem goes away by switching
to a ping timeout of 25000 milliseconds. Maybe the 10 second
socket_timeout hides the thing in this case [wild guess]. There is also
a relation between the ping_timeout and which connections do get checked
during maintenance (the connection_ping_interval). So a longer
ping_timeout reduces also the frequency of ping checks, so it should
also reduce the frequency of the info messages. Not sure whether the
combination of all results in not getting them any longer.
Go with connection_pool_minsize=0 and ignore very occasional info level
messages.
> I send a request to tomcat via apache/mod_jk. Request's mount is mapped
> to worker, not loadbalancer.
> After successful request, Tomcat manager status shows the socket in
> stage 'R' and keeped alive socket count as 1.
> After 60 seconds, Tomcat manager status shows keeped alive socket count
> as 0, socket still in stage 'R'
> Above error happens 2 minutes after a request is finished, I'm assuming
> because the keep alive socket is not there anymore.
You could have a look at "netstat -an | grep 8009" on the Apache server
(or whatever your AJP port is) and see, how the status of the
connections changes, e.g. from ESTABLISHED to CLOSE_WAIT (remote side
has closed the connection) and TIME_WAIT (local side has also closed the
connection).
> So I set tomcat's connectionTimeout to 0 and repeat request.
> This time Tomcat (after 60 seconds) doesn't reset the keeped alive
> socket count to 0 (as expected), socket still in stage 'R'.
> 2 minutes later from mod_jk I get:
Again everything is happening in one thread serially.
> [Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
> wc_maintain::jk_worker.c (339): Maintaining worker app-01
Starting internal maintenance.
> [Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
> ajp_maintain::jk_ajp_common.c (3081): reached pool min size 13 from 25
> cache slots
> [Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
> ajp_connection_tcp_send_message::jk_ajp_common.c (1070): sending to
> ajp13 pos=4 len=5 max=16
Send Cping
> [Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
> ajp_connection_tcp_send_message::jk_ajp_common.c (1070): 0000 12 34
> 00 01 0A 00 00 00 00 00 00 00 00 00 00 00 - .4..............
Putting it on the wire
> [Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
> ajp_connection_tcp_get_message::jk_ajp_common.c (1259): received from
> ajp13 pos=0 len=1 max=16
Hey we immediately get an answer
> [Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
> ajp_connection_tcp_get_message::jk_ajp_common.c (1259): 0000 09 00 00
> 00 00 00 00 00 00 00 00 00 00 00 00 00 - ................
Fine it's a Cpong packet
> [Wed Apr 15 17:30:08 2009] [23251:1102088512] [debug]
> ajp_maintain::jk_ajp_common.c (3126): pinged 1 sockets in 0 seconds from
> 25 pool slots
We saw that. Since Cping/Cpong worked, we do not even have an info
message, only debug messages.
> At this point tomcat manager status shows the socket in stage 'P' and
> keeped alive socket count is 0.
> Above mod_jk log repeats every 2 minutes. Tomcat manager status doesn't
> change.
Regards,
Rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org