Why is the prepared statement slower than the unprepared statement?
BACKGROUND
----------
DB as follows:
CREATE TABLE "SA"."UDEVENTDATA"
(
"ID" VARCHAR(100) NOT NULL,
"DOMAINKEYID" VARCHAR(100),
"CREATIONTIME" BIGINT NOT NULL,
"NAME" VARCHAR(32672),
*** AND MORE COLUMNS NOT USED IN THIS
EXAMPLE ****
);
with indices :
CREATE INDEX "SA"."UDSOFTOBJECTDATA_CREATIONTIME_IDX_UDEVENTDATA" ON
"SA"."UDEVENTDATA" ("CREATIONTIME");
CREATE INDEX "SA"."UDSOFTOBJECTDATA_DOMAINKEY_IDX_UDEVENTDATA" ON
"SA"."UDEVENTDATA" ("DOMAINKEYID");
CREATE INDEX "SA"."UDSOFTOBJECTDATA_NAME_IDX_UDEVENTDATA" ON
"SA"."UDEVENTDATA" ("NAME");
and runs as embedded.
DB contains 46000 records with the following properties
DOMAINKEY are 98% same.
NAMEs are all different.
CREATIONTIME 82% different.
PROBLEM STATEMENT
---------------------------------
ALTERNATIVE 1 uses a PreparedStatement with parameters.
ALTERNATIVE 2 mimics a Statement (and indeed a Statement returns the
same performance)
PreparedStatements (ALTERNATIVE 1) are VERY SLOW because of table scans
BUT Statements (ALTERNATIVE 2) are QUICK.
This can be seen in the NEXT and SELECT debug statements in the output
section.
JAVA CODE
---------
Vector rsv containing Names from the table column NAME.
PreparedStatement ps;
ALTERNATIVE 1 >
>1 ps = conn.prepareStatement("SELECT * From SA.UDEVENTDATA WHERE
DomainKeyId = ? AND CreationTime < ? AND Name > ? ");
< END 1
zize = 10;
beginTiming_ = java.lang.System.currentTimeMillis ();
for( int j=0;j<zize;j++ )
{
String s2 = (String)rsv.elementAt(j) ;
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,
--
View this message in context:
http://www.nabble.com/Statement-PreparedStatement-performance-difference-and-problem-tp16537511p16537511.html
Sent from the Apache Derby Users mailing list archive at Nabble.com.
