Bug 57906 - Message about failure to load ApplicationContextFacadeBeanInfo class when running with SecurityManager enabled
Message about failure to load ApplicationContextFacadeBeanInfo class when run...
Status: RESOLVED FIXED
Product: Tomcat 7
Classification: Unclassified
Component: Catalina
7.0.61
PC All
: P2 minor (vote)
: ---
Assigned To: Tomcat Developers Mailing List
:
Depends on:
Blocks:
  Show dependency tree
 
Reported: 2015-05-08 16:31 UTC by Konstantin Kolinko
Modified: 2015-12-17 14:55 UTC (History)
0 users



Attachments
test57905.jsp - simple page to test/demonstrate this issue (111 bytes, text/plain)
2015-12-17 13:44 UTC, Konstantin Kolinko
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Konstantin Kolinko 2015-05-08 16:31:19 UTC
I noted this while testing 7.0.62 release candidate, but this is reproducible with 7.0.61 as well, so it is not a regression.

The issue does not happen when running with Java 8u45.
The issue does not happen when running with Java 7u80.
The issue DOES happen when running with Java 6u45 (Windows 7).

So it depends on version of JRE.

Steps:
1. Get a clean copy of Tomcat 7
2. Set JAVA_HOME = jdk 6u45
3. Start with SecurityManager enabled  (catalina.bat start -security)
4. Access http://localhost:8080/
5. An INFO message with a stacktrace of java.security.AccessControlException is logged by WebappClassLoader to catalina.yyyy-mm-dd.log, as well as console.

I do not notice any user-visible consequences from the above. The index page shows successfully. Generated HTML is the same as when running without security manager.

The examples web application works successfully.

The message is only logged on the first access to index page of ROOT web application after Tomcat start. It is not logged on reloads of the page.

It is not logged for examples web application. If I restart Tomcat and walk around examples, there is no message. Once I visit the index page the message is logged.

The message: (Tomcat 7.0.62, Java 6u45)

[[[
08.05.2015 18:17:05 org.apache.catalina.loader.WebappClassLoader loadClass
INFO: Security Violation, attempt to use Restricted Class: org.apache.catalina.core.ApplicationContextFacadeBeanInfo
java.security.AccessControlException: access denied (java.lang.RuntimePermission accessClassInPackage.org.apache.catalina.core)
	at java.security.AccessControlContext.checkPermission(AccessControlContext.java:374)
	at java.security.AccessController.checkPermission(AccessController.java:549)
	at java.lang.SecurityManager.checkPermission(SecurityManager.java:532)
	at java.lang.SecurityManager.checkPackageAccess(SecurityManager.java:1512)
	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1656)
	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1571)
	at java.beans.Introspector.instantiate(Introspector.java:1470)
	at java.beans.Introspector.findExplicitBeanInfo(Introspector.java:431)
	at java.beans.Introspector.<init>(Introspector.java:380)
	at java.beans.Introspector.getBeanInfo(Introspector.java:154)
	at javax.el.BeanELResolver$BeanProperties.<init>(BeanELResolver.java:252)
	at javax.el.BeanELResolver.property(BeanELResolver.java:373)
	at javax.el.BeanELResolver.getValue(BeanELResolver.java:97)
	at org.apache.jasper.el.JasperELResolver.getValue(JasperELResolver.java:104)
	at org.apache.el.parser.AstValue.getValue(AstValue.java:183)
	at org.apache.el.ValueExpressionImpl.getValue(ValueExpressionImpl.java:184)
	at org.apache.jasper.runtime.PageContextImpl.proprietaryEvaluate(PageContextImpl.java:944)
	at org.apache.jsp.index_jsp._jspService(index_jsp.java:107)
	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
	at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:439)
	at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:395)
	at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:339)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:276)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:273)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAsPrivileged(Subject.java:517)
	at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:308)
	at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:168)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:297)
	at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:55)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:191)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:187)
	at java.security.AccessController.doPrivileged(Native Method)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:186)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
	at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:957)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423)
	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1079)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:620)
	at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:662)
]]]


I tried to workaround the issue by adding the following attribute to JreMemoryLeakPreventionListener class in server.xml [1]:

classesToInitialize="org.apache.catalina.core.ApplicationContextFacadeBeanInfo"

to preload that class. The workaround did not help. The behaviour with Java 6u45 has not changed.


[1] http://tomcat.apache.org/tomcat-7.0-doc/config/listeners.html
Comment 1 Konstantin Kolinko 2015-05-08 16:41:53 UTC
Preloading did not help, because there is no such class as "ApplicationContextFacadeBeanInfo" in Tomcat.

This issue has only a cosmetic effect. The class won't be loaded anyway, as there is no such class in Tomcat. It does not affect execution.


The java.beans.Introspector.findExplicitBeanInfo() method of JRE tries to load "xxxBeanInfo" class for "xxx" class that it works with. In this case BeanInfo class does not exist.



(Therefore I am reducing severity of this issue to 'minor'.)
Comment 2 Mark Thomas 2015-06-16 07:49:54 UTC
Given that:
- this is a purely cosmetic issue
- the root cause appears to be in the JRE since it only appears when running with Java 6
- public updates for Orace's Java 6 ceased in Feb 2013
- it only occurs when running under a security manager

I'm am leaning towards resolving this as WONTFIX.

Users still running Java 6 who want a fix for this issue can either update to Java 7 or request a Java 6 fix from their JVM vendor.
Comment 3 Konstantin Kolinko 2015-12-17 13:44:27 UTC
Created attachment 33358 [details]
test57905.jsp - simple page to test/demonstrate this issue

Updating status of this issue, with current Tomcat code

First, a simple test page

Updated steps:

(In reply to Konstantin Kolinko from comment #0)
> Steps:
> 1. Get a clean copy of Tomcat 7
> 2. Set JAVA_HOME = jdk 6u45
> 3. Start with SecurityManager enabled  (catalina.bat start -security)

4.1. Put the attached test57905.jsp into webapps/ROOT
4.2. Access http://localhost:8080/test57905.jsp

> 5.1. The page shows successfully

It displays Tomcat version number.

> 5.2. An INFO message with a stacktrace of java.security.AccessControlException
> is logged by WebappClassLoader to catalina.yyyy-mm-dd.log, as well as
> console.
>
Comment 4 Konstantin Kolinko 2015-12-17 14:09:00 UTC
1. This issue was not visible with 7.0.57 because EL evaluation was performed with elevated privileges (CVE-2014-7810, fixed in 7.0.58 onwards)

2. The differences between versions of Java

> at java.beans.Introspector.instantiate(Introspector.java:1470)
> at java.beans.Introspector.findExplicitBeanInfo(Introspector.java:431)

In JDK 6u45 Introspector.instantiate() is a method that tries several classloaders to load class named (beanClass.getName() + BEANINFO_SUFFIX)

a. tries original classloader beanClass
b. tries system classloader
c. tries TCCL

All tries are wrapped with try{}catch(Exception){} and the Exception is silently swallowed.

The "c." step is what triggers the INFO message and stacktrace here.


In Java 7 the implementation was moved into different class,
com.sun.beans.finder.ClassFinder.findClass(className, beanClass.getClassLoader())

According to some version of source code [1], the implementation of that method starts with a "checkPackageAccess(name);" call. So a SecurityException is raised immediately and no class loading occurs.


[1] http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/7u40-b43/com/sun/beans/finder/ClassFinder.java/#100


3. Stacktrace with current Tomcat 7 (@rev.1720550) and Java 6u45

Behaviour is the same as documented in Comment 0, but stacktrace is a bit different. WebappClassLoader has been refactored, so the calls are now in WebappClassLoaderBase class.

[[[
17.12.2015 17:08:00 org.apache.catalina.loader.WebappClassLoaderBase loadClass
INFO: Security Violation, attempt to use Restricted Class: org.apache.catalina.core.ApplicationContextFacadeBeanInfo
java.security.AccessControlException: access denied (java.lang.RuntimePermission accessClassInPackage.org.apache.catalina.core)
	at java.security.AccessControlContext.checkPermission(AccessControlContext.java:374)
	at java.security.AccessController.checkPermission(AccessController.java:549)
	at java.lang.SecurityManager.checkPermission(SecurityManager.java:532)
	at java.lang.SecurityManager.checkPackageAccess(SecurityManager.java:1512)
	at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1791)
	at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1705)
	at java.beans.Introspector.instantiate(Introspector.java:1470)
	at java.beans.Introspector.findExplicitBeanInfo(Introspector.java:431)
	at java.beans.Introspector.<init>(Introspector.java:380)
	at java.beans.Introspector.getBeanInfo(Introspector.java:154)
	at javax.el.BeanELResolver$BeanProperties.<init>(BeanELResolver.java:252)
	at javax.el.BeanELResolver.property(BeanELResolver.java:373)
	at javax.el.BeanELResolver.getValue(BeanELResolver.java:97)
	at org.apache.jasper.el.JasperELResolver.getValue(JasperELResolver.java:104)
	at org.apache.el.parser.AstValue.getValue(AstValue.java:184)
	at org.apache.el.ValueExpressionImpl.getValue(ValueExpressionImpl.java:184)
	at org.apache.jasper.runtime.PageContextImpl.proprietaryEvaluate(PageContextImpl.java:950)
	at org.apache.jsp.test57905_jsp._jspService(test57905_jsp.java:82)
	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
	at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:439)
	at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:395)
	at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:339)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:288)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:285)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAsPrivileged(Subject.java:517)
	at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:320)
	at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:175)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:297)
	at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:55)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:191)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:187)
	at java.security.AccessController.doPrivileged(Native Method)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:186)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
	at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423)
	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1079)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625)
	at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:662)
]]]
Comment 5 Konstantin Kolinko 2015-12-17 14:39:42 UTC
4. Tomcat 6 does not log any INFO message with Java 6u45.
The reason for this though is an unexpected one.

The reason is in the following block of code:

[[[
        try {
            clazz = system.loadClass(name);
            if (clazz != null) {
                if (resolve)
                    resolveClass(clazz);
                return (clazz);
            }
        } catch (ClassNotFoundException e) {
            // Ignore
        }
]]]

The system.loadClass(name) call fails with a SecurityException (AccessControlException). This exception is not logged.


If I add an additional try/catch and debug logging in WebappClassLoader.loadClass() method, the stacktrace is as following:

The below is 6u45 + Tomcat 6. Note: WebappClassLoader.java was edited to add debug logging, as such line numbers are shifted.

[[[
java.security.AccessControlException: access denied (java.lang.RuntimePermission accessClassInPackage.org.apache.catalina.core)
	at java.security.AccessControlContext.checkPermission(AccessControlContext.java:374)
	at java.security.AccessController.checkPermission(AccessController.java:549)
	at java.lang.SecurityManager.checkPermission(SecurityManager.java:532)
	at java.lang.SecurityManager.checkPackageAccess(SecurityManager.java:1512)
	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:298)
	at java.lang.ClassLoader.loadClass(ClassLoader.java:247)
	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1613)
	at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1526)
	at java.beans.Introspector.instantiate(Introspector.java:1470)
	at java.beans.Introspector.findExplicitBeanInfo(Introspector.java:431)
	at java.beans.Introspector.<init>(Introspector.java:380)
	at java.beans.Introspector.getBeanInfo(Introspector.java:154)
	at javax.el.BeanELResolver$BeanProperties.<init>(BeanELResolver.java:200)
	at javax.el.BeanELResolver.property(BeanELResolver.java:320)
	at javax.el.BeanELResolver.getValue(BeanELResolver.java:81)
	at javax.el.CompositeELResolver.getValue(CompositeELResolver.java:54)
	at org.apache.el.parser.AstValue.getValue(AstValue.java:123)
	at org.apache.el.ValueExpressionImpl.getValue(ValueExpressionImpl.java:182)
	at org.apache.jasper.runtime.PageContextImpl.proprietaryEvaluate(PageContextImpl.java:897)
	at org.apache.jsp.test57905_jsp._jspService(test57905_jsp.java:53)
	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:723)
	at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:388)
	at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:313)
	at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:260)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:723)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:277)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:276)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAsPrivileged(Subject.java:517)
	at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:309)
	at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:170)
	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:103)
	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:861)
	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:620)
	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
	at java.lang.Thread.run(Thread.java:662)
]]]


Tomcat 7 calls a different class loader (the j2se bootstrap classloader instead of system one), and that call does not fail, and fails a few lines later -- at an explicit "securityManager.checkPackageAccess(..);" call.


Conclusion
--------
1. The difference with Tomcat 6 is that
- Tomcat 6 throws original SecurityException,
- Tomcat 7 catches SecurityException, logs an INFO message and throws a new ClassNotFoundException

I do not see any fault in Tomcat 6 rethrowing the exception. The access to protected classes is blocked either way.


I do not know why Tomcat 7 converts a SecurityException into ClassNotFoundException.  One guess is that the reason is that "SecurityException" is not mentioned in javadoc of ClassLoader.loadClass() method so it is unclear whether the method is allowed to throw one.


2. Possible mitigations:
a. Change Tomcat 7 to rethrow original SecurityException instead of converting it into ClassNotFoundException

b. Reduce logging level from INFO to DEBUG if the loaded class name ends with "BeanInfo".

This does not hide anything substantial. An attempt to load a '*BeanInfo' class is not related to any attempt to load a '*' class.

c. WONTFIX.


I am in favor of mitigation "b.".

We can use "a." if there are other similar reports, but for now I do not see enough reasons to change the behaviour.
Comment 6 Konstantin Kolinko 2015-12-17 14:55:28 UTC
Fixed in Tomcat 7 by r1720568 and will be in 7.0.68.

Tomcat 6 does not need this fix.
Tomcat 8 and later run on later versions of Java and do not need this fix either.