Count prepared statements within your grails application

Sometimes it is not so easy to find hotspots within your grails application. Even commercial profilers like JProfiler seem to have their problems generating useful “output” of the artifacts generated by the grails/groovy stack. For lack of alternatives we use a “primitve” closure to measure the time-consumption of a code-block, just to get some hint if we increased the performance of a block of code (e.g. a grails-service) or not.

But sometimes you need more than just a time-measurement closure. A good point to start performance-optimizations in our application seems to be to watch out for blocks doing a lot of sql-statements. With all that ORM and GORM magic you can run very fast in a situation that hundreds of selects and updates are fired within one service but you don’t know which individual methods within the service are causing them.

To “count” the number of prepared statements used within a code-block, we use the following closure within a “Measurement” class:

public class Measurement {
    // ...
    public static def countSQLStatements = { String blockIdentifier, Closure toExecute ->
        SessionFactory sessionFactory = ApplicationHolder.application.mainContext.sessionFactory
        boolean oldStatisticsState = enableStatistics(sessionFactory)

        long start = System.nanoTime()
        long queriesBeforeCall = sessionFactory.getStatistics().prepareStatementCount
        toExecute.call()
        long queriesOfCall =  sessionFactory.getStatistics().prepareStatementCount - queriesBeforeCall
        println "${blockIdentifier} caused the execution of ${queriesOfCall} prepared statements and took ${getTimeDeltaInMilliSeconds(start, System.nanoTime())} ms."

        resetStatisticsState(oldStatisticsState, sessionFactory)
        return queriesOfCall
    }
    //...
}

The method “getTimeDeltaInMilliSeconds” is implemented like this:

private static long getTimeDeltaInMilliSeconds(long nanoTimeStart, long nanoTimeEnd) {
    return  (nanoTimeEnd - nanoTimeStart) / 1E6
}

So, whenever you want to know how expensive a method call or other block within your code is, you can just write:

Measurement.countSQLStatements("Some block description",
  { methodCallToMeasure1()
     methodCallToMeasure2()
     // ...
})

Do you have any more tricks how to profile a grails-app? We would love to hear about them.

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s