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.
