(RADIATOR) average response time

[onrubia carlos]

Hello,

I am busy doing some tests with different setup's and I am interested in
measuring the
time radiator take to treat one authentication request or one accounting
request.
To do this I do a log in microseconds and I make the difference between the
time when the packets enter the radiator soft
and the time radiator finishs the treatment.

I have seen that radiator also has statistics with one argument being the
average response time.
Can somebody explain how this value is calculated?
I have made some tests and the value do not correspond with the value I
calculate with the method given here above.


Some part of my config (authentication)
----------------------

<StatsLog FILE>
        Interval 60
        Filename %L/stats.auth
        Header
        Format %0:%1:%2:%6:%3:%5:%23:%22
</StatsLog>


<Handler SkyHandler = skynet>
PreProcessingHook sub { my $bittype = "4"; ${$_[0]}->add_attr('BGCBitType',
$bittype); }
RewriteFunction sub { my($a) = shift; $a =~ tr/A-Z/a-z/; $a =~ s/[\000]//g;
$a =~ s/^([^@]+).*/$1/; $a =~ s/[^A-Za-z0-9\.\-_\@]//g; $a; }
AuthBy BGC_bit_Auth
AuthLog BGC_Log
PostAuthHook    file:"/usr/local/radiator/hooks/new.mkReplyAttributes"
#       Log BGC_broadband
SessionDatabase SkynetOnline
StripFromReply Framed-Routing
</Handler>



I have made a restart of the authentication process and then I made requests
during some minutes and I have the
following result in the file "stats.auth":

radius501:/var/log/radiator# tail -f stats.auth | grep skynet:

1180624929:Handler:SkyHandler = skynet:584:584:0:0.00234573791941321:584
1180624989:Handler:SkyHandler = skynet:886:886:0:0.0330370099558509:886
1180625049:Handler:SkyHandler = skynet:1216:1216:0:0.00119843628979964:1216
                                                        ==> average response
time (all requests have been accepted)


When I measure in the logfile, all the requests take about 20ms to be
treated (trace here below)
                ==> the values in the statistics seems not to have any
sense.


Can somebody gives the reason?
Are the average response time in the statistics valid?


Thanks in advance for your answers.



Thu May 31 17:30:02 2007 849384: DEBUG: Packet dump:
*** Received from 81.247.251.5 port 35087 ....
Code:       Access-Request
Identifier: 137
Authentic:  1234567890123456
Attributes:
        User-Name = xxxxx
        Service-Type = Framed-User
        NAS-IP-Address = 1.2.3.4
        NAS-Port = 1234
        Called-Station-Id = "123456789"
        Calling-Station-Id = "987654321"
        NAS-Port-Type = Async
        User-Password = "<8><149><178><136><166>gD<27>9:-X<214>y|<245>"
        Calling-Station-Id = "27061311"

Thu May 31 17:30:02 2007 851009: DEBUG: Handling request with Handler
'SkyHandler = skynet'
Thu May 31 17:30:02 2007 851453: DEBUG: Rewrote user name to fa051981
Thu May 31 17:30:02 2007 851835: DEBUG: SkynetOnline Deleting session for
xxxx 1.2.3.4, 1234
Thu May 31 17:30:02 2007 852308: DEBUG: do query is: 'DELETE FROM
onlineusers ....
Thu May 31 17:30:02 2007 856125: DEBUG: Handling with Radius::AuthSQL
Thu May 31 17:30:02 2007 856495: DEBUG: Handling with Radius::AuthSQL:
BGC_bit_Auth
Thu May 31 17:30:02 2007 857155: DEBUG: Query is: 'SELECT HIGH_PRIORITY CASE
....
Thu May 31 17:30:02 2007 858628: DEBUG: Radius::AuthSQL looks for match with
xxxxxx
Thu May 31 17:30:02 2007 859326: DEBUG: Query is: 'SELECT nas_id, 0 AS
nas_port, session_id FROM onlineusers WHERE login = 'xxxx'':
Thu May 31 17:30:02 2007 866351: DEBUG: Radius::AuthSQL ACCEPT:
Thu May 31 17:30:02 2007 867028: DEBUG: BGC: Database is up, retrieving
reply attributes for type 4
Thu May 31 17:30:02 2007 868602: DEBUG: BGC: === Session-Timeout
session_timeout
Thu May 31 17:30:02 2007 868927: DEBUG: BGC: === Ascend-Minimum-Channels
isdn_min_channels
Thu May 31 17:30:02 2007 869153: DEBUG: BGC: === RB-Rate-Limit-Rate
rate_limit
Thu May 31 17:30:02 2007 869330: DEBUG: BGC: === Framed-Route fixed_route
Thu May 31 17:30:02 2007 869496: DEBUG: BGC: === Ascend-Base-Channel-Count
isdn_base_channels
Thu May 31 17:30:02 2007 869672: DEBUG: BGC: === cisco-avpair
cisco_address_pool
Thu May 31 17:30:02 2007 869837: DEBUG: BGC: === Framed-IP-Address fixed_ip
Thu May 31 17:30:02 2007 870003: DEBUG: BGC: === Ascend-Maximum-Channels
isdn_max_channels
Thu May 31 17:30:02 2007 870178: DEBUG: BGC: === RB-Rate-Limit-Burst
rate_burst
Thu May 31 17:30:02 2007 870466: DEBUG: Access accepted for xxxxx
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.open.com.au/pipermail/radiator/attachments/20070531/733bafee/attachment.html>