Skip to Main Content
  • Questions

  • Fetching the result of a select very slow using jdbc

Breadcrumb

Question and Answer

Tom Kyte

Thanks for the question, Olivier.

Asked: April 13, 2011 - 11:42 am UTC

Last updated: January 21, 2013 - 7:37 am UTC

Version: 10.2.0

Viewed 10K+ times! This question is

You Asked

Hi Tom,

Oracle Version: 10gR2
JDBC-Driver Version: 10.2.0.4.0
Java Version: 1.6.0_14
used driver: ojdbc14.jar

I have the following behavior i can't explain.
I need more than 2'30'' to read 908 lines from a java ResultSet. The ResultSet fetch size is set by 500. the ResultSet Type is the default one(TYPE_FORWARD_ONLY).

the sql request needs nearly 130 seconds to be executed.

the table contains nearly 7.6 Mio entries, the attr Column is a string one.

The time logs
15:42:43,760 - prepareQuery SELECT id  FROM table1 WHERE ((UPPER(table1.attr) LIKE UPPER('%22725_5%'))) ORDER BY table1.id ASC
15:42:43,761 - Fetch ids.
15:44:57,696 - Finished pure sql.
15:44:57,696 - Start fetching of ids.
15:47:25,370 - finished fetching of ids.


hier the code in java:
cnx = requestConnection(); /* get a free connection from a connection pool */
stmt = prepareQuery( *** ); 
configureStatement( stmt );
logger.info( "Fetch ids." ); 
rs = stmt.executeQuery();
logger.info( "Finished pure sql." );
if( job != null )
job.setIndeterminate( false );
1641 
IntList idList = new IntList();
logger.info( "Start fetching of ids." );
if( limit > 0 )
{
      while( rs.next() )
      {
   idList.add( rs.getInt( 1 ) );
      }
}
logger.info( "finished fetching of ids." );


I am asking if the first call of rs.next() triggers a new computation a the select.

The id column is indexed.

Do you have some hints for me to evaluate this problem or any idea about their origin?

Thanks,

Olivier

and Tom said...

one wonders "why" you need upper when the text is all numbers?

I would guess that it takes 2.5 minutes on your system to full scan 7.6 million of your records.


Think about it - you are using a where clause:


WHERE ((UPPER(table1.attr) LIKE UPPER('%22725_5%')))


that is going to full scan - an index on any column would be "not useful".

I think you may need to reset your expectations on this one - you are using % on the leading and trailing edge, you are using upper() on the column, you are doing that like and upper call 7.6 million times - all while full scanning the table. I'm guessing that you are waiting for IO to complete.


Use dbms_monitor.session_trace_enable( waits => true ) and run your SQL (just using SQLPlus - don't even need java!) and you'll see what it is doing and what it is waiting on.

It'll be physical IO.

Rating

  (3 ratings)

Is this answer out of date? If it is, please let us know via a Comment

Comments

Read Java ResultSet

A reader, April 13, 2011 - 5:16 pm UTC

First of all thanks for your response.

The Upper of the text part is due to the application level that permit to search anything in any char column. we didn't put any optimization to remove the upper in the few cases where it would improve the request performance.

Tests done shown us that the difference with and without upper didn't mae the difference.

But i think i didn't formulate my question correctly. The time for the select is as given, it is slow, but ok.

My question was why does the the loop to read the result set takes that long time (only 908 line containing one int).

Thats the way i expect the jdbc driver works:
doing the statement.execute() runs the sql request and gives back a cursor that will be read using the resultset object in java, so the whole computing part should have been done calling the execute method, the resultset.next should only be a read access to the result of the sql request and be fast.

am i that wrong?

Olivier
Tom Kyte
April 13, 2011 - 6:14 pm UTC

Tests done shown us that the difference with and without upper didn't mae the difference.


it doesn't help, but yes - you'll find the MAJOR time is spent on IO.


My question was why does the the loop to read the result set takes that long time (only 908 line containing one int).


because the first fetch will be the fetch that actually executes the query. For this particular query, which I guess the plan is:

1 sort order by
2 full scan

the first row will take a long time - and the rest of the rows will fly out of there really fast - but only because the first row got ALL of the rows.

we do a deferred execute whenever possible - we don't do work until we need to.

I'm seeing the same thing as the orignal questioner, but I still don't understand something...

Doug, January 20, 2013 - 4:24 pm UTC

Thanks for your input above. I'm seeing nearly the exact same behaviour as the orignal author. The database is nearly 20GB, and I'm getting 3200 rows from it. The query is very fast, but ResultSet is very, very, very slow. Several minutes, in fact.
There are two things that I don't understand: 1. When I execute the exact same SELECT query in a terminal window, the answer is back in seconds. This experiment (I think) shows that the problem is real, and it really is with ResultSet. I'm guessing we need to configure something, but I have no idea what.....

Thanks,

Tom Kyte
January 21, 2013 - 7:34 am UTC

the query isn't executed until you start fetching, the query "isn't fast and result set is slow"

it is that the query takes a long time to complete - period. preparing and executing a select doesn't actually materialize a result set anywhere - it just gets us ready to start fetching data - the first fetch is the thing that actually "does work".


1) do you wait for the last row to be fetched here. have you traced it and used tkprof to see how long it takes in the database?

I have a feeling you are seeing the first rows come back in the terminal but not waiting for last row to come back... The query in the terminal takes a long time too - you just never complete it.


oops

Doug, January 20, 2013 - 4:28 pm UTC

And the second confusing thing is: subsequent SELECTs on the exact same data respond much more quickly than the first SELECT, even if I restart the program that is running the JDBC (but other SELECTs take just as long the first time they are run)
Tom Kyte
January 21, 2013 - 7:37 am UTC

oh, then it is a buffer cache thing.

first time you run it, nothing in cache.
second time you run it, lots in the cache.

use dbms_monitor.session_trace_enable( waits => true ) to trace your session the first time, tkprof the results and you'll see lots of IO based waits.

run again and they'll have gone.
more

Connor and Chris don't just spend all day on AskTOM. You can also catch regular content via Connor's blog and Chris's blog. Or if video is more your thing, check out Connor's channel and Chris's channel from their Youtube channels. And of course, keep up to date with AskTOM via the official twitter account.

More to Explore

PL/SQL demos

Check out more PL/SQL tutorials on our LiveSQL tool.

PL/SQL docs

PL/SQL reference manual from the Oracle documentation library