tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Pid <...@pidster.com>
Subject Re: mod_jk restarting during uploads of large files
Date Thu, 07 Jul 2011 11:01:15 GMT
Linux OOM killer?

 http://lwn.net/Articles/317814/


p


On 07/07/2011 09:35, martin@alt-v.co.uk wrote:
> Yeh, I've worked out what was happening, seems that tomcat was being
> killed by the system running out of memory, which was happening without
> any log messages on the system at all, which was rather unhelpful and
> left me completely stumped for a while.  However adding extra swap space
> and memory seem to fix the problem.
> 
> Thanks anyway for the reply
> 
> Quoting Rainer Jung <rainer.jung@kippdata.de>:
> 
>> It seems it is not a mod_jk problem. mod_jk never shuts down Tomcat, but
>> obviously your Tomcat shuts down during processing the request.
>>
>> I would
>>
>> - update Tomcat *and* the service wrapper (jdvc) to the most recent
>> patch update (e.g. Tomcat 5.5.33).
>>
>> - run Tomcat once without the service wrapper to decide, whether the
>> problem comes from the wrapper or from Tomcat respectively your web
>> application.
>>
>> Regards,
>>
>> Rainer
>>
>> On 04.07.2011 18:27, martin@alt-v.co.uk wrote:
>>> 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
>>
>>
> 
> 
> 
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
> 



Mime
View raw message