Comparing times and debugging query problems with MySQL and Hibernate 

Earlier today I was working on a problem that involved comparing the values of some java.sql.Time members persisted in MySQL 5.5. I had a start time and a stop time (persisted as time fields), and I needed to generate lists of all entities that were “running” (e.g. the current time was between the entity’s start and stop time). This simple problem caused me a lot of aggravation which boiled down to a basic misunderstanding about how certain Hibernate Restrictions worked, but while I was debugging the issue I learned a little bit about to diagnose problems forming a query via Hibernate. I thought it would be good to publish my experience as I had a hard time finding any information addressing my specific issue.

Comparing Times

First, the time comparisons. To find active entities (here where state >= 1) whose run time range included the current time, it was as simple as this:

Time now = new Time(Calendar.getInstance().getTime().getTime());

Criteria c = session.createCriteria(Thing.class)
	.add(Restrictions.ge("state", 1))
	.add(Restrictions.le("start", now))
	.add(Restrictions.ge("stop", now));

Assuming it was 01:00 AM, that would produce a query equivalent to this:

SELECT    *
FROM      Thing
WHERE     state = 1
  AND     start <= '01:00:00'
  AND     stop >= '01:00:00'; 

Now if we if wanted to find idle entities:

Time now = new Time(Calendar.getInstance().getTime().getTime());

Criteria c = session.createCriteria(Thing.class)
	.add(Restrictions.ge("state", 1))
	.add(Restrictions
		.or(Restrictions.ge("start", now), Restrictions.le("stop", now)));	

You’d get this:

SELECT    *
FROM      Thing
WHERE     state = 1
  AND     (start >= '01:00:00' OR stop <= '01:00:00'); 

Debugging

After assuming the problem had something to do with how Hibernate was comparing java.sql.Time objects, I took to the Google looking for answers but found nothing useful. I realized it would be helpful to actually see the SQL Hibernate was generating and go from there, but I had no idea how to do that off the top of my head. There are two ways of doing this.

Have MySQL log queries
I found it cleaner to have MySQL log the queries itself. My dev box runs Ubuntu 12.04 and has MySQL server installed directly from Ubuntu’s official repos, so it was all set up as a nice Upstart job. MySQL’s reference manual has clear instructions for enabling this logging. It was as simple as modifying a single line in the Upstart script.

Change this:

exec /usr/sbin/mysqld

To this:

exec /usr/sbin/mysqld --general_log=1 --general_log_file=/var/log/mysql/query.log

Substituting another log file if you like, of course.

Have Hibernate log queries
You can have Hibernate log the queries it generates with a few simple configuration properties. To get nice formatted output, I added the following to my persistence.xml:

<property name="hibernate.show_sql" value="true"/>
<property name="hibernate.format_sql" value="true" />

If you’re a masochist who likes reading mashed together text you can omit the format_sql.