We are interpreting the log files visually.<\/p>\n
In the preceding tutorials we have customized the Apache log format and performed a variety of statistical analyses. But we have yet to graphically display the numbers obtained. The visualization of data does in fact provide a big help in identifying problems. In particular, time series are very informative and even performance problems can be better quantified and narrowed down visually. But graphical display can also provide interesting information about false positives among the volumes of ModSecurity alarms.<\/p>\n
The benefit of visualization is readily apparent and is a good reason why graphs have always been an important component of dashboards and regular reports. However, in this tutorial we will not be aiming for perfectly laid out graphs that management would like. We instead want to get highly informative graphs showing the essential parts of data by the simplest of means possible.<\/p>\n
For this reason, we will be using a little-known feature of The appearance of entries in log files follows a chronological sequence. However, it is actually relatively difficult to follow this chronological sequence in the text file. Visualization of the log files is the answer. Dashboards have already been mentioned and a variety of commercial products and open source projects have become established in the past few years. These tools are very useful. But they are not always easily accessible or the log data must first be imported and sometimes even converted or indexed. There is thus a big gap in displaying graphs in the shell. The graphical tool Let\u2019s generate a simple graph in which the number of requests per hour is presented on a time line. As an example, to do this we are using the access log that we became familiar with while fine tuning ModSecurity false positives in one of the preceding tutorials: tutorial-8-example-access.log<\/a>.<\/p>\n Let\u2019s concentrate on the entries from May 20 to 29 and extract the timestamps from them:<\/p>\n Each of these lines represents a request. The number of requests per unit of time can thus be easily determined by counting them. Totaling by hour can be easily done by cutting the timestamp at the colon and adding them up via Here\u2019s the total per hour:<\/p>\n This seems to work, although there also seem to be gaps in the log file. We\u2019ll be taking care of them later on. In the first column we now see the requests per hour, with the second and third columns showing the time or hour. We now feed the result into the gnuplot<\/code>.<\/p>\nRequirements<\/h3>\n
\n
gnuplot<\/code> package; e.g.\u00a0as present in the Ubuntu<\/code> distribution.<\/li>\n<\/ul>\nStep 1: Graphically displaying time series in the shell<\/h3>\n
gnuplot<\/code> can in fact do this in ASCII and be controlled completely from the command line.<\/p>\ngnuplot<\/code> can be demanding to use and control and if you only use it occasionally you face the same learning curve again and again. For this reason, I have developed a wrapper script called arbigraph<\/code> that uses gnuplot to display simple graphs: arbigraph<\/a> We will be using this script in different situations in this tutorial and become familiar with a large number of command line options. So, let\u2019s start off with a simple case:<\/p>\n<\/a>$><\/span> grep<\/span> 2015-05-2 tutorial-8-example-access.log |<\/span> altimestamp<\/span> |<\/span> head<\/span><\/span>\n<\/a>2015-05-20<\/span> 12:53:11.139981<\/span>\n<\/a>2015-05-20<\/span> 12:53:12.232266<\/span>\n<\/a>2015-05-20<\/span> 12:54:57.772135<\/span>\n<\/a>2015-05-20<\/span> 12:54:58.842986<\/span>\n<\/a>2015-05-20<\/span> 12:54:59.009303<\/span>\n<\/a>2015-05-20<\/span> 12:54:59.003103<\/span>\n<\/a>2015-05-20<\/span> 12:54:59.006098<\/span>\n<\/a>2015-05-20<\/span> 12:54:58.992113<\/span>\n<\/a>2015-05-20<\/span> 12:54:58.994096<\/span>\n<\/a>2015-05-20<\/span> 12:55:00.270296<\/span><\/code><\/pre><\/div>\nuniq -c<\/code>. Just to be safe, we\u2019ll insert a sort<\/code> since the log files are not necessarily in chronological order (the entry follows the completion of the request, but the timestamp indicates the receipt of the request line in the request. This means that a \u201cslower\u201d request at 12:59 may appear in the log file after a \u201cfast\u201d request at 13:00. We can already see this problem at 12:54:58 and 12:54:59 above).<\/p>\n<\/a>$><\/span> grep<\/span> 2015-05-2 tutorial-8-example-access.log |<\/span> altimestamp<\/span> |<\/span> cut<\/span> -d: -f1 |<\/span> sort<\/span> |<\/span> uniq<\/span> -c |<\/span> head<\/span><\/span>\n<\/a> 37<\/span> 2015-05-20 12<\/span>\n<\/a> 6<\/span> 2015-05-20 13<\/span>\n<\/a> 1<\/span> 2015-05-20 14<\/span>\n<\/a> 105<\/span> 2015-05-20 15<\/span>\n<\/a> 38<\/span> 2015-05-20 16<\/span>\n<\/a> 25<\/span> 2015-05-20 17<\/span>\n<\/a> 19<\/span> 2015-05-20 18<\/span>\n<\/a> 32<\/span> 2015-05-20 19<\/span>\n<\/a> 19<\/span> 2015-05-20 22<\/span>\n<\/a> 1<\/span> 2015-05-21 06<\/span><\/code><\/pre><\/div>\narbigraph<\/code> script which only uses the first column for graphical display:<\/p>\n<\/a>$><\/span> grep<\/span> 2015-05-2 tutorial-8-example-access.log |<\/span> altimestamp<\/span> |<\/span> cut<\/span> -d: -f1 |<\/span> sort<\/span> |<\/span> uniq<\/span> -c |<\/span> arbigraph<\/span><\/span>\n<\/a><\/span>\n<\/a> 250<\/span> ++-----------------+-------------------+-------------------+-------------------+-------------------+-------------------++<\/span>\n<\/a> |<\/span> +<\/span> + + + + Col 1 ******+|<\/span><\/span>\n<\/a> |<\/span> **<\/span> |<\/span><\/span>\n<\/a> |<\/span> **<\/span> |<\/span><\/span>\n<\/a> |<\/span> **<\/span> |<\/span><\/span>\n<\/a> 200<\/span> ++ ** ** ++<\/span>\n<\/a> |<\/span> **<\/span> ** ** |<\/span><\/span>\n<\/a> |<\/span> **<\/span> ** ** |<\/span><\/span>\n<\/a> |<\/span> ***<\/span> ** ** ** ** |<\/span><\/span>\n<\/a> |<\/span> ***<\/span> ** ** ** ** |<\/span><\/span>\n<\/a> 150<\/span> ++ ** *** ** ** ***** ** ** ** ++<\/span>\n<\/a> |<\/span> **<\/span> ** *** ** ** ******* ***** ** |<\/span><\/span>\n<\/a> |<\/span> **<\/span> ** *** ** ** ** ******* ***** ** |<\/span><\/span>\n<\/a> |<\/span> **<\/span> ** *** *** ** ** ** ******* ***** ** |<\/span><\/span>\n<\/a> |<\/span> ***<\/span> ** *** *** *** ** ** ** ******* ***** ** |<\/span><\/span>\n<\/a> 100<\/span> ++ ** *** ** *** *** ***** ** ** ** ******* ***** *** ++<\/span>\n<\/a> |<\/span> **<\/span> *** ** *** ** **** ***** ** ** ** ******* ********* |<\/span><\/span>\n<\/a> |<\/span> **<\/span> **** *** *** ** ***** ***** ** ** ** ******* ********* |<\/span><\/span>\n<\/a> |<\/span> **<\/span> ***** *** *** *** ** ** ***** ******** ** ********** *********** |<\/span><\/span>\n<\/a> |<\/span> **<\/span> ***** *** *** *** ** **** ***** ******** *** ********** *********** |<\/span><\/span>\n<\/a> 50<\/span> ++ ** ********** ****** *** ******* ***** ************ ********** *********** ++<\/span>\n<\/a> **<\/span> *** ********** ****** *** ******* ** ***** ** ** ************ ********** *********** |<\/span><\/span>\n<\/a> **<\/span> *** ** ********** ********** ******* ** ** ***** *** ** ************** ************ ************ |<\/span><\/span>\n<\/a> **<\/span> ***************** ********** ********* **** ** ************* ** ************** **************************** |<\/span><\/span>\n<\/a> *********************<\/span> ************************** *** ******************************** ******************************<\/span>\n<\/a> 0<\/span> *************************************************************************************************************************<\/span>\n<\/a>