How to track result set size using hibernate?

Question

I'm trying to detect and optimize inefficient joins within a Java/Hibernate application. I've noticed that in some cases, due to the nature of how joins are handled in result sets, the over-the-wire data flow is very inefficient.

Let me provide an example. Suppose you have an HQL query that looks like this:

select s from Store s
left join fetch s.items i
left join fetch s.employees e
left join fetch s.customers c
where s.id = :id

(Ignore for a moment that this is not a smart query - it's just a simplified example).

If you imagine that a given store has 1000 items and 10 employees and 100 customers, you will get back a java object tree with 1111 entities. That might lull you into thinking that approximately 1111 rows were returned from the database, whereas in fact the result set had 1,000,000 rows!

The presence of all the columns makes this worse. If you imagine that each table had 5 columns, you might imagine that you got approximately 5555 "items" back, whereas the number of cells (row * column) in the result set was actually 20,000,000.

Clearly, it is the application developer's responsibility to be aware of this issue and not write queries in that way. However, this sometimes happens unintentionally (and in less severe ways), and it would be great to be able to instrument the application to somehow identify these situations.

However, I've been unable to find any way to calculate (from within a Java/Hibernate app) either the number of rows or the number of columns in the raw result set. Neither Hibernate interceptors, Hibernate events, nor Hibernate statistics seem to give access to this information.

Any suggestions? Thanks in advance.

Answer 1

There's a project called log4jdbc that provides a proxy JDBC driver, it can log SQL (with bind arguments added) as well as timing statistics, connection open and close events, even ResultSet calls. There are several forks, at least one (called log4jdbc-remix) logs resultsets as tables.

I'd think using the jdbc.sqltiming logger should be enough to point out where problems are, then you can drill down with the other options if you need to. But it sounds do-able to hack on it to get resultset counts.