db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Bergquist, Brett" <BBergqu...@canoga.com>
Subject Why is a very bad query plan being chosen and why did it change from good to bad?
Date Fri, 23 Mar 2012 22:04:29 GMT
Okay, I have in fact hit a problem that I think is Derby related that I need some input on
where to look.  

While looking at syscs_diag.transaction table, I saw one of the queries that needs to be performed.
  So on a whim, I ran this same query in SquirrelSQL and took a look at the query execution
plan.  The query returns exactly 1 row.

There is an index on CORE_V1.CONFIGURATION_BUNDLE.BUNDLE_NAME.  
CORE_V1.CONFIGURATION_SET.ID is the primary key.   
CORE_V1.CONFIGURATIONSET_CONFIGURATIONBUNDLE has a primary key of (CONFIGURATIONSET_ID, CONFIGURATIONBUNDLE_ID).
CORE_V1.CONFIGURATION_BUNDLE.ID is the primary key.
 
Here is the query plan:

Statement Name: 
	SQL_CURLH000C2
Statement Text: 
	SELECT CB.ID FROM PKG_9145E_V1.CONFIGURATION_SET CS JOIN CORE_V1.CONFIGURATIONSET_CONFIGURATIONBUNDLE
CSCB ON CSCB.CONFIGURATIONSET_ID = CS.ID JOIN CORE_V1.CONFIGURATION_BUNDLE CB ON CB.ID = CSCB.CONFIGURATIONBUNDLE_ID
AND CB.BUNDLE_NAME = 'SOAM_SYSTEM_CFG' AND CS.ID = 898103
Parse Time: 0
Bind Time: 0
Optimize Time: 0
Generate Time: 0
Compile Time: 0
Execute Time: 0
Begin Compilation Timestamp : null
End Compilation Timestamp : null
Begin Execution Timestamp : null
End Execution Timestamp : null
Statement Execution Plan Text: 
Project-Restrict ResultSet (7):
Number of opens = 1
Rows seen = 1
Rows filtered = 0
restriction = false
projection = true
	constructor time (milliseconds) = 0
	open time (milliseconds) = 0
	next time (milliseconds) = 0
	close time (milliseconds) = 0
	restriction time (milliseconds) = 0
	projection time (milliseconds) = 0
	optimizer estimated row count: 19561.00
	optimizer estimated cost: 206733.70
Source result set:
	Nested Loop Exists Join ResultSet:
	Number of opens = 1
	Rows seen from the left = 436409
	Rows seen from the right = 1
	Rows filtered = 0
	Rows returned = 1
		constructor time (milliseconds) = 0
		open time (milliseconds) = 0
		next time (milliseconds) = 0
		close time (milliseconds) = 0
		optimizer estimated row count: 19561.00
		optimizer estimated cost: 206733.70
	Left result set:
		Nested Loop Join ResultSet:
		Number of opens = 1
		Rows seen from the left = 1
		Rows seen from the right = 436409
		Rows filtered = 0
		Rows returned = 436409
			constructor time (milliseconds) = 0
			open time (milliseconds) = 0
			next time (milliseconds) = 0
			close time (milliseconds) = 0
			optimizer estimated row count: 19561.00
			optimizer estimated cost: 53033.14
		Left result set:
			Index Scan ResultSet for CONFIGURATION_SET using constraint SQL081029110511950 at read
committed isolation level using share row locking chosen by the optimizer
			Number of opens = 1
			Rows seen = 1
			Rows filtered = 0
			Fetch Size = 1
				constructor time (milliseconds) = 0
				open time (milliseconds) = 0
				next time (milliseconds) = 0
				close time (milliseconds) = 0
				next time in milliseconds/row = 0

			scan information:
				Bit set of columns fetched={0}
				Number of columns fetched=1
				Number of deleted rows visited=0
				Number of pages visited=3
				Number of rows qualified=1
				Number of rows visited=1
				Scan type=btree
				Tree height=3
				start position:
					>= on first 1 column(s).
					Ordered null semantics on the following columns: 
					0 
				stop position:
					> on first 1 column(s).
					Ordered null semantics on the following columns: 
					0 
				qualifiers:
					None
				optimizer estimated row count: 1.00
				optimizer estimated cost: 4.71
		Right result set:
			Index Row to Base Row ResultSet for CONFIGURATION_BUNDLE:
			Number of opens = 1
			Rows seen = 436409
			Columns accessed from heap = {2, 3}
				constructor time (milliseconds) = 0
				open time (milliseconds) = 0
				next time (milliseconds) = 0
				close time (milliseconds) = 0
				optimizer estimated row count: 19561.00
				optimizer estimated cost: 53028.43
				Index Scan ResultSet for CONFIGURATION_BUNDLE using index CONFIGURATION_BUNDLE_IX_2 at
read committed isolation level using instantaneous share row locking chosen by the optimizer
				Number of opens = 1
				Rows seen = 436409
				Rows filtered = 0
				Fetch Size = 16
					constructor time (milliseconds) = 0
					open time (milliseconds) = 0
					next time (milliseconds) = 0
					close time (milliseconds) = 0
					next time in milliseconds/row = 0

				scan information:
					Bit set of columns fetched=All
					Number of columns fetched=2
					Number of deleted rows visited=193
					Number of pages visited=3979
					Number of rows qualified=436409
					Number of rows visited=436603
					Scan type=btree
					Tree height=5
					start position:
						>= on first 1 column(s).
						Ordered null semantics on the following columns: 
						0 
					stop position:
						> on first 1 column(s).
						Ordered null semantics on the following columns: 
						0 
					qualifiers:
						None
					optimizer estimated row count: 19561.00
					optimizer estimated cost: 53028.43


	Right result set:
		Index Scan ResultSet for CONFIGURATIONSET_CONFIGURATIONBUNDLE using constraint CONFIGURATIONSET_CONFIGURATIONBUNDLE_PK
at read committed isolation level using share row locking chosen by the optimizer
		Number of opens = 436409
		Rows seen = 1
		Rows filtered = 0
		Fetch Size = 1
			constructor time (milliseconds) = 0
			open time (milliseconds) = 0
			next time (milliseconds) = 0
			close time (milliseconds) = 0
			next time in milliseconds/row = 0

		scan information:
			Bit set of columns fetched={0, 1}
			Number of columns fetched=2
			Number of deleted rows visited=0
			Number of pages visited=2186202
			Number of rows qualified=1
			Number of rows visited=436409
			Scan type=btree
			Tree height=5
			start position:
				>= on first 2 column(s).
				Ordered null semantics on the following columns: 
				0 1 
			stop position:
				> on first 2 column(s).
				Ordered null semantics on the following columns: 
				0 1 
			qualifiers:
				None
			optimizer estimated row count: 19561.00
			optimizer estimated cost: 153700.56

It seems the optimizer decided to choose retrieve the CORE_V1.CONFIGURATION_BUNDLE table,
filter out the rows that matched the constraint (436409), and then joined that with the other
tables.   

If it had chosen to retrieve the CORE_V1.CONFIGURATION_SET table first with the constraint,
it would have returned 1 row, joined this with the CORE_V1.CONFIGURATIONSET_CONFIGURATIONBUNDLE
table which would have produced about 60 rows, and then joined with the CORE_V1.CONFIGURATION_BUNDLE
table to produce 60 rows which then would have been filtered by the constrain to 1 row, this
would have come back nearly instantaneously.   

The funny thing is, the optimizer was choosing the optimal query plan for a while today. 
And then I went to test a bit more and everything stopped and I found this.  Ouch that the
query plan changed.   More rows were added to all of the tables today.

Note that I am running 10.8.2.2 and do have the IndexStats daemon enabled.  

So any idea why the query plan would change to a non-optimal one?  I almost think I should
drop the index on CORE_V1.CONFIGURATION_BUNDLE.BUNDLE_NAME so that it will not attempt to
use this index in the optimizer...

Brett


Mime
View raw message