Grails, p6spy and Sql Profiler

There are several ways to have Grails log SQL statements that Hibernate is sending to the database under the covers of GORM.  The first is the loggingSql flag in DataSource.groovy:

loggingSql=true

This will show you the prepared statement that Hibernate is generating, like this:

SELECT
    this_.id AS id6_0_,
    this_.version AS version6_0_,
    this_.authority AS authority6_0_,
    this_.description AS descript4_6_0_
FROM
    role this_
WHERE
    this_.authority=?

This is a good first step – but what if I want to see the parameter that is being sent as well?  You could turn logging for the org.hibernate.type package to TRACE level:

//in Config.groovy
log4j = {
    trace  'org.hibernate.type'
}

YIKES! That gets REALLY noisy, really fast:

Hibernate:
    select
        this_.id as id6_0_,
        this_.version as version6_0_,
        this_.authority as authority6_0_,
        this_.description as descript4_6_0_
    from
        role this_
    where
        this_.authority=?
TRACE type.StringType  - binding 'ROLE_USER' to parameter: 1
TRACE type.LongType  - returning '1' as column: id6_0_
TRACE type.LongType  - returning '1' as column: version6_0_
TRACE type.StringType  - returning 'ROLE_USER' as column: authority6_0_
TRACE type.StringType  - returning 'Default user role' as column: descript4_6_0_

Besides, what I really want is the ability to copy and paste a query, with the parameters bound, directly into a SQL editor to execute the query and see the results myself. Enter the p6spy plugin for Grails:

grails install-plugin p6spy

Swap the driver in your DataSource.groovy file from your driver to the p6spy driver (the plugin will automatically add this, you just need to comment it in):

environments {
  development {
    dataSource {
      //driverClassName = "org.hsqldb.jdbcDriver"
      driverClassName = "com.p6spy.engine.spy.P6SpyDriver"
    }
  }
}

Fire up your Grails application – p6spy will create a spy.log file in your application directory and log a pipe delimited line – the last column has the actual SQL being executed, with the parameters!

select this_.id as id2_0_, this_.version as version2_0_, this_.authority as authority2_0_, this_.description as descript4_2_0_ from role this_ where this_.authority='ROLE_USER'

This is a great start, and most people stop here. But sometimes there are so many queries being executed that it’s difficult to wade through spy.log to find the one you’re looking for. Thanks to a tip from the excellent Grails In Action book that was recently released – SQL Profiler can help!

Download SQL Profiler (http://sourceforge.net/projects/sqlprofiler) and add these lines to grails-app/conf/spy.properties:

log4j.appender.SQLPROFILER_CLIENT=org.apache.log4j.net.SocketAppender
log4j.appender.SQLPROFILER_CLIENT.RemoteHost=localhost
log4j.appender.SQLPROFILER_CLIENT.Port=4445
log4j.appender.SQLPROFILER_CLIENT.LocationInfo=true

Add the appender to the logger definition:

log4j.logger.p6spy=INFO,STDOUT,SQLPROFILER_CLIENT

Finally, make sure the Log4j Appender is enabled:

#specifies the appender to use for logging
appender=com.p6spy.engine.logging.appender.Log4jLogger
#appender=com.p6spy.engine.logging.appender.StdoutLogger
#appender=com.p6spy.engine.logging.appender.FileLogger

Then, in the directory in which you downloaded the SQL Profiler jar, launch the GUI with this line:

java -jar sqlprofiler.jar

Now, p6spy will log SQL to the SQL Profiler GUI! You can use it to profile SQL statements, but you can also use the ‘Logger’ tab to filter the log. I click the little trash can icon in the upper left to clear the log, run a test in the application, then filter the results using the filter fields available. For instance, if I only want to see queries related to the ‘ROLE’ table, just put the word ‘role’ in the Filter message text box, and you’ll only see queries related to that table. It’s a great way to get straight at a particular SQL query when you’re drowning in tons and tons of SQL messages.

---------------------------------------------------------------------------------------------

如果遇到这个问题：

Exception in thread "Thread-2" java.lang.NumberFormatException: For input string
: "21:26:47"
        at java.lang.NumberFormatException.forInputString(Unknown Source)
        at java.lang.Long.parseLong(Unknown Source)
        at java.lang.Long.parseLong(Unknown Source)
        at org.jahia.sqlprofiler.QueryEntry.parseP6Encoding(QueryEntry.java:134)

那么屏蔽掉spy.properties文件里面这一行内容：

# sets the date format using Java's SimpleDateFormat routine
#dateformat=HH:mm:ss

参考文章：
http://www.piragua.com/2009/06/17/grails-p6spy-and-sql-profiler/
http://grails.1312388.n4.nabble.com/p6spy-slqprofiler-error-td1385711.html