Log SQL Query with Data Bindings in grails for a piece of code

23 / Apr / 2015 by Sandeep Poonia 0 comments

Although in grails, we can use the logSql property in the DataSource file to log SQL queries or enable loggers “org.hibernate.SQL” for logging queries and “org.hibernate.type.descriptor.sql.BasicBinder” for logging bindings. But this solution wouldn’t be that much helpful if we just want the logging for a particular piece of code rather than the whole project.

So we need something that enables these loggers only when our required piece of code starts execution and reset them when that code finishes execution.

We will create a method executeWithBindings in a class LogSql so that we can access it anywhere in our code. The argument of the method will be a Closure. So we can put our code inside a closure call and execute that code inside our method.

import org.apache.log4j.Level
import org.apache.log4j.Logger

class LogSql {

	public static def executeWithBindings(Closure closure) {
		//Get the SQL and BasicBinder loggers
		Logger sqlLogger = Logger.getLogger("org.hibernate.SQL")
		Logger basicBinderLogger = Logger.getLogger("org.hibernate.type.descriptor.sql.BasicBinder")

		//Store their current levels
		Level currentLevel = sqlLogger.level
		Level basicBinderLevel = basicBinderLogger.level

		//Set their Levels to Trace for fined grained logging
		sqlLogger.setLevel(Level.TRACE)
		basicBinderLogger.setLevel(Level.TRACE)

		//Execute the closure
		def result = closure.call()

		//Reset Levels
		sqlLogger.setLevel(currentLevel)
		basicBinderLogger.setLevel(basicBinderLevel)

		return result
	}
}

To prints the logs for any piece of code, we just need to put that code inside our closure call.

String firstName = "Sandeep"
LogSql.executeWithBindings {
	User.findWhere(["firstName": firstName])
}

This will print logs for all SQL statements executed inside this block and their corresponding bindings.

DEBUG  org.hibernate.SQL 17.04.2015 15:29:11 -- select this_.id as id40_0_, this_.version as version40_0_, this_.activation_date as activation3_40_0_, this_.admin as admin40_0_, this_.deactivation_date as deactiva5_40_0_, this_.email as email40_0_, this_.first_name as first8_40_0_, this_.last_name as last12_40_0_ from user this_ where (this_.first_name=?) limit ?
TRACE  org.hibernate.type.descriptor.sql.BasicBinder 17.04.2015 15:29:11 -- binding parameter [1] as [VARCHAR] - Sandeep

The only thing to keep in mind is that we are enabling the global loggers, so during the execution of this piece of code if any other SQL code gets executed somewhere in the application by some other process, then that part will also get logged.

FOUND THIS USEFUL? SHARE IT

Leave a comment -