Thursday, October 22, 2015

Hibernate / JPA SQL and JDBC logging with log4jdbc

1. Motivation
It's very common the need of a better log for our parameterized queries. Instead of seeing

INSERT INTO stock_transaction (CHANGE, CLOSE, DATE, OPEN, STOCK_ID, VOLUME)
VALUES (?, ?, ?, ?, ?, ?)

we´d like to see

INSERT INTO stock_transaction (CHANGE, CLOSE, DATE, OPEN, STOCK_ID, VOLUME)
VALUES (10.1, 1.1, '30 December 2009', 1.2, 11, 1000000)

You can get a not so practical result if you set log appenders for Hibernate (you can see here how to configure it this way). The problem is that you can't just copy and paste the SQL statement right into your SQL worksheet. It takes a lot of work and time to do it.

Hibernate: INSERT INTO stock_transaction (CHANGE, CLOSE, DATE, OPEN, STOCK_ID, VOLUME) VALUES (?, ?, ?, ?, ?, ?)
13:33:07,253 DEBUG FloatType:133 - binding '10.0' to parameter: 1
13:33:07,253 DEBUG FloatType:133 - binding '1.1' to parameter: 2
13:33:07,253 DEBUG DateType:133 - binding '30 December 2009' to parameter: 3
13:33:07,269 DEBUG FloatType:133 - binding '1.2' to parameter: 4
13:33:07,269 DEBUG IntegerType:133 - binding '11' to parameter: 5
13:33:07,269 DEBUG LongType:133 - binding '1000000' to parameter: 6

I´m going to show in this post a working example of how to log SQL queries with parameters, and some other informations, in an application that uses Spring, Hibernate, JPA and logback.

2. History of log4jdbc
It all started with the original library log4jdbc (https://code.google.com/p/log4jdbc/). Then it was improved with the log4jdbc-remix (https://code.google.com/p/log4jdbc-remix/) and finally we have the log4jdbc-log4j2 (https://code.google.com/p/log4jdbc-log4j2/) that is the version of the library that we'll use in the example.

3. The sample application
The objective here is to have an working application that serves as an example of how to configure and use log4jdbc library in the code. With that in mind I chose an application that is build during a great PluralSight course: Spring with JPA and Hibernate.You can find this version in my GitHub repository.

    Fitness Tracker log example

4. Required software
In order to have this application working in your machine, here are some requirements:
  • JDK 7
  • Apache Tomcat 7
  • MySQL server running on default port 3306  / username: root / password: password
  • Maven 3
5. The good parts
I´ll show now what takes to have JDBC parameters logged, among other things. If you have git installed, you can use the command below to see the changes I made to the original application:

    git diff v1.0.0.0 v2.0.0.0

5.1 Two new dependencies were added to the project. One is logback and the other is the log4jdbc2

5.2 As the application uses Slf4j library, we need to configure the option log4jdbc.spylogdelegator.name to the value net.sf.log4jdbc.log.slf4j.Slf4jSpyLogDelegator. This is done by creating the file log4jdbc.log4j2.properties in the src/main/resources folder:

5.3 Now we can see the change in the data source reference in jpaContext.xml point to the log4jdbc data source wrapper.

5.4 And last, the logback with its appenders was configured.

The property SERVER_LOG_PATH may be redefined passing a new path in the server.logging.path VM property
    -Dserver.logging.path=/new/path/to/log

It was defined an appender to jdbc.sqlonly logger with additivity=false, which makes the messages be logged only in this appender. With one file per logger is easier to decide what log configuration to choose.

6. Installing and running the sample application

6.1 Start your MySQL server instance
6.2 Get the application from GitHub. From a shell where you want to have this application:

    git clone https://github.com/mroger/fitness-tracker-sql-log-example.git

6.3 Build the application

    mvn clean install

6.4 Copy the war file (FitnessTracker.war) from project's target folder  to the Tomcat's webapps folder
6.5 Start Tomcat if not already started
6.6 Access the application in the URL http://localhost:8080/FitnessTracker/index.jsp
6.6 Use the application, save some data and see how the queries are logged in the folder /var/log/fitnesstracker

8. Conclusion
Being able to copy and paste the exact query that was executed directly in a SQL tool can save a lot of time in finding performance bottlenecks or the source of errors. And log4jdbc library makes it easy to accomplish this.
Adding maven profiles to this, you can orchestrate your builds so each environment gets the correct configuration automatically.

Saturday, October 3, 2015

Cleaner java code with Lombok

Sometimes, to discover what a class does, you see yourself reading several lines of code. And much of these lines are constructors, getters, setters, toString, equals, hashcode, etc. They simply get on your way.

Wouldn´t be great if all those lines just weren´t there?

Lombok is a library that can help you with that. It's great helping you reduce tedious and boilerplate code.

Your class may go from this:

To this:

Lombok instruments the code for you. You can check the class´ methods that were automatically generated with the command:

javap Person.class

And this is how it looks like after the instrumentation made by Lombok:

If your class is a Value Object as described in Martin Fowler´s article, you can use more fine grained annotations as seen in the code below:


Another great feature is the @Builder feature. I recommend it to all who's going to try Lombok.

To use Lombok, you need to put its library in the classpath during the compile time and only during the compile time. At runtime, your class´ bytecode has already been changed.

If you use Maven, you can declare lombok as a provided dependency in your POM file like this:


The installation and a description of the basic functions can be found here. There is also a great video in the frontpage. All of these resources and references are very clear and simple to follow. You´ll be using Lombok in your project in no time.

Just a little warning for Sonar users: it does not like Lombok! It complains that the bytecode lacks getters, setters and such. To help with this, there is a command called delombok that I think that can help making Sonar happy.

Any comment about this post? Please drop a line! I´ll be glad to hear from you!