Hibernate: Logging SQLs executed by a method

In development environment we want to log whatever SQLs that are getting executed by hibernate to identify performance impacting queries or some other issues. For that we set show_sql flag to true or set org.hibernate.SQL to debug mode. But this logs every SQL that is being executed. But as a developer sometimes I felt that I need SQLs logs of a particular method execution. This can be done when we use profilers like JProfiler. But for using some profilers you might need a licence or profilers increases your debugging time. You know the consequences in using profilers.

This is where I tweak hibernate logger to on/off whenever I required. Let’s say I have a Service class which make calls to ServiceOne, ServiceTwo and ServieThree. And I want to log whatever SQLs being executed by ServiceTwo. How this can be done?

Extending org.hibernate.jdbc.util.SQLStatementLogger:

Hibernate uses org.hibernate.jdbc.util.SQLStatementLogger class for logging its SQLs. And it has a method called public void logStatement(String statement, FormatStyle style). So, I thought of extending this class and overriding logStatement(String statement, FormatStyle style) to behave in my way.

public class SQLLogger extends SQLStatementLogger{

	private static Map<Thread, Boolean> LOG_SWITCH = new HashMap<Thread, Boolean>();

	@Override
	public void logStatement(String statement, FormatStyle style) {
		Boolean isOn = LOG_SWITCH.get(Thread.currentThread());
		if(Boolean.TRUE.equals(isOn)){
			System.out.println("SQL: "+statement);
		}
	}

	public static void turnOn(){
		LOG_SWITCH.put(Thread.currentThread(), Boolean.TRUE);
	}

	public static void turnOff(){
		LOG_SWITCH.remove(Thread.currentThread());
	}

	public static void clear(){
		LOG_SWITCH.clear();
	}
}

In java, whether it’s standalone or web application, everything is executed under a thread. Every request/UI event starts a thread to handle the execution. So, I maintained a static map to hold running Thread and it’s log flag(whether to log or not). So, When you call turnOn() it sets logging ON for that particular thread. When you call turnOff() it stops logging for the same thread.

Replacing SQLStatementLogger with your new class instance:

While building SessionFactory hibernate creates instance of org.hibernate.cfg.Settings from hibernate properties that we configured in hibernate.cfg.xml/hibernate.properties file. So, while building Settings hibernate prepares SQLStatementLogger instance and sets it to Settings instance. So, I should be able to replace that instance with my new subclass instance to work.

public class LoggerReplaceServlet extends HttpServlet{

	@Override
	public void init() throws ServletException {
		SessionFactoryImpl sessionFactory = (SessionFactoryImpl) getSessionFactory();
		try {
			Settings settings = sessionFactory.getSettings();
			Method declaredMethod = settings.getClass().getDeclaredMethod("setSqlStatementLogger", new Class[] {SQLStatementLogger.class});
			declaredMethod.setAccessible(true);
			declaredMethod.invoke(settings, new SQLLogger());
		} catch (SecurityException e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		} catch (NoSuchMethodException e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		} catch (IllegalArgumentException e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		} catch (IllegalAccessException e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		} catch (InvocationTargetException e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		}

	}

	@Override
	public void destroy() {
		SQLLogger.clear();
	}

}

Servlet Configuration:

<servlet>
   <servlet-name>Logger</servlet-name>
   <servlet-class>org.pokuri.LoggerReplaceServlet</servlet-class>  	  	
   <load-on-startup>1</load-on-startup>
</servlet>

Here somehow you need to get SessionFactory built for your application and replace it’s SQLStatementLogger instance as shown above. This replacing logic should be at the start of the application. As mine is webapplication I went for servlet which should be loaded before application starts. If it is a standalone application it should be after building your SessionFactory. If you are using Spring IOC then you can do that in BeanPostProcessor regardless of application type(Standalone or Web application).

Using your logger:

public class OrderService {

	public void execute(){
		serviceOne.execute();

		SQLLogger.turnOn();
		serviceTwo.execute();
		SQLLogger.turnOff();

		serviceThree.execute();
	}

}

As shown in the code just add SQLLogger.turnOn() and SQLLogger.turnOff() around your serviceTwo.execute() method to log just that method generating SQLs.

For simplicity I am logging to standard console. If you want you can configure a file logger in log4j and log to it. Even you can format statement before logging using FormatStyle. For that you can look at SQLStatementLogger.logStatement() to how to use FormatStyle.