db-derby-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From DerbyNovice <clars...@ureason.com>
Subject Re: Statement/PreparedStatement performance difference and problem
Date Wed, 16 Apr 2008 16:13:08 GMT

Hi,

Sorry to nag you, but do you think you could please have a look a my
small test demonstrating the problem?

Thanks in advance



Thomas Nielsen - Sun Microsystems - Trondheim, Norway wrote:
> 
> Hi,
> 
> I haven't looked at this in detail, but can you please confirm that the 
> following is correct:
> 
> 1) The query you run in alt. 2 is not identical to alt 1 - there's an 
> extra AND in the WHERE clause, making it an illegal query. Is this just 
> a copy-paste blurp?
> 
> 2) The alt. 2 output of "Statement text" isn't the SELECT but rather a 
> CALL SYSCS_UTIL.SYSCS_SET_STATISTICS_TIMING(1). Is this correct? If so 
> are you comparing the timing of a SELECT to a CALL? Or am I missing 
> something?
> 
> As Knut said, the optimizer sometimes does make bad decisions...
> 
> Cheers,
> Thomas
> 
> DerbyNovice wrote:
> 
>> PROBLEM STATEMENT
>> ---------------------------------
>> ALTERNATIVE 1 uses a PreparedStatement with parameters.
>> ALTERNATIVE 2 mimics a Statement (and indeed a Statement returns the 
>> same performance)
> 
> ...
> 
>> ALTERNATIVE 1 >
>>  >1        ps = conn.prepareStatement("SELECT * From SA.UDEVENTDATA 
>> WHERE
>> DomainKeyId = ? AND CreationTime <  ? AND Name  > ? ");
>> < END 1
> ...
> 
>> ALTERNATIVE 1 >
>>  >1            ps.setString(3,(String)s2);
>>  >1            ps.setString(1,"d46chez0v8cdg-c4m");
>>  >1            ps.setString(2,"1200269947000");
>>  >1
>> < END 1
>>
>> ALTERNATIVE 2 >    
>>  >2                String sels = "SELECT * From SA.UDEVENTDATA  WHERE AND
>> DomainKeyId = 'd46chez0v8cdg-c4m' AND CreationTime <  1200269947000 AND
>> Name 
>>> '"+s2+"'  ";
>>  >2               ps = conn.prepareStatement(sels);
>> < END 2
>>             startStat();
>>             beginTiming_ = java.lang.System.currentTimeMillis ();
>>             rs = ps.executeQuery();
>>             endTiming_ = java.lang.System.currentTimeMillis ();
>>             elapsed = endTiming_ - beginTiming_;
>>             System.out.println( "?#?#? SimpleApp2.java at line: 235
>> Dbg-out
>> variable elapsed SELECT ["+elapsed+"]" );
>>             
>>             count = 0;
>>             beginTiming_ = java.lang.System.currentTimeMillis ();
>>             while(rs.next())
>>                 {
>>                 //do something with the result set
>>                 for( int i= 1; i <= cols ; i++)
>>                     {
>>                     Object o = getData((String)vclass.elementAt(i-1),
>>                                rs,
>>                                i);
>>                     } /* end of for i */
>>                 count++;
>>                 }
>>             endTiming_ = java.lang.System.currentTimeMillis ();
>>             printStat();
>>             elapsed = endTiming_ - beginTiming_;
>>             System.out.println( "LOOP NO "+j );
>>             System.out.println( "?#?#? SimpleApp2.java at line: 235
>> Dbg-out
>> variable elapsed NEXT ["+elapsed+"]" );
>>             System.out.println("Counted "+count+" in resultset");
>>             }
>> 
>> 
>> OUPUT WITH ALTERNATIVE 1
>> ------------------------
>> LOOP NO 0
>> ?#?#? SimpleApp2.java at line: 235 Dbg-out variable elapsed NEXT [3092]
>> Counted 8 in resultset
>> ?#?#? SimpleApp2.java at line: 235 Dbg-out variable elapsed SELECT [41]
>> Query Plan: Statement Name:
>>         null
>> Statement Text:
>>         SELECT * From SA.UDEVENTDATA  WHERE DomainKeyId = ? AND 
>> CreationTime <  ? AND Name  > ?
>> Parse Time: 0
>> Bind Time: 0
>> Optimize Time: 0
>> Generate Time: 0
>> Compile Time: 0
>> Execute Time: 3069
>> Begin Compilation Timestamp : null
>> End Compilation Timestamp : null
>> Begin Execution Timestamp : 2008-04-07 15:50:06.788
>> End Execution Timestamp : 2008-04-07 15:50:09.95
>> Statement Execution Plan Text:
>> Project-Restrict ResultSet (3):
>> Number of opens = 1
>> Rows seen = 46372
>> Rows filtered = 46364
>> restriction = true
>> projection = true
>>         constructor time (milliseconds) = 0
>>         open time (milliseconds) = 1
>>         next time (milliseconds) = 3068
>>         close time (milliseconds) = 0
>>         restriction time (milliseconds) = 117
>>         projection time (milliseconds) = 0
>>         optimizer estimated row count:          505.06
>>         optimizer estimated cost:        56292.47
>> 
>> Source result set:
>>         Index Row to Base Row ResultSet for UDEVENTDATA:
>>         Number of opens = 1
>>         Rows seen = 46372
>>         Columns accessed from heap = {0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 
>> 11, 12, 13, 14, 15, 16, 17, 18, 19, 20}
>>                 constructor time (milliseconds) = 0
>>                 open time (milliseconds) = 1
>>                 next time (milliseconds) = 2751
>>                 close time (milliseconds) = 25
>>                 optimizer estimated row count:          505.06
>>                 optimizer estimated cost:        56292.47
>> 
>>                 Index Scan ResultSet for UDEVENTDATA using index 
>> UDSOFTOBJECTDATA_DOMAINKEY_IDX_UDEVENTDATA at read committed isolation 
>> level using instantaneous share row locking chosen by the optimizer
>>                 Number of opens = 1
>>                 Rows seen = 46372
>>                 Rows filtered = 0
>>                 Fetch Size = 16
>>                         constructor time (milliseconds) = 0
>>                         open time (milliseconds) = 3
>>                         next time (milliseconds) = 417
>>                         close time (milliseconds) = 25
>>                         next time in milliseconds/row = 0
>> 
>>                 scan information:
>>                         Bit set of columns fetched=All
>>                         Number of columns fetched=2
>>                         Number of deleted rows visited=1
>>                         Number of pages visited=424
>>                         Number of rows qualified=46372
>>                         Number of rows visited=46374
>>                         Scan type=btree
>>                         Tree height=3
>>                         start position:
>>         >= on first 1 column(s).
>>         Ordered null semantics on the following columns:
>> 
>>                         stop position:
>>         > on first 1 column(s).
>>         Ordered null semantics on the following columns:
>> 
>>                         qualifiers:
>> None
>>                         optimizer estimated row count:          505.06
>>                         optimizer estimated cost:        56292.47
>> 
>> 
>> 
>> OUPUT WITH ALTERNATIVE 2
>> ------------------------
>> LOOP NO 0
>> ?#?#? SimpleApp2.java at line: 235 Dbg-out variable elapsed NEXT [36]
>> Counted 8 in resultset
>> ?#?#? SimpleApp2.java at line: 235 Dbg-out variable elapsed SELECT [0]
>> Query Plan: Statement Name:
>>         null
>> Statement Text:
>>         CALL SYSCS_UTIL.SYSCS_SET_STATISTICS_TIMING(1)
>> Parse Time: 1
>> Bind Time: 0
>> Optimize Time: 0
>> Generate Time: 3
>> Compile Time: 4
>> Execute Time: -1207579584105
>> Begin Compilation Timestamp : 2008-04-07 15:46:24.1
>> End Compilation Timestamp : 2008-04-07 15:46:24.104
>> Begin Execution Timestamp : 2008-04-07 15:46:24.105
>> End Execution Timestamp : 2008-04-07 15:46:24.105
>> Statement Execution Plan Text:
>> null
>> 
>> 
>> 
>> QUESTION
>> --------
>> 
>> Why cannot the prepared statement figure out how to use the indices when 
>> statements can, i.e. that domainkey should not be scanned ?
>> How can you make the prepared statement use the same execution plan as 
>> the statement so as to return the same type of performance?
>> The problem seems to be Derby specific as MSQL returns adequate 
>> performance for ALT 1.
>> 
>> Thanks in advance,
>> 
>> 
>> 
>> 
>> 
> 
> -- 
> Thomas Nielsen
> 
> 

-- 
View this message in context: http://www.nabble.com/Statement-PreparedStatement-performance-difference-and-problem-tp16537511p16722575.html
Sent from the Apache Derby Users mailing list archive at Nabble.com.


Mime
View raw message