ClassNotFoundException for sun.reflect.MethodAccessorImpl using Janino + Logback + Tomcat on redeploy

Question

I have an application deployed under tomcat 8.5.32 (latest java 8, 1.8.0_181), using the latest logback 1.2.3, janino 3.0.8 and slf4f 1.7.25.

My logback xml has a filter like this:

<filter class="ch.qos.logback.core.filter.EvaluatorFilter">   
<evaluator> 
        <expression>return message != null &amp;&amp; message.contains("127.0.0.1");
</expression>   
</evaluator>   
<OnMismatch>NEUTRAL</OnMismatch>   
<OnMatch>DENY</OnMatch>
</filter>

It all works fine until I redeploy. Then I get an exception like this:

Jul 30, 2018 8:00:18 AM org.apache.catalina.startup.HostConfig reload
WARNING: Error during context [] restart
org.apache.catalina.LifecycleException: Failed to stop component [StandardEngine[Catalina-b].StandardHost[localhost].StandardContext[]]
        at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:238)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:142)
        at org.apache.catalina.startup.HostConfig.reload(HostConfig.java:1386)
        at org.apache.catalina.startup.HostConfig.checkResources(HostConfig.java:1287)
        at org.apache.catalina.startup.HostConfig.check(HostConfig.java:1586)
        at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:280)
        at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:94)
        at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1136)
        at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1372)
        at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1376)
        at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1344)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NoClassDefFoundError: sun/reflect/MethodAccessorImpl
        at sun.misc.Unsafe.defineClass(Native Method)
        at sun.reflect.ClassDefiner.defineClass(ClassDefiner.java:63)
        at sun.reflect.MethodAccessorGenerator$1.run(MethodAccessorGenerator.java:399)
        at sun.reflect.MethodAccessorGenerator$1.run(MethodAccessorGenerator.java:394)
        at java.security.AccessController.doPrivileged(Native Method)
        at sun.reflect.MethodAccessorGenerator.generate(MethodAccessorGenerator.java:393)
        at sun.reflect.MethodAccessorGenerator.generateMethod(MethodAccessorGenerator.java:75)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:53)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.codehaus.janino.ScriptEvaluator.evaluate(ScriptEvaluator.java:756)
        at org.codehaus.janino.ScriptEvaluator.evaluate(ScriptEvaluator.java:748)
        at ch.qos.logback.core.boolex.JaninoEventEvaluatorBase.evaluate(JaninoEventEvaluatorBase.java:72)
        at ch.qos.logback.core.filter.EvaluatorFilter.decide(EvaluatorFilter.java:65)
        at ch.qos.logback.core.spi.FilterAttachableImpl.getFilterChainDecision(FilterAttachableImpl.java:52)
        at ch.qos.logback.core.AppenderBase.getFilterChainDecision(AppenderBase.java:134)
        at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:80)
        at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)
        at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:272)
        at ch.qos.logback.classic.Logger.callAppenders(Logger.java:259)
        at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:441)
        at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:395)
        at ch.qos.logback.classic.Logger.log(Logger.java:787)
        at org.slf4j.bridge.SLF4JBridgeHandler.callLocationAwareLogger(SLF4JBridgeHandler.java:224)
        at org.slf4j.bridge.SLF4JBridgeHandler.publish(SLF4JBridgeHandler.java:301)
        at java.util.logging.Logger.log(Logger.java:738)
        at java.util.logging.Logger.doLog(Logger.java:765)
        at java.util.logging.Logger.logp(Logger.java:1042)
        at org.apache.juli.logging.DirectJDKLog.log(DirectJDKLog.java:181)
        at org.apache.juli.logging.DirectJDKLog.error(DirectJDKLog.java:147)
        at org.apache.catalina.core.StandardContext.listenerStop(StandardContext.java:4780)
        at org.apache.catalina.core.StandardContext.stopInternal(StandardContext.java:5411)
        at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:226)
        ... 11 more
Caused by: java.lang.ClassNotFoundException: sun.reflect.MethodAccessorImpl
        at org.codehaus.janino.ByteArrayClassLoader.findClass(ByteArrayClassLoader.java:68)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        ... 44 more

My theory is that juli->SLF4J->logback->janino ends up using the container class loader that ends up stopped, but the logging framework doesn't realize that.

Any idea on how to work around this?

Answer 1

This turned out to be a problem caused by the logback listener not being first in my web.xml

<listener>
    <listener-class>ch.qos.logback.classic.selector.servlet.ContextDetachingSCL</listener-class>
</listener>

https://logback.qos.ch/manual/loggingSeparation.html clearly stated as much:

Most containers invoke the contextInitialized() method of listeners in the order in which they are declared but invoke their contextDestroyed() method in reverse order. It follows that if you have multiple ServletContextListener declarations in your web.xml, then ContextDetachingSCL should be declared first so that its contextDestroyed() method is invoked last during application shutdown.