Has anyone experienced problems with poor performance of queries executed against a remote oracle database? The same queries are 10-50x faster with direct JDBC calls. Please see below.

Any help is appreciated.

Brent




----- Original Message -----
From: "Brent Usrey" <usrey@kihost.com>
To: "Gavin King" <gavin@hibernate.org>
Cc: <BUsrey@ups-scs.com>
Sent: Thursday, January 08, 2004 7:22 AM
Subject: Re: $100 challenge RE: slow access to remote oracle database


> I could have guessed that the challenge was bogus. So much for using
> Hibernate in a distributed environment. Also, don't put out your email
> address if you don't want people to use it. You are the one that issued the
> challenge.
>
> Brent
>
> ----- Original Message -----
> From: "Gavin King" <gavin@hibernate.org>
> To: "Brent Usrey" <usrey@kihost.com>
> Sent: Thursday, January 08, 2004 12:31 AM
> Subject: Re: $100 challenge RE: slow access to remote oracle database
>
>
> > No. Of course not.
> > Please direct this to the user forum.
> >
> > Do not email me directly with this kind of problem. TIA
> >
> > Regards,
> > Gavin
> >
> >
> > Brent Usrey wrote:
> >
> > > Would this type of performance problem qualify for the $100 challenge?
> > >
> > >
> > > You wrote:
> > >
> > >>Gavin,
> > >>I am experiencing very slow query performance when accessing a database
> (oracle
> > >>in atlanta) that is not in the same data center as my application server
> > >>(tomcat in dallas).
> > >>It runs fine as long as the database is on the same box as the
> application
> > >>server.
> > >>I would like to use hibernate to replace an existing web app that is
> using
> > >>direct JDBC calls but can't explain to my client why hibernate would be
> slower
> > >>across the network.
> > >>I have not been able to find anything about this in any of the Forums or
> > >>Mailing lists. Any help or direction would be appreciated.
> > >>Thanks,
> > >>Brent Usrey
> > >
> > >
> > > --
> > > Brent
> >
> > --
> > Gavin King
> > JBoss Group
> > +61 410534454
> > http://hibernate.org
> >
>

There is no difference between Hibernate executing JDBC calls or your application executing JDBC calls directly, if both use Batch Updates and Prepared Statements.

Brent, for your future reference:

(1) It is always a faux pas to direct email the developer(s) of an opensource project looking for support - this is commonly accepted by all projects that I have come into contact with.

(2) It is certainly always incredibly rude to copy a private email into a public forum, in any kind of community.

(3) Your performance problems are obviously not the fault of Hibernate, as anyone can plainly see.

What I do not understand is if Hibernate is not configured correctly why would it work fine against the local database and not against a remote database? I have not seen anything that address this in the configuration. The same queries are 10-50x faster with direct JDBC calls against the remote database, which is exactly what you asked for in your challenge.

Has anyone else connected to a remote Oracle database with Hibernate?

Again, I apologize if I have somehow offended you. I am just looking for help. If I can get this to work for my client I am sure that this will be a big win for all of us.

Brent

Thousands of people run Hibernate with remote databases.

Brent,

It looks like you have a network issue, nothing to do with Hibernate (unless I am misunderstanding your topology). Look at ping times between the app server and the database server.


Sherman

Does anyone have any suggestions?

Once again, in the same instance of Tomcat using the same data source, Hibernate is MUCH slower to return a query that the direct JDBC call to the remote database. When the query is to the local database, there is no measurable difference. Has anyone else tried this?

I don't care about the $100 challenge and I don't doubt that there is something simple that can be tweaked to fix this. I am using the Thread Local Session example from the website. Could that be part of the problem?

What more information could I give to spark someone's interest? So far it seems that I have just gotten people mad, which is not my intent.

Thanks Sherman,

I don't think that is it because as I mentioned above, I am using the same data source with different results. Any other ideas?

I appreciate your suggestion,

Brent

Could it be that Hibernate creates more network traffic in preparing and executing a query that a direct JDBC call?? That might explain the difference.

Brent

No. Enable Hibernate SQL logging, logging of prepared statements and various other logs to find your problem. We can't help you by guessing.

http://www.hibernate.org/27.html#A6

Christian,

It looks like Hibernate is creating a new prepared statement for each row that is returned by the original query, then fetching that row, then closing the statement, and then reopening another statement, fetching another row, closing the statement, etc.

Is that normal? It certainly would create a lot of network traffic. What settings could I change to fix it?

Thanks, Brent

10:33:42,234 DEBUG SessionImpl:413 - opened session
10:33:42,234 DEBUG SessionImpl:1392 - iterate: select cnam from com.kihost.upsscs.cmedi.model.Cnam as cnam
10:33:42,234 DEBUG QueryTranslator:144 - compiling query
10:33:42,250 DEBUG SessionImpl:2011 - flushing session
10:33:42,250 DEBUG SessionImpl:2113 - Flushing entities and processing referenced collections
10:33:42,250 DEBUG SessionImpl:2397 - Processing unreferenced collections
10:33:42,250 DEBUG SessionImpl:2408 - Scheduling collection removes/(re)creates/updates
10:33:42,250 DEBUG SessionImpl:2023 - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
10:33:42,250 DEBUG SessionImpl:2028 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
10:33:42,250 DEBUG SessionImpl:1573 - Dont need to execute flush
10:33:42,250 DEBUG QueryTranslator:200 - HQL: select cnam from com.kihost.upsscs.cmedi.model.Cnam as cnam
10:33:42,265 DEBUG QueryTranslator:201 - SQL: select cnam0_.cnam as x0_0_ from x_cnam cnam0_
10:33:42,265 DEBUG BatcherImpl:166 - about to open: 0 open PreparedStatements, 0 open ResultSets

10:33:43,593 DEBUG SessionFactoryImpl:526 - prepared statement get: select cnam0_.cnam as x0_0_ from x_cnam cnam0_
Hibernate: select cnam0_.cnam as x0_0_ from x_cnam cnam0_
10:33:43,609 DEBUG SessionFactoryImpl:536 - preparing statement

10:33:45,109 DEBUG IteratorImpl:54 - retrieving next results
10:33:45,125 DEBUG StringType:65 - returning '0033055' as column: x0_0_
10:33:45,125 DEBUG SessionImpl:1752 - loading [com.kihost.upsscs.cmedi.model.Cnam#0033055]
10:33:45,125 DEBUG SessionImpl:1843 - attempting to resolve [com.kihost.upsscs.cmedi.model.Cnam#0033055]
10:33:45,125 DEBUG SessionImpl:1887 - object not resolved in any cache [com.kihost.upsscs.cmedi.model.Cnam#0033055]
10:33:45,125 DEBUG EntityPersister:394 - Materializing entity: com.kihost.upsscs.cmedi.model.Cnam#0033055
10:33:45,125 DEBUG BatcherImpl:166 - about to open: 1 open PreparedStatements, 1 open ResultSets
10:33:45,125 DEBUG SessionFactoryImpl:526 - prepared statement get: select cnam0_.cnam as cnam, cnam0_.description as descript2_ from x_cnam cnam0_ where cnam0_.cnam=?
Hibernate: select cnam0_.cnam as cnam, cnam0_.description as descript2_ from x_cnam cnam0_ where cnam0_.cnam=?
10:33:45,125 DEBUG SessionFactoryImpl:536 - preparing statement
10:33:45,437 DEBUG StringType:44 - binding '0033055' to parameter: 1
10:33:46,406 DEBUG Loader:148 - processing result set
10:33:46,406 DEBUG Loader:260 - result row: 0033055
10:33:46,406 DEBUG Loader:357 - Initializing object from ResultSet: 0033055
10:33:46,406 DEBUG Loader:413 - Hydrating entity: com.kihost.upsscs.cmedi.model.Cnam#0033055
10:33:46,406 DEBUG StringType:65 - returning 'Apple COM' as column: descript2_
10:33:46,765 DEBUG Loader:182 - done processing result set (1 rows)
10:33:46,765 DEBUG BatcherImpl:173 - done closing: 1 open PreparedStatements, 1 open ResultSets
10:33:46,765 DEBUG SessionFactoryImpl:554 - closing statement
10:33:47,062 DEBUG Loader:195 - total objects hydrated: 1

10:33:47,062 DEBUG SessionImpl:1954 - resolving associations for [com.kihost.upsscs.cmedi.model.Cnam#0033055]
10:33:47,062 DEBUG SessionImpl:1975 - done materializing entity [com.kihost.upsscs.cmedi.model.Cnam#0033055]
10:33:47,062 DEBUG IteratorImpl:54 - retrieving next results
10:33:47,062 DEBUG StringType:65 - returning '0050334' as column: x0_0_
10:33:47,062 DEBUG SessionImpl:1752 - loading [com.kihost.upsscs.cmedi.model.Cnam#0050334]
10:33:47,078 DEBUG SessionImpl:1843 - attempting to resolve [com.kihost.upsscs.cmedi.model.Cnam#0050334]
10:33:47,078 DEBUG SessionImpl:1887 - object not resolved in any cache [com.kihost.upsscs.cmedi.model.Cnam#0050334]
10:33:47,078 DEBUG EntityPersister:394 - Materializing entity: com.kihost.upsscs.cmedi.model.Cnam#0050334
10:33:47,078 DEBUG BatcherImpl:166 - about to open: 1 open PreparedStatements, 1 open ResultSets
10:33:47,078 DEBUG SessionFactoryImpl:526 - prepared statement get: select cnam0_.cnam as cnam, cnam0_.description as descript2_ from x_cnam cnam0_ where cnam0_.cnam=?
Hibernate: select cnam0_.cnam as cnam, cnam0_.description as descript2_ from x_cnam cnam0_ where cnam0_.cnam=?
10:33:47,078 DEBUG SessionFactoryImpl:536 - preparing statement
10:33:47,500 DEBUG StringType:44 - binding '0050334' to parameter: 1
10:33:48,671 DEBUG Loader:148 - processing result set
10:33:48,671 DEBUG Loader:260 - result row: 0050334
10:33:48,687 DEBUG Loader:357 - Initializing object from ResultSet: 0050334
10:33:48,687 DEBUG Loader:413 - Hydrating entity: com.kihost.upsscs.cmedi.model.Cnam#0050334
10:33:48,687 DEBUG StringType:65 - returning 'Apple CO' as column: descript2_
10:33:49,093 DEBUG Loader:182 - done processing result set (1 rows)
10:33:49,093 DEBUG BatcherImpl:173 - done closing: 1 open PreparedStatements, 1 open ResultSets
10:33:49,093 DEBUG SessionFactoryImpl:554 - closing statement
10:33:49,484 DEBUG Loader:195 - total objects hydrated: 1

There are many ways to prevent this n+1 selects problem, for example, you can fetch this collection using outer joins. Instead of us guessing what your problem might be, please read and follow this advice:

http://www.hibernate.org/ForumMailingli ... AskForHelp

Also note that you should be using a connection pool that implements prepared statement caching. (eg. an appserver datasource)

Christian,

The strange thing is, there is no join. Where is the n+1 business coming from? I can't imagine that you would want this to be your default behavior.

Gavin, I will look at the connect pool in Tomcat to see about making it cache the statements.


You can't get much simpler than this table:

SQL> desc X_CNAM
Name Null? Type
----------------------------------------- -------- ----------------
CNAM NOT NULL VARCHAR2(12)
DESCRIPTION VARCHAR2(255)

And the query is also very simple:

String thequery = "select cnam from "
+ " com.kihost.upsscs.cmedi.model.Cnam"
+ " as cnam ";


This is the mapping:

<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
"-//Hibernate/Hibernate Mapping DTD//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd">

<hibernate-mapping>

<class name="com.kihost.upsscs.cmedi.model.Cnam" table="x_cnam">

<id
name="cnam"
column="cnam"
type="java.lang.String"
length="12"
>
<generator class="assigned">
</generator>
</id>


<property
name="description"
type="java.lang.String"
column="description"
/>

</class>

</hibernate-mapping>
<!-- parsed in 0ms -->

and this is the class:

package com.kihost.upsscs.cmedi.model;

public class Cnam {

private String cnam;
private String description;


public Cnam () {}

public Cnam (String cnam,
String description) {
this.cnam = cnam;
this.description = description;
}
public String getCnam() {
return cnam;
}

public String getDescription() {
return description;
}

public void setCnam(String string) {
cnam = string;
}

public void setDescription(String string) {
description = string;
}

}

Any thoughts?


Brent

How do your code for accessing the objects look like ?

Are you using iterate() ?