| Subject | RE: [firebird-support] Reads inconsistency between FB TraceManager and IB Planalyser |
|---|---|
| Author | Louis van Alphen |
| Post date | 2015-08-11T16:22:33Z |
Sure I understand that, but the reads/fetches are >3000 to return 1 row.
From: firebird-support@yahoogroups.com [mailto:firebird-support@yahoogroups.com]
Sent: 11 August 2015 06:15 PM
To: firebird-support@yahoogroups.com
Subject: Re: [firebird-support] Reads inconsistency between FB TraceManager and IB Planalyser
Hi Lois,
Reads value means actual reads from the disk.
If you run query twice, necessary database pages are cached, and you will see in stats more "fetches" - i.e., calls to cache, not record fetches.
Actually, always is better to run query twice, to get heated cache.
Regards,
Alexey Kovyazin
IBSurgeon
I am trying to find a performance issue in a system and I am using 2 tools just for comparison and verification. One being FB TraceManager (FBTM) and the other is an old util called
Interbase Planalyzer (IP)
It seems that the particular query from the view TRACKED_ITEM_LOCATION_DETAIL is slow.
From FBTM,while monitoring the app, I get the following raw output:
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
2015-08-11T16:35:52.4990 (6180:0000000000F9A948) EXECUTE_STATEMENT_FINISH
D:\PROJECTS\KKI\TECH\DATABASE\PRODUCTION DATABASES\2015-07-14\DIGITAN.KKI.FDB (ATT_34, SYSDBA:NONE, NONE, TCPv4:127.0.0.1)
(TRA_20898, READ_COMMITTED | NO_REC_VERSION | WAIT | READ_WRITE)
Statement 3407:
-------------------------------------------------------------------------------
select * from TRACKED_ITEM_LOCATION_DETAIL where ITEM_ID = ? order by ID
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
PLAN JOIN (JOIN (JOIN (TRACKED_ITEM_LOCATION_DETAIL TILD ORDER TILD_PK_IDX INDEX (TILD_ITEM_IDX), TRACKED_ITEM_LOCATION_DETAIL TL INDEX (TL_PK_IDX)), TRACKED_ITEM_LOCATION_DETAIL FTL INDEX (TL_PK_IDX)), TRACKED_ITEM_LOCATION_DETAIL USR INDEX (USR_PK_IDX))
param0 = bigint, "2147191655"
1 records fetched
112 ms, 3316 read(s), 3325 fetch(es)
Table Natural Index Update Insert Delete Backout Purge Expunge
***************************************************************************************************************
USER_ 1
TRACKING_LOCATION_ 1
TRACKED_ITEM_LOCATION_DETAIL_ 1
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
3325 fetches and 112ms seem way over the top. The cache hit ratio is 0%.
However, when I use IP and manually enter the same SQL, I get the following:
Prepare time 1ms
Execution time 148ms
Fetch time 4ms
With a total of 7 fetches. Not sure where FBTM gets 3K fetches?
Also, if I remove the order by, IP reports a drastic reduction is execution time i.e. down to 6msec. Does the ORDER BY on the PK make such a difference?
I am not understanding what is going on.
Either way, here are the table & view info & stats
Thanks
Louis van Alphen
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
CREATE TABLE TRACKED_ITEM_LOCATION_DETAIL_ (
UID DOM_UID /* DOM_UID = VARCHAR(36) */,
ID DOM_ID /* DOM_ID = BIGINT NOT NULL */,
IS_DELETED DOM_BINARY /* DOM_BINARY = SMALLINT DEFAULT 0 NOT NULL CHECK (( value in ( 0,1) )) */,
CREATED_DTM DOM_DTM default current_timestamp /* DOM_DTM = TIMESTAMP */,
CREATED_USER_ID DOM_FK /* DOM_FK = BIGINT */,
ROW_ORIGIN DOM_FK /* DOM_FK = BIGINT */,
ITEM_ID DOM_FK NOT NULL /* DOM_FK = BIGINT */,
LOCATION_ID DOM_FK NOT NULL /* DOM_FK = BIGINT */,
FROM_LOCATION_ID DOM_FK /* DOM_FK = BIGINT */,
START_DTM DOM_DTM NOT NULL /* DOM_DTM = TIMESTAMP */,
END_DTM DOM_DTM /* DOM_DTM = TIMESTAMP */,
START_DAT DOM_DAT NOT NULL /* DOM_DAT = DATE */,
END_DAT DOM_DAT /* DOM_DAT = DATE */
);
ALTER TABLE TRACKED_ITEM_LOCATION_DETAIL_ ADD CONSTRAINT TILD_PK PRIMARY KEY (ID)
USING INDEX TILD_PK_IDX;
CREATE INDEX TILD_END_DAT_IDX ON TRACKED_ITEM_LOCATION_DETAIL_ (END_DAT);
CREATE INDEX TILD_ITEM_IDX ON TRACKED_ITEM_LOCATION_DETAIL_ (ITEM_ID);
CREATE INDEX TILD_LOCATION_IDX ON TRACKED_ITEM_LOCATION_DETAIL_ (LOCATION_ID);
CREATE INDEX TILD_START_DAT_IDX ON TRACKED_ITEM_LOCATION_DETAIL_ (START_DAT);
CREATE OR ALTER VIEW TRACKED_ITEM_LOCATION_DETAIL(
UID,
ID,
IS_DELETED,
CREATED_DTM,
CREATED_USER_ID,
ROW_ORIGIN,
ITEM_ID,
LOCATION_ID,
FROM_LOCATION_ID,
START_DTM,
END_DTM,
START_DAT,
END_DAT,
LOCATION_NAME,
FROM_LOCATION_NAME,
USER_FULL_NAME)
AS
select
TILD.*,
TL.NAME as LOCATION_NAME,
FTL.NAME as FROM_LOCATION_NAME,
USR.FIRST_NAME || ' ' || USR.LAST_NAME as USER_FULL_NAME
from TRACKED_ITEM_LOCATION_DETAIL_ TILD
left outer join TRACKING_LOCATION_ TL on TL.ID = TILD.LOCATION_ID
left outer join TRACKING_LOCATION_ FTL on FTL.ID = TILD.FROM_LOCATION_ID
left outer join USER_ USR on USR.ID = TILD.CREATED_USER_ID
#
Fetch Timestamp
Table Name
Relation ID
Number Of Indexes
Average Record Length
Total Records
Average Version Length
Total Versions
Total Versions [%]
Max. Versions
Maximum from Total Versions [%]
Data Pages
Table Size [KB]
Table Size [MB]
Table Size [GB]
Table Size [%]
Data Page Slots
Average Fill [%]
Fill Distr. 0 - 19%
Fill Distr. 20 - 39%
Fill Distr. 40 - 59%
Fill Distr. 60 - 79%
Fill Distr. 80 - 99%
Primary Pointer Page
Index Root Page
Severity
360
2015-08-11 16:39
TRACKED_ITEM_LOCATION_DETAIL_
186
5
0
0
0
0
0
42800
684800
668.75
0.65
42800
0
0
1
9
42790
273
274
NONE
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
And here is the index stats
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
#
Fetch Timestamp
Index Name
Index ID
RDB$INDEX_ID
Table Name
Depth
Leaf Buckets
Index Size [KB]
Index Size [MB]
Index Size [GB]
Index Size Database [%]
Index Size Table [%]
Nodes
Nodes Per Page
Average Data Length
Total Duplicates
Total Duplicates [%]
Total Uniques
Total Uniques [%]
Maximum Duplicates
Maximum from Total Duplicates [%]
Index Statistics Calculated
Fill Distr. 0 - 19%
Fill Distr. 20 - 39%
Fill Distr. 40 - 59%
Fill Distr. 60 - 79%
Fill Distr. 80 - 99%
Number Of Fields
Index Fields
Unique?
Primary Key?
Foreign Key?
Active?
System?
Function-based?
Function Expression
Index Statistics Fetched
Index Statistics Diff [%]
Severity
RootPage
Average Node Length
Average Key Length
Compression Ratio
Average Prefix Length
Clustering Factor
Clustering Ratio
818
2015-08-11 16:39
TILD_END_DAT_IDX
4
5
TRACKED_ITEM_LOCATION_DETAIL_
2
1469
23504
22.95
0.02
4824682
3284
0
4821379
3303
293211
0.000302755
0
2
2
0
1465
0
0
WARNING
819
2015-08-11 16:39
TILD_ITEM_IDX
1
2
TRACKED_ITEM_LOCATION_DETAIL_
3
1593
25488
24.89
0.02
4824682
3028
0.27
4531470
293212
115
3.41E-06
0
0
1
1
1591
0
0
WARNING
820
2015-08-11 16:39
TILD_LOCATION_IDX
2
3
TRACKED_ITEM_LOCATION_DETAIL_
2
1487
23792
23.23
0.02
4824682
3244
0
4824578
104
285392
0.009615385
0
0
3
0
1484
0
0
WARNING
821
2015-08-11 16:39
TILD_PK_IDX
0
1
TRACKED_ITEM_LOCATION_DETAIL_
3
3305
52880
51.64
0.05
4824682
1459
5.1
0
4824682
0
2.07E-07
1
0
0
0
3304
0
0
NONE
822
2015-08-11 16:39
TILD_START_DAT_IDX
3
4
TRACKED_ITEM_LOCATION_DETAIL_
2
1485
23760
23.2
0.02
4824682
3248
0
4821201
3481
24166
0.000287274
0
0
0
1
1484
0
0
WARNING
[Non-text portions of this message have been removed]
From: firebird-support@yahoogroups.com [mailto:firebird-support@yahoogroups.com]
Sent: 11 August 2015 06:15 PM
To: firebird-support@yahoogroups.com
Subject: Re: [firebird-support] Reads inconsistency between FB TraceManager and IB Planalyser
Hi Lois,
Reads value means actual reads from the disk.
If you run query twice, necessary database pages are cached, and you will see in stats more "fetches" - i.e., calls to cache, not record fetches.
Actually, always is better to run query twice, to get heated cache.
Regards,
Alexey Kovyazin
IBSurgeon
I am trying to find a performance issue in a system and I am using 2 tools just for comparison and verification. One being FB TraceManager (FBTM) and the other is an old util called
Interbase Planalyzer (IP)
It seems that the particular query from the view TRACKED_ITEM_LOCATION_DETAIL is slow.
From FBTM,while monitoring the app, I get the following raw output:
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
2015-08-11T16:35:52.4990 (6180:0000000000F9A948) EXECUTE_STATEMENT_FINISH
D:\PROJECTS\KKI\TECH\DATABASE\PRODUCTION DATABASES\2015-07-14\DIGITAN.KKI.FDB (ATT_34, SYSDBA:NONE, NONE, TCPv4:127.0.0.1)
(TRA_20898, READ_COMMITTED | NO_REC_VERSION | WAIT | READ_WRITE)
Statement 3407:
-------------------------------------------------------------------------------
select * from TRACKED_ITEM_LOCATION_DETAIL where ITEM_ID = ? order by ID
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
PLAN JOIN (JOIN (JOIN (TRACKED_ITEM_LOCATION_DETAIL TILD ORDER TILD_PK_IDX INDEX (TILD_ITEM_IDX), TRACKED_ITEM_LOCATION_DETAIL TL INDEX (TL_PK_IDX)), TRACKED_ITEM_LOCATION_DETAIL FTL INDEX (TL_PK_IDX)), TRACKED_ITEM_LOCATION_DETAIL USR INDEX (USR_PK_IDX))
param0 = bigint, "2147191655"
1 records fetched
112 ms, 3316 read(s), 3325 fetch(es)
Table Natural Index Update Insert Delete Backout Purge Expunge
***************************************************************************************************************
USER_ 1
TRACKING_LOCATION_ 1
TRACKED_ITEM_LOCATION_DETAIL_ 1
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
3325 fetches and 112ms seem way over the top. The cache hit ratio is 0%.
However, when I use IP and manually enter the same SQL, I get the following:
Prepare time 1ms
Execution time 148ms
Fetch time 4ms
With a total of 7 fetches. Not sure where FBTM gets 3K fetches?
Also, if I remove the order by, IP reports a drastic reduction is execution time i.e. down to 6msec. Does the ORDER BY on the PK make such a difference?
I am not understanding what is going on.
Either way, here are the table & view info & stats
Thanks
Louis van Alphen
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
CREATE TABLE TRACKED_ITEM_LOCATION_DETAIL_ (
UID DOM_UID /* DOM_UID = VARCHAR(36) */,
ID DOM_ID /* DOM_ID = BIGINT NOT NULL */,
IS_DELETED DOM_BINARY /* DOM_BINARY = SMALLINT DEFAULT 0 NOT NULL CHECK (( value in ( 0,1) )) */,
CREATED_DTM DOM_DTM default current_timestamp /* DOM_DTM = TIMESTAMP */,
CREATED_USER_ID DOM_FK /* DOM_FK = BIGINT */,
ROW_ORIGIN DOM_FK /* DOM_FK = BIGINT */,
ITEM_ID DOM_FK NOT NULL /* DOM_FK = BIGINT */,
LOCATION_ID DOM_FK NOT NULL /* DOM_FK = BIGINT */,
FROM_LOCATION_ID DOM_FK /* DOM_FK = BIGINT */,
START_DTM DOM_DTM NOT NULL /* DOM_DTM = TIMESTAMP */,
END_DTM DOM_DTM /* DOM_DTM = TIMESTAMP */,
START_DAT DOM_DAT NOT NULL /* DOM_DAT = DATE */,
END_DAT DOM_DAT /* DOM_DAT = DATE */
);
ALTER TABLE TRACKED_ITEM_LOCATION_DETAIL_ ADD CONSTRAINT TILD_PK PRIMARY KEY (ID)
USING INDEX TILD_PK_IDX;
CREATE INDEX TILD_END_DAT_IDX ON TRACKED_ITEM_LOCATION_DETAIL_ (END_DAT);
CREATE INDEX TILD_ITEM_IDX ON TRACKED_ITEM_LOCATION_DETAIL_ (ITEM_ID);
CREATE INDEX TILD_LOCATION_IDX ON TRACKED_ITEM_LOCATION_DETAIL_ (LOCATION_ID);
CREATE INDEX TILD_START_DAT_IDX ON TRACKED_ITEM_LOCATION_DETAIL_ (START_DAT);
CREATE OR ALTER VIEW TRACKED_ITEM_LOCATION_DETAIL(
UID,
ID,
IS_DELETED,
CREATED_DTM,
CREATED_USER_ID,
ROW_ORIGIN,
ITEM_ID,
LOCATION_ID,
FROM_LOCATION_ID,
START_DTM,
END_DTM,
START_DAT,
END_DAT,
LOCATION_NAME,
FROM_LOCATION_NAME,
USER_FULL_NAME)
AS
select
TILD.*,
TL.NAME as LOCATION_NAME,
FTL.NAME as FROM_LOCATION_NAME,
USR.FIRST_NAME || ' ' || USR.LAST_NAME as USER_FULL_NAME
from TRACKED_ITEM_LOCATION_DETAIL_ TILD
left outer join TRACKING_LOCATION_ TL on TL.ID = TILD.LOCATION_ID
left outer join TRACKING_LOCATION_ FTL on FTL.ID = TILD.FROM_LOCATION_ID
left outer join USER_ USR on USR.ID = TILD.CREATED_USER_ID
#
Fetch Timestamp
Table Name
Relation ID
Number Of Indexes
Average Record Length
Total Records
Average Version Length
Total Versions
Total Versions [%]
Max. Versions
Maximum from Total Versions [%]
Data Pages
Table Size [KB]
Table Size [MB]
Table Size [GB]
Table Size [%]
Data Page Slots
Average Fill [%]
Fill Distr. 0 - 19%
Fill Distr. 20 - 39%
Fill Distr. 40 - 59%
Fill Distr. 60 - 79%
Fill Distr. 80 - 99%
Primary Pointer Page
Index Root Page
Severity
360
2015-08-11 16:39
TRACKED_ITEM_LOCATION_DETAIL_
186
5
0
0
0
0
0
42800
684800
668.75
0.65
42800
0
0
1
9
42790
273
274
NONE
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
And here is the index stats
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
#
Fetch Timestamp
Index Name
Index ID
RDB$INDEX_ID
Table Name
Depth
Leaf Buckets
Index Size [KB]
Index Size [MB]
Index Size [GB]
Index Size Database [%]
Index Size Table [%]
Nodes
Nodes Per Page
Average Data Length
Total Duplicates
Total Duplicates [%]
Total Uniques
Total Uniques [%]
Maximum Duplicates
Maximum from Total Duplicates [%]
Index Statistics Calculated
Fill Distr. 0 - 19%
Fill Distr. 20 - 39%
Fill Distr. 40 - 59%
Fill Distr. 60 - 79%
Fill Distr. 80 - 99%
Number Of Fields
Index Fields
Unique?
Primary Key?
Foreign Key?
Active?
System?
Function-based?
Function Expression
Index Statistics Fetched
Index Statistics Diff [%]
Severity
RootPage
Average Node Length
Average Key Length
Compression Ratio
Average Prefix Length
Clustering Factor
Clustering Ratio
818
2015-08-11 16:39
TILD_END_DAT_IDX
4
5
TRACKED_ITEM_LOCATION_DETAIL_
2
1469
23504
22.95
0.02
4824682
3284
0
4821379
3303
293211
0.000302755
0
2
2
0
1465
0
0
WARNING
819
2015-08-11 16:39
TILD_ITEM_IDX
1
2
TRACKED_ITEM_LOCATION_DETAIL_
3
1593
25488
24.89
0.02
4824682
3028
0.27
4531470
293212
115
3.41E-06
0
0
1
1
1591
0
0
WARNING
820
2015-08-11 16:39
TILD_LOCATION_IDX
2
3
TRACKED_ITEM_LOCATION_DETAIL_
2
1487
23792
23.23
0.02
4824682
3244
0
4824578
104
285392
0.009615385
0
0
3
0
1484
0
0
WARNING
821
2015-08-11 16:39
TILD_PK_IDX
0
1
TRACKED_ITEM_LOCATION_DETAIL_
3
3305
52880
51.64
0.05
4824682
1459
5.1
0
4824682
0
2.07E-07
1
0
0
0
3304
0
0
NONE
822
2015-08-11 16:39
TILD_START_DAT_IDX
3
4
TRACKED_ITEM_LOCATION_DETAIL_
2
1485
23760
23.2
0.02
4824682
3248
0
4821201
3481
24166
0.000287274
0
0
0
1
1484
0
0
WARNING
[Non-text portions of this message have been removed]