[
https://issues.apache.org/jira/browse/DERBY-5066?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
George Xu updated DERBY-5066:
-----------------------------
1) Indeed, the number of rows is much less in the execution plan because I used
a smaller case to generate the plan.
2) It is true that I did not do fetch. As the result is pretty sometimes (up
to 500k or 1000k for example), the app never expects an user to fetch all rows.
We page first 2000 rows actually. I assume that the "executeQuery" would only
compile the plan and return the pointer to the first row. However, this does
not look like the case in Derby. I run in IJ, in both cases, there is such a
long delay before the rows sart to move.
3) The code is a complete snipplet that we are return the first row, and then
it is up to the user to page the resultset.
4) The reason the I had "PID > 0" is represent a case when a user entered a
zero in UI, than made the sql look like that. It is expected the "PID >0" can
cause full table scan because all PID is bigger than zero, however, the full
table scan shall not happen when the fetch start...not do the actual full table
scan.
I tried the following code and it did not help
CallableStatement cs2 = con.prepareCall("CALL
SYSCS_UTIL.SYSCS_COMPRESS_TABLE(?,?,?)");
cs2.setString(1, "APP");
cs2.setString(2, "LOGDATA871218");
cs2.setShort(3, (short) 1);
cs.execute();
The new plan looks like this
Statement Text:
SELECT TIMESTAMP, HOSTPORT AS "HOST ID", PID, SESSIONID, REQUESTID,
SUBREQUESTID, STEPID, TID, COMPONENT, BUILDNUM, LOGLEVELORIG AS "LEVEL",
LOGGER, OPERATION, OBJECTTYPE, OBJECTPATH, STATUS, MESSAGE, DATA, NDX FROM
LOGDATA786780 WHERE PID > 0 ORDER BY PID
Parse Time: 93
Bind Time: 16
Optimize Time: 62
Generate Time: 16
Compile Time: 187
Execute Time: 4750
Begin Compilation Timestamp : 2011-02-24 17:58:27.071
End Compilation Timestamp : 2011-02-24 17:58:27.258
Begin Execution Timestamp : 2011-02-24 17:58:27.258
End Execution Timestamp : 2011-02-24 17:58:32.117
Statement Execution Plan Text:
Sort ResultSet:
Number of opens = 1
Rows input = 69612
Rows returned = 0
Eliminate duplicates = false
In sorted order = false
Sort information:
Number of merge runs=38
Number of rows input=69612
Number of rows output=69612
Size of merge runs=[1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791,
1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791,
1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791, 1791,
1791, 1791, 1791, 1791]
Sort type=external
constructor time (milliseconds) = 0
open time (milliseconds) = 4750
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 22153.56
optimizer estimated cost: 230567.20
Source result set:
Project-Restrict ResultSet (2):
Number of opens = 1
Rows seen = 69612
Rows filtered = 0
restriction = false
projection = true
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 672
close time (milliseconds) = 16
restriction time (milliseconds) = 0
projection time (milliseconds) = 16
optimizer estimated row count: 22153.56
optimizer estimated cost: 230567.20
Source result set:
Table Scan ResultSet for LOGDATA786780 at read committed
isolation level using instantaneous share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 69612
Rows filtered = 0
Fetch Size = 16
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 656
close time (milliseconds) = 16
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched={0, 8, 9, 10, 11, 13, 14,
16, 17, 18, 19, 21, 22, 23, 24, 25, 26, 27, 28}
Number of columns fetched=19
Number of pages visited=1608
Number of rows qualified=69612
Number of rows visited=69612
Scan type=heap
start position:
null
stop position:
null
qualifiers:
Column[0][0] Id: 9
Operator: <=
Ordered nulls: false
Unknown return value: true
Negate comparison result: true
optimizer estimated row count: 22153.56
optimizer estimated cost: 230567.20
> full table scan when index is used, taking extremely long time in JDBC
> ----------------------------------------------------------------------
>
> Key: DERBY-5066
> URL: https://issues.apache.org/jira/browse/DERBY-5066
> Project: Derby
> Issue Type: Bug
> Components: Eclipse Plug-in, JDBC
> Affects Versions: 10.7.1.1
> Environment: Windows XP environment
> Reporter: George Xu
>
> When a very large table (500k rows) is used with a column is indexed.
> select * from tab where pid > 0 order by pid takes extremely longer time than
> select * from tab order by pid. Actually, it is 100 times slower. However,
> in IJ, ther performance seems to be similar. PID column is indexed.
> Here is the code snipplet
> import java.sql.Connection;
> import java.sql.DriverManager;
> import java.sql.ResultSet;
> import java.sql.SQLException;
> import java.sql.Statement;
> public class TestPerformance {
> //20343 mill-sec
> static String s1 = "SELECT TIMESTAMP, HOSTPORT AS \"HOST ID\", PID,
> SESSIONID, REQUESTID, " +
> "SUBREQUESTID, STEPID, TID, COMPONENT, BUILDNUM, " +
> "LOGLEVELORIG AS \"LEVEL\", LOGGER, OPERATION, OBJECTTYPE, OBJECTPATH,
> " +
> "STATUS, MESSAGE, DATA, NDX FROM LOGDATA871218 where PID > 0 ORDER BY
> PID";
> //297 million sec.
> static String s2 = "SELECT TIMESTAMP, HOSTPORT AS \"HOST ID\", PID,
> SESSIONID, REQUESTID, " +
> "SUBREQUESTID, STEPID, TID, COMPONENT, BUILDNUM, " +
> "LOGLEVELORIG AS \"LEVEL\", LOGGER, OPERATION, OBJECTTYPE, OBJECTPATH,
> " +
> "STATUS, MESSAGE, DATA, NDX FROM LOGDATA871218 ORDER BY PID";
> public static void main(String[] args) throws InstantiationException,
> IllegalAccessException, ClassNotFoundException {
> Statement stmt3;
> try {
>
> //connect'jdbc:derby:C:/devroot/runtime-New_configuration/LogXData';
> String db =
> "C:/devroot/runtime-New_configuration/LogXData";
> String driver = "org.apache.derby.jdbc.EmbeddedDriver";
> Class.forName(driver).newInstance();
> Connection con =
> DriverManager.getConnection("jdbc:derby:"+db);
> stmt3 = con.createStatement(ResultSet.FETCH_FORWARD,
> ResultSet.TYPE_FORWARD_ONLY);
> long startTime3 = System.currentTimeMillis();
> ResultSet rs3 = stmt3.executeQuery(s1);
> long elapsed3 = System.currentTimeMillis() - startTime3;
> System.out.println("Statment.executeQuery Dup: " +
> elapsed3);
> } catch (SQLException e) {
> // TODO Auto-generated catch block
> e.printStackTrace();
> }
> }
> }
--
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
