[
https://issues.apache.org/jira/browse/DERBY-6093?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Tony Brusseau updated DERBY-6093:
---------------------------------
Description:
If I run a count query given all the parameters directly, then the query
executes in .05s, however, if I send it across as a prepared statement, then
the query takes 40s to run (because is does a complete table scan on a table
with 15m rows).
The query looks like:
SELECT COUNT(*)
FROM KB.FORMULA_ENTRIES fe1, KB.FORMULA_ENTRIES fe2
WHERE
(fe1.arg_0_term = 1407374883620920) AND (fe1.arg_num = 1) AND (fe1.arg_term =
1407374883574780) AND (fe1.formula_type = 0)
AND (fe1.formula_id = fe2.formula_id) AND (fe2.arg_0_term = 1407374883620920)
AND (fe2.arg_num = 2) AND (fe2.arg_term = 1407374883663337) AND
(fe2.formula_type = 0)
or the prepared version like:
SELECT COUNT(*)
FROM KB.FORMULA_ENTRIES fe1
, KB.FORMULA_ENTRIES fe2
WHERE
(fe1.arg_0_term = ?) AND (fe1.arg_num = ?) AND (fe1.arg_term = ?) AND
(fe1.formula_type = ?)
AND (fe1.formula_id = fe2.formula_id) AND (fe2.arg_0_term = ?) AND (fe2.arg_num
= ?) AND (fe2.arg_term = ?) AND (fe2.formula_type = ?)
The table is defined as:
DROP TABLE KB.FORMULA_ENTRIES;
CREATE TABLE KB.FORMULA_ENTRIES
(
formula_entries_id BIGINT NOT NULL,)
formula_id BIGINT NOT NULL,
arg_0_term BIGINT NOT NULL,
arg_term BIGINT NOT NULL,
arg_num INTEGER NOT NULL,
formula_type SMALLINT NOT NULL
);
ALTER TABLE kb.formula_entries ADD CONSTRAINT kb_formula_entries_pk PRIMARY KEY
(formula_entries_id);
ALTER TABLE kb.formula_entries ADD CONSTRAINT kb_fomula_entries_formula_id_fk
FOREIGN KEY (formula_id) REFERENCES kb.formula_term (term_id) ON DELETE
CASCADE;
CREATE INDEX kb_formula_entries_formula_term_type ON kb.formula_entries
(arg_term, formula_type);
CREATE INDEX kb_formula_entries_formula_term_arg0_type ON kb.formula_entries
(arg_term, arg_0_term, formula_type);
CREATE INDEX kb_formula_entries_formula_term_num_type ON kb.formula_entries
(arg_term, arg_num, formula_type);
CREATE INDEX kb_formula_entries_formula_term_arg0_num_type ON
kb.formula_entries (arg_term, arg_0_term, arg_num, formula_type);
*************************************************************************
The good query plan (when *not* sent as a prepared statements) looks like:
Tue Feb 26 16:15:21 CST 2013 Thread[DRDAConnThread_5,5,main] (XID = 40971291),
(SESSIONID = 7), SELECT COUNT(*)
FROM KB.FORMULA_ENTRIES fe1, KB.FORMULA_ENTRIES fe2
WHERE
(fe1.arg_0_term = 1407374883620920) AND (fe1.arg_num = 1) AND (fe1.arg_term =
1407374883574780) AND (fe1.formula_type = 0)
AND (fe1.formula_id = fe2.formula_id) AND (fe2.arg_0_term = 1407374883620920)
AND (fe2.arg_num = 2) AND (fe2.arg_term = 1407374883663337) AND
(fe2.formula_type = 0) ******* Project-Restrict ResultSet (10):
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: 1.00
optimizer estimated cost: 7184.99
Source result set:
Scalar Aggregate ResultSet:
Number of opens = 1
Rows input = 3863
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: 7184.99
Index Key Optimization = false
Source result set:
Project-Restrict ResultSet (9):
Number of opens = 1
Rows seen = 3863
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: 7184.99
Source result set:
Nested Loop Join ResultSet:
Number of opens = 1
Rows seen from the left = 3863
Rows seen from the right = 3863
Rows filtered = 0
Rows returned = 3863
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: 7184.99
Left result set:
Project-Restrict ResultSet (5):
Number of opens = 1
Rows seen = 3865
Rows filtered = 2
restriction = true
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: 35.89
optimizer estimated cost: 6785.98
Source result set:
Index Row to Base Row ResultSet for
FORMULA_ENTRIES:
Number of opens = 1
Rows seen = 3865
Columns accessed from heap = {1, 2, 3,
4, 5}
constructor time (milliseconds)
= 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count:
35.89
optimizer estimated cost:
6785.98
Index Scan ResultSet for
FORMULA_ENTRIES using index KB_FORMULA_ENTRIES_FORMULA_TERM_TYPE at read
committed isolation level using instantaneous share row locking chosen by the
optimizer
Number of opens = 1
Rows seen = 3865
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=3
Number of deleted rows
visited=0
Number of pages
visited=7
Number of rows
qualified=3865
Number of rows
visited=3866
Scan type=btree
Tree height=3
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: 35.89
optimizer estimated
cost: 6785.98
Right result set:
Project-Restrict ResultSet (8):
Number of opens = 3863
Rows seen = 15452
Rows filtered = 11589
restriction = true
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: 399.01
Source result set:
Index Row to Base Row ResultSet for
FORMULA_ENTRIES:
Number of opens = 3863
Rows seen = 15452
Columns accessed from heap = {1, 2, 3,
4, 5}
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: 399.01
Index Scan ResultSet for
FORMULA_ENTRIES using constraint KB_FOMULA_ENTRIES_FORMULA_ID_FK at read
committed isolation level using instantaneous share row locking chosen by the
optimizer
Number of opens = 3863
Rows seen = 15452
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=11606
Number of rows
qualified=15452
Number of rows
visited=19315
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: 0.00
optimizer estimated
cost: 399.01
*************************************************************************
The bad query plan (when sent as a prepared statements) looks like:
Tue Feb 26 16:09:35 CST 2013 Thread[DRDAConnThread_4,5,main] (XID = 40971265),
(SESSIONID = 5), SELECT COUNT(*)
FROM KB.FORMULA_ENTRIES fe1
, KB.FORMULA_ENTRIES fe2
WHERE
(fe1.arg_0_term = ?) AND (fe1.arg_num = ?) AND (fe1.arg_term = ?) AND
(fe1.formula_type = ?)
AND (fe1.formula_id = fe2.formula_id) AND (fe2.arg_0_term = ?) AND (fe2.arg_num
= ?) AND (fe2.arg_term = ?) AND (fe2.formula_type = ?) ******* Project-Restrict
ResultSet (9):
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: 1.00
optimizer estimated cost: 43.36
Source result set:
Scalar Aggregate ResultSet:
Number of opens = 1
Rows input = 3863
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: 43.36
Index Key Optimization = false
Source result set:
Project-Restrict ResultSet (8):
Number of opens = 1
Rows seen = 3863
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: 43.36
Source result set:
Nested Loop Join ResultSet:
Number of opens = 1
Rows seen from the left = 3863
Rows seen from the right = 3863
Rows filtered = 0
Rows returned = 3863
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: 43.36
Left result set:
Index Row to Base Row ResultSet for
FORMULA_ENTRIES:
Number of opens = 1
Rows seen = 3863
Columns accessed from heap = {1, 2, 3, 4, 5}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 2.98
optimizer estimated cost: 10.89
Index Scan ResultSet for
FORMULA_ENTRIES using index KB_FORMULA_ENTRIES_FORMULA_TERM_ARG0_NUM_TYPE at
read committed isolation level using instantaneous share row locking chosen by
the optimizer
Number of opens = 1
Rows seen = 3863
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=5
Number of deleted rows visited=0
Number of pages visited=8
Number of rows qualified=3863
Number of rows visited=3864
Scan type=btree
Tree height=3
start position:
>= on first 4 column(s).
Ordered null semantics
on the following columns:
stop position:
> on first 4 column(s).
Ordered null semantics
on the following columns:
qualifiers:
None
optimizer estimated row count:
2.98
optimizer estimated cost: 10.89
Right result set:
Project-Restrict ResultSet (7):
Number of opens = 3863
Rows seen = 14922769
Rows filtered = 14918906
restriction = true
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: 32.47
Source result set:
Index Row to Base Row ResultSet for
FORMULA_ENTRIES:
Number of opens = 3863
Rows seen = 14922769
Columns accessed from heap = {1, 2, 3,
4, 5}
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: 32.47
Index Scan ResultSet for
FORMULA_ENTRIES using index KB_FORMULA_ENTRIES_FORMULA_TERM_ARG0_NUM_TYPE at
read committed isolation level using instantaneous share row locking chosen by
the optimizer
Number of opens = 3863
Rows seen = 14922769
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=5
Number of deleted rows
visited=0
Number of pages
visited=34767
Number of rows
qualified=14922769
Number of rows
visited=14926632
Scan type=btree
Tree height=3
start position:
>= on first 4
column(s).
Ordered null
semantics on the following columns:
stop position:
> on first 4
column(s).
Ordered null
semantics on the following columns:
qualifiers:
None
optimizer estimated row
count: 0.00
optimizer estimated
cost: 32.47
was:
If I run a count query given all the parameters directly, then the query
executes in .05s, however, if I send it across as a prepared statement, then
the query takes 40s to run (because is does a complete table scan on a table
with 15m rows).
The query looks like:
SELECT COUNT(*)
FROM KB.FORMULA_ENTRIES fe1, KB.FORMULA_ENTRIES fe2
WHERE
(fe1.arg_0_term = 1407374883620920) AND (fe1.arg_num = 1) AND (fe1.arg_term =
1407374883574780) AND (fe1.formula_type = 0)
AND (fe1.formula_id = fe2.formula_id) AND (fe2.arg_0_term = 1407374883620920)
AND (fe2.arg_num = 2) AND (fe2.arg_term = 1407374883663337) AND
(fe2.formula_type = 0)
or the prepared version like:
SELECT COUNT(*)
FROM KB.FORMULA_ENTRIES fe1
, KB.FORMULA_ENTRIES fe2
WHERE
(fe1.arg_0_term = ?) AND (fe1.arg_num = ?) AND (fe1.arg_term = ?) AND
(fe1.formula_type = ?)
AND (fe1.formula_id = fe2.formula_id) AND (fe2.arg_0_term = ?) AND (fe2.arg_num
= ?) AND (fe2.arg_term = ?) AND (fe2.formula_type = ?)
The table is defined as:
DROP TABLE KB.FORMULA_ENTRIES;
CREATE TABLE KB.FORMULA_ENTRIES
(
formula_entries_id BIGINT NOT NULL,)
formula_id BIGINT NOT NULL,
arg_0_term BIGINT NOT NULL,
arg_term BIGINT NOT NULL,
arg_num INTEGER NOT NULL,
formula_type SMALLINT NOT NULL
);
ALTER TABLE kb.formula_entries ADD CONSTRAINT kb_formula_entries_pk PRIMARY KEY
(formula_entries_id);
ALTER TABLE kb.formula_entries ADD CONSTRAINT kb_fomula_entries_formula_id_fk
FOREIGN KEY (formula_id) REFERENCES kb.formula_term (term_id) ON DELETE
CASCADE;
CREATE INDEX kb_formula_entries_formula_term_type ON kb.formula_entries
(arg_term, formula_type);
CREATE INDEX kb_formula_entries_formula_term_arg0_type ON kb.formula_entries
(arg_term, arg_0_term, formula_type);
CREATE INDEX kb_formula_entries_formula_term_num_type ON kb.formula_entries
(arg_term, arg_num, formula_type);
CREATE INDEX kb_formula_entries_formula_term_arg0_num_type ON
kb.formula_entries (arg_term, arg_0_term, arg_num, formula_type);
The good query plan looks (when *not* sent as a prepared statements) looks like:
Tue Feb 26 16:15:21 CST 2013 Thread[DRDAConnThread_5,5,main] (XID = 40971291),
(SESSIONID = 7), SELECT COUNT(*)
FROM KB.FORMULA_ENTRIES fe1, KB.FORMULA_ENTRIES fe2
WHERE
(fe1.arg_0_term = 1407374883620920) AND (fe1.arg_num = 1) AND (fe1.arg_term =
1407374883574780) AND (fe1.formula_type = 0)
AND (fe1.formula_id = fe2.formula_id) AND (fe2.arg_0_term = 1407374883620920)
AND (fe2.arg_num = 2) AND (fe2.arg_term = 1407374883663337) AND
(fe2.formula_type = 0) ******* Project-Restrict ResultSet (10):
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: 1.00
optimizer estimated cost: 7184.99
Source result set:
Scalar Aggregate ResultSet:
Number of opens = 1
Rows input = 3863
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: 7184.99
Index Key Optimization = false
Source result set:
Project-Restrict ResultSet (9):
Number of opens = 1
Rows seen = 3863
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: 7184.99
Source result set:
Nested Loop Join ResultSet:
Number of opens = 1
Rows seen from the left = 3863
Rows seen from the right = 3863
Rows filtered = 0
Rows returned = 3863
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: 7184.99
Left result set:
Project-Restrict ResultSet (5):
Number of opens = 1
Rows seen = 3865
Rows filtered = 2
restriction = true
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: 35.89
optimizer estimated cost: 6785.98
Source result set:
Index Row to Base Row ResultSet for
FORMULA_ENTRIES:
Number of opens = 1
Rows seen = 3865
Columns accessed from heap = {1, 2, 3,
4, 5}
constructor time (milliseconds)
= 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count:
35.89
optimizer estimated cost:
6785.98
Index Scan ResultSet for
FORMULA_ENTRIES using index KB_FORMULA_ENTRIES_FORMULA_TERM_TYPE at read
committed isolation level using instantaneous share row locking chosen by the
optimizer
Number of opens = 1
Rows seen = 3865
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=3
Number of deleted rows
visited=0
Number of pages
visited=7
Number of rows
qualified=3865
Number of rows
visited=3866
Scan type=btree
Tree height=3
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: 35.89
optimizer estimated
cost: 6785.98
Right result set:
Project-Restrict ResultSet (8):
Number of opens = 3863
Rows seen = 15452
Rows filtered = 11589
restriction = true
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: 399.01
Source result set:
Index Row to Base Row ResultSet for
FORMULA_ENTRIES:
Number of opens = 3863
Rows seen = 15452
Columns accessed from heap = {1, 2, 3,
4, 5}
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: 399.01
Index Scan ResultSet for
FORMULA_ENTRIES using constraint KB_FOMULA_ENTRIES_FORMULA_ID_FK at read
committed isolation level using instantaneous share row locking chosen by the
optimizer
Number of opens = 3863
Rows seen = 15452
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=11606
Number of rows
qualified=15452
Number of rows
visited=19315
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: 0.00
optimizer estimated
cost: 399.01
The bad query plan looks (when sent as a prepared statements) looks like:
Tue Feb 26 16:09:35 CST 2013 Thread[DRDAConnThread_4,5,main] (XID = 40971265),
(SESSIONID = 5), SELECT COUNT(*)
FROM KB.FORMULA_ENTRIES fe1
, KB.FORMULA_ENTRIES fe2
WHERE
(fe1.arg_0_term = ?) AND (fe1.arg_num = ?) AND (fe1.arg_term = ?) AND
(fe1.formula_type = ?)
AND (fe1.formula_id = fe2.formula_id) AND (fe2.arg_0_term = ?) AND (fe2.arg_num
= ?) AND (fe2.arg_term = ?) AND (fe2.formula_type = ?) ******* Project-Restrict
ResultSet (9):
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: 1.00
optimizer estimated cost: 43.36
Source result set:
Scalar Aggregate ResultSet:
Number of opens = 1
Rows input = 3863
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: 43.36
Index Key Optimization = false
Source result set:
Project-Restrict ResultSet (8):
Number of opens = 1
Rows seen = 3863
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: 43.36
Source result set:
Nested Loop Join ResultSet:
Number of opens = 1
Rows seen from the left = 3863
Rows seen from the right = 3863
Rows filtered = 0
Rows returned = 3863
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: 43.36
Left result set:
Index Row to Base Row ResultSet for
FORMULA_ENTRIES:
Number of opens = 1
Rows seen = 3863
Columns accessed from heap = {1, 2, 3, 4, 5}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 2.98
optimizer estimated cost: 10.89
Index Scan ResultSet for
FORMULA_ENTRIES using index KB_FORMULA_ENTRIES_FORMULA_TERM_ARG0_NUM_TYPE at
read committed isolation level using instantaneous share row locking chosen by
the optimizer
Number of opens = 1
Rows seen = 3863
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=5
Number of deleted rows visited=0
Number of pages visited=8
Number of rows qualified=3863
Number of rows visited=3864
Scan type=btree
Tree height=3
start position:
>= on first 4 column(s).
Ordered null semantics
on the following columns:
stop position:
> on first 4 column(s).
Ordered null semantics
on the following columns:
qualifiers:
None
optimizer estimated row count:
2.98
optimizer estimated cost: 10.89
Right result set:
Project-Restrict ResultSet (7):
Number of opens = 3863
Rows seen = 14922769
Rows filtered = 14918906
restriction = true
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: 32.47
Source result set:
Index Row to Base Row ResultSet for
FORMULA_ENTRIES:
Number of opens = 3863
Rows seen = 14922769
Columns accessed from heap = {1, 2, 3,
4, 5}
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: 32.47
Index Scan ResultSet for
FORMULA_ENTRIES using index KB_FORMULA_ENTRIES_FORMULA_TERM_ARG0_NUM_TYPE at
read committed isolation level using instantaneous share row locking chosen by
the optimizer
Number of opens = 3863
Rows seen = 14922769
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=5
Number of deleted rows
visited=0
Number of pages
visited=34767
Number of rows
qualified=14922769
Number of rows
visited=14926632
Scan type=btree
Tree height=3
start position:
>= on first 4
column(s).
Ordered null
semantics on the following columns:
stop position:
> on first 4
column(s).
Ordered null
semantics on the following columns:
qualifiers:
None
optimizer estimated row
count: 0.00
optimizer estimated
cost: 32.47
> dramatically worse query plan for prepared stamement vs calling directly
> ------------------------------------------------------------------------
>
> Key: DERBY-6093
> URL: https://issues.apache.org/jira/browse/DERBY-6093
> Project: Derby
> Issue Type: Bug
> Components: Store
> Affects Versions: 10.9.1.0
> Environment: Linux
> Reporter: Tony Brusseau
>
> If I run a count query given all the parameters directly, then the query
> executes in .05s, however, if I send it across as a prepared statement, then
> the query takes 40s to run (because is does a complete table scan on a table
> with 15m rows).
> The query looks like:
> SELECT COUNT(*)
> FROM KB.FORMULA_ENTRIES fe1, KB.FORMULA_ENTRIES fe2
> WHERE
> (fe1.arg_0_term = 1407374883620920) AND (fe1.arg_num = 1) AND (fe1.arg_term =
> 1407374883574780) AND (fe1.formula_type = 0)
> AND (fe1.formula_id = fe2.formula_id) AND (fe2.arg_0_term = 1407374883620920)
> AND (fe2.arg_num = 2) AND (fe2.arg_term = 1407374883663337) AND
> (fe2.formula_type = 0)
>
> or the prepared version like:
> SELECT COUNT(*)
> FROM KB.FORMULA_ENTRIES fe1
> , KB.FORMULA_ENTRIES fe2
> WHERE
> (fe1.arg_0_term = ?) AND (fe1.arg_num = ?) AND (fe1.arg_term = ?) AND
> (fe1.formula_type = ?)
> AND (fe1.formula_id = fe2.formula_id) AND (fe2.arg_0_term = ?) AND
> (fe2.arg_num = ?) AND (fe2.arg_term = ?) AND (fe2.formula_type = ?)
> The table is defined as:
> DROP TABLE KB.FORMULA_ENTRIES;
> CREATE TABLE KB.FORMULA_ENTRIES
> (
> formula_entries_id BIGINT NOT NULL,)
> formula_id BIGINT NOT NULL,
> arg_0_term BIGINT NOT NULL,
> arg_term BIGINT NOT NULL,
> arg_num INTEGER NOT NULL,
> formula_type SMALLINT NOT NULL
> );
> ALTER TABLE kb.formula_entries ADD CONSTRAINT kb_formula_entries_pk PRIMARY
> KEY (formula_entries_id);
> ALTER TABLE kb.formula_entries ADD CONSTRAINT kb_fomula_entries_formula_id_fk
> FOREIGN KEY (formula_id) REFERENCES kb.formula_term (term_id) ON
> DELETE CASCADE;
> CREATE INDEX kb_formula_entries_formula_term_type ON kb.formula_entries
> (arg_term, formula_type);
> CREATE INDEX kb_formula_entries_formula_term_arg0_type ON kb.formula_entries
> (arg_term, arg_0_term, formula_type);
> CREATE INDEX kb_formula_entries_formula_term_num_type ON kb.formula_entries
> (arg_term, arg_num, formula_type);
> CREATE INDEX kb_formula_entries_formula_term_arg0_num_type ON
> kb.formula_entries (arg_term, arg_0_term, arg_num, formula_type);
> *************************************************************************
> The good query plan (when *not* sent as a prepared statements) looks like:
> Tue Feb 26 16:15:21 CST 2013 Thread[DRDAConnThread_5,5,main] (XID =
> 40971291), (SESSIONID = 7), SELECT COUNT(*)
> FROM KB.FORMULA_ENTRIES fe1, KB.FORMULA_ENTRIES fe2
> WHERE
> (fe1.arg_0_term = 1407374883620920) AND (fe1.arg_num = 1) AND (fe1.arg_term =
> 1407374883574780) AND (fe1.formula_type = 0)
> AND (fe1.formula_id = fe2.formula_id) AND (fe2.arg_0_term = 1407374883620920)
> AND (fe2.arg_num = 2) AND (fe2.arg_term = 1407374883663337) AND
> (fe2.formula_type = 0) ******* Project-Restrict ResultSet (10):
> 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: 1.00
> optimizer estimated cost: 7184.99
> Source result set:
> Scalar Aggregate ResultSet:
> Number of opens = 1
> Rows input = 3863
> 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: 7184.99
> Index Key Optimization = false
> Source result set:
> Project-Restrict ResultSet (9):
> Number of opens = 1
> Rows seen = 3863
> 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: 7184.99
> Source result set:
> Nested Loop Join ResultSet:
> Number of opens = 1
> Rows seen from the left = 3863
> Rows seen from the right = 3863
> Rows filtered = 0
> Rows returned = 3863
> 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: 7184.99
> Left result set:
> Project-Restrict ResultSet (5):
> Number of opens = 1
> Rows seen = 3865
> Rows filtered = 2
> restriction = true
> 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: 35.89
> optimizer estimated cost: 6785.98
> Source result set:
> Index Row to Base Row ResultSet for
> FORMULA_ENTRIES:
> Number of opens = 1
> Rows seen = 3865
> Columns accessed from heap = {1, 2, 3,
> 4, 5}
> constructor time (milliseconds)
> = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count:
> 35.89
> optimizer estimated cost:
> 6785.98
> Index Scan ResultSet for
> FORMULA_ENTRIES using index KB_FORMULA_ENTRIES_FORMULA_TERM_TYPE at read
> committed isolation level using instantaneous share row locking chosen by the
> optimizer
> Number of opens = 1
> Rows seen = 3865
> 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=3
> Number of deleted rows
> visited=0
> Number of pages
> visited=7
> Number of rows
> qualified=3865
> Number of rows
> visited=3866
> Scan type=btree
> Tree height=3
> 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: 35.89
> optimizer estimated
> cost: 6785.98
> Right result set:
> Project-Restrict ResultSet (8):
> Number of opens = 3863
> Rows seen = 15452
> Rows filtered = 11589
> restriction = true
> 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: 399.01
> Source result set:
> Index Row to Base Row ResultSet for
> FORMULA_ENTRIES:
> Number of opens = 3863
> Rows seen = 15452
> Columns accessed from heap = {1, 2, 3,
> 4, 5}
> 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: 399.01
> Index Scan ResultSet for
> FORMULA_ENTRIES using constraint KB_FOMULA_ENTRIES_FORMULA_ID_FK at read
> committed isolation level using instantaneous share row locking chosen by the
> optimizer
> Number of opens = 3863
> Rows seen = 15452
> 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=11606
> Number of rows
> qualified=15452
> Number of rows
> visited=19315
> 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: 0.00
> optimizer estimated
> cost: 399.01
> *************************************************************************
> The bad query plan (when sent as a prepared statements) looks like:
> Tue Feb 26 16:09:35 CST 2013 Thread[DRDAConnThread_4,5,main] (XID =
> 40971265), (SESSIONID = 5), SELECT COUNT(*)
> FROM KB.FORMULA_ENTRIES fe1
> , KB.FORMULA_ENTRIES fe2
> WHERE
> (fe1.arg_0_term = ?) AND (fe1.arg_num = ?) AND (fe1.arg_term = ?) AND
> (fe1.formula_type = ?)
> AND (fe1.formula_id = fe2.formula_id) AND (fe2.arg_0_term = ?) AND
> (fe2.arg_num = ?) AND (fe2.arg_term = ?) AND (fe2.formula_type = ?) *******
> Project-Restrict ResultSet (9):
> 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: 1.00
> optimizer estimated cost: 43.36
> Source result set:
> Scalar Aggregate ResultSet:
> Number of opens = 1
> Rows input = 3863
> 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: 43.36
> Index Key Optimization = false
> Source result set:
> Project-Restrict ResultSet (8):
> Number of opens = 1
> Rows seen = 3863
> 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: 43.36
> Source result set:
> Nested Loop Join ResultSet:
> Number of opens = 1
> Rows seen from the left = 3863
> Rows seen from the right = 3863
> Rows filtered = 0
> Rows returned = 3863
> 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: 43.36
> Left result set:
> Index Row to Base Row ResultSet for
> FORMULA_ENTRIES:
> Number of opens = 1
> Rows seen = 3863
> Columns accessed from heap = {1, 2, 3, 4, 5}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 2.98
> optimizer estimated cost: 10.89
> Index Scan ResultSet for
> FORMULA_ENTRIES using index KB_FORMULA_ENTRIES_FORMULA_TERM_ARG0_NUM_TYPE at
> read committed isolation level using instantaneous share row locking chosen
> by the optimizer
> Number of opens = 1
> Rows seen = 3863
> 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=5
> Number of deleted rows visited=0
> Number of pages visited=8
> Number of rows qualified=3863
> Number of rows visited=3864
> Scan type=btree
> Tree height=3
> start position:
> >= on first 4 column(s).
> Ordered null semantics
> on the following columns:
> stop position:
> > on first 4 column(s).
> Ordered null semantics
> on the following columns:
> qualifiers:
> None
> optimizer estimated row count:
> 2.98
> optimizer estimated cost: 10.89
> Right result set:
> Project-Restrict ResultSet (7):
> Number of opens = 3863
> Rows seen = 14922769
> Rows filtered = 14918906
> restriction = true
> 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: 32.47
> Source result set:
> Index Row to Base Row ResultSet for
> FORMULA_ENTRIES:
> Number of opens = 3863
> Rows seen = 14922769
> Columns accessed from heap = {1, 2, 3,
> 4, 5}
> 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: 32.47
> Index Scan ResultSet for
> FORMULA_ENTRIES using index KB_FORMULA_ENTRIES_FORMULA_TERM_ARG0_NUM_TYPE at
> read committed isolation level using instantaneous share row locking chosen
> by the optimizer
> Number of opens = 3863
> Rows seen = 14922769
> 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=5
> Number of deleted rows
> visited=0
> Number of pages
> visited=34767
> Number of rows
> qualified=14922769
> Number of rows
> visited=14926632
> Scan type=btree
> Tree height=3
> start position:
> >= on first 4
> column(s).
> Ordered null
> semantics on the following columns:
> stop position:
> > on first 4
> column(s).
> Ordered null
> semantics on the following columns:
> qualifiers:
> None
> optimizer estimated row
> count: 0.00
> optimizer estimated
> cost: 32.47
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
