Logging for Hibernate (Step by Step)

1. Log4J Basic, a very good link from http://logging.apache.org/log4j/1.2/manual.html
2. Hibernate Log Categories is documented at http://docs.jboss.org/hibernate/core/3.3/reference/en/html/session-configuration.html
3. My Example, code part:

package Core;
import java.util.List;
import org.apache.log4j.Level;
import org.apache.log4j.Logger;
import org.apache.log4j.PropertyConfigurator;

public class Tester {
  static Logger logger = Logger.getLogger("MM");  
  public static void main(String[] args) {
      PropertyConfigurator.configure("src/Core/log.config");
      //    Either use the function above, or use the line for simple / quick configuration:
      //org.apache.log4j.BasicConfigurator.configure();
    
      //logger.setLevel(Level.INFO);
      //    This line above is the same as the configuration:
      //    log4j.logger.MM = INFO
    
      logger.debug("Going to start my log test");      
      StudentsDAO sdao = new StudentsDAO();
      List <Students> records = sdao.findAll();
      Students myrec = sdao.findById(1);
      logger.info("Student Name:" + myrec.getName());
    
  }
}

This part is the configuration file log.config:

# Set root logger level to DEBUG and its only appender to stdout and R
log4j.rootLogger=debug, stdout, R

# Changing our own logger
log4j.logger.MM = INFO
# this line will not be print out: logger.debug("Going to start my log test");

########## Section to Manipulate Hibernate Related Logging ##########
# Disable all other hibernate related logging
log4j.logger.org.hibernate = FATAL
# Enable SQL generation logging
log4j.logger.org.hibernate.SQL=DEBUG, stdout
# Enable Cache related logging
log4j.org.hibernate.cache = DEBUG, stdout, R



########## Defining the console based appender ###########
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
# Pattern to output the caller's file name and line number.
log4j.appender.stdout.layout.ConversionPattern=(%d)%5p [%t] (%F:%L) - %m%n



########### Defining a file based log appender ############
log4j.appender.R=org.apache.log4j.RollingFileAppender
log4j.appender.R.File=minrui.log
log4j.appender.R.MaxFileSize=1000KB
# Keep 20 backup file
log4j.appender.R.MaxBackupIndex=20
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%p %t %c - %m%n



Log printed out on stdout:

2009-12-12 18:25:47,229)DEBUG [main] (StudentsDAO.java:100) - finding all Students instances
(2009-12-12 18:25:48,701)DEBUG [main] (AbstractBatcher.java:401) - select students0_.id as id0_, students0_.name as name0_, students0_.address as address0_ from hibernate.students students0_
(2009-12-12 18:25:48,701)DEBUG [main] (AbstractBatcher.java:401) - select students0_.id as id0_, students0_.name as name0_, students0_.address as address0_ from hibernate.students students0_
(2009-12-12 18:25:48,741)DEBUG [main] (StudentsDAO.java:51) - getting Students instance with id: 1
(2009-12-12 18:25:48,761) INFO [main] (Tester.java:19) - Student Name:MinRui


A more effective way to analyze the SQL behavior is to use the P6spy and SQL profiler.