Log SQL Query with Data Bindings in grails for a piece of code
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.
[code lang=”groovy”]
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
}
}
[/code]
To prints the logs for any piece of code, we just need to put that code inside our closure call.
[code lang=”groovy”]
String firstName = "Sandeep"
LogSql.executeWithBindings {
User.findWhere(["firstName": firstName])
}
[/code]
This will print logs for all SQL statements executed inside this block and their corresponding bindings.
[code lang=”sql”]
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
[/code]
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.
