Hibernate is 1000 times slower than sql query

Question

I have this setup

@Table(name ="A")
EntityA {
    Long ID;
    List<EntityB> children;
}

@Table(name ="B")
EntityB {
    Long ID;
    EntityA parent;
    EntityC grandchild;
}

@Table(name ="C")
EntityC {
    Long ID;
}

The SQL query is this (I omitted irrelevant details):

select top 300 from A where ... and ID in (select parent from B where ... and grandchild in (select ID from C where ...)) order by ...

The sql query in direct database or through Hibernate (3.5) SQL runs 1000 faster than using Criteria or HQL to express this.

The SQL generated is identical from HQL and Criteria and the SQL I posted there.

[EDIT]: Correction - the sql was not identical. I didn't try the Hibernate style parameter setting on the management studio side because I did not realize this until later - see my answer.

If I separate out the subqueries into separate queries, then it is fast again.

I tried

• removing all mappings of child, parent, ect.. and just use Long Id references - same thing, so its not a fetching, lazy,eager related.
• using joins instead of subqueries, and got the same slow behaviour with all combinations of fetching and loading.
• setting a projection on ID instead of retrieving entities, so there is no object conversion - still slow

I looked at Hibernate code and it is doing something astounding. It has a loop through all 300 results that end up hitting the database.

private List doQuery(
        final SessionImplementor session,
        final QueryParameters queryParameters,
        final boolean returnProxies) throws SQLException, HibernateException {

    final RowSelection selection = queryParameters.getRowSelection();
    final int maxRows = hasMaxRows( selection ) ?
            selection.getMaxRows().intValue() :
            Integer.MAX_VALUE;

    final int entitySpan = getEntityPersisters().length;

    final ArrayList hydratedObjects = entitySpan == 0 ? null : new ArrayList( entitySpan * 10 );
    final PreparedStatement st = prepareQueryStatement( queryParameters, false, session );
    final ResultSet rs = getResultSet( st, queryParameters.hasAutoDiscoverScalarTypes(), queryParameters.isCallable(), selection, session );

// would be great to move all this below here into another method that could also be used
// from the new scrolling stuff.
//
// Would need to change the way the max-row stuff is handled (i.e. behind an interface) so
// that I could do the control breaking at the means to know when to stop

    final EntityKey optionalObjectKey = getOptionalObjectKey( queryParameters, session );
    final LockMode[] lockModesArray = getLockModes( queryParameters.getLockOptions() );
    final boolean createSubselects = isSubselectLoadingEnabled();
    final List subselectResultKeys = createSubselects ? new ArrayList() : null;
    final List results = new ArrayList();

    try {

        handleEmptyCollections( queryParameters.getCollectionKeys(), rs, session );

        EntityKey[] keys = new EntityKey[entitySpan]; //we can reuse it for each row

        if ( log.isTraceEnabled() ) log.trace( "processing result set" );

        int count;
        for ( count = 0; count < maxRows && rs.next(); count++ ) {

            if ( log.isTraceEnabled() ) log.debug("result set row: " + count);

            Object result = getRowFromResultSet( 
                    rs,
                    session,
                    queryParameters,
                    lockModesArray,
                    optionalObjectKey,
                    hydratedObjects,
                    keys,
                    returnProxies 
            );
            results.add( result );

            if ( createSubselects ) {
                subselectResultKeys.add(keys);
                keys = new EntityKey[entitySpan]; //can't reuse in this case
            }

        }

        if ( log.isTraceEnabled() ) {
            log.trace( "done processing result set (" + count + " rows)" );
        }

    }
    finally {
        session.getBatcher().closeQueryStatement( st, rs );
    }

    initializeEntitiesAndCollections( hydratedObjects, rs, session, queryParameters.isReadOnly( session ) );

    if ( createSubselects ) createSubselects( subselectResultKeys, queryParameters, session );

    return results; //getResultList(results);

}

In this code

final ResultSet rs = getResultSet( st, queryParameters.hasAutoDiscoverScalarTypes(), queryParameters.isCallable(), selection, session );

it hits the database with the full SQL, but there are no results collected anywhere.

Then it proceeds to go through this loop

for ( count = 0; count < maxRows && rs.next(); count++ ) {

Where for every one of the expected 300 results, it ends up hitting the database to get the actual result.

This seems insane, since it should already have all the results after 1 query. Hibernate logs do not show any additional SQL being issued during all that time.

Anyone have any insight? The only option I have is to go to native SQL query through Hibernate.

Answer 1

We noticed a similar behaviour in our system.

And also encountered that writing the query with hardcoded parameters instead of using setParameter() would fixed the issue.

We are using MS SQL Server and after further investigation we noticed the the root cause of our issue is a default configuration of the sql server driver that transmits the query parameters as unicode. This lead to our indices being ignored since they were based on the ascii values on the queried columns.

The solution was to setup this property in the jdbc url : sendStringParametersAsUnicode=false

More details can be found here. https://stackoverflow.com/a/32867579

Answer 2

I finally managed to get to the bottom of this. The problem was being caused by Hibernate setting the parameters separately from the actual SQL query that involved subqueries. So native SQL or not, the performance will be slow if this is done. For example this will be slow:

String sql = some sql that has named parameter = :value
SQLQuery sqlQuery = session.createSQLQuery(sql);
sqlQuery.setParameter ("value", someValue);
List<Object[]> list = (List<Object[]>)sqlQuery.list();

And this will be fast

String sql = some native sql where parameter = 'actualValue'
SQLQuery sqlQuery = session.createSQLQuery(sql);
List<Object[]> list = (List<Object[]>)sqlQuery.list();

It seems that for some reason with letting Hibernate take care of the parameters it ends up getting stuck in the resultSet fetching. This is probably because the underlying query on the database is taking much longer being parameterized. I ended up writing the equivalent of Hibernate Criteria and Restrictions code that sets the parameters directly as above.