db-derby-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From John English <john.fore...@gmail.com>
Subject Using indexes
Date Sat, 25 Sep 2021 14:39:30 GMT
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


Mime
View raw message