Hi there,
We use Apache Derby in our commercial application, PaperCut NG
<http://www.papercut.com/>. It's proven to be very reliable, however we
occasionally get reports of very bad performance in some areas. We
haven't had the time to investigate them fully previously (usually
upgrading to an external DB like Postgres or SQL Server fixes the
issue). This time we had a look in more detail with a recent report,
and we've found some very strange performance characteristics ... and
would love some advice and assistance.
We have a query that is doing inner joins to 5 tables. It's quite a
simple query, but the core table has about 300,000 rows, and where
limiting the results based on a date in that table that is indexed.
Here's a summary of my situation/findings:
* Using the latest Derby release 10.3.1.4, with a Java 1.5 VM on
Windows.
* We only have a single WHERE clause, which is on the indexed date
field is restricting the data such that no data is returned. e.g.
log_date > (latest log date). So derby should quickly detect
there is litte/no data to return.
* Running the original query takes 22 minutes running 100% CPU.
* Running a count(*) for the same query is quick (< 1 sec).
* Removing the ORDER BY and changing the select list to just include
a single field from each table and it still takes 22 minutes.
* Changing the select list to retrieve only a single field from 2 of
the table and it still takes 22 minutes (I have a log of the query
and the runtime stats for this attached "derby-slow.log").
* Changing the select list to a single field from 1 of the tables
makes the query run fast - less than a second. (I have a log of
the query and the runtime stats for this attached "derby-fast.log").
* Running the original query on the same dataset in PostgreSQL or
SQL Server is very fast (less than a second). This is why we
often recommend customers upsize to Postgres or SQL Server.
* Also the SQL is generated via Hibernate ORM, so we have some
limitations in how we can modify the SQL.
From the query plan it seems that seems that it stops using the date
index on the "tbl_printer_usage_log" log table, and changes from Hash
joins to Nested Loop joins. On a large table like this when providing a
where clause that on a field that is indexed .... we have to ensure that
derby uses the index.
If I increase the pageCacheSize to 100,000 pages, it reduces the time of
the query to about 2-3 minutes, but it's still very slow compared to
when the correct index is used.
Can anyone please help me understand the following:
* Why does the query plan change dramatically, just by changing the
fields that are retrieved?
* Why is derby avoiding the most obvious index? The date field in
the 300,000 row table (the date field is the only field in our
where clause).
* Is there anyway to avoid this behavior?
If we can understand what's causing this, we'll be able to make a much
more effective use of Derby. At the moment, on customers with large
datasets, we currently just recommend they "upsize" to Postgres or SQL
Server and the problem goes away. However, we'd much prefer to fix this
and have our Derby database behave better.
I'd be happy to provide the derby database that exhibits these problems
if someone would like to see what's going on. The database is from a
customer, so I don't want to post it publicly, but if you send me an
email off-list I'd be happy to provide it.
Regards.
--
Matt Doran
PaperCut Software International Pty. Ltd.
Phone: +61 (3) 9807 5767
E-mail: [EMAIL PROTECTED]
Profile: http://www.papercut.com/about/#matt
Blog: http://www.papercut.com/blog/
----------------------------------------------------------------
2007-12-03 03:19:39.984 GMT:
Booting Derby version The Apache Software Foundation - Apache Derby - 10.3.1.4
- (561794): instance c013800d-0116-9e04-2443-000001d78c58
on database directory C:\Development\pc-ng\server\working\data\internal\derby
Database Class Loader started - derby.database.classpath=''
2007-12-03 03:19:40.218 GMT Thread[main,5,main] (XID = 136302), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), Committing
2007-12-03 03:19:40.218 GMT:
Shutting down instance c013800d-0116-9e04-2443-000001d78c58
----------------------------------------------------------------
----------------------------------------------------------------
2007-12-03 03:19:40.250 GMT:
Booting Derby version The Apache Software Foundation - Apache Derby - 10.3.1.4
- (561794): instance a816c00e-0116-9e04-2443-000001d78c58
on database directory C:\Development\pc-ng\server\working\data\internal\derby
Database Class Loader started - derby.database.classpath=''
2007-12-03 03:19:40.265 GMT Thread[main,5,main] (XID = 136308), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), Committing
2007-12-03 03:20:14.453 GMT Thread[main,5,main] (XID = 136309), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), Begin compiling prepared statement: select
account3_.account_name, account4_.account_name from tbl_printer_usage_log
printerusa0_ inner join tbl_printer printer1_ on
printerusa0_.printer_id=printer1_.printer_id inner join tbl_user user2_ on
printerusa0_.used_by_user_id=user2_.user_id inner join tbl_account account3_ on
printerusa0_.charged_to_account_id=account3_.account_id inner join tbl_account
account4_ on printerusa0_.assoc_with_account_id=account4_.account_id where
printerusa0_.usage_date>='2007-12-02 00:00:00' :End prepared statement
2007-12-03 03:20:15.875 GMT Thread[main,5,main] (XID = 136309), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), End compiling prepared statement: select
account3_.account_name, account4_.account_name from tbl_printer_usage_log
printerusa0_ inner join tbl_printer printer1_ on
printerusa0_.printer_id=printer1_.printer_id inner join tbl_user user2_ on
printerusa0_.used_by_user_id=user2_.user_id inner join tbl_account account3_ on
printerusa0_.charged_to_account_id=account3_.account_id inner join tbl_account
account4_ on printerusa0_.assoc_with_account_id=account4_.account_id where
printerusa0_.usage_date>='2007-12-02 00:00:00' :End prepared statement
2007-12-03 03:20:15.968 GMT Thread[main,5,main] (XID = 136309), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), Executing prepared statement: select account3_.account_name,
account4_.account_name from tbl_printer_usage_log printerusa0_ inner join
tbl_printer printer1_ on printerusa0_.printer_id=printer1_.printer_id inner
join tbl_user user2_ on printerusa0_.used_by_user_id=user2_.user_id inner join
tbl_account account3_ on
printerusa0_.charged_to_account_id=account3_.account_id inner join tbl_account
account4_ on printerusa0_.assoc_with_account_id=account4_.account_id where
printerusa0_.usage_date>='2007-12-02 00:00:00' :End prepared statement
2007-12-03 03:42:14.093 GMT Thread[main,5,main] (XID = 136309), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), Committing
2007-12-03 03:42:14.187 GMT Thread[main,5,main] (XID = 136309), (SESSIONID =
0), select account3_.account_name, account4_.account_name from
tbl_printer_usage_log printerusa0_ inner join tbl_printer printer1_ on
printerusa0_.printer_id=printer1_.printer_id inner join tbl_user user2_ on
printerusa0_.used_by_user_id=user2_.user_id inner join tbl_account account3_ on
printerusa0_.charged_to_account_id=account3_.account_id inner join tbl_account
account4_ on printerusa0_.assoc_with_account_id=account4_.account_id where
printerusa0_.usage_date>='2007-12-02 00:00:00' ******* Project-Restrict
ResultSet (14):
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: 10758.40
optimizer estimated cost: 1239913.91
Source result set:
Nested Loop Exists Join ResultSet:
Number of opens = 1
Rows seen from the left = 0
Rows seen from the right = 0
Rows filtered = 0
Rows returned = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10758.40
optimizer estimated cost: 1239913.91
Left result set:
Nested Loop Exists Join ResultSet:
Number of opens = 1
Rows seen from the left = 0
Rows seen from the right = 0
Rows filtered = 0
Rows returned = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10758.40
optimizer estimated cost: 1178773.95
Left result set:
Nested Loop Join ResultSet:
Number of opens = 1
Rows seen from the left = 260898
Rows seen from the right = 0
Rows filtered = 0
Rows returned = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 10758.40
optimizer estimated cost: 1117633.98
Left result set:
Nested Loop Join ResultSet:
Number of opens = 1
Rows seen from the left = 67
Rows seen from the right = 260898
Rows filtered = 0
Rows returned = 260898
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count:
280728.00
optimizer estimated cost:
99880.70
Left result set:
Index Scan ResultSet for TBL_PRINTER
using constraint SQL071203102955020 at read committed isolation level using
instantaneous share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 67
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}
Number of columns fetched=1
Number of deleted rows visited=0
Number of pages visited=1
Number of rows qualified=67
Number of rows visited=67
Scan type=btree
Tree height=-1
start position:
None
stop position:
None
qualifiers:
None
optimizer estimated row count:
72.00
optimizer estimated cost:
142.63
Right result set:
Index Scan ResultSet for TBL_USER using
constraint SQL071203102955630 at read committed isolation level using
instantaneous share row locking chosen by the optimizer
Number of opens = 67
Rows seen = 260898
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}
Number of columns fetched=1
Number of deleted rows visited=0
Number of pages visited=469
Number of rows qualified=260898
Number of rows visited=260898
Scan type=btree
Tree height=2
start position:
None
stop position:
None
qualifiers:
None
optimizer estimated row count:
280728.00
optimizer estimated cost:
99738.07
Right result set:
Project-Restrict ResultSet (9):
Number of opens = 260898
Rows seen = 21842804
Rows filtered = 21842804
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:
10758.40
optimizer estimated cost:
1017753.28
Source result set:
Index Row to Base Row ResultSet for
TBL_PRINTER_USAGE_LOG:
Number of opens = 260898
Rows seen = 21842804
Columns accessed from heap = {1, 3, 4,
7, 24}
constructor time (milliseconds)
= 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count:
10758.40
optimizer estimated cost:
1017753.28
Index Scan ResultSet for
TBL_PRINTER_USAGE_LOG using index IX_PRINTER_USAGE_LOG_USER at read committed
isolation level using instantaneous share row locking chosen by the optimizer
Number of opens = 260898
Rows seen = 21842804
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=550405
Number of rows
qualified=21842804
Number of rows
visited=22103166
Scan type=btree
Tree height=2
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: 10758.40
optimizer estimated
cost: 1017753.28
Right result set:
Index Row to Base Row ResultSet for TBL_ACCOUNT:
Number of opens = 0
Rows seen = 0
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: 10758.40
optimizer estimated cost: 61139.96
Index Scan ResultSet for TBL_ACCOUNT using
constraint SQL071203102954490 at read committed isolation level using share row
locking chosen by the optimizer
Number of opens = 0
Rows seen = 0
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
scan information:
start position:
>= 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:
10758.40
optimizer estimated cost:
61139.96
Right result set:
Index Row to Base Row ResultSet for TBL_ACCOUNT:
Number of opens = 0
Rows seen = 0
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: 10758.40
optimizer estimated cost: 61139.96
Index Scan ResultSet for TBL_ACCOUNT using constraint
SQL071203102954490 at read committed isolation level using share row locking
chosen by the optimizer
Number of opens = 0
Rows seen = 0
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
scan information:
start position:
>= 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: 10758.40
optimizer estimated cost: 61139.96
2007-12-03 03:42:14.234 GMT Thread[main,5,main] (XID = 136309), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), Committing
2007-12-03 03:44:39.421 GMT Thread[main,5,main] (XID = 136309), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DATABASE = C:\Development\pc-ng\server\working\data\internal/derby), (DRDAID =
null), Rolling back
----------------------------------------------------------------
2007-12-03 02:50:00.078 GMT:
Booting Derby version The Apache Software Foundation - Apache Derby - 10.3.1.4
- (561794): instance c013800d-0116-9de8-fb81-000001d78c58
on database directory C:\Development\pc-ng\server\working\data\internal\derby
Database Class Loader started - derby.database.classpath=''
2007-12-03 02:50:00.312 GMT Thread[main,5,main] (XID = 136296), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), Committing
2007-12-03 02:50:00.312 GMT:
Shutting down instance c013800d-0116-9de8-fb81-000001d78c58
----------------------------------------------------------------
----------------------------------------------------------------
2007-12-03 02:50:00.328 GMT:
Booting Derby version The Apache Software Foundation - Apache Derby - 10.3.1.4
- (561794): instance a816c00e-0116-9de8-fb81-000001d78c58
on database directory C:\Development\pc-ng\server\working\data\internal\derby
Database Class Loader started - derby.database.classpath=''
2007-12-03 02:50:00.343 GMT Thread[main,5,main] (XID = 136302), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), Committing
2007-12-03 02:50:02.875 GMT Thread[main,5,main] (XID = 136303), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), Begin compiling prepared statement: select
account4_.account_name from tbl_printer_usage_log printerusa0_ inner join
tbl_printer printer1_ on printerusa0_.printer_id=printer1_.printer_id inner
join tbl_user user2_ on printerusa0_.used_by_user_id=user2_.user_id inner join
tbl_account account3_ on
printerusa0_.charged_to_account_id=account3_.account_id inner join tbl_account
account4_ on printerusa0_.assoc_with_account_id=account4_.account_id where
printerusa0_.usage_date>='2007-12-02 00:00:00' :End prepared statement
2007-12-03 02:50:04.000 GMT Thread[main,5,main] (XID = 136303), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), End compiling prepared statement: select
account4_.account_name from tbl_printer_usage_log printerusa0_ inner join
tbl_printer printer1_ on printerusa0_.printer_id=printer1_.printer_id inner
join tbl_user user2_ on printerusa0_.used_by_user_id=user2_.user_id inner join
tbl_account account3_ on
printerusa0_.charged_to_account_id=account3_.account_id inner join tbl_account
account4_ on printerusa0_.assoc_with_account_id=account4_.account_id where
printerusa0_.usage_date>='2007-12-02 00:00:00' :End prepared statement
2007-12-03 02:50:04.093 GMT Thread[main,5,main] (XID = 136303), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), Executing prepared statement: select account4_.account_name
from tbl_printer_usage_log printerusa0_ inner join tbl_printer printer1_ on
printerusa0_.printer_id=printer1_.printer_id inner join tbl_user user2_ on
printerusa0_.used_by_user_id=user2_.user_id inner join tbl_account account3_ on
printerusa0_.charged_to_account_id=account3_.account_id inner join tbl_account
account4_ on printerusa0_.assoc_with_account_id=account4_.account_id where
printerusa0_.usage_date>='2007-12-02 00:00:00' :End prepared statement
2007-12-03 02:50:04.125 GMT Thread[main,5,main] (XID = 136303), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), Committing
2007-12-03 02:50:04.218 GMT Thread[main,5,main] (XID = 136303), (SESSIONID =
0), select account4_.account_name from tbl_printer_usage_log printerusa0_ inner
join tbl_printer printer1_ on printerusa0_.printer_id=printer1_.printer_id
inner join tbl_user user2_ on printerusa0_.used_by_user_id=user2_.user_id inner
join tbl_account account3_ on
printerusa0_.charged_to_account_id=account3_.account_id inner join tbl_account
account4_ on printerusa0_.assoc_with_account_id=account4_.account_id where
printerusa0_.usage_date>='2007-12-02 00:00:00' ******* Project-Restrict
ResultSet (12):
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: 107585.61
optimizer estimated cost: 953819.40
Source result set:
Hash Exists Join ResultSet:
Number of opens = 1
Rows seen from the left = 0
Rows seen from the right = 0
Rows filtered = 0
Rows returned = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 107585.61
optimizer estimated cost: 953819.40
Left result set:
Nested Loop Exists Join ResultSet:
Number of opens = 1
Rows seen from the left = 0
Rows seen from the right = 0
Rows filtered = 0
Rows returned = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 107585.61
optimizer estimated cost: 953675.34
Left result set:
Hash Exists Join ResultSet:
Number of opens = 1
Rows seen from the left = 0
Rows seen from the right = 0
Rows filtered = 0
Rows returned = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 107585.61
optimizer estimated cost: 342266.32
Left result set:
Hash Exists Join ResultSet:
Number of opens = 1
Rows seen from the left = 0
Rows seen from the right = 0
Rows filtered = 0
Rows returned = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count:
107585.61
optimizer estimated cost:
340798.77
Left result set:
Index Row to Base Row ResultSet for
TBL_PRINTER_USAGE_LOG:
Number of opens = 1
Rows seen = 0
Columns accessed from heap = {1, 3, 4,
7, 24}
constructor time (milliseconds)
= 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count:
107585.61
optimizer estimated cost:
339335.68
Index Scan ResultSet for
TBL_PRINTER_USAGE_LOG using index IX_PRINTER_USAGE_LOG_DATE at read committed
isolation level using instantaneous 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=2
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:
stop position:
None
qualifiers:
None
optimizer estimated row
count: 107585.61
optimizer estimated
cost: 339335.68
Right result set:
Hash Scan ResultSet for TBL_USER using
constraint SQL071203102955630 at read committed isolation level using
instantaneous share row locking:
Number of opens = 0
Hash table size = 0
Hash key is column number 0
Rows seen = 0
Rows filtered = 0
constructor time (milliseconds)
= 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
scan information:
start position:
None
stop position:
None
scan qualifiers:
None
next qualifiers:
Column[0][0] Id: 0
Operator: =
Ordered nulls: false
Unknown return value: false
Negate comparison result: false
optimizer estimated row count:
107585.61
optimizer estimated cost:
1463.09
Right result set:
Hash Scan ResultSet for TBL_ACCOUNT using
constraint SQL071203102954490 at read committed isolation level using
instantaneous share row locking:
Number of opens = 0
Hash table size = 0
Hash key is column number 0
Rows seen = 0
Rows filtered = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
scan information:
start position:
None
stop position:
None
scan qualifiers:
None
next qualifiers:
Column[0][0] Id: 0
Operator: =
Ordered nulls: false
Unknown return value: false
Negate comparison result: false
optimizer estimated row count:
107585.61
optimizer estimated cost:
1467.56
Right result set:
Index Row to Base Row ResultSet for TBL_ACCOUNT:
Number of opens = 0
Rows seen = 0
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: 107585.61
optimizer estimated cost: 611409.02
Index Scan ResultSet for TBL_ACCOUNT using
constraint SQL071203102954490 at read committed isolation level using share row
locking chosen by the optimizer
Number of opens = 0
Rows seen = 0
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
scan information:
start position:
>= 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:
107585.61
optimizer estimated cost:
611409.02
Right result set:
Hash Scan ResultSet for TBL_PRINTER using constraint
SQL071203102955020 at read committed isolation level using instantaneous share
row locking:
Number of opens = 0
Hash table size = 0
Hash key is column number 0
Rows seen = 0
Rows filtered = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
scan information:
start position:
None
stop position:
None
scan qualifiers:
None
next qualifiers:
Column[0][0] Id: 0
Operator: =
Ordered nulls: false
Unknown return value: false
Negate comparison result: false
optimizer estimated row count: 107585.61
optimizer estimated cost: 144.05
2007-12-03 02:50:04.265 GMT Thread[main,5,main] (XID = 136303), (SESSIONID =
0), (DATABASE = C:\Development\pc-ng\server\working\data\internal/derby),
(DRDAID = null), Committing
