Hi, On Fri, 24 Jun 2016 at 01:38 Alan DeKok <aland@deployingradius.com> wrote:
On Jun 22, 2016, at 9:13 PM, Pshem Kowalczyk <pshem.k@gmail.com> wrote:
We've started using the linelog module to record various events that happen within the radius system. All of our linelog entries start with "%t" to denote the time of the event. During one of the troubleshooting sessions we've discovered that the entries don't necessarily end up in the order we expected them to.
The entries are written sequentially, so they are in time order.
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.
Finally we realised that the "%t" is the time the request
hits radius and not when the linelog entry is processed. In our case (we proxy all requests) that actually matters, since the home servers can take time to respond. I had a look through the dictionaries and run-time-variables but can't find 'current timestamp', is it actually available?
For various reasons.. no.
If your proxies take more than a second to respond, there's something seriously broken with them. That should be fixed rather than poking FreeRADIUS to have more up to date timestamps.
Why do you need wall-clock timestamps?
So I can pump these logs into a system that analyses them and tells me
about performance of various aspects of the system. Since the processing in our case involves database lookups, proxying, REST calls, more database lookups I want to know where the bottlenecks are. If I could call linelog at various stages of processing and then compare timestamps I could see exactly where things are slowing down (and when). I realise that having proxies that take more than 1 sec is no ideal, but some things are outside of our control, also having those timestamps would make it easier to prove that there is actually an issue with the proxy (or REST calls or databases). kind regards Pshem