Bug 58766 - Embedded Tomcat 8 startup hangs on RedHat when calling addWebapp
Embedded Tomcat 8 startup hangs on RedHat when calling addWebapp
Status: RESOLVED DUPLICATE of bug 57823
Product: Tomcat 8
Classification: Unclassified
Component: Catalina
8.0.29
PC Linux
: P2 blocker (vote)
: ----
Assigned To: Tomcat Developers Mailing List
:
Depends on:
Blocks:
  Show dependency tree
 
Reported: 2015-12-24 09:44 UTC by nitsan_daniel
Modified: 2016-01-18 03:41 UTC (History)
0 users



Attachments
thread dump (9.33 KB, text/plain)
2015-12-24 09:44 UTC, nitsan_daniel
Details
Debug logs (109.24 KB, application/x-rar)
2015-12-27 12:24 UTC, nitsan_daniel
Details

Note You need to log in before you can comment on or make changes to this bug.
Description nitsan_daniel 2015-12-24 09:44:13 UTC
Created attachment 33373 [details]
thread dump

After upgrading to Tomcat 8.0.29 (used Tomcat 7 before), starting from the second startup of the application, tomcat hangs when calling addWebapp.

At the first startup everything works OK. Just after stopping the service of my application and starting it again the problem will occur.
I assume it's related to exploding the war file.

This happens on RedHat only (Suse works just fine).

Moreover, when I start my application from script, rather than as a service, everything works well. 

Any idea what can I do to solve this?

Thanks.
Comment 1 Mark Thomas 2015-12-26 08:49:17 UTC
There is no evidence of a Tomcat bug in this report.

Please use the users mailing list to debug the problem you are seeing. If the conclusion from that is that there is a bug here then this issue can be re-opened and the necessary detail added.
Comment 2 Konstantin Kolinko 2015-12-26 23:49:13 UTC
Read about annotation scanning in this FAQ article:
https://wiki.apache.org/tomcat/HowTo/FasterStartUp

I agree with Mark that there is not enough evidence here.

Annotation scanning is expected to take notable time, -- as explained in the above FAQ entry.

Comments:

1) If you can turn on debug logging and are able to provide an evidence that Tomcat performs the same work over and over, e.g. scans the same set of classes, this would be a valid issue.

Tomcat uses standard java.util.logging API as provided by Java Runtime. The Oracle JDK documentation describes how configure it. This configuration is available for standalone applications as well.

2) A single thread dump does not say whether things change over time. The usual advice is to take several (3) dumps over time.

https://wiki.apache.org/tomcat/FAQ/Troubleshooting_and_Diagnostics#Common_Troubleshooting_Scenario

3) Current version of Tomcat 8 is 8.0.30.

4) If you need help, ask on the Tomcat users' mailing list,
https://wiki.apache.org/tomcat/FAQ/Tomcat_User
Comment 3 nitsan_daniel 2015-12-27 07:27:34 UTC
The problem is not about Tomcat loading slowly.
It is just stuck.

We've committed several thread dumps, all show the same problem.
Moreover, we've waiting for hours - tomcat won't return from this same method.
Comment 4 Konstantin Kolinko 2015-12-27 11:49:13 UTC
It sounds like a duplicate of bug 57823.


By the way, regarding
org.apache.catalina.startup.ContextConfig.processAnnotationsFile()
method:

1. This method needs debug logging. (There is none at the moment).
2. The following condition needs first && second swapped:

>> } else if (file.canRead() && file.getName().endsWith(".class")) {

As can be seen from stacktrace in Comment 0, the "canRead()" call is an I/O operation. This is more expensive than a filename check.


> java.lang.Thread.State: RUNNABLE
>   at java.io.UnixFileSystem.checkAccess(UnixFileSystem.java:-1)
>   at java.io.File.canRead(File.java:768)
>   at org.apache.catalina.startup.ContextConfig.processAnnotationsFile(ContextConfig.java:1992)
>   at org.apache.catalina.startup.ContextConfig.processAnnotationsFile(ContextConfig.java:1988)
>   at org.apache.catalina.startup.ContextConfig.processAnnotationsFile(ContextConfig.java:1988)
>   <the same line (ContextConfig.java:1988) repeated a dozen of times...>
Comment 5 nitsan_daniel 2015-12-27 12:24:50 UTC
Created attachment 33377 [details]
Debug logs
Comment 6 Konstantin Kolinko 2015-12-27 14:20:15 UTC
(In reply to nitsan_daniel from comment #5)
> Created attachment 33377 [details]
> Debug logs

In tomcat.log.2:

Dec-27-2015 12:18:24 GMT DEBUG [org.apache.tomcat.util.scan.StandardJarScanner] [localhost-startStop-1] [DEBUG] - Scanning JAR [/WEB-INF/lib/perf4j-0.9.16.jar] from /WEB-INF/lib

Dec-27-2015 12:18:24 GMT DEBUG [org.apache.tomcat.util.scan.StandardJarScanner] [localhost-startStop-1] [DEBUG] - Scanning JAR [file:/opt/bmc/App_Visibility/portal/webapps/portal-console/WEB-INF/classes/] from classpath

Dec-27-2015 12:18:24 GMT DEBUG [org.apache.tomcat.util.scan.StandardJarScanner] [localhost-startStop-1] [DEBUG] - Scanning JAR [file:/] from classpath

Dec-27-2015 12:18:24 GMT DEBUG [org.apache.tomcat.util.scan.StandardJarScanner] [localhost-startStop-1] [DEBUG] - Scanning JAR [file:/opt/bmc/App_Visibility/common/lib/quartz-all-2.1.1.jar] from classpath

There is no hanging here (and I see no hanging in these debug logs), but "file:/" is certainly in class path.

Thus it is a duplicate of bug 57823

*** This bug has been marked as a duplicate of bug 57823 ***
Comment 7 nitsan_daniel 2015-12-28 08:46:24 UTC
How can this be the problem if it's working on the first start but fails starting from the second start and beyond.
The classpath is the same all the time.
If this was indeed the problem I would expect it to hang during the first start as well.
Comment 8 Konstantin Kolinko 2015-12-28 11:47:58 UTC
(In reply to nitsan_daniel from comment #7)
My guess:

Either classpath is different between starts,

or the current working directory is different between starts (as misconfigured classpath includes the current working directory),

or some other reason (different file tree, e.g. some remote drives not mounted at boot time).
Comment 9 nitsan_daniel 2015-12-29 10:48:57 UTC
We've found the our classpath starts with a colon (for instance, :/a.jar:/b.jar), after removing the leading colon Tomcat didn't scan [file:/] and the problem was resolved.
Comment 10 nitsan_daniel 2015-12-29 10:53:24 UTC
Thank you guys for your help!
Comment 11 Konstantin Kolinko 2016-01-18 03:41:34 UTC
(In reply to Konstantin Kolinko from comment #4)
> It sounds like a duplicate of bug 57823.
> 
> 
> By the way, regarding
> org.apache.catalina.startup.ContextConfig.processAnnotationsFile()
> method:
> 
> 1. This method needs debug logging. (There is none at the moment).
> 2. The following condition needs first && second swapped:
> 
> >> } else if (file.canRead() && file.getName().endsWith(".class")) {
> 
> As can be seen from stacktrace in Comment 0, the "canRead()" call is an I/O
> operation. This is more expensive than a filename check.
> 

The above improvements were implemented and will be in 7.0.68, 8.0.31, 9.0.0.M2 onwards.
(r1725165/r1725167/r1725170)