Linelog - timestamps

[A.L.M.Buxey at lboro.ac.uk]

Hi,

> That's correct, but we end up with something like this
> 
> Fri Jun 24 05:17:11 2016 Username [ABC] BNG: 03 Accept
> Fri Jun 24 05:17:12 2016 Username [DEF] BNG: 02 Accept
> Fri Jun 24 05:17:10 2016 Username [GHI] BNG: 03 Accept
> 
> So in this case packet for GHI was actually received first but responded to
> last.

you know...you can linelog elsewhere - so have a 'receive' linelog...
then have a auth linelog.... if you linelog with eg syslog then syslog will
timestamp the event at the current system time when it got logged - you 
can then look at that versus the packet receive time to see where the
delay lag is - in your case you could then log the 'auth' time (syslog)
versus the receive time (linelog entry you already have)

but...you talk about databases....then just put the auth stuff into
a DB(!) - you can have one column being insert time (NOW() or whatever your
DB uses) versus receive time of the datagram by RADIUS server.... then you can
do lots of basic analysis on culmns where insert_time - receive_time  > X seconds

if you have questions about your servers surrounding the system
then run freeradius in fuller debug mode - eg radiusd -xxx  and such - this
gives you the time of each packet - you can then see how long each thing -
LDAP, SQL, logging, perl , exec etc etc took before the packet continued.
you can then profile it (theres no simple profiling tool to work with such
logs that I know of....but would be very handy!! ;-) )

ilan