How To Tell If The IO Subsystem Reads Are Struggling
How many times have you heard or felt, "It's an IO problem!" How can you tell? What does this even mean? Who's fault is it? It is a broad and complicated topic.
But before we can approach the IO team, we must know if the IO subsystem is struggling.
For this article I am focusing on how to tell if the IO reads are fast enough. To add a little spice and reality into the mix, I am only going to use the Oracle performance v$ views.
So, here we go!
How To Tell If IO Reads Are Fast Enough
As DBAs, we have a powerful way to understand how long it takes for a single operating system IO read request to complete. The secret lives within the common Oracle wait event, db file sequential read.
The db file sequential read wait is unique in its simplicity. And, it is this simplicity which enables us to know, with confidence, if the IO reads are fast enough.
How Oracle Gets IO Read Times
Here is how it works. Because Oracle instruments its non-CPU consuming source code, before a wait event occurs, Oracle asks the OS, "What time is it?" and stores the result. When the wait is over, Oracle again asks the OS, "What time is it?" At this point, Oracle knows both the begin and end time plus what the wait was all about, so Oracle gives it a name.
The db file sequential read is a simple single block synchronous read IO call. On Linux the system call is usually, pread. We can use this simplicity to determine if the IO subsystem is struggling with IO reads.
Here is a great reference about the difference between read and pread.
Using the Linux strace command, we can see how this is done. Below is a snippet from an Oracle Database 12c foreground process when it is screaming, "db file sequential read!"
$ strace –rp 2518
...
0.000324 clock_gettime(CLOCK_MONOTONIC, {504, 52586559}) = 0
0.000040 clock_gettime(CLOCK_MONOTONIC, {504, 52625324}) = 0
0.000040 pread(257, "\6\242\0\f\0"..., 8192, 427270144) = 8192
0.000047 clock_gettime(CLOCK_MONOTONIC, {504, 52712996}) = 0
0.000044 clock_gettime(CLOCK_MONOTONIC, {504, 52757393}) = 0
0.000329 clock_gettime(CLOCK_MONOTONIC, {504, 53086771}) = 0
0.000040 clock_gettime(CLOCK_MONOTONIC, {504, 53125505}) = 0
0.000040 pread(257, "\6\76 [y\f\0"..., 8192, 427278336) = 8192
0.000047 clock_gettime(CLOCK_MONOTONIC, {504, 53213583}) = 0
0.000040 clock_gettime(CLOCK_MONOTONIC, {504, 53253021}) = 0
0.000327 clock_gettime(CLOCK_MONOTONIC, {504, 53580561}) = 0
0.000040 clock_gettime(CLOCK_MONOTONIC, {504, 53619199}) = 0
0.000040 pread(257, "\6\273\f\0"..., 8192, 427286528) = 8192
0.000047 clock_gettime(CLOCK_MONOTONIC, {504, 53706779}) = 0
0.000040 clock_gettime(CLOCK_MONOTONIC, {504, 53752611}) = 0
...
Let's focus on the above output for a bit. Knowing the Oracle database block size is 8KB, we can tell the Oracle foreground process is making single Oracle database block reads using the Linux pread call.
Do you see the system call, which is also a C function, clock_gettime? This is the Oracle foreground process asking, "What time is it?". As DBAs through Oracle's wait event views, we see the ending time minus the beginning time as the wait time for these db file sequential read(s).
Pure and simple, for the Oracle foreground process, this is the response time for a single block synchronous read call. If you want to know how long single block synchronous read calls are taking, simply look at your db file sequential read times.
Actually Watching An Oracle Process Figuring Out the Wait Time
It's true. You can learn a lot from sitting on your butt. If you want to see with your own eyes an Oracle server process determine wait time for a multiple block synchronous read (event name is, db file scattered read), watch the below video.
WARNING: I need to mention that, for multiple block reads, Oracle will want to do asynchronous multi-block read calls instead of synchronous multi-block read calls. So, please do NOT use db file scattered read wait times to determine IO read response times. Currently, the only way I know of to reliably and easily get IO read response times from within Oracle is to use the sequential read wait times.
How Long Is Too Long?
This really is the question, isn't it? My rule of thumb is 10ms. That is, if the average db file sequential read time is greater than 10ms then the IO subsystem is struggling.
There is more to this story. My 10ms rule is truly a "rule of thumb." There are other factors, such as, "Is 10ms too long for a hugely expensive IO subsystem?" Probably.
Here's an idea. Right now, email your IO vendor or IO system administrator. Ask them what is an acceptable average single block read time. Don't hang up until you get an answer ;)
Are there other factors? For sure. The average wait time is, well... the average. Are their longer wait times? For sure. How many and how long? We can get this information and we can use it to tell if the IO subsystem is truly struggling.
Want to know how to determine the answers to these questions? That's the topic for my next article.
All the best in your Oracle performance tuning work!
Craig.
Start my FREE 18 lesson Machine Learning For Oracle Professionals E-Course here.
Craig Shallahamer is a long time Oracle DBA who specializes in predictive analytics, machine learning and Oracle performance tuning. Craig is a performance researcher and blogger, consultant, author of two books, an enthusiastic conference speaker a passionate teacher and an Oracle ACE Director. More about Craig Shallahamer...
If you have any questions or comments, feel free to email me directly at craig at orapub.com.
 |
 |
 |
|||
| How To Identify Oracle Sorting Issues | A Real Story In A Real Life: Everything Started With A Simple Post | The Thrill Of Solving The Puzzle | |||
