 |
XFC introduction
The OpenVMS operating system has two types of caches -- the
data cache and the metadata cache. The data cache is referred to as eXtended
File Cache (XFC) and the metadata cache is called the eXtended Qio Processor (XQP).
XFC caches contents of all files present on the disk, excluding directory files.
XQP caches file headers and directory files.
Statistics provided by XFC
XFC provides various statistics of the system, which can be used for the overall system performance tuning. XFC provides the statistics at the
system, volume, file and I/O level. The DCL commands or the XFC SDA extension can be used to get the XFC statistics. In most scenarios, DCL as well as XFC SDA extensions provide
a similar type of statistics. The XFC SDA extension generally provides little more information than the corresponding DCL commands.
Some of the important statistic include Read hit rate, XFC cache memory, I/O size distribution, and so on. This
paper explores about the various statistics that are provided by XFC.
HotFile statistics
Hotfile is a file in the system that records many
activities in terms of read and write operations. In many environments it is
observed that 80% of the I/O's that are issued are on 20% of the files present
in the system. This being the case, it is very important to know which among the
many files that are present in the system fall into this 20% category.
Hotfile – TOPQIO
On a given volume, the TOPQIO keyword instructs XFC to display the first ‘N’ entries in descending order of the number of
IOs done to the file.
DCL command
$
$ SHOW MEM/CACHE=(VOLUME=<VOL-NAME>,OPEN,CLOSED,TOPQIO:N)
<VOL-NAME>: Volume name
N: Number of entries to be displayed
Sample output
$SHOW MEMORY/CACHE=(VOLUME=BRAMHA$DKB200:,OPEN,CLOSED,TOPQIO:2)
System Memory Resources on 30-MAY-2010 03:13:44.48
Extended File Cache Top QIO File Statistics:
_BRAMHA$DKB200: (DISK$BR_V83R), Caching mode is VIOC Compatible
_BRAMHA$DKB200:[MURALI]PERFORM_TEST.COM;68 (389451, 1057, 0) (closed)
Caching is enabled, active caching mode is Write Through
Allocated pages 1 Total QIOs 1177
Read hits 1176 Virtual reads 1176
Virtual writes 1 Hit rate 100%
Read aheads 0 Read throughs
1176
Write throughs 1 Read arounds 0
Write arounds 0
_BRAMHA$DKB200:[MURALI]TEST_CONFIG.COM;47 (389469, 13875, 0) (closed)
Caching is enabled, active caching mode is Write Through
Allocated pages 1 Total QIOs 393
Read hits 392 Virtual reads 392
Virtual writes 1 Hit rate 100%
Read aheads 0 Read throughs
392
Write throughs 1 Read arounds 0
Write arounds 0
Total of 2 files for this volume
$
Interpreting the output
On the disk BRAMHA$DKB200, the maximum number of IOs are done to the file PERFORM_TEST.COM (389451, 1057, 0).
- The total number of IOs done to the file is 1177. Among these IOs, 1176
are read IOs and 1 write IO.
- The read hits of the file are 100%. This is excellent because all attempts to read the file were satisfied from the cache itself.
- Allocated pages of the file is 1 Page. This is a small temporary file and hence consumes a very small portion of XFC cache memory.
Hotfile – TOPHITRATE
On a given volume, the TOPHITRATE keyword instructs XFC to display the first ‘N’ entries in descending order of
read hit rates of the file.
DCL command
$ SHOW MEM/CACHE=(VOLUME=<VOL-NAME>,OPEN,CLOSED,TOPQIO:N)
<VOL-NAME>: Volume name
N: Number of entries to be displayed
Sample output
$SHOW MEMORY/CACHE=(VOLUME=BRAMHA$DKB200:,OPEN,CLOSED,TOPHITRATE:2)
System Memory Resources on 30-MAY-2010 03:27:08.67
Extended File Cache Top Hitrate File Statistics:
_BRAMHA$DKB200: (DISK$BR_V83R), Caching mode is VIOC Compatible
_BRAMHA$DKB200:[MURALI]TRACE_SETUP.COM;5 (389474, 1, 0) (closed)
Caching is enabled, active caching mode is Write Through
Allocated pages 1 Total QIOs
5
Read hits
4 Virtual reads 4
Virtual writes 1 Hit rate 100%
Read aheads 0 Read throughs
4
Write throughs 1 Read arounds 0
Write arounds 0
_BRAMHA$DKB200:[MURALI]PERFORM_TEST.COM;68 (389451, 1057, 0) (closed)
Caching is enabled, active caching mode is Write Through
Allocated pages 1 Total QIOs 1177
Read hits
1176 Virtual reads
1176
Virtual writes 1 Hit rate 100%
Read aheads 0 Read throughs 1176
Write throughs 1 Read arounds 0
Write arounds 0
Total of 2 files for this volume
$
Interpreting the output
On the disk BRAMHA$DKB200, the file with maximum read hit rate is TRACE_SETUP.COM (389474, 1, 0).
- The total number of IOs done to the file is 5. Among these IOs, 4 are read
IOs and 1 write IO.
- The read hits of the file are 100%. This is excellent because all attempts to read the file were satisfied from the cache itself.
-
Allocated page of the file is one page. This is a small temporary file and hence consumes a very small portion of the XFC cache memory.
Memory statistics
The "SHOW MEM/CACHE" DCL command provides the XFC memory utilization statistics at the system level. It also provides other important statistics, such as read hit rate, and number of read/write
IOs at the system level.
DCL command
$SHOW MEMORY/CACHE
Sample output
$SHOW MEMORY/CACHE
System Memory Resources on 30-MAY-2010 04:37:45.74 Extended File Cache (Time of last reset: 29-MAY-2010 00:25:38.06)
Allocated (MBytes) 80.90 Maximum size (MBytes) 2047.81
Free (MBytes) 0.00 Minimum size (MBytes)
3.12
In use (MBytes) 80.90 Percentage Read I/Os
77%
Read hit rate 90% Write hit rate
0%
Read I/O count 70914 Write I/O count
20452
Read hit count 63875 Write hit count
0
Reads bypassing cache 204 Writes bypassing cache
24
Files cached open 398 Files cached closed
312
Vols in Full XFC mode 0 Vols in VIOC Compatible
mode
1
Vols in No Caching mode 0 Vols in Perm. No Caching mode 0
$
Interpreting the output
- XFC memory can grow to a maximum of 2GB, that is 2047.81 MB
- Currently XFC has allocated itself a memory of 80.9 MB
- The free memory with XFC is 0MB. Any subsequent request to cache a file would cause XFC to expand in size.
- The overall read hit rate of the system is 90%. This is a good hit rate.
- Out of the total IOs issued in the system, 77% of the IOs are read IOs.
SDA command
SDA> SHOW MEM/CACHE
Sample output
SDA> SHOW MEM/CACHE
System Memory Resources from Running System on 30-MAY-2010 04:44:48.61
----------------------------------------------------------------
Extended File Cache (Time of last reset: 29-MAY-2010 00:25:38.06)
Allocated (MBytes) 80.90 Maximum size (MBytes) 2047.81
Free (MBytes) 0.00 Minimum size (MBytes)
3.12
In use (MBytes) 80.90 Percentage Read I/Os
77%
Read hit rate 90% Write hit rate
0%
Read I/O count 70914 Write I/O count
20452
Read hit count 63875 Write hit count
0
Reads bypassing cache 204 Writes bypassing cache
24
Files cached open 399 Files
cached closed 311
Vols in Full XFC mode 0 Vols in VIOC Compatible
mode
1
Vols in No Caching mode 0 Vols in Perm. No Caching mode 0
SDA>
Interpreting the output
The output is interpreted similar to that of the corresponding “SHOW MEM/CACHE” DCL
command.
System statistics
The "SHOW MEM/CACHE" DCL command or the “XFC SHOW SUMMARY” SDA command provides the XFC statistic at the system level. Some of the important statistics that can obtained are read hit rate and
the number of read/write IOs.
DCL command
$ SHOW MEM/CACHE
Sample output
$SHOW MEMORY/CACHE
System Memory Resources on 30-MAY-2010 04:37:45.74
Extended File Cache (Time of last reset: 29-MAY-2010 00:25:38.06)
Allocated (MBytes) 80.90 Maximum size (MBytes) 2047.81
Free (MBytes) 0.00 Minimum size (MBytes)
3.12
In use (MBytes) 80.90
Percentage Read I/Os 77%
Read hit rate 90% Write hit rate
0%
Read I/O count 70914 Write I/O count
20452
Read hit count 63875
Write hit count
0
Reads bypassing cache 204 Writes
bypassing cache 24
Files cached
open 399 Files cached closed
312
Vols in Full XFC mode 0 Vols in VIOC Compatible
mode
1
Vols in No Caching mode 0 Vols in Perm. No Caching mode 0
$
Interpreting the system output
- The overall read hit rate of the system is 90%. This is a very good hit rate.
- Out of the total IOs issued in the system 77% of the IOs are read IOs.
- In this system, the number of open files cached by XFC is 398 and the number
of closed files cached by XFC is 312.
SDA command
SDA> XFC SHOW SUMMARY
Sample output
SDA> XFC SHOW SUMMARY
XFC Summary (current time 30-MAY-2010 04:59:24.36)
--------------------------------------------------------------------------------
...
Virtual Reads: 71090
Read Hits: 64019
Read Cache Hit Percentage: 90.05 %
Virtual Writes: 20770
Open Files: 400
Closed Files in the Cache: 311
Total Files in Cache: 711
...
SDA>
Interpreting the system output
- 71090 virtual read IOs and 20770 virtual write IOs are issued.
- Read hit rate is 90.05%. This is a very good hit rate.
- The total number of files in the cache is 711. Out of these, 400 files are open files and 311 files are closed files.
Periodic system activity statistics
The "SHOW MEM/CACHE" DCL command provides the XFC memory utilization statistic at the system level. It also provides other important statistics such as read hit rate and
the number of read/write IOs at the system level. XFC records the activity of the system on a periodic basis, which is at a regular interval
every 10 minutes. XFC records various information about the system, which would be useful to track the behavior of the system. Some of the statistics captured are:
Number of read/write IOs
Read hit rate
Open/closed files in cache
XFC cache memory
SDA command
SDA>XFC SHOW HISTORY
Sample output
SDA>XFC SHOW HISTORY
XFC Performance History (current time 30-MAY-2010 05:20:43.64)
--------------------------------------------------------------
Time Peak .....Cache I/O Counts....... ... Allocated
IO Reads Hits Rate
Writes Memory
...
29-MAY 01:05 1 10 7 70% 316 ... 73.5 MB
29-MAY 00:55 3 49364 46923 95% 2231 ... 71.0 MB
29-MAY 00:45 1 315 265 84% 25 ... 66.9 MB
29-MAY 00:35 8 17234 13279 77% 167 ... 65.9 MB
...
SDA>
Interpreting the output
Between the time intervals of 29-MAY 00:35 and 29-MAY 00:45, the following data was gathered:
- Number of read IOs were 315, number of write IOs were 25
- Read hit rate was 84%
- The XFC cache memory increased from 65.9 MB to 66.9MB
Systemwide IO Size distribution statistic
XFC also keeps track of all the IOs issued in the system based on the IO size i.e., 1 block or 2 blocks and so on.
For IOs of particular size, XFC keeps track of statistics such as:
- Number of read operations
- Number of write operations
- Number of read hits
This statistic provides information on the read hit of IOs based
upon the IO size.
DCL command
$ SHOW MEM/CACHE/FULL
Sample output
$SHOW MEMORY/CACHE/FULL
System Memory Resources on 31-MAY-2010 02:36:47.05
Extended File Cache (Time of last reset: 29-MAY-2010 00:25:38.06)
...
I/O Statistics - Distributions (MAX_IO_SIZE: 127)
------------------------------------------------------------------
Transfer Size: Reads Read Hits Writes
1 Block IO: 28160 27428 2384
2 Block IO: 6948 6345 24
3 Block IO: 402 307 34
...
126 Block IO: 2 0 0
>127<256 Block IO: 27 3
>255 Block IO: 53 0
-------------------------------------------------
Totals: 73403 65848 34574
$
Interpreting the system output
- 2384 write IOs were of size 1 block. 28160 IOs were of size 1 block
and among these 27428 IOs were a read hit.
- 27 read IOs and 3 write IOs issued were of size in the range of
127-256 blocks. None of them was a read hit.
- 53 read IOs and no write IOs issued were of size greater than
255 blocks. None of them was a read hit.
SDA command
SDA> XFC SHOW SUMMARY/STATS
XFC Summary (current time
31-MAY-2010 02:51:16.69)
Sample output
SDA> XFC SHOW SUMMARY/STATS
---------------------------
...
I/O Statistics - Distributions (MAX_IO_SIZE: 127 )
--------------------------------------------------
Transfer Size Reads Hit Rate Writes ...
(blocks)
1 28196 97% 2384 ...
2 6962 91% 24 ...
3 403 76% 34 ...
...
Reads between 128 and 255 blocks since last reset: 27
Read hits between 128 and 255 blocks since last reset: 0
(0%)
Reads larger than 256 blocks since last
reset: 53
Read hits larger than 256 blocks since last reset: 0 (0%)
Writes between 128 and 255 blocks since last reset: 3
Writes larger than 256 blocks since last
reset: 0
...
SDA>
Interpreting the system output
- 28196 read IOs and 2384 write IOs were of size 1 block. The read
hit rate for 1 block IOs is 97%.
- 27 read IOs and 3 write IOs issued were of size in the range of
127-256 block. None of them was a read hit.
- 53 read IOs and no write IOs that were issued were of size greater than
255 blocks. None of them was a read hit.
Volume statistics
The "SHOW MEM/CACHE=VOL=<VOL-NAME>" DCL command or the
“SDA>XFC SHOW VOLUME/NAME=<VOL-NAME>” command provides the XFC statistics at the
volume level. Some of the important statistics are read hit rate, and the number of
read/write IOs.
DCL command
$ SHOW MEMORY/CACHE=VOLUME=<VOL-NAME>
<VOL-NAME>: Name of the volume
Sample output
$SHOW MEMORY/CACHE=VOLUME=BRAMHA$DKA100:
System Memory Resources on 30-MAY-2010
05:38:56.87
Extended File Cache Volume Statistics:
_BRAMHA$DKA100:
(DISK$BR_V84R), Caching mode is VIOC Compatible
Open files 398 Closed
files 314
Files ever opened 1519 Files ever
deposed 807
Allocated pages 9715 Locks
acquired 0
Total QIOs 85299 Read
hits 61370
Virtual reads 66304 Virtual
writes 18995
Read hit rate 92 % Read aheads 344
Read throughs 66132 Write throughs 18992
Read arounds 172 Write arounds
3
Ave Disk I/O Resp Time incl cache hits
(microseconds) 1126
Total of 1 volume in cache
$
Interpreting the output
On the volume BRAMHA$DKA100:
- The number of open files in cache is 398 and the number of closed
files in the cache is 314.
- This volume has consumed 9715 pages of the total XFC cache memory
- The read hit rate of the volume is 92%. This is a very good read
hit rate.
- Total IOs done on this volume is 85299. Out of this amount, 66304 IOs
are virtual reads and 18995 IOs are virtual writes.
SDA command
SDA> XFC SHOW VOLUME/NAME=<VOL-NAME>
<VOL-NAME> = DISK$<LBL>
<LBL> is the label of the volume.
Sample output
SDA> XFC SHOW VOLUME/NAME=DISK$BR_V84R
Full List of XFC Cached Volumes (CVBs)
--------------------------------------
Cache Volume Block (CVB)
------------------------
Statistics Valid From: 29-MAY-2010 00:25:40.06
...
Cached Open Files: 400
Cached Closed Files: 312
...
Name: DISK$BR_V84R
QIO count: 85447
Virtual Read Count: 66452
Virtual Write Count: 18995
Read Percentage: 77 %
Hit Rate: 71 %
...
I/O Response Times (This Volume)
Overall Average: 1.1242 milliseconds
Cache Hit: 0.0070 milliseconds
Disk: 3.9962
milliseconds
Accuracy: 99 %
...
SDA> Interpreting the output
On the DISK$BR_V84R volume:
- The number of open files in cache is 400 and the number of closed
files in the cache is 312.
- The hit rate of the volume is 71%.
Note: This is its hit rate and NOT
read hit rate, where
Hit rate = Read hits / (virtual reads + virtual writes)
- Total IOs done on this volume is 85447. Out of this amount, 66452 IOs
are virtual reads and 18995 IOs are virtual writes.
- XFC computes the IO response time for various IOs that are issued to
this volume. I.e., on any given volume, for each IOs, XFC keeps track of the
following:
- IOs that start and end on the same CPU and are cache hits
- IOs that start and end on the same CPU and are cache misses
File statistics
The "SHOW MEM/CACHE=FILE=<FILE-NAME>" DCL command or the
“SDA>XFC SHOW FILE/ID=<FILD-IN-HEX>” command provides the XFC statistics at the
file level. Some of the important statistics are read hit rate, number of read/write
IOs, and XFC cache memory consumed by the file.
DCL command
$SHOW MEMORY/CACHE=FILE=<FILE-NAME>
<FILE-NAME>: Full path of the file
Sample output
$SHOW
MEMORY/CACHE=FILE=BRAMHA$DKB200:[MURALI]PERFORM_TEST.COM
System Memory Resources on 30-MAY-2010
06:01:04.46
Extended File Cache File Statistics:
_BRAMHA$DKB200:[MURALI]PERFORM_TEST.COM;68 (389451, 1057,
0) (closed)
Caching is enabled, active caching mode is Write Through
Allocated pages 1 Total QIOs
1177
Read hits 1176 Virtual
reads 1176
Virtual writes 1 Hit
rate 100 %
Read aheads 0 Read throughs
1176
Write throughs 1 Read arounds
0
Write arounds 0
$
Interpreting the output
For the file PERFORM_TEST.COM (389451, 1057, 0),
- This file has consumed one page of the total XFC cache memory.
- The read hit rate of the file is 100%. This means that all attempts to
access the file were satisfied from the cache itself.
- Total IOs done on this file is 1177. Out of these, 1176
IOs are
virtual reads and 1 IO is virtual write.
SDA command
SDA> XFC SHOW FILE/ID=<FID-IN-HEX>/STATS
<FID-IN-HEX> = File number component of the file's FID in Hex
Sample output
SDA> XFC SHOW FILE/ID=2368/STATS
Full XFC Cache File Block (CFB) Details
--------------------------------------- -
File: DISK$TEST:[SYS0.SYSERR]ERRLOG.SYS;1
...
External FID: (9064,1,0)
...
File IO Statistics (current time 29-MAY-2010 09:19:13.85)
------------------------------------- --------------------
Statistics Valid From: 24-MAY-2010 03:13:24.80
Total QIOs to this file: 2297
Read IOs to this file: 1530
Read Hits: 1220
Hit Rate: 53.11 %
Write IOs to this file: 767
Truncates: 1
Accesses: 765
Deaccesses: 765
I/O Response Times (This File)
Overall Average: 1.9058 milliseconds
Cache Hit: 0.0266
milliseconds
Disk: 4.0346
milliseconds
Accuracy: 100 %
...
SDA>
Interpreting the output
For the file ERRLOG.SYS (9064, 1, 0):
- Total IOs done on this file is 2297. Out of these, 1530 IOs are
virtual reads and 767 IOs are virtual writes.
- The hit rate of the file is 53.11%.
(Note: This is the hit rate and NOT read hit
rate).
Hit Rate = read hits / (virtual reads + virtual writes)
- There has been 1 truncate, 765 access and 765 deaccess operations
on the file
- XFC computes the IO response time for various IOs that are issued
to this file.
I.e. On the file, for each IOs, XFC keeps track of:
- IOs that are cache hits which start and end on the same CPU
- IOs that are cache miss which start and end on the same CPU
IO statistics
XFC creates a context block for every IO that it handles.
The context block stores various information about the IO request such as IRP,
operation start time, current IO phase and so on. At any given point of time,
the context block indicates the current state of the IO.
IO statistics are generally used for debugging purpose.
While analyzing the crash dump, you may be interested to know the current state
of an IO request. In such cases, if the IO request has gone through XFC, then XFC would have created a context block for that IO request. The
context block can then be examined to know the current state of the IO
request.
If XFC is handling multiple IO requests, then it would have
created multiple context blocks, one for each IO request. In such cases, you
must examine the context block that corresponds to the IO request that you are
looking for. This is done by examining the list of all the context blocks and
then selecting a particular context block based on whether it's IRP field
corresponds to the IRP we are looking for.
SDA command
SDA> XFC SHOW CONTEXT
Sample output
SDA> XFC SHOW CONTEXT
List of All XFC Active Contexts (CTX) (current time
31-MAY-2010 03:04:47.33)
----------------------------------------------------------------------
Context (CTX) Address: FFFFFFFF89379910
I/O Phase: eiopDiskIO
I/O Type: eiotWriteThrough
Operation started: 31-MAY-2010 03:04:47.32
Stall Reason: estrDiskIO
...
Stall Op (IRP): FFFFFFFF8916DBC0
...
Cache Hit: False
...
Volume (CVB): 0000000000000000
Volume Id: FFFFFFFEE0189120
File Id: 000000000000398F
...
Cache File Block: FFFFFFFF7D715940
Process (PCB): FFFFFFFF896B0CC0
...
SDA>
Interpreting the output
For the context block FFFFFFFF89379910:
XFC received the IO request on "31-MAY-2010 03:04:47.32".
- The IO request is for a write operation.
- The file id of the file to which this IO is done is "398F"
- This IO request is not a cache hit and hence the data has to be
fetched from the disk
- Other structures associated with this IO are:
- IRP - FFFFFFFF8916DBC0 --> IO request packet
- PCB - FFFFFFFF896B0CC0 --> process control block
Summary
The techniques described here allow a user to get the XFC statistics at the
system/volume/file/IO level. These statistics should then be analyzed to
determine the hot files in the system at the volume level and also if the
overall system performance is acceptable or not.
One of the important parameters that impacts the system performance is the
read hit rate of the system /volume/file, which depends on a number of factors
such as:
- Number of local read/write IOs to the file
- Number of clusterwide read/write IOs to the file
Once we collect the XFC statistics, for example:
- Read hit rate of the system is 50%
This means the overall cache read hit rates on the system is 50%. This is
very low and hence there is a need to tune the system to increase the overall
cache read hit rates. This would involve analyzing the IOs issued on the system,
i.e. on different volumes by various applications.
- Read hit rate of the volume V1 is 50%
This means that the cache hit rate on the volume V1 is 50%. This is very low
and hence there is a need to tune the system with respect to the IO operations
on the volume to increase the read hit rate of the volume. This would involve
analyzing the IOs issued on the volume V1 by various applications.
|