[RADIATOR] Performance logging

[Heikki Vatiainen]

On 03/24/2016 01:18 PM, Hartmaier Alexander wrote:

> If you already calculate the response time can you please also expose it
> via a special placeholder character?

In the current patches there's the possibility to log RecvTime and
RecvTimeMicros which are the second and microsecond of the time when the
request was received. These are variables stamped in the current request
and with the patches you can do %{ReplyVar:RecvTime} to e.g., log them.

What you could do is to log these two variables and the current time and
let the log processing system do the math.

Currently the response time calculation happens just before the reply is
sent, so it's not available earlier, for example, for authentication
logging.

> I'd add this value to the AuthLog which goes via RabbitMQ to
> Elasticsearch and can then be graphed in Kibana.

Sounds much like what our development team has worked on lately. A lot
of work has been done with Radiator logging recently.

> We only struggle with Radiators' logging in one place: the global
> logfile contains log messages from e.g. Hooks which are hard to
> impossible to link to a specific request.
> I'm in the process of getting more Radiator logs into Elasticsearch and
> I'll look into if the Handler Identifier can be logged there as well.

As Alan mentioned, there's support in patches for linking/tracking
requests that are related to each other. When a request is received, a
tracing id is assigned to it. This id is then available for logging and
can be logged, for example, as a JSON attribute for log and
authentication log. See LogFormat.pm for an example.

It's also possible to use the Class attribute to bind authentication
with the subsequent accounting messages. For example, if the tracing id
is logged in the authentication log, you can use it later to view all
the log and accounting information related to that id. This will show
how the authentication and accounting was processed and what accounting
records were created for that particular session.

Binding with State is also supported. This allows tracing EAP
authentication sessions and other multi round authentications that use
State.

If you use the default log file format instead of e.g., JSON, you can
configure the tracing id to be appended in front of each line that is
logged into the log file. This allows using grep to quickly see all
lines that are related to a request.

This is still ongoing work, but the above should summarise what's been
done so far.

Any thoughts and ideas are welcome. I can certainly tell more about the
subject, but I tried to keep this message short instead of going into
full details immediately. The patches download page also has the list of
what's been added recently.

Thanks,
Heikki

-- 
Heikki Vatiainen <hvn at open.com.au>

Radiator: the most portable, flexible and configurable RADIUS server
anywhere. SQL, proxy, DBM, files, LDAP, NIS+, password, NT, Emerald,
Platypus, Freeside, TACACS+, PAM, external, Active Directory, EAP, TLS,
TTLS, PEAP, TNC, WiMAX, RSA, Vasco, Yubikey, MOTP, HOTP, TOTP,
DIAMETER etc. Full source on Unix, Windows, MacOSX, Solaris, VMS,
NetWare etc.