You are viewing a plain text version of this content. The canonical link for it is here.
Posted to derby-dev@db.apache.org by "John English (JIRA)" <ji...@apache.org> on 2013/04/03 17:09:16 UTC
[jira] [Updated] (DERBY-6148) Peculiar sorting behaviour
[ https://issues.apache.org/jira/browse/DERBY-6148?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
John English updated DERBY-6148:
--------------------------------
Description:
I have a query that looks like this:
SELECT tests.id,tests.item,title FROM tests,item_usage
WHERE username=? AND user_role>?
AND item_usage.item=tests.item
ORDER BY tests.item,title
The result ordering is by item code followed by title, but the item codes are listed in the order in which they appear in the ITEMS table where they are the primary key rather than in ascending order as expected. If however I change the ORDER BY clause to sort by item_usage.item rather than tests.item, it works correctly, even though the two values are the same!
The same thing happens in another unrelated query involving item_usage, and the same workaround cures it.
The relevant tables are defined like so:
CREATE TABLE item_usage (
username VARCHAR(15) NOT NULL,
item VARCHAR(15) NOT NULL,
value SMALLINT DEFAULT 0,
CONSTRAINT item_usage_pk PRIMARY KEY (username,item),
CONSTRAINT item_usage_1 FOREIGN KEY (username)
REFERENCES users(username)
ON DELETE CASCADE,
CONSTRAINT item_usage_2 FOREIGN KEY (item)
REFERENCES items(item)
ON DELETE CASCADE,
CONSTRAINT item_usage_3 CHECK (value BETWEEN 0 AND 4)
);
CREATE TABLE tests (
id INTEGER GENERATED ALWAYS AS IDENTITY,
item VARCHAR(15) NOT NULL,
title VARCHAR(255) NOT NULL,
disp SMALLINT NOT NULL DEFAULT 0,
starttime TIMESTAMP DEFAULT NULL,
endtime TIMESTAMP DEFAULT NULL,
offsetx INTEGER NOT NULL DEFAULT 0,
offsety INTEGER NOT NULL DEFAULT 0,
rate INTEGER NOT NULL DEFAULT 0,
duration INTEGER NOT NULL DEFAULT 0,
calibrate INTEGER NOT NULL DEFAULT 0,
deadline TIMESTAMP DEFAULT NULL,
stepsize INTEGER NOT NULL DEFAULT 0,
interval INTEGER NOT NULL DEFAULT 0,
stand CHAR(1) DEFAULT NULL,
hidden CHAR(1) DEFAULT NULL,
repeated CHAR(1) DEFAULT NULL,
private CHAR(1) DEFAULT NULL,
sequential CHAR(1) DEFAULT NULL,
final CHAR(1) DEFAULT NULL,
notes CLOB DEFAULT NULL,
testxml CLOB NOT NULL,
author VARCHAR(15) NOT NULL,
time TIMESTAMP NOT NULL,
CONSTRAINT tests_pk PRIMARY KEY (id),
CONSTRAINT tests_1 UNIQUE (item, title),
CONSTRAINT tests_2 FOREIGN KEY (item)
REFERENCES items(item)
ON DELETE CASCADE,
CONSTRAINT tests_3 CHECK (disp BETWEEN 0 AND 100),
CONSTRAINT tests_4 CHECK (rate BETWEEN 0 AND 100),
CONSTRAINT tests_5 CHECK (stepsize BETWEEN 0 AND 100)
);
If I run the query manually I get this, as expected:
ID ITEM TITLE
37 60001 Test 1
42 60001 Test 2
51 60001 Test 3
17 61303 Test 2a
16 61303 Test 2b
7 7205731 Test 2a
8 7205731 Test 2b
Now, this is actually part of a web app that should turn this into a list of options in a <select> item using the following code:
while (query.next()) {
println("<option value='" + query.getInt("id") + "'>"
+ encode(query.getString("item") + ": "
+ query.getString("title")) + "</option>");
}
What I actually get is this:
<option value="17">61303: Test 2a</option>
<option value="16">61303: Test 2b</option>
<option value="7">7205731: Test 2a</option>
<option value="8">7205731: Test 2b</option>
<option value="37">60001: Test 1</option>
<option value="42">60001: Test 2</option>
<option value="51">60001: Test 3</option>
The results are sorted by item then by title, but the item order is the order in which they were originally inserted into the items table (where the item and item description are stored, referenced by item_usage.item) rather than by item code.
I've tried to reproduce this behaviour in a simple example, but without success. I have logged the query plans for both versions; the log output is as follows, with the INCORRECT query (using ORDER BY tests.item) followed later by the CORRECT query (using ORDER BY item_usage.item):
Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID = 7222148), (SESSIONID = 26), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY tests.item,title :End prepared statement with 1 parameters begin parameter #1: TAMMY :end parameter
Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID = 7222148), (SESSIONID = 26), SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY tests.item,title ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 30
Number of reads from hash table = 30
Number of writes to hash table = 30
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 19.34
optimizer estimated cost: 5186.92
Source result set:
Project-Restrict ResultSet (7):
Number of opens = 1
Rows seen = 30
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: 19.34
optimizer estimated cost: 5186.92
Source result set:
Nested Loop Join ResultSet:
Number of opens = 1
Rows seen from the left = 5
Rows seen from the right = 30
Rows filtered = 0
Rows returned = 30
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 19.34
optimizer estimated cost: 5186.92
Left result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 5
Rows filtered = 0
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: 1.80
optimizer estimated cost: 17.01
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 5
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 17.01
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 5
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=2
Number of rows qualified=5
Number of rows visited=6
Scan type=btree
Tree height=2
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: 1.80
optimizer estimated cost: 17.01
Right result set:
Index Row to Base Row ResultSet for TESTS:
Number of opens = 5
Rows seen = 30
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 19.34
optimizer estimated cost: 5169.91
Index Scan ResultSet for TESTS using constraint TESTS_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 5
Rows seen = 30
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched={0, 2}
Number of columns fetched=2
Number of deleted rows visited=9
Number of pages visited=5
Number of rows qualified=30
Number of rows visited=43
Scan type=btree
Tree height=1
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: 19.34
optimizer estimated cost: 5169.91
Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID = 7222148), (SESSIONID = 26), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID = 7222148), (SESSIONID = 26), (DATABASE = ../db/db_copy), (DRDAID = null), Rolling back
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222149), (SESSIONID = 27), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222149), (SESSIONID = 27), (DATABASE = ../db/db_copy), (DRDAID = null), Rolling back
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222150), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222151), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT items.item,title,user_role FROM items,item_usage WHERE items.item=item_usage.item AND username=? AND user_role>? ORDER BY item_usage.item :End prepared statement with 2 parameters begin parameter #1: TAMMY :end parameter begin parameter #2: -1 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222151), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222152), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222152), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Source result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=1
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: 1.00
optimizer estimated cost: 5.80
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222152), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222153), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222153), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 7
Number of reads from hash table = 7
Number of writes to hash table = 7
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 271
Rows filtered = 264
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: 55.77
optimizer estimated cost: 439.00
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 271
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 271
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=2
Number of pages visited=4
Number of rows qualified=271
Number of rows visited=274
Scan type=btree
Tree height=2
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: 55.77
optimizer estimated cost: 439.00
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222153), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222154), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 61108 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222154), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Source result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=1
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: 1.00
optimizer estimated cost: 5.80
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222154), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222155), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 61108 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222155), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 1
Rows filtered = 0
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: 55.77
optimizer estimated cost: 439.00
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using 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=2
Number of rows qualified=1
Number of rows visited=2
Scan type=btree
Tree height=2
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: 55.77
optimizer estimated cost: 439.00
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222155), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222156), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 61303 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222156), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Source result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=1
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: 1.00
optimizer estimated cost: 5.80
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222156), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222157), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 61303 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222157), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 3
Number of reads from hash table = 3
Number of writes to hash table = 3
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 146
Rows filtered = 143
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: 55.77
optimizer estimated cost: 439.00
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 146
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 146
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=4
Number of rows qualified=146
Number of rows visited=147
Scan type=btree
Tree height=2
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: 55.77
optimizer estimated cost: 439.00
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222157), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222158), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 7205731 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222158), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Source result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=1
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: 1.00
optimizer estimated cost: 5.80
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222158), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222159), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 7205731 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222159), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 2
Number of reads from hash table = 2
Number of writes to hash table = 2
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 28
Rows filtered = 26
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: 55.77
optimizer estimated cost: 439.00
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 28
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 28
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=1
Number of pages visited=2
Number of rows qualified=28
Number of rows visited=30
Scan type=btree
Tree height=2
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: 55.77
optimizer estimated cost: 439.00
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222159), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222160), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: XY101 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222160), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Source result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=1
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: 1.00
optimizer estimated cost: 5.80
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222160), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: XY101 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 2
Number of reads from hash table = 2
Number of writes to hash table = 2
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 3
Rows filtered = 1
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: 55.77
optimizer estimated cost: 439.00
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 3
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 3
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=2
Number of pages visited=2
Number of rows qualified=3
Number of rows visited=5
Scan type=btree
Tree height=2
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: 55.77
optimizer estimated cost: 439.00
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), SELECT items.item,title,user_role FROM items,item_usage WHERE items.item=item_usage.item AND username=? AND user_role>? ORDER BY item_usage.item ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 5
Number of reads from hash table = 5
Number of writes to hash table = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 27.45
Source result set:
Project-Restrict ResultSet (9):
Number of opens = 1
Rows seen = 5
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.80
optimizer estimated cost: 27.45
Source result set:
Sort ResultSet:
Number of opens = 1
Rows input = 5
Rows returned = 5
Eliminate duplicates = false
In sorted order = false
Sort information:
Number of rows input=5
Number of rows output=5
Sort type=internal
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 27.45
Source result set:
Project-Restrict ResultSet (7):
Number of opens = 1
Rows seen = 5
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.80
optimizer estimated cost: 27.45
Source result set:
Nested Loop Exists Join ResultSet:
Number of opens = 1
Rows seen from the left = 5
Rows seen from the right = 5
Rows filtered = 0
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 27.45
Left result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 5
Rows filtered = 0
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: 1.80
optimizer estimated cost: 17.01
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 5
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 17.01
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 5
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=2
Number of rows qualified=5
Number of rows visited=6
Scan type=btree
Tree height=2
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: 1.80
optimizer estimated cost: 17.01
Right result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 5
Rows seen = 5
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: 1.80
optimizer estimated cost: 10.43
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 5
Rows seen = 5
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=5
Number of rows qualified=5
Number of rows visited=5
Scan type=btree
Tree height=1
start position:
>= on first 1 column(s).
Ordered null semantics on the following columns:
0
stop position:
> on first 1 column(s).
Ordered null semantics on the following columns:
0
qualifiers:
None
optimizer estimated row count: 1.80
optimizer estimated cost: 10.43
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222162), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222162), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Source result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=1
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: 1.00
optimizer estimated cost: 5.80
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222162), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222163), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222163), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 7
Number of reads from hash table = 7
Number of writes to hash table = 7
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 271
Rows filtered = 264
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: 55.77
optimizer estimated cost: 439.00
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 271
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 271
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=2
Number of pages visited=4
Number of rows qualified=271
Number of rows visited=274
Scan type=btree
Tree height=2
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: 55.77
optimizer estimated cost: 439.00
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222163), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222164), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND username=? :End prepared statement with 2 parameters begin parameter #1: 60001 :end parameter begin parameter #2: TAMMY :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222164), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND username=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.36
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.36
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=3
Number of deleted rows visited=0
Number of pages visited=2
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=2
start position:
>= on first 2 column(s).
Ordered null semantics on the following columns:
stop position:
> on first 2 column(s).
Ordered null semantics on the following columns:
qualifiers:
None
optimizer estimated row count: 1.00
optimizer estimated cost: 5.36
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222164), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222165), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT item FROM item_usage WHERE username=? AND user_role>0 ORDER BY item :End prepared statement with 1 parameters begin parameter #1: TAMMY :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222165), (SESSIONID = 28), SELECT item FROM item_usage WHERE username=? AND user_role>0 ORDER BY item ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 5
Number of reads from hash table = 5
Number of writes to hash table = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 17.20
Source result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 5
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.80
optimizer estimated cost: 17.20
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 5
Rows filtered = 0
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: 1.80
optimizer estimated cost: 17.20
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 5
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 17.20
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 5
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched={0, 2}
Number of columns fetched=2
Number of deleted rows visited=2
Number of pages visited=2
Number of rows qualified=5
Number of rows visited=8
Scan type=btree
Tree height=2
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: 1.80
optimizer estimated cost: 17.20
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222165), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222166), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM users WHERE username=? AND manager IS NOT NULL :End prepared statement with 1 parameters begin parameter #1: TAMMY :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222166), (SESSIONID = 28), SELECT * FROM users WHERE username=? AND manager IS NOT NULL ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.59
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 1
Rows filtered = 0
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: 1.00
optimizer estimated cost: 5.59
Source result set:
Index Row to Base Row ResultSet for USERS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2, 3, 4, 5, 6, 7, 8, 9, 10}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.59
Index Scan ResultSet for USERS using constraint USERS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=2
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=2
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: 1.00
optimizer estimated cost: 5.59
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222166), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222167), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT count(*) AS msgs FROM messages WHERE item IS NULL AND id>? :End prepared statement with 1 parameters begin parameter #1: 1 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222167), (SESSIONID = 28), SELECT count(*) AS msgs FROM messages WHERE item IS NULL AND id>? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 1.57
Source result set:
Project-Restrict ResultSet (6):
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: 1.57
Source result set:
Scalar Aggregate ResultSet:
Number of opens = 1
Rows input = 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: 1.57
Index Key Optimization = false
Source result set:
Project-Restrict ResultSet (5):
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: 1.57
Source result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 0
Rows filtered = 0
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: 1.57
Source result set:
Index Row to Base Row ResultSet for MESSAGES:
Number of opens = 1
Rows seen = 0
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: 1.57
Index Scan ResultSet for MESSAGES using constraint MESSAGES_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
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 deleted rows visited=0
Number of pages visited=1
Number of rows qualified=0
Number of rows visited=0
Scan type=btree
Tree height=1
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: 1.57
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222167), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222168), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT count(*) AS msgs FROM messages WHERE item=? AND id>? :End prepared statement with 2 parameters begin parameter #1: 60001 :end parameter begin parameter #2: 1 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222168), (SESSIONID = 28), SELECT count(*) AS msgs FROM messages WHERE item=? AND id>? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 83.86
Source result set:
Project-Restrict ResultSet (6):
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: 83.86
Source result set:
Scalar Aggregate ResultSet:
Number of opens = 1
Rows input = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 0.20
optimizer estimated cost: 83.86
Index Key Optimization = false
Source result set:
Project-Restrict ResultSet (5):
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.20
optimizer estimated cost: 83.86
Source result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 0
Rows filtered = 0
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.20
optimizer estimated cost: 83.86
Source result set:
Index Row to Base Row ResultSet for MESSAGES:
Number of opens = 1
Rows seen = 0
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.20
optimizer estimated cost: 83.86
Index Scan ResultSet for MESSAGES using constraint MESSAGES_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
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 deleted rows visited=1
Number of pages visited=1
Number of rows qualified=0
Number of rows visited=1
Scan type=btree
Tree height=1
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.20
optimizer estimated cost: 83.86
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222168), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222169), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT COUNT(*) FROM edits_view WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222169), (SESSIONID = 28), SELECT COUNT(*) FROM edits_view WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 1001.34
Source result set:
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) = 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: 1001.34
Source result set:
Scalar Aggregate ResultSet:
Number of opens = 1
Rows input = 4
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.10
optimizer estimated cost: 1001.34
Index Key Optimization = false
Source result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 4
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: 4.10
optimizer estimated cost: 1001.34
Source result set:
Index Row to Base Row ResultSet for XMLTEMP:
Number of opens = 1
Rows seen = 4
Columns accessed from heap = {0, 1, 5}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.10
optimizer estimated cost: 1001.34
Index Scan ResultSet for XMLTEMP using constraint XMLTEMP_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 4
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=3
Number of deleted rows visited=6
Number of pages visited=1
Number of rows qualified=4
Number of rows visited=11
Scan type=btree
Tree height=1
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: 4.10
optimizer estimated cost: 1001.34
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222169), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222170), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT title,DateTimeFormat(t_time,null) AS t_time,username,link FROM edits_view WHERE item=? ORDER BY username ASC,1 ASC :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222170), (SESSIONID = 28), SELECT title,DateTimeFormat(t_time,null) AS t_time,username,link FROM edits_view WHERE item=? ORDER BY username ASC,1 ASC ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 4
Number of reads from hash table = 4
Number of writes to hash table = 4
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.10
optimizer estimated cost: 1001.34
Source result set:
Sort ResultSet:
Number of opens = 1
Rows input = 4
Rows returned = 4
Eliminate duplicates = false
In sorted order = false
Sort information:
Number of rows input=4
Number of rows output=4
Sort type=internal
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.10
optimizer estimated cost: 1001.34
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 4
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: 4.10
optimizer estimated cost: 1001.34
Source result set:
Index Row to Base Row ResultSet for XMLTEMP:
Number of opens = 1
Rows seen = 4
Columns accessed from heap = {0, 1, 5}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.10
optimizer estimated cost: 1001.34
Index Scan ResultSet for XMLTEMP using constraint XMLTEMP_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 4
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=3
Number of deleted rows visited=6
Number of pages visited=1
Number of rows qualified=4
Number of rows visited=11
Scan type=btree
Tree height=1
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: 4.10
optimizer estimated cost: 1001.34
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222170), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222171), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT COUNT(*) FROM tests_view WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222171), (SESSIONID = 28), SELECT COUNT(*) FROM tests_view WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 2873.71
Source result set:
Project-Restrict ResultSet (8):
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: 2873.71
Source result set:
Scalar Aggregate ResultSet:
Number of opens = 1
Rows input = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.75
optimizer estimated cost: 2873.71
Index Key Optimization = false
Source result set:
Attached subqueries:
Begin Subquery Number 0
Any ResultSet (Attached to 4):
Number of opens = 5
Rows seen = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 36.00
optimizer estimated cost: 23.54
Source result set:
Project-Restrict ResultSet (6):
Number of opens = 5
Rows seen = 40
Rows filtered = 36
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: 36.00
optimizer estimated cost: 23.54
Source result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 39
Rows seen from the right = 1
Rows returned = 40
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 11.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 38
Rows seen from the right = 1
Rows returned = 39
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 36
Rows seen from the right = 2
Rows returned = 38
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 9.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 33
Rows seen from the right = 3
Rows returned = 36
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 8.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 29
Rows seen from the right = 4
Rows returned = 33
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 7.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 25
Rows seen from the right = 4
Rows returned = 29
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 6.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 20
Rows seen from the right = 5
Rows returned = 25
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 5.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 15
Rows seen from the right = 5
Rows returned = 20
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 10
Rows seen from the right = 5
Rows returned = 15
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 3.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 5
Rows seen from the right = 5
Rows returned = 10
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: 0.00
Left result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 4
Rows returned = 4
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 4
Rows returned = 4
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 3
Rows returned = 3
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 2
Rows returned = 2
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 1
Rows returned = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 1
Rows returned = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
End Subquery Number 0
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 5
Rows filtered = 4
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: 10.75
optimizer estimated cost: 2873.71
Source result set:
Index Row to Base Row ResultSet for TESTS:
Number of opens = 1
Rows seen = 5
Columns accessed from heap = {0, 9, 21, 22, 23}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.75
optimizer estimated cost: 2873.71
Index Scan ResultSet for TESTS using constraint TESTS_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 5
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=3
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=5
Number of rows visited=6
Scan type=btree
Tree height=1
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: 10.75
optimizer estimated cost: 2873.71
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222171), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222172), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT title,DateTimeFormat(t_time,null) AS t_time,author,link FROM tests_view WHERE item=? ORDER BY author ASC,1 ASC :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222172), (SESSIONID = 28), SELECT title,DateTimeFormat(t_time,null) AS t_time,author,link FROM tests_view WHERE item=? ORDER BY author ASC,1 ASC ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.75
optimizer estimated cost: 2873.71
Source result set:
Sort ResultSet:
Number of opens = 1
Rows input = 1
Rows returned = 1
Eliminate duplicates = false
In sorted order = false
Sort information:
Number of rows input=1
Number of rows output=1
Sort type=internal
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.75
optimizer estimated cost: 2873.71
Source result set:
Attached subqueries:
Begin Subquery Number 0
Any ResultSet (Attached to 3):
Number of opens = 5
Rows seen = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 387.00
optimizer estimated cost: 253.09
Source result set:
Project-Restrict ResultSet (5):
Number of opens = 5
Rows seen = 40
Rows filtered = 36
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: 387.00
optimizer estimated cost: 253.09
Source result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 39
Rows seen from the right = 1
Rows returned = 40
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 11.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 38
Rows seen from the right = 1
Rows returned = 39
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 36
Rows seen from the right = 2
Rows returned = 38
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 9.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 33
Rows seen from the right = 3
Rows returned = 36
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 8.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 29
Rows seen from the right = 4
Rows returned = 33
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 7.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 25
Rows seen from the right = 4
Rows returned = 29
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 6.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 20
Rows seen from the right = 5
Rows returned = 25
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 5.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 15
Rows seen from the right = 5
Rows returned = 20
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 10
Rows seen from the right = 5
Rows returned = 15
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 3.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 5
Rows seen from the right = 5
Rows returned = 10
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: 0.00
Left result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 4
Rows returned = 4
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 4
Rows returned = 4
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 3
Rows returned = 3
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 2
Rows returned = 2
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 1
Rows returned = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 1
Rows returned = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
End Subquery Number 0
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 5
Rows filtered = 4
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: 10.75
optimizer estimated cost: 2873.71
Source result set:
Index Row to Base Row ResultSet for TESTS:
Number of opens = 1
Rows seen = 5
Columns accessed from heap = {0, 9, 21, 22, 23}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.75
optimizer estimated cost: 2873.71
Index Scan ResultSet for TESTS using constraint TESTS_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 5
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=3
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=5
Number of rows visited=6
Scan type=btree
Tree height=1
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: 10.75
optimizer estimated cost: 2873.71
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222172), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Begin compiling prepared statement: SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY item_usage.item,title :End prepared statement
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), End compiling prepared statement: SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY item_usage.item,title :End prepared statement
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY item_usage.item,title :End prepared statement with 1 parameters begin parameter #1: TAMMY :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY item_usage.item,title ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 30
Number of reads from hash table = 30
Number of writes to hash table = 30
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 5186.92
Source result set:
Project-Restrict ResultSet (9):
Number of opens = 1
Rows seen = 30
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.80
optimizer estimated cost: 5186.92
Source result set:
Sort ResultSet:
Number of opens = 1
Rows input = 30
Rows returned = 30
Eliminate duplicates = false
In sorted order = false
Sort information:
Number of rows input=30
Number of rows output=30
Sort type=internal
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 19.34
optimizer estimated cost: 5186.92
Source result set:
Project-Restrict ResultSet (7):
Number of opens = 1
Rows seen = 30
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: 19.34
optimizer estimated cost: 5186.92
Source result set:
Nested Loop Join ResultSet:
Number of opens = 1
Rows seen from the left = 5
Rows seen from the right = 30
Rows filtered = 0
Rows returned = 30
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 19.34
optimizer estimated cost: 5186.92
Left result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 5
Rows filtered = 0
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: 1.80
optimizer estimated cost: 17.01
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 5
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 17.01
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 5
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=2
Number of rows qualified=5
Number of rows visited=6
Scan type=btree
Tree height=2
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: 1.80
optimizer estimated cost: 17.01
Right result set:
Index Row to Base Row ResultSet for TESTS:
Number of opens = 5
Rows seen = 30
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 19.34
optimizer estimated cost: 5169.91
Index Scan ResultSet for TESTS using constraint TESTS_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 5
Rows seen = 30
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={0, 2}
Number of columns fetched=2
Number of deleted rows visited=9
Number of pages visited=5
Number of rows qualified=30
Number of rows visited=43
Scan type=btree
Tree height=1
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: 19.34
optimizer estimated cost: 5169.91
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Rolling back
was:
I have a query that looks like this:
SELECT tests.id,tests.item,title FROM tests,item_usage
WHERE username=? AND user_role>?
AND item_usage.item=tests.item
ORDER BY tests.item,title
The result ordering is by item code followed by title, but the item codes are listed in the order in which they appear in the ITEMS table where they are the primary key rather than in ascending order as expected. If however I change the ORDER BY clause to sort by item_usage.item rather than tests.item, it works correctly, even though the two values are the same!
The same thing happens in another unrelated query involving item_usage, and the same workaround cures it.
The relevant tables are defined like so:
CREATE TABLE item_usage (
username VARCHAR(15) NOT NULL,
item VARCHAR(15) NOT NULL,
value SMALLINT DEFAULT 0,
CONSTRAINT item_usage_pk PRIMARY KEY (username,item),
CONSTRAINT item_usage_1 FOREIGN KEY (username)
REFERENCES users(username)
ON DELETE CASCADE,
CONSTRAINT item_usage_2 FOREIGN KEY (item)
REFERENCES items(item)
ON DELETE CASCADE,
CONSTRAINT item_usage_3 CHECK (value BETWEEN 0 AND 4)
);
CREATE TABLE tests (
id INTEGER GENERATED ALWAYS AS IDENTITY,
item VARCHAR(15) NOT NULL,
title VARCHAR(255) NOT NULL,
disp SMALLINT NOT NULL DEFAULT 0,
starttime TIMESTAMP DEFAULT NULL,
endtime TIMESTAMP DEFAULT NULL,
offsetx INTEGER NOT NULL DEFAULT 0,
offsety INTEGER NOT NULL DEFAULT 0,
rate INTEGER NOT NULL DEFAULT 0,
duration INTEGER NOT NULL DEFAULT 0,
calibrate INTEGER NOT NULL DEFAULT 0,
deadline TIMESTAMP DEFAULT NULL,
stepsize INTEGER NOT NULL DEFAULT 0,
interval INTEGER NOT NULL DEFAULT 0,
stand CHAR(1) DEFAULT NULL,
hidden CHAR(1) DEFAULT NULL,
repeated CHAR(1) DEFAULT NULL,
private CHAR(1) DEFAULT NULL,
sequential CHAR(1) DEFAULT NULL,
final CHAR(1) DEFAULT NULL,
notes CLOB DEFAULT NULL,
testxml CLOB NOT NULL,
author VARCHAR(15) NOT NULL,
time TIMESTAMP NOT NULL,
CONSTRAINT tests_pk PRIMARY KEY (id),
CONSTRAINT tests_1 UNIQUE (item, title),
CONSTRAINT tests_2 FOREIGN KEY (item)
REFERENCES items(item)
ON DELETE CASCADE,
CONSTRAINT tests_3 CHECK (disp BETWEEN 0 AND 100),
CONSTRAINT tests_4 CHECK (rate BETWEEN 0 AND 100),
CONSTRAINT tests_5 CHECK (stepsize BETWEEN 0 AND 100)
);
If I run the query manually I get this, as expected:
ID ITEM TITLE
37 60001 Test 1
42 60001 Test 2
51 60001 Test 3
17 61303 Test 2a
16 61303 Test 2b
7 7205731 Test 2a
8 7205731 Test 2b
Now, this is actually part of a web app that should turn this into a list of options in a <select> item using the following code:
while (query.next()) {
println("<option value='" + query.getInt("id") + "'>"
+ encode(query.getString("item") + ": "
+ query.getString("title")) + "</option>");
}
What I actually get is this:
<option value="17">61303: Test 2a</option>
<option value="16">61303: Test 2b</option>
<option value="7">7205731: Test 2a</option>
<option value="8">7205731: Test 2b</option>
<option value="37">60001: Test 1</option>
<option value="42">60001: Test 2</option>
<option value="51">60001: Test 3</option>
The results are sorted by item then by title, but the item order is the order in which they were originally inserted into the items table (where the item and item description are stored, referenced by item_usage.item) rather than by item code.
I've tried without success to reproduce this behaviour in a simple example, but without success. I have logged the query plans for both versions; the log output is as follows, with the INCORRECT query (using ORDER BY tests.item) followed later by the CORRECT query (using ORDER BY item_usage.item):
Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID = 7222148), (SESSIONID = 26), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY tests.item,title :End prepared statement with 1 parameters begin parameter #1: TAMMY :end parameter
Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID = 7222148), (SESSIONID = 26), SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY tests.item,title ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 30
Number of reads from hash table = 30
Number of writes to hash table = 30
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 19.34
optimizer estimated cost: 5186.92
Source result set:
Project-Restrict ResultSet (7):
Number of opens = 1
Rows seen = 30
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: 19.34
optimizer estimated cost: 5186.92
Source result set:
Nested Loop Join ResultSet:
Number of opens = 1
Rows seen from the left = 5
Rows seen from the right = 30
Rows filtered = 0
Rows returned = 30
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 19.34
optimizer estimated cost: 5186.92
Left result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 5
Rows filtered = 0
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: 1.80
optimizer estimated cost: 17.01
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 5
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 17.01
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 5
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=2
Number of rows qualified=5
Number of rows visited=6
Scan type=btree
Tree height=2
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: 1.80
optimizer estimated cost: 17.01
Right result set:
Index Row to Base Row ResultSet for TESTS:
Number of opens = 5
Rows seen = 30
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 19.34
optimizer estimated cost: 5169.91
Index Scan ResultSet for TESTS using constraint TESTS_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 5
Rows seen = 30
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched={0, 2}
Number of columns fetched=2
Number of deleted rows visited=9
Number of pages visited=5
Number of rows qualified=30
Number of rows visited=43
Scan type=btree
Tree height=1
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: 19.34
optimizer estimated cost: 5169.91
Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID = 7222148), (SESSIONID = 26), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID = 7222148), (SESSIONID = 26), (DATABASE = ../db/db_copy), (DRDAID = null), Rolling back
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222149), (SESSIONID = 27), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222149), (SESSIONID = 27), (DATABASE = ../db/db_copy), (DRDAID = null), Rolling back
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222150), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222151), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT items.item,title,user_role FROM items,item_usage WHERE items.item=item_usage.item AND username=? AND user_role>? ORDER BY item_usage.item :End prepared statement with 2 parameters begin parameter #1: TAMMY :end parameter begin parameter #2: -1 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222151), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222152), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222152), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Source result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=1
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: 1.00
optimizer estimated cost: 5.80
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222152), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222153), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222153), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 7
Number of reads from hash table = 7
Number of writes to hash table = 7
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 271
Rows filtered = 264
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: 55.77
optimizer estimated cost: 439.00
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 271
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 271
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=2
Number of pages visited=4
Number of rows qualified=271
Number of rows visited=274
Scan type=btree
Tree height=2
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: 55.77
optimizer estimated cost: 439.00
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222153), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222154), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 61108 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222154), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Source result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=1
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: 1.00
optimizer estimated cost: 5.80
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222154), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222155), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 61108 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222155), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 1
Rows filtered = 0
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: 55.77
optimizer estimated cost: 439.00
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using 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=2
Number of rows qualified=1
Number of rows visited=2
Scan type=btree
Tree height=2
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: 55.77
optimizer estimated cost: 439.00
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222155), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222156), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 61303 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222156), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Source result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=1
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: 1.00
optimizer estimated cost: 5.80
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222156), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222157), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 61303 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222157), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 3
Number of reads from hash table = 3
Number of writes to hash table = 3
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 146
Rows filtered = 143
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: 55.77
optimizer estimated cost: 439.00
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 146
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 146
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=4
Number of rows qualified=146
Number of rows visited=147
Scan type=btree
Tree height=2
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: 55.77
optimizer estimated cost: 439.00
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222157), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222158), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 7205731 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222158), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Source result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=1
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: 1.00
optimizer estimated cost: 5.80
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222158), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222159), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 7205731 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222159), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 2
Number of reads from hash table = 2
Number of writes to hash table = 2
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 28
Rows filtered = 26
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: 55.77
optimizer estimated cost: 439.00
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 28
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 28
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=1
Number of pages visited=2
Number of rows qualified=28
Number of rows visited=30
Scan type=btree
Tree height=2
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: 55.77
optimizer estimated cost: 439.00
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222159), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222160), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: XY101 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222160), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Source result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=1
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: 1.00
optimizer estimated cost: 5.80
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222160), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: XY101 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 2
Number of reads from hash table = 2
Number of writes to hash table = 2
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 3
Rows filtered = 1
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: 55.77
optimizer estimated cost: 439.00
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 3
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 3
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=2
Number of pages visited=2
Number of rows qualified=3
Number of rows visited=5
Scan type=btree
Tree height=2
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: 55.77
optimizer estimated cost: 439.00
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), SELECT items.item,title,user_role FROM items,item_usage WHERE items.item=item_usage.item AND username=? AND user_role>? ORDER BY item_usage.item ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 5
Number of reads from hash table = 5
Number of writes to hash table = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 27.45
Source result set:
Project-Restrict ResultSet (9):
Number of opens = 1
Rows seen = 5
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.80
optimizer estimated cost: 27.45
Source result set:
Sort ResultSet:
Number of opens = 1
Rows input = 5
Rows returned = 5
Eliminate duplicates = false
In sorted order = false
Sort information:
Number of rows input=5
Number of rows output=5
Sort type=internal
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 27.45
Source result set:
Project-Restrict ResultSet (7):
Number of opens = 1
Rows seen = 5
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.80
optimizer estimated cost: 27.45
Source result set:
Nested Loop Exists Join ResultSet:
Number of opens = 1
Rows seen from the left = 5
Rows seen from the right = 5
Rows filtered = 0
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 27.45
Left result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 5
Rows filtered = 0
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: 1.80
optimizer estimated cost: 17.01
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 5
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 17.01
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 5
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=2
Number of rows qualified=5
Number of rows visited=6
Scan type=btree
Tree height=2
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: 1.80
optimizer estimated cost: 17.01
Right result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 5
Rows seen = 5
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: 1.80
optimizer estimated cost: 10.43
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 5
Rows seen = 5
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=5
Number of rows qualified=5
Number of rows visited=5
Scan type=btree
Tree height=1
start position:
>= on first 1 column(s).
Ordered null semantics on the following columns:
0
stop position:
> on first 1 column(s).
Ordered null semantics on the following columns:
0
qualifiers:
None
optimizer estimated row count: 1.80
optimizer estimated cost: 10.43
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222162), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222162), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Source result set:
Index Row to Base Row ResultSet for ITEMS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.80
Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=1
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: 1.00
optimizer estimated cost: 5.80
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222162), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222163), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222163), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 7
Number of reads from hash table = 7
Number of writes to hash table = 7
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 271
Rows filtered = 264
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: 55.77
optimizer estimated cost: 439.00
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 271
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 55.77
optimizer estimated cost: 439.00
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 271
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=2
Number of pages visited=4
Number of rows qualified=271
Number of rows visited=274
Scan type=btree
Tree height=2
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: 55.77
optimizer estimated cost: 439.00
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222163), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222164), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND username=? :End prepared statement with 2 parameters begin parameter #1: 60001 :end parameter begin parameter #2: TAMMY :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222164), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND username=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.36
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.36
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=3
Number of deleted rows visited=0
Number of pages visited=2
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=2
start position:
>= on first 2 column(s).
Ordered null semantics on the following columns:
stop position:
> on first 2 column(s).
Ordered null semantics on the following columns:
qualifiers:
None
optimizer estimated row count: 1.00
optimizer estimated cost: 5.36
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222164), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222165), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT item FROM item_usage WHERE username=? AND user_role>0 ORDER BY item :End prepared statement with 1 parameters begin parameter #1: TAMMY :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222165), (SESSIONID = 28), SELECT item FROM item_usage WHERE username=? AND user_role>0 ORDER BY item ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 5
Number of reads from hash table = 5
Number of writes to hash table = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 17.20
Source result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 5
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.80
optimizer estimated cost: 17.20
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 5
Rows filtered = 0
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: 1.80
optimizer estimated cost: 17.20
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 5
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 17.20
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 5
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched={0, 2}
Number of columns fetched=2
Number of deleted rows visited=2
Number of pages visited=2
Number of rows qualified=5
Number of rows visited=8
Scan type=btree
Tree height=2
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: 1.80
optimizer estimated cost: 17.20
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222165), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222166), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM users WHERE username=? AND manager IS NOT NULL :End prepared statement with 1 parameters begin parameter #1: TAMMY :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222166), (SESSIONID = 28), SELECT * FROM users WHERE username=? AND manager IS NOT NULL ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.59
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 1
Rows filtered = 0
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: 1.00
optimizer estimated cost: 5.59
Source result set:
Index Row to Base Row ResultSet for USERS:
Number of opens = 1
Rows seen = 1
Columns accessed from heap = {1, 2, 3, 4, 5, 6, 7, 8, 9, 10}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 5.59
Index Scan ResultSet for USERS using constraint USERS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 1
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=2
Number of deleted rows visited=0
Number of pages visited=2
Number of rows qualified=1
Number of rows visited=1
Scan type=btree
Tree height=2
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: 1.00
optimizer estimated cost: 5.59
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222166), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222167), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT count(*) AS msgs FROM messages WHERE item IS NULL AND id>? :End prepared statement with 1 parameters begin parameter #1: 1 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222167), (SESSIONID = 28), SELECT count(*) AS msgs FROM messages WHERE item IS NULL AND id>? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 1.57
Source result set:
Project-Restrict ResultSet (6):
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: 1.57
Source result set:
Scalar Aggregate ResultSet:
Number of opens = 1
Rows input = 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: 1.57
Index Key Optimization = false
Source result set:
Project-Restrict ResultSet (5):
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: 1.57
Source result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 0
Rows filtered = 0
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: 1.57
Source result set:
Index Row to Base Row ResultSet for MESSAGES:
Number of opens = 1
Rows seen = 0
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: 1.57
Index Scan ResultSet for MESSAGES using constraint MESSAGES_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
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 deleted rows visited=0
Number of pages visited=1
Number of rows qualified=0
Number of rows visited=0
Scan type=btree
Tree height=1
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: 1.57
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222167), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222168), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT count(*) AS msgs FROM messages WHERE item=? AND id>? :End prepared statement with 2 parameters begin parameter #1: 60001 :end parameter begin parameter #2: 1 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222168), (SESSIONID = 28), SELECT count(*) AS msgs FROM messages WHERE item=? AND id>? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 83.86
Source result set:
Project-Restrict ResultSet (6):
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: 83.86
Source result set:
Scalar Aggregate ResultSet:
Number of opens = 1
Rows input = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 0.20
optimizer estimated cost: 83.86
Index Key Optimization = false
Source result set:
Project-Restrict ResultSet (5):
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.20
optimizer estimated cost: 83.86
Source result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 0
Rows filtered = 0
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.20
optimizer estimated cost: 83.86
Source result set:
Index Row to Base Row ResultSet for MESSAGES:
Number of opens = 1
Rows seen = 0
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.20
optimizer estimated cost: 83.86
Index Scan ResultSet for MESSAGES using constraint MESSAGES_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
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 deleted rows visited=1
Number of pages visited=1
Number of rows qualified=0
Number of rows visited=1
Scan type=btree
Tree height=1
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.20
optimizer estimated cost: 83.86
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222168), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222169), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT COUNT(*) FROM edits_view WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222169), (SESSIONID = 28), SELECT COUNT(*) FROM edits_view WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 1001.34
Source result set:
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) = 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: 1001.34
Source result set:
Scalar Aggregate ResultSet:
Number of opens = 1
Rows input = 4
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.10
optimizer estimated cost: 1001.34
Index Key Optimization = false
Source result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 4
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: 4.10
optimizer estimated cost: 1001.34
Source result set:
Index Row to Base Row ResultSet for XMLTEMP:
Number of opens = 1
Rows seen = 4
Columns accessed from heap = {0, 1, 5}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.10
optimizer estimated cost: 1001.34
Index Scan ResultSet for XMLTEMP using constraint XMLTEMP_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 4
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=3
Number of deleted rows visited=6
Number of pages visited=1
Number of rows qualified=4
Number of rows visited=11
Scan type=btree
Tree height=1
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: 4.10
optimizer estimated cost: 1001.34
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222169), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222170), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT title,DateTimeFormat(t_time,null) AS t_time,username,link FROM edits_view WHERE item=? ORDER BY username ASC,1 ASC :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222170), (SESSIONID = 28), SELECT title,DateTimeFormat(t_time,null) AS t_time,username,link FROM edits_view WHERE item=? ORDER BY username ASC,1 ASC ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 4
Number of reads from hash table = 4
Number of writes to hash table = 4
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.10
optimizer estimated cost: 1001.34
Source result set:
Sort ResultSet:
Number of opens = 1
Rows input = 4
Rows returned = 4
Eliminate duplicates = false
In sorted order = false
Sort information:
Number of rows input=4
Number of rows output=4
Sort type=internal
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.10
optimizer estimated cost: 1001.34
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 4
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: 4.10
optimizer estimated cost: 1001.34
Source result set:
Index Row to Base Row ResultSet for XMLTEMP:
Number of opens = 1
Rows seen = 4
Columns accessed from heap = {0, 1, 5}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.10
optimizer estimated cost: 1001.34
Index Scan ResultSet for XMLTEMP using constraint XMLTEMP_2 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 4
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=3
Number of deleted rows visited=6
Number of pages visited=1
Number of rows qualified=4
Number of rows visited=11
Scan type=btree
Tree height=1
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: 4.10
optimizer estimated cost: 1001.34
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222170), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222171), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT COUNT(*) FROM tests_view WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222171), (SESSIONID = 28), SELECT COUNT(*) FROM tests_view WHERE item=? ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 2873.71
Source result set:
Project-Restrict ResultSet (8):
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: 2873.71
Source result set:
Scalar Aggregate ResultSet:
Number of opens = 1
Rows input = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.75
optimizer estimated cost: 2873.71
Index Key Optimization = false
Source result set:
Attached subqueries:
Begin Subquery Number 0
Any ResultSet (Attached to 4):
Number of opens = 5
Rows seen = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 36.00
optimizer estimated cost: 23.54
Source result set:
Project-Restrict ResultSet (6):
Number of opens = 5
Rows seen = 40
Rows filtered = 36
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: 36.00
optimizer estimated cost: 23.54
Source result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 39
Rows seen from the right = 1
Rows returned = 40
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 11.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 38
Rows seen from the right = 1
Rows returned = 39
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 36
Rows seen from the right = 2
Rows returned = 38
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 9.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 33
Rows seen from the right = 3
Rows returned = 36
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 8.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 29
Rows seen from the right = 4
Rows returned = 33
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 7.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 25
Rows seen from the right = 4
Rows returned = 29
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 6.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 20
Rows seen from the right = 5
Rows returned = 25
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 5.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 15
Rows seen from the right = 5
Rows returned = 20
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 10
Rows seen from the right = 5
Rows returned = 15
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 3.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 5
Rows seen from the right = 5
Rows returned = 10
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: 0.00
Left result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 4
Rows returned = 4
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 4
Rows returned = 4
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 3
Rows returned = 3
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 2
Rows returned = 2
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 1
Rows returned = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 1
Rows returned = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
End Subquery Number 0
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 5
Rows filtered = 4
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: 10.75
optimizer estimated cost: 2873.71
Source result set:
Index Row to Base Row ResultSet for TESTS:
Number of opens = 1
Rows seen = 5
Columns accessed from heap = {0, 9, 21, 22, 23}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.75
optimizer estimated cost: 2873.71
Index Scan ResultSet for TESTS using constraint TESTS_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 5
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=3
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=5
Number of rows visited=6
Scan type=btree
Tree height=1
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: 10.75
optimizer estimated cost: 2873.71
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222171), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222172), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT title,DateTimeFormat(t_time,null) AS t_time,author,link FROM tests_view WHERE item=? ORDER BY author ASC,1 ASC :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222172), (SESSIONID = 28), SELECT title,DateTimeFormat(t_time,null) AS t_time,author,link FROM tests_view WHERE item=? ORDER BY author ASC,1 ASC ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 1
Number of reads from hash table = 1
Number of writes to hash table = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.75
optimizer estimated cost: 2873.71
Source result set:
Sort ResultSet:
Number of opens = 1
Rows input = 1
Rows returned = 1
Eliminate duplicates = false
In sorted order = false
Sort information:
Number of rows input=1
Number of rows output=1
Sort type=internal
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.75
optimizer estimated cost: 2873.71
Source result set:
Attached subqueries:
Begin Subquery Number 0
Any ResultSet (Attached to 3):
Number of opens = 5
Rows seen = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 387.00
optimizer estimated cost: 253.09
Source result set:
Project-Restrict ResultSet (5):
Number of opens = 5
Rows seen = 40
Rows filtered = 36
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: 387.00
optimizer estimated cost: 253.09
Source result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 39
Rows seen from the right = 1
Rows returned = 40
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 11.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 38
Rows seen from the right = 1
Rows returned = 39
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 36
Rows seen from the right = 2
Rows returned = 38
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 9.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 33
Rows seen from the right = 3
Rows returned = 36
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 8.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 29
Rows seen from the right = 4
Rows returned = 33
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 7.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 25
Rows seen from the right = 4
Rows returned = 29
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 6.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 20
Rows seen from the right = 5
Rows returned = 25
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 5.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 15
Rows seen from the right = 5
Rows returned = 20
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 4.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 10
Rows seen from the right = 5
Rows returned = 15
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 3.00
optimizer estimated cost: 0.00
Left result set:
Union ResultSet:
Number of opens = 5
Rows seen from the left = 5
Rows seen from the right = 5
Rows returned = 10
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: 0.00
Left result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 5
Rows returned = 5
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 4
Rows returned = 4
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 4
Rows returned = 4
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 3
Rows returned = 3
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 2
Rows returned = 2
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 1
Rows returned = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
Right result set:
Row ResultSet:
Number of opens = 1
Rows returned = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.00
optimizer estimated cost: 0.00
End Subquery Number 0
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 5
Rows filtered = 4
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: 10.75
optimizer estimated cost: 2873.71
Source result set:
Index Row to Base Row ResultSet for TESTS:
Number of opens = 1
Rows seen = 5
Columns accessed from heap = {0, 9, 21, 22, 23}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10.75
optimizer estimated cost: 2873.71
Index Scan ResultSet for TESTS using constraint TESTS_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 5
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched=All
Number of columns fetched=3
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=5
Number of rows visited=6
Scan type=btree
Tree height=1
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: 10.75
optimizer estimated cost: 2873.71
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222172), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Begin compiling prepared statement: SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY item_usage.item,title :End prepared statement
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), End compiling prepared statement: SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY item_usage.item,title :End prepared statement
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY item_usage.item,title :End prepared statement with 1 parameters begin parameter #1: TAMMY :end parameter
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY item_usage.item,title ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 30
Number of reads from hash table = 30
Number of writes to hash table = 30
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 5186.92
Source result set:
Project-Restrict ResultSet (9):
Number of opens = 1
Rows seen = 30
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.80
optimizer estimated cost: 5186.92
Source result set:
Sort ResultSet:
Number of opens = 1
Rows input = 30
Rows returned = 30
Eliminate duplicates = false
In sorted order = false
Sort information:
Number of rows input=30
Number of rows output=30
Sort type=internal
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 19.34
optimizer estimated cost: 5186.92
Source result set:
Project-Restrict ResultSet (7):
Number of opens = 1
Rows seen = 30
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: 19.34
optimizer estimated cost: 5186.92
Source result set:
Nested Loop Join ResultSet:
Number of opens = 1
Rows seen from the left = 5
Rows seen from the right = 30
Rows filtered = 0
Rows returned = 30
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 19.34
optimizer estimated cost: 5186.92
Left result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 5
Rows filtered = 0
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: 1.80
optimizer estimated cost: 17.01
Source result set:
Index Row to Base Row ResultSet for ITEM_USAGE:
Number of opens = 1
Rows seen = 5
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 1.80
optimizer estimated cost: 17.01
Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 5
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=2
Number of rows qualified=5
Number of rows visited=6
Scan type=btree
Tree height=2
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: 1.80
optimizer estimated cost: 17.01
Right result set:
Index Row to Base Row ResultSet for TESTS:
Number of opens = 5
Rows seen = 30
Columns accessed from heap = {0, 1, 2}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 19.34
optimizer estimated cost: 5169.91
Index Scan ResultSet for TESTS using constraint TESTS_1 at read uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 5
Rows seen = 30
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={0, 2}
Number of columns fetched=2
Number of deleted rows visited=9
Number of pages visited=5
Number of rows qualified=30
Number of rows visited=43
Scan type=btree
Tree height=1
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: 19.34
optimizer estimated cost: 5169.91
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Rolling back
> Peculiar sorting behaviour
> --------------------------
>
> Key: DERBY-6148
> URL: https://issues.apache.org/jira/browse/DERBY-6148
> Project: Derby
> Issue Type: Bug
> Components: SQL
> Affects Versions: 10.9.1.0
> Environment: Windows 7 64-bit, Ubuntu 32-bit; JRE 1.7.0_11+
> Reporter: John English
>
> I have a query that looks like this:
> SELECT tests.id,tests.item,title FROM tests,item_usage
> WHERE username=? AND user_role>?
> AND item_usage.item=tests.item
> ORDER BY tests.item,title
> The result ordering is by item code followed by title, but the item codes are listed in the order in which they appear in the ITEMS table where they are the primary key rather than in ascending order as expected. If however I change the ORDER BY clause to sort by item_usage.item rather than tests.item, it works correctly, even though the two values are the same!
> The same thing happens in another unrelated query involving item_usage, and the same workaround cures it.
> The relevant tables are defined like so:
> CREATE TABLE item_usage (
> username VARCHAR(15) NOT NULL,
> item VARCHAR(15) NOT NULL,
> value SMALLINT DEFAULT 0,
> CONSTRAINT item_usage_pk PRIMARY KEY (username,item),
> CONSTRAINT item_usage_1 FOREIGN KEY (username)
> REFERENCES users(username)
> ON DELETE CASCADE,
> CONSTRAINT item_usage_2 FOREIGN KEY (item)
> REFERENCES items(item)
> ON DELETE CASCADE,
> CONSTRAINT item_usage_3 CHECK (value BETWEEN 0 AND 4)
> );
> CREATE TABLE tests (
> id INTEGER GENERATED ALWAYS AS IDENTITY,
> item VARCHAR(15) NOT NULL,
> title VARCHAR(255) NOT NULL,
> disp SMALLINT NOT NULL DEFAULT 0,
> starttime TIMESTAMP DEFAULT NULL,
> endtime TIMESTAMP DEFAULT NULL,
> offsetx INTEGER NOT NULL DEFAULT 0,
> offsety INTEGER NOT NULL DEFAULT 0,
> rate INTEGER NOT NULL DEFAULT 0,
> duration INTEGER NOT NULL DEFAULT 0,
> calibrate INTEGER NOT NULL DEFAULT 0,
> deadline TIMESTAMP DEFAULT NULL,
> stepsize INTEGER NOT NULL DEFAULT 0,
> interval INTEGER NOT NULL DEFAULT 0,
> stand CHAR(1) DEFAULT NULL,
> hidden CHAR(1) DEFAULT NULL,
> repeated CHAR(1) DEFAULT NULL,
> private CHAR(1) DEFAULT NULL,
> sequential CHAR(1) DEFAULT NULL,
> final CHAR(1) DEFAULT NULL,
> notes CLOB DEFAULT NULL,
> testxml CLOB NOT NULL,
> author VARCHAR(15) NOT NULL,
> time TIMESTAMP NOT NULL,
> CONSTRAINT tests_pk PRIMARY KEY (id),
> CONSTRAINT tests_1 UNIQUE (item, title),
> CONSTRAINT tests_2 FOREIGN KEY (item)
> REFERENCES items(item)
> ON DELETE CASCADE,
> CONSTRAINT tests_3 CHECK (disp BETWEEN 0 AND 100),
> CONSTRAINT tests_4 CHECK (rate BETWEEN 0 AND 100),
> CONSTRAINT tests_5 CHECK (stepsize BETWEEN 0 AND 100)
> );
> If I run the query manually I get this, as expected:
> ID ITEM TITLE
> 37 60001 Test 1
> 42 60001 Test 2
> 51 60001 Test 3
> 17 61303 Test 2a
> 16 61303 Test 2b
> 7 7205731 Test 2a
> 8 7205731 Test 2b
> Now, this is actually part of a web app that should turn this into a list of options in a <select> item using the following code:
> while (query.next()) {
> println("<option value='" + query.getInt("id") + "'>"
> + encode(query.getString("item") + ": "
> + query.getString("title")) + "</option>");
> }
> What I actually get is this:
> <option value="17">61303: Test 2a</option>
> <option value="16">61303: Test 2b</option>
> <option value="7">7205731: Test 2a</option>
> <option value="8">7205731: Test 2b</option>
> <option value="37">60001: Test 1</option>
> <option value="42">60001: Test 2</option>
> <option value="51">60001: Test 3</option>
> The results are sorted by item then by title, but the item order is the order in which they were originally inserted into the items table (where the item and item description are stored, referenced by item_usage.item) rather than by item code.
> I've tried to reproduce this behaviour in a simple example, but without success. I have logged the query plans for both versions; the log output is as follows, with the INCORRECT query (using ORDER BY tests.item) followed later by the CORRECT query (using ORDER BY item_usage.item):
> Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID = 7222148), (SESSIONID = 26), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY tests.item,title :End prepared statement with 1 parameters begin parameter #1: TAMMY :end parameter
> Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID = 7222148), (SESSIONID = 26), SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY tests.item,title ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 30
> Number of reads from hash table = 30
> Number of writes to hash table = 30
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 19.34
> optimizer estimated cost: 5186.92
> Source result set:
> Project-Restrict ResultSet (7):
> Number of opens = 1
> Rows seen = 30
> 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: 19.34
> optimizer estimated cost: 5186.92
> Source result set:
> Nested Loop Join ResultSet:
> Number of opens = 1
> Rows seen from the left = 5
> Rows seen from the right = 30
> Rows filtered = 0
> Rows returned = 30
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 19.34
> optimizer estimated cost: 5186.92
> Left result set:
> Project-Restrict ResultSet (4):
> Number of opens = 1
> Rows seen = 5
> Rows filtered = 0
> 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: 1.80
> optimizer estimated cost: 17.01
> Source result set:
> Index Row to Base Row ResultSet for ITEM_USAGE:
> Number of opens = 1
> Rows seen = 5
> Columns accessed from heap = {0, 1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.80
> optimizer estimated cost: 17.01
> Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_1 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 5
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=2
> Number of deleted rows visited=0
> Number of pages visited=2
> Number of rows qualified=5
> Number of rows visited=6
> Scan type=btree
> Tree height=2
> 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: 1.80
> optimizer estimated cost: 17.01
> Right result set:
> Index Row to Base Row ResultSet for TESTS:
> Number of opens = 5
> Rows seen = 30
> Columns accessed from heap = {0, 1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 19.34
> optimizer estimated cost: 5169.91
> Index Scan ResultSet for TESTS using constraint TESTS_1 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 5
> Rows seen = 30
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched={0, 2}
> Number of columns fetched=2
> Number of deleted rows visited=9
> Number of pages visited=5
> Number of rows qualified=30
> Number of rows visited=43
> Scan type=btree
> Tree height=1
> 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: 19.34
> optimizer estimated cost: 5169.91
> Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID = 7222148), (SESSIONID = 26), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID = 7222148), (SESSIONID = 26), (DATABASE = ../db/db_copy), (DRDAID = null), Rolling back
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222149), (SESSIONID = 27), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222149), (SESSIONID = 27), (DATABASE = ../db/db_copy), (DRDAID = null), Rolling back
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222150), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222151), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT items.item,title,user_role FROM items,item_usage WHERE items.item=item_usage.item AND username=? AND user_role>? ORDER BY item_usage.item :End prepared statement with 2 parameters begin parameter #1: TAMMY :end parameter begin parameter #2: -1 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222151), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222152), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222152), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.80
> Source result set:
> Index Row to Base Row ResultSet for ITEMS:
> Number of opens = 1
> Rows seen = 1
> Columns accessed from heap = {1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.80
> Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 1
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=2
> Number of deleted rows visited=0
> Number of pages visited=1
> Number of rows qualified=1
> Number of rows visited=1
> Scan type=btree
> Tree height=1
> 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: 1.00
> optimizer estimated cost: 5.80
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222152), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222153), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222153), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 7
> Number of reads from hash table = 7
> Number of writes to hash table = 7
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 55.77
> optimizer estimated cost: 439.00
> Source result set:
> Project-Restrict ResultSet (3):
> Number of opens = 1
> Rows seen = 271
> Rows filtered = 264
> 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: 55.77
> optimizer estimated cost: 439.00
> Source result set:
> Index Row to Base Row ResultSet for ITEM_USAGE:
> Number of opens = 1
> Rows seen = 271
> Columns accessed from heap = {0, 1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 55.77
> optimizer estimated cost: 439.00
> Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 271
> 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=2
> Number of pages visited=4
> Number of rows qualified=271
> Number of rows visited=274
> Scan type=btree
> Tree height=2
> 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: 55.77
> optimizer estimated cost: 439.00
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222153), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222154), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 61108 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222154), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.80
> Source result set:
> Index Row to Base Row ResultSet for ITEMS:
> Number of opens = 1
> Rows seen = 1
> Columns accessed from heap = {1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.80
> Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 1
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=2
> Number of deleted rows visited=0
> Number of pages visited=1
> Number of rows qualified=1
> Number of rows visited=1
> Scan type=btree
> Tree height=1
> 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: 1.00
> optimizer estimated cost: 5.80
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222154), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222155), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 61108 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222155), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 55.77
> optimizer estimated cost: 439.00
> Source result set:
> Project-Restrict ResultSet (3):
> Number of opens = 1
> Rows seen = 1
> Rows filtered = 0
> 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: 55.77
> optimizer estimated cost: 439.00
> Source result set:
> Index Row to Base Row ResultSet for ITEM_USAGE:
> Number of opens = 1
> Rows seen = 1
> Columns accessed from heap = {0, 1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 55.77
> optimizer estimated cost: 439.00
> Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using 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=2
> Number of rows qualified=1
> Number of rows visited=2
> Scan type=btree
> Tree height=2
> 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: 55.77
> optimizer estimated cost: 439.00
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222155), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222156), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 61303 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222156), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.80
> Source result set:
> Index Row to Base Row ResultSet for ITEMS:
> Number of opens = 1
> Rows seen = 1
> Columns accessed from heap = {1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.80
> Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 1
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=2
> Number of deleted rows visited=0
> Number of pages visited=1
> Number of rows qualified=1
> Number of rows visited=1
> Scan type=btree
> Tree height=1
> 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: 1.00
> optimizer estimated cost: 5.80
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222156), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222157), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 61303 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222157), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 3
> Number of reads from hash table = 3
> Number of writes to hash table = 3
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 55.77
> optimizer estimated cost: 439.00
> Source result set:
> Project-Restrict ResultSet (3):
> Number of opens = 1
> Rows seen = 146
> Rows filtered = 143
> 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: 55.77
> optimizer estimated cost: 439.00
> Source result set:
> Index Row to Base Row ResultSet for ITEM_USAGE:
> Number of opens = 1
> Rows seen = 146
> Columns accessed from heap = {0, 1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 55.77
> optimizer estimated cost: 439.00
> Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 146
> 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=4
> Number of rows qualified=146
> Number of rows visited=147
> Scan type=btree
> Tree height=2
> 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: 55.77
> optimizer estimated cost: 439.00
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222157), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222158), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 7205731 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222158), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.80
> Source result set:
> Index Row to Base Row ResultSet for ITEMS:
> Number of opens = 1
> Rows seen = 1
> Columns accessed from heap = {1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.80
> Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 1
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=2
> Number of deleted rows visited=0
> Number of pages visited=1
> Number of rows qualified=1
> Number of rows visited=1
> Scan type=btree
> Tree height=1
> 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: 1.00
> optimizer estimated cost: 5.80
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222158), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222159), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 7205731 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222159), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 2
> Number of reads from hash table = 2
> Number of writes to hash table = 2
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 55.77
> optimizer estimated cost: 439.00
> Source result set:
> Project-Restrict ResultSet (3):
> Number of opens = 1
> Rows seen = 28
> Rows filtered = 26
> 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: 55.77
> optimizer estimated cost: 439.00
> Source result set:
> Index Row to Base Row ResultSet for ITEM_USAGE:
> Number of opens = 1
> Rows seen = 28
> Columns accessed from heap = {0, 1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 55.77
> optimizer estimated cost: 439.00
> Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 28
> 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=1
> Number of pages visited=2
> Number of rows qualified=28
> Number of rows visited=30
> Scan type=btree
> Tree height=2
> 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: 55.77
> optimizer estimated cost: 439.00
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222159), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222160), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: XY101 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222160), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.80
> Source result set:
> Index Row to Base Row ResultSet for ITEMS:
> Number of opens = 1
> Rows seen = 1
> Columns accessed from heap = {1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.80
> Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 1
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=2
> Number of deleted rows visited=0
> Number of pages visited=1
> Number of rows qualified=1
> Number of rows visited=1
> Scan type=btree
> Tree height=1
> 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: 1.00
> optimizer estimated cost: 5.80
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222160), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: XY101 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 2
> Number of reads from hash table = 2
> Number of writes to hash table = 2
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 55.77
> optimizer estimated cost: 439.00
> Source result set:
> Project-Restrict ResultSet (3):
> Number of opens = 1
> Rows seen = 3
> Rows filtered = 1
> 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: 55.77
> optimizer estimated cost: 439.00
> Source result set:
> Index Row to Base Row ResultSet for ITEM_USAGE:
> Number of opens = 1
> Rows seen = 3
> Columns accessed from heap = {0, 1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 55.77
> optimizer estimated cost: 439.00
> Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 3
> 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=2
> Number of pages visited=2
> Number of rows qualified=3
> Number of rows visited=5
> Scan type=btree
> Tree height=2
> 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: 55.77
> optimizer estimated cost: 439.00
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), SELECT items.item,title,user_role FROM items,item_usage WHERE items.item=item_usage.item AND username=? AND user_role>? ORDER BY item_usage.item ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 5
> Number of reads from hash table = 5
> Number of writes to hash table = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.80
> optimizer estimated cost: 27.45
> Source result set:
> Project-Restrict ResultSet (9):
> Number of opens = 1
> Rows seen = 5
> 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.80
> optimizer estimated cost: 27.45
> Source result set:
> Sort ResultSet:
> Number of opens = 1
> Rows input = 5
> Rows returned = 5
> Eliminate duplicates = false
> In sorted order = false
> Sort information:
> Number of rows input=5
> Number of rows output=5
> Sort type=internal
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.80
> optimizer estimated cost: 27.45
> Source result set:
> Project-Restrict ResultSet (7):
> Number of opens = 1
> Rows seen = 5
> 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.80
> optimizer estimated cost: 27.45
> Source result set:
> Nested Loop Exists Join ResultSet:
> Number of opens = 1
> Rows seen from the left = 5
> Rows seen from the right = 5
> Rows filtered = 0
> Rows returned = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.80
> optimizer estimated cost: 27.45
> Left result set:
> Project-Restrict ResultSet (4):
> Number of opens = 1
> Rows seen = 5
> Rows filtered = 0
> 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: 1.80
> optimizer estimated cost: 17.01
> Source result set:
> Index Row to Base Row ResultSet for ITEM_USAGE:
> Number of opens = 1
> Rows seen = 5
> Columns accessed from heap = {0, 1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.80
> optimizer estimated cost: 17.01
> Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_1 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 5
> 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=2
> Number of rows qualified=5
> Number of rows visited=6
> Scan type=btree
> Tree height=2
> 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: 1.80
> optimizer estimated cost: 17.01
> Right result set:
> Index Row to Base Row ResultSet for ITEMS:
> Number of opens = 5
> Rows seen = 5
> 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: 1.80
> optimizer estimated cost: 10.43
> Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 5
> Rows seen = 5
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=2
> Number of deleted rows visited=0
> Number of pages visited=5
> Number of rows qualified=5
> Number of rows visited=5
> Scan type=btree
> Tree height=1
> start position:
> >= on first 1 column(s).
> Ordered null semantics on the following columns:
> 0
> stop position:
> > on first 1 column(s).
> Ordered null semantics on the following columns:
> 0
> qualifiers:
> None
> optimizer estimated row count: 1.80
> optimizer estimated cost: 10.43
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222161), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222162), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM items WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222162), (SESSIONID = 28), SELECT * FROM items WHERE item=? ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.80
> Source result set:
> Index Row to Base Row ResultSet for ITEMS:
> Number of opens = 1
> Rows seen = 1
> Columns accessed from heap = {1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.80
> Index Scan ResultSet for ITEMS using constraint ITEMS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 1
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=2
> Number of deleted rows visited=0
> Number of pages visited=1
> Number of rows qualified=1
> Number of rows visited=1
> Scan type=btree
> Tree height=1
> 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: 1.00
> optimizer estimated cost: 5.80
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222162), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222163), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND user_role>0 :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222163), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND user_role>0 ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 7
> Number of reads from hash table = 7
> Number of writes to hash table = 7
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 55.77
> optimizer estimated cost: 439.00
> Source result set:
> Project-Restrict ResultSet (3):
> Number of opens = 1
> Rows seen = 271
> Rows filtered = 264
> 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: 55.77
> optimizer estimated cost: 439.00
> Source result set:
> Index Row to Base Row ResultSet for ITEM_USAGE:
> Number of opens = 1
> Rows seen = 271
> Columns accessed from heap = {0, 1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 55.77
> optimizer estimated cost: 439.00
> Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_2 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 271
> 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=2
> Number of pages visited=4
> Number of rows qualified=271
> Number of rows visited=274
> Scan type=btree
> Tree height=2
> 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: 55.77
> optimizer estimated cost: 439.00
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222163), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222164), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM item_usage WHERE item=? AND username=? :End prepared statement with 2 parameters begin parameter #1: 60001 :end parameter begin parameter #2: TAMMY :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222164), (SESSIONID = 28), SELECT * FROM item_usage WHERE item=? AND username=? ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.36
> Source result set:
> Index Row to Base Row ResultSet for ITEM_USAGE:
> Number of opens = 1
> Rows seen = 1
> Columns accessed from heap = {2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.36
> Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_PK at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 1
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=3
> Number of deleted rows visited=0
> Number of pages visited=2
> Number of rows qualified=1
> Number of rows visited=1
> Scan type=btree
> Tree height=2
> start position:
> >= on first 2 column(s).
> Ordered null semantics on the following columns:
> stop position:
> > on first 2 column(s).
> Ordered null semantics on the following columns:
> qualifiers:
> None
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.36
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222164), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222165), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT item FROM item_usage WHERE username=? AND user_role>0 ORDER BY item :End prepared statement with 1 parameters begin parameter #1: TAMMY :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222165), (SESSIONID = 28), SELECT item FROM item_usage WHERE username=? AND user_role>0 ORDER BY item ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 5
> Number of reads from hash table = 5
> Number of writes to hash table = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.80
> optimizer estimated cost: 17.20
> Source result set:
> Project-Restrict ResultSet (4):
> Number of opens = 1
> Rows seen = 5
> 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.80
> optimizer estimated cost: 17.20
> Source result set:
> Project-Restrict ResultSet (3):
> Number of opens = 1
> Rows seen = 5
> Rows filtered = 0
> 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: 1.80
> optimizer estimated cost: 17.20
> Source result set:
> Index Row to Base Row ResultSet for ITEM_USAGE:
> Number of opens = 1
> Rows seen = 5
> Columns accessed from heap = {0, 1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.80
> optimizer estimated cost: 17.20
> Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_PK at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 5
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched={0, 2}
> Number of columns fetched=2
> Number of deleted rows visited=2
> Number of pages visited=2
> Number of rows qualified=5
> Number of rows visited=8
> Scan type=btree
> Tree height=2
> 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: 1.80
> optimizer estimated cost: 17.20
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222165), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222166), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT * FROM users WHERE username=? AND manager IS NOT NULL :End prepared statement with 1 parameters begin parameter #1: TAMMY :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222166), (SESSIONID = 28), SELECT * FROM users WHERE username=? AND manager IS NOT NULL ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.59
> Source result set:
> Project-Restrict ResultSet (3):
> Number of opens = 1
> Rows seen = 1
> Rows filtered = 0
> 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: 1.00
> optimizer estimated cost: 5.59
> Source result set:
> Index Row to Base Row ResultSet for USERS:
> Number of opens = 1
> Rows seen = 1
> Columns accessed from heap = {1, 2, 3, 4, 5, 6, 7, 8, 9, 10}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 5.59
> Index Scan ResultSet for USERS using constraint USERS_PK at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 1
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=2
> Number of deleted rows visited=0
> Number of pages visited=2
> Number of rows qualified=1
> Number of rows visited=1
> Scan type=btree
> Tree height=2
> 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: 1.00
> optimizer estimated cost: 5.59
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222166), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222167), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT count(*) AS msgs FROM messages WHERE item IS NULL AND id>? :End prepared statement with 1 parameters begin parameter #1: 1 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222167), (SESSIONID = 28), SELECT count(*) AS msgs FROM messages WHERE item IS NULL AND id>? ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 1.57
> Source result set:
> Project-Restrict ResultSet (6):
> 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: 1.57
> Source result set:
> Scalar Aggregate ResultSet:
> Number of opens = 1
> Rows input = 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: 1.57
> Index Key Optimization = false
> Source result set:
> Project-Restrict ResultSet (5):
> 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: 1.57
> Source result set:
> Project-Restrict ResultSet (4):
> Number of opens = 1
> Rows seen = 0
> Rows filtered = 0
> 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: 1.57
> Source result set:
> Index Row to Base Row ResultSet for MESSAGES:
> Number of opens = 1
> Rows seen = 0
> 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: 1.57
> Index Scan ResultSet for MESSAGES using constraint MESSAGES_1 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> 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 deleted rows visited=0
> Number of pages visited=1
> Number of rows qualified=0
> Number of rows visited=0
> Scan type=btree
> Tree height=1
> 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: 1.57
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222167), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222168), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT count(*) AS msgs FROM messages WHERE item=? AND id>? :End prepared statement with 2 parameters begin parameter #1: 60001 :end parameter begin parameter #2: 1 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222168), (SESSIONID = 28), SELECT count(*) AS msgs FROM messages WHERE item=? AND id>? ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 83.86
> Source result set:
> Project-Restrict ResultSet (6):
> 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: 83.86
> Source result set:
> Scalar Aggregate ResultSet:
> Number of opens = 1
> Rows input = 0
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 0.20
> optimizer estimated cost: 83.86
> Index Key Optimization = false
> Source result set:
> Project-Restrict ResultSet (5):
> 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.20
> optimizer estimated cost: 83.86
> Source result set:
> Project-Restrict ResultSet (4):
> Number of opens = 1
> Rows seen = 0
> Rows filtered = 0
> 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.20
> optimizer estimated cost: 83.86
> Source result set:
> Index Row to Base Row ResultSet for MESSAGES:
> Number of opens = 1
> Rows seen = 0
> 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.20
> optimizer estimated cost: 83.86
> Index Scan ResultSet for MESSAGES using constraint MESSAGES_1 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> 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 deleted rows visited=1
> Number of pages visited=1
> Number of rows qualified=0
> Number of rows visited=1
> Scan type=btree
> Tree height=1
> 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.20
> optimizer estimated cost: 83.86
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222168), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222169), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT COUNT(*) FROM edits_view WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222169), (SESSIONID = 28), SELECT COUNT(*) FROM edits_view WHERE item=? ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 1001.34
> Source result set:
> 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) = 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: 1001.34
> Source result set:
> Scalar Aggregate ResultSet:
> Number of opens = 1
> Rows input = 4
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 4.10
> optimizer estimated cost: 1001.34
> Index Key Optimization = false
> Source result set:
> Project-Restrict ResultSet (4):
> Number of opens = 1
> Rows seen = 4
> 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: 4.10
> optimizer estimated cost: 1001.34
> Source result set:
> Index Row to Base Row ResultSet for XMLTEMP:
> Number of opens = 1
> Rows seen = 4
> Columns accessed from heap = {0, 1, 5}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 4.10
> optimizer estimated cost: 1001.34
> Index Scan ResultSet for XMLTEMP using constraint XMLTEMP_2 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 4
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=3
> Number of deleted rows visited=6
> Number of pages visited=1
> Number of rows qualified=4
> Number of rows visited=11
> Scan type=btree
> Tree height=1
> 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: 4.10
> optimizer estimated cost: 1001.34
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222169), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222170), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT title,DateTimeFormat(t_time,null) AS t_time,username,link FROM edits_view WHERE item=? ORDER BY username ASC,1 ASC :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222170), (SESSIONID = 28), SELECT title,DateTimeFormat(t_time,null) AS t_time,username,link FROM edits_view WHERE item=? ORDER BY username ASC,1 ASC ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 4
> Number of reads from hash table = 4
> Number of writes to hash table = 4
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 4.10
> optimizer estimated cost: 1001.34
> Source result set:
> Sort ResultSet:
> Number of opens = 1
> Rows input = 4
> Rows returned = 4
> Eliminate duplicates = false
> In sorted order = false
> Sort information:
> Number of rows input=4
> Number of rows output=4
> Sort type=internal
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 4.10
> optimizer estimated cost: 1001.34
> Source result set:
> Project-Restrict ResultSet (3):
> Number of opens = 1
> Rows seen = 4
> 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: 4.10
> optimizer estimated cost: 1001.34
> Source result set:
> Index Row to Base Row ResultSet for XMLTEMP:
> Number of opens = 1
> Rows seen = 4
> Columns accessed from heap = {0, 1, 5}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 4.10
> optimizer estimated cost: 1001.34
> Index Scan ResultSet for XMLTEMP using constraint XMLTEMP_2 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 4
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=3
> Number of deleted rows visited=6
> Number of pages visited=1
> Number of rows qualified=4
> Number of rows visited=11
> Scan type=btree
> Tree height=1
> 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: 4.10
> optimizer estimated cost: 1001.34
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222170), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222171), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT COUNT(*) FROM tests_view WHERE item=? :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222171), (SESSIONID = 28), SELECT COUNT(*) FROM tests_view WHERE item=? ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 2873.71
> Source result set:
> Project-Restrict ResultSet (8):
> 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: 2873.71
> Source result set:
> Scalar Aggregate ResultSet:
> Number of opens = 1
> Rows input = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 10.75
> optimizer estimated cost: 2873.71
> Index Key Optimization = false
> Source result set:
> Attached subqueries:
> Begin Subquery Number 0
> Any ResultSet (Attached to 4):
> Number of opens = 5
> Rows seen = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 36.00
> optimizer estimated cost: 23.54
> Source result set:
> Project-Restrict ResultSet (6):
> Number of opens = 5
> Rows seen = 40
> Rows filtered = 36
> 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: 36.00
> optimizer estimated cost: 23.54
> Source result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 39
> Rows seen from the right = 1
> Rows returned = 40
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 11.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 38
> Rows seen from the right = 1
> Rows returned = 39
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 10.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 36
> Rows seen from the right = 2
> Rows returned = 38
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 9.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 33
> Rows seen from the right = 3
> Rows returned = 36
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 8.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 29
> Rows seen from the right = 4
> Rows returned = 33
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 7.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 25
> Rows seen from the right = 4
> Rows returned = 29
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 6.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 20
> Rows seen from the right = 5
> Rows returned = 25
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 5.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 15
> Rows seen from the right = 5
> Rows returned = 20
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 4.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 10
> Rows seen from the right = 5
> Rows returned = 15
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 3.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 5
> Rows seen from the right = 5
> Rows returned = 10
> 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: 0.00
> Left result set:
> Row ResultSet:
> Number of opens = 5
> Rows returned = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 5
> Rows returned = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 5
> Rows returned = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 5
> Rows returned = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 5
> Rows returned = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 4
> Rows returned = 4
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 4
> Rows returned = 4
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 3
> Rows returned = 3
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 2
> Rows returned = 2
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 1
> Rows returned = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 1
> Rows returned = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> End Subquery Number 0
> Project-Restrict ResultSet (4):
> Number of opens = 1
> Rows seen = 5
> Rows filtered = 4
> 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: 10.75
> optimizer estimated cost: 2873.71
> Source result set:
> Index Row to Base Row ResultSet for TESTS:
> Number of opens = 1
> Rows seen = 5
> Columns accessed from heap = {0, 9, 21, 22, 23}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 10.75
> optimizer estimated cost: 2873.71
> Index Scan ResultSet for TESTS using constraint TESTS_1 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 5
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=3
> Number of deleted rows visited=0
> Number of pages visited=1
> Number of rows qualified=5
> Number of rows visited=6
> Scan type=btree
> Tree height=1
> 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: 10.75
> optimizer estimated cost: 2873.71
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222171), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222172), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT title,DateTimeFormat(t_time,null) AS t_time,author,link FROM tests_view WHERE item=? ORDER BY author ASC,1 ASC :End prepared statement with 1 parameters begin parameter #1: 60001 :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222172), (SESSIONID = 28), SELECT title,DateTimeFormat(t_time,null) AS t_time,author,link FROM tests_view WHERE item=? ORDER BY author ASC,1 ASC ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 1
> Number of reads from hash table = 1
> Number of writes to hash table = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 10.75
> optimizer estimated cost: 2873.71
> Source result set:
> Sort ResultSet:
> Number of opens = 1
> Rows input = 1
> Rows returned = 1
> Eliminate duplicates = false
> In sorted order = false
> Sort information:
> Number of rows input=1
> Number of rows output=1
> Sort type=internal
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 10.75
> optimizer estimated cost: 2873.71
> Source result set:
> Attached subqueries:
> Begin Subquery Number 0
> Any ResultSet (Attached to 3):
> Number of opens = 5
> Rows seen = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 387.00
> optimizer estimated cost: 253.09
> Source result set:
> Project-Restrict ResultSet (5):
> Number of opens = 5
> Rows seen = 40
> Rows filtered = 36
> 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: 387.00
> optimizer estimated cost: 253.09
> Source result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 39
> Rows seen from the right = 1
> Rows returned = 40
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 11.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 38
> Rows seen from the right = 1
> Rows returned = 39
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 10.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 36
> Rows seen from the right = 2
> Rows returned = 38
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 9.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 33
> Rows seen from the right = 3
> Rows returned = 36
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 8.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 29
> Rows seen from the right = 4
> Rows returned = 33
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 7.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 25
> Rows seen from the right = 4
> Rows returned = 29
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 6.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 20
> Rows seen from the right = 5
> Rows returned = 25
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 5.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 15
> Rows seen from the right = 5
> Rows returned = 20
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 4.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 10
> Rows seen from the right = 5
> Rows returned = 15
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 3.00
> optimizer estimated cost: 0.00
> Left result set:
> Union ResultSet:
> Number of opens = 5
> Rows seen from the left = 5
> Rows seen from the right = 5
> Rows returned = 10
> 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: 0.00
> Left result set:
> Row ResultSet:
> Number of opens = 5
> Rows returned = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 5
> Rows returned = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 5
> Rows returned = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 5
> Rows returned = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 5
> Rows returned = 5
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 4
> Rows returned = 4
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 4
> Rows returned = 4
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 3
> Rows returned = 3
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 2
> Rows returned = 2
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 1
> Rows returned = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> Right result set:
> Row ResultSet:
> Number of opens = 1
> Rows returned = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.00
> optimizer estimated cost: 0.00
> End Subquery Number 0
> Project-Restrict ResultSet (3):
> Number of opens = 1
> Rows seen = 5
> Rows filtered = 4
> 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: 10.75
> optimizer estimated cost: 2873.71
> Source result set:
> Index Row to Base Row ResultSet for TESTS:
> Number of opens = 1
> Rows seen = 5
> Columns accessed from heap = {0, 9, 21, 22, 23}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 10.75
> optimizer estimated cost: 2873.71
> Index Scan ResultSet for TESTS using constraint TESTS_1 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 5
> Rows filtered = 0
> Fetch Size = 1
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> next time in milliseconds/row = 0
> scan information:
> Bit set of columns fetched=All
> Number of columns fetched=3
> Number of deleted rows visited=0
> Number of pages visited=1
> Number of rows qualified=5
> Number of rows visited=6
> Scan type=btree
> Tree height=1
> 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: 10.75
> optimizer estimated cost: 2873.71
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222172), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Begin compiling prepared statement: SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY item_usage.item,title :End prepared statement
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), End compiling prepared statement: SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY item_usage.item,title :End prepared statement
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Executing prepared statement: SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY item_usage.item,title :End prepared statement with 1 parameters begin parameter #1: TAMMY :end parameter
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), SELECT tests.id,tests.item,title FROM tests,item_usage WHERE username=? AND user_role>=3 AND item_usage.item=tests.item ORDER BY item_usage.item,title ******* Scroll Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 30
> Number of reads from hash table = 30
> Number of writes to hash table = 30
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.80
> optimizer estimated cost: 5186.92
> Source result set:
> Project-Restrict ResultSet (9):
> Number of opens = 1
> Rows seen = 30
> 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.80
> optimizer estimated cost: 5186.92
> Source result set:
> Sort ResultSet:
> Number of opens = 1
> Rows input = 30
> Rows returned = 30
> Eliminate duplicates = false
> In sorted order = false
> Sort information:
> Number of rows input=30
> Number of rows output=30
> Sort type=internal
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 19.34
> optimizer estimated cost: 5186.92
> Source result set:
> Project-Restrict ResultSet (7):
> Number of opens = 1
> Rows seen = 30
> 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: 19.34
> optimizer estimated cost: 5186.92
> Source result set:
> Nested Loop Join ResultSet:
> Number of opens = 1
> Rows seen from the left = 5
> Rows seen from the right = 30
> Rows filtered = 0
> Rows returned = 30
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 19.34
> optimizer estimated cost: 5186.92
> Left result set:
> Project-Restrict ResultSet (4):
> Number of opens = 1
> Rows seen = 5
> Rows filtered = 0
> 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: 1.80
> optimizer estimated cost: 17.01
> Source result set:
> Index Row to Base Row ResultSet for ITEM_USAGE:
> Number of opens = 1
> Rows seen = 5
> Columns accessed from heap = {0, 1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 1.80
> optimizer estimated cost: 17.01
> Index Scan ResultSet for ITEM_USAGE using constraint ITEM_USAGE_1 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 1
> Rows seen = 5
> 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=2
> Number of rows qualified=5
> Number of rows visited=6
> Scan type=btree
> Tree height=2
> 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: 1.80
> optimizer estimated cost: 17.01
> Right result set:
> Index Row to Base Row ResultSet for TESTS:
> Number of opens = 5
> Rows seen = 30
> Columns accessed from heap = {0, 1, 2}
> constructor time (milliseconds) = 0
> open time (milliseconds) = 0
> next time (milliseconds) = 0
> close time (milliseconds) = 0
> optimizer estimated row count: 19.34
> optimizer estimated cost: 5169.91
> Index Scan ResultSet for TESTS using constraint TESTS_1 at read uncommitted isolation level using share row locking chosen by the optimizer
> Number of opens = 5
> Rows seen = 30
> 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={0, 2}
> Number of columns fetched=2
> Number of deleted rows visited=9
> Number of pages visited=5
> Number of rows qualified=30
> Number of rows visited=43
> Scan type=btree
> Tree height=1
> 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: 19.34
> optimizer estimated cost: 5169.91
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Committing
> Tue Apr 02 21:14:56 IDT 2013 Thread[qtp31568925-35,5,main] (XID = 7222173), (SESSIONID = 28), (DATABASE = ../db/db_copy), (DRDAID = null), Rolling back
--
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