Bug 52326

Summary:	Lower log level for failed class loading
Product:	Tomcat 7	Reporter:	Filip Hanik <fhanik>
Component:	Catalina	Assignee:	Tomcat Developers Mailing List <dev>
Status:	RESOLVED FIXED
Severity:	minor	CC:	cbeams, mail, rmorgan
Priority:	P2
Version:	7.0.23
Target Milestone:	---
Hardware:	PC
OS:	All

Description Filip Hanik 2011-12-13 18:47:41 UTC

Reference: https://jira.springsource.org/browse/SPR-8894

Tomcat attempts to load classes when it searches for annotations. These class loading attempts when failed, should be silently ignored. 

If the application attempts to load the classes later, it will receive the actual error. However, when Tomcat prints out the stack trace of this class loading error, it gives the wrong signal. There is actually not anything wrong in the application itself, so a WARN as tomcat logs with a stack trace becomes misleading.

The initial fix would be: ContextConfig.java to drop log level to debug in checkHandleTypes method
       Class<?> clazz = null;
        try {
            clazz = context.getLoader().getClassLoader().loadClass(className);
        } catch (NoClassDefFoundError e) {
            log.debug(sm.getString("contextConfig.invalidSciHandlesTypes",
                    className), e);
            return;
        } catch (ClassNotFoundException e) {
            log.warn(sm.getString("contextConfig.invalidSciHandlesTypes",
                    className), e);
            return;
        } catch (ClassFormatError e) {
            log.warn(sm.getString("contextConfig.invalidSciHandlesTypes",
                    className), e);
            return;
        } catch (Throwable t) {
            ExceptionUtils.handleThrowable(t);
            log.warn(sm.getString("contextConfig.invalidSciHandlesTypes",
                    className), t);
            return;
        }

The better fix would be to achieve the same without classloading at all.
Other containers do ignore any type of classloading errors during this sequence.

Comment 1 Johannes Rost 2011-12-22 10:55:19 UTC

If the application is big, the process of loading all classes takes quite long. Aproximatly 3 minutes extra for a 66MB web application, which takes about 20 seconds to start up, when no ServletContainerInitializer implementation is present.
It also consumes a lot of permGenSpace. More than 128MB extra, compared to start up without the initializer.

Comment 2 Chris Beams 2011-12-22 11:59:55 UTC

Filip, here's an additional closely related issue, essentially making the case that much stronger.

https://jira.springsource.org/browse/SPR-8945

Comment 3 Mark Thomas 2011-12-29 20:10:39 UTC

Fixed (by dropping to debug level) in trunk and 7.0.x. The fix will be in 7.0.24 onwards.

The 'better' fix will require a fair amount of refactoring. The reason the classes are loaded at the moment is to perform a Class.isAssignableFrom(Class) call.

Comment 4 Chris Beams 2012-01-01 20:01:14 UTC

Thanks, Mark.  We've seen several comments lately about startup time suffering due (apparently) to SCI classloading overhead.

For example: http://forum.springsource.org/showthread.php?120138-Startup-time-in-3-1-0-RELEASE

This is leading us to recommend folks start using metadata-complete="true" in web.xml; it's nice that there is an escape hatch here, but unfortunate to require people to do this when upgrading to Spring 3.1+Tomcat 7.

Is there already another issue that addresses the refactoring necessary to avoid classloading?  I can create it if not, though I'm sure you'd be more articulate at doing so.

Regards,

Chris

Comment 5 Konstantin Kolinko 2012-01-01 21:18:54 UTC

It sounds like offtopic in this issue, but just to correct misinformation,

(In reply to comment #4)
> This is leading us to recommend folks start using metadata-complete="true" in
> web.xml; it's nice that there is an escape hatch here, but unfortunate to
> require people to do this when upgrading to Spring 3.1+Tomcat 7.

The metadata-complete attribute is nothing new. It is @since Servlet 2.5 and thus is already present in Tomcat 6.

The tip to set metadata-complete="true" is valid for any web application using servlet 2.5 or later, regardless of the server that you are using.

Comment 6 Chris Beams 2012-01-02 07:24:44 UTC

Hi Konstantin,

Right, the 'metadata-complete' attribute has been around for a while, but when used against Servlet 3.0+, its semantics expand to mean that ServletContainerInitializer processing is skipped altogether.  For users experiencing long startup times due to ServletContainerInitializer classloading overhead, metadata-complete="true" provides a simple way of avoiding the problem.

Of course, the trouble is that these users may actually want or need to use ServletContainerInitializer functionality, for example taking advantage of Spring 3.1's WebApplicationInitializer support[1].  As long as SCI processing involves expensive classloading, larger applications will suffer from long startup times and thus be encouraged to "shut off" this functionality via metadata-complete="true".

Thanks,

Chris

[1] http://static.springsource.org/spring/docs/3.1.x/javadoc-api/org/springframework/web/WebApplicationInitializer.html

Comment 7 Chris Beams 2012-01-09 17:13:57 UTC

I just created bug 52444 to capture the request to move away from classloading when processing @HandlesTypes.

Comment 8 Costin Leau 2012-01-29 11:33:15 UTC

Another +1 regarding skipping class loading - it simply has too many bad side effects (including initializing static blocks way too early). See bug 52549 for more info.