[ic] Logging slow pages

[Bill Carr]

On Jun 14, 2006, at 8:53 AM, Peter wrote:

> On 06/14/2006 04:51 AM, Mark Johnson wrote:
>> Use IC's [time] instead:
>> [calcn]
>> 	$Tag->tmpn('StartTime', $Tag->time({},'%s'));
>> 	return;
>> [/calcn]
>> Then you access it via $Scratch->{StartTime}:
>> [calcn]
>>      my $long_page_time = $Variable->{LONG_PAGE_TIME} || 5;
>>      my $page_time = $Tag->time({},'%s') - $Scratch->{StartTime};
>>      if ($page_time >= $long_page_time) {
>>           my $mv_page = $Tag->var('MV_PAGE',1);
>>           my $remote_addr = $Session->{shost} || $Session->{ohost};
>>           Debug(qq{Slow page: $Variable->{IC_CATALOG}/$mv_page, Time:
>> $page_time, remote_host: $remote_addr, CGI:} .
>>  ::uneval($CGI));
>>      }
>>      return;
>> [/calcn]
>
> You shouldn't need $Tag->tmpn.  Just set a global (initialise  
> without my), it will hold till the end of the page...
>
> [calcn]
> 	$start_time = $tag->time({},'%s');
> 	return;
> [/calcn]
>
> ...
>
> [calcn]
> 	my $long_page_time = $Variable->{LONG_PAGE_TIME} || 5;
> 	my $page_time = $tag->time({},'%s') - $start_time;
>
> 	...
>
> [/calcn]
Here is a little script for summarizing the results:
#!/usr/bin/perl
my @files = @ARGV;
die "Usage: dumpslowlog <log_file> [<log_file2>]...\n" unless @files;
my $pages;
for my $file (@files) {
   open FILE, "<$file" || die "Can't open log file $file: $!\n";
   while (<FILE>) {
     next unless s/^.*?Slow page: //;
     my ($page, $time, $host, $cgi) = split /,[^:]+: /;
     (my $catalog, $page) = split '/', $page, 2;
     $pages->{$page}->{time} += $time;
     $pages->{$page}->{count}++;
   }
   close FILE;
}
for my $page (sort { $pages->{$b}->{time} <=> $pages->{$a}->{time} }  
keys %$pages) {
   my $time =  $pages->{$page}->{time};
   my $count = $pages->{$page}->{count};
   print qq{$page: Total: $time, Count: $count, Average: } . int(100* 
$time/$count)/100 . qq{\n};
}
exit;

Add a space after 'CGI:' in the Debug line above.

I think this technique is giving me a good idea of where I should be  
focussing my optimization efforts much like working with MySQL's slow  
query log. Thanks for all the help.

Bill