Format of FreeRADIUS log to enable interoperation with Raptor
Contents
Scope
Prelimiary work with FreeRADIUS
FTICKS
Contributors: Adam Bishop, Alan Buxey, Rhys Smith
Scope
As decided at the DOT1XSIG meeting of 24th October 2012, the deliverable is:
- an agreement on WHAT gets logged in FR
- assurance that same format can be achieved on other platforms
An agreed basic logging string for eg FreeRADIUS and Radiator (syslog or flatfile) agreed for members would have two advantages - the initial one being to aid the required plugins for such platforms with the Raptor tool, the other one is that with standard format, having some web-front-end with dB backend tool for trouble-shooting WOULD be more possible
Raptor - http://iam.cf.ac.uk/trac/RAPTOR
(Note, Raptor, much like DaloeRADIUS, dialup-admin (from FreeRADIUS project), Ciscos NCS web interface etc are designed for looking at working users... whereas it is believed an issue ishow to look for reporting ways for the PROBLEM users who fail. a standard logging format for THOSE would be just as beneficial)
Preliminary FR work
by Adam BishopSystems
I've had a play with FreeRADIUS, and producing a useful log entry is difficult, but I've come up with something that only requires a small amount of tweaking.
This assumes that the RADIUS server behaves like the one suggested in the Sussex study - it requires the presence of stripped-user-domain to work (as realm tends to get overwritten when the packet is to be proxied).
It also requires that Operator-Name is injected into every Access-Request - even local ones.
With those changes, I'm able to generate the following:
Oct 26 14:19:37 radtest radiusd: SP DENIED steve@camford.ac.uk:02-00-00-00-00-01 from camford.ac.uk use of EDUROAM: Reply-Message: Misconfigured client: Only EAP requests are accepted from 127.0.0.1.
Oct 26 14:19:38 radtest radiusd: SP DENIED steve@camford.ac.uk:02-00-00-00-00-01 from camford.ac.uk use of EDUROAM: Reply-Message: Misconfigured client: Only EAP requests are accepted from 127.0.0.1.
Oct 26 14:19:39 radtest radiusd: IDP ACCEPTED steve@camford.ac.uk:02-00-00-00-00-01 from 1camford.ac.uk use of EDUROAM:
Oct 26 14:19:39 radtest radiusd: SP PERMITTED @camford.ac.uk:02-00-00-00-00-01 from camford.ac.uk use of EDUROAM:
Oct 26 14:19:39 radtest radiusd: IDP ACCEPTED steve@camford.ac.uk:02-00-00-00-00-01 from 1camford.ac.uk use of EDUROAM:
Oct 26 14:19:39 radtest radiusd: SP PERMITTED @camford.ac.uk:02-00-00-00-00-01 from camford.ac.uk use of EDUROAM:
Oct 26 14:19:39 radtest radiusd: IDP ACCEPTED steve@camford.ac.uk:02-00-00-00-00-01 from 1camford.ac.uk use of EDUROAM:
Oct 26 14:19:39 radtest radiusd: SP PERMITTED @camford.ac.uk:02-00-00-00-00-01 from camford.ac.uk use of EDUROAM:
Oct 26 14:19:39 radtest radiusd: IDP ACCEPTED steve@camford.ac.uk:02-00-00-00-00-01 from 1camford.ac.uk use of EDUROAM:
Oct 26 14:19:39 radtest radiusd: SP PERMITTED @camford.ac.uk:02-00-00-00-00-01 from camford.ac.uk use of EDUROAM:
Oct 26 14:19:42 radtest radiusd: SP PERMITTED @ja.net:02-00-00-00-00-01 from ja.net use of EDUROAM:
Oct 26 14:19:43 radtest radiusd: IDP ACCEPTED steve@camford.ac.uk:02-00-00-00-00-01 from 1ja.net use of EDUROAM:
The format is:
<syslog boilerplate> SP <PERMITTED/DENIED> <username>:CSID from <realm> use of <service name>: <Payload> <syslog boilerplate> IDP <ACCEPTED/REJECTED> <username> from <Operator-Name> use of <service name>: <Payload>
It'd be better if the Operator-Name attribute could be included in Access-Reject/Accept packets. This would harmonise the log output between IDP and SP entries, but this requires policy changes (and we're still fighting to get people to include Operator-Name anyway, so I've used stripped-user-domain for the SP component).
At the moment the service name in the log entry is static - I think it may be worth defining a VSA injected by the visited site into Access-Requests to indicate the service a user is authenticating to, and consider the absence of the attribute to mean eduroam:
VENDOR UKERNA 25622
BEGIN-VENDOR UKERNA
ATTRIBUTE SERVICE-CLASS 150 integer
VALUE SERVICE-CLASS 0 EDUROAM
VALUE SERVICE-CLASS 1000 FILTERED-EDUROAM
VALUE SERVICE-CLASS 2000 3G
VALUE SERVICE-CLASS 3000 4G
There is a similar VSA used by Moonshot, but it has a strict meaning.
This would allow site administrators to track what services users are using, in a similar way to Shib + Raptor.
LineLog config follows.
linelog idp {
filename = syslog
format = "Something has gone wrong with the IDP log"
reference = "idp.%{%{reply:Packet-Type}:-format}"
idp {
Access-Accept = "IDP ACCEPTED %{User-Name}:%{%{request:Calling-Station-Id}:-UnknownCSID} from %{%{request:Operator-Name}:-Unknown} use of EDUROAM: "
Access-Reject = "IDP REJECTED %{User-Name}:%{%{request:Calling-Station-Id}:-UnknownCSID} from %{%{request:Operator-Name}:-Unknown} use of EDUROAM: Reply-Message: %{reply:reply-message}"
}
}
linelog sp {
filename = syslog
format = "Something has gone wrong with the SP log"
reference = "sp.%{%{reply:Packet-Type}:-format}"
sp {
Access-Accept = "SP PERMITTED %{User-Name}:%{%{request:Calling-Station-Id}:-UnknownCSID} from %{%{request:Stripped-User-Domain}:-Unknown} use of EDUROAM: "
Access-Reject = "SP DENIED %{User-Name}:%{%{request:Calling-Station-Id}:-UnknownCSID} from %{%{request:Stripped-User-Domain}:-Unknown} use of EDUROAM: Reply-Message: %{reply:reply-message}"
}
}
---
Optional policy to make the CSID look nice:
rewrite_calling_station_id {
if (Calling-Station-Id =~ /([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})/i){
update request {
Calling-Station-Id := "%{tolower:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}"
}
}
else {
noop
}
}
FTICKS
The FTICKS format and method is documented here
https://confluence.terena.org/display/H2eduroam/freeradius-sp
We are not tied to a specific format, so an extended FTICKS type log entry would work as well as a FR format, (or an FTICKS 1.1).
The content of the entries is the important bit - Raptor is capable of making use of quite a bit more information than the FTICKS format provides (IDP/SP Differentiation, logging of the remote site operator for the Home site etc).
Raptor is a program, not a human, so all the extra words can be removed, making log files smaller and more readily machine readable.
The preference would be that it should be machine parseable rather than human readable, so attributes separated by | or # are a pretty common way of doing that.
Therefore it would make sense to define essentially an FTICKS-MAX - like FTICKS is now but with more info along the lines of the things Adam has suggested.
Complete list of all the fields available to be logged by FreeRADIUS/Radiator
It would be useful to have a complete list of all the fields available to be logged by FreeRADIUS/Radiator.
In FreeRADIUS you have all the VSA/TLVs that can be logged and there are also variables that can be used:
+-----------+---------------------------+----------------------------+
| Variable | Description | Proper Equivalent |
+===========+===========================+
|%a |Protocol (SLIP/PPP) |%{Framed-Protocol} |
+-----------+---------------------------+----------------------------+
|%c |Callback-Number |%{Callback-Number} |
+-----------+---------------------------+----------------------------+
|%d |request day (DD) | |
+-----------+---------------------------+-----------------------------+
|%f |Framed IP address |%{Framed-IP-Address} |
+-----------+---------------------------+-----------------------------+
|%i |Calling Station ID |%{Calling-Station-Id} |
+-----------+---------------------------+-----------------------------+
|%l |request timestamp | |
+-----------+---------------------------+-----------------------------+
|%m |request month (MM) | |
+-----------+---------------------------+-----------------------------+
|%n |NAS IP address |%{NAS-IP-Address} |
+-----------+---------------------------+-----------------------------+
|%p |Port number |%{NAS-Port} |
+-----------+---------------------------+-----------------------------+
|%s |Speed (PW_CONNECT_INFO) |%{Connect-Info} |
+-----------+---------------------------+-----------------------------+
|%t |request in ctime format | |
+-----------+---------------------------+-----------------------------+
|%u |User name |%{User-Name} |
+-----------+---------------------------+-----------------------------+
|%A |radacct_dir |%{config:radacctdir} |
+-----------+---------------------------+-----------------------------+
|%C |clientname | |
+-----------+---------------------------+-----------------------------+
|%D |request date (YYYYMMDD) | |
+-----------+---------------------------+-----------------------------+
|%G |request minute | |
+-----------+---------------------------+-----------------------------+
|%H |request hour | |
+-----------+---------------------------+------------------------------+
|%I |request ID | |
+-----------+---------------------------+------------------------------+
|%L |radlog_dir |%{config:logdir} |
+-----------+---------------------------+------------------------------+
|%M |MTU |%{Framed-MTU} |
+-----------+---------------------------+------------------------------+
|%R |radius_dir |%{config:raddbdir} |
+-----------+---------------------------+------------------------------+
|%S |request timestamp | |
| |in SQL format | |
+-----------+---------------------------+-------------------------------+
|%T |request timestamp | |
| |in database format | |
+-----------+---------------------------+-------------------------------+
|%U |Stripped User name |%{Stripped-User-Name} |
+-----------+---------------------------+--------------------------------+
|%V |Request-Authenticator | |
| |(Verified/None) | |
+-----------+---------------------------+--------------------------------+
|%Y |request year (YYYY) | |
+-----------+---------------------------+--------------------------------+
|%Z |All request attributes | |
| |except password | |
| |(must have a big buffer) | |
+-----------+---------------------------+--------------------------------+
Radiator
In Radiator you have all the VSA/TLVs too and also...
%l
The current time in long format, e.g. Thu Jul 1 08:38:21 1999 %B The current time in common SQL date time format, e.g. Sep 12, 2003 15:48 %G The current time in extended SQL date format including seconds, e.g. Sep 12, 2003 15:48:59 %t The current time in seconds since Jan 1 1970 %S the current second (00-59) %M The current minute (00-59) %H The current hour (00-23) %d Current day of the month (2 digits) %m Current month number (2 digits, 01-12) %Y Current year (4 digits) %y Last 2 digits of the current year (2 digits) %q Day of the week, abbreviated (e.g. Sun, Mon, Tue, ....) %Q Day of the week (e.g. Sunday, Monday, Tuesday, ....) %v Month of the year, abbreviated (e.g. Jan, Feb, Mar, ...) %V Month of the year, (e.g. January, February, March, ...) %s Microseconds in the current second (requires perl Time::HiRes module) %O When FarmSize is used to specify a server farm, %O is replaced by the server instance number, where 0 is the main (supervising ) server.
from the Timestamp of the current packet (if any):
%o
The Timestamp in long format, e.g. Thu Jul 1 08:38:21 1999 %A The Timestamp in common SQL date time format, e.g. Sep 12, 2003 15:48 %J The Timestamp in another common SQL date time format: 2003-09-12 15:48:00 %F The Timestamp in extended SQL date format including seconds, e.g. Sep 12, 2003 15:48:59 %b The Timestamp in seconds since Jan 1 1970 %p the Timestamp second (0-59) %k The Timestamp minute (0-59) %j The Timestamp hour (0-23) %i The Timestamp day of the month (2 digits) %g The Timestamp month number (2 digits) %f The Timestamp year (4 digits) %e Last 2 digits of the Timestamp year (2 digits) %E The elapsed time in seconds since the packet was received. Can be used to log processing time for proxied packets etc.
other information from the current request (if any):
%c
IP address of the client who sent the current request (if any) %C Client name of the client who sent the current request (if any). Caution: this does a reverse name lookup on the address, and depending on your environment, this may take a number of seconds to resolve.
%R
The realm of the username named in the current request (if any), after any RewriteUsername was applied. This is everything following the first @ sign in the User-Name.
%K
The trailing realm of the username named in the current request (if any), after any RewriteUsername was applied. This is everything following the last @ sign in the User-Name.
%N
The NAS-IP-Address in the current request (if any) %n The User-Name (i.e. the full user name, including the realm) currently being authenticated, after any RewriteUsername was applied.
%U
The User-Name currently being authenticated with the realm (if any) stripped off, after any RewriteUsername was applied.
%u
The full original User-Name that was received, before any RewriteUsername were applied.
%w
The user name part of the full original user name (before any RewriteUsername rules were applied).
%W
The realm part of the full original user name (before any RewriteUsername rules were applied).
%P
The decrypted User-Password from the current request %T The request type of the current request, if any (e.g. Access-Request, Accounting- Request) %z The User-Name in the current packet, hashed with MD5.
%I
The NAS identifier as an integer instead of dotted decimal character string. Use- ful for speeding up SQL queries.
%X
For EAP requests, the EAP identity, with any trailing @realm stripped off.
%x
The EAP Identity for PEAP and TTLS inner requests.
%Z
The RADIUS Identifier of the incoming request.
%{attr}
The value of the named attribute in the current packet (if any). For example, %{User-Name} is the same as %n %% The percent character %r A literal newline character %D The value of DbDir as configured in your Radiator configuration file %L The value of LogDir as configured in your Radiator configuration file %h The hostname this server is running on %{Special:X} Same as%X, where X is any of the single special characters listed above. For example, %{Special:a} will produce the same result as just %a.
%{GlobalVar:name}
The value of the global variable called name. Global variables can bet set with name=value on the command line, or with “DefineGlobalVar name value” in the configuration file. If the variable “name” has not been defined, replaced with an empty string.
%a
The Framed-IP-Address in the reply message being created (if any) %{Request:name} The value of the named attribute in the current request (if any). This is the same as just %{name}, but may be used instead for clarity.
%{OuterRequest:name}
The value of the named attribute in the outer request (if any) of the current request (if any). May be used where the request has been tunnelled using PEAP or TTLS.
%{Reply:name}
The value of the named attribute in the reply currently being created (if any). For example, %{Reply:Framed-IP-Address} is the same as %a. If there is no current reply, or the attribute is not present in the reply, replaced with an empty string %{Client:name} The value of the named parameter from the Client clause that accepted the cur- rent packet (if any).
%{Handler:name}
The value of the named parameter from the Handler clause that is handling the current packet (if any).
%{Server:name}
The value of the named parameter from the global server configuration (e.g. %{Server:Trace} is replaced by the current value of the global Trace parameter).
%{IntegerVal:name}
The value of the named attribute in the current packet (if any), expressed as an integer, instead of as a value name from the dictionary. (e.g. %{IntegerVal:Tun- nel-Type} would be replaced by ‘3’ if the Tunnel-Type is ‘L2TP’).
%{HexAddress:name}
Replaced by the named IPV4 attribute in the current packet (if any), expressed as a hexadecimal string. (e.g. %{HexAddress: NAS-IP-Address} would be replaced by ‘CB3F9A01’ if the NAS-IP-Address in the current request was 203.63.154.1).
%{Quote:somestring}
When used with SQL modules, replaced by somestring quoted with the appropri- ate quoting style for the SQL database in use. For example when used with a mysql database, %{Quote:somestring} would be replaced by ’somestring’.
%{SQL:identifier:query}
Replaced with a value fetched from an SQL database. Looks for a previously defined AuthBy SQL clause with an Identifier of ’identifier’ and runs the SQL query given by ’query’. The first row in the result will be used as the value of the special character. This type of lookup is done whenever the special character is evaluated.
%0 - %99
Depending on the context, these may be replaced with context specific values, which are documented in the relevant sections below.
Different log file for the audit logs of IdP vs SP operations
Could we define a different log file for the audit logs of IdP vs SP operations? Whilst this may not be something we'd want, it is useful to consider possibilities.
Yes - you could call a different logger depending on what virtual-server you are using....or the SSID or the type of user etc etc
