tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From mar...@alt-v.co.uk
Subject mod_jk restarting during uploads of large files
Date Mon, 04 Jul 2011 16:27:36 GMT
Hi
I have a problem when uploading files to tomcat through mod_jk.  When  
uploading smaller files (<100kb) everything seems to work fine, but  
when uploading files of about 1.5Mb it seems as if the server is  
restarting and causing a 503 error.  I've tried modifying timeouts in  
both apache and tomcat, still i get this output on the catalina.err  
file: (sorry for long log files)


04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:31 7211 jsvc.exec error: Shutdown or reload already scheduled
04/07/2011 15:19:32 7210 jsvc.exec error: Service killed by signal 9
Jul 4, 2011 3:19:35 PM org.apache.catalina.core.AprLifecycleListener init
INFO: The APR based Apache Tomcat Native library which allows optimal  
performance in production environments was not found on the  
java.library.path:  
/usr/local/jdk/jre/lib/i386/client:/usr/local/jdk/jre/lib/i386:/usr/java/packages/lib/i386:/lib:/usr/lib
Jul 4, 2011 3:19:35 PM org.apache.coyote.http11.Http11BaseProtocol init
INFO: Initializing Coyote HTTP/1.1 on http-8080
Jul 4, 2011 3:19:35 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 426 ms
Jul 4, 2011 3:19:35 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
Jul 4, 2011 3:19:35 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/5.5.33
Jul 4, 2011 3:19:35 PM org.apache.catalina.core.StandardHost start
INFO: XML validation disabled
Jul 4, 2011 3:19:35 PM org.apache.catalina.core.StandardHost start
INFO: XML validation disabled
Jul 4, 2011 3:19:36 PM org.apache.catalina.core.StandardHost start
INFO: XML validation disabled
Jul 4, 2011 3:19:36 PM org.apache.catalina.core.StandardHost start
INFO: XML validation disabled
Jul 4, 2011 3:19:36 PM org.apache.catalina.core.StandardHost start
INFO: XML validation disabled
Jul 4, 2011 3:19:37 PM org.apache.coyote.http11.Http11BaseProtocol start
INFO: Starting Coyote HTTP/1.1 on http-8080
Jul 4, 2011 3:19:37 PM org.apache.jk.common.ChannelSocket init
INFO: JK: ajp13 listening on /0.0.0.0:8009
Jul 4, 2011 3:19:37 PM org.apache.jk.server.JkMain start
INFO: Jk running ID=0 time=0/246  config=null
Jul 4, 2011 3:19:37 PM org.apache.catalina.storeconfig.StoreLoader load
INFO: Find registry server-registry.xml at classpath resource
Jul 4, 2011 3:19:37 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 2419 ms
----------

The error from the apache mod_jk.log file is:

[Mon Jul 04 15:18:09 2011] [7413:3080754960] [info] init_jk::mod_jk.c  
(3189): mod_jk/1.2.30 initialized
[Mon Jul 04 15:19:32 2011] [7460:3080754960] [info]  
ajp_connection_tcp_get_message::jk_ajp_common.c (1223): (ajp13) can't  
receive the response header message from tomcat, tomcat  
(127.0.0.1:8009) has forced a connection close for socket 2
7
[Mon Jul 04 15:19:32 2011] [7460:3080754960] [error]  
ajp_get_reply::jk_ajp_common.c (2055): (ajp13) Tomcat is down or  
refused connection. No response has been sent to the client (yet)
[Mon Jul 04 15:19:32 2011] [7460:3080754960] [error]  
ajp_service::jk_ajp_common.c (2533): (ajp13) sending request to tomcat  
failed (unrecoverable),  (attempt=1)
[Mon Jul 04 15:19:32 2011] ajp13 barcodes3.alt-v.co.uk 27.361459
[Mon Jul 04 15:19:32 2011] [7460:3080754960] [info]  
jk_handler::mod_jk.c (2618): Service error=0 for worker=ajp13
[Mon Jul 04 15:19:33 2011] [7464:3080754960] [info]  
jk_open_socket::jk_connect.c (622): connect to 127.0.0.1:8009 failed  
(errno=111)
[Mon Jul 04 15:19:33 2011] [7464:3080754960] [info]  
ajp_connect_to_endpoint::jk_ajp_common.c (959): Failed opening socket  
to (127.0.0.1:8009) (errno=111)
[Mon Jul 04 15:19:33 2011] [7464:3080754960] [error]  
ajp_send_request::jk_ajp_common.c (1585): (ajp13) connecting to  
backend failed. Tomcat is probably not started or is listening on the  
wrong port (errno=111)
[Mon Jul 04 15:19:33 2011] [7464:3080754960] [info]  
ajp_service::jk_ajp_common.c (2540): (ajp13) sending request to tomcat  
failed (recoverable), because of error during request sending  
(attempt=1)
[Mon Jul 04 15:19:33 2011] [7464:3080754960] [info]  
jk_open_socket::jk_connect.c (622): connect to 127.0.0.1:8009 failed  
(errno=111)
[Mon Jul 04 15:19:33 2011] [7464:3080754960] [info]  
ajp_connect_to_endpoint::jk_ajp_common.c (959): Failed opening socket  
to (127.0.0.1:8009) (errno=111)
[Mon Jul 04 15:19:33 2011] [7464:3080754960] [error]  
ajp_send_request::jk_ajp_common.c (1585): (ajp13) connecting to  
backend failed. Tomcat is probably not started or is listening on the  
wrong port (errno=111)
[Mon Jul 04 15:19:33 2011] [7464:3080754960] [info]  
ajp_service::jk_ajp_common.c (2540): (ajp13) sending request to tomcat  
failed (recoverable), because of error during request sending  
(attempt=2)
[Mon Jul 04 15:19:33 2011] [7464:3080754960] [error]  
ajp_service::jk_ajp_common.c (2559): (ajp13) connecting to tomcat  
failed.
[Mon Jul 04 15:19:33 2011] ajp13 barcodes3.alt-v.co.uk 0.116266
[Mon Jul 04 15:19:33 2011] [7464:3080754960] [info]  
jk_handler::mod_jk.c (2618): Service error=-3 for worker=ajp13
[Mon Jul 04 15:19:34 2011] [7467:3080754960] [info]  
jk_open_socket::jk_connect.c (622): connect to 127.0.0.1:8009 failed  
(errno=111)
[Mon Jul 04 15:19:34 2011] [7467:3080754960] [info]  
ajp_connect_to_endpoint::jk_ajp_common.c (959): Failed opening socket  
to (127.0.0.1:8009) (errno=111)
[Mon Jul 04 15:19:34 2011] [7467:3080754960] [error]  
ajp_send_request::jk_ajp_common.c (1585): (ajp13) connecting to  
backend failed. Tomcat is probably not started or is listening on the  
wrong port (errno=111)
[Mon Jul 04 15:19:34 2011] [7467:3080754960] [info]  
ajp_service::jk_ajp_common.c (2540): (ajp13) sending request to tomcat  
failed (recoverable), because of error during request sending  
(attempt=1)
[Mon Jul 04 15:19:34 2011] [7467:3080754960] [info]  
jk_open_socket::jk_connect.c (622): connect to 127.0.0.1:8009 failed  
(errno=111)
[Mon Jul 04 15:19:34 2011] [7467:3080754960] [info]  
ajp_connect_to_endpoint::jk_ajp_common.c (959): Failed opening socket  
to (127.0.0.1:8009) (errno=111)
[Mon Jul 04 15:19:34 2011] [7467:3080754960] [error]  
ajp_send_request::jk_ajp_common.c (1585): (ajp13) connecting to  
backend failed. Tomcat is probably not started or is listening on the  
wrong port (errno=111)
[Mon Jul 04 15:19:34 2011] [7467:3080754960] [info]  
ajp_service::jk_ajp_common.c (2540): (ajp13) sending request to tomcat  
failed (recoverable), because of error during request sending  
(attempt=2)
[Mon Jul 04 15:19:34 2011] [7467:3080754960] [error]  
ajp_service::jk_ajp_common.c (2559): (ajp13) connecting to tomcat  
failed.
[Mon Jul 04 15:19:34 2011] ajp13 barcodes3.alt-v.co.uk 0.100502
[Mon Jul 04 15:19:34 2011] [7467:3080754960] [info]  
jk_handler::mod_jk.c (2618): Service error=-3 for worker=ajp13


------




So I think its restarting the server for some reason.  As far as I can  
tell I'm not getting any errors on the startup of the server.  Is  
there any way to find out more about whats happening and maybe fix  
this problem.  My workers.conf is:

worker.ajp13.port=8009
worker.ajp13.host=localhost
worker.ajp13.type=ajp13
#
# Specifies the load balance factor when used with
# a load balancing worker.
# Note:
#  ----> lbfactor must be > 0
#  ----> Low lbfactor means less work done by the worker.

worker.ajp13.lbfactor=1

#
# Specify the size of the open connection pool.
#worker.ajp13.connection_pool_size
connection_pool_timeout=600
connectionTimeout=600000
#


The connector for the server is:

     <Connector port="8009"
                maxProcessors="50" enableLookups="false"  
disableUploadTimeout="true" protocol="AJP/1.3"  
connectionTimeout="180000" maxSavePostSize="-1" maxPostSize="0" />


I would post the rest of the file if its needed, but i think thats the  
most important part.

The jk.conf from apache is:

JkWorkersFile /usr/local/jakarta/tomcat/conf/workers.properties
JkLogFile /usr/local/apache/logs/mod_jk.log
JkLogLevel info
JkWatchdogInterval 600
JkLogStampFormat "[%a %b %d %H:%M:%S %Y] "
JkOptions +ForwardKeySize +ForwardURICompat -ForwardDirectories
JkRequestLogFormat "%w %V %T"

I'm using tomcat 5.5, it would be difficult for me to upgrade.  Can  
anyone point out anything that I might be doing wrong, or if you need  
any more info let me know

Thanks



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


Mime
View raw message