Re: does this mod_jk.log look healthy?
Thanks for Your answer. There are at least two (watchdog) ajp requests through the web server to the workers every minute, and as i wrote, the ajp connection_pool_timeout ist 600, connectionTimeout in Tomcats server.xml is accordingly 60. So I cannot image how the web server can be more idle than the pool timeout, even at busy daytime, where the log messages also occure every few minutes? We will look forward to upgrade to 1.2.26. 2009/1/27 Rainer Jung rainer.j...@kippdata.de Without additional error level messages that's OK. The web server noticed, that there was no connection to the backend open and will transparently create a new one. This could happen, if your web server is more idle than configured with the JK connection pool timeout or Tomcat's connectionTimeout. You should update to 1.2.27, it's better than 1.2.23 :)
Re: does this mod_jk.log look healthy?
On 28.01.2009 12:00, Arne Riecken wrote:
Thanks for Your answer.
There are at least two (watchdog) ajp requests through the web server to the
workers every minute, and as i wrote, the ajp connection_pool_timeout ist
600, connectionTimeout in Tomcats server.xml is accordingly 60. So I
cannot image how the web server can be more idle than the pool timeout, even
at busy daytime, where the log messages also occure every few minutes?
We will look forward to upgrade to 1.2.26.
The pool is local to any Apache httpd process. I assume your requests
get distributed to more than one httpd process. You can log the process
ID of the httpd process with %P in the access log, and if you are using
a multi-threaded MPM (worker) also the thread id (%{tid}P).
1.2.27 would be better than 1,2,26 ;)
Regards,
Rainer
2009/1/27 Rainer Jungrainer.j...@kippdata.de
Without additional error level messages that's OK. The web server noticed,
that there was no connection to the backend open and will transparently
create a new one. This could happen, if your web server is more idle than
configured with the JK connection pool timeout or Tomcat's
connectionTimeout.
You should update to 1.2.27, it's better than 1.2.23 :)
-
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
Re: does this mod_jk.log look healthy?
Hi, On 27.01.2009 13:20, Arne Riecken wrote: Hi, please have a look at the mod_jk.log. Can anyone say if these info-entrys are normal or if the system is unhealthy? Or might the network be bad? These entrys come at least two times per hour. 1) All messages are info level, that's good. 2) All messages with the same process id and thread id (the number pair following the timestamp) and close to each other in time belong to the same event. 3) In you log excerpt, there are two types of events: a) client abort ajp_process_callback::jk_ajp_common.c (1448): Writing to client aborted or client network problems ajp_service::jk_ajp_common.c (1857): (worker6) request failed, because of client write error without recovery in send loop attempt=0 service::jk_lb_worker.c (1068): unrecoverable error 200, request failed. Client failed in the middle of request, we can't recover to another instance. jk_handler::mod_jk.c (2158): Aborting connection for worker=routerExt2 Client write error means, that when sending back data to the browser, the web server realized that the browser already closed the connection. Most likely the user decided to click on some link while waiting for a response. If this happens only occasionally, it should be fine. If it happens very often it might be an indication for performance problems, i.e. your users clicking repeatedly on the same links, because they don't get a fast answer. b) idle connection timeouts ajp_send_request::jk_ajp_common.c (1215): (worker1) error sending request. Will try another pooled connection ajp_send_request::jk_ajp_common.c (1241): (worker1) all endpoints are disconnected ajp_send_request::jk_ajp_common.c (1244): (worker1) increase the backend idle connection timeout or the connection_pool_minsize ajp_service::jk_ajp_common.c (1941): (worker1) sending request to tomcat failed, recoverable operation attempt=1 Without additional error level messages that's OK. The web server noticed, that there was no connection to the backend open and will transparently create a new one. This could happen, if your web server is more idle than configured with the JK connection pool timeout or Tomcat's connectionTimeout. 4) Please keep info log level. As long as there are no warn or error messages, everything is fine, but once there are error messages, the aditional info messages are helpful. You should update to 1.2.27, it's better than 1.2.23 :) Regards, Rainer Thanks. mod_jk 1.2.23 Apache 1.3.34 Tomcat 5.5.20 socket_keepalive=False connect_timeout=3 prepost_timeout=3 connection_pool_timeout=600 all others default Firewall is dropping idle connections after 1h. [Sat Jan 24 01:07:15 2009] [29654:] [info] ajp_process_callback::jk_ajp_common.c (1448): Writing to client ab orted or client network problems [Sat Jan 24 01:07:15 2009] [29654:] [info] ajp_service::jk_ajp_common.c (1857): (worker6) request failed, because of client write error without recovery in send loop attempt=0 [Sat Jan 24 01:07:15 2009] [29654:] [info] service::jk_lb_worker.c (1068): unrecoverable error 200, request failed. Client failed in the middle of request, we can't recover to another instance. [Sat Jan 24 01:07:15 2009] [29654:] [info] jk_handler::mod_jk.c (2158): Aborting connection for worker=routerExt2 [Sat Jan 24 01:08:53 2009] [31110:] [info] ajp_send_request::jk_ajp_common.c (1215): (worker1) error sending request. Will try another pooled connection [Sat Jan 24 01:08:53 2009] [31110:] [info] ajp_send_request::jk_ajp_common.c (1241): (worker1) all endpoints are disconnected [Sat Jan 24 01:08:53 2009] [31110:] [info] ajp_send_request::jk_ajp_common.c (1244): (worker1) increase the backend idle connection timeout or the connection_pool_minsize [Sat Jan 24 01:08:53 2009] [31110:] [info] ajp_service::jk_ajp_common.c (1941): (worker1) sending request to tomcat failed, recoverable operation attempt=1 [Sat Jan 24 01:14:46 2009] [31781:] [info] ajp_send_request::jk_ajp_common.c (1215): (worker1) error sending request. Will try another pooled connection [Sat Jan 24 01:14:46 2009] [31781:] [info] ajp_send_request::jk_ajp_common.c (1241): (worker1) all endpoints are disconnected [Sat Jan 24 01:14:46 2009] [31781:] [info] ajp_send_request::jk_ajp_common.c (1244): (worker1) increase the backend idle connection timeout or the connection_pool_minsize [Sat Jan 24 01:14:46 2009] [31781:] [info] ajp_service::jk_ajp_common.c (1941): (worker1) sending request to tomcat failed, recoverable operation attempt=1 [Sat Jan 24 01:15:04 2009] [31959:] [info] ajp_send_request::jk_ajp_common.c (1215): (worker9) error sending request. Will try another pooled connection [Sat Jan 24 01:15:04 2009] [31959:] [info] ajp_send_request::jk_ajp_common.c (1241): (worker9) all endpoints are disconnected [Sat Jan 24 01:15:04 2009] [31959:] [info] ajp_send_request::jk_ajp_common.c (1244): (worker9) increase the backend idle
Re: does this mod_jk.log look healthy?
Hi. Sorry to invade/hijack, but I believe the following is very similar to the original OP's request. Rainer, I have a case very similar to the one below at a customer, running under RHEL 5, with Apache 2.0.x, mod_jk 1.2.28 (dev) and Tomcat 5.5.x. (the mod_jk 1.2.6 originally installed showed the same issues, only slightly different error messages). I also have both kinds of messages, like the OP (from mod_jk to client, and from mod_jk to Tomcat). What concerns me is the ones to the clients. These messages happen very regularly (every few minutes), sometimes in bursts. It is pretty-well established that the users do not click away from the page and do not click the cancel button. The browser is IE6, and often returns a This page cannot be displayed (friendly IE error message, which unfortunately cannot be turned off by the users, settings locked). The users are getting pretty p.. off by what they perceive as an application problem, but we do not see a problem at the application level (logfiles etc..). When users, after the IE error page, click the reload button, the same request/response usually works fine. The users say that this problem affects only this application and/or server, but we do not know if they actually use any other comparable service. The server is hosted by a service company, in a location physically distant from the users, but supposedly with good connectivity. The server/application can sometimes take a while to respond to a request, but never more than say 10 seconds at most, and users kind of know when they ask a heavy question, so they would not really get so impatient. Users are spread out, so even when monitoring the mod_jk log in real time it is not easy to immediately connect one of these client-side mod_jk error messages with the occurrence of an error at IE level. We just kind of suppose they are linked. The problem is specific to that customer site. We have similar setups at many other places, none of them exhibiting the same issue. Any ideas/suggestions of what we could do to better pin-point the problem ? (or of some setting to overcome it ?) Note that I am not saying that mod_jk has any responsibility in the issue. It is just that the mod_jk log seems to be the only one that actually sems to show where the error happens. Thanks. Rainer Jung wrote: Hi, On 27.01.2009 13:20, Arne Riecken wrote: Hi, please have a look at the mod_jk.log. Can anyone say if these info-entrys are normal or if the system is unhealthy? Or might the network be bad? These entrys come at least two times per hour. 1) All messages are info level, that's good. 2) All messages with the same process id and thread id (the number pair following the timestamp) and close to each other in time belong to the same event. 3) In you log excerpt, there are two types of events: a) client abort ajp_process_callback::jk_ajp_common.c (1448): Writing to client aborted or client network problems ajp_service::jk_ajp_common.c (1857): (worker6) request failed, because of client write error without recovery in send loop attempt=0 service::jk_lb_worker.c (1068): unrecoverable error 200, request failed. Client failed in the middle of request, we can't recover to another instance. jk_handler::mod_jk.c (2158): Aborting connection for worker=routerExt2 Client write error means, that when sending back data to the browser, the web server realized that the browser already closed the connection. Most likely the user decided to click on some link while waiting for a response. If this happens only occasionally, it should be fine. If it happens very often it might be an indication for performance problems, i.e. your users clicking repeatedly on the same links, because they don't get a fast answer. b) idle connection timeouts ajp_send_request::jk_ajp_common.c (1215): (worker1) error sending request. Will try another pooled connection ajp_send_request::jk_ajp_common.c (1241): (worker1) all endpoints are disconnected ajp_send_request::jk_ajp_common.c (1244): (worker1) increase the backend idle connection timeout or the connection_pool_minsize ajp_service::jk_ajp_common.c (1941): (worker1) sending request to tomcat failed, recoverable operation attempt=1 Without additional error level messages that's OK. The web server noticed, that there was no connection to the backend open and will transparently create a new one. This could happen, if your web server is more idle than configured with the JK connection pool timeout or Tomcat's connectionTimeout. 4) Please keep info log level. As long as there are no warn or error messages, everything is fine, but once there are error messages, the aditional info messages are helpful. You should update to 1.2.27, it's better than 1.2.23 :) Regards, Rainer Thanks. mod_jk 1.2.23 Apache 1.3.34 Tomcat 5.5.20 socket_keepalive=False connect_timeout=3 prepost_timeout=3 connection_pool_timeout=600 all
