If we want to troubleshoot issues related to Hibernate, its important that we know exactly what’s going on inside Hibernate. The answer to this is to enable logging at hibernate level so we can see the executed SQL statements.
It will also help if you want to do some performance tuning.
Let’s begin with the setup.
Below are my setup details:
Dependencies
Add the following dependencies:
hibernate-corethe core hibernate librarymysql-connector-javafor database driverslf4j-apias hibernate uses Simple Logging Facade for Java as the logging mechanism.slf4j-log4j12for loggingjavassisthibernate uses this for Java bytecode manipulation
Hibernate depends on the abstract logging framework SLF4J so you can chose your own logging framework. If no binding is found on the class path, then SLF4J will default to a no-operation implementation. In our example, we will use Log4j as the binding.
Add Hibernate to Log4j Properties
You need to create a log4j.properties file and copy it to your classpath.
log4j.properties:
# Root logger option
log4j.rootLogger=INFO, console
log4j.logger.com.javarticles=INFO, console
# Direct log messages to console
log4j.appender.console=org.apache.log4j.ConsoleAppender
log4j.appender.console.Target=System.out
log4j.appender.console.layout=org.apache.log4j.PatternLayout
log4j.appender.console.layout.ConversionPattern=%d{HH:mm}| %p | %F %L | %m%n
# direct messages to file hibernate.log
log4j.logger.org.hibernate=DEBUG, hibernate
log4j.appender.hibernate=org.apache.log4j.RollingFileAppender
log4j.appender.hibernate.File=hibernate.log
log4j.appender.hibernate.layout=org.apache.log4j.PatternLayout
log4j.appender.hibernate.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %5p %c{1}:%L - %m%n
In the above log4j.properties, we are directing all hibernate specific messages to hibernate.log. The category used is the main package org.hibernate. If you are only interested in messages only a some specific hibernate category then you need configure for that specific category.
Here are some of the important categories:
- org.hibernate.SQL – To Log all SQL DML statements as they are executed
org.hibernate.type– To Log all JDBC parametersorg.hibernate.transaction– To Log transaction related activityorg.hibernate.jdbc– To Log all JDBC resource acquisitionorg.hibernate.tool.hbm2ddl– To Log all SQL DDL statements as they are executedorg.hibernate– To Log all hibernate messages
Logger setting for category org.hibernate.SQL will log the SQL statements. Instead of that, there is a simpler way to view the SQL statements. Simply set show_sql to true.
Let’s now test to see whether logger is enabled.
Hibernate Logging Example
Create an entity bean.
Order:
package com.javarticles.hibernate;
import java.util.Date;
public class Order {
private Long orderId;
private String orderNbr;
private Date orderDate;
private String orderDesc;
private Long orderQty;
public Order() {
}
public Order(String orderNbr) {
this.orderNbr = orderNbr;
}
public Long getOrderId() {
return orderId;
}
private void setOrderId(Long orderId) {
this.orderId = orderId;
}
public Date getOrderDate() {
return orderDate;
}
public void setOrderDate(Date orderDate) {
this.orderDate = orderDate;
}
public String getOrderDesc() {
return orderDesc;
}
public void setOrderDesc(String orderDesc) {
this.orderDesc = orderDesc;
}
public Long getOrderQty() {
return orderQty;
}
public void setOrderQty(Long orderQty) {
this.orderQty = orderQty;
}
public String toString() {
return "Order: nbr[" + orderNbr + "] date [" + orderDate + "] desc["
+ orderDesc + "] qty[" + orderQty + "]";
}
}
The ORM file.
orders.hbm.xml:
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN" "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd"> <hibernate-mapping package="com.javarticles.hibernate"> <class name="com.javarticles.hibernate.Order" table="orders"> <id name="orderId" column="order_id"> <generator class="native" /> </id> <property name="orderNbr" column="order_nbr" type="string" length="30" access="field"/> <property name="orderDesc" column="order_desc" type="string" length="60" /> <property name="orderDate" type="timestamp" column="order_date"/> <property name="orderQty" column="qty" type="long" /> </class> </hibernate-mapping>
We do some delete, insert or query operations.
HibernateLoggingExample:
package com.javarticles.hibernate;
import java.io.IOException;
import java.util.Date;
import java.util.List;
import org.hibernate.MappingException;
import org.hibernate.Query;
import org.hibernate.Session;
import org.hibernate.SessionFactory;
import org.hibernate.Transaction;
import org.hibernate.cfg.Configuration;
public class HibernateLoggingExample {
public static void main(String[] args) throws MappingException, IOException {
Configuration configuration = new Configuration().configure();
SessionFactory sessionFactory = configuration.buildSessionFactory();
Session session = sessionFactory.getCurrentSession();
Transaction tx = session.getTransaction();
tx.begin();
Query query = session.createQuery("from Order where orderNbr='ORD01'");
List list = query.list();
System.out.println("Orders found: " + list.size());
for(Order order: list) {
session.delete(order);
System.out.println("Deleted " + order);
}
tx.commit();
session = sessionFactory.getCurrentSession();
tx = session.getTransaction();
tx.begin();
Order order = new Order("ORD01");
order.setOrderDesc("Laptop");
order.setOrderQty(2L);
order.setOrderDate(new Date());
session.save(order);
tx.commit();
session = sessionFactory.getCurrentSession();
tx = session.getTransaction();
tx.begin();
query = session.createQuery("from Order where orderNbr='ORD01'");
System.out.println("List all orders: " + query.list());
tx.commit();
sessionFactory.close();
}
}
There is lot of output from hibernate, I have pasted some of it here.
Output:
19:14| DEBUG | IntegratorServiceImpl.java 46 | Adding Integrator [org.hibernate.cfg.beanvalidation.BeanValidationIntegrator]. 19:14| DEBUG | IntegratorServiceImpl.java 46 | Adding Integrator [org.hibernate.secure.spi.JaccIntegrator]. 19:14| DEBUG | IntegratorServiceImpl.java 46 | Adding Integrator [org.hibernate.cache.internal.CollectionCacheInvalidator]. ... 19:14| DEBUG | LocalXmlResourceResolver.java 74 | Recognized legacy hibernate-mapping identifier; attempting to resolve on classpath under org/hibernate/ 19:14| DEBUG | MappingBinder.java 53 | Performing JAXB binding of hbm.xml document : Origin(name=orders.hbm.xml,type=RESOURCE) 19:14| DEBUG | BasicTypeRegistry.java 130 | Adding type registration boolean -> [email protected] 19:14| DEBUG | BasicTypeRegistry.java 130 | Adding type registration boolean -> [email protected] 19:14| DEBUG | BasicTypeRegistry.java 130 | Adding type registration java.lang.Boolean -> [email protected] ... 19:14| DEBUG | ErrorCounter.java 95 | throwQueryException() : no errors 19:14| DEBUG | QueryTranslatorImpl.java 246 | HQL: from com.javarticles.hibernate.Order where orderNbr='ORD01' 19:14| DEBUG | QueryTranslatorImpl.java 247 | SQL: select order0_.order_id as order_id1_0_, order0_.order_nbr as order_nb2_0_, order0_.order_desc as order_de3_0_, order0_.order_date as order_da4_0_, order0_.qty as qty5_0_ from orders order0_ where order0_.order_nbr='ORD01' 19:14| DEBUG | ErrorCounter.java 95 | throwQueryException() : no errors ... 19:14| DEBUG | SqlStatementLogger.java 92 | delete from orders where order_id=? Hibernate: delete from orders where order_id=? ... 19:14| DEBUG | SqlStatementLogger.java 92 | insert into orders (order_nbr, order_desc, order_date, qty) values (?, ?, ?, ?) Hibernate: insert into orders (order_nbr, order_desc, order_date, qty) values (?, ?, ?, ?)
Download the source code
This was an example about enabling logging in hibernate.
You can download the source code here: hibernateLoggingExample.zip
