Forum Discussion

Leslie_South_55's avatar
Leslie_South_55
Icon for Nimbostratus rankNimbostratus
Apr 03, 2008

Collecting website statistics

Greetings DevCentral,

 

 

So the challange was to be able to gather website statistics (client IP, pages hit, spiders, crawlers, search text, etc, etc, etc). There is seemingly useful tool called AWStats, available on sourceforge. Very nice interface.

 

 

AWStats builds it's stats page using web server logs recording all the METHODS and REPONSES. So now the challange; we have 8 web servers with log files wraping every hour, PLUS we have some iRules in front of this pool to either redirect or block certain request types, so the web servers don't see all the traffic.

 

 

Enter another iRule...and here is the code (partially built from several examples found here)

 


when HTTP_REQUEST { 
set curtime [clock seconds]
set formattedtime [clock format $curtime -format {%d/%b/%Y:%T %z}]
set referer [HTTP::header value Referer]
set useragent [HTTP::header value User-Agent]
set log_format "[IP::client_addr] - - \[$formattedtime\] \"[HTTP::method] [HTTP::uri] HTTP/[HTTP::version]\" \"$referer\" \"$useragent\""
}
when HTTP_RESPONSE {
log local1.info "$log_format [HTTP::status] [HTTP::payload length]"
}

 

 

notice that I am using local1 which I defined in my syslog-ng.conf to send to a remote_server, as not to log to local disk on the bigip.

 

 

Testing was great, when fine BUT when I put this in production...LOOK OUT..my 6400 went bonkers..alertd and syslog-ng daemons consumed 99.5% of the 2nd CPU and the UNIX remote syslog IO was equally utilized.

 

 

In 5 min, we accumilated a 17MB log file with over 53,000 lines (each line representing one HTTP_RESPONSE)needless to say I had to remove the rule.

 

 

The VS that we are trying to gather stats on maintains an average 1000 HTTP connections.

 

 

I am looking for any advice or words of wisdom that could help me complete my challange.

 

 

Thanks

 

-L

6 Replies

  • I'm not sure whether you're hitting a resource limit on the BIG-IP trying to log ~175 events/sec or if the rule could be streamlined to improve the situation.

    Do you need to calculate the time using clock? The log entries should already have a timestamp. I realize this would require more post-processing but I'm guessing you would already need to take out the default timestamp with the rule you're testing now.

    You could also remove the intermediate variables referer and useragent. and just use log_format to save the values for reference in HTTP_RESPONSE.

    Are you seeing [HTTP::payload length] return a value in HTTP_RESPONSE? I would think this would always be 0 unless you were collecting the response data and logging the value in HTTP_RESPONSE_DATA. If you want to get the response size, you could try logging HTTP::header value Content-Length. Of course, this won't be valid for chunked responses.

    
    when HTTP_REQUEST {
       set log_format "[IP::client_addr] - - - \"[HTTP::method] [HTTP::uri] \
          HTTP/[HTTP::version]\" \"[HTTP::header value Referer]\" \"[HTTP::header value User-Agent]\""
    }
    when HTTP_RESPONSE {
       log local1.info "$log_format [HTTP::status] [HTTP::header value Content-Length]"
    }

    [Edit: also, what version of BIG-IP are you running? I think there was an issue with the clock command in early 9.x versions]

    Aaron
  • I'm going to try your suggestions, and yes we will have to do additional post processing on the log file without the date/time stamp, I guess I could pull the LTM time stamp, as you mention, and just insert it in the correct place?

     

     

    I am getting a value for [HTTP::[payload length], here is a sample from my output - see line 5, the response was a 200 and the value for payload length is 107, all other requests were 304's

     

     

     

    Apr 2 15:59:06 tmm tmm[29667]: Rule rule_awstats_log : 1.1.1.1 - - [02/Apr/2008:15:59:06 -0500] "GET /i/v/t/10.gif HTTP/1.1" "http://www.somesite.com" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; .NET CLR 1.1.4322; .NET CLR 2.0.50727)" 304 0

     

    Apr 2 15:59:06 tmm tmm[29667]: Rule rule_awstats_log : 2.2.2.2 - - [02/Apr/2008:15:59:06 -0500] "GET /i/v/t/10.gif HTTP/1.1" "http://www.somesite.com" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322)" 304 0

     

    Apr 2 15:59:06 tmm tmm[29667]: Rule rule_awstats_log : 3.3.3.3 - - [02/Apr/2008:15:59:06 -0500] "GET /i/v/t/header.gif HTTP/1.1" "http://www.somesite.com" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; .NET CLR 1.1.4322; InfoPath.1)" 304 0

     

    Apr 2 15:59:06 tmm tmm[29667]: Rule rule_awstats_log : 4.4.4.4 - - [02/Apr/2008:15:59:06 -0500] "GET /common/v/Tags.js HTTP/1.1" "http://www.somesite.com" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; .NET CLR 2.0.50727)" 200 1298

     

    Apr 2 15:59:06 tmm tmm[29667]: Rule rule_awstats_log : 5.5.5.5 - - [02/Apr/2008:15:59:06 -0500] "GET /i/v/t/corner.gif HTTP/1.1" "http://www.somesite.com" "Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9b4) Gecko/2008031318 Firefox/3.0b4" 200 107

     

    Apr 2 15:59:06 tmm tmm[29667]: Rule rule_awstats_log : 6.6.6.6 - - [02/Apr/2008:15:59:06 -0500] "GET /h/n HTTP/1.1" "" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.0; SLCC1; .NET CLR 2.0.50727; .NET CLR 3.0.04506)" 404 1386

     

    Apr 2 15:59:06 tmm tmm[29667]: Rule rule_awstats_log : 7.7.7.7 - - [02/Apr/2008:15:59:06 -0500] "GET /i/v/t/header.gif HTTP/1.1" "http://www.somesite.com" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; .NET CLR 1.1.4322; InfoPath.1)" 304 0

     

     

     

     

    I'm going to have to play with the perl script to try to manipulate the time stamp a bit, I will update you with my progress...BTW if there is another way of doing what I am trying to do, please let me know.

     

     

    Thanks

     

    -L
  • OK..so I took your sugestions with one addition (see below) and I am currently monitoring in production (after I tested in stage)...we are about 1/2 as busy as we were the other day, averaging around 600 HTTP requests per sec. alertd is running at 20% and syslog-ng at 0.9 which gives me an average of just under 50% total CPU (not TMM) utilization.

     

     

    Do you think the CPU utilization gows liner with the connection count? so if my traffic is 50% of what we usually see, will the CPU increase by 50%?

     

     

    Here is the current rule, I had to add the [clock format] in the log statement as we could not chomp the LTM date/time stamp effeciently

     

     

     

    when HTTP_REQUEST {

     

    set log_format "[IP::client_addr] - - \"[HTTP::method] [HTTP::uri] \

     

    HTTP/[HTTP::version]\" \"[HTTP::header value Referer]\" \"[HTTP::header value User-Agent]\""

     

    }

     

    when HTTP_RESPONSE {

     

    log local1.info "\[[clock format [clock seconds] -format {%d/%b/%Y:%T %z} ]\] $log_format [HTTP::status] [HTTP::header value Content-Length]"

     

    }

     

     

     

     

    We are going to let this run for a few hours and then take it off for the weekend; it would be great if anyone could comment on my CPU to connections question.

     

     

    Thanks !

     

    -L
  • I think the CPU usage should increase linearly, but I'd be happy to have someone with more knowledge on this comment.

     

     

    Out of curiosity, how did the CPU usage look without the clock command? If there was a measurable improvement without the clock command, I'd suggest it might be better to leave it out. Even if it takes a fair amount of time/resources to parse the timestamp afterwards. The advantage is that you're not taking as many resources away from the load balancing.

     

     

    Aaron
  • I have not tested withou the clock command...that is something I will do next.

     

     

    Thanks again for the help.

     

     

    -L
  • Removing the clock command in the log statement

     

     

     

    \[[clock format [clock seconds] -format {%d/%b/%Y:%T %z} ]\

     

     

     

     

    shows no improvement in CPU utilization, a 1 to 2 % reduction at best. With around 1000 current HTTP requests to the VS, total CPU was around 75 to 80%.

     

     

    Anyone have any other ideas on how best to report on web site useage/stats?

     

     

    Thanks

     

    -L