I asked something like this some months ago, but am still not getting
anywhere...
I have a table used for logging events, which current contains just
under 400,000 rows:
CREATE TABLE system_log (
id INTEGER GENERATED ALWAYS AS IDENTITY,
time TIMESTAMP DEFAULT NULL,
username VARCHAR(15),
name VARCHAR(520),
facility VARCHAR(15) NOT NULL,
event VARCHAR(31) NOT NULL,
details VARCHAR(32000),
CONSTRAINT systemlog_pk PRIMARY KEY (id)
);
I generally want to display most recent events first, so have defined an
index for the purpose:
CREATE INDEX log_index ON system_log (id DESC);
I execute the following query:
SELECT id,DateTimeFormat(time,null) AS
t_time,name,username,facility,event,details
FROM system_log
ORDER BY id DESC
NULLS LAST
FETCH FIRST 20 ROWS ONLY;
(DateTimeFormat is a simple function that converts a timestamp into
something human-readable like "25-Sep-2021 at 12:30".)
A timing test showed that it takes 6.348 seconds to execute this. If I
order by id ASC, it takes 0.124 seconds.
I used SYSCS_SET_RUNTIMESTATISTICS(1) and
SYSCS_SET_STATISTICS_TIMING(1), and got a dump showing that it's doing
an external sort and not using the index using ORDER BY id DESC, but
using the PK index for ORDER BY id ASC (see below)
Why isn't the first query using the index I created, and what can I do
to persuade Derby to use it?
Rick Hillegas mentioned "covering indexes", but thanks to the large
"details" column I was unable to create such a beast. Would a CLOB be
any better?
TIA,
--
John English
-------------------------------------------------------------------------
Using ORDER BY id DESC:
Statement Text:
SELECT id,DateTimeFormat(time,null) AS
t_time,name,username,facility,event,details
FROM system_log
ORDER BY id DESC
NULLS LAST
FETCH FIRST 20 ROWS ONLY
Parse Time: 20
Bind Time: 1
Optimize Time: 1
Generate Time: 1
Compile Time: 23
Execute Time: 6305
Begin Compilation Timestamp : 2021-09-25 17:15:19.947
End Compilation Timestamp : 2021-09-25 17:15:19.97
Begin Execution Timestamp : 2021-09-25 17:15:19.971
End Execution Timestamp : 2021-09-25 17:15:26.295
Statement Execution Plan Text:
Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 20
Number of reads from hash table = 20
Number of writes to hash table = 20
constructor time (milliseconds) = 0
open time (milliseconds) = 6302
next time (milliseconds) = 3
close time (milliseconds) = 0
optimizer estimated row count: 388223.00
optimizer estimated cost: 398112.27
Source result set:
Row Count (1):
Number of opens = 1
Rows seen = 20
Rows filtered = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 6302
next time (milliseconds) = 3
close time (milliseconds) = 18
optimizer estimated row count: 388223.00
optimizer estimated cost: 398112.27
Source result set:
Sort ResultSet:
Number of opens = 1
Rows input = 388218
Rows returned = 20
Eliminate duplicates = false
In sorted order = false
Sort information:
Number of merge runs=11
Number of rows input=388218
Number of rows output=388218
Size of merge runs=[32767, 32767, 32767, 32767, 32767, 32767, 32767,
32767, 32767, 32767, 32767]
Sort type=external
constructor time (milliseconds) = 0
open time (milliseconds) = 6302
next time (milliseconds) = 3
close time (milliseconds) = 18
optimizer estimated row count: 388223.00
optimizer estimated cost: 398112.27
Source result set:
Project-Restrict ResultSet (3):
Number of opens = 1
Rows seen = 388218
Rows filtered = 0
restriction = false
projection = true
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 3881
close time (milliseconds) = 0
restriction time (milliseconds) = 0
projection time (milliseconds) = 1434
optimizer estimated row count: 388223.00
optimizer estimated cost: 398112.27
Source result set:
Table Scan ResultSet for SYSTEM_LOG at read uncommitted isolation
level using share row locking chosen by the optimizer
Number of opens = 1
Rows seen = 388218
Rows filtered = 0
Fetch Size = 16
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 2423
close time (milliseconds) = 0
next time in milliseconds/row = 0
scan information:
Bit set of columns fetched={0, 1, 2, 3,
4, 7, 8}
Number of columns fetched=7
Number of pages visited=2661
Number of rows qualified=388218
Number of rows visited=388404
Scan type=heap
start position:
null
stop position:
null
qualifiers:
None
optimizer estimated row count: 388223.00
optimizer estimated cost: 398112.27
-------------------------------------------------------------------------
Using ORDER BY id ASC:
Statement Name:
null
Statement Text:
SELECT id,DateTimeFormat(time,null) AS
t_time,name,username,facility,event,details
FROM system_log
ORDER BY id ASC
NULLS LAST
FETCH FIRST 20 ROWS ONLY
Parse Time: 24
Bind Time: 1
Optimize Time: 1
Generate Time: 1
Compile Time: 27
Execute Time: 123
Begin Compilation Timestamp : 2021-09-25 17:14:57.128
End Compilation Timestamp : 2021-09-25 17:14:57.155
Begin Execution Timestamp : 2021-09-25 17:20:31.615
End Execution Timestamp : 2021-09-25 17:20:31.738
Statement Execution Plan Text:
Scroll Insensitive ResultSet:
Number of opens = 1
Rows seen = 20
Number of reads from hash table = 20
Number of writes to hash table = 20
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 123
close time (milliseconds) = 0
optimizer estimated row count: 388223.00
optimizer estimated cost: 1035759.04
Source result set:
Row Count (1):
Number of opens = 1
Rows seen = 20
Rows filtered = 0
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 123
close time (milliseconds) = 0
optimizer estimated row count: 388223.00
optimizer estimated cost: 1035759.04
Source result set:
Project-Restrict ResultSet (4):
Number of opens = 1
Rows seen = 20
Rows filtered = 0
restriction = false
projection = true
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 123
close time (milliseconds) = 0
restriction time (milliseconds) = 0
projection time (milliseconds) = 1
optimizer estimated row count: 388223.00
optimizer estimated cost: 1035759.04
Source result set:
Index Row to Base Row ResultSet for SYSTEM_LOG:
Number of opens = 1
Rows seen = 20
Columns accessed from heap = {0, 1, 2, 3, 4, 7, 8}
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 122
close time (milliseconds) = 0
optimizer estimated row count: 388223.00
optimizer estimated cost: 1035759.04
Index Scan ResultSet for SYSTEM_LOG using constraint SYSTEMLOG_PK at
read uncommitted isolation level using share row locking chosen by the
optimizer
Number of opens = 1
Rows seen = 20
Rows filtered = 0
Fetch Size = 1
constructor time (milliseconds) = 0
open time (milliseconds) = 0
next time (milliseconds) = 121
close time (milliseconds) = 0
next time in milliseconds/row = 6
scan information:
Bit set of columns fetched={1}
Number of columns fetched=1
Number of deleted rows visited=94
Number of pages visited=1187
Number of rows qualified=20
Number of rows visited=114
Scan type=btree
Tree height=3
start position:
None
stop position:
None
qualifiers:
None
optimizer estimated row count: 388223.00
optimizer estimated cost: 1035759.04
--
This email has been checked for viruses by AVG.
https://www.avg.com
