tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From André Warnier ...@ice-sa.com>
Subject Re: mod_jk restarting during uploads of large files
Date Thu, 07 Jul 2011 14:27:03 GMT
Hi.

Since this concerns large files upload, I wonder if something along these lines is happening
:

A file upload is a POST request, usually with an enctype=multipart/form-data format 
(similar to an email with attachments).
Furthermore, for sending this file, the browser is going to encode the file using Base64 
encoding, which increases the brutto size by at least 1/3.  So your 500 MB file becomes 
something like 700 MB in the POST.

Now let's imagine that by default Tomcat is buffering this in memory until it has read the

whole POST and can start parsing it.  That could easily cause some memory issues.

I seem to remember that there existed a parameter somewhere telling Tomcat how much it 
should buffer in memory before it starts offloading that to disk, but I do not remember 
where.  Maybe it was in the former "FileUpload" project though..



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
> 
> 


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


Mime
View raw message