tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From babu <babulalsatas...@gmail.com>
Subject Re: [OT] mod_jk -> tomcat sending delay
Date Sat, 10 Feb 2007 00:56:56 GMT

Hi,

We tried updating it once but we have problem in load balancing and we went
back to original mod_jk which we working fine. We upgraded to 1.2.15, but we
are planing to try out new one 1.2.20, but I am watching this discussion
board and there issues even in 1.2.20 and I have posted because of thius.

With regards,

Babulal Satasiya


Rainer Jung-3 wrote:
> 
> Version 1.2.6 of mod_jk is an antiquity. First update before 
> investigating the problem.
> 
> babu wrote:
>> Hi,
>> 
>> We are also facing same problem and we are using mod_jk 1.2.6 with apache
>> 2.0.53 and tomcat 5.0.27. Mod_jk is configured with loadbalancer. We have
>> Apache+mod_jk with LB +  9 tomcats in backend. Mod_jk is set with sticky
>> bit
>> set.
>> 
>> Partial workers.properites
>> 
>> worker.list=loadbalancer
>> worker.loadbalancer.type=lb
>> worker.loadbalancer.balanced_workers=tc_1_1,tc_1_2,tc_1_3,tc_2_1,tc_2_2,tc_2_3,tc_3_1,tc_3_2,tc_3_3
>> 
>> 
>> 
>> worker.tc_1_1.host=cna-prod-app-25
>> worker.tc_1_1.port=8000
>> worker.tc_1_1.type=ajp13
>> worker.tc_1_1.lbfactor=1
>> worker.tc_1_1.cachesize=50
>> worker.tc_1_1.cache_timeout=180
>> worker.tc_1_1.socket_timeout=300
>> worker.tc_1_1.socket_keepalive=1
>> worker.tc_1_1.recovery_options=0
>> worker.tc_1_1.sticky_session=1
>> 
>> server.xml
>> 
>> <Connector port="8000"
>>               protocol="AJP/1.3"
>>               address="cna-prod-app-25"
>>               minProcessors="50"
>>               maxProcessors="100"
>>               enableLookups="false"
>>               debug="0"
>>               URIEncoding="UTF-8"
>>                           connectionTimeout="180000"
>>               />
>> 
>> I found in one of discussion board, that connection timeout in sever.xml
>> and
>> timeout parameters in workers.properties should be matched properly and
>> also
>> found that in server.xml its in miliseconds and in workers.properites it
>> is
>> seconds.
>> 
>> 
>> We do not find any issue at client side but erorr keeps going in mod_jk
>> log.
>> ( I am not sure of client side issues are there or not)
>> 
>> 
>> mod_jk log
>> 
>> [Fri Feb 09 22:00:55 2007]  [jk_ajp_common.c (1250)]: Tomcat is down or
>> network problems. No response has been sent to the client (yet)
>> [Fri Feb 09 22:00:55 2007]  [jk_ajp_common.c (1449)]: ERROR: Receiving
>> from
>> tomcat failed, recoverable operation. err=2
>> [Fri Feb 09 22:00:55 2007]  [jk_ajp_common.c (1477)]: Error connecting to
>> tomcat. Tomcat is probably not started or is listening on the wrong port.
>> worker=tc_3_3 failed errno = 0
>> [Fri Feb 09 22:01:21 2007]  [jk_ajp_common.c (783)]: ERROR: can't receive
>> the response message from tomcat, network problems or tomcat is down
>> (128.107.229.109:8002), err=-1
>> [Fri Feb 09 22:01:21 2007]  [jk_ajp_common.c (1250)]: Tomcat is down or
>> network problems. No response has been sent to the client (yet)
>> [Fri Feb 09 22:01:21 2007]  [jk_ajp_common.c (1449)]: ERROR: Receiving
>> from
>> tomcat failed, recoverable operation. err=2
>> [Fri Feb 09 22:01:21 2007]  [jk_ajp_common.c (1477)]: Error connecting to
>> tomcat. Tomcat is probably not started or is listening on the wrong port.
>> worker=tc_1_3 failed errno = 0
>> [Fri Feb 09 22:01:41 2007]  [jk_ajp_common.c (783)]: ERROR: can't receive
>> the response message from tomcat, network problems or tomcat is down
>> (128.107.229.110:8001), err=-1
>> [Fri Feb 09 22:01:41 2007]  [jk_ajp_common.c (1250)]: Tomcat is down or
>> network problems. No response has been sent to the client (yet)
>> [Fri Feb 09 22:01:41 2007]  [jk_ajp_common.c (1449)]: ERROR: Receiving
>> from
>> tomcat failed, recoverable operation. err=2
>> [Fri Feb 09 22:01:41 2007]  [jk_ajp_common.c (1477)]: Error connecting to
>> tomcat. Tomcat is probably not started or is listening on the wrong port.
>> worker=tc_2_2 failed errno = 0
>> [Fri Feb 09 22:01:44 2007]  [jk_ajp_common.c (783)]: ERROR: can't receive
>> the response message from tomcat, network problems or tomcat is down
>> (128.107.229.109:8000), err=-1
>> [Fri Feb 09 22:01:44 2007]  [jk_ajp_common.c (1250)]: Tomcat is down or
>> network problems. No response has been sent to the client (yet)
>> [Fri Feb 09 22:01:44 2007]  [jk_ajp_common.c (1449)]: ERROR: Receiving
>> from
>> tomcat failed, recoverable operation. err=0
>> [Fri Feb 09 22:02:03 2007]  [jk_ajp_common.c (783)]: ERROR: can't receive
>> the response message from tomcat, network problems or tomcat is down
>> (128.107.229.110:8002), err=-1
>> [Fri Feb 09 22:02:03 2007]  [jk_ajp_common.c (1250)]: Tomcat is down or
>> network problems. No response has been sent to the client (yet)
>> [Fri Feb 09 22:02:03 2007]  [jk_ajp_common.c (1449)]: ERROR: Receiving
>> from
>> tomcat failed, recoverable operation. err=1
>> [Fri Feb 09 22:02:49 2007]  [jk_ajp_common.c (783)]: ERROR: can't receive
>> the response message from tomcat, network problems or tomcat is down
>> (128.107.229.110:8002), err=-1
>> [Fri Feb 09 22:02:49 2007]  [jk_ajp_common.c (1250)]: Tomcat is down or
>> network problems. No response has been sent to the client (yet)
>> [Fri Feb 09 22:02:49 2007]  [jk_ajp_common.c (1449)]: ERROR: Receiving
>> from
>> tomcat failed, recoverable operation. err=0
>> [Fri Feb 09 22:02:59 2007]  [jk_ajp_common.c (783)]: ERROR: can't receive
>> the response message from tomcat, network problems or tomcat is down
>> (128.107.229.110:8001), err=-1
>> [Fri Feb 09 22:02:59 2007]  [jk_ajp_common.c (1250)]: Tomcat is down or
>> network problems. No response has been sent to the client (yet)
>> [Fri Feb 09 22:02:59 2007]  [jk_ajp_common.c (1449)]: ERROR: Receiving
>> from
>> tomcat failed, recoverable operation. err=2
>> [Fri Feb 09 22:02:59 2007]  [jk_ajp_common.c (1477)]: Error connecting to
>> tomcat. Tomcat is probably not started or is listening on the wrong port.
>> worker=tc_2_2 failed errno = 0
>> 
>> If you find any soluttion to this then please update me with your
>> solution.
>> 
>> with regards,
>> 
>> Babulal Satasiya
>> 
>> Cisco System Inc.
>> Sanjose, CA.
>> 
>> 
>> Marcin ZajÄ…czkowski wrote:
>>> Hi,
>>>
>>>
>>> I observe in mod_jk's log errors:
>>> [error] ajp_get_reply::jk_ajp_common.c (1566): (ajp13w) Tomcat is down 
>>> or refused connection. No response has been sent to the client (yet)
>>>
>>> In the rush hours (20-30 requests/second) up to several entries per
>>> hour.
>>> Sometimes it's followed by:
>>> [error] ajp_service::jk_ajp_common.c (1928): (ajp13w) Connecting to 
>>> tomcat failed. Tomcat is probably not started or is listening on the 
>>> wrong port
>>> or
>>> [error] ajp_connection_tcp_get_message::jk_ajp_common.c (948): (ajp13w) 
>>> can't receive the response message from tomcat, network problems or 
>>> tomcat is down (127.0.0.1:8009), err=-104
>>>
>>> but usually it is covered by another retries. It's corresponding to 
>>> exception in tomcat:
>>> ERROR [org.apache.jk.common.HandlerRequest] Error decoding request
>>> java.net.SocketTimeoutException: Read timed out
>>>
>>> *Note* Post is quite long because of info from logs. To get know what it 
>>> is about it is enough to read descriptions next to numbers.
>>>
>>>
>>> I increased logs granularity (mod_jk and tomcat + tcpdump) and in a few 
>>> checked issues it looks like:
>>>
>>> *1*. mod_jk talks with tomcat and some request is serviced.
>>>
>>> (...)
>>> [11:10:30] [debug] ajp_process_callback::jk_ajp_common.c (1491): AJP13 
>>> protocol: Reuse is OK
>>> [debug] ajp_done::jk_ajp_common.c (2258): recycling connection pool 
>>> slot=0 for worker ajp13w
>>> [debug] jk_handler::mod_jk.c (2126): Service finished with status=200 
>>> for worker=wlb
>>>
>>> *2*. A few seconds later thread is used again by an another request.
>>>
>>> [11:10:32] [debug] wc_get_worker_for_name::jk_worker.c (114): found a 
>>> worker wlb
>>> [debug] wc_get_name_for_type::jk_worker.c (290): Found worker type 'lb'
>>> [debug] init_ws_service::mod_jk.c (584): Service protocol=HTTP/1.1 
>>> method=POST (...)
>>> [debug] service::jk_lb_worker.c (840): service sticky_session=1 
>>> id='8A49C0D934C8A115342BA5CBFC79C434'
>>> [debug] service::jk_lb_worker.c (860): service worker=ajp13w
>>> route=ajp13w
>>> [debug] ajp_get_endpoint::jk_ajp_common.c (2315): acquired connection 
>>> pool slot=0
>>> [debug] ajp_marshal_into_msgb::jk_ajp_common.c (548): ajp marshaling
>>> done
>>> [debug] ajp_service::jk_ajp_common.c (1771): processing ajp13w with 2 
>>> retries
>>> [debug] ajp_connection_tcp_send_message::jk_ajp_common.c (893): sending 
>>> to ajp13 pos=4 len=307 max=8192
>>> (...) [header is sent and it is received by tomcat]
>>>
>>> *3*.
>>> a) mod_jk tries to send body:
>>>
>>> [11:10:32] [debug] ajp_send_request::jk_ajp_common.c (1273): request 
>>> body to send 646 - request body to resend 0
>>>
>>> b) tomcat is waiting for it:
>>> DEBUG [org.apache.jk.common.ChannelSocket] Call next 0 
>>> org.apache.jk.common.HandlerRequest@1ca8b3d
>>> DEBUG [org.apache.jk.common.HandlerRequest] Handling 2
>>> DEBUG [org.apache.jk.common.ChannelSocket] receive()
>>>
>>> *4*. 5 seconds later (connector timeout is 5000ms) tomcat throws
>>> exception:
>>> [11:10:37] ERROR [org.apache.jk.common.HandlerRequest] Error decoding 
>>> request
>>> java.net.SocketTimeoutException: Read timed out
>>> and resets connection (regarding to tcpdump log)
>>>
>>> *5*. A few more seconds later (e.g. 8 from point 3) mod_jk starts 
>>> sending a body:
>>> [11:10:40] [debug] ajp_connection_tcp_send_message::jk_ajp_common.c 
>>> (893): sending to ajp13 pos=4 len=652 max=8192
>>> [debug] ajp_connection_tcp_send_message::jk_ajp_common.c (893): 0000 
>>> 12 34 02 88 02 86 3C 3F (...) [body's dump]
>>>
>>> *6*. Unfortunately connection was already reseted by tomcat and mod_jk 
>>> got info about that:
>>> [11:10:40] [info]  ajp_connection_tcp_get_message::jk_ajp_common.c 
>>> (942): (ajp13w) Tomcat has forced a connection close for socket 28
>>> [error] ajp_get_reply::jk_ajp_common.c (1566): (ajp13w) Tomcat is down 
>>> or refused connection. No response has been sent to the client (yet)
>>> [info]  ajp_service::jk_ajp_common.c (1877): (ajp13w) receiving from 
>>> tomcat failed, recoverable operation attempt=0
>>>
>>> *7*. mod_jk tries to do send request again to tomcat:
>>> [11:10:40] [info]  ajp_service::jk_ajp_common.c (1916): (ajp13w) sending 
>>> request to tomcat failed,  recoverable operation attempt=1
>>> [debug] jk_open_socket::jk_connect.c (335): socket TCP_NODELAY set to On
>>> [debug] jk_open_socket::jk_connect.c (433): trying to connect socket 28 
>>> to 127.0.0.1:8009
>>> [debug] jk_open_socket::jk_connect.c (459): socket 28 connected to 
>>> 127.0.0.1:8009
>>> [debug] ajp_connect_to_endpoint::jk_ajp_common.c (847): Connected socket 
>>> 28 to (127.0.0.1:8009)
>>> [debug] ajp_connection_tcp_send_message::jk_ajp_common.c (893): sending 
>>> to ajp13 pos=4 len=307 max=8192
>>>
>>> Usually (but not always) it is able to do that without errors.
>>>
>>> I sniffed into mod_jk source code, but I haven't found a place where it 
>>> can stuck.
>>>
>>>
>>> *Question*
>>> What can be delay (about 8 seconds) in mod_jk between sending HTTP 
>>> header and HTTP content caused by?
>>>
>>>
>>> I use Apache 2.0.52 (with MPM prefork), mod_jk 1.2.20, JBoss 3.2.5 with 
>>> Tomcat 5.0 (probably 5.0.27) and Red Hat Enterprise Linux ES 4.
>>>
>>> mod_jk configuration is quite simple, without load balancing (and wasn't 
>>> changed for years).
>>>
>>> <workers.properties>
>>> workers.tomcat_home=/jboss/deploy/jbossweb-tomcat50.sar
>>> workers.java_home=/jboss/java
>>> ps=/
>>>
>>> worker.list=wlb,jkstatus
>>>
>>> worker.ajp13w.type=ajp13
>>> worker.ajp13w.host=localhost
>>> worker.ajp13w.port=8009
>>>
>>> worker.wlb.type=lb
>>> worker.wlb.balance_workers=ajp13w
>>> </workers.properties>
>>>
>>> The only change in mod_jk config was:
>>> JkShmSize 1024k
>>>
>>> <servel.xml>
>>>        <Connector port="8009" address="127.0.0.1"
>>>         minProcessors="5" maxProcessors="100"
>>>         enableLookups="false" acceptCount="100" debug="0"
>>>         connectionTimeout="5000" useURIValidationHack="false"
>>>         protocol="AJP/1.3"/>
>>> </servel.xml>
>>>
>>>
>>> Thanks for your advice
>>> Marcin
>>>
>>>
>>> ---------------------------------------------------------------------
>>> To start a new topic, e-mail: users@tomcat.apache.org
>>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>>
>>>
>>>
>> 
> 
> -- 
> kippdata informationstechnologie GmbH
> Bornheimer Str. 33a
> 53111 Bonn
> 
> Tel.: 0228/98549-0
> Fax:  0228/98549-50
> www.kippdata.de
> =======================
> kippdata informationstechnologie GmbH
> Bornheimer Str. 33a
> D-53111 Bonn
> 
> Tel.: +49/0228/98549-0
> Fax:  +49/0228/98549-50
> www.kippdata.de
> 
> ---------------------------------------------------------------------
> To start a new topic, e-mail: users@tomcat.apache.org
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
> 
> 
> 

-- 
View this message in context: http://www.nabble.com/mod_jk--%3E-tomcat-sending-delay-tf3121799.html#a8896404
Sent from the Tomcat - User mailing list archive at Nabble.com.


---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Mime
View raw message