Monday, October 10, 2016

Hibernate show sql with parameter values

In this article i will show you "How to log the SQL with parameters in Hibernate?"

As we know Hibernate is ORM framework which is being used at persistence layer. If you are a developer and you are Woking on development environment than i guess you faced a challenge to debug the SQL statement. 


Hibernate gives us a feature to show sql in the logs 


<property name="show_sql">true</property>
<property name="format_sql">true</property>
<property name="use_sql_comments">true</property>

But the above feature doesn't let see the parameters which you are passing into your SQL statement. 


Hibernate provides 2 category and levels to execute the SQL parameters and show their bind parameters.


1. Use org.hibernate.SQL as debug

2. org.hibernate.type.descriptor.sql as trace

Here is the code snippet of log4j : - 

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{HH:mm:ss, SSS} %-5p [%c] - %m%n
log4j.rootLogger = info, stdout
log4j.logger.org.hibernate = info
#following parameters will be used to log the sql parameters
log4j.logger.org.hibernate.SQL=debug
log4j.logger.org.hibernate.type.descriptor.sql=trace


Please have look on the logs where you can see the actual parameters are being printed 


Hibernate: insert into employee (employee_address, employee_name, id) values (?, ?, ?)
11:50:40, 209 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [1] as [VARCHAR] - [Address 0]
11:50:40, 209 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [2] as [VARCHAR] - [Employee 0]
11:50:40, 209 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [3] as [BIGINT] - [7008]
11:50:40, 210 DEBUG [org.hibernate.SQL] - insert into employee (employee_address, employee_name, id) values (?, ?, ?)
Hibernate: insert into employee (employee_address, employee_name, id) values (?, ?, ?)
11:50:40, 210 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [1] as [VARCHAR] - [Address 1]
11:50:40, 211 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [2] as [VARCHAR] - [Employee 1]
11:50:40, 211 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [3] as [BIGINT] - [7009]
11:50:40, 211 DEBUG [org.hibernate.SQL] - insert into employee (employee_address, employee_name, id) values (?, ?, ?)
Hibernate: insert into employee (employee_address, employee_name, id) values (?, ?, ?)
11:50:40, 211 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [1] as [VARCHAR] - [Address 2]
11:50:40, 211 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [2] as [VARCHAR] - [Employee 2]
11:50:40, 211 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [3] as [BIGINT] - [7010]


Employee entity used in the code : - 


import javax.persistence.Column;
import javax.persistence.Entity;
import javax.persistence.GeneratedValue;
import javax.persistence.GenerationType;
import javax.persistence.Id;
import javax.persistence.Table;
@Entity
@Table(name = "employee")
public class Employee {
@Id
@GeneratedValue(strategy=GenerationType.AUTO)
@Column(name = "id")
Long id;
@Column(name="employee_name")
String employeeName;
@Column(name="employee_address")
String employeeAddress;
public Employee(Long id, String employeeName, String employeeAddress) {
this.id = id;
this.employeeName = employeeName;
this.employeeAddress = employeeAddress;
}
public Employee() {
}
public Long getId() {
return id;
}
public void setId(Long id) {
this.id = id;
}
public String getEmployeeName() {
return employeeName;
}
public void setEmployeeName(String employeeName) {
this.employeeName = employeeName;
}
public String getEmployeeAddress() {
return employeeAddress;
}
public void setEmployeeAddress(String employeeAddress) {
this.employeeAddress = employeeAddress;
}
}


Main class : - 


import org.hibernate.Session;
import org.hibernate.SessionFactory;
import org.hibernate.Transaction;
import org.hibernate.cfg.Configuration;
import com.hibernate.tutorial.entity.Employee;
public class MainClass {
public static void main(String[] args) {
SessionFactory sessionFactory;
sessionFactory = new Configuration().configure() // configures settings
// from
// hibernate.cfg.xml
.buildSessionFactory();
Session session = sessionFactory.openSession();
Transaction tx = session.beginTransaction();
// Employee entitiy class
Employee emp = new Employee();
// Generate records for 10 employee
for (int i = 0; i <= 10; i++) {
emp = new Employee();
//emp.setId(new Long(i));
emp.setEmployeeName("Employee " + i);
emp.setEmployeeAddress("Address " + i);
session.save(emp);
}
tx.commit();
session.close();
}
}


Summary :-


So using "log4j.logger.org.hibernate.SQL=debug" and "log4j.logger.org.hibernate.type.descriptor.sql=trace" we can easily log SQL parameters. With these features it is really easy to trouble shoot or debug the issue on development environment. But always remember it is always being advisable in the development or sand box environment. Please do not use this features on production environment because it will generate a lot of unnecessary logs and may creak disk space issue in the long run.

2 comments:

  1. I did all of the above and am still not seeing the bind parameters in my log prints. WTF were the hibernate people thinking? Just give me the goddamn query it's sending to the DB, it shouldn't be rocket science!

    ReplyDelete