Enterprise Java Development@TOPIC@
In this chapter we will refine the use of print and debug statements by using a "logger". By adopting a logger into your production and test code you can avoid print statements to stdout/stderr and be able to re-direct them to log files, databases, messaging topics etc. There are several to choose from (Java's built-in logger, Commons logging API, SLF's logging API, and log4j to name a few). This course uses the SLF API and and the log4j implementation.
Change the System.out() calls in App and AppTest from Part A to use SLF logging API. The slf4j-api Javadoc and manual will be helpful in understanding this interface.
package myorg.mypackage.ex1;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class App {
private static Logger logger = LoggerFactory.getLogger(App.class);
public int returnOne() {
//System.out.println( "Here's One!" );
logger.debug( "Here's One!" );
return 1;
}
public static void main( String[] args ) {
//System.out.println( "Hello World!" );
logger.info( "Hello World!" );
}
}
package myorg.mypackage.ex1;
...
import static org.junit.Assert.*;
import org.junit.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class AppTest {
private static Logger logger = LoggerFactory.getLogger(AppTest.class);
...
@Test
public void testApp() {
//System.out.println("testApp");
logger.info("testApp");
App app = new App();
assertTrue("app didn't return 1", app.returnOne() == 1);
}
}
Add a log4j.xml configuration file to the directory structure. Place this file in src/test/resources/log4j.xml. This file is used to control logging output. Refer to the log4j manual for possible information on how to configure and use log4j. It doesn't matter whether you use a log4j.xml format or log4j.properties format. Of note, the implementation we are using is based on "Log4j 1" -- which reached its end of life in 2015. It still works but all energy in this area is within "Log4j 2".
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration
xmlns:log4j="http://jakarta.apache.org/log4j/"
debug="false">
<appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">
<param name="Target" value="System.out"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern"
value="%-5p %d{dd-MM HH:mm:ss,SSS} (%F:%M:%L) -%m%n"/>
</layout>
</appender>
<appender name="logfile" class="org.apache.log4j.RollingFileAppender">
<param name="File" value="target/log4j-out.txt"/>
<param name="Append" value="false"/>
<param name="MaxFileSize" value="100KB"/>
<param name="MaxBackupIndex" value="1"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern"
value="%-5p %d{dd-MM HH:mm:ss,SSS} [%c] (%F:%M:%L) -%m%n"/>
</layout>
</appender>
<logger name="myorg.mypackage">
<level value="debug"/>
<appender-ref ref="logfile"/>
</logger>
<root>
<priority value="info"/>
<appender-ref ref="CONSOLE"/>
</root>
</log4j:configuration>
The log4j.xml is placed in the JVM classpath; where log4j will locate it by default. However, it should not be placed in with the main classes (ex1.jar). Placing it in a our JAR file would polute the application assembler and deployer's job of specifying the correct configuration file at runtime. Our test classes and resources are not a part of follow-on deployment.
Add the slf4j-api.jar to the compile classpaths and the slf4j-api.jar, slf4j-log4j.jar, and log4j.jar to the runtime classpath used during tests. Also add an additional task to copy the log4j.xml file into target/test-classes so that it is seen by the classloader as a resource. Realize that your classes have no compilation dependencies on log4j. Log4j is only used if it is located at runtime.
# ex1 build.properties junit.classpath=${M2_REPO}/junit/junit/4.12/junit-4.12.jar:\ ${M2_REPO}/org/hamcrest/hamcrest-core/1.3/hamcrest-core-1.3.jar slf4j-api.classpath=${M2_REPO}/org/slf4j/slf4j-api/1.7.25/slf4j-api-1.7.25.jar slf4j-log4j.classpath=${M2_REPO}/org/slf4j/slf4j-log4j12/1.7.25/slf4j-log4j12-1.7.25.jar log4j.classpath=${M2_REPO}/log4j/log4j/1.2.17/log4j-1.2.17.jar
<target name="echo">
...
<echo>slf4j-api.classpath=${slf4j-api.classpath}</echo>
<echo>slf4j-log4j.classpath=${slf4j-log4j.classpath}</echo>
<echo>log4j.classpath=${log4j.classpath}</echo>
</target>
<javac srcdir="${src.dir}/main/java"
destdir="${build.dir}/classes"
debug="true"
source="1.8"
target="1.8"
includeantruntime="false">
<classpath>
<pathelement path="${slf4j-api.classpath}"/>
</classpath>
</javac>
<javac srcdir="${src.dir}/test/java"
destdir="${build.dir}/test-classes"
debug="true"
source="1.8"
target="1.8"
includeantruntime="false">
<classpath>
<pathelement location="${build.dir}/${artifactId}.jar"/>
<pathelement path="${junit.classpath}"/>
<pathelement path="${slf4j-api.classpath}"/>
</classpath>
</javac>
<copy todir="${build.dir}/test-classes">
<fileset dir="${src.dir}/test/resources"/>
</copy>
<junit printsummary="true" fork="true">
<classpath>
<pathelement path="${junit.classpath}"/>
<pathelement location="${build.dir}/${artifactId}.jar"/>
<pathelement location="${build.dir}/test-classes"/>
<pathelement path="${commons-logging.classpath}"/>
<pathelement path="${log4j.classpath}"/>
</classpath>
...
Test application and inspect reports. All loggers inherit from the root logger and may only extend its definition; not limit it. Notice that the root logger's priority filter "info" value allows log.info() (warning and fatal) messages to printed to the console. The myorg.mypackage logger's level filter allows log.debug() messages from the myorg.mypackage.* classes to appear in both the console and logfile. This means that any Java classes not in our package hierarchy will only have INFO or higher priority messages logged.
$ ant clean test Buildfile: /home/jcstaff/proj/784/exercises/ex1/build.xml clean: [delete] Deleting directory /home/jcstaff/proj/784/exercises/ex1/target package: [mkdir] Created dir: /home/jcstaff/proj/784/exercises/ex1/target/classes [javac] Compiling 1 source file to /home/jcstaff/proj/784/exercises/ex1/target/classes [jar] Building jar: /home/jcstaff/proj/784/exercises/ex1/target/ex1.jar test: [mkdir] Created dir: /home/jcstaff/proj/784/exercises/ex1/target/test-classes [javac] Compiling 1 source file to /home/jcstaff/proj/784/exercises/ex1/target/test-classes [copy] Copying 1 file to /home/jcstaff/proj/784/exercises/ex1/target/test-classes [mkdir] Created dir: /home/jcstaff/proj/784/exercises/ex1/target/test-reports [junit] Running myorg.mypackage.ex1.AppTest [junit] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 15.127 sec BUILD SUCCESSFUL Total time: 17 seconds
You won't see the output come to stdout when using Ant, but you can locate all output in the FILE logger output defined to be in target/log4j-out.txt. This behavior will get a little better under Maven.
$ more target/log4j-out.txt INFO 13-08 18:24:21,983 [myorg.mypackage.ex1.AppTest] (AppTest.java:testApp:18) -testApp DEBUG 13-08 18:24:21,986 [myorg.mypackage.ex1.App] (App.java:returnOne:11) -Here's One!
Your project structure should look like the following at this point.
> find . -type f ./src/main/java/myorg/mypackage/ex1/App.java ./src/test/java/myorg/mypackage/ex1/AppTest.java ./src/test/resources/log4j.xml ./build.properties ./build.xml ./target/classes/myorg/mypackage/ex1/App.class ./target/ex1.jar ./target/test-classes/myorg/mypackage/ex1/AppTest.class ./target/test-classes/log4j.xml ./target/test-reports/TEST-myorg.mypackage.ex1.AppTest.txt ./target/test-reports/TEST-myorg.mypackage.ex1.AppTest.xml ./target/log4j-out.txt
Change the logging level so that only the App class performs logs to the logfile. By extending the logger name specification all the way to the class, we further limit which classes apply to this logger.
<logger name="myorg.mypackage.ex1.App">
<level value="debug"/>
<appender-ref ref="logfile"/>
</logger>
After re-running the build you should notice the DEBUG for only the App is included because of the change we made to the logger outside the code.
$ more target/log4j-out.txt DEBUG 26-08 23:07:04,809 [myorg.mypackage.ex1.App] (App.java:returnOne:11) -Here's One!
Repeat after me. "I will never use System.out.println() in this class." Doing so will make it difficult for your deployed components to have their logs controlled and accessible as it is instantiated in unit testing, integration testing, and deployment environments.
In this chapter we added some sophistication to the production class and its unit test which required additional compile-time and runtime resources. Please note that we added only a dependency on slf4j-api to the javac compiler task because log4j was never directly referenced in the source code. We added a runtime dependency on log4j (and the slf4j-log4j adapter) in order to configure a logger implementation during the execution of tests. The distinction of resources required for compile-time, test, and runtime required will become even more important when using Maven. Use the explicit classpaths we created here to help you understand Maven dependency scope when we get there.