Logs separation by app not working when log4j2 libs are inside tomcat/lib

[cagliotto]

Hi,
I have multiple java web applications running under tomcat (9.0.85 is the exact version).
The logj4 libraries are inside tomcat/lib, not inside each project.
The log4j2.xml files are configured to separate logs between apps so to have dedicated folders.
Log4j2.xml is stored in the root classpath.

Originally, when I had the log4j libs in each project, everything was working smoothly.
By company policies we had to share common libraries so I had to place log4j libs inside tomcat/libs, as stated before.
After that, logs weren't separated correctly since I had all log events written inside the same file.
The first deployed app was the one storing all the logs:

APP1 is configured to store logs inside logs/APP1/app1.log
APP2 is configured to store logs inside logs/APP2/app2.log
APP3 is configured to store logs inside logs/APP3/app3.log

Since APP1 was the first one being deployed, only logs/APP1/app1.log was created and logs of other apps were written there too.

To overcome this problem I added this lines inside every web.xml:

<context-param>
        <param-name>log4jConfiguration</param-name>
        <param-value>/WEB-INF/classes/log4j2.xml</param-value>
</context-param>

Now the log events occurring inside each classpath are correctly separated but the logs related to external packages (example org.springrframework, org.primefaces, org.ibatis ecc. ecc.) are still only registered in the app1.log, mixing everything together.
I've also noticed something stranger; if I configure only one app to show me external packages logs, I see events of other apps too; I mean, if log4j2.xml of APP1 is configured to show me org.springframeworks events but APP2 and APP3 aren't, I still see events of APP2 and APP3.

Am I missing something? Is there a solution/workaround to have all logs separated correctly?
For the reason explained before, the solution shouldn't be to move back log4j libraries inside each app.

Configuration:

• Apache Tomcat 9.0.85
• log4j2 version: 2.23.0
• jars used: log4j-1.2-api, log4j-api, log4j-core, log4j-web
• Server: RockyLinux (versions 8 and 9)
• Java version: openjdk 17 provided by rocky

Thanks for your help.

[ppkarwasz]

Hi @cagliotto,

No, you are not missing anything.

The main problem with having a single deployment of log4j-core in Tomcat is that (most of the time) the default ClassLoaderContextSelector creates a new logger context for the current classloader only if no parent classloader has a logger context (cf. #2314). This corresponds to the initial situation you are describing (the logs of all apps go to the same file).

The only way to force ClassLoaderContextSelector to create a new logger context is to pass a non-null configLocation to one of the LogManager#getContext methods (cf. javadoc). This is exactly what log4j-web does in your second attempt.

Note that the behavior of ClassLoaderContextSelector is not totally absurd: Tomcat has multiple types of classloaders and IIRC JSP pages also create additional ones. You are probably interested only in:

• one logger context attached to the system or common classloader,
• one logger context per application (including JSPs).

In order to do that, you need to change context selector. I have written a small set of utilities for Log4j and Tomcat in copernik-eu/log4j-plugins. In the still unreleased 3.0.0 version there is an alternative context selector that might fill your needs.

Using Copernik.eu Log4j extensions

The new 3.0.0 version of my Log4j extensions will feature a new TomcatContextSelector in the log4j-tomcat-juli-core artifact with Maven coordinates:

<dependency>
    <groupId>eu.copernik</groupId>
    <artifactId>log4j-tomcat-juli-core</artifactId>
    <version>3.0.0-SNAPSHOT</version>
</dependency>

Currently you can download it from the OSSRH snapshot repository.

To use the selector:

• Put the log4j-tomcat-juli-core JAR in the $CATALINA_BASE/lib folder (or add it to the CLASSPATH variable in a setenv.sh file),
• Set the log4j2.contextSelector Java system property to eu.copernik.log4j.tomcat.juli.core.TomcatContextSelector (on the command line or catalina.properties).

The selector will select the logger context based on the thread context classloader and will create:

• a single global logger context named -tomcat. This means it can be configured using files named either log4j2-tomcat.xml or log4j2.xml in the classpath,
• a separate logger context per web application named using the /[enginename]/[hostname]/[appname] schema you are certainly familiar with. Therefore you can use configuration files like log4j2/Catalina/localhost/app1.xml or log4j2.xml.

If you choose to use a single configuration file for all contexts, you can profit from the TomcatLookup that is available in the same artifact. For example your configuration file could look like:

<Configuration>
    <Appenders>
        <File name="FILE"
              fileName="/var/log/tomcat/${tomcat:context.name}"/>
    </Appenders>
    <Loggers>
        <!-- Shorthand for org.apache.catalina.core.ContainerBase.[enginename].[hostname].[appname] -->
        <Logger name="${tomcat:context.logger}" level="DEBUG"/>
        <Root level="INFO">
           <AppenderRef ref="FILE"/>
        </Root>
    </Loggers>
</Configuration>

[ppkarwasz]

Remark: Regarding logs issued by org.springrframework, org.primefaces, org.ibatis in the common classloader, the situation will not necessarily improve. There are two ways to use loggers: they can be static or instance variable (cf. our short comparison). Depending on which kind of logger they use:

• libraries that use instance loggers will log every message into the correct logger context (see Tomcat's own AuthenticatorBase class for example),
• libraries that use static loggers will log every message into the first application that called them.

For the second kind there is a workaround:

• follow the instruction for Application Server integration to replace Tomcat JULI with Log4j Core (in this case the aforementioned log4j-tomcat-juli-core artifact need also to be added to the system and not common classloader),
• create a console appender that follows the changes in System.out:

  <Console name="FOLLOWING" follow="true"/>
  ...
  <Logger name="org.ibatis" additivity="false">
    <AppenderRef ref="FOLLOWING"/>
  </Logger>

• ask Tomcat to redirect System.out back to the logging system in context.xml,

  <Context swallowOutput="true"/>

• the content will exit the logging system again through a logger named org.apache.catalina.core.ContainerBase.[enginename].[hostname].[appname], so you can redirect it wherever you want (just not the console ;-) ).

[cagliotto]

Hi @ppkarwasz ,
thank you very much for you detailed explanation!

[ppkarwasz]

@cagliotto,

I'll be doing a beta release of my extensions one of these weekends. Would you be available to test them?

They have an extensive unit test coverage, but I am no longer using Tomcat in my dayjob, so I haven't tested a lot of deployments.

[cagliotto]

@ppkarwasz I'll see in the next weeks because this morning we had to close the monthly release so I didn't have time to try or apply what you suggested.
Based on the assignments I have during the next weeks, I'll know whether I have to deal with log4j again or not.
In the meantime, thank you again!