On 21/12/2012 19:40, Knut Anders Hatlen wrote:
If you run the query with derby.language.logQueryPlan=true and check
derby.log, does the query plan say that log_index is used?
It seems to use it:
Sat Dec 22 18:44:54 IST 2012 Thread[qtp9851452-34,5,main] (XID = 5645972),
(SESSIONID = 18), SELECT DateTimeFormat(t_time,null) AS
t_time,facility,event,details,name,username,module,test FROM system_log_view
ORDER BY time DESC ******* Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 20
Number of reads from hash table = 21
Number of writes to hash table = 95103
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 95105.00
optimizer estimated cost: 237241.89
Source result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 95103
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: 95105.00
optimizer estimated cost: 237241.89
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 95103
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: 95105.00
optimizer estimated cost: 237241.89
Source result set:
Index Row to Base Row ResultSet for SYSTEM_LOG:
Number of opens = 1
Rows seen = 95103
Columns accessed from heap = {2, 3, 4, 5, 6, 7}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 0
close time (milliseconds) = 0
optimizer estimated row count: 95105.00
optimizer estimated cost: 237241.89
Index Scan ResultSet for SYSTEM_LOG using index LOG_INDEX at read
uncommitted isolation level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 95103
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=715
Number of rows qualified=95103
Number of rows visited=95103
Scan type=btree
Tree height=3
start position:
None
stop position:
None
qualifiers:
None
optimizer estimated row count:
95105.00
optimizer estimated cost:
237241.89
Does it change anything if you access the table directly instead of via
the view? I think we've had reports that the optimizer cannot always see
through the views and misses out on some opportunities for optimization.
It cuts it down to about 9 seconds, which is much more acceptable. The time is
no longer formatted, but when I tried taking that out before it didn't seem to
make much difference, so maybe it is the view. I'll try some more experiments
with different variations of formatting and views and see what I can find out.
Thanks,
--
John English
