Recently my server was giving notifications of disk io activity
rising above a certain threshold at regular intervals. My first guess
was that some cronjob task was causing that. So I tried to check various
cron tasks to find out which task or process was causing the io burst.
On servers specially its always a good practice to monitor resource
usage to make sure that websites work fast and well.
However searching manually is not quite easy and this is where
utilities like iotop come in. iotop shows what or how much disk io are
all current processes doing. Its quite easy to use. Just run it from a
terminal and you should see some output like this
Total DISK READ: 0.00 B/s | Total DISK WRITE: 106.14 K/s
TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
335 be/3 root 0.00 B/s 98.56 K/s 0.00 % 2.03 % [jbd2/sda6-8]
4096 be/4 www-data 0.00 B/s 0.00 B/s 0.00 % 0.00 % apache2 -k start
1 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % init
2 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [kthreadd]
3 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [ksoftirqd/0]
4100 be/4 www-data 0.00 B/s 0.00 B/s 0.00 % 0.00 % apache2 -k start
5 be/0 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [kworker/0:0H]
4102 be/4 www-data 0.00 B/s 0.00 B/s 0.00 % 0.00 % apache2 -k start
7 be/0 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [kworker/u:0H]
8 rt/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [migration/0]
9 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [rcu_bh]
10 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [rcu_sched]
As we can see, each row shows a certain process and the amount of
data it is reading or writing to. This information is actually
instantaneous, so iotop keeps updating the values at certain interval
like 1 second. Running iotop like this just tells the current io usage.
What if we want to keep running iotop and record all io activity and
analyse it later. This is where cron comes in.
Automatic logging via cron
Cron will run iotop in the background and record io usage details to a file that can be analysed later.
Here is the basic iotop command that we want to run in the background via cron.
$ iotop -botqqqk --iter=60
17:38:13 335 be/3 root 0.00 K/s 7.64 K/s 0.00 % 2.30 % [jbd2/sda6-8]
17:38:13 3296 be/4 enlighte 0.00 K/s 15.28 K/s 0.00 % 0.00 % chrome
17:38:14 335 be/3 root 0.00 K/s 7.62 K/s 0.00 % 3.35 % [jbd2/sda6-8]
17:38:14 3293 be/4 enlighte 0.00 K/s 7.62 K/s 0.00 % 0.02 % chrome
17:38:15 3319 be/4 enlighte 0.00 K/s 19.09 K/s 0.00 % 0.00 % chrome
Note that iotop must be run with root privileges. So use sudo on ubuntu for example.
Now the most important option used in the above command is the "b"
option which is for batch/non-interactive mode. In batch mode iotop will
keep outputting line after line instead of showing a long list that
updates automatically. This is necessary when we want to log io activity
over a certain period of time.
The other option called "o" will show only those processes which
actually did some io activity. Otherwise iotop would show all processes.
The t option adds a timestamp which adds further information if you
want to track a specific high io process. The k option shows all figures
in kilobytes.
To log the output we simply need to redirect it to a file. The best
place is /var/log and the file could be named iotop. So here is the next
command
$ iotop -botqqqk --iter=60 >> /var/log/iotop
This will run iotop for 60 seconds where each iteration takes 1
second, and the output would be logged to the file /var/log/iotop. Now
the command has to be run every minute which cron would do easily.
Setup cron as root
Get into your linux server as root and create a file
/etc/cron.d/iotop
Add to this file our earlier iotop command that would log the iotop output.
* * * * * root /usr/sbin/iotop -botqqqk --iter=60 >> /var/log/iotop
Simple! Now cron would run the command every minute and every time
the command would run for a minute taking samples as 1 second interval
and all activity gets logged to /var/log/iotop.
Make sure to mention the full path to iotop otherwise cron might not
be able to run it at all. To find the location of iotop on your linux
server, use the which command
$ which iotop
/usr/sbin/iotop
Monitor only high io processes
I had to setup this io monitoring because my linux server was giving
high io alerts at around 3 AM in the morning when I could not get up to
check manually. And since the server alert was showing high disk io
activity I decided to monitor only those processes that did high disk
io.
Here is a simple command that greps the iotop output to grab process that have over 10 k/s of disk io anywhere.
$ sudo iotop -botqqqk --iter=60 | grep -P "\d\d\.\d\d K/s"
17:49:02 335 be/3 root 0.00 K/s 41.90 K/s 0.00 % 8.43 % [jbd2/sda6-8]
17:49:02 3307 be/4 enlighte 0.00 K/s 152.36 K/s 0.00 % 0.87 % chrome
17:49:10 3310 be/4 enlighte 0.00 K/s 22.80 K/s 0.00 % 0.10 % chrome
17:49:15 3319 be/4 enlighte 0.00 K/s 26.54 K/s 0.00 % 2.50 % chrome
17:49:16 3310 be/4 enlighte 0.00 K/s 19.02 K/s 0.00 % 0.00 % chrome
So it would not show those process that had less than 10 K/s of disk
io. It does so by filtering the output using grep and regular
expressions. This is very useful when we want to find any process that
is causing very high io activity.
High activity would mean around 1 M/s of disk activity for some time. So
grepping for values with 4 digits will find those processes right away.
To add the same command to cron replace the earlier command like this
* * * * * root /usr/sbin/iotop -botqqqk --iter=60 | grep -P "\d\d\.\d\d K/s" >> /var/log/iotop
I used it, and it works quite well. Here is how the output looks when filtered using grep to show only high io process entries.
13:19:01 1325 be/4 root 0.00 K/s 1897.74 K/s 0.00 % 5.65 % [kjournald]
13:24:22 2836 be/4 mysql 0.00 K/s 1071.07 K/s 0.00 % 0.18 % mysqld
13:32:01 1325 be/4 root 0.00 K/s 1469.17 K/s 0.00 % 7.13 % [kjournald]
13:46:18 10978 be/4 binary 1634.31 K/s 0.00 K/s 0.00 % 23.87 % php-fpm: pool binary
13:47:01 2955 be/4 mysql 0.00 K/s 8738.80 K/s 0.00 % 0.00 % mysqld
14:17:01 1325 be/4 root 0.00 K/s 1354.01 K/s 0.00 % 6.84 % [kjournald]
14:23:02 1325 be/4 root 0.00 K/s 1146.18 K/s 0.00 % 4.69 % [kjournald]
14:25:01 1325 be/4 root 0.00 K/s 1494.21 K/s 0.00 % 11.05 % [kjournald]
14:34:01 9938 be/4 mysql 0.00 K/s 2878.55 K/s 0.00 % 0.00 % mysqld
14:36:01 9424 be/4 mysql 0.00 K/s 2694.21 K/s 0.00 % 0.00 % mysqld
So try it out on your server.
http://www.binarytides.com/monitor-disk-io-iotop-cron/