db-derby-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Anthony Bargnesi" <abargn...@selventa.com>
Subject Explanation of "Compile Time" metric in Runtime Statistics
Date Thu, 24 Feb 2011 18:47:54 GMT
Hello Derby community,

It is stated in the latest 10.7 tuning documentation that a connection 
only needs to compile a PreparedStatement once, however the runtime 
statistics's "Compile Time" remains static.  The following is a JRuby 
script that shows PreparedStatement usage:

....
connection.createStatement().executeUpdate("CALL 
SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('derby.language.logStatementText', 'true')")
connection.createStatement().executeUpdate("CALL 
SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('derby.language.logQueryPlan', 
'true')")
connection.createStatement().executeUpdate("CALL 
SYSCS_UTIL.SYSCS_SET_RUNTIMESTATISTICS(1)")
connection.createStatement().executeUpdate("CALL 
SYSCS_UTIL.SYSCS_SET_STATISTICS_TIMING(1)")

#compile
ps = connection.prepareStatement("select * from \"APP\".\"kam_edge\" ke, 
\"APP\".\"object\" o1, \"APP\".\"object\" o2 where 
ke.\"kam_node_source_id\" = o1.\"object_id\" and 
ke.\"kam_node_target_id\" = o2.\"object_id\" and 
ke.\"type_abbreviation_oid\" = ?");

#first query
ps.setInt 1, 400000
rs = ps.executeQuery
while rs.next
   puts rs.getString "kam_edge_id"
end
rs.close

rs = connection.createStatement().executeQuery("VALUES 
SYSCS_UTIL.SYSCS_GET_RUNTIMESTATISTICS()")
while rs.next
   puts rs.getString 1
end
rs.close


#second query
ps.setInt 1, 5230012
rs = ps.executeQuery
while rs.next
   puts rs.getString "kam_edge_id"
end
rs.close
rs = connection.createStatement().executeQuery("VALUES 
SYSCS_UTIL.SYSCS_GET_RUNTIMESTATISTICS()")
while rs.next
   puts rs.getString 1
end
rs.close


The runtime statistics yields the following output for statement 1 
(first prepared statement compile) and statement 2 (same prepared 
statement executed again with different parameter):

Statement Name:
     SQL_CURLH000C5
Statement Text:
     select * from "APP"."kam_edge" ke, "APP"."object" o1, 
"APP"."object" o2 where ke."kam_node_source_id" = o1."object_id" and 
ke."kam_node_target_id" = o2."object_id" and ke."type_abbreviation_oid" = ?
Parse Time: 16
Bind Time: 11
Optimize Time: 49
Generate Time: 9
Compile Time: 85
Execute Time: 2
Begin Compilation Timestamp : 2011-02-24 13:09:50.816
End Compilation Timestamp : 2011-02-24 13:09:50.901
Begin Execution Timestamp : 2011-02-24 13:09:59.499
End Execution Timestamp : 2011-02-24 13:09:59.502

Statement Name:
     SQL_CURLH000C5
Statement Text:
     select * from "APP"."kam_edge" ke, "APP"."object" o1, 
"APP"."object" o2 where ke."kam_node_source_id" = o1."object_id" and 
ke."kam_node_target_id" = o2."object_id" and ke."type_abbreviation_oid" = ?
Parse Time: 16
Bind Time: 11
Optimize Time: 49
Generate Time: 9
Compile Time: 85
Execute Time: 3
Begin Compilation Timestamp : 2011-02-24 13:09:50.816
End Compilation Timestamp : 2011-02-24 13:09:50.901
Begin Execution Timestamp : 2011-02-24 13:09:59.499
End Execution Timestamp : 2011-02-24 13:09:59.536


The cost of compiling statement 2 is the same as statement 1.  Am I 
interpreting the statistics incorrectly?

-- 

Anthony Bargnesi
Senior Engineer
Selventa | T: 617.547.5421 x216

Please note that our email and website addresses have changed

Mime
View raw message