Monitor disk io on linux server with iotop and cron

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/

Posted by N R

Tweet