Consider an Apache access log file like below,
192.168.250.40 - - [11/Oct/2013:11:59:59 +0700] "POST /process.php HTTP/1.0" 200 - 192.168.250.10 - - [11/Oct/2013:12:00:00 +0700] "POST /process.php HTTP/1.0" 200 - 192.168.250.10 - - [11/Oct/2013:12:00:00 +0700] "POST /process.php HTTP/1.0" 200 - 192.168.250.10 - - [11/Oct/2013:12:00:00 +0700] "POST /process.php HTTP/1.0" 200 - 192.168.250.10 - - [11/Oct/2013:11:59:59 +0700] "POST /process.php HTTP/1.0" 200 - 192.168.250.10 - - [11/Oct/2013:12:00:00 +0700] "POST /process.php HTTP/1.0" 200 - 192.168.250.10 - - [11/Oct/2013:11:59:59 +0700] "POST /process.php HTTP/1.0" 200 - 192.168.250.40 - - [11/Oct/2013:12:00:00 +0700] "POST /process.php HTTP/1.0" 200 - 192.168.250.40 - - [11/Oct/2013:12:00:00 +0700] "POST /process.php HTTP/1.0" 200 - 192.168.250.10 - - [11/Oct/2013:11:59:59 +0700] "POST /process.php HTTP/1.0" 200 - 192.168.250.10 - - [11/Oct/2013:12:00:00 +0700] "POST /process.php HTTP/1.0" 200 - 192.168.250.40 - - [11/Oct/2013:11:59:59 +0700] "POST /process.php HTTP/1.0" 200 -
If we separate one line by the space fourth portion has the time component. We can easily do it by “cut” command.
cut -d" " -f4 access.log | head
Here -d” “ cut the line by space, -f4 print the fourth portion and finally “head” will show only fist 10 lines
[11/Oct/2013:12:00:00 [11/Oct/2013:11:59:59 [11/Oct/2013:11:59:59 [11/Oct/2013:11:59:59 [11/Oct/2013:11:59:59 [11/Oct/2013:11:59:59 [11/Oct/2013:11:59:59 [11/Oct/2013:11:59:59 [11/Oct/2013:11:59:59 [11/Oct/2013:12:00:00
In this result, the time value is in between 14th character and 21st character (-c14-21). So we’ll pipe this result through another “cut“.
cut -d" " -f4 access.log | cut -c14-21 | head
It will give,
12:00:00 11:59:59 11:59:59 11:59:59 11:59:59 11:59:59 11:59:59 11:59:59 11:59:59 12:00:00
Now we have to count this result by grouping the lines. “uniq -c” will do it. But remember to “sort” before counting.
cut -d" " -f4 access.log | cut -c14-21 | sort | uniq -c | head
Now we’ll get a result something like,
42 11:59:59 1161 12:00:00 977 12:00:01 884 12:00:02 976 12:00:03 1065 12:00:04 1017 12:00:05 936 12:00:06 926 12:00:07 981 12:00:08
This means that there were 1161 requests at 12:00:00, 977 at 12:00:01, 884 at 12:00:02 …etc. Now we want to find the maximum value of the first column. So we’ll “sort” the first column (-k 1) again numerically (-n) in revers (-r) order.
cut -d" " -f4 access.log | cut -c14-21 | sort | uniq -c | sort -k 1 -n -r | head
Now we see the final results.
1253 12:17:12 1222 12:17:14 1201 12:32:23 1174 12:13:00 1169 12:00:38 1167 12:56:23 1161 12:00:00 1159 12:14:22 1158 12:14:52 1156 12:18:37
The maximum requests per second is 1222 and it has happened at 12:17:14.
There may also be some other methods to find this. But, anyway you learned three commands from this post which are very useful for simply analyzing log files.