FreeRADIUS latest package upgrade

stevepaladino

FreeRADIUS latest package upgrade broke Plain Mac Authentication.

From system logs:
Jan 28 15:30:06 radiusd Login incorrect: [valid_mac_address] (from client <valid_access_point> port 0 cli <valid_mac_address>)
Jan 28 15:30:06 radiusd Invalid user: [valid_mac_address] (from client <valid_access_point> port 0 cli <valid_mac_address>)

viktor_g

@stevepaladino Please run radiusd in debugging mode to see actual issue:

# killall radiusd
# radiusd -X

that could be related to https://github.com/pfsense/FreeBSD-ports/commit/8f80400e337a7e97bd0dbdc73abf9727c911c9f2#diff-4e127f04e9e61d64b97159f68be89fe4b00a081836c1f9c7b46093d90e636f4d

but I see another issue with files authentication in debug output:

(6)     } # update = noop
(6) exec: Executing: /bin/sh /usr/local/etc/raddb/scripts/datacounter_auth.sh raduser1 daily:
(6) exec: ERROR: Program returned code (99) and output ''
(6) exec: ERROR: Program returned invalid code (greater than max rcode) (99 > 9):

viktor_g

@stevepaladino fix is ready: https://redmine.pfsense.org/issues/11331

while waiting for a new package, you can fix it manually,
see:

/usr/local/pkg/freeradius.inc
@@ -2265,7 +2265,7 @@ authorize {
 	}
 #	unix
 	files
-	if (notfound || noop) {
+	if ((notfound || noop) && (&control:Auth-Type != Accept)) {
 		{$varsqlconfauthorize}
 		if (notfound || noop) {
 			{$varmodulesldapenableauthorize}

viktor_g

fixed in pfSense-pkg-freeradius 0.15.7_26

stevepaladino

@viktor_g

Fix verified. Awesome! Thanks all!

johnpoz

Well this looks to have broken something else.

I just updated to _26 and now getting these

Jan 29 09:58:34 	radiusd 	24555 	(45) Login incorrect: [johnsXR/<via Auth-Type = eap>] (from client uap-pro port 0 cli F4-06-16-4F-F6-36) 192.168.2.2 Auth-Type: eap
Jan 29 09:58:34 	radiusd 	24555 	(45) Invalid user: [johnsXR/<via Auth-Type = eap>] (from client uap-pro port 0 cli F4-06-16-4F-F6-36) 192.168.2.2 Auth-Type: eap
Jan 29 09:58:28 	radiusd 	24555 	(43) Login incorrect: [johnsXR/<via Auth-Type = eap>] (from client uap-pro port 0 cli F4-06-16-4F-F6-36) 192.168.2.2 Auth-Type: eap
Jan 29 09:58:28 	radiusd 	24555 	(43) Invalid user: [johnsXR/<via Auth-Type = eap>] (from client uap-pro port 0 cli F4-06-16-4F-F6-36) 192.168.2.2 Auth-Type: eap
Jan 29 09:58:17 	radiusd 	24555 	(41) Login incorrect: [kimphone/<via Auth-Type = eap>] (from client uap-lr port 0 cli 88-B2-91-98-D6-F0) 192.168.2.3 Auth-Type: eap
Jan 29 09:58:17 	radiusd 	24555 	(41) Invalid user: [kimphone/<via Auth-Type = eap>] (from client uap-lr port 0 cli 88-B2-91-98-D6-F0) 192.168.2.3 Auth-Type: eap
Jan 29 09:58:11 	radiusd 	24555 	(39) Login incorrect: [kimphone/<via Auth-Type = eap>] (from client uap-lr port 0 cli 88-B2-91-98-D6-F0) 192.168.2.3 Auth-Type: eap

And they were clearly working before..

Jan 29 06:48:28 	radiusd 	2903 	(984) Login OK: [kimphone/<via Auth-Type = eap>] (from client uap-lr port 0 cli 88-B2-91-98-D6-F0) 192.168.2.3 Auth-Type: eap

A Former User

@johnpoz Strange. Mine are still working after updating to _26.

Screen Shot 2021-01-29 at 11.02.42.png

Let me know if I can look at anything that would help you debug.

johnpoz

Its odd.. But it might of broken from previous update.. I didn't notice it until mention of 26 upgrade.. Then I looked at my phone and it was on a different ssid.. So tried to move it back to my eap-tls ssid and failed..

But nothing has changed other than upgrading the package.

Let me restart the service..

edit: Well that didn't fix it..

Jan 29 10:09:23 	radiusd 	50700 	(1) Login incorrect: [johnsXR/<via Auth-Type = eap>] (from client uap-pro port 0 cli F4-06-16-4F-F6-36) 192.168.2.2 Auth-Type: eap
Jan 29 10:09:23 	radiusd 	50700 	(1) Invalid user: [johnsXR/<via Auth-Type = eap>] (from client uap-pro port 0 cli F4-06-16-4F-F6-36) 192.168.2.2 Auth-Type: eap
Jan 29 10:09:04 	radiusd 	50700 	Ready to process requests
Jan 29 10:09:04 	radiusd 	50700 	Loaded virtual server inner-tunnel-peap
Jan 29 10:09:04 	radiusd 	50700 	Loaded virtual server inner-tunnel-ttls
Jan 29 10:09:04 	radiusd 	50700 	Ignoring "ldap" (see raddb/mods-available/README.rst)
Jan 29 10:09:04 	radiusd 	50700 	Ignoring "sql" (see raddb/mods-available/README.rst)
Jan 29 10:09:04 	radiusd 	50700 	Loaded virtual server default
Jan 29 10:09:04 	radiusd 	50700 	Loaded virtual server <default>
Jan 29 10:09:04 	radiusd 	50145 	Debugger not attached
Jan 29 10:08:53 	radiusd 	24555 	Exiting normally

A Former User

I also upgraded to _25 and then _26. Didn't notice any issues with at any point this morning.

johnpoz

Hmmm - let me start it in debug mode..

A Former User

Screen Shot 2021-01-29 at 11.13.08.png

Restarted my iphone. Authed ok. Hallway is a nanoHD running 5.43.23 firmware.

I'm not in a good spot to restart the WAP or kick the pfSense box. School from home...

slu

@johnpoz
_25 works for me with EAP-TTLS, I haven't tried version _26.

johnpoz

Ok - I need more coffee... But nothing jumping out at me here

Do you see anything?

Ready to process requests
(0) Received Access-Request Id 14 from 192.168.2.2:43356 to 192.168.2.253:1812 length 236
(0)   User-Name = "johnsXR"
(0)   NAS-IP-Address = 192.168.2.2
(0)   NAS-Identifier = "802aa8154f07"
(0)   Called-Station-Id = "80-2A-A8-15-4F-07:unifi-ent"
(0)   NAS-Port-Type = Wireless-802.11
(0)   Service-Type = Framed-User
(0)   Calling-Station-Id = "F4-06-16-4F-F6-36"
(0)   Connect-Info = "CONNECT 0Mbps 802.11b"
(0)   Acct-Session-Id = "4F431ED7267F8975"
(0)   Acct-Multi-Session-Id = "2BCC27BEC5AC38A5"
(0)   Mobility-Domain-Id = 40405
(0)   WLAN-Pairwise-Cipher = 1027076
(0)   WLAN-Group-Cipher = 1027076
(0)   WLAN-AKM-Suite = 1027075
(0)   WLAN-Group-Mgmt-Cipher = 1027078
(0)   Framed-MTU = 1400
(0)   EAP-Message = 0x02bc000c016a6f686e735852
(0)   Message-Authenticator = 0x90a59c6b7887b79e71b495a8ebc24f95
(0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(0)   authorize {
(0)     [preprocess] = ok
(0)     [chap] = noop
(0)     [mschap] = noop
(0)     [digest] = noop
(0) suffix: Checking for suffix after "@"
(0) suffix: No '@' in User-Name = "johnsXR", skipping NULL due to config.
(0)     [suffix] = noop
(0) ntdomain: Checking for prefix before "\"
(0) ntdomain: No '\' in User-Name = "johnsXR", skipping NULL due to config.
(0)     [ntdomain] = noop
(0) eap: Peer sent EAP Response (code 2) ID 188 length 12
(0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize
(0)     [eap] = ok
(0)   } # authorize = ok
(0) Found Auth-Type = eap
(0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(0)   authenticate {
(0) eap: Peer sent packet with method EAP Identity (1)
(0) eap: Calling submodule eap_tls to process data
(0) eap_tls: Initiating new TLS session
(0) eap_tls: Setting verify mode to require certificate from client
(0) eap_tls: [eaptls start] = request
(0) eap: Sending EAP Request (code 1) ID 189 length 6
(0) eap: EAP session adding &reply:State = 0xdf51dbcadfecd654
(0)     [eap] = handled
(0)   } # authenticate = handled
(0) Using Post-Auth-Type Challenge
(0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(0)   Challenge { ... } # empty sub-section is ignored
(0) Sent Access-Challenge Id 14 from 192.168.2.253:1812 to 192.168.2.2:43356 length 0
(0)   EAP-Message = 0x01bd00060d20
(0)   Message-Authenticator = 0x00000000000000000000000000000000
(0)   State = 0xdf51dbcadfecd65448515f9521c110a4
(0) Finished request
Waking up in 4.9 seconds.
(1) Received Access-Request Id 15 from 192.168.2.2:43356 to 192.168.2.253:1812 length 403
(1)   User-Name = "johnsXR"
(1)   NAS-IP-Address = 192.168.2.2
(1)   NAS-Identifier = "802aa8154f07"
(1)   Called-Station-Id = "80-2A-A8-15-4F-07:unifi-ent"
(1)   NAS-Port-Type = Wireless-802.11
(1)   Service-Type = Framed-User
(1)   Calling-Station-Id = "F4-06-16-4F-F6-36"
(1)   Connect-Info = "CONNECT 0Mbps 802.11b"
(1)   Acct-Session-Id = "4F431ED7267F8975"
(1)   Acct-Multi-Session-Id = "2BCC27BEC5AC38A5"
(1)   Mobility-Domain-Id = 40405
(1)   WLAN-Pairwise-Cipher = 1027076
(1)   WLAN-Group-Cipher = 1027076
(1)   WLAN-AKM-Suite = 1027075
(1)   WLAN-Group-Mgmt-Cipher = 1027078
(1)   Framed-MTU = 1400
(1)   EAP-Message = 0x02bd00a10d800000009716030100920100008e0303601433ecac4bbb43f730aa52e23e4eb64fdf235d9dd288ea5fd1af9f487e469600002c00ffc02cc02bc024c023c00ac009c008c030c02fc028c027c014c013c012009d009c003d003c0035002f000a01000039000a00080006001700180019000b00020100000d00120010040102010501060104030203050306030005000501000000000012000000170000
(1)   State = 0xdf51dbcadfecd65448515f9521c110a4
(1)   Message-Authenticator = 0x72d154f581e65c96917fd999ecbf9802
(1) session-state: No cached attributes
(1) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(1)   authorize {
(1)     [preprocess] = ok
(1)     [chap] = noop
(1)     [mschap] = noop
(1)     [digest] = noop
(1) suffix: Checking for suffix after "@"
(1) suffix: No '@' in User-Name = "johnsXR", skipping NULL due to config.
(1)     [suffix] = noop
(1) ntdomain: Checking for prefix before "\"
(1) ntdomain: No '\' in User-Name = "johnsXR", skipping NULL due to config.
(1)     [ntdomain] = noop
(1) eap: Peer sent EAP Response (code 2) ID 189 length 161
(1) eap: No EAP Start, assuming it's an on-going EAP conversation
(1)     [eap] = updated
(1)     [files] = noop
(1)     if ((notfound || noop) && (&control:Auth-Type != Accept)) {
(1)     if ((notfound || noop) && (&control:Auth-Type != Accept))  -> TRUE
(1)     if ((notfound || noop) && (&control:Auth-Type != Accept))  {
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
(1)       [daily] = noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
(1)       [weekly] = noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
(1)       [monthly] = noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
(1)       [forever] = noop
(1)       if (notfound || noop) {
(1)       if (notfound || noop)  -> TRUE
(1)       if (notfound || noop)  {
(1)         if (notfound || noop) {
(1)         if (notfound || noop)  -> TRUE
(1)         if (notfound || noop)  {
(1)           [reject] = reject
(1)         } # if (notfound || noop)  = reject
(1)       } # if (notfound || noop)  = reject
(1)     } # if ((notfound || noop) && (&control:Auth-Type != Accept))  = reject
(1)   } # authorize = reject
(1) EXPAND %{NAS-IP-Address} Auth-Type: %{control:Auth-Type}
(1)    --> 192.168.2.2 Auth-Type: eap
(1) Invalid user: [johnsXR/<via Auth-Type = eap>] (from client uap-pro port 0 cli F4-06-16-4F-F6-36) 192.168.2.2 Auth-Type: eap
(1) Using Post-Auth-Type Reject
(1) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(1)   Post-Auth-Type REJECT {
(1) attr_filter.access_reject: EXPAND %{User-Name}
(1) attr_filter.access_reject:    --> johnsXR
(1) attr_filter.access_reject: Matched entry DEFAULT at line 11
(1)     [attr_filter.access_reject] = updated
(1) eap: Expiring EAP session with state 0xdf51dbcadfecd654
(1) eap: Finished EAP session with state 0xdf51dbcadfecd654
(1) eap: Previous EAP request found for state 0xdf51dbcadfecd654, released from the list
(1) eap: Request was previously rejected, inserting EAP-Failure
(1) eap: Sending EAP Failure (code 4) ID 189 length 4
(1)     [eap] = updated
(1)     policy remove_reply_message_if_eap {
(1)       if (&reply:EAP-Message && &reply:Reply-Message) {
(1)       if (&reply:EAP-Message && &reply:Reply-Message)  -> FALSE
(1)       else {
(1)         [noop] = noop
(1)       } # else = noop
(1)     } # policy remove_reply_message_if_eap = noop
(1)   } # Post-Auth-Type REJECT = updated
(1) EXPAND %{NAS-IP-Address} Auth-Type: %{control:Auth-Type}
(1)    --> 192.168.2.2 Auth-Type: eap
(1) Login incorrect: [johnsXR/<via Auth-Type = eap>] (from client uap-pro port 0 cli F4-06-16-4F-F6-36) 192.168.2.2 Auth-Type: eap
(1) Delaying response for 1.000000 seconds
Waking up in 0.3 seconds.
Waking up in 0.6 seconds.
(1) Sending delayed response
(1) Sent Access-Reject Id 15 from 192.168.2.253:1812 to 192.168.2.2:43356 length 44
(1)   EAP-Message = 0x04bd0004
(1)   Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 3.8 seconds.
(0) Cleaning up request packet ID 14 with timestamp +12
(1) Cleaning up request packet ID 15 with timestamp +12
Ready to process requests

A Former User

Nothing that jumps out... Let me restart radius in debug to compare.

OK, looks about the same...

viktor_g

@johnpoz said in FreeRADIUS latest package upgrade:

[forever] = noop
(1) if (notfound || noop) {
(1) if (notfound || noop) -> TRUE
(1) if (notfound || noop) {
(1) if (notfound || noop) {
(1) if (notfound || noop) -> TRUE
(1) if (notfound || noop) {
(1) [reject] = reject
(1) } # if (notfound || noop) = reject
(1) } # if (notfound || noop) = reject
(1) } # if ((notfound || noop) && (&control:Auth-Type != Accept)) = reject
(1) } # authorize = reject

this is about the _25 change that broke plain mac auth:
https://github.com/pfsense/FreeBSD-ports/commit/8f80400e337a7e97bd0dbdc73abf9727c911c9f2

it sequentially check all DB (files, sql, ldap) for user and reject authentication if not found.
Successfully tested with EAP-TLS and EAP-PEAP with files and LDAP backends.

could you provide more info about your configuration?
are you sure this user exists?

johnpoz

Yeah they exist - since they were logging on just before update.

What other info do you want? I can post up the full configs.

Here is login from yesterday from same phone.

Jan 28 01:16:49 	radiusd 	18052 	(582) Login OK: [johnsXR/<via Auth-Type = eap>] (from client uap-lite port 0 cli F4-06-16-4F-F6-36) 192.168.2.4 Auth-Type: eap

And above showed valid login from my wife phone.. So clearly the users exist..

They have been in use for like 2 years.. And were working just fine last night.. I woke up this morning noticed a few package updates. I updated them all... Then noticed this thread with newer update _26

So I updated to that.. After that is when I noticed my phone was not using the eap-tls ssid.. And was logged into one of my psk ssids.

So I tried to change it back over and it failed, that is when started to look in the log.. Is there I can reload package from before _25??

viktor_g

@johnpoz hm.. SQL backend?
please post /usr/local/etc/raddb/sites-enabled/default

johnpoz

No SQL backend..

 cat /usr/local/etc/raddb/sites-enabled/default
server default {
listen {
        type = auth
        ipaddr = 192.168.2.253
        port = 1812
}

authorize {
#       filter_username
#       filter_password
        preprocess
#       operator-name
#       cui
##### AUTHORIZE FOR PLAIN MAC-AUTH IS DISABLED #####
#       auth_log
        chap
        mschap
        digest
#       wimax
#       IPASS
        suffix
        ntdomain
        eap {
                ok = return
#               updated = return
        }
#       unix
        files
        if ((notfound || noop) && (&control:Auth-Type != Accept)) {
                        ### sql DISABLED ###
        -daily
        -weekly
        -monthly
        -forever
                if (notfound || noop) {
                        ### ldap ###
                        if (notfound || noop) {
                                reject
                        }
                }
        }
        # Formerly checkval
        if (&request:Calling-Station-Id == &control:Calling-Station-Id) {
                ok
        }
        expiration
        logintime
        pap
        Autz-Type Status-Server {

        }
}

authenticate {
        Auth-Type PAP {
                pap
        }
        Auth-Type CHAP {
                chap
        }
        Auth-Type MS-CHAP {
                mschap
        }
        mschap
        Auth-Type MOTP {
                motp
        }
        Auth-Type GOOGLEAUTH {
                googleauth
        }
        digest
#       pam
#       unix

        #Auth-Type LDAP {
                #ldap
                #### ldap2 disabled ###
        #}

        eap
#       Auth-Type eap {
#               eap {
#                       handled = 1
#               }
#               if (handled && (Response-Packet-Type == Access-Challenge)) {
#                       attr_filter.access_challenge.post-auth
#                       handled  # override the "updated" code from attr_filter
#               }
#       }
}

preacct {
        preprocess
##### ACCOUNTING FOR PLAIN MAC-AUTH DISABLED #####
#       acct_counters64
        update request {
                &FreeRADIUS-Acct-Session-Start-Time = "%{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}}"
        }
acct_unique
#       IPASS
        suffix
        ntdomain
        files
}

accounting {
#       cui
        detail
        ### This makes it possible to run the datacounter_acct module only on accounting-stop and interim-updates
        if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) {
                datacounterdaily
                datacounterweekly
                datacountermonthly
                datacounterforever
        }
#       unix
        radutmp
#       sradutmp
#       main_pool
        ### sql DISABLED ###
        daily
        weekly
        monthly
        forever
#       if (noop) {
#               ok
#       }
#       pgsql-voip
        exec
        attr_filter.accounting_response
        Acct-Type Status-Server {

        }
}

session {
#       radutmp
        radutmp
}

post-auth {
#       if (!&reply:State) {
#               update reply {
#                       State := "0x%{randstr:16h}"
#               }
#       }
        update {
                &reply: += &session-state:
        }
#       main_pool
#       cui
#       reply_log
### sql DISABLED ###
#       ldap
        exec
#       wimax
#       update reply {
#               Reply-Message += "%{TLS-Cert-Serial}"
#               Reply-Message += "%{TLS-Cert-Expiration}"
#               Reply-Message += "%{TLS-Cert-Subject}"
#               Reply-Message += "%{TLS-Cert-Issuer}"
#               Reply-Message += "%{TLS-Cert-Common-Name}"
#               Reply-Message += "%{TLS-Cert-Subject-Alt-Name-Email}"
#
#               Reply-Message += "%{TLS-Client-Cert-Serial}"
#               Reply-Message += "%{TLS-Client-Cert-Expiration}"
#               Reply-Message += "%{TLS-Client-Cert-Subject}"
#               Reply-Message += "%{TLS-Client-Cert-Issuer}"
#               Reply-Message += "%{TLS-Client-Cert-Common-Name}"
#               Reply-Message += "%{TLS-Client-Cert-Subject-Alt-Name-Email}"
#       }
#       insert_acct_class
#       if (&reply:EAP-Session-Id) {
#               update reply {
#                       EAP-Key-Name := &reply:EAP-Session-Id
#               }
#       }
        remove_reply_message_if_eap
        Post-Auth-Type REJECT {
                # log failed authentications in SQL, too.
                # sql
                attr_filter.access_reject
                eap
                remove_reply_message_if_eap
        }
        Post-Auth-Type Challenge {

        }
}

pre-proxy {
#       operator-name
#       cui
#       files
        attr_filter.pre-proxy
#       pre_proxy_log
}

post-proxy {

#       post_proxy_log
        attr_filter.post-proxy
        eap
#       Post-Proxy-Type Fail-Accounting {
#                       detail
#       }
}
}
[2.4.5-RELEASE][admin@sg4860.local.lan]/root:

viktor_g

@johnpoz EAP-TLS? PEAP, TTLS?
same username registry in freeradius?
check /usr/local/etc/raddb/users

johnpoz

eap-tls

No there are no users listed in registry.. They have never been there, and worked before..

[2.4.5-RELEASE][admin@sg4860.local.lan]/root: cat /usr/local/etc/raddb/users
[2.4.5-RELEASE][admin@sg4860.local.lan]/root:

Have never had to put users in there before, not when using eap-tls and they have certs.

Again this was just working last night.. before update to _25 and then _26 no changes on anything.

So I added johnsXR as a user - and now working.. But they were never in there..

an 29 11:08:48 	radiusd 	9145 	(7) Login OK: [johnsXR/<via Auth-Type = eap>] (from client uap-pro port 0 cli F4-06-16-4F-F6-36) 192.168.2.2 Auth-Type: eap