Hibernate Logging using Logback Logging Framework
In this section, you will learn how to configure logging using Logback Logging Framework. Logback is purposefully created to be successor of the Log4j.
During development or after release, sometimes some unexpected error occurred with the application. To trace the error, logging is very helpful. Logback is the tool which helps in displaying logs or keeping it's track(for example in a log file). Using Logback logging can be enable at run time without modifying the application code. The jar file used in the below example are : logback-core-0.9.28.jar and logback-classic-0.9.28.jar.
For using Logback Logging Framework, you must need slf4j API jar file. In the below example we are using slf4j.api-1.6.1.jar file.
The 3 modules of Logback are :
- logback-core
This is the core library of the Logback Logging Framework. It has basic module needed for implementation of this framework. - logback-classic
It implements SLF4J API which helps us in switching between Logback and other framework. - logback-access
It easily integrate with with Servlet containers, such as Tomcat and Jetty, to provide HTTP-access log functionality.
The project hierarchy is given below :
CODE
hibernate.cfg.xml
<?xml version='1.0' encoding='utf-8'?> <!DOCTYPE hibernate-configuration PUBLIC "-//Hibernate/Hibernate Configuration DTD//EN" "http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd"> <hibernate-configuration> <session-factory> <property name="hibernate.connection.driver_class">com.mysql.jdbc.Driver</property> <property name="hibernate.connection.url">jdbc:mysql://192.168.10.13:3306/ankdb</property> <property name="hibernate.connection.username">root</property> <property name="hibernate.connection.password">root</property> <property name="hibernate.connection.pool_size">10</property> <property name="show_sql">true</property> <property name="dialect">org.hibernate.dialect.MySQLDialect</property> <property name="hibernate.current_session_context_class">thread</property> <mapping class="net.roseindia.Worker" /> </session-factory> </hibernate-configuration>
HandlingWorker.java
package net.roseindia;
import java.util.List;
import java.util.Iterator;
import org.hibernate.HibernateException;
import org.hibernate.Session;
import org.hibernate.Transaction;
import org.hibernate.SessionFactory;
import org.hibernate.cfg.Configuration;
import org.hibernate.service.ServiceRegistry;
import org.hibernate.service.ServiceRegistryBuilder;
public class HandlingWorker {
private static SessionFactory factory;
private static ServiceRegistry serviceRegistry;
public static void main(String[] args) {
try{
Configuration configuration = new Configuration();
configuration.configure();
serviceRegistry = new ServiceRegistryBuilder().applySettings(configuration.getProperties()).buildServiceRegistry();
factory = configuration.buildSessionFactory(serviceRegistry);
}catch (Throwable ex) {
System.err.println("Failed to create sessionFactory object." + ex);
throw new ExceptionInInitializerError(ex);
}
HandlingWorker handle = new HandlingWorker();
/* Add few worker records in database */
Integer worker1 = handle.addWorker("Kumar", "Dhawan", 1000);
Integer worker2 = handle.addWorker("Sriprakash", "Marathe", 5000);
Integer worker3 = handle.addWorker("Rudra", "Shah", 10000);
/* List down all the workers */
handle.listWorkers();
/* Update worker's records */
handle.updateWorker(worker1, 5000);
handle.updateWorker(worker3, 15000);
/* Delete an worker from the database */
handle.deleteWorker(worker2);
/* List down new list of the workers */
handle.listWorkers();
}
/* Method to CREATE an worker in the database */
public Integer addWorker(String fname, String lname, int salary){
Session session = factory.openSession();
Transaction tx = null;
Integer workerID = null;
try{
tx = session.beginTransaction();
Worker worker = new Worker(fname, lname, salary);
workerID = (Integer) session.save(worker);
tx.commit();
}catch (HibernateException e) {
if (tx!=null) tx.rollback();
e.printStackTrace();
}finally {
session.close();
}
return workerID;
}
/* Method to READ all the employees */
public void listWorkers( ){
Session session = factory.openSession();
Transaction tx = null;
try{
tx = session.beginTransaction();
List employees = session.createQuery("FROM Worker").list();
for (Iterator iterator =
employees.iterator(); iterator.hasNext();){
Worker worker = (Worker) iterator.next();
System.out.print("First Name: " + worker.getFirstName());
System.out.print(" Last Name: " + worker.getLastName());
System.out.println(" Salary: " + worker.getSalary());
}
tx.commit();
}catch (HibernateException e) {
if (tx!=null) tx.rollback();
e.printStackTrace();
}finally {
session.close();
}
}
/* Method to UPDATE salary for an worker */
public void updateWorker(Integer WorkerID, int salary ){
Session session = factory.openSession();
Transaction tx = null;
try{
tx = session.beginTransaction();
Worker worker =
(Worker)session.get(Worker.class, WorkerID);
worker.setSalary( salary );
session.update(worker);
tx.commit();
}catch (HibernateException e) {
if (tx!=null) tx.rollback();
e.printStackTrace();
}finally {
session.close();
}
}
/* Method to DELETE an worker from the records */
public void deleteWorker(Integer WorkerID){
Session session = factory.openSession();
Transaction tx = null;
try{
tx = session.beginTransaction();
Worker worker =
(Worker)session.get(Worker.class, WorkerID);
session.delete(worker);
tx.commit();
}catch (HibernateException e) {
if (tx!=null) tx.rollback();
e.printStackTrace();
}finally {
session.close();
}
}
}
Worker.java
package net.roseindia;
import javax.persistence.*;
@Entity
@Table(name = "Worker")
public class Worker {
@Id
@GeneratedValue
@Column(name = "id")
private int id;
@Column(name = "first_name")
private String firstName;
@Column(name = "last_name")
private String lastName;
@Column(name = "salary")
private int salary;
public Worker() {
}
public Worker(String fname, String lname, int salary) {
this.firstName = fname;
this.lastName = lname;
this.salary = salary;
}
public int getId() {
return id;
}
public void setId(int id) {
this.id = id;
}
public String getFirstName() {
return firstName;
}
public void setFirstName(String first_name) {
this.firstName = first_name;
}
public String getLastName() {
return lastName;
}
public void setLastName(String last_name) {
this.lastName = last_name;
}
public int getSalary() {
return salary;
}
public void setSalary(int salary) {
this.salary = salary;
}
}
logback.xml( /src/logback.xml )
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<Pattern>%d{yyyy-MM-dd_HH:mm:ss.SSS} %-5level %logger{36} - %msg%n
</Pattern>
</encoder>
</appender>
<appender name="FILE"
class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>c:/PROJECTLOG.log</file>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<Pattern>%d{yyyy-MM-dd_HH:mm:ss.SSS} [%thread] %-5level %logger{36} -
%msg%n
</Pattern>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
<FileNamePattern>c:/PROJECTLOG.%i.log.zip</FileNamePattern>
<MinIndex>1</MinIndex>
<MaxIndex>10</MaxIndex>
</rollingPolicy>
<triggeringPolicy
class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
<MaxFileSize>2MB</MaxFileSize>
</triggeringPolicy>
</appender>
<logger name="org.hibernate.type" level="ALL" />
<logger name="org.hibernate" level="DEBUG" />
<root level="INFO">
<appender-ref ref="FILE" />
<appender-ref ref="STDOUT" />
</root>
</configuration>
The above configuration will print the logs on console and also save the logs on the file saved in C: drive (C:\\PROJECTLOG.log). To download this log file click here.
OUTPUT
2012-03-05_14:59:42.437 DEBUG o.h.hql.internal.ast.ErrorCounter - throwQueryException() : no errors
2012-03-05_14:59:42.453 DEBUG o.h.h.i.antlr.HqlSqlBaseWalker - select << begin [level=1, statement=select]
2012-03-05_14:59:42.468 DEBUG o.h.h.internal.ast.tree.FromElement - FromClause{level=1} : net.roseindia.Worker (<no alias>) -> worker0_
2012-03-05_14:59:42.468 DEBUG o.h.h.i.antlr.HqlSqlBaseWalker - select : finishing up [level=1, statement=select]
2012-03-05_14:59:42.468 DEBUG o.h.hql.internal.ast.HqlSqlWalker - processQuery() : ( SELECT ( FromClause{level=1} Worker worker0_ ) )
2012-03-05_14:59:42.468 DEBUG o.h.hql.internal.ast.HqlSqlWalker - Derived SELECT clause created.
2012-03-05_14:59:42.484 DEBUG o.h.h.i.ast.util.JoinProcessor - Using FROM fragment [Worker worker0_]
2012-03-05_14:59:42.484 DEBUG o.h.h.i.antlr.HqlSqlBaseWalker - select >> end [level=1, statement=select]
2012-03-05_14:59:42.484 DEBUG o.h.h.i.ast.QueryTranslatorImpl - --- SQL AST ---
\-[SELECT] QueryNode: 'SELECT' querySpaces (Worker)
+-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
| +-[SELECT_EXPR] SelectExpressionImpl: 'worker0_.id as id0_' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=Worker,tableAlias=worker0_,origin=null,columns={,className=net.roseindia.Worker}}}
| \-[SQL_TOKEN] SqlFragment: 'worker0_.first_name as first2_0_, worker0_.last_name as last3_0_, worker0_.salary as salary0_'
\-[FROM] FromClause: 'FROM' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[], fromElementByTableAlias=[worker0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
\-[FROM_FRAGMENT] FromElement: 'Worker worker0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=Worker,tableAlias=worker0_,origin=null,columns={,className=net.roseindia.Worker}}
2012-03-05_14:59:42.484 DEBUG o.h.hql.internal.ast.ErrorCounter - throwQueryException() : no errors
2012-03-05_14:59:42.484 DEBUG o.h.h.i.ast.QueryTranslatorImpl - HQL: FROM net.roseindia.Worker
2012-03-05_14:59:42.484 DEBUG o.h.h.i.ast.QueryTranslatorImpl - SQL: select worker0_.id as id0_, worker0_.first_name as first2_0_, worker0_.last_name as last3_0_, worker0_.salary as salary0_ from Worker worker0_
2012-03-05_14:59:42.484 DEBUG o.h.hql.internal.ast.ErrorCounter - throwQueryException() : no errors
2012-03-05_14:59:42.484 DEBUG org.hibernate.SQL - select worker0_.id as id0_, worker0_.first_name as first2_0_, worker0_.last_name as last3_0_, worker0_.salary as salary0_ from Worker worker0_
Hibernate: select worker0_.id as id0_, worker0_.first_name as first2_0_, worker0_.last_name as last3_0_, worker0_.salary as salary0_ from Worker worker0_
2012-03-05_14:59:42.500 DEBUG org.hibernate.loader.Loader - Result set row: 0
2012-03-05_14:59:42.500 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [55] as column [id0_]
2012-03-05_14:59:42.500 DEBUG org.hibernate.loader.Loader - Result row: EntityKey[net.roseindia.Worker#55]
2012-03-05_14:59:42.500 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Kumar] as column [first2_0_]
2012-03-05_14:59:42.500 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Dhawan] as column [last3_0_]
2012-03-05_14:59:42.500 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [1000] as column [salary0_]
2012-03-05_14:59:42.500 DEBUG org.hibernate.loader.Loader - Result set row: 1
2012-03-05_14:59:42.500 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [56] as column [id0_]
2012-03-05_14:59:42.500 DEBUG org.hibernate.loader.Loader - Result row: EntityKey[net.roseindia.Worker#56]
2012-03-05_14:59:42.500 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Sriprakash] as column [first2_0_]
2012-03-05_14:59:42.500 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Marathe] as column [last3_0_]
2012-03-05_14:59:42.500 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [5000] as column [salary0_]
2012-03-05_14:59:42.500 DEBUG org.hibernate.loader.Loader - Result set row: 2
2012-03-05_14:59:42.500 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [57] as column [id0_]
2012-03-05_14:59:42.500 DEBUG org.hibernate.loader.Loader - Result row: EntityKey[net.roseindia.Worker#57]
2012-03-05_14:59:42.500 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Rudra] as column [first2_0_]
2012-03-05_14:59:42.500 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Shah] as column [last3_0_]
2012-03-05_14:59:42.500 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [10000] as column [salary0_]
2012-03-05_14:59:42.500 DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [net.roseindia.Worker#55]
2012-03-05_14:59:42.500 DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [net.roseindia.Worker#55]
2012-03-05_14:59:42.500 DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [net.roseindia.Worker#56]
2012-03-05_14:59:42.500 DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [net.roseindia.Worker#56]
2012-03-05_14:59:42.500 DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [net.roseindia.Worker#57]
2012-03-05_14:59:42.500 DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [net.roseindia.Worker#57]
2012-03-05_14:59:42.500 DEBUG o.h.e.i.StatefulPersistenceContext - Initializing non-lazy collections
First Name: Kumar Last Name: Dhawan Salary: 1000
First Name: Sriprakash Last Name: Marathe Salary: 5000
First Name: Rudra Last Name: Shah Salary: 10000
2012-03-05_14:59:42.500 DEBUG o.h.e.t.spi.AbstractTransactionImpl - committing
2012-03-05_14:59:42.500 DEBUG o.h.e.i.AbstractFlushingEventListener - Processing flush-time cascades
2012-03-05_14:59:42.500 DEBUG o.h.e.i.AbstractFlushingEventListener - Dirty checking collections
2012-03-05_14:59:42.500 DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 3 objects
2012-03-05_14:59:42.500 DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2012-03-05_14:59:42.500 DEBUG o.h.internal.util.EntityPrinter - Listing entities:
2012-03-05_14:59:42.500 DEBUG o.h.internal.util.EntityPrinter - net.roseindia.Worker{id=56, lastName=Marathe, salary=5000, firstName=Sriprakash}
2012-03-05_14:59:42.500 DEBUG o.h.internal.util.EntityPrinter - net.roseindia.Worker{id=57, lastName=Shah, salary=10000, firstName=Rudra}
2012-03-05_14:59:42.500 DEBUG o.h.internal.util.EntityPrinter - net.roseindia.Worker{id=55, lastName=Dhawan, salary=1000, firstName=Kumar}
2012-03-05_14:59:42.500 DEBUG o.h.e.t.i.jdbc.JdbcTransaction - committed JDBC Connection
2012-03-05_14:59:42.500 DEBUG o.h.e.j.i.LogicalConnectionImpl - Releasing JDBC connection
2012-03-05_14:59:42.500 DEBUG o.h.e.j.i.LogicalConnectionImpl - Released JDBC connection
2012-03-05_14:59:42.500 DEBUG o.h.e.j.i.p.ConnectionProxyHandler - HHH000163: Logical connection releasing its physical connection
2012-03-05_14:59:42.515 DEBUG org.hibernate.internal.SessionImpl - Opened session at timestamp: 13309397825
2012-03-05_14:59:42.515 DEBUG o.h.e.t.spi.AbstractTransactionImpl - begin
2012-03-05_14:59:42.515 DEBUG o.h.e.j.i.LogicalConnectionImpl - Obtaining JDBC connection
2012-03-05_14:59:42.515 DEBUG o.h.e.j.i.LogicalConnectionImpl - Obtained JDBC connection
2012-03-05_14:59:42.515 DEBUG o.h.e.t.i.jdbc.JdbcTransaction - initial autocommit status: false
2012-03-05_14:59:42.515 DEBUG org.hibernate.loader.Loader - Loading entity: [net.roseindia.Worker#55]
2012-03-05_14:59:42.515 DEBUG org.hibernate.SQL - select worker0_.id as id0_0_, worker0_.first_name as first2_0_0_, worker0_.last_name as last3_0_0_, worker0_.salary as salary0_0_ from Worker worker0_ where worker0_.id=?
Hibernate: select worker0_.id as id0_0_, worker0_.first_name as first2_0_0_, worker0_.last_name as last3_0_0_, worker0_.salary as salary0_0_ from Worker worker0_ where worker0_.id=?
2012-03-05_14:59:42.515 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [INTEGER] - 55
2012-03-05_14:59:42.515 DEBUG org.hibernate.loader.Loader - Result set row: 0
2012-03-05_14:59:42.515 DEBUG org.hibernate.loader.Loader - Result row: EntityKey[net.roseindia.Worker#55]
2012-03-05_14:59:42.515 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Kumar] as column [first2_0_0_]
2012-03-05_14:59:42.515 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Dhawan] as column [last3_0_0_]
2012-03-05_14:59:42.515 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [1000] as column [salary0_0_]
2012-03-05_14:59:42.515 DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [net.roseindia.Worker#55]
2012-03-05_14:59:42.515 DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [net.roseindia.Worker#55]
2012-03-05_14:59:42.515 DEBUG o.h.e.i.StatefulPersistenceContext - Initializing non-lazy collections
2012-03-05_14:59:42.515 DEBUG org.hibernate.loader.Loader - Done entity load
2012-03-05_14:59:42.515 DEBUG o.h.e.t.spi.AbstractTransactionImpl - committing
2012-03-05_14:59:42.515 DEBUG o.h.e.i.AbstractFlushingEventListener - Processing flush-time cascades
2012-03-05_14:59:42.515 DEBUG o.h.e.i.AbstractFlushingEventListener - Dirty checking collections
2012-03-05_14:59:42.515 DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
2012-03-05_14:59:42.515 DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2012-03-05_14:59:42.515 DEBUG o.h.internal.util.EntityPrinter - Listing entities:
2012-03-05_14:59:42.515 DEBUG o.h.internal.util.EntityPrinter - net.roseindia.Worker{id=55, lastName=Dhawan, salary=5000, firstName=Kumar}
2012-03-05_14:59:42.515 DEBUG org.hibernate.SQL - update Worker set first_name=?, last_name=?, salary=? where id=?
Hibernate: update Worker set first_name=?, last_name=?, salary=? where id=?
2012-03-05_14:59:42.515 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [VARCHAR] - Kumar
2012-03-05_14:59:42.515 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [2] as [VARCHAR] - Dhawan
2012-03-05_14:59:42.515 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [3] as [INTEGER] - 5000
2012-03-05_14:59:42.515 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [4] as [INTEGER] - 55
2012-03-05_14:59:42.546 DEBUG o.h.e.t.i.jdbc.JdbcTransaction - committed JDBC Connection
2012-03-05_14:59:42.546 DEBUG o.h.e.j.internal.JdbcCoordinatorImpl - HHH000420: Closing un-released batch
2012-03-05_14:59:42.546 DEBUG o.h.e.j.i.LogicalConnectionImpl - Releasing JDBC connection
2012-03-05_14:59:42.546 DEBUG o.h.e.j.i.LogicalConnectionImpl - Released JDBC connection
2012-03-05_14:59:42.546 DEBUG o.h.e.j.i.p.ConnectionProxyHandler - HHH000163: Logical connection releasing its physical connection
2012-03-05_14:59:42.546 DEBUG org.hibernate.internal.SessionImpl - Opened session at timestamp: 13309397825
2012-03-05_14:59:42.546 DEBUG o.h.e.t.spi.AbstractTransactionImpl - begin
2012-03-05_14:59:42.546 DEBUG o.h.e.j.i.LogicalConnectionImpl - Obtaining JDBC connection
2012-03-05_14:59:42.546 DEBUG o.h.e.j.i.LogicalConnectionImpl - Obtained JDBC connection
2012-03-05_14:59:42.546 DEBUG o.h.e.t.i.jdbc.JdbcTransaction - initial autocommit status: false
2012-03-05_14:59:42.546 DEBUG org.hibernate.loader.Loader - Loading entity: [net.roseindia.Worker#57]
2012-03-05_14:59:42.562 DEBUG org.hibernate.SQL - select worker0_.id as id0_0_, worker0_.first_name as first2_0_0_, worker0_.last_name as last3_0_0_, worker0_.salary as salary0_0_ from Worker worker0_ where worker0_.id=?
Hibernate: select worker0_.id as id0_0_, worker0_.first_name as first2_0_0_, worker0_.last_name as last3_0_0_, worker0_.salary as salary0_0_ from Worker worker0_ where worker0_.id=?
2012-03-05_14:59:42.562 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [INTEGER] - 57
2012-03-05_14:59:42.562 DEBUG org.hibernate.loader.Loader - Result set row: 0
2012-03-05_14:59:42.562 DEBUG org.hibernate.loader.Loader - Result row: EntityKey[net.roseindia.Worker#57]
2012-03-05_14:59:42.562 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Rudra] as column [first2_0_0_]
2012-03-05_14:59:42.562 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Shah] as column [last3_0_0_]
2012-03-05_14:59:42.562 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [10000] as column [salary0_0_]
2012-03-05_14:59:42.562 DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [net.roseindia.Worker#57]
2012-03-05_14:59:42.562 DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [net.roseindia.Worker#57]
2012-03-05_14:59:42.562 DEBUG o.h.e.i.StatefulPersistenceContext - Initializing non-lazy collections
2012-03-05_14:59:42.562 DEBUG org.hibernate.loader.Loader - Done entity load
2012-03-05_14:59:42.562 DEBUG o.h.e.t.spi.AbstractTransactionImpl - committing
2012-03-05_14:59:42.562 DEBUG o.h.e.i.AbstractFlushingEventListener - Processing flush-time cascades
2012-03-05_14:59:42.562 DEBUG o.h.e.i.AbstractFlushingEventListener - Dirty checking collections
2012-03-05_14:59:42.562 DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
2012-03-05_14:59:42.562 DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2012-03-05_14:59:42.562 DEBUG o.h.internal.util.EntityPrinter - Listing entities:
2012-03-05_14:59:42.562 DEBUG o.h.internal.util.EntityPrinter - net.roseindia.Worker{id=57, lastName=Shah, salary=15000, firstName=Rudra}
2012-03-05_14:59:42.562 DEBUG org.hibernate.SQL - update Worker set first_name=?, last_name=?, salary=? where id=?
Hibernate: update Worker set first_name=?, last_name=?, salary=? where id=?
2012-03-05_14:59:42.562 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [VARCHAR] - Rudra
2012-03-05_14:59:42.562 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [2] as [VARCHAR] - Shah
2012-03-05_14:59:42.562 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [3] as [INTEGER] - 15000
2012-03-05_14:59:42.562 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [4] as [INTEGER] - 57
2012-03-05_14:59:42.578 DEBUG o.h.e.t.i.jdbc.JdbcTransaction - committed JDBC Connection
2012-03-05_14:59:42.578 DEBUG o.h.e.j.internal.JdbcCoordinatorImpl - HHH000420: Closing un-released batch
2012-03-05_14:59:42.578 DEBUG o.h.e.j.i.LogicalConnectionImpl - Releasing JDBC connection
2012-03-05_14:59:42.578 DEBUG o.h.e.j.i.LogicalConnectionImpl - Released JDBC connection
2012-03-05_14:59:42.578 DEBUG o.h.e.j.i.p.ConnectionProxyHandler - HHH000163: Logical connection releasing its physical connection
2012-03-05_14:59:42.578 DEBUG org.hibernate.internal.SessionImpl - Opened session at timestamp: 13309397825
2012-03-05_14:59:42.578 DEBUG o.h.e.t.spi.AbstractTransactionImpl - begin
2012-03-05_14:59:42.578 DEBUG o.h.e.j.i.LogicalConnectionImpl - Obtaining JDBC connection
2012-03-05_14:59:42.578 DEBUG o.h.e.j.i.LogicalConnectionImpl - Obtained JDBC connection
2012-03-05_14:59:42.578 DEBUG o.h.e.t.i.jdbc.JdbcTransaction - initial autocommit status: false
2012-03-05_14:59:42.578 DEBUG org.hibernate.loader.Loader - Loading entity: [net.roseindia.Worker#56]
2012-03-05_14:59:42.578 DEBUG org.hibernate.SQL - select worker0_.id as id0_0_, worker0_.first_name as first2_0_0_, worker0_.last_name as last3_0_0_, worker0_.salary as salary0_0_ from Worker worker0_ where worker0_.id=?
Hibernate: select worker0_.id as id0_0_, worker0_.first_name as first2_0_0_, worker0_.last_name as last3_0_0_, worker0_.salary as salary0_0_ from Worker worker0_ where worker0_.id=?
2012-03-05_14:59:42.578 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [INTEGER] - 56
2012-03-05_14:59:42.593 DEBUG org.hibernate.loader.Loader - Result set row: 0
2012-03-05_14:59:42.593 DEBUG org.hibernate.loader.Loader - Result row: EntityKey[net.roseindia.Worker#56]
2012-03-05_14:59:42.593 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Sriprakash] as column [first2_0_0_]
2012-03-05_14:59:42.593 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Marathe] as column [last3_0_0_]
2012-03-05_14:59:42.593 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [5000] as column [salary0_0_]
2012-03-05_14:59:42.593 DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [net.roseindia.Worker#56]
2012-03-05_14:59:42.593 DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [net.roseindia.Worker#56]
2012-03-05_14:59:42.593 DEBUG o.h.e.i.StatefulPersistenceContext - Initializing non-lazy collections
2012-03-05_14:59:42.593 DEBUG org.hibernate.loader.Loader - Done entity load
2012-03-05_14:59:42.593 DEBUG o.h.e.t.spi.AbstractTransactionImpl - committing
2012-03-05_14:59:42.593 DEBUG o.h.e.i.AbstractFlushingEventListener - Processing flush-time cascades
2012-03-05_14:59:42.593 DEBUG o.h.e.i.AbstractFlushingEventListener - Dirty checking collections
2012-03-05_14:59:42.593 DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 1 deletions to 1 objects
2012-03-05_14:59:42.593 DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2012-03-05_14:59:42.593 DEBUG o.h.internal.util.EntityPrinter - Listing entities:
2012-03-05_14:59:42.593 DEBUG o.h.internal.util.EntityPrinter - net.roseindia.Worker{id=56, lastName=Marathe, salary=5000, firstName=Sriprakash}
2012-03-05_14:59:42.593 DEBUG org.hibernate.SQL - delete from Worker where id=?
Hibernate: delete from Worker where id=?
2012-03-05_14:59:42.593 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [INTEGER] - 56
2012-03-05_14:59:42.625 DEBUG o.h.e.t.i.jdbc.JdbcTransaction - committed JDBC Connection
2012-03-05_14:59:42.625 DEBUG o.h.e.j.internal.JdbcCoordinatorImpl - HHH000420: Closing un-released batch
2012-03-05_14:59:42.625 DEBUG o.h.e.j.i.LogicalConnectionImpl - Releasing JDBC connection
2012-03-05_14:59:42.625 DEBUG o.h.e.j.i.LogicalConnectionImpl - Released JDBC connection
2012-03-05_14:59:42.625 DEBUG o.h.e.j.i.p.ConnectionProxyHandler - HHH000163: Logical connection releasing its physical connection
2012-03-05_14:59:42.625 DEBUG org.hibernate.internal.SessionImpl - Opened session at timestamp: 13309397826
2012-03-05_14:59:42.625 DEBUG o.h.e.t.spi.AbstractTransactionImpl - begin
2012-03-05_14:59:42.625 DEBUG o.h.e.j.i.LogicalConnectionImpl - Obtaining JDBC connection
2012-03-05_14:59:42.625 DEBUG o.h.e.j.i.LogicalConnectionImpl - Obtained JDBC connection
2012-03-05_14:59:42.625 DEBUG o.h.e.t.i.jdbc.JdbcTransaction - initial autocommit status: false
2012-03-05_14:59:42.625 DEBUG org.hibernate.SQL - select worker0_.id as id0_, worker0_.first_name as first2_0_, worker0_.last_name as last3_0_, worker0_.salary as salary0_ from Worker worker0_
Hibernate: select worker0_.id as id0_, worker0_.first_name as first2_0_, worker0_.last_name as last3_0_, worker0_.salary as salary0_ from Worker worker0_
2012-03-05_14:59:42.625 DEBUG org.hibernate.loader.Loader - Result set row: 0
2012-03-05_14:59:42.625 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [55] as column [id0_]
2012-03-05_14:59:42.625 DEBUG org.hibernate.loader.Loader - Result row: EntityKey[net.roseindia.Worker#55]
2012-03-05_14:59:42.625 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Kumar] as column [first2_0_]
2012-03-05_14:59:42.625 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Dhawan] as column [last3_0_]
2012-03-05_14:59:42.625 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [5000] as column [salary0_]
2012-03-05_14:59:42.625 DEBUG org.hibernate.loader.Loader - Result set row: 1
2012-03-05_14:59:42.625 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [57] as column [id0_]
2012-03-05_14:59:42.625 DEBUG org.hibernate.loader.Loader - Result row: EntityKey[net.roseindia.Worker#57]
2012-03-05_14:59:42.625 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Rudra] as column [first2_0_]
2012-03-05_14:59:42.625 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [Shah] as column [last3_0_]
2012-03-05_14:59:42.625 TRACE o.h.t.descriptor.sql.BasicExtractor - Found [15000] as column [salary0_]
2012-03-05_14:59:42.625 DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [net.roseindia.Worker#55]
2012-03-05_14:59:42.625 DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [net.roseindia.Worker#55]
2012-03-05_14:59:42.625 DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [net.roseindia.Worker#57]
2012-03-05_14:59:42.625 DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [net.roseindia.Worker#57]
2012-03-05_14:59:42.625 DEBUG o.h.e.i.StatefulPersistenceContext - Initializing non-lazy collections
First Name: Kumar Last Name: Dhawan Salary: 5000
First Name: Rudra Last Name: Shah Salary: 15000
2012-03-05_14:59:42.625 DEBUG o.h.e.t.spi.AbstractTransactionImpl - committing
2012-03-05_14:59:42.625 DEBUG o.h.e.i.AbstractFlushingEventListener - Processing flush-time cascades
2012-03-05_14:59:42.625 DEBUG o.h.e.i.AbstractFlushingEventListener - Dirty checking collections
2012-03-05_14:59:42.625 DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
2012-03-05_14:59:42.625 DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2012-03-05_14:59:42.625 DEBUG o.h.internal.util.EntityPrinter - Listing entities:
2012-03-05_14:59:42.625 DEBUG o.h.internal.util.EntityPrinter - net.roseindia.Worker{id=57, lastName=Shah, salary=15000, firstName=Rudra}
2012-03-05_14:59:42.625 DEBUG o.h.internal.util.EntityPrinter - net.roseindia.Worker{id=55, lastName=Dhawan, salary=5000, firstName=Kumar}
2012-03-05_14:59:42.625 DEBUG o.h.e.t.i.jdbc.JdbcTransaction - committed JDBC Connection
2012-03-05_14:59:42.625 DEBUG o.h.e.j.i.LogicalConnectionImpl - Releasing JDBC connection
2012-03-05_14:59:42.625 DEBUG o.h.e.j.i.LogicalConnectionImpl - Released JDBC connection
2012-03-05_14:59:42.625 DEBUG o.h.e.j.i.p.ConnectionProxyHandler - HHH000163: Logical connection releasing its physical connection
In the worker table, you will get the following :
