In this post, I will use the seeks.d and iopattern DTrace scripts, which are available as part of the DTraceToolKit (This toolkit is an extremely useful collection of scripts created by Brendan Gregg), to view the I/O access patterns typical of Oracle. DTrace is able to capture data throughout the kernel and so the job of finding access patterns has been greatly simplified.
The system on which these examples are being run has redo logs on one disk, datafiles on another disk and the control file is on another disk.
To get system-wide access patterns, the iopattern script can be used. Sample output is as follows:
# ./iopattern
%RAN %SEQ COUNT MIN MAX AVG KR KW
100 0 7 4096 8192 7606 4 48
0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0
100 0 6 8192 8192 8192 0 48
0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0
100 0 6 8192 8192 8192 0 48
0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0
100 0 6 8192 8192 8192 0 48
0 0 0 0 0 0 0 0
This output was generated on an idle system (0.04 load). You can see that the iopattern script provides the percentage of random and sequential I/O on the system. During this monitoring period while the system was idle, all the I/O was random. The iopattern script also provides the number and total size of the I/O operations performed during the sample period, and it provides the minimum, maximum, and average I/O sizes.
Now, look at the output generated from the iopattern script during a period of heavy database load:
# ./iopattern
%RAN %SEQ COUNT MIN MAX AVG KR KW
92 8 69 4096 8192 6589 304 140
86 14 69 4096 8192 5995 228 176
82 18 67 4096 8192 5257 64 280
84 16 19 4096 8192 6036 40 72
77 23 22 4096 8192 4282 0 92
88 12 68 4096 1015808 21744 1120 324
97 3 67 4096 8192 7274 400 76
89 11 66 4096 8192 6392 276 136
90 10 71 4096 8192 6345 216 224
87 13 62 4096 8192 5879 184 172
90 10 10 4096 8192 6553 40 24
100 0 17 8192 8192 8192 88 48
87 13 33 4096 1048576 38353 1168 68
86 14 65 4096 8192 6049 236 148
As you can see from the above output, the majority of the I/O which occurs during this period is random. In my mind, this one indication that the type of I/O typical in an OLTP environment is random (as we would expect).
To get the I/O distribution for each disk, the seeks.d script can be used. This script measures the seek distance for disk events and generates a distribution plot. This script is based on the seeksize.d script provided with the DTraceToolKit and is available in the Solaris Internals volumes.
Sample output from the seeks.d script is show below:
# ./seeks.d
Tracing... Hit Ctrl-C to end.
^C
cmdk0
value ------------- Distribution ------------- count
-1 | 0
0 |@@@@@@@@@@@@@@@@@@@@@ 43
1 | 0
2 | 0
4 | 0
8 | 0
16 | 0
32 | 0
64 | 0
128 |@@@@@@@@@@@@@ 26
256 |@@@@@@ 12
512 | 0
sd1
value ------------- Distribution ------------- count
32768 | 0
65536 |@@@@@@@@@@@@@@@@@@@@ 1
131072 | 0
262144 | 0
524288 | 0
1048576 |@@@@@@@@@@@@@@@@@@@@ 1
2097152 | 0
This output was generated when the system was idle as before. This output summarizes the seeks performed by each disk on the system. The sd1 disk in the output above is the disk on which my Oracle datafiles reside. The value column in the output indicates the size of the seek that was performed in bytes. This indicates some random I/O on this disk since the length of the seeks are quite large. The disk on which the redo logs are located does not show up in the output above since no I/O is being generated on that disk (sd2).
Now, it is interesting to look at the output generated from the seeks.d script during a period when the database is under a heavy load.
# ./seeks.d
Tracing... Hit Ctrl-C to end.
^C
cmdk0
value ------------- Distribution ------------- count
-1 | 0
0 |@@@@@@@@@@@@@@@@@@@@@@@ 18
1 | 0
2 | 0
4 | 0
8 | 0
16 | 0
32 | 0
64 | 0
128 |@@@@@@@@@@@@@ 10
256 |@@@@@ 4
512 | 0
sd2
value ------------- Distribution ------------- count
-1 | 0
0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 430
1 | 0
2 | 0
4 | 0
8 |@@@@@@@@ 120
16 |@ 11
32 | 3
64 | 0
128 | 0
256 | 0
512 | 0
1024 | 0
2048 | 0
4096 | 0
8192 | 0
16384 | 0
32768 | 0
65536 | 6
131072 | 0
sd1
value ------------- Distribution ------------- count
512 | 0
1024 |@@@ 31
2048 | 5
4096 | 0
8192 | 0
16384 | 0
32768 | 0
65536 |@@ 23
131072 |@@@@@@@@ 92
262144 |@@@@@@@ 73
524288 |@ 6
1048576 | 4
2097152 |@ 14
4194304 |@@@ 29
8388608 |@@@@ 40
16777216 |@@@@@ 56
33554432 |@@@@@@ 65
67108864 | 0
This time the disk on which the redo logs are located shows up as there is activity occurring on it. You can see that most of this activity is sequential as most of the events incurred a zero length seek. This makes sense as the log writer background process (LGWR) writes the redo log files in a sequential manner. However, you can see that I/O on the disk which contains the Oracle datafiles is random as seen by the distributed seek lengths (up to the 33554432 to 67108864 bucket).
The above post did not really contain any new information but I thought it would be cool to show a tiny bit of the possibility that DTrace has. This is one of the coolest tools I have used in the last year and is one of the many reasons why I have become a huge Solaris fan!
No comments:
Post a Comment