Mike I have a reproducible case but the database is 132GB so it is not practical. I am willing to dig in and try to help debug this. On the issue that was pointed to, Mamta seemed to have used a debug procedure that would print out more information on why the optimizer is choosing what it does. This might be useful in this case as well.
So if someone can point me in the right area of the code to start looking and adding some debug that would be helpful. I have done some fixes for Derby in the past so I am able to build and debug Derby. -----Original Message----- From: Mike Matrigali [mailto:[email protected]] Sent: Thursday, March 28, 2013 5:11 PM To: [email protected] Subject: Re: Why is the optimizer choosing such a bad path On 3/28/2013 6:38 AM, Bergquist, Brett wrote: > I tried adding: > > derby.storage.indexStats.debug.keepDisposableStats=true > > to derby.properties *and* regenerating statistics for the tables. There is > no change in the query plan. > > Does this mean that applying the patches suggested will probably have no > effect either? I think this is correct. The patch should only fix problems where update statistics is run and a bad query plan shows up in base system 10.9, but a good plan results when that flag is enabled and update statistics is run. I think you have always been doing this but always best to run update statistics after data is loaded. At this point hard to say where the problem is. It seems very strange for optimizer to come up with 0 rows for a 62 million row table (or for any table with more than a few rows - lets say 10,000 to be safe). The system has a separate call for the optmizer to get the number of rows that is separate from anything the stats generated by update stats. But it is an estimate maintained by the storage system and the estimate is updated as a by product of running update statistics (or any table scan of the table/index). But it should also be maintained continuously as part of inserts. Best next step would be to somehow get a reproducible case where the optimizer returns 0 row estimate for that big table and track down the call that is giving the bad data. > > -----Original Message----- > From: Bergquist, Brett [mailto:[email protected]] > Sent: Thursday, March 28, 2013 8:52 AM > To: [email protected] > Subject: RE: Why is the optimizer choosing such a bad path > > After dropping and recreating on index: > > DROP INDEX CORE_V1.CONFIGURATION_BUNDLE_IX_1; > CREATE INDEX CONFIGURATION_BUNDLE_IX_1 ON > "CORE_V1"."CONFIGURATION_BUNDLE"(DTYPE); > > And rerunning the query, the optimizer chose that index and the optimizer row > count estimates are no longer 0. > > So it appears that there is something bad with that index that > SYSCS_UTIL.SYSCS_CHECK_TABLE does not see and even > SYSCS_UTIL.SYSCS_DROP_STATISTICS and SYSCS_UTIL.SYSCS_UPDATE_STATISTICS > cannot fix. > > Statement Name: > SQL_CURLH000C2 > Statement Text: > SELECT t0.ID, t0.DTYPE, t0.BUNDLE_NAME, t0.OPLOCK, t1.ID, > t2.ID, t2.LLQ_CONFIG_ENTRY_ID FROM > CORE_V1.CONFIGURATIONSET_CONFIGURATIONBUNDLE t3, > PKG_9145E10G.INGRESS_COS_QUEUE_CONFIG_BUNDLE t2, > PKG_9145E10G.CONFIGURATION_BUNDLE_9145E10G t1, > CORE_V1.CONFIGURATION_BUNDLE t0 WHERE (((t3.CONFIGURATIONSET_ID = > 4000) AND (t0.ID = t3.CONFIGURATIONBUNDLE_ID)) AND (((t2.ID = t0.ID) > AND (t1.ID = t0.ID)) AND (t0.DTYPE = > 'INGRESS_COS_QUEUE_CONFIG_BUNDLE_9145E10G'))) > Parse Time: 5 > Bind Time: 9 > Optimize Time: 133 > Generate Time: 6 > Compile Time: 153 > Execute Time: 35 > Begin Compilation Timestamp : 2013-03-28 08:44:40.901 End Compilation > Timestamp : 2013-03-28 08:44:41.054 Begin Execution Timestamp : 2013-03-28 > 08:44:41.058 End Execution Timestamp : 2013-03-28 08:44:41.094 Statement > Execution Plan Text: > Project-Restrict ResultSet (10): > Number of opens = 1 > Rows seen = 0 > Rows filtered = 0 > restriction = false > projection = true > constructor time (milliseconds) = 0 > open time (milliseconds) = 35 > next time (milliseconds) = 0 > close time (milliseconds) = 0 > restriction time (milliseconds) = 0 > projection time (milliseconds) = 0 > optimizer estimated row count: 2.00 > optimizer estimated cost: 51.52 Source result set: > Nested Loop Exists Join ResultSet: > Number of opens = 1 > Rows seen from the left = 0 > Rows seen from the right = 0 > Rows filtered = 0 > Rows returned = 0 > constructor time (milliseconds) = 0 > open time (milliseconds) = 35 > next time (milliseconds) = 0 > close time (milliseconds) = 1 > optimizer estimated row count: 2.00 > optimizer estimated cost: 51.52 > Left result set: > Nested Loop Exists Join ResultSet: > Number of opens = 1 > Rows seen from the left = 0 > Rows seen from the right = 0 > Rows filtered = 0 > Rows returned = 0 > constructor time (milliseconds) = 0 > open time (milliseconds) = 35 > next time (milliseconds) = 0 > close time (milliseconds) = 1 > optimizer estimated row count: 2.00 > optimizer estimated cost: 37.18 > Left result set: > Nested Loop Exists Join ResultSet: > Number of opens = 1 > Rows seen from the left = 4 > Rows seen from the right = 0 > Rows filtered = 0 > Rows returned = 0 > constructor time (milliseconds) = 0 > open time (milliseconds) = 1 > next time (milliseconds) = 34 > close time (milliseconds) = 1 > optimizer estimated row count: 2.00 > optimizer estimated cost: 27.75 > Left result set: > Index Row to Base Row ResultSet for > CONFIGURATION_BUNDLE: > Number of opens = 1 > Rows seen = 4 > Columns accessed from heap = {0, 1, 2, 3} > constructor time (milliseconds) = 1 > open time (milliseconds) = 0 > next time (milliseconds) = 0 > close time (milliseconds) = 1 > optimizer estimated row count: 2.00 > optimizer estimated cost: 12.04 > Index Scan ResultSet for > CONFIGURATION_BUNDLE using index CONFIGURATION_BUNDLE_IX_1 at read committed > isolation level using instantaneous share row locking chosen by the optimizer > Number of opens = 1 > Rows seen = 4 > Rows filtered = 0 > Fetch Size = 16 > constructor time > (milliseconds) = 0 > open time (milliseconds) = 1 > next time (milliseconds) = 0 > close time (milliseconds) = 1 > next time in > milliseconds/row = 0 > > scan information: > Bit set of columns > fetched=All > Number of columns fetched=2 > Number of deleted rows > visited=0 > Number of pages visited=4 > Number of rows qualified=4 > Number of rows visited=5 > Scan type=btree > Tree height=4 > 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: 2.00 > optimizer estimated > cost: 12.04 > > 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 = 4 > Rows seen = 0 > Rows filtered = 0 > Fetch Size = 1 > constructor time (milliseconds) = 0 > open time (milliseconds) = 1 > next time (milliseconds) = 33 > close time (milliseconds) = 1 > > scan information: > Bit set of columns fetched={0, 1} > Number of columns fetched=2 > Number of deleted rows visited=0 > Number of pages visited=20 > Number of rows qualified=0 > Number of rows visited=4 > 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: 2.00 > optimizer estimated cost: > 15.72 > > Right result set: > Index Scan ResultSet for > CONFIGURATION_BUNDLE_9145E10G using constraint SQL100226025356610 at read > committed isolation level using share row locking chosen by the optimizer > Number of opens = 0 > Rows seen = 0 > Rows filtered = 0 > Fetch Size = 1 > constructor time (milliseconds) = 0 > open time (milliseconds) = 0 > next time (milliseconds) = 0 > close time (milliseconds) = 0 > > scan information: > start position: > Positioning information not > available because this ResultSet was never opened. > stop position: > Positioning information not > available because this ResultSet was never opened. > qualifiers: > Column[0][0] Id: 0 > Operator: = > Ordered nulls: false > Unknown return value: false > Negate comparison result: false > optimizer estimated row count: 2.00 > optimizer estimated cost: 9.43 > > Right result set: > Index Row to Base Row ResultSet for > INGRESS_COS_QUEUE_CONFIG_BUNDLE: > Number of opens = 0 > Rows seen = 0 > Columns accessed from heap = {1} > constructor time (milliseconds) = 0 > open time (milliseconds) = 0 > next time (milliseconds) = 0 > close time (milliseconds) = 0 > optimizer estimated row count: 2.00 > optimizer estimated cost: 14.34 > Index Scan ResultSet for > INGRESS_COS_QUEUE_CONFIG_BUNDLE using constraint SQL130327093437740 at read > committed isolation level using share row locking chosen by the optimizer > Number of opens = 0 > Rows seen = 0 > Rows filtered = 0 > Fetch Size = 1 > constructor time (milliseconds) = 0 > open time (milliseconds) = 0 > next time (milliseconds) = 0 > close time (milliseconds) = 0 > > scan information: > start position: > Positioning information not > available because this ResultSet was never opened. > stop position: > Positioning information not > available because this ResultSet was never opened. > qualifiers: > Column[0][0] Id: 0 > Operator: = > Ordered nulls: false > Unknown return value: false > Negate comparison result: false > optimizer estimated row count: 2.00 > optimizer estimated cost: 14.34 > > > > -----Original Message----- > From: Bergquist, Brett [mailto:[email protected]] > Sent: Thursday, March 28, 2013 8:33 AM > To: [email protected] > Subject: RE: Why is the optimizer choosing such a bad path > > Okay, I finally figured out that " CALL > SYSCS_UTIL.SYSCS_SET_STATISTICS_TIMING(1);" is required. Now from the name > which has "timing" in it, one (or at least I) would not think that this would > affect the returning of the optimizer estimates. I guess I naively assumed > this would affect the reporting of the compile and execution times. Maybe > the documentation needs to be fixed here. > > In any case, below is the query plan with this turned on. Note that > optimizer is estimating a row count of 0 for the table with 64 million rows > and does a table scan. > > Statement Name: > SQL_CURLH000C1 > Statement Text: > SELECT t0.ID, t0.DTYPE, t0.BUNDLE_NAME, t0.OPLOCK, t1.ID, > t2.ID, t2.LLQ_CONFIG_ENTRY_ID FROM > CORE_V1.CONFIGURATIONSET_CONFIGURATIONBUNDLE t3, > PKG_9145E10G.INGRESS_COS_QUEUE_CONFIG_BUNDLE t2, > PKG_9145E10G.CONFIGURATION_BUNDLE_9145E10G t1, > CORE_V1.CONFIGURATION_BUNDLE t0 WHERE (((t3.CONFIGURATIONSET_ID = > 4000) AND (t0.ID = t3.CONFIGURATIONBUNDLE_ID)) AND (((t2.ID = t0.ID) > AND (t1.ID = t0.ID)) AND (t0.DTYPE = > 'INGRESS_COS_QUEUE_CONFIG_BUNDLE_9145E10G'))) > Parse Time: 8 > Bind Time: 66 > Optimize Time: 3935 > Generate Time: 7 > Compile Time: 4016 > Execute Time: 220556 > Begin Compilation Timestamp : 2013-03-28 08:27:13.028 End Compilation > Timestamp : 2013-03-28 08:27:17.044 Begin Execution Timestamp : 2013-03-28 > 08:27:17.053 End Execution Timestamp : 2013-03-28 08:30:57.615 Statement > Execution Plan Text: > Project-Restrict ResultSet (9): > Number of opens = 1 > Rows seen = 0 > Rows filtered = 0 > restriction = false > projection = true > constructor time (milliseconds) = 0 > open time (milliseconds) = 220556 > next time (milliseconds) = 0 > close time (milliseconds) = 0 > restriction time (milliseconds) = 0 > projection time (milliseconds) = 0 > optimizer estimated row count: 0.00 > optimizer estimated cost: 8.05 Source result set: > Nested Loop Join ResultSet: > Number of opens = 1 > Rows seen from the left = 0 > Rows seen from the right = 0 > Rows filtered = 0 > Rows returned = 0 > constructor time (milliseconds) = 0 > open time (milliseconds) = 220556 > next time (milliseconds) = 0 > close time (milliseconds) = 6 > optimizer estimated row count: 0.00 > optimizer estimated cost: 8.05 > Left result set: > Nested Loop Join ResultSet: > Number of opens = 1 > Rows seen from the left = 0 > Rows seen from the right = 0 > Rows filtered = 0 > Rows returned = 0 > constructor time (milliseconds) = 0 > open time (milliseconds) = 220556 > next time (milliseconds) = 0 > close time (milliseconds) = 6 > optimizer estimated row count: 0.00 > optimizer estimated cost: 8.05 > Left result set: > Nested Loop Join ResultSet: > Number of opens = 1 > Rows seen from the left = 4 > Rows seen from the right = 0 > Rows filtered = 0 > Rows returned = 0 > constructor time (milliseconds) = 0 > open time (milliseconds) = 63 > next time (milliseconds) = 220493 > close time (milliseconds) = 6 > optimizer estimated row count: 0.00 > optimizer estimated cost: 8.05 > Left result set: > Index Row to Base Row ResultSet for > CONFIGURATION_BUNDLE: > Number of opens = 1 > Rows seen = 4 > Columns accessed from heap = {0, 1, 2, 3} > constructor time (milliseconds) = 0 > open time (milliseconds) = 0 > next time (milliseconds) = 64 > close time (milliseconds) = 6 > optimizer estimated row count: 0.00 > optimizer estimated cost: 8.05 > Index Scan ResultSet for > CONFIGURATION_BUNDLE using index CONFIGURATION_BUNDLE_IX_1 at read committed > isolation level using instantaneous share row locking chosen by the optimizer > Number of opens = 1 > Rows seen = 4 > Rows filtered = 0 > Fetch Size = 16 > constructor time > (milliseconds) = 0 > open time (milliseconds) = 2 > next time (milliseconds) = 1 > close time (milliseconds) = 6 > next time in > milliseconds/row = 0 > > scan information: > Bit set of columns > fetched=All > Number of columns fetched=2 > Number of deleted rows > visited=0 > Number of pages visited=5 > Number of rows qualified=4 > Number of rows visited=5 > Scan type=btree > Tree height=5 > 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: 0.00 > optimizer estimated > cost: 8.05 > > Right result set: > Table Scan ResultSet for > CONFIGURATIONSET_CONFIGURATIONBUNDLE at read committed isolation level using > instantaneous share row locking chosen by the optimizer > Number of opens = 4 > Rows seen = 0 > Rows filtered = 0 > Fetch Size = 16 > constructor time (milliseconds) = 0 > open time (milliseconds) = 64 > next time (milliseconds) = 0 > close time (milliseconds) = > 11 > > scan information: > Bit set of columns fetched=All > Number of columns fetched=2 > Number of pages visited=670832 > Number of rows qualified=0 > Number of rows visited=262428000 > Scan type=heap > start position: > null > stop position: > null > qualifiers: > Column[0][0] Id: 0 > Operator: = > Ordered nulls: false > Unknown return value: false > Negate comparison result: > false > Column[0][1] Id: 1 > Operator: = > Ordered nulls: false > Unknown return value: false > Negate comparison result: > false > optimizer estimated row count: 0.00 > optimizer estimated cost: > 0.00 > > Right result set: > Table Scan ResultSet for > INGRESS_COS_QUEUE_CONFIG_BUNDLE at read committed isolation level using > instantaneous share row locking chosen by the optimizer > Number of opens = 0 > Rows seen = 0 > Rows filtered = 0 > Fetch Size = 16 > constructor time (milliseconds) = 0 > open time (milliseconds) = 0 > next time (milliseconds) = 0 > close time (milliseconds) = 0 > > scan information: > start position: > null > stop position: > null > qualifiers: > Column[0][0] Id: 0 > Operator: = > Ordered nulls: false > Unknown return value: false > Negate comparison result: false > optimizer estimated row count: 0.00 > optimizer estimated cost: 0.00 > > Right result set: > Table Scan ResultSet for CONFIGURATION_BUNDLE_9145E10G at > read committed isolation level using instantaneous share row locking chosen > by the optimizer > Number of opens = 0 > Rows seen = 0 > Rows filtered = 0 > Fetch Size = 16 > constructor time (milliseconds) = 0 > open time (milliseconds) = 0 > next time (milliseconds) = 0 > close time (milliseconds) = 0 > > scan information: > start position: > null > stop position: > null > qualifiers: > Column[0][0] Id: 0 > Operator: = > Ordered nulls: false > Unknown return value: false > Negate comparison result: false > optimizer estimated row count: 0.00 > optimizer estimated cost: 0.00 > > -----Original Message----- > From: Bergquist, Brett [mailto:[email protected]] > Sent: Wednesday, March 27, 2013 8:42 PM > To: [email protected] > Subject: RE: Why is the optimizer choosing such a bad path > > I am able to build Derby so I can try a patch. On DERBY-6045, there are two > attached patches. Two questions: > > 1. Are the patches against the trunk or can they be applied to 10.9.1.0 (I > already have been building the equivalent of that release anyways myself). > 2. Apply both patches? > > > ________________________________________ > From: Mike Matrigali [[email protected]] > Sent: Wednesday, March 27, 2013 6:22 PM > To: [email protected] > Subject: Re: Why is the optimizer choosing such a bad path > > I would suggest seeing if this is related to DERBY-6045 or not. I > don't think this query goes through the in-list path but I am not sure, so if > you are set up you could apply the patch and see if it makes a difference. > There is a patch available and I believe it will be going into trunk soon. > > I have been waiting for that patch to go in, and then look to see if the > underlying problem exists in other parts of the code. The problem is that we > changed update statistics to not create a statistic on a unique single column > index, and that the code above then did not do the right thing when that stat > did not exist. To see if you are running into a similar problem you can use > the workaround that Kristian suggested in that issue: > > I think specifying > derby.storage.indexStats.debug.keepDisposableStats=true *and* regenerating > statistics for the relevant tables will suffice as a work-around for this > issue. > > Given that we agree the statistics for single-column unique indexes aren't > needed, do we know what puts off the optimizer? > The lack of statistics, or stale row estimates? > (I don't have time to dig into that, and I don't know what the > optimizer does in this case.) > > If you set the property on your db and rerun all the statistics and see a > different result then it will point to another place in the code that needs > to change to handle a stat not existing in the catalog. > > On 3/27/2013 12:16 PM, Bergquist, Brett wrote: >> Some background. >> >> I have a customer that is using an earlier release of our system that has >> Derby 10.8.2.1 installed. Because of issues like >> https://issues.apache.org/jira/browse/DERBY-5680, >> it has been running with the indexStat daemon disabled. >> >> We are going to have a new release soon and it will be installing Derby >> 10.9.1.0 with the indexStat >> daemon enabled. I recently got a copy of the customer's database (132Gb) >> and ran into >> a very long query. I manually ran SYS_UTIL.SYSCS_UPDATE_STATISTICS on all >> of the tables >> in the query to ensure that the statistics are up to date. >> >> The tables in the query look like: >> >> // 62,908,433 Rows >> CREATE TABLE "CORE_V1"."CONFIGURATIONSET_CONFIGURATIONBUNDLE" >> ( >> CONFIGURATIONBUNDLE_ID int NOT NULL, >> CONFIGURATIONSET_ID int NOT NULL, >> CONSTRAINT CONFIGURATIONSET_CONFIGURATIONBUNDLE_PK PRIMARY KEY >> (CONFIGURATIONBUNDLE_ID,CONFIGURATIONSET_ID) >> ); >> ALTER TABLE "CORE_V1"."CONFIGURATIONSET_CONFIGURATIONBUNDLE" >> ADD CONSTRAINT CONFIGURATIONSET_CONFIGURATIONBUNDLE_FK_2 >> FOREIGN KEY (CONFIGURATIONSET_ID) >> REFERENCES "CORE_V1"."CONFIGURATION_SET"(ID); >> ALTER TABLE "CORE_V1"."CONFIGURATIONSET_CONFIGURATIONBUNDLE" >> ADD CONSTRAINT CONFIGURATIONSET_CONFIGURATIONBUNDLE_FK_1 >> FOREIGN KEY (CONFIGURATIONBUNDLE_ID) >> REFERENCES "CORE_V1"."CONFIGURATION_BUNDLE"(ID); >> CREATE INDEX SQL100922214558160 ON >> "CORE_V1"."CONFIGURATIONSET_CONFIGURATIONBUNDLE"(CONFIGURATIONSET_ID) >> ; >> CREATE INDEX SQL100922215312050 ON >> "CORE_V1"."CONFIGURATIONSET_CONFIGURATIONBUNDLE"(CONFIGURATIONBUNDLE_ >> I D); CREATE UNIQUE INDEX SQL081029110254290 ON >> "CORE_V1"."CONFIGURATIONSET_CONFIGURATIONBUNDLE" >> ( >> CONFIGURATIONBUNDLE_ID, >> CONFIGURATIONSET_ID >> ); >> >> // 4 Rows >> CREATE TABLE "PKG_9145E10G"."INGRESS_COS_QUEUE_CONFIG_BUNDLE" >> ( >> ID int PRIMARY KEY NOT NULL, >> LLQ_CONFIG_ENTRY_ID int NOT NULL ); ALTER TABLE >> "PKG_9145E10G"."INGRESS_COS_QUEUE_CONFIG_BUNDLE" >> ADD CONSTRAINT INGRESS_COS_QUEUE_CONFIG_BUNDLE_FK_2 >> FOREIGN KEY (LLQ_CONFIG_ENTRY_ID) >> REFERENCES "PKG_9145E10G"."INGRESS_COS_QUEUE_CONFIG_ENTRY"(ID); >> ALTER TABLE "PKG_9145E10G"."INGRESS_COS_QUEUE_CONFIG_BUNDLE" >> ADD CONSTRAINT INGRESS_COS_QUEUE_CONFIG_BUNDLE_FK_1 >> FOREIGN KEY (ID) >> REFERENCES "CORE_V1"."CONFIGURATION_BUNDLE"(ID); >> CREATE INDEX SQL130327093508050 ON >> "PKG_9145E10G"."INGRESS_COS_QUEUE_CONFIG_BUNDLE"(ID); >> CREATE INDEX SQL130327093508060 ON >> "PKG_9145E10G"."INGRESS_COS_QUEUE_CONFIG_BUNDLE"(LLQ_CONFIG_ENTRY_ID) >> ; CREATE UNIQUE INDEX SQL130327093437740 ON >> "PKG_9145E10G"."INGRESS_COS_QUEUE_CONFIG_BUNDLE"(ID); >> >> // 197,363 Rows >> CREATE TABLE "PKG_9145E10G"."CONFIGURATION_BUNDLE_9145E10G" >> ( >> ID int PRIMARY KEY NOT NULL >> ); >> ALTER TABLE "PKG_9145E10G"."CONFIGURATION_BUNDLE_9145E10G" >> ADD CONSTRAINT CONFIGURATION_BUNDLE_9145E10G_FK_1 >> FOREIGN KEY (ID) >> REFERENCES "CORE_V1"."CONFIGURATION_BUNDLE"(ID); >> CREATE UNIQUE INDEX SQL100226025356610 ON >> "PKG_9145E10G"."CONFIGURATION_BUNDLE_9145E10G"(ID); >> CREATE INDEX SQL100922215631540 ON >> "PKG_9145E10G"."CONFIGURATION_BUNDLE_9145E10G"(ID); >> >> // 6,740,327 Rows >> CREATE TABLE "CORE_V1"."CONFIGURATION_BUNDLE" >> ( >> DTYPE varchar(64), >> OPLOCK int DEFAULT 0 NOT NULL, >> BUNDLE_NAME varchar(64) NOT NULL, >> ID int PRIMARY KEY NOT NULL >> ); >> CREATE INDEX CONFIGURATION_BUNDLE_IX_2 ON >> "CORE_V1"."CONFIGURATION_BUNDLE"(BUNDLE_NAME); >> CREATE INDEX CONFIGURATION_BUNDLE_IX_1 ON >> "CORE_V1"."CONFIGURATION_BUNDLE"(DTYPE); >> CREATE UNIQUE INDEX SQL100922215131580 ON >> "CORE_V1"."CONFIGURATION_BUNDLE"(ID); >> >> >> For some reason, the optimizer is doing a table scan across the >> CORE_V1.CONFIGURATIONSET_CONFIGURATIONBUNDLE table which has 64 million rows >> and it even goes across this 4 times!. >> >> One issue is that this query is generated by Eclipselink (JPA) and I have no >> control on the query generation. >> >> So any ideas on why it would chose this path and what I might be able to do >> about it? In playing >> around and trying to find the issue, I notice that if I remove the >> >> t0.DTYPE = 'INGRESS_COS_QUEUE_CONFIG_BUNDLE_9145E10G') >> >> constraint, then the query returns 0 rows (it should even with this >> constraint as there are no rows >> that are acceptable) and returns them in about .05 seconds. Note >> CORE_V1.CONFIGURATION_BUNDLE does >> have a non-unique index on DTYPE. >> >> Ok, just on a whim, I removed the index on DTYPE and the query came >> back .06 seconds. That column is used by Eclipselink in determining which of >> a "derived" object to return so I don't have much control on it. >> >> ---- >> Statement Name: >> SQL_CURLH000C1 >> Statement Text: >> SELECT t0.ID, t0.DTYPE, t0.BUNDLE_NAME, t0.OPLOCK, t1.ID, >> t2.ID, t2.LLQ_CONFIG_ENTRY_ID FROM >> CORE_V1.CONFIGURATIONSET_CONFIGURATIONBUNDLE t3, >> PKG_9145E10G.INGRESS_COS_QUEUE_CONFIG_BUNDLE t2, >> PKG_9145E10G.CONFIGURATION_BUNDLE_9145E10G t1, >> CORE_V1.CONFIGURATION_BUNDLE t0 WHERE (((t3.CONFIGURATIONSET_ID = >> 4000) AND (t0.ID = t3.CONFIGURATIONBUNDLE_ID)) AND (((t2.ID = t0.ID) >> AND (t1.ID = t0.ID)) AND (t0.DTYPE = >> 'INGRESS_COS_QUEUE_CONFIG_BUNDLE_9145E10G'))) >> 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 (9): >> Number of opens = 1 >> Rows seen = 0 >> 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: 0.00 >> optimizer estimated cost: 8.05 Source result set: >> Nested Loop Join ResultSet: >> Number of opens = 1 >> Rows seen from the left = 0 >> Rows seen from the right = 0 >> Rows filtered = 0 >> Rows returned = 0 >> constructor time (milliseconds) = 0 >> open time (milliseconds) = 0 >> next time (milliseconds) = 0 >> close time (milliseconds) = 0 >> optimizer estimated row count: 0.00 >> optimizer estimated cost: 8.05 >> Left result set: >> Nested Loop Join ResultSet: >> Number of opens = 1 >> Rows seen from the left = 0 >> Rows seen from the right = 0 >> Rows filtered = 0 >> Rows returned = 0 >> constructor time (milliseconds) = 0 >> open time (milliseconds) = 0 >> next time (milliseconds) = 0 >> close time (milliseconds) = 0 >> optimizer estimated row count: 0.00 >> optimizer estimated cost: 8.05 >> Left result set: >> Nested Loop Join ResultSet: >> Number of opens = 1 >> Rows seen from the left = 4 >> Rows seen from the right = 0 >> Rows filtered = 0 >> Rows returned = 0 >> constructor time (milliseconds) = 0 >> open time (milliseconds) = 0 >> next time (milliseconds) = 0 >> close time (milliseconds) = 0 >> optimizer estimated row count: 0.00 >> optimizer estimated cost: 8.05 >> Left result set: >> Index Row to Base Row ResultSet for >> CONFIGURATION_BUNDLE: >> Number of opens = 1 >> Rows seen = 4 >> Columns accessed from heap = {0, 1, 2, 3} >> constructor time (milliseconds) = 0 >> open time (milliseconds) = 0 >> next time (milliseconds) = 0 >> close time (milliseconds) = 0 >> optimizer estimated row count: 0.00 >> optimizer estimated cost: 8.05 >> Index Scan ResultSet for >> CONFIGURATION_BUNDLE using index CONFIGURATION_BUNDLE_IX_1 at read committed >> isolation level using instantaneous share row locking chosen by the optimizer >> Number of opens = 1 >> Rows seen = 4 >> 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=0 >> Number of pages visited=5 >> Number of rows qualified=4 >> Number of rows visited=5 >> Scan type=btree >> Tree height=5 >> 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: 0.00 >> optimizer estimated >> cost: 8.05 >> >> Right result set: >> Table Scan ResultSet for >> CONFIGURATIONSET_CONFIGURATIONBUNDLE at read committed isolation level using >> instantaneous share row locking chosen by the optimizer >> Number of opens = 4 >> Rows seen = 0 >> Rows filtered = 0 >> Fetch Size = 16 >> constructor time (milliseconds) = 0 >> open time (milliseconds) = 0 >> next time (milliseconds) = 0 >> close time (milliseconds) = 0 >> >> scan information: >> Bit set of columns fetched=All >> Number of columns fetched=2 >> Number of pages visited=670838 >> Number of rows qualified=0 >> Number of rows visited=262429876 >> Scan type=heap >> start position: >> null >> stop position: >> null >> qualifiers: >> Column[0][0] Id: 0 >> Operator: = >> Ordered nulls: false >> Unknown return value: false >> Negate comparison result: >> false >> Column[0][1] Id: 1 >> Operator: = >> Ordered nulls: false >> Unknown return value: false >> Negate comparison result: >> false >> optimizer estimated row count: 0.00 >> optimizer estimated cost: 0.00 >> >> Right result set: >> Table Scan ResultSet for >> INGRESS_COS_QUEUE_CONFIG_BUNDLE at read committed isolation level using >> instantaneous share row locking chosen by the optimizer >> Number of opens = 0 >> Rows seen = 0 >> Rows filtered = 0 >> Fetch Size = 16 >> constructor time (milliseconds) = 0 >> open time (milliseconds) = 0 >> next time (milliseconds) = 0 >> close time (milliseconds) = 0 >> >> scan information: >> start position: >> null >> stop position: >> null >> qualifiers: >> Column[0][0] Id: 0 >> Operator: = >> Ordered nulls: false >> Unknown return value: false >> Negate comparison result: false >> optimizer estimated row count: 0.00 >> optimizer estimated cost: 0.00 >> >> Right result set: >> Table Scan ResultSet for CONFIGURATION_BUNDLE_9145E10G at >> read committed isolation level using instantaneous share row locking chosen >> by the optimizer >> Number of opens = 0 >> Rows seen = 0 >> Rows filtered = 0 >> Fetch Size = 16 >> constructor time (milliseconds) = 0 >> open time (milliseconds) = 0 >> next time (milliseconds) = 0 >> close time (milliseconds) = 0 >> >> scan information: >> start position: >> null >> stop position: >> null >> qualifiers: >> Column[0][0] Id: 0 >> Operator: = >> Ordered nulls: false >> Unknown return value: false >> Negate comparison result: false >> optimizer estimated row count: 0.00 >> optimizer estimated cost: 0.00 >> >> >> > > > > > > > > >
