Skinny War and Log4j Related Logging Issue

Recently, I packaged my web modules in EAR in skinny war fashion. With this skinny war, I managed to get the size of the EAR down to around 75 MB from 120 MB without skinny war, which is really cool. But this skinny war becomes nightmare, when I started observing log merging issue into different web application's log files at run time. I have noted down the same issue and its possible solutions in this post. If you have applied skinny war in your web modules and you are also the victim of this Log4j logging issue, I am sure you have got the right place to refer. Hope this post will help you out.

Issue: Logs are merged into single log file for different web modules which are packaged in EAR in Skinny War fashion.

I packaged all jars inside EAR/lib (including log4j.jar) so that all WAR refers to jar from this common location not from Web-INF/lib. This way there are no jars in WAR file and it refers to common location. When I deployed this EAR application, it loads the Log4j jar from EAR root (using parent first class loading policy) which is shared across all the wars. I could see application specific log files are created during server start up. But, while accessing application, logs are merged into single log file rather going to application specific log files. Below is the high level overview of EAR structure and Log4j configuration for separate web applications.

EAR Packaging Structure

 |-- META-INF

 |   `-- application.xml

 |-- lib

 |    -- jar1

 |    -- mydao.jar

 |    -- mysevice.jar

 |    -- log4j.jar

 |-- App1-1.0.0.war

 |     -- /WEB-INF/classes/App1-log4j.xml         

 `-- App2-1.0.0.war

 |     -- /WEB-INF/classes/App2-log4j.xml

Web.xml Configuration for different WARs

App1-1.0.0.war: web.xml

<context-param>

            <param-name>log4jExposeWebAppRoot</param-name>

            <param-value>false</param-value>

</context-param>

<context-param>

        <param-name>log4jConfigLocation</param-name>

        <param-value>/WEB-INF/classes/App1-log4j.xml</param-value>

</context-param>

<listener>

        <listener-class>org.springframework.web.util.Log4jConfigListener</listener-class>

</listener>

App2-1.0.0.war: web.xml:                   

<context-param>

   <param-name>log4jExposeWebAppRoot</param-name>

   <param-value>false</param-value>

</context-param>

<context-param>

    <param-name>log4jConfigLocation</param-name>

    <param-value>/WEB-INF/classes/App2-log4j.xml</param-value>

</context-param>

<listener>

      <listener-class>org.springframework.web.util.Log4jConfigListener</listener-class>

</listener>

Solution:

After digging into deep to analyze this issue, I observed Logger.getLogger() returns the logger associated to the web application which is loaded at last. That means, even though I have separate log files created specific to war, but while initializing EAR it overrides logging configuration with log4j.xml of web application which is loaded at last. That is the reason all WAR logs are written in one of the application’s log file.

To overcome this problem, I created custom Repository Selector on top of Log4j’s Repository Selector. With this custom repository selector, you can change the way how the LogManager gets a logger. You can implement this repository selector in a manner such that each context class loader has its own configuration set up with its own log4j.xml file. Using this approach, Logger.getLogger() will return a different logger based on the context class loader. You can refer these links (link1, link2) to get more detail on how you can implement your custom repository selector. With this change, I could see issue is resolved for all the classes which are packaged at web module level but not for all the classes/jars which are packaged at EAR level and shared across the web modules. So till now issue was not resolved fully. 

To resolve it fully, I started searching on net and reached to this link. Then I realized, I should check all the Logger variables in the classes which are packaged in JAR at EAR level. I found, I had below code in my service classes to get the logger instance. This static logger was also the culprit that was causing the log merging issue for the common classes which are shared across the web modules.

public class  MyServiceImpl {       private static final Logger LOGGER = Logger.getLogger(MyServiceImpl.class);          private static final String CLASS_NAME = LOGGER.getName();       // Other code here }

I converted all static Loggers to class level instance variables. After making this change, I got log merging issue is resolved for all the classes whether those are at EAR or WAR level. 

Thanks to Repository Selector concept, that helped to solve this log merging issue across different applications. I also raised question on stack overflow for the same issue and posted my findings for other developer's references.