You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by "Huy Vo (hvo)" <hv...@cisco.com> on 2007/10/15 22:09:44 UTC

Classloader deadlock during Tomcat startup

Hi all,
 
I can re-create the following deadlock situation fairly consistently.  I
am using Tomcat 5.0.28 on Linux using JDK 1.4.2_11.  This Tomcat
instance is serving a webapp using Struts (1.2.9)/JSP.
 
Setup:
    - a few browsers connecting to the Tomcat server.  In each browser,
there are two Javascript pollers using XmlHttpRequest object.  One
poller would send HTTP request for a Struts action, while the other for
a simple resource (like an image file).  The frequency of the pollers is
set to 7 seconds.  The pollers are started up at different times though.
    - restart Tomcat process while these browsers are connecting to it,
and Tomcat will run into a deadlock (about 80% of the time).
 
The thread dump is at the bottom of this message.  Thread processor19
seems serving a Struts action request, while processor23 is serving a
resource.  In this dump, processor19 is loading the class ModuleUtils
(ActionServlet line 1189), hence it locked the webappclassloader, and
then called the method checkPackageAccess() on SecurityManager.  This
method is synchronized on a String array (object ID 0x914a4150).  In the
meanwhile, processor23 thread is loading the class
DefaultServlet$ResourceInfo, so it called checkPackageAccess() which
locked the String array, and then this thread tried to load another
class which requires locking the webappclassloader.  A deadlock is hence
seen.  I got these class names here after turning on debug for the
webappclassloader and standardclassloader classes.
 
My questions is:
 
- the setup above is quite typical; hence I wonder if anyone has ran
into this problem before.  Yet I could not find much help searching the
Web.  In processor23, the loader being used was StandardClassLoader, and
the deadlock occurred when it tries to grab the webappclassloader after
that.  Is this a bug in Tomcat?  How do others normally handle HTTP
requests coming in while the server is being restarted?  I am thinking
of pre-loading classes but it seems like a hack for a very typical
deployment.
 
I appreciate any pointers.  
 
Regards,
 
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: Found one Java-level
deadlock:
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger:
=============================
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: "http-8443-Processor19":
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger:   waiting to lock monitor
0x081702dc (object 0x914a4150, a [Ljava.lang.String;),
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger:   which is held by
"http-8443-Processor23"
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: "http-8443-Processor23":
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger:   waiting to lock monitor
0x84392f6c (object 0x91d86af8, a
org.apache.catalina.loader.WebappClassLoader),
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger:   which is held by
"http-8443-Processor19"
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: 
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: Java stack information for
the threads listed above:
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger:
===================================================
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: "http-8443-Processor19":
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
java.lang.SecurityManager.checkPackageAccess(SecurityManager.java:1467)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^I- waiting to lock
<0x914a4150> (a [Ljava.lang.String;)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader
.java:1276)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader
.java:1190)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
java.lang.ClassLoader.loadClassInternal(ClassLoader.java:302)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^I- locked <0x91d86af8> (a
org.apache.catalina.loader.WebappClassLoader)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
org.apache.struts.action.ActionServlet.process(ActionServlet.java:1189)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:414)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
javax.servlet.http.HttpServlet.service(HttpServlet.java:689)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: "http-8443-Processor23":
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
java.lang.Class.forName0(Native Method)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
java.lang.Class.forName(Class.java:219)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
javax.security.auth.Policy$3.run(Policy.java:215)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
java.security.AccessController.doPrivileged(Native Method)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
javax.security.auth.Policy.getPolicyNoCheck(Policy.java:209)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^I- locked <0xb0f678f0> (a
java.lang.Class)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
javax.security.auth.Policy.getPolicy(Policy.java:179)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
javax.security.auth.SubjectDomainCombiner$2.run(SubjectDomainCombiner.ja
va:180)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
java.security.AccessController.doPrivileged(Native Method)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
javax.security.auth.SubjectDomainCombiner.combine(SubjectDomainCombiner.
java:176)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
java.security.AccessControlContext.goCombiner(AccessControlContext.java:
386)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
java.security.AccessControlContext.optimize(AccessControlContext.java:31
0)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
java.security.AccessController.checkPermission(AccessController.java:400
)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
java.lang.SecurityManager.checkPermission(SecurityManager.java:524)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
java.lang.SecurityManager.checkPackageAccess(SecurityManager.java:1491)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^I- locked <0x914a4150> (a
[Ljava.lang.String;)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
org.apache.catalina.loader.StandardClassLoader.loadClass(StandardClassLo
ader.java:791)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
org.apache.catalina.loader.StandardClassLoader.loadClass(StandardClassLo
ader.java:722)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
java.lang.ClassLoader.loadClassInternal(ClassLoader.java:302)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^I- locked <0x914901a8> (a
org.apache.catalina.loader.StandardClassLoader)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
org.apache.catalina.servlets.DefaultServlet.serveResource(DefaultServlet
.java:860)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
org.apache.catalina.servlets.DefaultServlet.doGet(DefaultServlet.java:44
8)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
javax.servlet.http.HttpServlet.service(HttpServlet.java:689)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
Oct 14 16:58:57 tsbu-ctm14 local6 6 logger: ^Iat
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 
===================
Huy T. Vo
Voice:   408-853-0535
Fax:      408-853-1671