db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Bergquist, Brett" <BBergqu...@canoga.com>
Subject Re: I need help on getting Derby to use a primary key index on a query
Date Fri, 23 Aug 2013 18:04:08 GMT
I just enabled the derby.storage.indexStats.debug.keepDisposableStats=true in derby.properties
and restarted the network server.   I am running with straight 10.9.1.0 right now and have
a database with exactly two tables.  I have used the "syscs_util.syscs_drop_statistics" to
drop the statistics and then uses the "syscs_util.syscs_update_statistics" to recreate the
statistics.   Here is the statistics query:

select tablename || ' (' || CONGLOMERATENAME || ')' as INDEX,
REFERENCEID,
CREATIONTIMESTAMP,
TYPE,
VALID,
COLCOUNT,
cast (STATISTICS as varchar(80)) stats,
      CASE WHEN CAST(creationtimestamp AS varchar(24))  IS NULL
      THEN 'Recreate Index to Initialize'
      ELSE CAST(creationtimestamp AS varchar(24))  END
from sys.systables t, sys.sysconglomerates c
    LEFT OUTER JOIN sys.sysstatistics s ON c.conglomerateid = s.referenceid
where t.tableid = c.tableid
and c.isindex = true and t.tabletype = 'T'
order by INDEX;

Here is the output from that:

INDEX REFERENCEID CREATIONTIMESTAMP TYPE VALID COLCOUNT STATS 8
CONFIGURATION_BUNDLE3 (CONFIGURATION_BUNDLE3_IX_1) 522b00e8-0140-ab92-f364-ffff93450f77 2013-08-23
13:54:30.812 I true 1 numunique= 135 numrows= 7003481 2013-08-23 13:54:30.812
CONFIGURATION_BUNDLE3 (CONFIGURATION_BUNDLE3_IX_2) 597e80e5-0140-ab92-f364-ffff93450f77 2013-08-23
13:54:21.516 I true 1 numunique= 92 numrows= 7003481 2013-08-23 13:54:21.516
CONFIGURATION_BUNDLE3 (SQL130823102831500) d7bd80dd-0140-ab92-f364-ffff93450f77 2013-08-23
13:54:13.129 I true 1 numunique= 7003481 numrows= 7003481 2013-08-23 13:54:13.129
COSEDDROPPROFILEDSCPTABLEBUNDLE_COSEDDROPPROFILEDSCPTABLEENTRY3 (COSEDDROPPROFILEDSCPTABLEBUNDLE_COSEDDROPPROFILEDSCPTABLEENTRY3_IX_0)
46f7c11b-0140-ab92-f364-ffff93450f77 2013-08-23 13:57:22.96 I true 1 numunique= 53053312 numrows=
58248128 2013-08-23 13:57:22.96
COSEDDROPPROFILEDSCPTABLEBUNDLE_COSEDDROPPROFILEDSCPTABLEENTRY3 (SQL130823102836170) 4760c0fe-0140-ab92-f364-ffff93450f77
2013-08-23 13:55:30.662 I true 2 numunique= 58248128 numrows= 58248128 2013-08-23 13:55:30.662
COSEDDROPPROFILEDSCPTABLEBUNDLE_COSEDDROPPROFILEDSCPTABLEENTRY3 (SQL130823102836170) 4760c0fe-0140-ab92-f364-ffff93450f77
2013-08-23 13:55:30.661 I true 1 numunique= 910127 numrows= 58248128 2013-08-23 13:55:30.661
COSEDDROPPROFILEDSCPTABLEBUNDLE_COSEDDROPPROFILEDSCPTABLEENTRY3 (SQL130823102836240) f8e18104-0140-ab92-f364-ffff93450f77
2013-08-23 13:56:24.379 I true 1 numunique= 910127 numrows= 58248128 2013-08-23 13:56:24.379


So as can be seen, the primary key backing index of CONFIGURATION_BUNDLE3 shows that the are
7003481 unique rows and COSEDDROPPROFILEDSCPTABLEBUNDLE_COSEDDROPPROFILEDSCPTABLEENTRY3 shows
58248128 unique rows.

The query that I am performing is:

CALL SYSCS_UTIL.SYSCS_SET_RUNTIMESTATISTICS(1);
CALL SYSCS_UTIL.SYSCS_SET_STATISTICS_TIMING(1);
SELECT * FROM APP.CONFIGURATION_BUNDLE3 T1,
APP.COSEDDROPPROFILEDSCPTABLEBUNDLE_COSEDDROPPROFILEDSCPTABLEENTRY3 t0
WHERE t1.ID = t0.COSEDDROPPROFILEDSCPTABLEBUNDLE_ID and
t0.COSEDDROPPROFILEDSCPTABLEENTRY_ID = 12344444;
VALUES SYSCS_UTIL.SYSCS_GET_RUNTIMESTATISTICS();
CALL SYSCS_UTIL.SYSCS_SET_RUNTIMESTATISTICS(0);
CALL SYSCS_UTIL.SYSCS_SET_STATISTICS_TIMING(0);

The optimizer plan from this is below.   The plan correctly chooses to use the index on the
COSEDDROPPROFILEDSCPTABLEENTRY_ID on the  COSEDDROPPROFILEDSCPTABLEBUNDLE_COSEDDROPPROFILEDSCPTABLEENTRY3
table but still estimates 0 rows (there is actually 1 row) and then uses a table scan on CONFIGURATION_BUNDLE3
even though the join field APP.CONFIGURATION_BUNDLE3.ID is the primary key.

I have so far been able to do nothing that will cause this to operate correctly now that it
is in this state.   Dropping and recreating statistics has no effect.   I will try dropping
and recreating the indexes and primary key next.

Here is the query plan:

Statement Name:
SQL_CURLH000C2
Statement Text:
SELECT * FROM APP.CONFIGURATION_BUNDLE3 T1,
APP.COSEDDROPPROFILEDSCPTABLEBUNDLE_COSEDDROPPROFILEDSCPTABLEENTRY3 t0
WHERE t1.ID = t0.COSEDDROPPROFILEDSCPTABLEBUNDLE_ID and
t0.COSEDDROPPROFILEDSCPTABLEENTRY_ID = 12344444
Parse Time: 2
Bind Time: 3
Optimize Time: 16
Generate Time: 3
Compile Time: 24
Execute Time: 9609
Begin Compilation Timestamp : 2013-08-23 13:59:44.959
End Compilation Timestamp : 2013-08-23 13:59:44.983
Begin Execution Timestamp : 2013-08-23 13:59:44.986
End Execution Timestamp : 2013-08-23 13:59:54.595
Statement Execution Plan Text:
Project-Restrict ResultSet (5):
Number of opens = 1
Rows seen = 1
Rows filtered = 0
restriction = false
projection = true
constructor time (milliseconds) = 0
open time (milliseconds) = 1
next time (milliseconds) = 9608
close time (milliseconds) = 0
restriction time (milliseconds) = 0
projection time (milliseconds) = 0
optimizer estimated row count: 0.00
optimizer estimated cost: 7.86
Source result set:
Nested Loop Join ResultSet:
Number of opens = 1
Rows seen from the left = 1
Rows seen from the right = 1
Rows filtered = 0
Rows returned = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 1
next time (milliseconds) = 9608
close time (milliseconds) = 0
optimizer estimated row count: 0.00
optimizer estimated cost: 7.86
Left result set:
Index Row to Base Row ResultSet for COSEDDROPPROFILEDSCPTABLEBUNDLE_COSEDDROPPROFILEDSCPTABLEENTRY3:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {0, 1}
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: 7.86
Index Scan ResultSet for COSEDDROPPROFILEDSCPTABLEBUNDLE_COSEDDROPPROFILEDSCPTABLEENTRY3 using
index COSEDDROPPROFILEDSCPTABLEBUNDLE_COSEDDROPPROFILEDSCPTABLEENTRY3_IX_0 at read committed
isolation level using instantaneous share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
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=1
Number of rows visited=2
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: 0.00
optimizer estimated cost: 7.86

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

scan information:
Bit set of columns fetched=All
Number of columns fetched=4
Number of pages visited=197281
Number of rows qualified=1
Number of rows visited=7003481
Scan type=heap
start position:
null
stop position:
null
qualifiers:
Column[0][0] Id: 3
Operator: =
Ordered nulls: false
Unknown return value: false
Negate comparison result: false
optimizer estimated row count: 0.00
optimizer estimated cost: 0.00


On Aug 23, 2013, at 1:10 PM, Mamta Satoor <msatoor@gmail.com<mailto:msatoor@gmail.com>>
wrote:

Hi Brett,

We have encountered and fixed at least one bug in case of single-column unique index, where
starting 10.9 we have decided not to keep stats for such indexes. The bug fixed is DERBY-6045
and it is in Derby 10.10.1.1(revision 1480153). I was wondering if you could share java org.apache.derby.tools.sysinfo
so we know if you have that fix.

If you do have that fix, then it is possible (though I am not certain) that there may be other
bug in this area that
you are running into. One way to figure that out is to use the property derby.storage.indexStats.debug.keepDisposableStats=true.
This property will force Derby to collect the stats for single-column unique index. So, if
you can recreate your db with this property and run the query, we can check the query plan
to see if it starts using the single-column unique index. It might be possible to use existing
db with this property and recreate the stats and try the query if creating the db from scratch
with this property is a time consuming process.

thanks,
Mamta



On Wed, Aug 21, 2013 at 4:55 PM, Bryan Pendleton <bpendleton.derby@gmail.com<mailto:bpendleton.derby@gmail.com>>
wrote:
Any thoughts or comments on why this the optimizer chooses on over the other?

Unfortunately, no.

But there have been concerns about the optimizer's cost
analysis for years; see https://issues.apache.org/jira/browse/DERBY-1905
and some of the other issues linked from it (DERBY-1259, DERBY-1260).

So, while I know it's frustrating for you to be wrestling with
an optimizer that won't behave, it's also good news, for Derby,
that you've made such good progress in trying to understand
this peculiar behavior.

Perhaps when we get to the bottom of the strange behavior
you're seeing, we'll have a better understanding of some of
the other strange optimizer behaviors we've seen in the past.

thanks,

bryan





Mime
View raw message