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 Fri, 18 Apr 2008 15:57:50 GMT

Hello,

Thanks for the pointer, it is the same problem !
Insertion of the correct index=xx in the prepared statement via the
--DERBY-PROPERTIES
fixes the problem. The preparedstatement will see the same number of rows
and have the
same performance as the (unprepared)statement.

Now that the workaround is known we should maybe raise the level of the
question a bit.
There are only 3 indices in my example of which one is bad=all keys are
similar and yet the prepared statement algorithm chooses this index while
the unprepared does not. Is this a freak incident
or a systematic problem that needs looking at? I have quite a large number
of preparedstatements
in my codebase and my assumption has always been that the preparedstatement
can do a better
job than the unprepared statement. Or is the prepared statement a simple
convenience utility
that save programmers from implementing a simple macro substitution at the
expense of performance? In short, should I rewrite all my preparedstatments
into statements for Derby or
can I be reasonably sure that it will do the right thing?

Thank you all for your help and interest.




Kristian Waagan-4 wrote:
> 
> DerbyNovice skrev:
>> Hi,
>>
>> Sorry to nag you, but do you think you could please have a look a my
>> small test demonstrating the problem?
>>   
> Hello,
> 
> I'm wondering if you are seeing the same problem as described in
> DERBY-2572.
> (https://issues.apache.org/jira/browse/DERBY-2752)
> 
> Can you have a look?
> At least one workaround is mentioned, and it would be nice if you could 
> add a comment there saying you are facing the same problem.
> 
> 
> regards,
> -- 
> Kristian
> 
>> 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-tp16537511p16763534.html
Sent from the Apache Derby Users mailing list archive at Nabble.com.


Mime
View raw message