You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Shanti Suresh <sh...@umich.edu> on 2014/04/03 18:19:01 UTC
catalina.out anomaly?
Greetings,
I am unable to understand how Tomcat v7.0.23 suppresses startup messages in
catalina.out and Tomcat v7.0.52 displays them all in catalina.out. Also
Tomcat 7.0.23 starts up much faster than Tomcat v7.0.52. Contexts are
served immediately upon a v7.0.23 restart. I used the same
logging.properties file from 7.0.23 into 7.0.52. I would like to avoid the
context being redeployed every time v7.0.52 starts up. Here are some
details:
(1) Startup Times:
------------------------
v7.0.23 starts up in a couple of minutes at most (can't see exact times as
they are not captured in catalina.out)
v7.0.52 starts up in 479924 ms <-- so so long!
(2) Catalina.out messages:
v7.0.23 catalina.out is empty.
------------------------------------
----------v7.0.52 catalina.out snippet:-----------
Apr 3, 2014 9:07:24 AM org.apache.catalina.startup.HostConfig
deployDescriptor
INFO: Deploying configuration descriptor
/opt/tomcat/delivery/apache-tomcat-7.0.52/conf/Catalina/localhost/context_1.xml
Apr 3, 2014 9:07:28 AM org.apache.catalina.startup.HostConfig
deployDescriptor
INFO: Deploying configuration descriptor
/opt/tomcat/delivery/apache-tomcat-7.0.52/conf/Catalina/localhost/context_2.xml
...
Apr 3, 2014 9:07:31 AM org.apache.catalina.startup.HostConfig
deployDescriptor
INFO: Deploying configuration descriptor
/opt/tomcat/delivery/apache-tomcat-7.0.52/conf/Catalina/localhost/context_136.xml
...
Apr 3, 2014 9:15:04 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 479924 ms
----------end of v7.0.52 catalina.out snippet:-----------
(3) Contexts after a restart:
------------------------------------
After a restart, the contexts load up right away with v7.0.23 rather
than a "Service
Temporarily Unavailable" as in 7.0.52.
(4) My Questions are:
------------------------------
a.) How can I prevent contexts from being redeployed? I have 136 contexts
under /opt/tomcat/apache/conf/Catalina/localhost/ and these are deployed
everytime I restart v7.0.52
I don't think JARs are scanned in 7.0.52 for things to slow down so much.
Not sure if "metadata-complete=true" will help here. Running all the
FIleHandlers in FINEST mode shows nothing while contexts are being
deployed. But I can see time being spent as each context is deployed.
b) I want to speed up the startup times in v7.0.52 drastically.
Thanks for all help!
-Shanti
Re: catalina.out anomaly?
Posted by Shanti Suresh <sh...@umich.edu>.
All,
First of all, I apologize for the question on "catalina.out" being empty in
v7.0.23. That's because I am using log4j for Tomcat logging, and the level
was set to "ERROR".
Here is an interesting finding between v7.0.23 and v7.0.52. It appears
that a 3 second delay occurs in v7.0.52 as the debug logs show below for
context, "lsa":
-------------start of v7.0.23 debug log snippet:-------
[2014-04-04 14:55:37,661][DEBUG] org.apache.catalina.util.LifecycleBase -
Setting state for [WebappLoader[/lsa]] to [STARTED]
[2014-04-04 14:55:37,662][DEBUG] org.apache.catalina.startup.ContextConfig
- Context [/lsa] will parse web.xml and web-fragment.xml files with
validation:false and namespaceAware:false
[2014-04-04 14:55:37,682][DEBUG] org.apache.catalina.util.LifecycleBase -
Setting state for
[StandardEngine[Catalina].StandardHost[localhost].StandardContext[/lsa].StandardWrapper[jsp]]
to [INITIALIZING]
-------------end of v7.0.23 debug log snippet---------
------------start of v7.0.52 debug log snippet:-------
[2014-04-04 16:37:09,525][DEBUG] org.apache.catalina.util.LifecycleBase -
Setting state for [WebappLoader[/lsa]] to [STARTED]
[2014-04-04 16:37:09,526][DEBUG] org.apache.catalina.startup.ContextConfig
- Context [/lsa] will parse web.xml and web-fragment.xml files with
validation:false and namespaceAware:false
[2014-04-04 16:37:12,043][DEBUG] org.apache.catalina.util.LifecycleBase -
Setting state for
[StandardEngine[Catalina].StandardHost[localhost].StandardContext[/lsa].StandardWrapper[jsp]]
to [INITIALIZING]
--------------end of v7.0.52 debug log snippet------
So why is there such a delay in initializing a context between the two
versions? I have noticed delays of up to 6 or 7 seconds in configuring a
context in v7.0.52.
Thanks,
-Shanti
Re: catalina.out anomaly?
Posted by Shanti Suresh <sh...@umich.edu>.
Hi Chris,
Thanks you for the note!
On Thu, Apr 3, 2014 at 12:40 PM, Christopher Schultz <
chris@christopherschultz.net> wrote:
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
>
> Shanti,
>
>
> They work the same way. Are you launching them differently for
> different versions?
>
Yes, actually. The logging.properties file and the catalina.properties
file are the same.
The JVM arguments are the same as well between the two versions. But I am
using Executor ThreadPool in 7.0.52. Let me revert to not using an
Executor ThreadPool and see what goes on.
>
>
>
> At some point, Tomcat was modified to adhere to some rulings made by
> the Servlet EG about JAR-scanning and other (unfortunately)
> time-consuming operations. You can speed-up Tomcat startup by using
> metadata-complete="true" in your web.xml, and configuring the various
> JAR-scanning options.
>
>
> https://tomcat.apache.org/tomcat-7.0-doc/config/systemprops.html#JAR_Scanning
>
Please see your comment below.
If your context is not deployed, then your web application will not
> respond to requests. Are you sure you don't want it deployed?
>
> I mean, why does 7.0.23 not take forever to deploy these same 136 contexts
while 7.0.52 does? If I could only see where the output of 7.0.23 goes,
I'll know better. I don't see any swallowOutput on the Default context.
So I am unsure what's going on with 7.0.23. I only see "[Unloading
class.." messages because of the " -XX:+ClassUnloading" JVM argument.
That is a very long time. Can you take some thread dumps during the
> process. You certainly have a long time for that opportunity.
>
> Yes! Good point! Should have thought of that.
> > (2) Catalina.out messages:
> >
> > v7.0.23 catalina.out is empty.
>
> How do you launch Tomcat 7.0.23?
>
> Through /bin/service which invokes a start_tomcat script which invokes the
startup.sh Tomcat script.
> So Tomcat is deploying context_136 which is presumably your web
> application. Why does your web application take so long to launch?
>
Tomcat deploys 136 contexts. Each context is a website. Takes about 5-6
seconds to deploy each context. Now 7.023 is pretty quick. I'll compare
thread dumps between the two startups. Unless you can think of something
else that could prevent startup messages not showing up in 7.0.23's
catalina.out. BTW, the startup messages go nowhere in 7.0.23.
>
> So you want Tomcat to come up immediately without any applications
> available? That's no fun.
>
> I agree :-) But that's not what I meant. I didn't want context to be
deployed if I can save their meta-data somehow from the previous run of
Tomcat which the server can reuse.
> > I don't think JARs are scanned in 7.0.52 for things to slow down so
> > much.
>
> Are you sure? Take thread dumps.
>
Yes, I will do so.
>
> > Not sure if "metadata-complete=true" will help here. Running all
> > the FIleHandlers in FINEST mode shows nothing while contexts are
> > being deployed.
>
> Then you have done something wrong. When I set level=FINEST, I get so
> much logging it noticeably slows down the startup of my Tomcat instance.
>
>
> Hmm..
>
> How long does Tomcat take to launch if you have no web applications?
>
INFO: Server startup in 1454 ms
Well, the executor threadpool is a suspect. Let me work in making 7.0.52
like 7.0.23 in all respects, take thread dumps and then check things out.
Please let me know if the Executor threadpool can be slow. And, in the
meantime, also how I might make catalina.out talk in 7.0.23. I know I am
doing something silly but I can't seem to figure this one out.
Thanks!
-Shanti
Re: catalina.out anomaly?
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
Shanti,
On 4/3/14, 12:19 PM, Shanti Suresh wrote:
> I am unable to understand how Tomcat v7.0.23 suppresses startup
> messages in catalina.out and Tomcat v7.0.52 displays them all in
> catalina.out.
They work the same way. Are you launching them differently for
different versions?
> Also Tomcat 7.0.23 starts up much faster than Tomcat v7.0.52.
> Contexts are served immediately upon a v7.0.23 restart.
At some point, Tomcat was modified to adhere to some rulings made by
the Servlet EG about JAR-scanning and other (unfortunately)
time-consuming operations. You can speed-up Tomcat startup by using
metadata-complete="true" in your web.xml, and configuring the various
JAR-scanning options.
https://tomcat.apache.org/tomcat-7.0-doc/config/systemprops.html#JAR_Scanning
> I used the same logging.properties file from 7.0.23 into 7.0.52. I
> would like to avoid the context being redeployed every time v7.0.52
> starts up.
If your context is not deployed, then your web application will not
respond to requests. Are you sure you don't want it deployed?
> Here are some details:
>
> (1) Startup Times: ------------------------
>
> v7.0.23 starts up in a couple of minutes at most (can't see exact
> times as they are not captured in catalina.out)
They should be.
> v7.0.52 starts up in 479924 ms <-- so so long!
That is a very long time. Can you take some thread dumps during the
process. You certainly have a long time for that opportunity.
> (2) Catalina.out messages:
>
> v7.0.23 catalina.out is empty.
How do you launch Tomcat 7.0.23?
> ------------------------------------ ----------v7.0.52 catalina.out
> snippet:----------- Apr 3, 2014 9:07:24 AM
> org.apache.catalina.startup.HostConfig deployDescriptor INFO:
> Deploying configuration descriptor
> /opt/tomcat/delivery/apache-tomcat-7.0.52/conf/Catalina/localhost/context_1.xml
>
>
Apr 3, 2014 9:07:28 AM org.apache.catalina.startup.HostConfig
> deployDescriptor INFO: Deploying configuration descriptor
> /opt/tomcat/delivery/apache-tomcat-7.0.52/conf/Catalina/localhost/context_2.xml
>
>
...
> Apr 3, 2014 9:07:31 AM org.apache.catalina.startup.HostConfig
> deployDescriptor INFO: Deploying configuration descriptor
> /opt/tomcat/delivery/apache-tomcat-7.0.52/conf/Catalina/localhost/context_136.xml
>
>
...
So Tomcat is deploying context_136 which is presumably your web
application. Why does your web application take so long to launch?
> Apr 3, 2014 9:15:04 AM org.apache.catalina.startup.Catalina start
> INFO: Server startup in 479924 ms ----------end of v7.0.52
> catalina.out snippet:-----------
>
>
> (3) Contexts after a restart: ------------------------------------
> After a restart, the contexts load up right away with v7.0.23
> rather than a "Service Temporarily Unavailable" as in 7.0.52.
>
> (4) My Questions are: ------------------------------ a.) How can I
> prevent contexts from being redeployed? I have 136 contexts under
> /opt/tomcat/apache/conf/Catalina/localhost/ and these are deployed
> every time I restart v7.0.52
So you want Tomcat to come up immediately without any applications
available? That's no fun.
> I don't think JARs are scanned in 7.0.52 for things to slow down so
> much.
Are you sure? Take thread dumps.
> Not sure if "metadata-complete=true" will help here. Running all
> the FIleHandlers in FINEST mode shows nothing while contexts are
> being deployed.
Then you have done something wrong. When I set level=FINEST, I get so
much logging it noticeably slows down the startup of my Tomcat instance.
> But I can see time being spent as each context is deployed.
>
> b) I want to speed up the startup times in v7.0.52 drastically.
How long does Tomcat take to launch if you have no web applications?
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iQIcBAEBCAAGBQJTPY7tAAoJEBzwKT+lPKRY/X4P/09VdkSTyuyQuKB5fDky+eFq
DzpTGRWcLWhFb+nUbIhq6k7VCxXn7UhmtLE7Gsg0XiJf6xguouaxVtuJuD/8XzXm
VFplalAWa0IH0FfhXDqPOtN08sGIY7KxsjHemt+Kfa6ApCrtDbcnK8okp9J2BJln
hXlCUwuQ+shfv4bngkdT1c7woBP/cWJsy9Y56nb2VL3mNZpDqsKg6ec2YeXOxGGT
iJiuqJiqJk6C2cA/k1qpIa56uq1xH3vzK943My9gilSVwJ9CfAqo9GRdt6uCWT9P
ryiTRh0Oss3IgnwPA3S5ysVRtEVG+g4lFT3SlCgn3O/MTI8V+mMLgJpU09qqWG2F
Efbe1VDDVaa8uJa5GoqfTGvlyJPa39t6xnJnQaSL2fOQ8qHj9BqTEzZY/BbEpgO8
gKdGn4SgVNmIf1nKAEiDx1dnpyoLZSWrT3Xy56iPMVrDQ522tsOY79xs9tjIPOjv
gaMN9yCbY8mn6kv0bAzYgHTGOrLlkcNks+4VTbRiw6I/L2TxhvXs2YkMnt8KZfFt
0b2emzcXPXwRV5wXsy+5dpHi1qYuylaWrZv2skkQQqpXUEebQVMx2yznAQiJEB3a
W9GyEyScrdzHBZQuR1uUlV7DCXq3VKDmxtBA1Ti/bwfns1l5oSa3E2nnnF7RVW47
IXOtJRE9sz2iegTy3ld/
=5gve
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org