log4j2 creating but not logging to file and console appenders

[jannetta steyn]

I am using Idea as an IDE and I'm using log4j2 in my code. I also use maven to package my application. When I run the application in Idea the logging works perfectly and I don't get any errors.

When I package the application with maven into a jar with dependencies and run from the command line,  the application runs, log4j2 creates the log files files specified in the log4j2.properties file but it doesn't actually write anything to the file or to the console appenders.

For what it's worth, I have tested on both Linux and Windows in Idea as well as the Maven packaged version in the Linux terminal (openjdk 21.0.4), Git Bash terminal (Windows, java 17.0.11) and Cmd (java 17.0.11).

I don't know what I'm doing wrong but I also don't understand why it would work in the IDE if there is something wrong. This is my properties file:

property.basePath = DATA/outputs/
# Root logger option (log level 'debug' for LOGFILE and 'info' for STDOUT)
rootLogger=trace, STDOUT, LOGFILE, TRACEFILE

# Direct log messages to stdout (only 'info' and higher)
appender.console.name = STDOUT
appender.console.type = Console
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %d{yyyy-MM-dd HH:mm:ss} %-5p %c{1} - %m%n
appender.console.filter.threshold.type = ThresholdFilter
appender.console.filter.threshold.level = info

# Direct log messages to a file (only 'debug' and higher)
appender.file1.type = File
appender.file1.name = LOGFILE
appender.file1.fileName = ${basePath}/firm.log
appender.file1.layout.type = PatternLayout
appender.file1.layout.pattern = %msg%n
appender.file1.filter.threshold.type = ThresholdFilter
appender.file1.filter.threshold.level = debug

# Direct log messages to a file (only 'debug' and higher)
appender.file2.type = File
appender.file2.name = TRACEFILE
appender.file2.fileName = ${basePath}/TRACE.log
appender.file2.layout.type = PatternLayout
appender.file2.layout.pattern = %d{yyyy-MM-dd HH:mm:ss} %-5p %c{1} - %m%n
appender.file2.filter.threshold.type = ThresholdFilter
appender.file2.filter.threshold.level = trace

[Tim Holloway]

Probably 2 things.

First, you're defining a property named "property.basePath", but referencing a property named simply "basePath".

Secondly, the value of "property.basePath" is a relative path. That's risky. It's always better in Java to specify an absolute path.

[Ron McLeod]

Also, I think that rootLogger=trace, STDOUT, LOGFILE, TRACEFILE should actually be rootLogger.level = trace rootLogger.appenderRefs = STDOUT, LOGFILE, TRACEFILE rootLogger.appenderRef.stdout.ref = STDOUT rootLogger.appenderRef.logfile.ref = LOGFILE rootLogger.appenderRef.tracefile.ref = TRACEFILE

[jannetta steyn]

@Ron McLeod and @Tim Holloway, I updated my properties file as per your suggestions. Adding properties. in front of basepath breaks it completely. The log files don't even get created as before and also breaks it for Idea. Using the full path did not make a difference.

property.basePath = /Users/janne/IdeaProjects/F2_/DATA/outputs/
rootLogger.level = trace
rootLogger.appenderRefs = STDOUT, LOGFILE, TRACEFILE
rootLogger.appenderRef.stdout.ref = STDOUT
rootLogger.appenderRef.logfile.ref = LOGFILE
rootLogger.appenderRef.tracefile.ref = TRACEFILE
 
appender.console.name = STDOUT
appender.console.type = Console
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %d{yyyy-MM-dd HH:mm:ss} %-5p %c{1} - %m%n
appender.console.filter.threshold.type = ThresholdFilter
appender.console.filter.threshold.level = info

appender.file1.type = File
appender.file1.name = LOGFILE
appender.file1.fileName = ${property.basePath}/firm.log                        <--- DOING THIS BREAKS IT COMPLETELY
appender.file1.layout.type = PatternLayout
appender.file1.layout.pattern = %msg%n
appender.file1.filter.threshold.type = ThresholdFilter
appender.file1.filter.threshold.level = debug

appender.file2.type = File
appender.file2.name = TRACEFILE
appender.file2.fileName = ${property.basePath}/TRACE.log
appender.file2.layout.type = PatternLayout
appender.file2.layout.pattern = %d{yyyy-MM-dd HH:mm:ss} %-5p %c{1} - %m%n
appender.file2.filter.threshold.type = ThresholdFilter
appender.file2.filter.threshold.level = trace

[Tim Holloway]

Your top-level directory in basePath/property.basePath is "/Users". To me that smells like Microsoft Windows, since the "users" directory on Unix-like systems is named "/home".

In that case, your path is still not absolute, since it's relative to the drive you're logged into when basePath is referenced. Instead it should be in the form "C:/Users".

You might also find it useful to log to a directory that's external to your IntelliJ project directory. A production Unix/Linux system would typically log to /var/log/something (where "something" is your product). Windows hasn't got a standard log directory, since its own logging is done inside the event Manager, but you can create a log directory anywhere you have access rights.

[jannetta steyn]

I usually work on Linux. At the moment I'm on a mixture. My Linux file looks like this but still has the problem:

property.basePath = /home/jannetta/IdeaProjects/FIRM2/DATA/outputs/·
rootLogger.level = trace·
rootLogger.appenderRefs = STDOUT, LOGFILE, TRACEFILE·
rootLogger.appenderRef.stdout.ref = STDOUT·
rootLogger.appenderRef.logfile.ref = LOGFILE·
rootLogger.appenderRef.tracefile.ref = TRACEFILE·

[Tim Holloway]

Well, I can't really tell anything more. For one thing, I don't use the property file format for Log4J. I find the XML format easier to manage and I think it can handle some features that the property format can't.

But for what it's worth, here's a pared-down version of one of my log4j config files. It features rolling appenders, routing to multiple destinations and even a log to email.

<?xml version="1.0" encoding="UTF-8"?> <!DOCTYPE log4j:configuration SYSTEM "log4j.dtd"> <log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/"> <appender name="console" class="org.apache.log4j.ConsoleAppender"> <param name="Target" value="System.out"/> <layout class="org.apache.log4j.PatternLayout"> <param name="ConversionPattern" value="%d{DATE} %5p %c:%L - %m%n"/> </layout> </appender> <appender name="winemgmt" class="org.apache.log4j.DailyRollingFileAppender"> <param name="file" value="/WineMgmtSys/wms_dev/wms/logs/winemgmt.log"/> <param name="MaxBackupIndex" value="10"/> <rollingPolicy class="org.apache.log4j.rolling.TimeBasedRollingPolicy"> <!-- See: http://logging.apache.org/log4j/companions/extras/apidocs/org/apache/log4j/rolling/TimeBasedRollingPolicy.html --> <param name="FileNamePattern" value="/WineMgmtSys/wms_dev/wms/logs/winemgmt.log.%d.gz"/> </rollingPolicy> <layout class="org.apache.log4j.PatternLayout"> <param name="ConversionPattern" value="%d{ISO8601} %5p %c:%L - %m%n"/> </layout> </appender> <appender name="axis" class="org.apache.log4j.DailyRollingFileAppender"> <param name="file" value="/WineMgmtSys/wms_dev/wms/logs/axis.log"/> <param name="MaxBackupIndex" value="5"/> <rollingPolicy class="org.apache.log4j.rolling.TimeBasedRollingPolicy"> <param name="FileNamePattern" value="/WineMgmtSys/wms_dev/wms/logs/axis.log.%d.gz"/> </rollingPolicy> <layout class="org.apache.log4j.PatternLayout"> <param name="ConversionPattern" value="%d{ISO8601} %5p %c:%L - %m%n"/> </layout> </appender> <appender name="debug" class="org.apache.log4j.DailyRollingFileAppender"> <param name="file" value="/WineMgmtSys/wms_dev/wms/logs/debug.log"/> <param name="MaxBackupIndex" value="10"/> <rollingPolicy class="org.apache.log4j.rolling.TimeBasedRollingPolicy"> <param name="FileNamePattern" value="/WineMgmtSys/wms_dev/wms/logs/debug.log.%d.gz"/> </rollingPolicy> <layout class="org.apache.log4j.PatternLayout"> <param name="ConversionPattern" value="%d{ISO8601} %5p %c:%L - %m%n"/> </layout> </appender> <appender name="debug" class="org.apache.log4j.ConsoleAppender"> </appender> <appender name="AdministratorEmail" class="org.apache.log4j.net.SMTPAppender"> <param name="BufferSize" value="512"/> <param name="SMTPHost" value="www.winemgmtsys.com"/> <param name="From" value="[e-mail]"/> <param name="To" value="[e-mail]"/> <param name="Subject" value="WMS Error"/> <layout class="org.apache.log4j.PatternLayout"> <param name="ConversionPattern" value="[%d{ISO8601}]%n%n%-5p%n%n%c%n%n%m%n%n"/> </layout> <filter class="org.apache.log4j.varia.LevelRangeFilter"> <param name="LevelMin" value="error"/> <param name="LevelMax" value="fatal"/> </filter> </appender> <logger name="winemgmtsys"> <level value="INFO"/> <appender-ref ref="winemgmt"/> </logger> <logger name="org.hibernate" additivity="false"> <level value="WARN"/> <appender-ref ref="debug"/> <appender-ref ref="console"/> </logger>    <logger name="org.hibernate.SQL" additivity="false">        <level value="WARN"/>        <appender-ref ref="console"/>    </logger>    <logger name="org.hibernate.type" additivity="false"> <level value="WARN"/> <appender-ref ref="debug"/> <appender-ref ref="console"/> </logger>    <logger name="org.hibernate.cfg" additivity="false">        <level value="WARN"/>        <appender-ref ref="debug"/>        <appender-ref ref="winemgmt"/>        <appender-ref ref="console"/>    </logger>     <root> <level value="INFO"/> <appender-ref ref="winemgmt"/> <appender-ref ref="debug"/> <appender-ref ref="console"/> <appender-ref ref="AdministratorEmail"/> </root> </log4j:configuration>

[jannetta steyn]

What really puzzles me is the fact that the log files actually get created in the right place but then the logging itself to the console and the files just don't happen. Also, I tried copying the command line arguments from inside of Idea (I did this on both Linux and Windows) and then ran it from the terminal/Command Prompt. Doing this works perfectly. However, when I create a jar, either with Maven or as an artefact with Idea, the files are created but there is no log output - neither to file or console.

[Carey Brown]

I had a similar problem many moons ago and ran across this solution.

import org.apache.log4j.Logger;

public class Demo
{
	private static final Logger		log = Logger.getLogger( Demo.class );

    private static void main( String... args  )
    {
        Log4jConfigurator.configureLog4j();
        //...
    }
}

import java.io.FileInputStream;
import java.io.IOException;
import java.util.Properties;

import org.apache.log4j.PropertyConfigurator;

class Log4jConfigurator
{
	public static void configureLog4J()
	{
		try
		{
			Properties p = new Properties();
			p.load( new FileInputStream( /* "c:\\bin\\cmdline_app\\ */ "log4j.properties" ) );
			PropertyConfigurator.configure( p );
		}
		catch( IOException ioe )
		{
			System.err.println( "Couldn't configure Log4" );
			System.err.println( ioe.getMessage() );
		}
	}
}

[Tim Holloway]

jannetta steyn wrote:What really puzzles me is the fact that the log files actually get created in the right place but then the logging itself to the console and the files just don't happen. Also, I tried copying the command line arguments from inside of Idea (I did this on both Linux and Windows) and then ran it from the terminal/Command Prompt. Doing this works perfectly. However, when I create a jar, either with Maven or as an artefact with Idea, the files are created but there is no log output - neither to file or console.

When I use the external Tomcat plugin with Eclipse, it captures the stdout/stderr from the JVM running Tomcat and routes it to a console window in Ecliupse.

One thing to note: when running Tomcat from the command line, stdout/stderr is mostly routed to TOMCAT_HOME/logs/catalina.out*. Other webapp servers such as IBM WebSphere may do things differently. There is no standard from output from the webapp server JVM itself and webapps are entirely responsible for their own logging, so when you're logging to "console", it's wherever the webapp server decides the console is, not necessarily to the command shell output channels.

It has been a long age since I ran a webapp under IntelliJ, and I don't remember how it deals with consoles.

And I am talking webapps here. A stand-alone (non-web) Java app would output System.out/System.err to its containing shell's stdio channels, subject to command-line redirection.

* what isn't goes to the localhost log file.

[jannetta steyn]

Thanks for all your suggestions but I'm now giving up on using log4J. I don't want to complicate my application by having to use more frameworks and stuff. I actually just don't have the time to get my head around it all. It seems the way to do it would be to use one of the options here: https://logging.apache.org/log4j/2.x/faq.html#single-jar (if anyone else is interested in doing it).

[Tim Holloway]

OK, it sounds like you're trying to create an executable JAR.

When you tell Java to execute a JAR, the critical thing to remember is that the default classpath for that application is ONLY the JAR itself. If you build a JAR and put other JARS inside it, the contents of those JARS will NOT be part of the classpath. That's the "jar in jar" issue.

There are 2 ways to deal with that. One is to unpack all of the "included" JARs so that all their contents become ordinary class resources within the executable JAR. The other is to rig the app so that those JARs remain JARs within the executable JAR, but it expands its classpath to look inside those JARs as well. This is generally preferable.

To rig the classpath, you can either use brute-force classpath code, or, since you're using Maven, you can use the executable jar plugin in your POM, and that will add the required code in automatically.

Note that the log4.properties/log4j.xml file should go in the root of your JAR.

Incidentally, for large apps where you are using third-party libraries you may also need a logging aggregator (slf4j), since different libraries may use different logging systems.

As a purely educational note, mucking around with classpaths is how a webapp manages to get its WEB-INF/classes and WEB-INF/lib JARs into the webapp's classpath. And how it isolates the classpath of one webapp from other webapps in the same container