Do-Over: Post-Auth-Type Accept vs Post-Auth-Type Reject 3.0.14

[Wussler, Doug]

First, allow me to preface my inquiry by saying that we have been using FreeRADIUS for
at least 5 years now.  It does a fantastic job
for us and we very much appreciate having access to this excellent application and to this
extremely responsive listserv.  We are grateful and send our thanks to all contributors.

Now, to my inquiry:

In “radiusd.conf” the “log {}” section defines radius log processing.
In particular, “msg_goodpass” and “msg_badpass” allow you to add arbitrary info to your log
records through the expansion of custom variables.  Our config looks like this:

log {
        destination = files
        file = ${logdir}/radius.log
        auth = yes
        msg_goodpass = "%{SSID} %{Aruba-Location-Id} %{Aruba-AP-Group} %{Aruba-Device-Type} %{reply:VLAN}"
        msg_badpass  = "%{SSID} %{Aruba-Location-Id} %{Aruba-AP-Group} %{Aruba-Device-Type}"
}


Here is the relevant debug from a successful PEAP-MSChapV2 authentication.  Note that
the “Post-Auth” processing takes place BEFORE the log record is expanded and written.

(9) # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/fsu-1812
(9)   post-auth {
(9)     if ( session-state:Cached-Session-Policy ) {
(9)     if ( session-state:Cached-Session-Policy )  -> FALSE
(9)     policy fsu-policy {
(9)       if ( &Client-Shortname =~ /City/ ) {
(9)       EXPAND &Client-Shortname
(9)          --> CL
(9)       if ( &Client-Shortname =~ /City/ )  -> FALSE
(9)       else {
(9)         update {
(9)           &reply:Aruba-User-Vlan := &reply:VLAN -> 8
(9)         } # update = noop
(9)       } # else = noop
(9)       if ( !&SSID ) {
(9)       if ( !&SSID )  -> TRUE
(9)       if ( !&SSID )  {
(9)         if ( &Aruba-Essid-Name ) {
(9)         if ( &Aruba-Essid-Name )  -> TRUE
(9)         if ( &Aruba-Essid-Name )  {
(9)           update {
(9)             &SSID := &Aruba-Essid-Name -> 'FSU'
(9)           } # update = noop
(9)         } # if ( &Aruba-Essid-Name )  = noop
(9)         ... skipping elsif: Preceding "if" was taken
(9)         ... skipping elsif: Preceding "if" was taken
(9)         ... skipping elsif: Preceding "if" was taken
(9)         ... skipping else: Preceding "if" was taken
(9)       } # if ( !&SSID )  = noop
(9)     } # policy fsu-policy = noop
(9)   } # post-auth = noop
(9) EXPAND %{SSID} %{Aruba-Location-Id} %{Aruba-AP-Group} %{Aruba-Device-Type} %{reply:VLAN}
(9)    --> FSU wg-wireless.fsu.edu Sha iPhone 8
(9) Login OK: [dw] (from client CL port 0 cli Bbbbbbbbbbb FSU wg-wireless.fsu.edu Sha iPhone 8
(9) Sent Access-Accept Id 85 from 128.186.10.10:1812 to 128.186.11.11:34005 length 0


Here is the relevant debug from an unsuccessful auth.  Note that the Post-Auth-Type Reject
processing takes place AFTER the log record is expanded and written:

(8) Failed to authenticate the user
(8) EXPAND %{SSID} %{Aruba-Location-Id} %{Aruba-AP-Group} %{Aruba-Device-Type}
(8)    -->  wg-wireless.fsu.edu Sha iPhone
(8) Login incorrect (eap_peap: The users session was previously rejected: returning reject (again.)): [dw] (from client CL port 0 cli Bbbbbbbbbbbb)  wg-wireless.fsu.edu Sha iPhone
(8) Using Post-Auth-Type Reject
(8) # Executing group from file /usr/local/etc/raddb/sites-enabled/fsu-1812
(8)   Post-Auth-Type REJECT {
(8)     policy fsu-policy {
(8)       if ( !&SSID ) {
(8)       if ( !&SSID )  -> TRUE
(8)       if ( !&SSID )  {
(8)         if ( &Aruba-Essid-Name ) {
(8)         if ( &Aruba-Essid-Name )  -> TRUE
(8)         if ( &Aruba-Essid-Name )  {
(8)           update {
(8)             &SSID := &Aruba-Essid-Name -> 'FSU'
(8)           } # update = noop
(8)         } # if ( &Aruba-Essid-Name )  = noop
(8)         ... skipping elsif: Preceding "if" was taken
(8)         ... skipping elsif: Preceding "if" was taken
(8)         ... skipping elsif: Preceding "if" was taken
(8)         ... skipping else: Preceding "if" was taken
(8)       } # if ( !&SSID )  = noop
(8)     } # policy fsu-policy = noop
(8) attr_filter.access_reject: EXPAND %{User-Name}
(8) attr_filter.access_reject:    --> dw
(8) attr_filter.access_reject: Matched entry DEFAULT at line 17
(8)     [attr_filter.access_reject] = updated
(8)   } # Post-Auth-Type REJECT = updated
(8) Delaying response for 1.000000 seconds
Waking up in 0.3 seconds.
Waking up in 0.6 seconds.
(8) Sending delayed response
(8) Sent Access-Reject Id 95 from 128.186.10.10:1812 to 128.186.11.11:34005 length 44


Is there some reason why we would want Post-Auth Accept to run BEFORE log processing but
Post-Auth-Type Reject to run AFTER log processing?  It seems like we would want our Post-Auth
processing to occur in the same sequence relative to expanding and writing the log record
no matter whether we get an Accept or a Reject.


Doug Wussler
Florida State University