These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

View unanswered posts | View active topics


Board index » Hibernate & Java Persistence » NHibernate Users

All times are UTC - 5 hours [ DST ]


Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 3 posts ] 
  Previous topic | Next topic 
Author Message
ErikB
 Post subject: Bad performance when using CreateSQLQuery and Oracle CONNECT
PostPosted: Tue Jun 12, 2007 8:42 am 
Newbie

Joined: Tue Jun 12, 2007 8:25 am
Posts: 3
This is probably a fault of my own but I can't find an answer anywhere so I hope one of you has an inkling. I am using CreateSQLQuery to execute a CONNECT BY PRIOR query, as follows:

Code:
ISQLQuery query = session.CreateSQLQuery( "SELECT CODE_PART FROM COMPOSITION " +
"WHERE CODE_PART LIKE :part " +
"CONNECT BY PRIOR CODE_PART = CODE_COMPOSITE " +
"START WITH CODE_COMPOSITE = :root" );

query.AddScalar( "CODE_PART", NHibernateUtil.String );
query.SetString( "part", "<T><U>%</U><I>ERI0011WTF</I><T>" );
query.SetString( "root", "<U>ERI0008WTF</U>" );

string returnValue = query.UniqueResult<string>();


This query takes no less than 4.5(!) seconds to return (measured on subsequent runs), while the same query in Oracle takes no more than 0.2 seconds. Since I've not seen NHibernate perform badly before, I am thinking I must be doing something wrong.

When I use the following the response time is perfect (<0.3 seconds):

Code:
ISQLQuery query = session.CreateSQLQuery( "SELECT CODE_PART FROM COMPOSITION " +
"WHERE CODE_PART LIKE :part" );

query.AddScalar( "CODE_PART", NHibernateUtil.String );
query.SetString( "part", "<T><U>%</U><I>ERI0011WTF</I><T>" );

string returnValue = query.UniqueResult<string>();


Can anyone point me in the right direction, either towards the solution or on how to debug this?

Oh, I am using NHibernate 1.2.

Thanks,
Erik
Top
 Profile  
 
ErikB
 Post subject:
PostPosted: Wed Jun 13, 2007 6:43 am 
Newbie

Joined: Tue Jun 12, 2007 8:25 am
Posts: 3
I've digged a little further and came to the following surprising fact. When I hard-code the named parameters as follows:

Code:
ISQLQuery query = session.CreateSQLQuery( "SELECT CODE_PART FROM COMPOSITION " +
"WHERE CODE_PART LIKE '<T><U>%</U><I>ERI0011WTF</I><T>' " +
"CONNECT BY PRIOR CODE_PART = CODE_COMPOSITE " +
"START WITH CODE_COMPOSITE = '<U>ERI0008WTF</U>'" );

query.AddScalar( "CODE_PART", NHibernateUtil.String );

string returnValue = query.UniqueResult<string>();


The response time drops to a very comfortable 0.3 seconds.

It confuses me and our dbas to no end. This is what the log tells me when running WITH named parameters:

Code:
2007-06-13 12:32:08,418 [9   ] DEBUG NHibernate.Impl.SessionFactoryImpl - Instantiated session factory
2007-06-13 12:32:08,434 [9   ] DEBUG NHibernate.Impl.SessionImpl - opened session
2007-06-13 12:32:08,449 [9   ] DEBUG NHibernate.Loader.Custom.SQLCustomQuery - starting processing of sql query [SELECT CODE_PART FROM COMPOSITION WHERE CODE_PART LIKE :part CONNECT BY PRIOR CODE_PART = CODE_COMPOSITE START WITH CODE_COMPOSITE = :root]
2007-06-13 12:32:08,465 [9   ] DEBUG NHibernate.Impl.SessionImpl - flushing session
2007-06-13 12:32:08,465 [9   ] DEBUG NHibernate.Impl.SessionImpl - Flushing entities and processing referenced collections
2007-06-13 12:32:08,465 [9   ] DEBUG NHibernate.Impl.SessionImpl - Processing unreferenced collections
2007-06-13 12:32:08,465 [9   ] DEBUG NHibernate.Impl.SessionImpl - scheduling collection removes/(re)creates/updates
2007-06-13 12:32:08,465 [9   ] DEBUG NHibernate.Impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
2007-06-13 12:32:08,465 [9   ] DEBUG NHibernate.Impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2007-06-13 12:32:08,465 [9   ] DEBUG NHibernate.Impl.SessionImpl - dont need to execute flush
2007-06-13 12:32:08,480 [9   ] DEBUG NHibernate.Impl.BatcherImpl - Opened new IDbCommand, open IDbCommands: 1
2007-06-13 12:32:08,480 [9   ] DEBUG NHibernate.Impl.BatcherImpl - Building an IDbCommand object for the SqlString: SELECT CODE_PART FROM COMPOSITION WHERE CODE_PART LIKE ? CONNECT BY PRIOR CODE_PART = CODE_COMPOSITE START WITH CODE_COMPOSITE = ?
2007-06-13 12:32:08,480 [9   ] DEBUG NHibernate.Loader.Loader - BindNamedParameters() <U>ERI0008WTF</U> -> root [1]
2007-06-13 12:32:08,480 [9   ] DEBUG NHibernate.Type.StringType - binding '<U>ERI0008WTF</U>' to parameter: 1
2007-06-13 12:32:08,480 [9   ] DEBUG NHibernate.Loader.Loader - BindNamedParameters() <T><U>%</U><I>ERI0011WTF</I><T> -> part [0]
2007-06-13 12:32:08,480 [9   ] DEBUG NHibernate.Type.StringType - binding '<T><U>%</U><I>ERI0011WTF</I><T>' to parameter: 0
2007-06-13 12:32:08,480 [9   ] INFO  NHibernate.Loader.Loader - SELECT CODE_PART FROM COMPOSITION WHERE CODE_PART LIKE :p0 CONNECT BY PRIOR CODE_PART = CODE_COMPOSITE START WITH CODE_COMPOSITE = :p1
2007-06-13 12:32:08,480 [9   ] DEBUG NHibernate.SQL - SELECT CODE_PART FROM COMPOSITION WHERE CODE_PART LIKE :p0 CONNECT BY PRIOR CODE_PART = CODE_COMPOSITE START WITH CODE_COMPOSITE = :p1; :p0 = '<T><U>%</U><I>ERI0011WTF</I><T>', :p1 = '<U>ERI0008WTF</U>'
2007-06-13 12:32:08,480 [9   ] DEBUG NHibernate.Connection.DriverConnectionProvider - Obtaining IDbConnection from Driver
2007-06-13 12:32:08,605 [9   ] DEBUG NHibernate.Impl.BatcherImpl - Opened IDataReader, open IDataReaders: 1
2007-06-13 12:32:08,605 [9   ] DEBUG NHibernate.Loader.Loader - processing result set
2007-06-13 12:32:12,965 [9   ] DEBUG NHibernate.Loader.Loader - result set row: 0
2007-06-13 12:32:12,965 [9   ] DEBUG NHibernate.Loader.Loader - result row:
2007-06-13 12:32:12,980 [9   ] DEBUG NHibernate.Type.StringType - returning '<T><U>ERI0010WTF</U><I>ERI0011WTF</I><T>' as column: CODE_PART
2007-06-13 12:32:12,980 [9   ] DEBUG NHibernate.Loader.Loader - done processing result set (1 rows)
2007-06-13 12:32:12,980 [9   ] DEBUG NHibernate.Impl.BatcherImpl - Closed IDataReader, open IDataReaders :0
2007-06-13 12:32:12,980 [9   ] DEBUG NHibernate.Impl.BatcherImpl - Closed IDbCommand, open IDbCommands: 0
2007-06-13 12:32:12,980 [9   ] DEBUG NHibernate.Impl.ConnectionManager - aggressively releasing database connection
2007-06-13 12:32:12,980 [9   ] DEBUG NHibernate.Connection.ConnectionProvider - Closing connection
2007-06-13 12:32:12,980 [9   ] DEBUG NHibernate.Impl.SessionImpl - initializing non-lazy collections
2007-06-13 12:32:12,980 [9   ] DEBUG NHibernate.Impl.ConnectionManager - after autocommit
2007-06-13 12:32:12,980 [9   ] DEBUG NHibernate.Impl.ConnectionManager - aggressively releasing database connection
2007-06-13 12:32:12,980 [9   ] DEBUG NHibernate.Impl.SessionImpl - transaction completion
2007-06-13 12:32:12,980 [9   ] DEBUG NHibernate.Impl.SessionImpl - closing session
2007-06-13 12:32:12,980 [9   ] DEBUG NHibernate.Impl.BatcherImpl - running BatcherImpl.Dispose(true)
Top
 Profile  
 
nacarson
 Post subject: Cached plans...
PostPosted: Thu Jun 14, 2007 1:20 am 
Newbie

Joined: Sat Apr 01, 2006 1:23 am
Posts: 14
Sometimes actually using parameterized queries results in a worse
query plan in the DB. It's rare, but sometimes the database itself
can choose a better plan when it knows that a certain column's
value will be X, rather than it could be any range of values.

I would suggest comparing the two plans, and then adding the
appropriate query hints to your SQL.

Neil
Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 3 posts ] 

Board index » Hibernate & Java Persistence » NHibernate Users

All times are UTC - 5 hours [ DST ]

You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.