JPA (Hibernate) Native Query for Prepared Statement SLOW

Question

Having strange performance issue using Hibernate 3.3.2GA behind JPA (and the rest of the Hibernate packages included in JBoss 5.)

I'm using Native Query, and assembling SQL into a prepared statement.

EntityManager em = getEntityManager(MY_DS);
final Query query = em.createNativeQuery(fullSql, entity.getClass());

The SQL has a lot of joins, but is actually very basic, with a single parameter. Like:

SELECT field1, field2, field3 FROM entity left join entity2 on... left join entity3 on
WHERE stringId like ?

and the query runs in under a second on MSSQL Studio.

If I add

query.setParameter(0, "ABC123%");

The query will pause for 9 seconds

2012-01-20 14:36:21 - TRACE: - AbstractBatcher.getPreparedStatement:(484) | preparing statement
2012-01-20 14:36:21 - TRACE: - StringType.nullSafeSet:(133) | binding 'ABC123%' to parameter: 1
2012-01-20 14:36:30 - DEBUG: - AbstractBatcher.logOpenResults:(382) | about to open ResultSet (open ResultSets: 0, globally: 0)

However, if I just replace the "?" with the value (making it not a Prepared Statement, but just a straight SQL query.

fullSql = fullSql.replace("?", "'ABC123%'");

the query will complete in less that a second.

I would really prefer to us a Prepared Statement (the input for the parameters is being extracted from user data) to prevent injection attacks.

Tracing down the slow point in the code, I arrived deep within the jtds-1.2.2 package. The offending line seems to be SharedSocket line 841 "getIn().readFully(hdrBuf);" Nothing really obvious there though...

private byte[] readPacket(byte buffer[])
        throws IOException {
    //
    // Read rest of header
    try {
        getIn().readFully(hdrBuf);
    } catch (EOFException e) {
        throw new IOException("DB server closed connection.");
    }

Arrived to through this stack...

  at net.sourceforge.jtds.jdbc.SharedSocket.readPacket(SharedSocket.java:841)
  at net.sourceforge.jtds.jdbc.SharedSocket.getNetPacket(SharedSocket.java:722)
  at net.sourceforge.jtds.jdbc.ResponseStream.getPacket(ResponseStream.java:466)
  at net.sourceforge.jtds.jdbc.ResponseStream.read(ResponseStream.java:103)
  at net.sourceforge.jtds.jdbc.ResponseStream.peek(ResponseStream.java:88)
  at net.sourceforge.jtds.jdbc.TdsCore.wait(TdsCore.java:3928)
  at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1045)
  at net.sourceforge.jtds.jdbc.TdsCore.microsoftPrepare(TdsCore.java:1178)
  at net.sourceforge.jtds.jdbc.ConnectionJDBC2.prepareSQL(ConnectionJDBC2.java:657)
  at net.sourceforge.jtds.jdbc.JtdsPreparedStatement.executeQuery(JtdsPreparedStatement.java:776)
  at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:208)
  at org.hibernate.loader.Loader.getResultSet(Loader.java:1808)
  at org.hibernate.loader.Loader.doQuery(Loader.java:697)
  at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259)
  at org.hibernate.loader.Loader.doList(Loader.java:2228)
  at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2125)
  at org.hibernate.loader.Loader.list(Loader.java:2120)
  at org.hibernate.loader.custom.CustomLoader.list(CustomLoader.java:312)
  at org.hibernate.impl.SessionImpl.listCustomQuery(SessionImpl.java:1722)
  at org.hibernate.impl.AbstractSessionImpl.list(AbstractSessionImpl.java:165)
  at org.hibernate.impl.SQLQueryImpl.list(SQLQueryImpl.java:175)
  at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:67)

Solution 1

I'll leave this question and answer out here in case anyone has the same issue in the future.

The issue is in the way the JTDS drivers send the parameter strings to MSSQL. Apparently Java will attempt to send the parameters Unicode by default, and MSSQL will translate it to Ascii. Why that takes 9 seconds, I do not know.

Lot's of references to this out there, but nothing that helped my till I was able to isolate that it was an issue with the driver to MSSQL connection.

This link was helpful:

[http://server.pramati.com/blog/2010/06/02/perfissues-jdbcdrivers-mssqlserver/]

This is the string using the Microsoft driver.

jdbc:sqlserver://localhost\SQLEXPRESS;
  DatabaseName=TESTDB;
  sendStringParametersAsUnicode=false

You just need to get the sendStringParametersAsUnicode=false passed to your driver URL setup and you are good.

Solution 2

Check the query plans that SQL server is producing. Prepared statements can be especially problematic.

Let me explain...

If you do this:

SELECT field1, field2, field3 FROM entity left join entity2 on... left join entity3 on
WHERE stringId like 'ABC123%';

and you have an index on "stringId" SQL server knows it can use it.

However if you do this:

SELECT field1, field2, field3 FROM entity left join entity2 on... left join entity3 on
WHERE stringId like ?;

SQL server doesn't know it can use the index when it creates the prepared statement (as you could fill in the parameter with '%ABC123' instead of 'ABC123%') and thus may choose a completely different query plan.

Solution 3

And another answer for people potentially using Oracle with a similar Unicode problem...

Check to make sure someone hasn't set the property oracle.jdbc.defaultNChar=true

This is sometimes done to resolve unicode problems but it means all columns are treated as nvarchars. If you have an index on a varchar column, it won't be used because oracle has to use a function to convert the character encoding.

Comments

[javatestcase]

Thanks Gareth. What you say is 100% true. In this case the primary issue is with the driver-MSSQL connection. I think MSSQL may cache the query plans, and there are actually only a few possible iterations of the SP, with different sub queries for one-to-many relationships. After fixing that issue, 100 queries return in 47 seconds, a huge improvement over 9 seconds each!

[Gareth]

It takes 9 seconds because it doesn't translate your parameter to ascii (as it could lose data that way). It changes each column value to unicode before comparing against your parameter. This means it can't take full advantage of any index on the field "stringId" leading to much slower performance (I believe I also had an issue like this in the past).

[Gareth]

BTW, I am happy you fixed your problem.

[Carlos Jaime C. De Leon]

thanks for this information, i thought it was hibernate causing the issue

[CDT]

Is there a solution to this ?