Tutorial: logging during tests

Logging is a popular solution to show what the software is doing while it is running.

But what happens to the logging when we are unit testing our application with jUnit/TestNG ?

During the automated tests execution, we are usually not interested to see the logging messages because our main interest is the test results.

It would be nice to be able to disable logging messages during standard automated tests.

On the contrary, there are some cases where logging messages can be useful at test time. A typical example is when we are coding missing tests for some legacy code we do not want to touch before having a good test coverage in place. In this case logging messages on the console can help us to understand the code and how it works.

So we can identify three use cases:

  1. Running mode, when the application is executed: the logging is enabled and configured as required by the application
  2. Test execution mode, when the automated tests are executed all together: the logging messages should be disabled

  3. Test creation mode, when we are creating new tests: the logging messages are useful but it would be nice to have them in the console

Let see an example based on Maven and SLF4J, the popular logging facade.

Complete project can be found here.

Typical SLF4J configuration in the project pom.xml is the following:

        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>${slf4j.version}</version>
        </dependency>
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-log4j12</artifactId>
            <version>${slf4j.version}</version>
            <scope>runtime</scope>
        </dependency>

the slf4-api dependency is the main SLF4J library while the second one, slf4j-log4j12, is referencing one of the possible logging engines (LOG4J) that can work below the SLF4J.

This is the running mode configuration. In this example, the project resources will contain a LOG4J properties file which dictates what, how and where LOG4J should log.

The same situation happens when we are using a different logging engine like java.util.logging (JDK) and Logback. See Slf4J manual for more details.

In the Test execution mode we do not want logging so we can simply add the following scope test dependency

        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-nop</artifactId>
            <version>${slf4j.version}</version>
            <scope>test</scope>
        </dependency>

The NOP Logger (slf4j-nop) simply discards all logging.

Important: the dependencies order in the pom.xml is significant. Put the slf4j-nop dependency just after the slf4-apidependency so it will be used during the tests even if there is another logging engine in the dependency.

When there are multiple logging engines dependencies in the pom.xml, SLF4J will show anyway a message like the following:

    SLF4J: Class path contains multiple SLF4J bindings.
    SLF4J: Found binding in [jar:file:.m2/repository/org/slf4j/slf4j-nop/1.7.12/slf4j-nop-1.7.12.jar!/org/slf4j/impl/StaticLoggerBinder.class]
    SLF4J: Found binding in [jar:file:.m2/repository/org/slf4j/slf4j-log4j12/1.7.12/slf4j-log4j12-1.7.12.jar!/org/slf4j/impl/StaticLoggerBinder.class]
    SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
    SLF4J: Actual binding is of type [org.slf4j.helpers.NOPLoggerFactory]

To summarize, a complete configuration example is the following:

        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>${slf4j.version}</version>
        </dependency>
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-nop</artifactId>
            <version>${slf4j.version}</version>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-log4j12</artifactId>
            <version>${slf4j.version}</version>
            <scope>runtime</scope>
        </dependency>

Again, the last dependency should be adjusted to match the desired logging engine.

As I mentioned before, logging can be useful when creating new tests. In this case (Test creation mode), we can temporarily replace the slf4j-nop with the slf4j-simple dependnecy which enables the SLF4J Simple logger.

The logging messages will now be shown in the console window during tests execution as System.err messages. No configuration file is needed.

By default, the Simple logger does not log DEBUG messages. Standard logging level is INFO.

You can customize the Simple logger behaviour using system variables documented here.

A smart way to define Simple logger configuration is using the [Surefire plugin configuration section] (http://maven.apache.org/surefire/maven-surefire-plugin/examples/system-properties.html):

    <build>
        <plugins>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-surefire-plugin</artifactId>
                <version>2.18.1</version>
                <configuration>
                    <systemPropertyVariables>
                        <org.slf4j.simpleLogger.defaultLogLevel>DEBUG</org.slf4j.simpleLogger.defaultLogLevel>
                        <org.slf4j.simpleLogger.showDateTime>true</org.slf4j.simpleLogger.showDateTime>
                    </systemPropertyVariables>
                </configuration>
            </plugin>
        </plugins>
    </build>

In the systemPropertyVariables section we can create tags with the Simple logger variable name. In the above example, DEBUG and timestamp logging are enabled.

October 2015 Java releases

Java 9 (next)

New Java version is under development. Preliminary JDK versions and information can be found at https://jdk9.java.net/

Java 9 general availability is planned for September 2016.

Java 8 (current)

Java 8 is the current Java version.

Java 8 JDK/JRE update 65/66 (8u65/8u66) has been released. In addition to several fixes, this release does include additional currencies (fund codes) support. Release 66 bug fixes set is bigger.

Complete release notes can be found here.

JDK 8 can be downloaded here.

Java 7 (end-of-life)

Java 7 79/80 is the last public release. Updates are available for Oracle commercial customers only.

JDK 7u80 can be downloaded from Java 7 Archive downloads.

Java 6 (end-of-life)

Java 6 45 is the last public release. Updates are available for Oracle commercial customers only.

JDK 6u45 can be downloaded from Java 6 Archive downloads.

NetBeans project groups

I’m involved on several projects and during my working day it can happen that I need to switch from one project to another.

In NetBeans I usually create a project group for each project, to keep them well separated.

From the Projects window select Project Groups.. menu option. The Manage Groups window allows you to select the project group you want to switch to or to create a new one.

But what is a project group ?

It can be a single project (any NetBeans recognized project types like ant, maven, …). If the project is hierarchical, NetBeans will also include all sub modules in the project group.

It can also be a directory with many different projects. Nice if you like to pack similar projects together (by customer, by type…).

Finally a project group can also be free: every project you will open after the project group creation will be automatically included in it.

If you do nothing, your are in a special None free project group.

Project groups are a nice feature but there is a weak point if we compare NetBeans with the other most popular IDEs: IDEA and Eclipse.

When NetBeans starts, the last used project group is opened again, with consequent project loading and scanning which is annoying if you wanted to work on a different project because you have to wait until complete project loading before switching to the desired project.

On the contrary Idea has a nice startup GUI which shows the list of the past projects in addition to the possibility to create or import a new one. Eclipse has less flexible but still efficient solution based on workspace selection. Both are before loading last opened projects so very fast.

The NetBeans solution is based on the following command line parameters:

  • --open-group NAME
    open a project group by name
  • --close-group
    close any open project group
  • --list-groups
    list available project groups

Invoking NetBeans with --open-group PROJ1 will force NetBeans to immediately close the last opened project group and open the specified one (PROJ1 in this example).

For each project, on Linux and OS-X you can create a dedicated invocation script while on Windows you can create a dedicated icon with a dedicated command line. Tricky but it works.

Another alternative (actually the one I prefer) is to add the `–close-group’ parameter to the netbeans_default_options parameter in the netbeans_home/etc/netbeans.conf file.

The `–close-group’ parameter force NetBeans to switch to the None project group. Once inside NetBeans you can open the project group you like.

For more inside about this feature, have a look at the Enhancement 168556.

NetBeans startup commands are documented here.

Java: how to check jar version at runtime

Class loading issues can happen in complex execution environments. Situation gets worst when there are different versions of the same library “loaded” and we are not sure which our application is picking up.

To help debugging this issue, we could check at runtime which version of the library is loaded with the our application.

A code like the following can help:

// Example using HTMLEmail from Apache Commons Email 
Class theClass = HtmlEmail.class;
 
// Find the path of the compiled class 
String classPath = theClass.getResource(theClass.getSimpleName() + ".class").toString(); 
System.out.println("Class: " + classPath); 

// Find the path of the lib which includes the class 
String libPath = classPath.substring(0, classPath.lastIndexOf("!")); 
System.out.println("Lib:   " + libPath); 

// Find the path of the file inside the lib jar 
String filePath = libPath + "!/META-INF/MANIFEST.MF"; 
System.out.println("File:  " + filePath); 

// We look at the manifest file, getting two attributes out of it 
Manifest manifest = new Manifest(new URL(filePath).openStream()); 
Attributes attr = manifest.getMainAttributes(); 
System.out.println("Manifest-Version: " + attr.getValue("Manifest-Version")); 
System.out.println("Implementation-Version: " + attr.getValue("Implementation-Version"));

The above code shows how to find jar file path and how to read the contents of a file (it is usually the Manifest) to read some info from it.

Tutorial: using FindBugs with Maven

FindBugs can be executed using Maven in two different modes: as stand-alone command or as part of the Maven site command.

These two modes require different settings in the project pom.xml but they are not incompatible to each other so we can use both of them.

info48
You can find complete Maven project here.

Stand-alone mode

Let’s start with the stand-alone mode which requires the following configuration in the pom.xml:

<build>
    <plugins>       
        <plugin>
            <groupId>org.codehaus.mojo</groupId>
            <artifactId>findbugs-maven-plugin</artifactId>
            <version>3.0.1</version>
        </plugin>
         ... other build plugins ....
    </plugins>
</build>

Please note that the FindBugs plugin definition is inside build – plugins section of the pom file.

Giving the following command:

mvn findbugs:findbugs

FindBugs is run against our project with the following log in the console output:

[INFO] --- findbugs-maven-plugin:3.0.1:findbugs (default-cli) @ CodeQualityGallery ---
[INFO] Fork Value is true
     [java] Warnings generated: 1
[INFO] Done FindBugs Analysis....

warning48
FindBugs analyze the compiled files (*.class). If the project is not compiled or just cleaned, FindBugs will report nothing, without error messages. So take care to build your project before running FindBugs.

A warnings number is reported on the console. Warnings are possible bugs found by the FindBugs detectors.

The warnings details are included in a report created in the file target/findbugsXml.xml which is in XML format and so not really readable.

A better way to examine the warnings is to use the FindBugs native GUI with the command:

mvn findbugs:gui

The FindBugs window shows the bugs on the left, the (read-only) code on the right and the bug explanation below.

FindBugs GUI

You can filter bugs for bug rank from the most critical (“scariest”) to trivial and even, saving project status, comparing project evolution (which means how may bugs has been eliminated/introduced after previous FindBugs check).

warning48All main IDEs (Eclipse, NetBeans, IntelliJ) FindBugs plugins show similar views and they can also let you modify the code so I don’t suggest to use FindBugs native GUI unless you have to create exclusion files (see below) which is easier with the native GUI: select a bug, filter it out and export bug filters.

 

Site mode

Maven site command is used to generate a project “site”, which is a collection of information on the project nicely reported in HTML pages. You can configure which information is included in the site report and, of course, you can add FindBugs analysis results.

Maven site requires a “reporting section” in the pom file.

<reporting>
    <plugins>       
        <plugin>
            <groupId>org.codehaus.mojo</groupId>
            <artifactId>findbugs-maven-plugin</artifactId>
            <version>3.0.1</version>
        </plugin>
         ... other site plugins ....
    </plugins>
</reporting>

Giving the following command (note: clean and install options are in to assure that project is compiled and all tests run):

mvn clean install site

on the console output we will see the following:

.....
[INFO] --- maven-site-plugin:3.3:site (default-site) @ CodeQualityGallery ---
[INFO] configuring report plugin org.apache.maven.plugins:maven-jxr-plugin:2.5
[INFO] configuring report plugin org.apache.maven.plugins:maven-project-info-reports-plugin:2.8
[INFO] configuring report plugin org.codehaus.mojo:findbugs-maven-plugin:3.0.1
[INFO] Fork Value is true
     [java] Warnings generated: 2
[INFO] Done FindBugs Analysis....
[INFO] configuring report plugin org.apache.maven.plugins:maven-pmd-plugin:3.4
[WARNING] No project URL defined - decoration links will not be relativized!
[INFO] Rendering site with org.apache.maven.skins:maven-default-skin:jar:1.0 skin.
[INFO] Skipped "Source Xref" report, file "xref/index.html" already exists for the English version.
[INFO] Generating "Source Xref" report    --- maven-jxr-plugin:2.5
[INFO] Generating "Dependency Convergence" report    --- maven-project-info-reports-plugin:2.8
[INFO] Generating "Dependency Information" report    --- maven-project-info-reports-plugin:2.8
[INFO] Generating "About" report    --- maven-project-info-reports-plugin:2.8
[INFO] Generating "Plugin Management" report    --- maven-project-info-reports-plugin:2.8
[INFO] Generating "Project Plugins" report    --- maven-project-info-reports-plugin:2.8
[INFO] Generating "Project Team" report    --- maven-project-info-reports-plugin:2.8
[INFO] Generating "Project Summary" report    --- maven-project-info-reports-plugin:2.8
[INFO] Generating "FindBugs" report    --- findbugs-maven-plugin:3.0.1
[INFO] Generating "PMD" report    --- maven-pmd-plugin:3.4
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
.....

The “site” is created in the target/site dir. Opening the file target/site/index.html with the browser, we will see something like the following:

2015-06-08bIn the Project Reports section you will find the FindBugs report like the following:

2015-06-08c   The report is interesting because it give us the complete picture of our project in the summary section but also the list of the files which have FindBugs detected issues with all details including the priority (i.e. how dangerous could be the problem).

Configuration options

Regardless the used mode, the FindBugs plugin can be configured to modify and tune its behaviour. All below configurations should be placed in the configuration section of the plugin:

<plugin>
    <groupId>org.codehaus.mojo</groupId>
    <artifactId>findbugs-maven-plugin</artifactId>
    <version>3.0.1</version>
    <configuration>
        .....put here
    </configuration>
</plugin>

warning48
Configurations in the build and reporting sections are independent so we can have two different settings in the two modes, stand-alone and site.

Best practice is to use a light and fast configuration on the standalone mode, in order to run quick checks during development and an high effort, production quality configuration for the site mode.

Let’s examine the most important configuration options:

DEBUG: With <debug>true</debug> option, FindBugs will show what is doing during analysis. Useful to fine tune or checks the settings.

EFFORT: with  <effort>Max</effort> we can increase the time FindBugs is allowed to use to analyze the code. More effort means more accurate analysis but, of course, FindBugs run slower.

EXTERNAL PLUGINS: FindBugs can be extended with additional detectors. See my post on the topic. The  <pluginList>plugin1[, plugin2…]</pluginList> configuration option list the plugins to be used. See the sample project for a real example.

EXCLUSIONS: If you need to disable a detector or to disable the analysis on same classes, an exclude list can be specified with the <excludeFilterFile> path_to_exclude_file </excludeFilterFile> option. File syntax is documented here. An easy way to create this file is by using the FindBugs GUI which has an export filter function. See the sample project for a real example.

 

FindBugs plugins

FindBugs is a key code quality tool for Java based projects.

It includes several dozens of bug patterns which are used by FindBugs to identify potential bugs and, more in general, weaknesses in our code.

FindBugs has a plugin architecture which can be used to extend the set of detectors (bug patterns) used during the analysis.

There are few open source projects which aim to develop FindBugs plugin.

My preferred one is Fb-Contrib which contains a significant amount of additional detectors. See here for the complete list. Most of them are really useful to detect poor code quality.

Another interesting plugin is Find Security Bugs; the focus here is on security vulnerabilities (list here) like using unsecured random generator or not checking data received from the user.

Let’s have a look at versions dependencies:

JDK FindBugs FB-Contrib Find Security Bugs
7 and 8 3.x 6.x 1.3 and above
5 and 6 2.x 5.x 1.2

All plugins are released in .jar format and they can be easily added to the FindBugs :

  • FindBugs stand-alone: place the jar in the plugins dir inside FindBugs installation dir
  • Eclipse FindBugs plugin: use the plugin options to specify the plugin path or place the jar file inside FindBugs plugins dir
  • NetBeans FindBugs integration: use Custom FindBugs Plugins button inside Editor → Hints → FindBugs page.
  • IntelliJ FindBugs plugin: add new plugin in the Plugin Configuration tab.

After adding new plugins, review the list of detectors enabled. New detectors are usually added but not enabled.

April 2015 Java releases

Java 9

New Java version is under development. Preliminary JDK versions and information can be found at https://jdk9.java.net/

Java 8

Java 8 is the current Java version.

Java 8 JDK/JRE update 45 has been released. This is mainly a bug fix release. No new functionalities have been introduced.

Complete bug fix list can be found at http://www.oracle.com/technetwork/java/javase/2col/8u45-bugfixes-2494164.html

JDK 8 can be downloaded from http://www.oracle.com/technetwork/java/javase/downloads/jdk8-downloads-2133151.html
Java 7

Java 7 79/80 is the last public release.

As happened for the latest realese, also latest Java 7 update is splitted in two releases:

  • Update 79 which includes critical security updates only
  • Update 80 which includes 79 updates plus a new command line option to detect deprecated mechanisms: endorsed-standards and extensions.

Endorsed-standards is a way to update Java core to the latest version of non Java standards. Extensions allows us to extend the Java core with new libraries and functionalities. Both mechanism have been declared deprecated and they will be phase-out in the next future. The option introduced in Java 7u80 detect if these mechanisms have been used i our environments.

Update 79 release notes can be found at http://www.oracle.com/technetwork/java/javase/7u79-relnotes-2494161.html

Update 80 release notes can be found at http://www.oracle.com/technetwork/java/javase/7u80-relnotes-2494162.html

JDK 7 can be downloaded from http://www.oracle.com/technetwork/java/javase/downloads/jdk7-downloads-1880260.html

Still using JAVA 6 and previous versions ? Have a look at  http://www.oracle.com/technetwork/java/javase/archive-139210.html