db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Tony Brusseau (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (DERBY-6093) dramatically worse query plan for prepared stamement vs calling directly
Date Tue, 26 Feb 2013 22:42:12 GMT

     [ 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

Mime
View raw message