Development Art

One critical feature missing in Hibernate is the ability to log how long queries are taking. This is vital when you are performance tuning your application to see which parts can be optimized and also can highlight issues with the database (missing indexes, fragmentation etc.). With the correct fetching and batch strategies you usually don’t have to do too much, but it is always good to know how long things are taking. It can help in defining the order in which queries should run and even identify that maybe you should be doing queries in parallel.

There are configuration options already which allow you to print the sql queries being run but nothing I have seen which allows me to do the above. btw. if anybody knows how to print the full sql query with the parameters I would love to know.

One can always write logging statements surrounding each method (usually DAO methods) running the queries, however this is quite pervasive. It would be nicer to do and change as little as possible and get query execution times. Aspect-oriented programming can help us here. The following piece is an example using Spring+Hibernate stack since this is what I use - and it makes it so easy!

For a full description on AOP head-over to wikipedia linked above - I will give a very short crash-course. The idea behind AOP is the separation of concerns. We have packages, classes and methods which assist us with separation and modularization. Some concerns though don’t fit into this idea - they ‘crosscut’ other concerns. An example is logging. Aspect oriented programming gives us additional tools by which we can separate these sorts of ‘concerns’.

So firstly the code -

package au.com.xyz.aop;

import org.apache.commons.lang.time.StopWatch;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.springframework.stereotype.Component;

@Component
@Aspect
public class DAOInterceptor {

            protected Log log = LogFactory.getLog(DAOInterceptor.class);

            @Around("execution(* au.com.xyz.dao..*.*(..))")
            public Object logHibernateQueryTimes(ProceedingJoinPoint pjp) throws Throwable {
                        StopWatch stopWatch = new StopWatch();
                        stopWatch.start();
                        Object retVal = pjp.proceed();
                        stopWatch.stop();

                        String str = pjp.getTarget().toString();
                        log.debug(str.substring(str.lastIndexOf(".")+1, str.lastIndexOf("@")) + " - " + pjp.getSignature().getName() + ": " + stopWatch.getTime() + "ms");
                        return retVal;
            }

}

The AOP class is a simple POJO with some annotations -

• @Component is Spring related - so Spring will create an instance of the bean when it scans.
• @Aspect declares that this class is an Aspect
• @Around is Aspect related - means that execute this method around the methods in the classes given by expression (i.e. before the actual method is called and after the method is called)

In the actual method you can see it is again very simple -

• Lines 19-20: I start a timer (commons StopWatch)
• Line 21: Invoke the DAO method which will run the query and keep the return value
• Line 22: Stop the timer
• Line 24-25: Log the time taken for the query
• Line 26: Return the value of the DAO method

The only other thing left to do is to configure Spring to enable AOP.

<beans xmlns:aop="http://www.springframework.org/schema/aop"
       xsi:schemaLocation="http://www.springframework.org/schema/aop
       					   http://www.springframework.org/schema/aop/spring-aop-2.5.xsd">

	<aop:aspectj-autoproxy />
</beans>

That’s it! Depending on how you’ve configured your logging, you should see output similar to the following in your log -

I have been searching for a method to dynamically route objects to databases at runtime using Hibernate and recently I found a solution which fit the bill. This post explores the problem and identifies one possible solution.

The Problem:

I have a web-application (using Spring+Hibernate for ORM) which makes use of two database schemas (in the same physical database). I specify a datasource accessible via JNDI (using tomcat achieved via context xml) so across my different deployment environments I can use the same war file. This is particularly important as I do not want to use different binaries for different environments. My ethos is to keep any dynamic information pertinent to the deployment environment strictly outside of the war file exactly for the above reason - same war file across deployments.

I specify one DS (datasource) since the spring hibernate session-factory expects a single DS. But this only gets my half way there - I have only specified one database connection string - what about the other database? You can have multiple session factories but then have to deal with cross session transactions.

We can solve this problem (not the main problem this post addresses) by using the ’schema’ and ‘catalog’ configuration items on our entities which are in the DB #2. Below is an example which I will use for reference involving 3 objects spanning 2 schemas. It involves a common practice where identity management information is kept in a separate database to the application(s) database. I have omitted most of the information from the objects for brevity.

@Table
@Entity
public class ApplicationUser {

	private IdentityUser identityUser;

}

@Table (schema="secure", catalog="identitymanagement")
@Entity
public class IdentityUser {

	@OneToMany(fetch = FetchType.LAZY)
    @JoinTable(name = "IdentityUserIdentityRole",
    		   schema="security",
    		   catalog="identitymanagement",
    		   joinColumns = {@JoinColumn(name = "IdentityUserID")},
               inverseJoinColumns = {@JoinColumn(name = "IdentityRoleID")})
    private Set<IdentityRole> roles;

}

@Table (schema="secure", catalog="identitymanagement")
@Entity
public class IdentityRole {

}

ApplicationUser is in DB #1 and is configured via my JNDI datasouce. Its schema and catalog can be configured via default hibernate properties. As can be seen, I have hard-coded the schema and catalog values for the identity management objects IdentityUser and IdentityUserRole. I cannot put dynamic elements in these annotations and also note that using hbm.xml files does not get around this (while also keeping a single binary across deployment environments). This is the core of the problem.

What this means is that I can have multiple instances of DB #1 and only a single instance of DB #2 (which must be named secure.identitymanagement.*) in any single deployment environment. Not very tenable.

The Solution:

The way hibernate builds its queries is that it prepends the schema and catalog names when referring to the tables - i.e. in my example we would end up with a queries to the effect of - “select * from secure.identitymanagement.IdentityUser”. What we need is a way of manipulating this query building.

Enter the hibernate interceptor.

public class HibernateInterceptor extends EmptyInterceptor {

	@Override
    public String onPrepareStatement(String sql) {
          String prepedStatement = super.onPrepareStatement(sql);
          prepedStatement = prepedStatement.replaceAll("secure.identitymanagement", "my_dynamic_goodness");
          return prepedStatement;
    }

}

This interface is probably one of the most powerful hibernate features in the framework. It allows you to get at the core of Hibernate and manipulate properties at execution time - in this instance to do dynamic table routing. The ‘onPrepareStatement’ is obviously called when Hibernate is preparing the sql statements just before it sends it to the DB. What the code is doing (if it isn’t obvious) is a simple string replacement of an exact string. This exact string is what we hard-code (can be anything but should be an identifier which will not occur otherwise in sql statements) and is to be replaced by the dynamic catalog and schema name. Where the actual catalog and schema name values come from is up-to the implementer. In the case of a web-application, I code this in the context as a String property and look it up via JNDI similar to the DS.

I have deliberately made the above code very simple to show the underlying concept. One could put some quite complicated routing logic in there to do other forms of dynamic routing (e.g. based on logged in customer, based on users region). There are other solutions to the dynamic routing problem which address slightly different use-cases - check Hibernate Shards and dynamic models.

I am not sure the interceptor was meant for what I am ‘hijacking’ it to do but the first line of the api does give some insight…

Allows user code to inspect and/or change property values.