Poor Hibernate Select Performance Comparing to Running Directly - How Debug

poor Hibernate select performance comparing to running directly - how debug?

Thank you all for help. After long time of struggling with that issue, finally kaliatech answer helped me to debug the problem.

First of all, I've made a terrible mistake in my quesion. I wrote that:

Running this query with local database is really fast, but using it remotely is really poor.

As it is not completly true. The query which I did in Hibernate looks like the one up:

select s.* from sales_unit s left join sales_unit_relation r on (s.sales_unit_id = r.sales_unit_child_id) where r.sales_unit_child_id is null

But the actual query which I did with SQL PLus or Navicat for example was:

select * from sales_unit s left join sales_unit_relation r on (s.sales_unit_id = r.sales_unit_child_id) where r.sales_unit_child_id is null

Please notice that first query select starts: select s.* ... and second one is select * .... And that was the reason of such poor performance. Now both queries are completed in no time. The question is, what's the difference: performance issue: difference between select s.* vs select *

performance issue: difference between select s.* vs select *

they are two different queries of course. the plan CAN change with the selects being different. i.e. in the sth.* it may be choosing a full/fast full index scan on the left joined table. whereas on the first it will possibly be a full table scan.

in order to help you further, can we see the plans please? preferably do this in SQL*PLUS

set timing on
set autotrace on traceonly

select s.* from sales_unit s left join sales_unit_relation r on (s.sales_unit_id = r.sales_unit_child_id) where r.sales_unit_child_id is null;

select * from sales_unit s left join sales_unit_relation r on (s.sales_unit_id = r.sales_unit_child_id) where r.sales_unit_child_id is null;

EDIT

given your explain plan, you see theres CARDINALITY=1 on every step? you've gathered stats when the tables were empty! see this:

SQL> select s.* from sales_unit s left join sales_unit_relation r on (s.sales_unit_id = r.child_sales_unit_id) where r.child_sales_unit_id is null;

no rows selected

Elapsed: 00:00:03.19

Execution Plan
----------------------------------------------------------
Plan hash value: 1064670292

------------------------------------------------------------------------------------
| Id  | Operation          | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |               |     1 |    48 |    27  (86)| 00:00:01 |
|   1 |  NESTED LOOPS ANTI |               |     1 |    48 |    27  (86)| 00:00:01 |
|   2 |   TABLE ACCESS FULL| SALES_UNIT    |     1 |    35 |     2   (0)| 00:00:01 |
|*  3 |   INDEX RANGE SCAN | SALES_REL_IX1 |     1 |    13 |    25  (92)| 00:00:01 |
------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   3 - access("S"."SALES_UNIT_ID"="R"."CHILD_SALES_UNIT_ID")

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
     200314  consistent gets
       2220  physical reads
          0  redo size
        297  bytes sent via SQL*Net to client
        339  bytes received via SQL*Net from client
          1  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          0  rows processed

so see it used 200314 IO and took a few seconds. Also see ROWS = 1 on every step (i.e the full scans)..lets gather stats:

SQL> begin dbms_stats.gather_table_stats(user, 'SALES_UNIT', degree=>8, cascade=>true); end;
  2  /

PL/SQL procedure successfully completed.

SQL> begin dbms_stats.gather_table_stats(user, 'SALES_UNIT_RELATION', degree=>8, cascade=>true); end;
  2  /

PL/SQL procedure successfully completed.

and now rerun:
SQL> select s.* from sales_unit s left join sales_unit_relation r on (s.sales_unit_id = r.child_sales_unit_id) where r.child_sales_unit_id is null;

no rows selected

Elapsed: 00:00:00.84

Execution Plan
----------------------------------------------------------
Plan hash value: 2005864719

-----------------------------------------------------------------------------------------------
| Id  | Operation             | Name          | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT      |               |   912 | 18240 |       |  1659   (3)| 00:00:20 |
|*  1 |  HASH JOIN ANTI       |               |   912 | 18240 |  2656K|  1659   (3)| 00:00:20 |
|   2 |   TABLE ACCESS FULL   | SALES_UNIT    |   100K|  1472K|       |    88   (3)| 00:00:02 |
|   3 |   INDEX FAST FULL SCAN| SALES_REL_IX1 |   991K|  4841K|       |   618   (3)| 00:00:08 |
-----------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - access("S"."SALES_UNIT_ID"="R"."CHILD_SALES_UNIT_ID")

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
       2537  consistent gets
          0  physical reads
          0  redo size
        297  bytes sent via SQL*Net to client
        339  bytes received via SQL*Net from client
          1  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          0  rows processed

SQL>

now we used 2537 gets only and the plan shows the right ROWS and a HASH join (better for our needs). my test tables are probably smaller than your real ones which is why the timings are closer

Hibernate is so slow on remoted database (Postgresql)

You need configure a conection pool

Reasons: The anatomy of Connection Pooling

For example, you can use C3P0 with Postgresql:

• Example 1
• Example 2

Regards

Spring, JPA (Hibernate) & Ehcache Poor Performance

Main point is, it all looks ok, the only real problem is that it's sooo damn slow.

Damn slow is a subjective measurement unit :)

When I load 3000 objects the first time (ie, hitting the db) it takes pretty much exactly the same as the second time (ie, hitting the cache).

Show metrics, without all the logging overhead (and also without P6Spy), using System.nanoTime()

long startTime = System.nanoTime();
// ... the code being measured ...
long estimatedTime = System.nanoTime() - startTime;

Maybe also try to perform your test inside a single transaction, using a single EntityManager, just to see how things behave in these conditions.

Like I said, is it cos the overhead is opening and closing the connection, flushing the session, dealing with transactions? I'm not sure. But it's pretty brutal at any rate.

Can't say, you should profile your code to see where the time is spent (and also monitor the GC activity).

But in theory:

• The connection in a Session is lazy (will get acquired only when required)
• Acquiring a connection from C3P0 should be pretty fast (negligible)
• Since your entities are cached as read-only, the flush should be pretty fast

In other words, I wouldn't expect the above operations to be expensive (so I'd focus on the surrounding parts). But as I said, profile (and monitor the GC activity).

---

Related Topics