Collecting website statistics

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