1

I wrote a small script to determine the average IOPs per hour in which I later manually convert to a graph and spreadsheet for management to discuss a potential SAN upgrade for an upcoming expansion project. The system running is currently a physical machine running RHEL 6.

I have the script scheduled in root's crontab like below:

0 * * * * /bin/bash /IOPsLogs/IOPs.sh  >> /var/log/cronjobIOPs.log 2>&1

My script IOPs.sh looks like:

#!/bin/bash
date >> /var/log/cronjobIOPs.log
date +"%Y-%m-%d--%H:00" >> /IOPsLogs/Daily$(date +%Y-%m-%d).log
timeout -sHUP 60m iostat -x 1 | grep sda -B 1 >> /IOPsLogs/IOPs_$(date +%Y-%m-%d--%H:00).log
grep "sda" /IOPsLogs/IOPs_$(date +%Y-%m-%d--%H:00 -d "1 hour ago").log | awk '{sum+=$4} END { print "Average IOPs read'/'sec= ",sum/NR}' >> /IOPsLogs/Daily$(date +%Y-%m-%d).log
grep "sda" /IOPsLogs/IOPs_$(date +%Y-%m-%d--%H:00 -d "1 hour ago").log | awk '{sum+=$5} END { print "Average IOPs write'/'sec= ",sum/NR}' >> /IOPsLogs/Daily$(date +%Y-%m-%d).log

the log file "/var/log/cronjobIOPs.log" looks like: (Which is good since I don't see any errors.)

Mon Apr 27 00:00:01 MST 2015
Mon Apr 27 01:00:01 MST 2015
Mon Apr 27 02:00:01 MST 2015
Mon Apr 27 03:00:01 MST 2015
Mon Apr 27 04:00:01 MST 2015
Mon Apr 27 05:00:01 MST 2015
Mon Apr 27 06:00:01 MST 2015
Mon Apr 27 07:00:01 MST 2015
Mon Apr 27 08:00:01 MST 2015
Mon Apr 27 09:00:01 MST 2015
Mon Apr 27 10:00:01 MST 2015
Mon Apr 27 11:00:01 MST 2015
Mon Apr 27 12:00:01 MST 2015
Mon Apr 27 13:00:01 MST 2015
Mon Apr 27 14:00:01 MST 2015
Mon Apr 27 15:00:01 MST 2015
Mon Apr 27 16:00:01 MST 2015
Mon Apr 27 17:00:01 MST 2015
Mon Apr 27 18:00:01 MST 2015
Mon Apr 27 19:00:01 MST 2015
Mon Apr 27 20:00:01 MST 2015
Mon Apr 27 21:00:01 MST 2015
Mon Apr 27 22:00:01 MST 2015
Mon Apr 27 23:00:01 MST 2015
Tue Apr 28 00:00:01 MST 2015
Tue Apr 28 01:00:01 MST 2015
Tue Apr 28 02:00:01 MST 2015
Tue Apr 28 03:00:01 MST 2015
Tue Apr 28 04:00:01 MST 2015
Tue Apr 28 05:00:01 MST 2015
Tue Apr 28 06:00:01 MST 2015
Tue Apr 28 07:00:01 MST 2015
Tue Apr 28 08:00:01 MST 2015
Tue Apr 28 09:00:01 MST 2015

Now my problem is that the daily logs are inconsistent with it providing one read and write average per hour. Sometimes it provides more than two answers to a time stamp or two time stamps. Something seems to be off with the timing somehow? (Not a VM and not seeing any time slippage over the years.) If I run it manually every hour then it works just fine. Does anyone have any ideas or a different approach?

Average IOPs read/sec=  0.0442611
Average IOPs write/sec=  13.4663
2015-04-27--00:00
Average IOPs read/sec=  79.1727
Average IOPs write/sec=  22.7509
2015-04-27--01:00
2015-04-27--02:00
Average IOPs read/sec=  0.0370389
Average IOPs write/sec=  13.1389
Average IOPs read/sec=  36.6858
2015-04-27--03:00
Average IOPs write/sec=  250.514
Average IOPs read/sec=  32.6261
2015-04-27--04:00
Average IOPs write/sec=  391.811
Average IOPs read/sec=  1.64334
Average IOPs write/sec=  84.6204
2015-04-27--05:00
2015-04-27--06:00
Average IOPs read/sec=  0.0487056
Average IOPs write/sec=  12.8323
Average IOPs read/sec=  0.0617611
Average IOPs write/sec=  14.0306
2015-04-27--07:00
2015-04-27--08:00
Average IOPs read/sec=  0.11815
Average IOPs write/sec=  14.094
Average IOPs read/sec=  0.0817611
Average IOPs write/sec=  14.9651
2015-04-27--09:00
Average IOPs read/sec=  0.0434278
Average IOPs write/sec=  13.6037
2015-04-27--10:00
Average IOPs read/sec=  0.613706
Average IOPs write/sec=  14.9003
2015-04-27--11:00
Average IOPs read/sec=  0.0389833
Average IOPs write/sec=  13.9256
2015-04-27--12:00
2015-04-27--13:00
Average IOPs read/sec=  0.0642528
Average IOPs write/sec=  15.1321
Average IOPs read/sec=  0.144817
Average IOPs write/sec=  13.8244
2015-04-27--14:00
Average IOPs read/sec=  0.0384222
2015-04-27--15:00
Average IOPs write/sec=  13.0468
Average IOPs read/sec=  0.0312028
Average IOPs write/sec=  12.7255
2015-04-27--16:00
Average IOPs read/sec=  0.0781472
Average IOPs write/sec=  13.7179
2015-04-27--17:00
Average IOPs read/sec=  0.0798139
Average IOPs write/sec=  15.9144
2015-04-27--18:00
Average IOPs read/sec=  0.138147
Average IOPs write/sec=  13.7297
2015-04-27--19:00
Average IOPs read/sec=  0.0362028
Average IOPs write/sec=  13.2324
2015-04-27--20:00
Average IOPs read/sec=  0.254536
Average IOPs write/sec=  14.9013
2015-04-27--21:00
Average IOPs read/sec=  0.0314806
Average IOPs write/sec=  12.8527
2015-04-27--22:00
2015-04-27--23:00
Average IOPs read/sec=  21.6865
Average IOPs write/sec=  70.7389
4

It is an overlap between one execution of the script and the one made an hour later. Sometimes the new execution writes its first line before the first execution has written its last two lines.

The first two lines are from the last execution made on 2015-04-26. When they are written the date is the 2015-04-27 since the log file used is based on the time at the write time, not start of execution.

An option is to store date & time in variables and write all three lines at the same time in the correct date file.

  • 2
    I thought it was something along those lines, but I couldn't quite put my finger on it. I suppose another option is just to while-loop the whole thing and run it as a service. – Hyppy Apr 28 '15 at 18:57

Your Answer

By clicking "Post Your Answer", you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.