Thanks for the extensive infos! I've copied the calculation code to my LogFormatHook code:
$message->{response_time} = Radius::Util::timeInterval( \ $p->{RecvTime}, \ $p->{RecvTimeMicros}, Radius::Util::getTimeHires()); \ I'd still prefer if that float was available with a placeholder variable. Works like a charm: [cid:part1.05080303.09030203@t-systems.at] It shows what I was expecting, EAP authentication is slow. Any pointers where I can start optimizing the EAP auth performance? Thanks, Alex On 2016-03-26 09:31, Heikki Vatiainen wrote: 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 *"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"* T-Systems Austria GesmbH Rennweg 97-99, 1030 Wien Handelsgericht Wien, FN 79340b *"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"* Notice: This e-mail contains information that is confidential and may be privileged. If you are not the intended recipient, please notify the sender and then delete this e-mail immediately. *"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*
_______________________________________________ radiator mailing list radiator@open.com.au http://www.open.com.au/mailman/listinfo/radiator