On iostat, disk latency; iohist onward!
Just a little heads-up and a bit of MySQL-related technical content for all of you still out there following along…
At Proven Scaling, we take on MySQL performance problems pretty regularly, I’m often in need of good tools to characterize current performance and find any issues. In the database world, you’re really looking for a few things of interest related to I/O: throughput in bytes, requests, and latency. The typical tool to get this information on Linux is iostat. You would normally run it like iostat -dx 1 sda and its output would be something like this, repeating every 1 second:
Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sda 0.00 8.00 0.00 4.00 0.00 96.00 0.00 48.00 24.00 0.06 15.75 15.75 6.30
Most of the output of iostat is interesting and reasonable for its intended purpose, which is as a general purpose way to monitor I/O. The really interesting things for most database servers (especially those in trouble) are:
- avgrq-sz — Average request size, in kilobytes.
- avgqu-sz — Average I/O queue length, in requests.
- await — Average waiting time (in queue and scheduler) before servicing a request, in milliseconds.
- svctm — Average total service time for I/O requests, in milliseconds. This includes await, so should always be higher than await. This is the most interesting number for any write-heavy transactional database server, as it translates directly to transaction commit time.
- %util — Approximate percent utilization for the device.
There are one major problem with using iostat to monitor MySQL/InnoDB servers: svctm and await combine reads and writes. With a reasonably configured InnoDB, on a server with RAID with a battery-backed write cache (BBWC), reads and writes will have very different behaviour. In general, with a non-filled cache, writes should complete (to the BBWC) in just about zero milliseconds. Reads should take approximately the theoretical average time possible on the underlying disk subsystem.
I’ve often times found myself scratching my head looking at a non-sensical svctm due to reads and writes being combined together. One day I was perplexed enough to do something about it: I opened up the code for iostat to see how it worked. It turns out that the core of what it does is quite simple (so much so, I wonder why it’s C instead of Perl) — it opens /proc/diskstats, and /proc/stat and does some magic to the contents.
What I really wanted is a histogram of the reads and writes (separately, please!) for the given device. I hacked up a quick script to do that, and noticed how incredibly useful it is. I recently had to extend it to address other customer needs, so I worked on it a bit more and now it looks pretty good. Here’s an example from a test machine (so not that realistic for a MySQL server):
util: 1.27% r_ios: 0 w_ios: 1 aveq: 0, ms : r_svctm : w_svctm 0 : : 1 : : 2 : : 3 : x : 4 : x : 5 : xxx : 6 : xxxx : 7 : : 8 : x : x 9 : x : xx 10 : x : xxxxx 11 : : xxxxxxxxxxxxxxx 12 : : xxxxxxxxxxxxxxxxxxxxxxxxx 13 : xx : xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx 14 : : xxxxxxxxxxxxxxxxxxxxx 15 : xx : xxxxxxxxxxx 16 : x : xxxxx 17 : x : xxxxxx 18 : : xxxx 19 : x : xx 20 : : x 21 : : x 22 : : x 23 : : x 24 : : x 25 : : 26 : : 27 : : 28 : x : 29 : : 30 : : ++ : 0 : 250
It uses Curses now to avoid redrawing the entire screen, and I’ve got a ton of ideas on how to improve it. I have a few more must-haves before I release it formally to the world, but I wonder what more features people would want from it. It is Linux-only for the foreseeable future.
What do you think?
May 8th, 2007 at 23:19:04
Great stuff!
I would like to see the same info in old text format. It is easier to copy-paste.
May 8th, 2007 at 23:31:04
Agreed with vadim. Text format output should be supported as well. And this is great stuff, kudos!
May 9th, 2007 at 00:56:29
Hm…….. I think you’re on to something… yeah… iostat is simple.
This would sort of be a TOP for IO……… hm…… I think the concept should be extended a bit but I generally like the idea…… w00t.
May 9th, 2007 at 04:52:05
I think that would be great… I’ve been fighting with some I/O problems on an NFS server and I’d love that tool.
Other features would be a time series display (ie just like iostat is now, but with reads and writes separated and in graph form) and some form of logging. I’ve just started looking at I/O scheduler tuning and have been trying to figure out a way to measure how effective a given setting is.
thanks,
Sean
May 9th, 2007 at 08:02:04
Vadim, Colin:
By “text format” do you mean raw numbers instead of a graph?
Sounds easy enough.
May 9th, 2007 at 15:57:36
Raw numbers! You can combine them with nagios/rrd/munin…
May 9th, 2007 at 16:12:26
I got your IM this morning. Thank you for writing this.
More insight into IO = Less time scratching head
Since the iostat on Solaris 10 has some different options, I will run all the commands you mentioned on Solaris to see how the same info can be extracted from Solaris iostat.
BTW, the writing comes at an ideal time because I am working on some DTrace stuff to track IO. The concepts you mentioned are very helpful.
Thanks again,
Frank
PS: Man, I was seeing chatting w/ Pascal and got to see pics from the Proven Scaling’s annual trip. It made me realize how much I missed it
May 9th, 2007 at 16:13:43
s/seeing chatting/chatting/

May 11th, 2007 at 08:54:08
[...] Jeremy Cole shows how to get a visual take on MySQL and I/O statistics on Linux. (Something Pythian’s Alex Gorbachev looked at in an older article on basic IO Monitoring on Linux). [...]
May 14th, 2007 at 18:27:37
@Jeremy: yeah, raw numbers for sure. Should be an easy implementation, because its easier to manipulate numbers than it is to manipulate a graph
June 12th, 2007 at 22:07:15
Any update on when / if you will release this?
November 5th, 2007 at 04:57:41
So — any chance you would release this tool? Pretty please, with sugar on top?
August 10th, 2008 at 08:29:20
I can haz download?!
April 9th, 2009 at 05:37:12
The MAN says
From MAN
await The average time (in milliseconds) for I/O requests
issued to the device to be served. This includes the time
spent by the requests in queue and the time spent servic-
ing them.
svctm
The average service time (in milliseconds) for I/O
requests that were issued to the device.
You seem to have it backwards. Your svctm includes await. Is that the conclusion you drew from looking into iostat code or just a typo? My awaits are almost always higher than svctm
June 23rd, 2009 at 10:56:27
[...] popular tool amongst the database crowd, so not surprisingly you’ll find a lot of great discussions documenting the use. Depending on your application you will need to focus on different metrics, but as a gentle [...]