Bug 48097 - NoClassDefFoundError on first access of first jsp
Summary: NoClassDefFoundError on first access of first jsp
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 6
Classification: Unclassified
Component: Catalina (show other bugs)
Version: 6.0.20
Hardware: PC Linux
: P2 normal (vote)
Target Milestone: default
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2009-11-01 11:06 UTC by Amichai
Modified: 2010-01-22 00:11 UTC (History)
1 user (show)



Attachments
simple webapp with one jsp and one class in one jar, reproducing the error (2.09 KB, application/zip)
2009-11-01 11:06 UTC, Amichai
Details
Patch for WebappClassLoader to do not swallow AccessControlException (618 bytes, patch)
2009-11-01 21:17 UTC, Konstantin Kolinko
Details | Diff
Patch for SecurityClassLoad to preload o.a.c.loader.ResourceEntry class (513 bytes, application/octet-stream)
2009-11-01 23:56 UTC, Konstantin Kolinko
Details
Patch for WebappClassLoader to do not swallow AccessControlException (updated) (1.13 KB, patch)
2009-11-02 00:03 UTC, Konstantin Kolinko
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Amichai 2009-11-01 11:06:06 UTC
Created attachment 24452 [details]
simple webapp with one jsp and one class in one jar, reproducing the error

I've had a strange situation getting NoClassDefFoundErrors on a particular jsp
page (which happened to be the index.jsp page). The class it claimed to not
find is a simple session bean class within a jar in the WEB-INF/lib folder. The
strange thing is that it gave this error only when this page was the first one
accessed after a tomcat restart. If any page was accessed before it, it would
work properly. But if this page was accessed first, then no matter what pages
were later accessed, the error remained in place. So the error/success state
was determined by whichever page was accessed first ater the tomcat restart,
and remained in the same error/success state for as long as tomcat was up,
regardless of anything happening later on (until the next restart)

This seems to be some sort of class-loading oder-of-initialization bug, but is
entirely consistent when the pages are accessed in this order after a tomcat
restart. It drove me nuts for a while, since the main application page was
showing an error after every restart, but I eventually stumbled on a strange
workaround: changing the order or a couple of lines in the jsp, involving the
useBean directive and access to java's URI class. with the order changed, the
error never happens. with the order returned, the error is reproduced as
described above.

I've managed to distill a simple scenario which reproduces this error - a short
jsp and a trivial bean session class - attached. I reproduced this on a fresh
installation of Kubuntu 9.10 in a virtual machine, with sun jre 6 and tomcat6
installed. I didn't change any configuration, just replaced the ROOT sample
webapp with this one, restarted tomcat, and browsed to
http://localhost:8080/index.jsp. Remember u have to restart tomcat after every
change to the jsp if u want to recreate the bug, because simply changing it and
refreshing the browser will always succeed.
Comment 1 Konstantin Kolinko 2009-11-01 12:44:49 UTC
What is your configuration of JspServlet in conf/web.xml file?
Its "development" option is set to true or false?

Is your Tomcat version 6.0.20?

Are you running with SecurityManager enabled?

Can you provide any stack traces? From the error page and from the log files.
Comment 2 Amichai 2009-11-01 13:51:27 UTC
Yes, it's version 6.0.20. As mentioned, I changed nothing at all in the default configuration from the distro's installation - simply overwrote the webapps/ROOT folder.

The JspServlet configuration in web.xml:

<servlet>
        <servlet-name>jsp</servlet-name>
        <servlet-class>org.apache.jasper.servlet.JspServlet</servlet-class>
        <init-param>
            <param-name>fork</param-name>
            <param-value>false</param-value>
        </init-param>
        <init-param>
            <param-name>xpoweredBy</param-name>
            <param-value>false</param-value>
        </init-param>
        <load-on-startup>3</load-on-startup>
    </servlet>

I don't see 'development' set anywhere in web.xml, so I guess it uses the default.

I didn't explicitly set a SecurityManager, where can I check what the default is, or if it is set?

There are two types of errors in the logs, from the first access after a restart, and a refresh after that:

ov 1, 2009 8:50:11 PM org.apache.catalina.core.StandardWrapperValve invoke
SEVERE: Servlet.service() for servlet jsp threw exception
java.lang.NoClassDefFoundError: net/freeutils/web/SessionBean
        at org.apache.jsp.index_jsp._jspService(index_jsp.java:64)
        at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
        at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:374)
        at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:342)
        at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:267)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:616)
        at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:269)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAsPrivileged(Subject.java:537)
        at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:301)
        at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:162)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:283)
        at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:56)
        at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:189)
        at java.security.AccessController.doPrivileged(Native Method)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:185)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:849)
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:454)
        at java.lang.Thread.run(Thread.java:636)
Nov 1, 2009 8:50:30 PM org.apache.catalina.core.StandardWrapperValve invoke
SEVERE: Servlet.service() for servlet jsp threw exception
java.lang.ClassNotFoundException: net.freeutils.web.SessionBean
        at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1387)
        at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1233)
        at org.apache.jasper.servlet.JasperLoader.loadClass(JasperLoader.java:128)
        at org.apache.jasper.servlet.JasperLoader.loadClass(JasperLoader.java:66)
        at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:336)
        at org.apache.jsp.index_jsp._jspService(index_jsp.java:64)
        at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
        at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:374)
        at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:342)
        at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:267)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:616)
        at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:269)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAsPrivileged(Subject.java:537)
        at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:301)
        at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:162)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:283)
        at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:56)
        at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:189)
        at java.security.AccessController.doPrivileged(Native Method)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:185)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:849)
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:454)
        at java.lang.Thread.run(Thread.java:636)


The error page exception:

description The server encountered an internal error () that prevented it from fulfilling this request.

exception

org.apache.jasper.JasperException: javax.servlet.ServletException: java.lang.NoClassDefFoundError: net/freeutils/web/SessionBean
	org.apache.jasper.servlet.JspServletWrapper.handleJspException(JspServletWrapper.java:522)
	org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:398)
	org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:342)
	org.apache.jasper.servlet.JspServlet.service(JspServlet.java:267)
	javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	java.lang.reflect.Method.invoke(Method.java:616)
	org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:269)
	java.security.AccessController.doPrivileged(Native Method)
	javax.security.auth.Subject.doAsPrivileged(Subject.java:537)
	org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:301)
	org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:162)

root cause

javax.servlet.ServletException: java.lang.NoClassDefFoundError: net/freeutils/web/SessionBean
	org.apache.jasper.runtime.PageContextImpl.doHandlePageException(PageContextImpl.java:862)
	org.apache.jasper.runtime.PageContextImpl.access$1100(PageContextImpl.java:71)
	org.apache.jasper.runtime.PageContextImpl$12.run(PageContextImpl.java:778)
	java.security.AccessController.doPrivileged(Native Method)
	org.apache.jasper.runtime.PageContextImpl.handlePageException(PageContextImpl.java:776)
	org.apache.jsp.index_jsp._jspService(index_jsp.java:85)
	org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
	javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:374)
	org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:342)
	org.apache.jasper.servlet.JspServlet.service(JspServlet.java:267)
	javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	java.lang.reflect.Method.invoke(Method.java:616)
	org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:269)
	java.security.AccessController.doPrivileged(Native Method)
	javax.security.auth.Subject.doAsPrivileged(Subject.java:537)
	org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:301)
	org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:162)

root cause

java.lang.NoClassDefFoundError: net/freeutils/web/SessionBean
	org.apache.jsp.index_jsp._jspService(index_jsp.java:64)
	org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
	javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:374)
	org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:342)
	org.apache.jasper.servlet.JspServlet.service(JspServlet.java:267)
	javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	java.lang.reflect.Method.invoke(Method.java:616)
	org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:269)
	java.security.AccessController.doPrivileged(Native Method)
	javax.security.auth.Subject.doAsPrivileged(Subject.java:537)
	org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:301)
	org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:162)


Any other information that I can supply to help resolve this?
Comment 3 Konstantin Kolinko 2009-11-01 16:18:11 UTC
Thank you for the information.

I can see from the stacktraces that you run with SecurityManager enabled.
(That is default in some re-distributions of Tomcat).

The "development" flag of JspServlet defaults to "true".


Unfortunately, as of now I cannot reproduce your error neither on 6.0.20 nor on the latest tc6.0.x.   While trying your app I saw an error once in latest tc6.0.x, but it was different from what you are observing, and it also is no more reproducible. As it is so hard to reproduce, I suppose it is a race condition.


The error that you observed occurs in _jspService() method of compiled JSP page class. So the class was successfully compiled, loaded into memory, its instance created, _jspService method called, and then the error occurs.
> org.apache.jsp.index_jsp._jspService(index_jsp.java:64)

Line 64 in my copy of the file, compiled by Tomcat 6.0.20, is
> bean = new net.freeutils.web.SessionBean();

It was WebappClassLoader's responsibility to load the class. Line 1387 there is the normal exit, when no classfile is found.
> org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1387)

I do not see any clues to what could have caused this.


Note, that requesting '/index.jsp' and requesting '/' might be different, because the latter involves more resource existence checks.


Our usual question regarding re-distributions of Tomcat is whether an error is reproducible with our official distribution from tomcat.apache.org.

Note, that to start with SecurityManager you run 'catalina.sh start -security', and that the default conf/catalina.policy file of TC 6.0.20 does not work with recent version of Sun JRE (starting with 6u14). You have to get the updated version of it from
http://svn.apache.org/repos/asf/tomcat/tc6.0.x/trunk/conf/
Comment 4 Amichai 2009-11-01 17:20:57 UTC
The bug occurs both with access to '/' and to '/index.jsp', so that can be ruled out as a cause.

I hope I understood you correctly - to make sure, here are the exact steps I just did:
0. stopped the distro's tomcat instance, and verified there's nothing at localhost:8080.
1. downloaded the tomcat 6.0.20 binary tar.gz distribution from http://tomcat.apache.org/download-60.cgi, and extracted it to a temp folder.
2. renamed the webapps/ROOT app to webapps/ROOT.original, and copied the ROOT app (the attachment to this bug) in its place.
3. ran './catalina.sh start -security' from the bin directory.
4. opened localhost:8080/index.jsp in the browser. the page loaded successfully.
5. I realized the classloading was behaving differently than before since there are other webapps (the samples in the distribution, etc.). I backed up the entire webapps folder to webapps.original, and then deleted all folders under webapps, leaving only the ROOT folder (which is my sample app).
6. ran './catalina.sh stop', refreshed the browser to make sure the server is down, followed by './catalina.sh start'.
7. refreshed the browser again - and the error was reproduced.
8. downloaded the catalina.policy file from http://svn.apache.org/repos/asf/tomcat/tc6.0.x/trunk/conf/ and replaced the conf/catalina.policy file with it.
9. did steps 6 and 7 again, and the error was reproduced again.
10. repeated steps 6 and 7 again a few more times, accessing either '/' or '/index.jsp', changing the order of the jsp lines (as described in the original report), etc. everything was reproduced exactly as in the original report.

So, in a nutshell, take the official tomcat binary unmodified, delete everything in the webapps folder (which cause a different classloading sequence to occur), put the attached ROOT sample app in there, and fire it up - this was enough to fully reproduce the bug.
Comment 5 Konstantin Kolinko 2009-11-01 21:17:48 UTC
Created attachment 24456 [details]
Patch for WebappClassLoader to do not swallow AccessControlException

The patch is for the current tc6.0.x
Comment 6 Konstantin Kolinko 2009-11-01 22:15:14 UTC
Thank you for the recipe, I was able to reproduce the issue.

The issue is observable both in 6.0.20 and in current 6.0.x sources, and I was able to do some debugging.

~ What is essential: ~

1). I updated my JDK to 6u16. I was using 6u15 previously.
I have not verified yet that it indeed works OK with 6u15, but it might be it.

2). It is essential to run with SecurityManager enabled.

The permissions are essential. If you add
grant {
        permission java.security.AllPermission;
}
all starts working again.

3). I removed all applications from the webapps folder, except the ROOT application that was replaced with the one from attachment 24452 [details].

4). You need to precompile the JSP page. That is, start Tomcat, access the page, shutdown Tomcat, and start it for the second time.

5). Access http://localhost:8080/

6). The stacktrace as in Comment #2 is observed.


~ Debugging showed the following: ~

The following line in WebappClassLoader#findResourceInternal(String) resulted in AccessControlException:
2070:   entry = new ResourceEntry();

The exception was caught by the caller (WebappClassLoader#findClass(String)) and wrapped into ClassNotFoundException.

The ClassNotFoundException was caught by the caller (WebappClassLoader#loadClass(String,boolean)) and ignored. That is why we do not see it in the logs.

The patch in attachment 24456 [details] makes WebappClassLoader#findClass(String) to log the AccessControlException when it is encountered.

The exception text and stacktrace are the following:

02.11.2009 7:53:51 org.apache.catalina.loader.WebappClassLoader findClass
SEVERE: findClassInternal(net.freeutils.web.SessionBean) failed
java.security.AccessControlException: access denied (java.lang.RuntimePermission accessClassInPackage.org.apache.catalina.loader)
	at java.security.AccessControlContext.checkPermission(Unknown Source)
	at java.security.AccessController.checkPermission(Unknown Source)
	at java.lang.SecurityManager.checkPermission(Unknown Source)
	at java.lang.SecurityManager.checkPackageAccess(Unknown Source)
	at sun.misc.Launcher$AppClassLoader.loadClass(Unknown Source)
	at java.lang.ClassLoader.loadClass(Unknown Source)
	at java.lang.ClassLoader.loadClass(Unknown Source)
	at java.lang.ClassLoader.loadClassInternal(Unknown Source)
	at org.apache.catalina.loader.WebappClassLoader.findResourceInternal(WebappClassLoader.java:2070)
	at org.apache.catalina.loader.WebappClassLoader.findClassInternal(WebappClassLoader.java:1851)
	at org.apache.catalina.loader.WebappClassLoader.findClass(WebappClassLoader.java:887)
	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1352)
	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1231)
	at org.apache.jasper.servlet.JasperLoader.loadClass(JasperLoader.java:128)
	at org.apache.jasper.servlet.JasperLoader.loadClass(JasperLoader.java:66)
	at java.lang.ClassLoader.loadClassInternal(Unknown Source)
	at org.apache.jsp.index_jsp._jspService(index_jsp.java:64)
	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:374)
	at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:334)
	at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:259)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:269)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAsPrivileged(Unknown Source)
	at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:301)
	at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:162)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:283)
	at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:56)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:189)
	at java.security.AccessController.doPrivileged(Native Method)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:185)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:294)
	at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:852)
	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:478)
	at java.lang.Thread.run(Unknown Source)


~ Notes: ~

1. The 
java.security.AccessControlException that I cited above is printed into catalina.<date>.log

2. At the same time,
02.11.2009 8:51:54 org.apache.catalina.core.StandardWrapperValve invoke
SEVERE: Servlet.service() for servlet jsp threw exception
java.lang.ClassNotFoundException: net.freeutils.web.SessionBean
	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1385)
	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1231)
	at org.apache.jasper.servlet.JasperLoader.loadClass(JasperLoader.java:128)
	at org.apache.jasper.servlet.JasperLoader.loadClass(JasperLoader.java:66)
	at java.lang.ClassLoader.loadClassInternal(Unknown Source)
	at org.apache.jsp.index_jsp._jspService(index_jsp.java:64)

is printed into different log file, localhost.<date>.log


3. java.lang.NoClassDefFoundError: net/freeutils/web/SessionBean
	org.apache.jsp.index_jsp._jspService(index_jsp.java:64)
that is displayed on the error 500 page is not printed into the logs.

Though the ClassNotFoundException is also printed on the error 500 page as the root cause of that NoClassDefFoundError.

4. While debugging I also observed different behaviour: The request to http://localhost:8080/  resulted in blank page (response with content length of 0) being returned by the server.

Note, that the classes layout and the policy file were different while I was debugging.

The following additional steps allowed me to reproduce this error in that setup:
1) I deployed an additional empty web application, where I copied index.html from our examples app.
2) The first access to http://localhost:8080/  resulted in empty page, but if after that I accessed the second webapp, and, after some delay (about 5-10 seconds), used Ctrl+F5 to refresh http://localhost:8080/  in my Firefox,  the error showed itself.


5. The blank response suggests that there is some other place in the code, where AccessControlException is ignored. Nothing is written into the logs when the blank response is shown.  I do not know where it occurs.

6. The fix to this issue would be to either add some permissions to the policy, or to preload some classes, as we do. I do not know what is the root cause of it yet, though.
Comment 7 Konstantin Kolinko 2009-11-01 23:44:06 UTC
I debugged the case of the blank response.

The sequence of events is the following:

1) The index_jsp.class is successfully loaded, instantiated, and its _jspInit() method was successfully called.
2) The error occurs in its _jspService(request, response) method.

The code there is the following:
    try {
      response.setContentType("text/html; charset=UTF-8");
      pageContext = _jspxFactory.getPageContext(this, request, response,
      			null, true, 8192, true);
      _jspx_page_context = pageContext;

(...)
    } catch (Throwable t) {
      if (!(t instanceof SkipPageException)){
        out = _jspx_out;
        if (out != null && out.getBufferSize() != 0)
          try { out.clearBuffer(); } catch (java.io.IOException e) {}
        if (_jspx_page_context != null) _jspx_page_context.handlePageException(t);
      }
    } finally {
      _jspxFactory.releasePageContext(_jspx_page_context);
    }

The exception occurs when calling response.setContentType(). The exception is:
java.security.AccessControlException: access denied (java.lang.RuntimePermission accessClassInPackage.org.apache.catalina.connector)

Because it occurs earlier than the _jspx_page_context variable is initialized, the _jspx_page_context.handlePageException(t); line is not called and empty response is returned to the client.


The failure in setContentType() method occurs in ResponseFacade#setContentType(). It is caused by the attempt to load the following class: ResponseFacade$SetContentTypePrivilegedAction

That class is listed in o.a.catalina.security.SecurityClassLoad#loadCoyotePackage() but, because I used org.apache.catalina.startup.Catalina class to start Tomcat in the IDE, that method was not called at all. It is called from Bootstrap#init() only.

Jasper's SecurityClassLoad on the contrary is called, because that occurs in another place.

The blank page issue disappeared when I used o.a.c.startup.Bootstrap class instead of Catalina.

I do not know, whether we should fix this bootstrap issue. (Is anyone concerned?)
Comment 8 Konstantin Kolinko 2009-11-01 23:56:14 UTC
Created attachment 24457 [details]
Patch for SecurityClassLoad to preload o.a.c.loader.ResourceEntry class

This patch fixes the NoClassDefFoundError: net/freeutils/web/SessionBean issue.
It is for the current tc6.0.x.
Comment 9 Konstantin Kolinko 2009-11-02 00:03:32 UTC
Created attachment 24458 [details]
Patch for WebappClassLoader to do not swallow AccessControlException (updated)

Updated the WebappClassLoader patch.
- Changed the log message
- Reduced severity from error to warning
- There exist one more case where AccessControlException was swallowed, in the same method.
The patch is for the current tc6.0.x.
Comment 10 Amichai 2009-11-02 00:58:32 UTC
Thanks for the detailed investigation and review!

I've actually been hit by the blank page issue too a year ago, with a production system's home page returning a blank page and not being noticed for a while (monitoring tools all saw it's a 200 OK and didn't report an error). I didn't know how to recreate it at the time... funny that you hit it with this bug's investigation... (well, maybe funny isn't the right word).

So, are both issues fixed by these patches? the blank screen replaced with an error, and the error replaced with a successful page load? Is there anything more you need my help with?
Comment 11 Konstantin Kolinko 2009-11-02 01:34:00 UTC
Regarding the blank page issue:
I did not fix it. It was a configuration issue on my side.
Running Tomcat with o.a.c.startup.Catalina using a SecurityManager would still be broken. As of now, I do not know, whether and how to fix that.

Suggestions from other Tomcat committers are welcome.

I committed both the patches that fix NoClassDefFoundError issue into trunk, and will propose them for tc6.0.x

As of now, the trunk does not run with SecurityManager, apparently because of servlet 3.0 classes. This app would be a good example to test it.

> Is there anything more you need my help with?

I think we are done with it.
You may want to test TC 6.0.21 when it becomes available.
Comment 12 Mark Thomas 2009-11-11 01:18:21 UTC
The patches have been applied to 6.0.x and will be in 6.0.21 onwards.

You should also now be able to run trunk with a security manager.
Comment 13 Konstantin Kolinko 2009-11-12 11:13:01 UTC
Reopening.

The WebappClassLoader$PrivilegedFindResourceByName class (added in rev.834814) has to be preloaded in o.a.c.security.SecurityClassLoad#loadLoaderPackage().

That can be demonstrated by the following:
1. Deploy the sample ROOT application, as described in comment #6
2. Copy default conf/web.xml to webapps/ROOT/WEB-INF/
3. Remove all content from the default conf/web.xml and leave just the root XML tag and its attributes.
4. Start  catalina.bat start -security
5. Access http://localhost:8080/
6. Observe the exception

Usually the first calls to WebappClassLoader#findResourceInternal() are to load JspServlet and DefaultServlet. In this configuration those are avoided.


This is already fixed in trunk. I will propose a backport soon.
Comment 14 Mark Thomas 2009-12-16 08:56:55 UTC
The back port was proposed and has been applied to 6.0.x. It will be included in 6.0.21 onwards.
Comment 15 Konstantin Kolinko 2010-01-22 00:11:10 UTC
Fixed in 5.5 in r900755, will be in 5.5.29.

Note, though, that there can be other errors observable at the same circumstances, that are not yet fixed. See bug 48581, bug 48580.