ClassCastException Log4JLogger cannot be cast to Logger when redeploying ESAPI application in WildFly

Ryan S picture Ryan S · Apr 22, 2015 · Viewed 7.4k times · Source

I'm having what appears to be a weird class loading issue using ESAPI inside a WAR file deployed to WildFly.8.2.0.Final. Here's the error I'm getting:

09:35:47,383 ERROR [stderr] (default task-12) Caused by: java.lang.reflect.InvocationTargetException
09:35:47,383 ERROR [stderr] (default task-12)   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
09:35:47,383 ERROR [stderr] (default task-12)   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
09:35:47,383 ERROR [stderr] (default task-12)   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
09:35:47,383 ERROR [stderr] (default task-12)   at java.lang.reflect.Method.invoke(Method.java:606)
09:35:47,383 ERROR [stderr] (default task-12)   at org.owasp.esapi.util.ObjFactory.make(ObjFactory.java:86)
09:35:47,383 ERROR [stderr] (default task-12)   ... 111 more
09:35:47,383 ERROR [stderr] (default task-12) Caused by: java.lang.ClassCastException: org.owasp.esapi.reference.Log4JLogger cannot be cast to org.owasp.esapi.Logger
09:35:47,383 ERROR [stderr] (default task-12)   at org.owasp.esapi.reference.Log4JLogFactory.getLogger(Log4JLogFactory.java:88)
09:35:47,383 ERROR [stderr] (default task-12)   at org.owasp.esapi.ESAPI.getLogger(ESAPI.java:154)
09:35:47,383 ERROR [stderr] (default task-12)   at org.owasp.esapi.reference.DefaultEncoder.<init>(DefaultEncoder.java:75)
09:35:47,383 ERROR [stderr] (default task-12)   at org.owasp.esapi.reference.DefaultEncoder.getInstance(DefaultEncoder.java:59)
09:35:47,383 ERROR [stderr] (default task-12)   ... 116 more

This error will not show up when starting / restarting WildFly, but if I start/stop or redeploy the application, this error is generated.

Right now I am testing a single WAR file, that includes a JAR (in its WEB-INF/lib) directory that calls the ESAPI library. Below is the code being executed from the JAR:

public String html(String html) {
    String sEncodedText = null;
    if (input != null) {
        sEncodedText = ESAPI.encoder().encodeForHTML(html);
    }
    return sEncodedText;
}

My project is being built using maven, and I have tried it without the log4j and with the log4j dependency being included via the scope tag. Netiher solves this problem. The ESAPI library is being loaded as a transitive dependency from the supporting JAR file.

I found the exact problem described here, but there was not resolution on the chain. I have checked class loading and there doesn't appear to be any other log4j instances being loaded. Right now I only have this single application in my test bed.

Including pom snippets for the JAR and WAR...

JAR:

<project    xmlns="http://maven.apache.org/POM/4.0.0"
            xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" 
            xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <groupId>foo.bar</groupId>
    <artifactId>esapi-utils</artifactId>
    <version>1.0-SNAPSHOT</version>
    <packaging>jar</packaging>

    <dependencies>
        <dependency>
            <groupId>org.owasp.esapi</groupId>
            <artifactId>esapi</artifactId>
            <version>2.0.1</version>
        </dependency>
    </dependencies>
</project>

WAR:

<project    xmlns="http://maven.apache.org/POM/4.0.0"
            xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
            xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>  
    <groupId>foo.bar</groupId> 
    <artifactId>esapi-webapp</artifactId>
    <version>1.0.0-SNAPSHOT</version>
    <packaging>war</packaging>

    <build>
        <plugins>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-compiler-plugin</artifactId>
                <version>2.1</version>
            </plugin>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-war-plugin</artifactId>
                <version>2.6</version>
            </plugin>
        </plugins>
    </build>

    <dependencies>
        <!-- Could this be causing Class-Loading issues? -->
        <dependency>
            <groupId>org.owasp</groupId>
            <artifactId>csrfguard</artifactId>
            <version>3.0.0</version>
            <scope>runtime</scope>
        </dependency>
        <dependency>
            <groupId>log4j</groupId>
            <artifactId>log4j</artifactId>
            <version>1.2.17</version>
            <scope>provided</scope>
        </dependency>
        <!-- Other libraries omitted -->
        <dependency>
            <groupId>foo.bar</groupId>
            <artifactId>esapi-utils</artifactId>
            <version>1.0-SNAPSHOT</version>
        </dependency>
    </dependencies>
</project>

And here is the complete mvn dependecy:tree output

[INFO] foo.bar:esapi-webapp:war:1.0.0-SNAPSHOT
[INFO] +- org.owasp:csrfguard:jar:3.0.0:runtime
[INFO] +- javax.servlet:servlet-api:jar:2.5:provided
[INFO] +- junit:junit:jar:4.12:test
[INFO] |  \- org.hamcrest:hamcrest-core:jar:1.3:test
[INFO] +- org.mockito:mockito-core:jar:1.10.19:test
[INFO] |  \- org.objenesis:objenesis:jar:2.1:test
[INFO] +- org.hamcrest:hamcrest-library:jar:1.3:test
[INFO] +- commons-io:commons-io:jar:1.4:compile
[INFO] +- javax.mail:mail:jar:1.4.3:compile
[INFO] |  \- javax.activation:activation:jar:1.1:compile
[INFO] +- log4j:log4j:jar:1.2.17:provided
[INFO] +- org.apache.velocity:velocity:jar:1.6:compile
[INFO] |  +- commons-collections:commons-collections:jar:3.2.1:compile
[INFO] |  +- commons-lang:commons-lang:jar:2.4:compile
[INFO] |  \- oro:oro:jar:2.0.8:compile
[INFO] +- org.apache.velocity:velocity-tools:jar:2.0:compile
[INFO] |  +- commons-beanutils:commons-beanutils:jar:1.7.0:compile
[INFO] |  +- commons-digester:commons-digester:jar:1.8:compile
[INFO] |  +- commons-chain:commons-chain:jar:1.1:compile
[INFO] |  +- commons-logging:commons-logging:jar:1.1:compile
[INFO] |  +- commons-validator:commons-validator:jar:1.3.1:compile
[INFO] |  +- dom4j:dom4j:jar:1.1:compile
[INFO] |  +- sslext:sslext:jar:1.2-0:compile
[INFO] |  +- org.apache.struts:struts-core:jar:1.3.8:compile
[INFO] |  |  \- antlr:antlr:jar:2.7.2:compile
[INFO] |  +- org.apache.struts:struts-taglib:jar:1.3.8:compile
[INFO] |  \- org.apache.struts:struts-tiles:jar:1.3.8:compile
[INFO] +- org.mybatis:mybatis-spring:jar:1.1.1:compile
[INFO] |  +- org.mybatis:mybatis:jar:3.1.1:compile
[INFO] |  +- org.springframework:spring-tx:jar:3.1.1.RELEASE:compile
[INFO] |  \- org.springframework:spring-jdbc:jar:3.1.1.RELEASE:compile
[INFO] +- org.springframework:spring-context:jar:3.2.13.RELEASE:compile
[INFO] |  +- org.springframework:spring-aop:jar:3.2.13.RELEASE:compile
[INFO] |  +- org.springframework:spring-beans:jar:3.2.13.RELEASE:compile
[INFO] |  +- org.springframework:spring-core:jar:3.2.13.RELEASE:compile
[INFO] |  \- org.springframework:spring-expression:jar:3.2.13.RELEASE:compile
[INFO] +- org.springframework:spring-test:jar:3.2.13.RELEASE:test
[INFO] +- org.springframework:spring-web:jar:3.2.13.RELEASE:compile
[INFO] +- org.springframework:spring-webmvc:jar:3.2.13.RELEASE:compile
[INFO] +- org.springframework:spring-context-support:jar:3.2.13.RELEASE:compile
[INFO] +- org.springframework.security:spring-security-web:jar:3.2.6.RELEASE:compile
[INFO] |  +- aopalliance:aopalliance:jar:1.0:compile
[INFO] |  \- org.springframework.security:spring-security-core:jar:3.2.6.RELEASE:compile
[INFO] +- org.springframework.security:spring-security-config:jar:3.2.6.RELEASE:compile
[INFO] +- foo.bar:esapi-util:jar:1.0-SNAPSHOT:compile
[INFO] |  +- jboss:jboss-common-jdbc-wrapper:jar:3.2.3:compile
[INFO] |  +- commons-codec:commons-codec:jar:1.4:compile
[INFO] |  \- org.owasp.esapi:esapi:jar:2.0.1:compile
[INFO] |     +- commons-configuration:commons-configuration:jar:1.5:compile
[INFO] |     +- commons-beanutils:commons-beanutils-core:jar:1.7.0:compile
[INFO] |     +- commons-fileupload:commons-fileupload:jar:1.2:compile
[INFO] |     +- xom:xom:jar:1.1:compile
[INFO] |     |  +- xerces:xmlParserAPIs:jar:2.6.2:compile
[INFO] |     |  +- xerces:xercesImpl:jar:2.6.2:compile
[INFO] |     |  +- xalan:xalan:jar:2.7.0:compile
[INFO] |     |  \- jaxen:jaxen:jar:1.1-beta-8:compile
[INFO] |     |     \- jdom:jdom:jar:1.0:compile
[INFO] |     +- org.beanshell:bsh-core:jar:2.0b4:compile
[INFO] |     \- org.owasp.antisamy:antisamy:jar:1.4.3:compile
[INFO] |        +- org.apache.xmlgraphics:batik-css:jar:1.7:compile
[INFO] |        +- net.sourceforge.nekohtml:nekohtml:jar:1.9.12:compile
[INFO] |        \- commons-httpclient:commons-httpclient:jar:3.1:compile
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 2.046 s
[INFO] Finished at: 2015-04-22T12:54:26-04:00
[INFO] Final Memory: 10M/25M
[INFO] ------------------------------------------------------------------------

Answer

Ryan S picture Ryan S · Apr 22, 2015

After fighting with this for two days, I think I have finally figured out the answer. A quick thanks to everyone who was providing some suggestions that eventually got us to the right place. I 100% want to post this answer for anyone who might come across this really strange and hard to track down issue in the future.

The TL;DR, is that WildFly only creates a new log4j module if it can find log4j.properties or log4j.xml on the classpath for the application. This process was during a migration from jboss 4 to WildFly, and the server was mis-configured and the configuration could not be found (no errors are reported, however, because WildFly just uses its own default configured in standalone.xml).

Basically, had to make sure the log4j.xml was on the classpath for the application, so that WildFly would create a new log4j module to use. Once this was done ESAPI worked as expected in the application.

EDIT : Further messing around with this found another solution (for those of you wanting to use the logging subsystem in wildfly and not have to provide separate log4j.properties. Adding the following line to the logging subsystem:

<subsystem xmlns="urn:jboss:domain:logging:2.0">
    <use-deployment-logging-config value="false"/>
    <!-- Logging Configuration Here -->
</subsystem>

Will also force classloading to behave properly without needing to explicitly provide a logging configuration file for log4j.