db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "George Xu (JIRA)" <j...@apache.org>
Subject [jira] Updated: (DERBY-5066) full table scan when index is used, taking extremely long time in JDBC
Date Thu, 24 Feb 2011 21:21:38 GMT

     [ https://issues.apache.org/jira/browse/DERBY-5066?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

George Xu updated DERBY-5066:
-----------------------------


Additional information with the execution plan... the full table scan happened.
==========================================================
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: 94
Bind Time: 31
Optimize Time: 63
Generate Time: 15
Compile Time: 203
Execute Time: 4937
Begin Compilation Timestamp : 2011-02-24 16:14:04.895
End Compilation Timestamp :   2011-02-24 16:14:05.098
Begin Execution Timestamp :   2011-02-24 16:14:05.114
End Execution Timestamp :     2011-02-24 16:14:12.411
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) = 4937
	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) = 842
		close time (milliseconds) = 32
		restriction time (milliseconds) = 0
		projection time (milliseconds) = 0
		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) = 827
			close time (milliseconds) = 32
			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

        

Mime
View raw message