Wednesday, October 10, 2007

How to plot how busy you server is from the user perspective

Do you run a mission critical application on an Apache web server?
if not stop reading - I'll post cute picks of kids or my MRI scan later.

click here if your a gheek and want to read more

How to plot how busy you server is from the user perspective.
The assumption I am making here is that the slower the server is the more user connections I will see because they spend more time connecting because the server is slower etc. etc.

In effect I'm going to plot the "requests being processed" against time.

So you've got mod_status installed and you have a cron job gziping and taring wgets of the server_status page

on a typical day head -n30 looks like this:

Apache Server Status for XXXXX.XXXXX.edu.au

Server Version: Apache/2.0.55 (Unix) DAV/2 mod_ssl/2.0.55 OpenSSL/0.9.6m mod_jk/1.2.6
Server Built: Jan 4 2006 17:25:42

Current Time: Wednesday, 10-Oct-2007 15:23:08 EST
Restart Time: Tuesday, 09-Oct-2007 17:24:28 EST
Parent Server Generation: 1
Server uptime: 21 hours 58 minutes 40 seconds
Total accesses: 1756415 - Total Traffic: 28.1 GB
CPU Usage: u1452.51 s1680.81 cu6053.03 cs0 - 11.6% CPU load
22.2 requests/sec - 372.4 kB/second - 16.8 kB/request
129 requests currently being processed, 41 idle workers

K_KCKKKWKWKKRWCKKKKKKKKKKKCK_KKRK_KKKKK_K._K.K.KKKKKWKCK.._KKKK_
.K_._._CKK__KK_K.KKK_KKWKKKK_KK..KK._.KK.K___KK.WK_KKCK_K_K_.KK_
.KKKKKK__WR_K.KK.K_KKWKKR.K._K__K..KKK_K_K_W.KK.K...............
....................................._..........................
....................._.................................K........
................................................................
..........................................K................_...K
......_.._..........................................K...........
................................................................
................K........K......................................
...........W....................................................
..............W.................................................
................................................................
.........._.................................................._..
.................................K..............................
........K...........................................K...........



And when you are being subjected to a DOS attack it looks more like this


Current Time: Monday, 08-Oct-2007 15:59:21 EST
Restart Time: Sunday, 09-Sep-2007 14:19:25 EST
Parent Server Generation: 29
Server uptime: 29 days 1 hour 39 minutes 56 seconds
Total accesses: 38331840 - Total Traffic: 326.1 GB
CPU Usage: u749.13 s842.35 cu2791.89 cs0 - .175% CPU load
15.3 requests/sec - 136.1 kB/second - 8.9 kB/request
1024 requests currently being processed, 0 idle workers

GRRRGRRRRRRRRRRGRRRRRRRRRRRRRRRRRKRRRRRRRRRRRRKRRKRRRRGRRRRRRRRR
RRRWGRGRRRRRRRRRRRRRRRRKRRRRRRRRRRRRGRKRRRRRRRRRRRGRRRRRRRRRWRRR
RRRGRRRRRGRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRGRGRKRRRCRRRKKRRRRRR
RRRRRRRRRRRRRRRRRRRRRRRRRRRRGRRRRRRRRRRRRRRRRRRKRRRRRRRRRRKRRRRR
RRRRRRRRRRRRRRRRRRRKKRRRRRRKRRRRKRRRRRRRRRRRRRRKRRRRRRRGRRRKRRRR
RRGRRRWRRGRRRRRRRRRKRGRRRRRRGGRRRRRRRRRRRRRRRRKRRRRRRRRRRKRRRRKR
RRKRRRRRRRRRRRRRRRRRRRRRRRRGRRRRRRRRRRRRRRRKRRRRKRRRRRRRRKRRRRRR
KRRRRRRRRRRKRRRRRRRRRRRRRRRRKRKRKRRRRRRRRRRRRRRRKKRRCRRRRRRRRKRW
RRKRCRKRRKRRRRRRRRRRRRRWRKKRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRR
RRRKRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRKRRRRRRRRRRRRRRRCRR
RRRKRRRKRRRRRRRRWRRRRRKRRRRRRRRRRRRRRRRRRRRRRWRRRRRRRRRRRRRRRRRR
KRRRRRRGRRRKKRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRKKRRRRRRRRRRRR
RRRRRRRRRRRRRRKRKRRRRKRRRRRRRRRRRRRRRRRRRRRRRRRRRRRWRKRRRRRRRRRR
KRRRRRKRRRKRRKRRRKRKRRRKRRRRRKRKRKRRRKRRRRRRRRRRRRRRRRRRRRRRRRRR
RRRRKKRRRRRRRRRRRRRRRRKRRRRKRRRRRRRRRRRRKKRRRRRRGRRRRRRRRRRRKRRK
KRKRRKRKRRRRRRRKRKRRRRKWKRRRRRRRKRRKRKRKRKRRRCRRRCKRCKRRRKRKRKKC



where all those R's are ..Reading..

Method

Write a script that loops through all your tar files untars and ungzips them then greps the head to get the date and the requests line. We gzip and tar the original pages into a directory - opt/servstat and then tar together whole days so mine looks like this but your mileage may vary:


#!/bin/bash

# Clear the screen in preparation for script output
clear
echo "--------------------------------------------------"

dir=`pwd`
startdir=$dir

if [ -d "tmp" ] ; then
rm -r tmp
fi

if [ -d "~/Desktop/out" ] ; then
rm -r ~/Desktop/out
fi
mkdir tmp
mkdir ~/Desktop/out

for file in $*; do
(
cd tmp

tar zxvf ../$file
(
cd opt/servstat
gunzip *.gz
sudo chown stephen\: *
mv *.txt ~/Desktop/out
head -n17 /home/stephen/Desktop/out/*.txt | grep -i Current >> ~/Desktop/outputFile
rm ~/Desktop/out/*.txt
)
)

done

cd $startdir

exit 0


end result being I get a file some 100K lines ling that looks like this;


<dt>Current Time: Wednesday, 10-Oct-2007 08:35:00 EST</dt>
<dt>69 requests currently being processed, 36 idle workers</dt>
<dt>Current Time: Wednesday, 10-Oct-2007 08:40:00 EST</dt>
<dt>103 requests currently being processed, 21 idle workers</dt>
<dt>Current Time: Wednesday, 10-Oct-2007 08:45:00 EST</dt>
<dt>78 requests currently being processed, 46 idle workers</dt>
<dt>Current Time: Wednesday, 10-Oct-2007 08:50:00 EST</dt>
<dt>80 requests currently being processed, 44 idle workers</dt>
<dt>Current Time: Wednesday, 10-Oct-2007 08:55:01 EST</dt>
<dt>111 requests currently being processed, 52 idle workers</dt>


you can get rid of the HTML if you want sed -e 's/<[^>]*>//g' outputFile > outputFileNoHTML

but chances are you want to keep it so that you can use it with sed to get the time, requests currently being processed, and idle workers all on the same line

if you want a csv to put into excel use this almighty "one liner"


cat outputFile | sed -e 's/<dt>Current Time: /\n/g' | sed -e :a -e '$!N;s/\n</ /;ta' -e 'P;D'| sed '/^$/d' | sed -e 's/ EST<\/dt> dt>/,/g' | sed -e 's/ requests currently being processed, /,/g' | sed -e 's/idle workers<\/dt>//g' > outputFile.csv


To Generate a tab seperated file use this:
cut -d ',' -f 2,3,4 aug.csv | sed 's/2007 /2007-/g' | sed 's/,/\t/g' > aug.tab
cut -d ',' -f 2,3,4 sep.csv | sed 's/2007 /2007-/g' | sed 's/,/\t/g' > sep.tab

or do the whole thing
cut -d ',' -f 2,3,4 outputFile.csv | sed 's/2007 /2007-/g' | sed 's/,/\t/g' > out.tab

now grep out the months if you want or deal with the whole file, i.e for September
grep Sep outputFile.csv > sep.csv
or
grep Sep outputFile.tab > out.csv

I'm using gnuplot to generate the plots. Here is the load file you want, in this case for all of August



# Gnuplot script file for plotting data from server_status
# This file is called aug.plot
unset log # remove any previous log-scaling
unset key # remove any previous key
unset label # remove any previous labels
unset title # remove any previous title
set xtic auto # set xtics automatically
set ytic auto # set ytics automatically
set yrange [0:1028] # Change the y-axis range
set xtics rotate # rotate the x-axis lables so they are verticle
set terminal jpeg size 1280, 780 # make a pretty picture for the output
set output 'aug.jpg' # name of the output file
set xdata time # set x axis to be time scale
set timefmt "%d-%b-%Y-%H:%M:%S" # set the input format of the time
set format x "%d/%m" # set the output format of the time label
set grid # show a grid in the picture
set title "Number of user connections" # the title of the output plot
set xlabel "Date/Time" # label the x axis
plot "aug.tab" using 1:2 # generate the plot using column 1 for x and 2 for y


if you want to plot a single day you want different x-axis labeling, use:
set format x "%d/%m %H:%M"

from within gnuplot to generate the plot from this plot file enter: load 'aug.plot'

You should now get a pretty picture.

Mine look like this:
For the year since the end of July


For Oct to date

For the 8th of Oct

And the 9th - can you spot the DOS attack ?

And this morning




--
edit
I'll be truly surprised if anybody reads this.

5 comments:

Arron's Kiwi Girl said...

I read it.
Even felt compelled to commment.

But, that's only cause you said you'd be surprised if anyone read it....

hehe

I'm just saying...
That will be all. For now.

Josh said...

You freaking uber geek!

I read it. I did not understand it. I was really hoping for some ASCII Pr0n in all those logs but was disappointed...

unique_stephen said...

But how good is that oneliner ..

Anonymous said...

Nice work Steve,
So you've drawn a pretty picture of the DOS attack after it occured. How do you stop the attack from bringing your server down or prevent it from happening in the first place?

Andrew.

unique_stephen said...

This was a traffic analysis exercise because our firewall failed to automatically detect the traffic. It was not like a normal DOS in that the traffic looked legitimate. It turns out that it was a service provider caching huge chunks of our site from tens of different IP addresses.