Re: TLS errors and clients sometimes rejected

17 Sep 2024


      Citando Alan DeKok <aland@deployingradius.com>:
...
That configuration tells FreeRADIUS to use TLS 1.0, 1.1, and 1.2.
But it disallows TLS 1.3.  So... if FreeRADIUS doesn't like the  
TLS version, that would likely be it.
I defined tls_max_version = "1.3" and the same errors persists.
...
Look at the logs.  It's not possible to debug complicated TLS  
issues by looking at 3-4 lines of TLS logs.
I managed to get the debug of when it was rejected, soon after this it  
is accepted. The problem seems to be random.
Below is both logs.
...
2.2.5 doesn't support TLS 1.3.
Plus, what is likely here is that the server running 2.2.5 is also  
running a very old version of OpenSSL.  Which allows many deprecated  
TLS ciphers, etc.
The server running 3.2 is using a new version of OpenSSL, which  
doesn't allow old / deprecated / insecure TLS ciphers.  That's  
likely why old systems fail to connect.
Doesn't cipher_list = "DEFAULT@SECLEVEL=0" says the server to support  
the old ciphers?
...
Configure OpenSSL (e.g. cipher_list) so that it works with a new  
version of OpenSSL.  Or, use an old version of OpenSSL.  There  
really aren't many other choices.
What are the other choices possible?


## REJECTED

(911) Received Access-Request Id 81 from 10.1.0.14:34441 to  
10.1.0.22:1812 length 444
(911)   User-Name = "20191010280"
(911)   Chargeable-User-Identity = 0x08
(911)   Location-Capable = Civic-Location
(911)   Calling-Station-Id = "98-b8-ba-34-40-13"
(911)   Called-Station-Id = "64-e9-50-67-62-f0:IFSUL PEL"
(911)   NAS-Port = 1
(911)   Cisco-AVPair = "audit-session-id=08f910ac000328864481e966"
(911)   Acct-Session-Id = "66e98144/98:b8:ba:34:40:13/218288"
(911)   NAS-IP-Address = 172.16.249.8
(911)   NAS-Identifier = "IFSUL_PEL_WLAN_CONTROLLER"
(911)   Airespace-Wlan-Id = 2
(911)   Service-Type = Framed-User
(911)   Framed-MTU = 1300
(911)   NAS-Port-Type = Wireless-802.11
(911)   Tunnel-Type:0 = VLAN
(911)   Tunnel-Medium-Type:0 = IEEE-802
(911)   Tunnel-Private-Group-Id:0 = "1"
(911)   EAP-Message =  
0x020d009419800000008a160301007e0100007a03037739896a2e5da1a5615f21e3679e96055f84253bd0f7768cf771d20de50588c100001ec02bc02fc02cc030cca9cca8c009c013c00ac014009c009d002f0035000a0100003300170000ff01000100000a00080006001d00170018000b00020100000d001400120403080404010503080505010806060102011503010002020a
(911)   State = 0x50e03ed05bed27ba1eb1b878bf54369b
(911)   Message-Authenticator = 0x4dbff684fe3293e27d2363756fdd54c9
(911) Restoring &session-state
(911)   &session-state:Framed-MTU = 994
(911)   &session-state:TLS-Session-Information = "(TLS) recv TLS 1.3  
Handshake, ClientHello"
(911)   &session-state:TLS-Session-Information = "(TLS) send TLS 1.2  
Handshake, ServerHello"
(911)   &session-state:TLS-Session-Information = "(TLS) send TLS 1.2  
Handshake, Certificate"
(911)   &session-state:TLS-Session-Information = "(TLS) send TLS 1.2  
Handshake, ServerKeyExchange"
(911)   &session-state:TLS-Session-Information = "(TLS) send TLS 1.2  
Handshake, ServerHelloDone"
(911)   &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2  
Handshake, ClientKeyExchange"
(911)   &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2  
Handshake, Finished"
(911)   &session-state:TLS-Session-Information = "(TLS) send TLS 1.2  
ChangeCipherSpec"
(911)   &session-state:TLS-Session-Information = "(TLS) send TLS 1.2  
Handshake, Finished"
(911)   &session-state:TLS-Session-Cipher-Suite =  
"ECDHE-RSA-AES128-GCM-SHA256"
(911)   &session-state:TLS-Session-Version = "TLS 1.2"
(911) # Executing section authorize from file  
/etc/freeradius/3.0/sites-enabled/default
(911)   authorize {
(911)     policy filter_username {
(911)       if (&User-Name) {
(911)       if (&User-Name)  -> TRUE
(911)       if (&User-Name)  {
(911)         if (&User-Name =~ / /) {
(911)         if (&User-Name =~ / /)  -> FALSE
(911)         if (&User-Name =~ /@[^@]*@/ ) {
(911)         if (&User-Name =~ /\.$/)   -> FALSE
(911)         if (&User-Name =~ /@\./)  {
(911)         if (&User-Name =~ /@\./)   -> FALSE
(911)       } # if (&User-Name)  = notfound
(911)     } # policy filter_username = notfound
(911)     [preprocess] = ok
(911)     [chap] = noop
(911)     [mschap] = noop
(911)     [digest] = noop
(911) suffix: Checking for suffix after "@"
(911) suffix: No '@' in User-Name = "20191010280", looking up realm NULL
(911) suffix: No such realm "NULL"
(911)     [suffix] = noop
(911) eap: Peer sent EAP Response (code 2) ID 13 length 148
(911) eap: Continuing tunnel setup
(911)     [eap] = ok
(911)   } # authorize = ok
(911) Found Auth-Type = eap
(911) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(911)   authenticate {
(911) eap: Expiring EAP session with state 0xf005b4e1f00eaea1
(911) eap: Finished EAP session with state 0x50e03ed05bed27ba
(911) eap: Previous EAP request found for state 0x50e03ed05bed27ba,  
released from the list
(911) eap: Peer sent packet with method EAP PEAP (25)
(911) eap: Calling submodule eap_peap to process data
(911) eap_peap: (TLS) EAP Peer says that the final record size will be  
138 bytes
(911) eap_peap: (TLS) EAP Got all data (138 bytes)
(911) eap_peap: (TLS) send TLS 1.2 Alert, fatal protocol_version
(911) eap_peap: ERROR: (TLS) Alert write:fatal:protocol version
(911) eap_peap: ERROR: (TLS) Error in fragmentation logic - code 1
(911) eap_peap: ERROR: (TLS) Failed reading application data from  
OpenSSL: error:0A00010B:SSL routines::wrong version number
(911) eap_peap: ERROR: (TLS) System call (I/O) error (-1)
(911) eap_peap: ERROR: [eaptls process] = fail
(911) eap: ERROR: Failed continuing EAP PEAP (25) session.  EAP  
sub-module failed
(911) eap: Sending EAP Failure (code 4) ID 13 length 4
(911) eap: Failed in EAP select
(911)     [eap] = invalid
(911)   } # authenticate = invalid
(911) Failed to authenticate the user
(911) Using Post-Auth-Type Reject
(911) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(911)   Post-Auth-Type REJECT {
(911) attr_filter.access_reject: EXPAND %{User-Name}
(911) attr_filter.access_reject:    --> 20191010280
(911) attr_filter.access_reject: Matched entry DEFAULT at line 11
(911)     [attr_filter.access_reject] = updated
(911)     [eap] = noop
(911)     policy remove_reply_message_if_eap {
(911)       if (&reply:EAP-Message && &reply:Reply-Message) {
(911)       if (&reply:EAP-Message && &reply:Reply-Message)  -> FALSE
(911)       else {
(911)         [noop] = noop
(911)       } # else = noop
(911)     } # policy remove_reply_message_if_eap = noop
(911)   } # Post-Auth-Type REJECT = updated
(911) Login incorrect (eap_peap: (TLS) Alert write:fatal:protocol  
version): [20191010280/<via Auth-Type = eap>] (from client cisco-wlc  
port 1 cli 98-b8-ba-34-40-13)
(911) Delaying response for 1.000000 seconds

## ACCEPTED

(4900) Tue Sep 17 13:34:22 2024: Debug: Received Access-Request Id 94  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 294
(4900) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4900) Tue Sep 17 13:34:22 2024: Debug:   Chargeable-User-Identity = 0x08
(4900) Tue Sep 17 13:34:22 2024: Debug:   Location-Capable = Civic-Location
(4900) Tue Sep 17 13:34:22 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4900) Tue Sep 17 13:34:22 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4900) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port = 1
(4900) Tue Sep 17 13:34:22 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4900) Tue Sep 17 13:34:22 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4900) Tue Sep 17 13:34:22 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4900) Tue Sep 17 13:34:22 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4900) Tue Sep 17 13:34:22 2024: Debug:   Airespace-Wlan-Id = 2
(4900) Tue Sep 17 13:34:22 2024: Debug:   Service-Type = Framed-User
(4900) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 1300
(4900) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4900) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Type:0 = VLAN
(4900) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4900) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4900) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x02010010013230313931303130323830
(4900) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x2bdc556ad75fd9afb64153a9f334d764
(4900) Tue Sep 17 13:34:22 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4900) Tue Sep 17 13:34:22 2024: Debug:   authorize {
(4900) Tue Sep 17 13:34:22 2024: Debug:     policy filter_username {
(4900) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name) {
(4900) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  -> TRUE
(4900) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  {
(4900) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /) {
(4900) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4900) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4900) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4900) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4900) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4900) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4900) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4900) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4900) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4900) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /@\./)  {
(4900) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4900) Tue Sep 17 13:34:22 2024: Debug:       } # if (&User-Name)  = notfound
(4900) Tue Sep 17 13:34:22 2024: Debug:     } # policy filter_username  
= notfound
(4900) Tue Sep 17 13:34:22 2024: Debug:     [preprocess] = ok
(4900) Tue Sep 17 13:34:22 2024: Debug:     [chap] = noop
(4900) Tue Sep 17 13:34:22 2024: Debug:     [mschap] = noop
(4900) Tue Sep 17 13:34:22 2024: Debug:     [digest] = noop
(4900) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4900) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4900) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4900) Tue Sep 17 13:34:22 2024: Debug:     [suffix] = noop
(4900) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 1 length 16
(4900) Tue Sep 17 13:34:22 2024: Debug: eap: EAP-Identity reply,  
returning 'ok' so we can short-circuit the rest of authorize
(4900) Tue Sep 17 13:34:22 2024: Debug:     [eap] = ok
(4900) Tue Sep 17 13:34:22 2024: Debug:   } # authorize = ok
(4900) Tue Sep 17 13:34:22 2024: Debug: Found Auth-Type = eap
(4900) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4900) Tue Sep 17 13:34:22 2024: Debug:   authenticate {
(4900) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP Identity (1)
(4900) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule eap_md5  
to process data
(4900) Tue Sep 17 13:34:22 2024: Debug: eap_md5: Issuing MD5 Challenge
(4900) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 2 length 22
(4900) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x739029df73922dbd
(4900) Tue Sep 17 13:34:22 2024: Debug:     [eap] = handled
(4900) Tue Sep 17 13:34:22 2024: Debug:   } # authenticate = handled
(4900) Tue Sep 17 13:34:22 2024: Debug: Using Post-Auth-Type Challenge
(4900) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4900) Tue Sep 17 13:34:22 2024: Debug:   Challenge { ... } # empty  
sub-section is ignored
(4900) Tue Sep 17 13:34:22 2024: Debug: Sent Access-Challenge Id 94  
from 10.1.0.22:1812 to 10.1.0.14:34441 length 80
(4900) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x010200160410b8d6ac66fdeae53dad33f4a2cbe9712b
(4900) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4900) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df73922dbdedd976aca8f84267
(4900) Tue Sep 17 13:34:22 2024: Debug: Finished request
(4902) Tue Sep 17 13:34:22 2024: Debug: Received Access-Request Id 95  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 302
(4902) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4902) Tue Sep 17 13:34:22 2024: Debug:   Chargeable-User-Identity = 0x08
(4902) Tue Sep 17 13:34:22 2024: Debug:   Location-Capable = Civic-Location
(4902) Tue Sep 17 13:34:22 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4902) Tue Sep 17 13:34:22 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4902) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port = 1
(4902) Tue Sep 17 13:34:22 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4902) Tue Sep 17 13:34:22 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4902) Tue Sep 17 13:34:22 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4902) Tue Sep 17 13:34:22 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4902) Tue Sep 17 13:34:22 2024: Debug:   Airespace-Wlan-Id = 2
(4902) Tue Sep 17 13:34:22 2024: Debug:   Service-Type = Framed-User
(4902) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 1300
(4902) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4902) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Type:0 = VLAN
(4902) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4902) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4902) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message = 0x020200060319
(4902) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df73922dbdedd976aca8f84267
(4902) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0xba3d8a4c85964018af870684df52b5ed
(4902) Tue Sep 17 13:34:22 2024: Debug: session-state: No cached attributes
(4902) Tue Sep 17 13:34:22 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4902) Tue Sep 17 13:34:22 2024: Debug:   authorize {
(4902) Tue Sep 17 13:34:22 2024: Debug:     policy filter_username {
(4902) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name) {
(4902) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  -> TRUE
(4902) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  {
(4902) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /) {
(4902) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4902) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4902) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4902) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4902) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4902) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4902) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4902) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4902) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4902) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /@\./)  {
(4902) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4902) Tue Sep 17 13:34:22 2024: Debug:       } # if (&User-Name)  = notfound
(4902) Tue Sep 17 13:34:22 2024: Debug:     } # policy filter_username  
= notfound
(4902) Tue Sep 17 13:34:22 2024: Debug:     [preprocess] = ok
(4902) Tue Sep 17 13:34:22 2024: Debug:     [chap] = noop
(4902) Tue Sep 17 13:34:22 2024: Debug:     [mschap] = noop
(4902) Tue Sep 17 13:34:22 2024: Debug:     [digest] = noop
(4902) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4902) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4902) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4902) Tue Sep 17 13:34:22 2024: Debug:     [suffix] = noop
(4902) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 2 length 6
(4902) Tue Sep 17 13:34:22 2024: Debug: eap: No EAP Start, assuming  
it's an on-going EAP conversation
(4902) Tue Sep 17 13:34:22 2024: Debug:     [eap] = updated
(4902) Tue Sep 17 13:34:22 2024: Debug:     [files] = noop
(4902) Tue Sep 17 13:34:22 2024: Debug: ldap: EXPAND  
(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}})
(4902) Tue Sep 17 13:34:22 2024: Debug: ldap:    -->  
(sAMAccountName=20191010280)
(4902) Tue Sep 17 13:34:22 2024: Debug: ldap: Performing search in  
"DC=adm,DC=ifsul,DC=edu,DC=br" with filter  
"(sAMAccountName=20191010280)", scope "sub"
(4902) Tue Sep 17 13:34:22 2024: Debug: ldap: Waiting for search result...
(4902) Tue Sep 17 13:34:22 2024: Debug: ldap: User object found at DN  
"CN=Roger Miranda  
Muller,OU=Students,OU=Users,OU=CampusPelotas,DC=adm,DC=ifsul,DC=edu,DC=br"
(4902) Tue Sep 17 13:34:22 2024: Debug: ldap: Processing user attributes
(4902) Tue Sep 17 13:34:22 2024: Debug:     [ldap] = ok
(4902) Tue Sep 17 13:34:22 2024: Debug:     if ((ok || updated) &&  
User-Password && !control:Auth-Type) {
(4902) Tue Sep 17 13:34:22 2024: Debug:     if ((ok || updated) &&  
User-Password && !control:Auth-Type)  -> FALSE
(4902) Tue Sep 17 13:34:22 2024: Debug:     [expiration] = noop
(4902) Tue Sep 17 13:34:22 2024: Debug:     [logintime] = noop
(4902) Tue Sep 17 13:34:22 2024: Debug:     [pap] = noop
(4902) Tue Sep 17 13:34:22 2024: Debug:   } # authorize = updated
(4902) Tue Sep 17 13:34:22 2024: Debug: Found Auth-Type = eap
(4902) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4902) Tue Sep 17 13:34:22 2024: Debug:   authenticate {
(4902) Tue Sep 17 13:34:22 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4902) Tue Sep 17 13:34:22 2024: Debug: eap: Finished EAP session with  
state 0x739029df73922dbd
(4902) Tue Sep 17 13:34:22 2024: Debug: eap: Previous EAP request  
found for state 0x739029df73922dbd, released from the list
(4902) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP NAK (3)
(4902) Tue Sep 17 13:34:22 2024: Debug: eap: Found mutually acceptable  
type PEAP (25)
(4902) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule  
eap_peap to process data
(4902) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Initiating new session
(4902) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 3 length 6
(4902) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x739029df729330bd
(4902) Tue Sep 17 13:34:22 2024: Debug:     [eap] = handled
(4902) Tue Sep 17 13:34:22 2024: Debug:   } # authenticate = handled
(4902) Tue Sep 17 13:34:22 2024: Debug: Using Post-Auth-Type Challenge
(4902) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4902) Tue Sep 17 13:34:22 2024: Debug:   Challenge { ... } # empty  
sub-section is ignored
(4902) Tue Sep 17 13:34:22 2024: Debug: session-state: Saving cached  
attributes
(4902) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 994
(4902) Tue Sep 17 13:34:22 2024: Debug: Sent Access-Challenge Id 95  
from 10.1.0.22:1812 to 10.1.0.14:34441 length 64
(4902) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message = 0x010300061920
(4902) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4902) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df729330bdedd976aca8f84267
(4902) Tue Sep 17 13:34:22 2024: Debug: Finished request
(4904) Tue Sep 17 13:34:22 2024: Debug: Received Access-Request Id 96  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 437
(4904) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4904) Tue Sep 17 13:34:22 2024: Debug:   Chargeable-User-Identity = 0x08
(4904) Tue Sep 17 13:34:22 2024: Debug:   Location-Capable = Civic-Location
(4904) Tue Sep 17 13:34:22 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4904) Tue Sep 17 13:34:22 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4904) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port = 1
(4904) Tue Sep 17 13:34:22 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4904) Tue Sep 17 13:34:22 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4904) Tue Sep 17 13:34:22 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4904) Tue Sep 17 13:34:22 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4904) Tue Sep 17 13:34:22 2024: Debug:   Airespace-Wlan-Id = 2
(4904) Tue Sep 17 13:34:22 2024: Debug:   Service-Type = Framed-User
(4904) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 1300
(4904) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4904) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Type:0 = VLAN
(4904) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4904) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4904) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x0203008d198000000083160301007e0100007a0303548558ca9b3c18e35359b588cfd907bc8bf7607fa38c975037f5f51183ea4d4b00001ec02bc02fc02cc030cca9cca8c009c013c00ac014009c009d002f0035000a0100003300170000ff01000100000a00080006001d00170018000b00020100000d00140012040308040401050308050501080606010201
(4904) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df729330bdedd976aca8f84267
(4904) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0xf539724d36dcbbf3118ee59ac20db217
(4904) Tue Sep 17 13:34:22 2024: Debug: Restoring &session-state
(4904) Tue Sep 17 13:34:22 2024: Debug:   &session-state:Framed-MTU = 994
(4904) Tue Sep 17 13:34:22 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4904) Tue Sep 17 13:34:22 2024: Debug:   authorize {
(4904) Tue Sep 17 13:34:22 2024: Debug:     policy filter_username {
(4904) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name) {
(4904) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  -> TRUE
(4904) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  {
(4904) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /) {
(4904) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4904) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4904) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4904) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4904) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4904) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4904) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4904) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4904) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4904) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /@\./)  {
(4904) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4904) Tue Sep 17 13:34:22 2024: Debug:       } # if (&User-Name)  = notfound
(4904) Tue Sep 17 13:34:22 2024: Debug:     } # policy filter_username  
= notfound
(4904) Tue Sep 17 13:34:22 2024: Debug:     [preprocess] = ok
(4904) Tue Sep 17 13:34:22 2024: Debug:     [chap] = noop
(4904) Tue Sep 17 13:34:22 2024: Debug:     [mschap] = noop
(4904) Tue Sep 17 13:34:22 2024: Debug:     [digest] = noop
(4904) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4904) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4904) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4904) Tue Sep 17 13:34:22 2024: Debug:     [suffix] = noop
(4904) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 3 length 141
(4904) Tue Sep 17 13:34:22 2024: Debug: eap: Continuing tunnel setup
(4904) Tue Sep 17 13:34:22 2024: Debug:     [eap] = ok
(4904) Tue Sep 17 13:34:22 2024: Debug:   } # authorize = ok
(4904) Tue Sep 17 13:34:22 2024: Debug: Found Auth-Type = eap
(4904) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4904) Tue Sep 17 13:34:22 2024: Debug:   authenticate {
(4904) Tue Sep 17 13:34:22 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4904) Tue Sep 17 13:34:22 2024: Debug: eap: Finished EAP session with  
state 0x739029df729330bd
(4904) Tue Sep 17 13:34:22 2024: Debug: eap: Previous EAP request  
found for state 0x739029df729330bd, released from the list
(4904) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP PEAP (25)
(4904) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule  
eap_peap to process data
(4904) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) EAP Peer says  
that the final record size will be 131 bytes
(4904) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) EAP Got all  
data (131 bytes)
(4904) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - before SSL initialization
(4904) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server before SSL initialization
(4904) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server before SSL initialization
(4904) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server SSLv3/TLS read client hello
(4904) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server SSLv3/TLS write server hello
(4904) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server SSLv3/TLS write certificate
(4904) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server SSLv3/TLS write key exchange
(4904) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server SSLv3/TLS write server done
(4904) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Server : Need  
to read more data: SSLv3/TLS write server done
(4904) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) In Handshake Phase
(4904) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 4 length 1004
(4904) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x739029df719430bd
(4904) Tue Sep 17 13:34:22 2024: Debug:     [eap] = handled
(4904) Tue Sep 17 13:34:22 2024: Debug:   } # authenticate = handled
(4904) Tue Sep 17 13:34:22 2024: Debug: Using Post-Auth-Type Challenge
(4904) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4904) Tue Sep 17 13:34:22 2024: Debug:   Challenge { ... } # empty  
sub-section is ignored
(4904) Tue Sep 17 13:34:22 2024: Debug: session-state: Saving cached  
attributes
(4904) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 994
(4904) Tue Sep 17 13:34:22 2024: Debug: Sent Access-Challenge Id 96  
from 10.1.0.22:1812 to 10.1.0.14:34441 length 1068
(4904) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x010403ec19c00000122d160303003d020000390303c188615242a9826441db470799b10b00630ddf90eb696713444f574e4752440100c02f000011ff01000100000b0004030001020017000016030310ac0b0010a80010a50006f3308206ef308205d7a003020102020c4a70f97b813476897264aa5e300d06092a864886f70d01010b05003064310b30090603550406130242523131302f060355040a132852656465204e6163696f6e616c20646520456e73696e6f2065205065737175697361202d20524e503122302006035504031319524e5020494350456475204f562053534c2043412032303139301e170d3234303331353137343630325a170d3235303431363137343630315a30819e310b3009060355040613024252311a30180603550408131152696f204772616e646520646f2053756c3110300e0603550407130750656c6f746173313a3038060355040a1331494e5354495455544f204645444552414c2053554c2d52494f2d4752414e44454e5345
(4904) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4904) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df719430bdedd976aca8f84267
(4904) Tue Sep 17 13:34:22 2024: Debug: Finished request
(4911) Tue Sep 17 13:34:22 2024: Debug: Received Access-Request Id 97  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 302
(4911) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4911) Tue Sep 17 13:34:22 2024: Debug:   Chargeable-User-Identity = 0x08
(4911) Tue Sep 17 13:34:22 2024: Debug:   Location-Capable = Civic-Location
(4911) Tue Sep 17 13:34:22 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4911) Tue Sep 17 13:34:22 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4911) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port = 1
(4911) Tue Sep 17 13:34:22 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4911) Tue Sep 17 13:34:22 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4911) Tue Sep 17 13:34:22 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4911) Tue Sep 17 13:34:22 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4911) Tue Sep 17 13:34:22 2024: Debug:   Airespace-Wlan-Id = 2
(4911) Tue Sep 17 13:34:22 2024: Debug:   Service-Type = Framed-User
(4911) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 1300
(4911) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4911) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Type:0 = VLAN
(4911) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4911) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4911) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message = 0x020400061900
(4911) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df719430bdedd976aca8f84267
(4911) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0xc2b8ff519169fbe8906ac5348dc8d1dd
(4911) Tue Sep 17 13:34:22 2024: Debug: Restoring &session-state
(4911) Tue Sep 17 13:34:22 2024: Debug:   &session-state:Framed-MTU = 994
(4911) Tue Sep 17 13:34:22 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4911) Tue Sep 17 13:34:22 2024: Debug:   authorize {
(4911) Tue Sep 17 13:34:22 2024: Debug:     policy filter_username {
(4911) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name) {
(4911) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  -> TRUE
(4911) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  {
(4911) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /) {
(4911) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4911) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4911) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4911) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4911) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4911) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4911) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4911) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4911) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4911) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /@\./)  {
(4911) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4911) Tue Sep 17 13:34:22 2024: Debug:       } # if (&User-Name)  = notfound
(4911) Tue Sep 17 13:34:22 2024: Debug:     } # policy filter_username  
= notfound
(4911) Tue Sep 17 13:34:22 2024: Debug:     [preprocess] = ok
(4911) Tue Sep 17 13:34:22 2024: Debug:     [chap] = noop
(4911) Tue Sep 17 13:34:22 2024: Debug:     [mschap] = noop
(4911) Tue Sep 17 13:34:22 2024: Debug:     [digest] = noop
(4911) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4911) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4911) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4911) Tue Sep 17 13:34:22 2024: Debug:     [suffix] = noop
(4911) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 4 length 6
(4911) Tue Sep 17 13:34:22 2024: Debug: eap: Continuing tunnel setup
(4911) Tue Sep 17 13:34:22 2024: Debug:     [eap] = ok
(4911) Tue Sep 17 13:34:22 2024: Debug:   } # authorize = ok
(4911) Tue Sep 17 13:34:22 2024: Debug: Found Auth-Type = eap
(4911) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4911) Tue Sep 17 13:34:22 2024: Debug:   authenticate {
(4911) Tue Sep 17 13:34:22 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4911) Tue Sep 17 13:34:22 2024: Debug: eap: Finished EAP session with  
state 0x739029df719430bd
(4911) Tue Sep 17 13:34:22 2024: Debug: eap: Previous EAP request  
found for state 0x739029df719430bd, released from the list
(4911) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP PEAP (25)
(4911) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule  
eap_peap to process data
(4911) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Peer ACKed our  
handshake fragment
(4911) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 5 length 1000
(4911) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x739029df709530bd
(4911) Tue Sep 17 13:34:22 2024: Debug:     [eap] = handled
(4911) Tue Sep 17 13:34:22 2024: Debug:   } # authenticate = handled
(4911) Tue Sep 17 13:34:22 2024: Debug: Using Post-Auth-Type Challenge
(4911) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4911) Tue Sep 17 13:34:22 2024: Debug:   Challenge { ... } # empty  
sub-section is ignored
(4911) Tue Sep 17 13:34:22 2024: Debug: session-state: Saving cached  
attributes
(4911) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 994
(4911) Tue Sep 17 13:34:22 2024: Debug: Sent Access-Challenge Id 97  
from 10.1.0.22:1812 to 10.1.0.14:34441 length 1064
(4911) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x010503e819400603551d1f043c303a3038a036a0348632687474703a2f2f63726c2e676c6f62616c7369676e2e636f6d2f726e706963706564756f7673736c6361323031392e63726c30270603551d110420301e821c626966726f73742e70656c6f7461732e696673756c2e6564752e6272301d0603551d250416301406082b0601050507030106082b06010505070302301f0603551d23041830168014ab30c707284bcb7a8e5bfe6169f7d47ab2859b48301d0603551d0e041604143d50ba6e59d01260689e980c37854032a31da29f3082017f060a2b06010401d6790204020482016f0482016b0169007700a2e30ae445efbdad9b7e38ed47677753d7825b8494d72b5e1b2cc4b950a447e70000018e4338912a0000040300483046022100d98d67469a7fc52fe0ff306bbc3b250db1b46fd5c286e49e0fc030b62421952b022100f2c71aa49654236ef8f11973c8ff14a888b4c378d7fac2022e22c476fbe9271e0077004e75a3275c9a10c3385b6cd4df3f52eb
(4911) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4911) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df709530bdedd976aca8f84267
(4911) Tue Sep 17 13:34:22 2024: Debug: Finished request
(4915) Tue Sep 17 13:34:22 2024: Debug: Received Access-Request Id 98  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 302
(4915) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4915) Tue Sep 17 13:34:22 2024: Debug:   Chargeable-User-Identity = 0x08
(4915) Tue Sep 17 13:34:22 2024: Debug:   Location-Capable = Civic-Location
(4915) Tue Sep 17 13:34:22 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4915) Tue Sep 17 13:34:22 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4915) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port = 1
(4915) Tue Sep 17 13:34:22 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4915) Tue Sep 17 13:34:22 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4915) Tue Sep 17 13:34:22 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4915) Tue Sep 17 13:34:22 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4915) Tue Sep 17 13:34:22 2024: Debug:   Airespace-Wlan-Id = 2
(4915) Tue Sep 17 13:34:22 2024: Debug:   Service-Type = Framed-User
(4915) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 1300
(4915) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4915) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Type:0 = VLAN
(4915) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4915) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4915) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message = 0x020500061900
(4915) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df709530bdedd976aca8f84267
(4915) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0xf869cefbbfdc0659e75ec25606aef2ac
(4915) Tue Sep 17 13:34:22 2024: Debug: Restoring &session-state
(4915) Tue Sep 17 13:34:22 2024: Debug:   &session-state:Framed-MTU = 994
(4915) Tue Sep 17 13:34:22 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4915) Tue Sep 17 13:34:22 2024: Debug:   authorize {
(4915) Tue Sep 17 13:34:22 2024: Debug:     policy filter_username {
(4915) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name) {
(4915) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  -> TRUE
(4915) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  {
(4915) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /) {
(4915) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4915) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4915) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4915) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4915) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4915) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4915) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4915) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4915) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4915) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /@\./)  {
(4915) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4915) Tue Sep 17 13:34:22 2024: Debug:       } # if (&User-Name)  = notfound
(4915) Tue Sep 17 13:34:22 2024: Debug:     } # policy filter_username  
= notfound
(4915) Tue Sep 17 13:34:22 2024: Debug:     [preprocess] = ok
(4915) Tue Sep 17 13:34:22 2024: Debug:     [chap] = noop
(4915) Tue Sep 17 13:34:22 2024: Debug:     [mschap] = noop
(4915) Tue Sep 17 13:34:22 2024: Debug:     [digest] = noop
(4915) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4915) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4915) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4915) Tue Sep 17 13:34:22 2024: Debug:     [suffix] = noop
(4915) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 5 length 6
(4915) Tue Sep 17 13:34:22 2024: Debug: eap: Continuing tunnel setup
(4915) Tue Sep 17 13:34:22 2024: Debug:     [eap] = ok
(4915) Tue Sep 17 13:34:22 2024: Debug:   } # authorize = ok
(4915) Tue Sep 17 13:34:22 2024: Debug: Found Auth-Type = eap
(4915) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4915) Tue Sep 17 13:34:22 2024: Debug:   authenticate {
(4915) Tue Sep 17 13:34:22 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4915) Tue Sep 17 13:34:22 2024: Debug: eap: Finished EAP session with  
state 0x739029df709530bd
(4915) Tue Sep 17 13:34:22 2024: Debug: eap: Previous EAP request  
found for state 0x739029df709530bd, released from the list
(4915) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP PEAP (25)
(4915) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule  
eap_peap to process data
(4915) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Peer ACKed our  
handshake fragment
(4915) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 6 length 1000
(4915) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x739029df779630bd
(4915) Tue Sep 17 13:34:22 2024: Debug:     [eap] = handled
(4915) Tue Sep 17 13:34:22 2024: Debug:   } # authenticate = handled
(4915) Tue Sep 17 13:34:22 2024: Debug: Using Post-Auth-Type Challenge
(4915) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4915) Tue Sep 17 13:34:22 2024: Debug:   Challenge { ... } # empty  
sub-section is ignored
(4915) Tue Sep 17 13:34:22 2024: Debug: session-state: Saving cached  
attributes
(4915) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 994
(4915) Tue Sep 17 13:34:22 2024: Debug: Sent Access-Challenge Id 98  
from 10.1.0.22:1812 to 10.1.0.14:34441 length 1064
(4915) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x010603e81940204733301e170d3230303730353030303030305a170d3236303531353030303030305a3064310b30090603550406130242523131302f060355040a132852656465204e6163696f6e616c20646520456e73696e6f2065205065737175697361202d20524e503122302006035504031319524e5020494350456475204f562053534c204341203230313930820122300d06092a864886f70d01010105000382010f003082010a0282010100a5f2d1a55214c1b80178122f9a039d43ea96cef33dad45ba29382aa4df4936b3d50eee70e2e5fbe9a0cbe6b442c34282e9d8ddf5d3c1698a3190018f8f8ae4e0b3c8d22e68065d1bb54de3e7ae216ac74ba303c9ca51df547fa33ed195ed1bc6fee6bc45015e83ff50889c62e3378deac854283a32c7ef03d65ff7ac16f80cb9c049a61b086634b49350bc0a14b633af13688ab01f81216a3af792138b63ae916e22e6588ff139f3bb694f5e2c3e494af22b9099b7dedf625db19f6450a8003a34e76851f74b5c
(4915) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4915) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df779630bdedd976aca8f84267
(4915) Tue Sep 17 13:34:22 2024: Debug: Finished request
(4918) Tue Sep 17 13:34:22 2024: Debug: Received Access-Request Id 99  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 302
(4918) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4918) Tue Sep 17 13:34:22 2024: Debug:   Chargeable-User-Identity = 0x08
(4918) Tue Sep 17 13:34:22 2024: Debug:   Location-Capable = Civic-Location
(4918) Tue Sep 17 13:34:22 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4918) Tue Sep 17 13:34:22 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4918) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port = 1
(4918) Tue Sep 17 13:34:22 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4918) Tue Sep 17 13:34:22 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4918) Tue Sep 17 13:34:22 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4918) Tue Sep 17 13:34:22 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4918) Tue Sep 17 13:34:22 2024: Debug:   Airespace-Wlan-Id = 2
(4918) Tue Sep 17 13:34:22 2024: Debug:   Service-Type = Framed-User
(4918) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 1300
(4918) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4918) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Type:0 = VLAN
(4918) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4918) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4918) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message = 0x020600061900
(4918) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df779630bdedd976aca8f84267
(4918) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x1bc5c2e2221f34cd9cdfc9f6ba121074
(4918) Tue Sep 17 13:34:22 2024: Debug: Restoring &session-state
(4918) Tue Sep 17 13:34:22 2024: Debug:   &session-state:Framed-MTU = 994
(4918) Tue Sep 17 13:34:22 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4918) Tue Sep 17 13:34:22 2024: Debug:   authorize {
(4918) Tue Sep 17 13:34:22 2024: Debug:     policy filter_username {
(4918) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name) {
(4918) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  -> TRUE
(4918) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  {
(4918) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /) {
(4918) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4918) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4918) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4918) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4918) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4918) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4918) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4918) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4918) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4918) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /@\./)  {
(4918) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4918) Tue Sep 17 13:34:22 2024: Debug:       } # if (&User-Name)  = notfound
(4918) Tue Sep 17 13:34:22 2024: Debug:     } # policy filter_username  
= notfound
(4918) Tue Sep 17 13:34:22 2024: Debug:     [preprocess] = ok
(4918) Tue Sep 17 13:34:22 2024: Debug:     [chap] = noop
(4918) Tue Sep 17 13:34:22 2024: Debug:     [mschap] = noop
(4918) Tue Sep 17 13:34:22 2024: Debug:     [digest] = noop
(4918) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4918) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4918) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4918) Tue Sep 17 13:34:22 2024: Debug:     [suffix] = noop
(4918) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 6 length 6
(4918) Tue Sep 17 13:34:22 2024: Debug: eap: Continuing tunnel setup
(4918) Tue Sep 17 13:34:22 2024: Debug:     [eap] = ok
(4918) Tue Sep 17 13:34:22 2024: Debug:   } # authorize = ok
(4918) Tue Sep 17 13:34:22 2024: Debug: Found Auth-Type = eap
(4918) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4918) Tue Sep 17 13:34:22 2024: Debug:   authenticate {
(4918) Tue Sep 17 13:34:22 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4918) Tue Sep 17 13:34:22 2024: Debug: eap: Finished EAP session with  
state 0x739029df779630bd
(4918) Tue Sep 17 13:34:22 2024: Debug: eap: Previous EAP request  
found for state 0x739029df779630bd, released from the list
(4918) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP PEAP (25)
(4918) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule  
eap_peap to process data
(4918) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Peer ACKed our  
handshake fragment
(4918) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 7 length 1000
(4918) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x739029df769730bd
(4918) Tue Sep 17 13:34:22 2024: Debug:     [eap] = handled
(4918) Tue Sep 17 13:34:22 2024: Debug:   } # authenticate = handled
(4918) Tue Sep 17 13:34:22 2024: Debug: Using Post-Auth-Type Challenge
(4918) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4918) Tue Sep 17 13:34:22 2024: Debug:   Challenge { ... } # empty  
sub-section is ignored
(4918) Tue Sep 17 13:34:22 2024: Debug: session-state: Saving cached  
attributes
(4918) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 994
(4918) Tue Sep 17 13:34:22 2024: Debug: Sent Access-Challenge Id 99  
from 10.1.0.22:1812 to 10.1.0.14:34441 length 1064
(4918) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x010703e819409f8d43b20edc0142ae6104b248449a3a6d743f5687280d4bc8bf7915435b0b2c7b3c009f31d6ef22a1afceca47fd657837c85ef7b6ed66a06c3c28e520d321b4d5757e3301f34c156c6441b4308451183b54e00291919e25e8ce3bf1d6b0e35d5bbea0e1884812c9e641725148d0fa9935a9690bf67d15652b8674c785eda31cbd88789fc78d50f37e2be5712b924f1c394e87e26450cb584bafed1ba20004ad308204a930820391a003020102021077bd0d753f2e19601bd54e0a02444676300d06092a864886f70d01010b0500304c3120301e060355040b1317476c6f62616c5369676e20526f6f74204341202d20523331133011060355040a130a476c6f62616c5369676e311330110603550403130a476c6f62616c5369676e301e170d3230303730353030303030305a170d3237303432353131303030305a3050310b300906035504061302424531193017060355040a1310476c6f62616c5369676e206e762d7361312630240603550403131d
(4918) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4918) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df769730bdedd976aca8f84267
(4918) Tue Sep 17 13:34:22 2024: Debug: Finished request
(4919) Tue Sep 17 13:34:22 2024: Debug: Received Access-Request Id 100  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 302
(4919) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4919) Tue Sep 17 13:34:22 2024: Debug:   Chargeable-User-Identity = 0x08
(4919) Tue Sep 17 13:34:22 2024: Debug:   Location-Capable = Civic-Location
(4919) Tue Sep 17 13:34:22 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4919) Tue Sep 17 13:34:22 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4919) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port = 1
(4919) Tue Sep 17 13:34:22 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4919) Tue Sep 17 13:34:22 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4919) Tue Sep 17 13:34:22 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4919) Tue Sep 17 13:34:22 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4919) Tue Sep 17 13:34:22 2024: Debug:   Airespace-Wlan-Id = 2
(4919) Tue Sep 17 13:34:22 2024: Debug:   Service-Type = Framed-User
(4919) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 1300
(4919) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4919) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Type:0 = VLAN
(4919) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4919) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4919) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message = 0x020700061900
(4919) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df769730bdedd976aca8f84267
(4919) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x7a35a55488d67fb2e24b2564ba314232
(4919) Tue Sep 17 13:34:22 2024: Debug: Restoring &session-state
(4919) Tue Sep 17 13:34:22 2024: Debug:   &session-state:Framed-MTU = 994
(4919) Tue Sep 17 13:34:22 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4919) Tue Sep 17 13:34:22 2024: Debug:   authorize {
(4919) Tue Sep 17 13:34:22 2024: Debug:     policy filter_username {
(4919) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name) {
(4919) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  -> TRUE
(4919) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  {
(4919) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /) {
(4919) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4919) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4919) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4919) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4919) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4919) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4919) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4919) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4919) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4919) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /@\./)  {
(4919) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4919) Tue Sep 17 13:34:22 2024: Debug:       } # if (&User-Name)  = notfound
(4919) Tue Sep 17 13:34:22 2024: Debug:     } # policy filter_username  
= notfound
(4919) Tue Sep 17 13:34:22 2024: Debug:     [preprocess] = ok
(4919) Tue Sep 17 13:34:22 2024: Debug:     [chap] = noop
(4919) Tue Sep 17 13:34:22 2024: Debug:     [mschap] = noop
(4919) Tue Sep 17 13:34:22 2024: Debug:     [digest] = noop
(4919) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4919) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4919) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4919) Tue Sep 17 13:34:22 2024: Debug:     [suffix] = noop
(4919) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 7 length 6
(4919) Tue Sep 17 13:34:22 2024: Debug: eap: Continuing tunnel setup
(4919) Tue Sep 17 13:34:22 2024: Debug:     [eap] = ok
(4919) Tue Sep 17 13:34:22 2024: Debug:   } # authorize = ok
(4919) Tue Sep 17 13:34:22 2024: Debug: Found Auth-Type = eap
(4919) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4919) Tue Sep 17 13:34:22 2024: Debug:   authenticate {
(4919) Tue Sep 17 13:34:22 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4919) Tue Sep 17 13:34:22 2024: Debug: eap: Finished EAP session with  
state 0x739029df769730bd
(4919) Tue Sep 17 13:34:22 2024: Debug: eap: Previous EAP request  
found for state 0x739029df769730bd, released from the list
(4919) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP PEAP (25)
(4919) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule  
eap_peap to process data
(4919) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Peer ACKed our  
handshake fragment
(4919) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 8 length 683
(4919) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x739029df759830bd
(4919) Tue Sep 17 13:34:22 2024: Debug:     [eap] = handled
(4919) Tue Sep 17 13:34:22 2024: Debug:   } # authenticate = handled
(4919) Tue Sep 17 13:34:22 2024: Debug: Using Post-Auth-Type Challenge
(4919) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4919) Tue Sep 17 13:34:22 2024: Debug:   Challenge { ... } # empty  
sub-section is ignored
(4919) Tue Sep 17 13:34:22 2024: Debug: session-state: Saving cached  
attributes
(4919) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 994
(4919) Tue Sep 17 13:34:22 2024: Debug: Sent Access-Challenge Id 100  
from 10.1.0.22:1812 to 10.1.0.14:34441 length 745
(4919) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x010802ab19006f6d2f726f6f742d72332e63726c30470603551d200440303e303c0604551d20003034303206082b06010505070201162668747470733a2f2f7777772e676c6f62616c7369676e2e636f6d2f7265706f7369746f72792f300d06092a864886f70d01010b0500038201010016f0e5418ed61a2d9f90bf226d6bef81e24f010e495b57a5c288969aa6361b6681ecb0031de28f860ebdb847430e9a6f37b162dda3880eb8d944c21495c9ecebe36109d9004b6442526701e73297cf75d7369a567980c37a3c4099af3e16faddb199280e6108b5b881c88830284a6e3f7a9a5ef3f48b0a5253624fe6805e457e798d0de3a10c4f9ef37eacf37472695ccbc536e5dd97c3482c3659682549bad785e5a0c9d0de10e996b6a7908e5ad39955ff53016eb563dce16faff3167d293def7291b83d9777647d069dc91e36305c1620227579b80329a9f72f571c502c4df1cf1f750c991ed621573e89ba13ff5e2d94af67da80122e22633da0021a7a54160303012c0c
(4919) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4919) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df759830bdedd976aca8f84267
(4919) Tue Sep 17 13:34:22 2024: Debug: Finished request
(4920) Tue Sep 17 13:34:22 2024: Debug: Received Access-Request Id 101  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 399
(4920) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4920) Tue Sep 17 13:34:22 2024: Debug:   Chargeable-User-Identity = 0x08
(4920) Tue Sep 17 13:34:22 2024: Debug:   Location-Capable = Civic-Location
(4920) Tue Sep 17 13:34:22 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4920) Tue Sep 17 13:34:22 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4920) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port = 1
(4920) Tue Sep 17 13:34:22 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4920) Tue Sep 17 13:34:22 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4920) Tue Sep 17 13:34:22 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4920) Tue Sep 17 13:34:22 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4920) Tue Sep 17 13:34:22 2024: Debug:   Airespace-Wlan-Id = 2
(4920) Tue Sep 17 13:34:22 2024: Debug:   Service-Type = Framed-User
(4920) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 1300
(4920) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4920) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Type:0 = VLAN
(4920) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4920) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4920) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x0208006719800000005d1603030025100000212036534c9bec68c6fcf6d3ad638ca8ffa38b0cd1a98f47f74a544c60d2e7b453191403030001011603030028000000000000000032b92616961104d7d35f23926d214b17dc4399576afcfac810de7f9d8309035f
(4920) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df759830bdedd976aca8f84267
(4920) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x0dad0e49ccec50e97823cd6976affe49
(4920) Tue Sep 17 13:34:22 2024: Debug: Restoring &session-state
(4920) Tue Sep 17 13:34:22 2024: Debug:   &session-state:Framed-MTU = 994
(4920) Tue Sep 17 13:34:22 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4920) Tue Sep 17 13:34:22 2024: Debug:   authorize {
(4920) Tue Sep 17 13:34:22 2024: Debug:     policy filter_username {
(4920) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name) {
(4920) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  -> TRUE
(4920) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  {
(4920) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /) {
(4920) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4920) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4920) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4920) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4920) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4920) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4920) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4920) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4920) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4920) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /@\./)  {
(4920) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4920) Tue Sep 17 13:34:22 2024: Debug:       } # if (&User-Name)  = notfound
(4920) Tue Sep 17 13:34:22 2024: Debug:     } # policy filter_username  
= notfound
(4920) Tue Sep 17 13:34:22 2024: Debug:     [preprocess] = ok
(4920) Tue Sep 17 13:34:22 2024: Debug:     [chap] = noop
(4920) Tue Sep 17 13:34:22 2024: Debug:     [mschap] = noop
(4920) Tue Sep 17 13:34:22 2024: Debug:     [digest] = noop
(4920) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4920) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4920) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4920) Tue Sep 17 13:34:22 2024: Debug:     [suffix] = noop
(4920) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 8 length 103
(4920) Tue Sep 17 13:34:22 2024: Debug: eap: Continuing tunnel setup
(4920) Tue Sep 17 13:34:22 2024: Debug:     [eap] = ok
(4920) Tue Sep 17 13:34:22 2024: Debug:   } # authorize = ok
(4920) Tue Sep 17 13:34:22 2024: Debug: Found Auth-Type = eap
(4920) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4920) Tue Sep 17 13:34:22 2024: Debug:   authenticate {
(4920) Tue Sep 17 13:34:22 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4920) Tue Sep 17 13:34:22 2024: Debug: eap: Finished EAP session with  
state 0x739029df759830bd
(4920) Tue Sep 17 13:34:22 2024: Debug: eap: Previous EAP request  
found for state 0x739029df759830bd, released from the list
(4920) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP PEAP (25)
(4920) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule  
eap_peap to process data
(4920) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) EAP Peer says  
that the final record size will be 93 bytes
(4920) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) EAP Got all  
data (93 bytes)
(4920) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server SSLv3/TLS write server done
(4920) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server SSLv3/TLS read client key exchange
(4920) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server SSLv3/TLS read change cipher spec
(4920) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server SSLv3/TLS read finished
(4920) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server SSLv3/TLS write change cipher spec
(4920) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - Server SSLv3/TLS write finished
(4920) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Handshake  
state - SSL negotiation finished successfully
(4920) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Connection Established
(4920) Tue Sep 17 13:34:22 2024: Debug: eap_peap:    
TLS-Session-Cipher-Suite = "ECDHE-RSA-AES128-GCM-SHA256"
(4920) Tue Sep 17 13:34:22 2024: Debug: eap_peap:    
TLS-Session-Version = "TLS 1.2"
(4920) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 9 length 57
(4920) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x739029df749930bd
(4920) Tue Sep 17 13:34:22 2024: Debug:     [eap] = handled
(4920) Tue Sep 17 13:34:22 2024: Debug:   } # authenticate = handled
(4920) Tue Sep 17 13:34:22 2024: Debug: Using Post-Auth-Type Challenge
(4920) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4920) Tue Sep 17 13:34:22 2024: Debug:   Challenge { ... } # empty  
sub-section is ignored
(4920) Tue Sep 17 13:34:22 2024: Debug: session-state: Saving cached  
attributes
(4920) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 994
(4920) Tue Sep 17 13:34:22 2024: Debug:   TLS-Session-Cipher-Suite =  
"ECDHE-RSA-AES128-GCM-SHA256"
(4920) Tue Sep 17 13:34:22 2024: Debug:   TLS-Session-Version = "TLS 1.2"
(4920) Tue Sep 17 13:34:22 2024: Debug: Sent Access-Challenge Id 101  
from 10.1.0.22:1812 to 10.1.0.14:34441 length 115
(4920) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x0109003919001403030001011603030028bbea5dda47acad028e4053fda633338a05dd3865a0c2c2a423b55774910df8697f241061db59aae6
(4920) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4920) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df749930bdedd976aca8f84267
(4920) Tue Sep 17 13:34:22 2024: Debug: Finished request
(4921) Tue Sep 17 13:34:22 2024: Debug: Received Access-Request Id 102  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 302
(4921) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4921) Tue Sep 17 13:34:22 2024: Debug:   Chargeable-User-Identity = 0x08
(4921) Tue Sep 17 13:34:22 2024: Debug:   Location-Capable = Civic-Location
(4921) Tue Sep 17 13:34:22 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4921) Tue Sep 17 13:34:22 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4921) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port = 1
(4921) Tue Sep 17 13:34:22 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4921) Tue Sep 17 13:34:22 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4921) Tue Sep 17 13:34:22 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4921) Tue Sep 17 13:34:22 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4921) Tue Sep 17 13:34:22 2024: Debug:   Airespace-Wlan-Id = 2
(4921) Tue Sep 17 13:34:22 2024: Debug:   Service-Type = Framed-User
(4921) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 1300
(4921) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4921) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Type:0 = VLAN
(4921) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4921) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4921) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message = 0x020900061900
(4921) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df749930bdedd976aca8f84267
(4921) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0xc42a9ab80a1d690dcb8842b8403075a3
(4921) Tue Sep 17 13:34:22 2024: Debug: Restoring &session-state
(4921) Tue Sep 17 13:34:22 2024: Debug:   &session-state:Framed-MTU = 994
(4921) Tue Sep 17 13:34:22 2024: Debug:    
&session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES128-GCM-SHA256"
(4921) Tue Sep 17 13:34:22 2024: Debug:    
&session-state:TLS-Session-Version = "TLS 1.2"
(4921) Tue Sep 17 13:34:22 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4921) Tue Sep 17 13:34:22 2024: Debug:   authorize {
(4921) Tue Sep 17 13:34:22 2024: Debug:     policy filter_username {
(4921) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name) {
(4921) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  -> TRUE
(4921) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  {
(4921) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /) {
(4921) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4921) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4921) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4921) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4921) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4921) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4921) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4921) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4921) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4921) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /@\./)  {
(4921) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4921) Tue Sep 17 13:34:22 2024: Debug:       } # if (&User-Name)  = notfound
(4921) Tue Sep 17 13:34:22 2024: Debug:     } # policy filter_username  
= notfound
(4921) Tue Sep 17 13:34:22 2024: Debug:     [preprocess] = ok
(4921) Tue Sep 17 13:34:22 2024: Debug:     [chap] = noop
(4921) Tue Sep 17 13:34:22 2024: Debug:     [mschap] = noop
(4921) Tue Sep 17 13:34:22 2024: Debug:     [digest] = noop
(4921) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4921) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4921) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4921) Tue Sep 17 13:34:22 2024: Debug:     [suffix] = noop
(4921) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 9 length 6
(4921) Tue Sep 17 13:34:22 2024: Debug: eap: Continuing tunnel setup
(4921) Tue Sep 17 13:34:22 2024: Debug:     [eap] = ok
(4921) Tue Sep 17 13:34:22 2024: Debug:   } # authorize = ok
(4921) Tue Sep 17 13:34:22 2024: Debug: Found Auth-Type = eap
(4921) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4921) Tue Sep 17 13:34:22 2024: Debug:   authenticate {
(4921) Tue Sep 17 13:34:22 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4921) Tue Sep 17 13:34:22 2024: Debug: eap: Finished EAP session with  
state 0x739029df749930bd
(4921) Tue Sep 17 13:34:22 2024: Debug: eap: Previous EAP request  
found for state 0x739029df749930bd, released from the list
(4921) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP PEAP (25)
(4921) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule  
eap_peap to process data
(4921) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) Peer ACKed our  
handshake fragment.  handshake is finished
(4921) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Session established.  
  Decoding tunneled attributes
(4921) Tue Sep 17 13:34:22 2024: Debug: eap_peap: PEAP state TUNNEL  
ESTABLISHED
(4921) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 10 length 40
(4921) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x739029df7b9a30bd
(4921) Tue Sep 17 13:34:22 2024: Debug:     [eap] = handled
(4921) Tue Sep 17 13:34:22 2024: Debug:   } # authenticate = handled
(4921) Tue Sep 17 13:34:22 2024: Debug: Using Post-Auth-Type Challenge
(4921) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4921) Tue Sep 17 13:34:22 2024: Debug:   Challenge { ... } # empty  
sub-section is ignored
(4921) Tue Sep 17 13:34:22 2024: Debug: session-state: Saving cached  
attributes
(4921) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 994
(4921) Tue Sep 17 13:34:22 2024: Debug:   TLS-Session-Cipher-Suite =  
"ECDHE-RSA-AES128-GCM-SHA256"
(4921) Tue Sep 17 13:34:22 2024: Debug:   TLS-Session-Version = "TLS 1.2"
(4921) Tue Sep 17 13:34:22 2024: Debug: Sent Access-Challenge Id 102  
from 10.1.0.22:1812 to 10.1.0.14:34441 length 98
(4921) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x010a00281900170303001dbbea5dda47acad032c6aefa9b24f3b2e128911fdd562f2fcaf5060fe1f
(4921) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4921) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df7b9a30bdedd976aca8f84267
(4921) Tue Sep 17 13:34:22 2024: Debug: Finished request
(4922) Tue Sep 17 13:34:22 2024: Debug: Received Access-Request Id 103  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 343
(4922) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4922) Tue Sep 17 13:34:22 2024: Debug:   Chargeable-User-Identity = 0x08
(4922) Tue Sep 17 13:34:22 2024: Debug:   Location-Capable = Civic-Location
(4922) Tue Sep 17 13:34:22 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4922) Tue Sep 17 13:34:22 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4922) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port = 1
(4922) Tue Sep 17 13:34:22 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4922) Tue Sep 17 13:34:22 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4922) Tue Sep 17 13:34:22 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4922) Tue Sep 17 13:34:22 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4922) Tue Sep 17 13:34:22 2024: Debug:   Airespace-Wlan-Id = 2
(4922) Tue Sep 17 13:34:22 2024: Debug:   Service-Type = Framed-User
(4922) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 1300
(4922) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4922) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Type:0 = VLAN
(4922) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4922) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4922) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x020a002f190017030300240000000000000001029a79bafacd80bd0974d579f28366f216e92cde1a2af0cba0f91d22
(4922) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df7b9a30bdedd976aca8f84267
(4922) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x7ca25417d80f44a57ce5dc8bfda58fd6
(4922) Tue Sep 17 13:34:22 2024: Debug: Restoring &session-state
(4922) Tue Sep 17 13:34:22 2024: Debug:   &session-state:Framed-MTU = 994
(4922) Tue Sep 17 13:34:22 2024: Debug:    
&session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES128-GCM-SHA256"
(4922) Tue Sep 17 13:34:22 2024: Debug:    
&session-state:TLS-Session-Version = "TLS 1.2"
(4922) Tue Sep 17 13:34:22 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4922) Tue Sep 17 13:34:22 2024: Debug:   authorize {
(4922) Tue Sep 17 13:34:22 2024: Debug:     policy filter_username {
(4922) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name) {
(4922) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  -> TRUE
(4922) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  {
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /) {
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4922) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4922) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /@\./)  {
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4922) Tue Sep 17 13:34:22 2024: Debug:       } # if (&User-Name)  = notfound
(4922) Tue Sep 17 13:34:22 2024: Debug:     } # policy filter_username  
= notfound
(4922) Tue Sep 17 13:34:22 2024: Debug:     [preprocess] = ok
(4922) Tue Sep 17 13:34:22 2024: Debug:     [chap] = noop
(4922) Tue Sep 17 13:34:22 2024: Debug:     [mschap] = noop
(4922) Tue Sep 17 13:34:22 2024: Debug:     [digest] = noop
(4922) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4922) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4922) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4922) Tue Sep 17 13:34:22 2024: Debug:     [suffix] = noop
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 10 length 47
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: Continuing tunnel setup
(4922) Tue Sep 17 13:34:22 2024: Debug:     [eap] = ok
(4922) Tue Sep 17 13:34:22 2024: Debug:   } # authorize = ok
(4922) Tue Sep 17 13:34:22 2024: Debug: Found Auth-Type = eap
(4922) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4922) Tue Sep 17 13:34:22 2024: Debug:   authenticate {
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: Finished EAP session with  
state 0x739029df7b9a30bd
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: Previous EAP request  
found for state 0x739029df7b9a30bd, released from the list
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP PEAP (25)
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule  
eap_peap to process data
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) EAP Done  
initial handshake
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Session established.  
  Decoding tunneled attributes
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap: PEAP state WAITING  
FOR INNER IDENTITY
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Identity - 20191010280
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Got inner identity  
'20191010280'
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Setting default EAP  
type for tunneled EAP session
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Got tunneled request
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap:   EAP-Message =  
0x020a0010013230313931303130323830
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Setting User-Name to  
20191010280
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Sending tunneled  
request to inner-tunnel
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap:   EAP-Message =  
0x020a0010013230313931303130323830
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap:    
FreeRADIUS-Proxied-To = 127.0.0.1
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap:   User-Name = "20191010280"
(4922) Tue Sep 17 13:34:22 2024: Debug: Virtual server inner-tunnel  
received request
(4922) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x020a0010013230313931303130323830
(4922) Tue Sep 17 13:34:22 2024: Debug:   FreeRADIUS-Proxied-To = 127.0.0.1
(4922) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4922) Tue Sep 17 13:34:22 2024: WARNING: Outer and inner identities  
are the same.  User privacy is compromised.
(4922) Tue Sep 17 13:34:22 2024: Debug: server inner-tunnel {
(4922) Tue Sep 17 13:34:22 2024: Debug:   # Executing section  
authorize from file /etc/freeradius/3.0/sites-enabled/inner-tunnel
(4922) Tue Sep 17 13:34:22 2024: Debug:     authorize {
(4922) Tue Sep 17 13:34:22 2024: Debug:       policy filter_username {
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name) {
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name)  -> TRUE
(4922) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name)  {
(4922) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~ / /) {
(4922) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~ /  
/)  -> FALSE
(4922) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~  
/@[^@]*@/ ) {
(4922) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4922) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~ /\.\./ ) {
(4922) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~  
/\.\./ )  -> FALSE
(4922) Tue Sep 17 13:34:22 2024: Debug:           if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4922) Tue Sep 17 13:34:22 2024: Debug:           if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4922) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~ /\.$/)  {
(4922) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~  
/\.$/)   -> FALSE
(4922) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~ /@\./)  {
(4922) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~  
/@\./)   -> FALSE
(4922) Tue Sep 17 13:34:22 2024: Debug:         } # if (&User-Name)  =  
notfound
(4922) Tue Sep 17 13:34:22 2024: Debug:       } # policy  
filter_username = notfound
(4922) Tue Sep 17 13:34:22 2024: Debug:       [chap] = noop
(4922) Tue Sep 17 13:34:22 2024: Debug:       [mschap] = noop
(4922) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4922) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4922) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4922) Tue Sep 17 13:34:22 2024: Debug:       [suffix] = noop
(4922) Tue Sep 17 13:34:22 2024: Debug:       update control {
(4922) Tue Sep 17 13:34:22 2024: Debug:       } # update control = noop
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 10 length 16
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: EAP-Identity reply,  
returning 'ok' so we can short-circuit the rest of authorize
(4922) Tue Sep 17 13:34:22 2024: Debug:       [eap] = ok
(4922) Tue Sep 17 13:34:22 2024: Debug:     } # authorize = ok
(4922) Tue Sep 17 13:34:22 2024: Debug:   Found Auth-Type = eap
(4922) Tue Sep 17 13:34:22 2024: Debug:   # Executing group from file  
/etc/freeradius/3.0/sites-enabled/inner-tunnel
(4922) Tue Sep 17 13:34:22 2024: Debug:     authenticate {
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP Identity (1)
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule  
eap_mschapv2 to process data
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_mschapv2: Issuing Challenge
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 11 length 42
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x3bfdb59b3bf6afb3
(4922) Tue Sep 17 13:34:22 2024: Debug:       [eap] = handled
(4922) Tue Sep 17 13:34:22 2024: Debug:     } # authenticate = handled
(4922) Tue Sep 17 13:34:22 2024: Debug: } # server inner-tunnel
(4922) Tue Sep 17 13:34:22 2024: Debug: Virtual server sending reply
(4922) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x010b002a1a010b002510e7d0cca7f74288e2ef701acfae1c455f667265657261646975732d332e322e31
(4922) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4922) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x3bfdb59b3bf6afb3e181313f34318f40
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Got tunneled reply code 11
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap:   EAP-Message =  
0x010b002a1a010b002510e7d0cca7f74288e2ef701acfae1c455f667265657261646975732d332e322e31
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap:    
Message-Authenticator = 0x00000000000000000000000000000000
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap:   State =  
0x3bfdb59b3bf6afb3e181313f34318f40
(4922) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Got tunneled  
Access-Challenge
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 11 length 73
(4922) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x739029df7a9b30bd
(4922) Tue Sep 17 13:34:22 2024: Debug:     [eap] = handled
(4922) Tue Sep 17 13:34:22 2024: Debug:   } # authenticate = handled
(4922) Tue Sep 17 13:34:22 2024: Debug: Using Post-Auth-Type Challenge
(4922) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4922) Tue Sep 17 13:34:22 2024: Debug:   Challenge { ... } # empty  
sub-section is ignored
(4922) Tue Sep 17 13:34:22 2024: Debug: session-state: Saving cached  
attributes
(4922) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 994
(4922) Tue Sep 17 13:34:22 2024: Debug:   TLS-Session-Cipher-Suite =  
"ECDHE-RSA-AES128-GCM-SHA256"
(4922) Tue Sep 17 13:34:22 2024: Debug:   TLS-Session-Version = "TLS 1.2"
(4922) Tue Sep 17 13:34:22 2024: Debug: Sent Access-Challenge Id 103  
from 10.1.0.22:1812 to 10.1.0.14:34441 length 131
(4922) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x010b00491900170303003ebbea5dda47acad0433c29177bb953a4c489c1bd8e95ad96194e2b31b71346de1d3e415159b28f0fb285d6997c22bb60e4973746472df379e6d37937e229b
(4922) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4922) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df7a9b30bdedd976aca8f84267
(4922) Tue Sep 17 13:34:22 2024: Debug: Finished request
(4923) Tue Sep 17 13:34:22 2024: Debug: Received Access-Request Id 104  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 397
(4923) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4923) Tue Sep 17 13:34:22 2024: Debug:   Chargeable-User-Identity = 0x08
(4923) Tue Sep 17 13:34:22 2024: Debug:   Location-Capable = Civic-Location
(4923) Tue Sep 17 13:34:22 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4923) Tue Sep 17 13:34:22 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4923) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port = 1
(4923) Tue Sep 17 13:34:22 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4923) Tue Sep 17 13:34:22 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4923) Tue Sep 17 13:34:22 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4923) Tue Sep 17 13:34:22 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4923) Tue Sep 17 13:34:22 2024: Debug:   Airespace-Wlan-Id = 2
(4923) Tue Sep 17 13:34:22 2024: Debug:   Service-Type = Framed-User
(4923) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 1300
(4923) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4923) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Type:0 = VLAN
(4923) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4923) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4923) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x020b00651900170303005a00000000000000020cedfa17fcc1a7740dbfa80b11c15e0d0619c56d7ab68586dd3a16c50625f5222ba035329743d75c18cb2bd3fe41eff3867539e054a78185481528f21ddf371561d049087ade6d8a1cbdc5a5d0368c9e73cb
(4923) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df7a9b30bdedd976aca8f84267
(4923) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x478290f99e6d745fe37831b4b9816269
(4923) Tue Sep 17 13:34:22 2024: Debug: Restoring &session-state
(4923) Tue Sep 17 13:34:22 2024: Debug:   &session-state:Framed-MTU = 994
(4923) Tue Sep 17 13:34:22 2024: Debug:    
&session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES128-GCM-SHA256"
(4923) Tue Sep 17 13:34:22 2024: Debug:    
&session-state:TLS-Session-Version = "TLS 1.2"
(4923) Tue Sep 17 13:34:22 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4923) Tue Sep 17 13:34:22 2024: Debug:   authorize {
(4923) Tue Sep 17 13:34:22 2024: Debug:     policy filter_username {
(4923) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name) {
(4923) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  -> TRUE
(4923) Tue Sep 17 13:34:22 2024: Debug:       if (&User-Name)  {
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /) {
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4923) Tue Sep 17 13:34:22 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~ /@\./)  {
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:       } # if (&User-Name)  = notfound
(4923) Tue Sep 17 13:34:22 2024: Debug:     } # policy filter_username  
= notfound
(4923) Tue Sep 17 13:34:22 2024: Debug:     [preprocess] = ok
(4923) Tue Sep 17 13:34:22 2024: Debug:     [chap] = noop
(4923) Tue Sep 17 13:34:22 2024: Debug:     [mschap] = noop
(4923) Tue Sep 17 13:34:22 2024: Debug:     [digest] = noop
(4923) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4923) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4923) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4923) Tue Sep 17 13:34:22 2024: Debug:     [suffix] = noop
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 11 length 101
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Continuing tunnel setup
(4923) Tue Sep 17 13:34:22 2024: Debug:     [eap] = ok
(4923) Tue Sep 17 13:34:22 2024: Debug:   } # authorize = ok
(4923) Tue Sep 17 13:34:22 2024: Debug: Found Auth-Type = eap
(4923) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4923) Tue Sep 17 13:34:22 2024: Debug:   authenticate {
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Finished EAP session with  
state 0x739029df7a9b30bd
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Previous EAP request  
found for state 0x739029df7a9b30bd, released from the list
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP PEAP (25)
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule  
eap_peap to process data
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap: (TLS) EAP Done  
initial handshake
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Session established.  
  Decoding tunneled attributes
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap: PEAP state phase2
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap: EAP method MSCHAPv2 (26)
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Got tunneled request
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap:   EAP-Message =  
0x020b00461a020b0041315a88e99faf3711edb821ce5c9fb475bd00000000000000000f371c451b683d67362225831c62b67762d3a9be73cbd6ee003230313931303130323830
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Setting User-Name to  
20191010280
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Sending tunneled  
request to inner-tunnel
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap:   EAP-Message =  
0x020b00461a020b0041315a88e99faf3711edb821ce5c9fb475bd00000000000000000f371c451b683d67362225831c62b67762d3a9be73cbd6ee003230313931303130323830
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap:    
FreeRADIUS-Proxied-To = 127.0.0.1
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap:   User-Name = "20191010280"
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap:   State =  
0x3bfdb59b3bf6afb3e181313f34318f40
(4923) Tue Sep 17 13:34:22 2024: Debug: Virtual server inner-tunnel  
received request
(4923) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x020b00461a020b0041315a88e99faf3711edb821ce5c9fb475bd00000000000000000f371c451b683d67362225831c62b67762d3a9be73cbd6ee003230313931303130323830
(4923) Tue Sep 17 13:34:22 2024: Debug:   FreeRADIUS-Proxied-To = 127.0.0.1
(4923) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4923) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x3bfdb59b3bf6afb3e181313f34318f40
(4923) Tue Sep 17 13:34:22 2024: WARNING: Outer and inner identities  
are the same.  User privacy is compromised.
(4923) Tue Sep 17 13:34:22 2024: Debug: server inner-tunnel {
(4923) Tue Sep 17 13:34:22 2024: Debug:   session-state: No cached attributes
(4923) Tue Sep 17 13:34:22 2024: Debug:   # Executing section  
authorize from file /etc/freeradius/3.0/sites-enabled/inner-tunnel
(4923) Tue Sep 17 13:34:22 2024: Debug:     authorize {
(4923) Tue Sep 17 13:34:22 2024: Debug:       policy filter_username {
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name) {
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name)  -> TRUE
(4923) Tue Sep 17 13:34:22 2024: Debug:         if (&User-Name)  {
(4923) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~ / /) {
(4923) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~ /  
/)  -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~  
/@[^@]*@/ ) {
(4923) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~ /\.\./ ) {
(4923) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~  
/\.\./ )  -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:           if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4923) Tue Sep 17 13:34:22 2024: Debug:           if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~ /\.$/)  {
(4923) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~  
/\.$/)   -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~ /@\./)  {
(4923) Tue Sep 17 13:34:22 2024: Debug:           if (&User-Name =~  
/@\./)   -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:         } # if (&User-Name)  =  
notfound
(4923) Tue Sep 17 13:34:22 2024: Debug:       } # policy  
filter_username = notfound
(4923) Tue Sep 17 13:34:22 2024: Debug:       [chap] = noop
(4923) Tue Sep 17 13:34:22 2024: Debug:       [mschap] = noop
(4923) Tue Sep 17 13:34:22 2024: Debug: suffix: Checking for suffix after "@"
(4923) Tue Sep 17 13:34:22 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4923) Tue Sep 17 13:34:22 2024: Debug: suffix: No such realm "NULL"
(4923) Tue Sep 17 13:34:22 2024: Debug:       [suffix] = noop
(4923) Tue Sep 17 13:34:22 2024: Debug:       update control {
(4923) Tue Sep 17 13:34:22 2024: Debug:       } # update control = noop
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 11 length 70
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: No EAP Start, assuming  
it's an on-going EAP conversation
(4923) Tue Sep 17 13:34:22 2024: Debug:       [eap] = updated
(4923) Tue Sep 17 13:34:22 2024: Debug:       [files] = noop
(4923) Tue Sep 17 13:34:22 2024: Debug: ldap: EXPAND  
(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}})
(4923) Tue Sep 17 13:34:22 2024: Debug: ldap:    -->  
(sAMAccountName=20191010280)
(4923) Tue Sep 17 13:34:22 2024: Debug: ldap: Performing search in  
"DC=adm,DC=ifsul,DC=edu,DC=br" with filter  
"(sAMAccountName=20191010280)", scope "sub"
(4923) Tue Sep 17 13:34:22 2024: Debug: ldap: Waiting for search result...
(4923) Tue Sep 17 13:34:22 2024: Debug: ldap: User object found at DN  
"CN=Roger Miranda  
Muller,OU=Students,OU=Users,OU=CampusPelotas,DC=adm,DC=ifsul,DC=edu,DC=br"
(4923) Tue Sep 17 13:34:22 2024: Debug: ldap: Processing user attributes
(4923) Tue Sep 17 13:34:22 2024: Debug:       [ldap] = ok
(4923) Tue Sep 17 13:34:22 2024: Debug:       [expiration] = noop
(4923) Tue Sep 17 13:34:22 2024: Debug:       [logintime] = noop
(4923) Tue Sep 17 13:34:22 2024: Debug:       [pap] = noop
(4923) Tue Sep 17 13:34:22 2024: Debug:       if (!&control:Auth-Type  
&& &User-Password) {
(4923) Tue Sep 17 13:34:22 2024: Debug:       if (!&control:Auth-Type  
&& &User-Password)  -> FALSE
(4923) Tue Sep 17 13:34:22 2024: Debug:     } # authorize = updated
(4923) Tue Sep 17 13:34:22 2024: Debug:   Found Auth-Type = eap
(4923) Tue Sep 17 13:34:22 2024: Debug:   # Executing group from file  
/etc/freeradius/3.0/sites-enabled/inner-tunnel
(4923) Tue Sep 17 13:34:22 2024: Debug:     authenticate {
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Finished EAP session with  
state 0x3bfdb59b3bf6afb3
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Previous EAP request  
found for state 0x3bfdb59b3bf6afb3, released from the list
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Peer sent packet with  
method EAP MSCHAPv2 (26)
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Calling submodule  
eap_mschapv2 to process data
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_mschapv2: # Executing  
group from file /etc/freeradius/3.0/sites-enabled/inner-tunnel
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_mschapv2:   authenticate {
(4923) Tue Sep 17 13:34:22 2024: Debug: mschap: Creating challenge  
hash with username: 20191010280
(4923) Tue Sep 17 13:34:22 2024: Debug: mschap: Client is using MS-CHAPv2
(4923) Tue Sep 17 13:34:22 2024: Debug: mschap: Executing:  
/usr/bin/ntlm_auth --request-nt-key --allow-mschapv2  
--username=%{mschap:User-Name:-None}  
--challenge=%{%{mschap:Challenge}:-00}  
--nt-response=%{%{mschap:NT-Response}:-00}:
(4923) Tue Sep 17 13:34:22 2024: Debug: mschap: EXPAND  
--username=%{mschap:User-Name:-None}
(4923) Tue Sep 17 13:34:22 2024: Debug: mschap:    --> --username=20191010280
(4923) Tue Sep 17 13:34:22 2024: Debug: mschap: Creating challenge  
hash with username: 20191010280
(4923) Tue Sep 17 13:34:22 2024: Debug: mschap: EXPAND  
--challenge=%{%{mschap:Challenge}:-00}
(4923) Tue Sep 17 13:34:22 2024: Debug: mschap:    -->  
--challenge=7342d718cf199e8a
(4923) Tue Sep 17 13:34:22 2024: Debug: mschap: EXPAND  
--nt-response=%{%{mschap:NT-Response}:-00}
(4923) Tue Sep 17 13:34:22 2024: Debug: mschap:    -->  
--nt-response=0f371c451b683d67362225831c62b67762d3a9be73cbd6ee
(4923) Tue Sep 17 13:34:22 2024: Debug: mschap: Program returned code  
(0) and output 'NT_KEY: 793201B2B067012B796F950D73FA044D'
(4923) Tue Sep 17 13:34:22 2024: Debug: mschap: Adding MS-CHAPv2 MPPE keys
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_mschapv2:     [mschap] = ok
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_mschapv2:   } # authenticate = ok
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_mschapv2: MSCHAP Success
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 12 length 51
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x3bfdb59b3af1afb3
(4923) Tue Sep 17 13:34:22 2024: Debug:       [eap] = handled
(4923) Tue Sep 17 13:34:22 2024: Debug:     } # authenticate = handled
(4923) Tue Sep 17 13:34:22 2024: Debug: } # server inner-tunnel
(4923) Tue Sep 17 13:34:22 2024: Debug: Virtual server sending reply
(4923) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x010c00331a030b002e533d43334137303237313538453630393830413939324445433543304242314546364432454241443043
(4923) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4923) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x3bfdb59b3af1afb3e181313f34318f40
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Got tunneled reply code 11
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap:   EAP-Message =  
0x010c00331a030b002e533d43334137303237313538453630393830413939324445433543304242314546364432454241443043
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap:    
Message-Authenticator = 0x00000000000000000000000000000000
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap:   State =  
0x3bfdb59b3af1afb3e181313f34318f40
(4923) Tue Sep 17 13:34:22 2024: Debug: eap_peap: Got tunneled  
Access-Challenge
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: Sending EAP Request (code  
1) ID 12 length 82
(4923) Tue Sep 17 13:34:22 2024: Debug: eap: EAP session adding  
&reply:State = 0x739029df799c30bd
(4923) Tue Sep 17 13:34:22 2024: Debug:     [eap] = handled
(4923) Tue Sep 17 13:34:22 2024: Debug:   } # authenticate = handled
(4923) Tue Sep 17 13:34:22 2024: Debug: Using Post-Auth-Type Challenge
(4923) Tue Sep 17 13:34:22 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4923) Tue Sep 17 13:34:22 2024: Debug:   Challenge { ... } # empty  
sub-section is ignored
(4923) Tue Sep 17 13:34:22 2024: Debug: session-state: Saving cached  
attributes
(4923) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 994
(4923) Tue Sep 17 13:34:22 2024: Debug:   TLS-Session-Cipher-Suite =  
"ECDHE-RSA-AES128-GCM-SHA256"
(4923) Tue Sep 17 13:34:22 2024: Debug:   TLS-Session-Version = "TLS 1.2"
(4923) Tue Sep 17 13:34:22 2024: Debug: Sent Access-Challenge Id 104  
from 10.1.0.22:1812 to 10.1.0.14:34441 length 140
(4923) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x010c005219001703030047bbea5dda47acad05d3c2e18be742233fd8a20f129b0fa7cd7a4e3607bae410581a2b051cac4b0c308faefca8137f4943349fe0cfb38b81ba50c69cefae26d1f18a800c00d26d3a
(4923) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4923) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df799c30bdedd976aca8f84267
(4923) Tue Sep 17 13:34:22 2024: Debug: Finished request
(4948) Tue Sep 17 13:34:22 2024: Debug: Received Access-Request Id 105  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 333
(4948) Tue Sep 17 13:34:22 2024: Debug:   User-Name = "20191010280"
(4948) Tue Sep 17 13:34:22 2024: Debug:   Chargeable-User-Identity = 0x08
(4948) Tue Sep 17 13:34:22 2024: Debug:   Location-Capable = Civic-Location
(4948) Tue Sep 17 13:34:22 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4948) Tue Sep 17 13:34:22 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4948) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port = 1
(4948) Tue Sep 17 13:34:22 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4948) Tue Sep 17 13:34:22 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4948) Tue Sep 17 13:34:22 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4948) Tue Sep 17 13:34:22 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4948) Tue Sep 17 13:34:22 2024: Debug:   Airespace-Wlan-Id = 2
(4948) Tue Sep 17 13:34:22 2024: Debug:   Service-Type = Framed-User
(4948) Tue Sep 17 13:34:22 2024: Debug:   Framed-MTU = 1300
(4948) Tue Sep 17 13:34:22 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4948) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Type:0 = VLAN
(4948) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4948) Tue Sep 17 13:34:22 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4948) Tue Sep 17 13:34:22 2024: Debug:   EAP-Message =  
0x020c00251900170303001a00000000000000039bf605f87578802bc8247e3e051a7b7619e8
(4948) Tue Sep 17 13:34:22 2024: Debug:   State =  
0x739029df799c30bdedd976aca8f84267
(4948) Tue Sep 17 13:34:22 2024: Debug:   Message-Authenticator =  
0x1f15971d68d8d91294c0854acece2227
(4948) Tue Sep 17 13:34:22 2024: Debug: Restoring &session-state
(4948) Tue Sep 17 13:34:22 2024: Debug:   &session-state:Framed-MTU = 994
(4948) Tue Sep 17 13:34:22 2024: Debug:    
&session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES128-GCM-SHA256"
(4948) Tue Sep 17 13:34:22 2024: Debug:    
&session-state:TLS-Session-Version = "TLS 1.2"
(4948) Tue Sep 17 13:34:22 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4948) Tue Sep 17 13:34:22 2024: Debug:   authorize {
(4948) Tue Sep 17 13:34:22 2024: Debug:     policy filter_username {
(4948) Tue Sep 17 13:34:23 2024: Debug:       if (&User-Name) {
(4948) Tue Sep 17 13:34:23 2024: Debug:       if (&User-Name)  -> TRUE
(4948) Tue Sep 17 13:34:23 2024: Debug:       if (&User-Name)  {
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~ / /) {
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4948) Tue Sep 17 13:34:23 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~ /@\./)  {
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:       } # if (&User-Name)  = notfound
(4948) Tue Sep 17 13:34:23 2024: Debug:     } # policy filter_username  
= notfound
(4948) Tue Sep 17 13:34:23 2024: Debug:     [preprocess] = ok
(4948) Tue Sep 17 13:34:23 2024: Debug:     [chap] = noop
(4948) Tue Sep 17 13:34:23 2024: Debug:     [mschap] = noop
(4948) Tue Sep 17 13:34:23 2024: Debug:     [digest] = noop
(4948) Tue Sep 17 13:34:23 2024: Debug: suffix: Checking for suffix after "@"
(4948) Tue Sep 17 13:34:23 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4948) Tue Sep 17 13:34:23 2024: Debug: suffix: No such realm "NULL"
(4948) Tue Sep 17 13:34:23 2024: Debug:     [suffix] = noop
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 12 length 37
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Continuing tunnel setup
(4948) Tue Sep 17 13:34:23 2024: Debug:     [eap] = ok
(4948) Tue Sep 17 13:34:23 2024: Debug:   } # authorize = ok
(4948) Tue Sep 17 13:34:23 2024: Debug: Found Auth-Type = eap
(4948) Tue Sep 17 13:34:23 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4948) Tue Sep 17 13:34:23 2024: Debug:   authenticate {
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Finished EAP session with  
state 0x739029df799c30bd
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Previous EAP request  
found for state 0x739029df799c30bd, released from the list
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Peer sent packet with  
method EAP PEAP (25)
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Calling submodule  
eap_peap to process data
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap: (TLS) EAP Done  
initial handshake
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap: Session established.  
  Decoding tunneled attributes
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap: PEAP state phase2
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap: EAP method MSCHAPv2 (26)
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap: Got tunneled request
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap:   EAP-Message =  
0x020c00061a03
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap: Setting User-Name to  
20191010280
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap: Sending tunneled  
request to inner-tunnel
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap:   EAP-Message =  
0x020c00061a03
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap:    
FreeRADIUS-Proxied-To = 127.0.0.1
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap:   User-Name = "20191010280"
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap:   State =  
0x3bfdb59b3af1afb3e181313f34318f40
(4948) Tue Sep 17 13:34:23 2024: Debug: Virtual server inner-tunnel  
received request
(4948) Tue Sep 17 13:34:23 2024: Debug:   EAP-Message = 0x020c00061a03
(4948) Tue Sep 17 13:34:23 2024: Debug:   FreeRADIUS-Proxied-To = 127.0.0.1
(4948) Tue Sep 17 13:34:23 2024: Debug:   User-Name = "20191010280"
(4948) Tue Sep 17 13:34:23 2024: Debug:   State =  
0x3bfdb59b3af1afb3e181313f34318f40
(4948) Tue Sep 17 13:34:23 2024: WARNING: Outer and inner identities  
are the same.  User privacy is compromised.
(4948) Tue Sep 17 13:34:23 2024: Debug: server inner-tunnel {
(4948) Tue Sep 17 13:34:23 2024: Debug:   session-state: No cached attributes
(4948) Tue Sep 17 13:34:23 2024: Debug:   # Executing section  
authorize from file /etc/freeradius/3.0/sites-enabled/inner-tunnel
(4948) Tue Sep 17 13:34:23 2024: Debug:     authorize {
(4948) Tue Sep 17 13:34:23 2024: Debug:       policy filter_username {
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name) {
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name)  -> TRUE
(4948) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name)  {
(4948) Tue Sep 17 13:34:23 2024: Debug:           if (&User-Name =~ / /) {
(4948) Tue Sep 17 13:34:23 2024: Debug:           if (&User-Name =~ /  
/)  -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:           if (&User-Name =~  
/@[^@]*@/ ) {
(4948) Tue Sep 17 13:34:23 2024: Debug:           if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:           if (&User-Name =~ /\.\./ ) {
(4948) Tue Sep 17 13:34:23 2024: Debug:           if (&User-Name =~  
/\.\./ )  -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:           if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4948) Tue Sep 17 13:34:23 2024: Debug:           if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:           if (&User-Name =~ /\.$/)  {
(4948) Tue Sep 17 13:34:23 2024: Debug:           if (&User-Name =~  
/\.$/)   -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:           if (&User-Name =~ /@\./)  {
(4948) Tue Sep 17 13:34:23 2024: Debug:           if (&User-Name =~  
/@\./)   -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:         } # if (&User-Name)  =  
notfound
(4948) Tue Sep 17 13:34:23 2024: Debug:       } # policy  
filter_username = notfound
(4948) Tue Sep 17 13:34:23 2024: Debug:       [chap] = noop
(4948) Tue Sep 17 13:34:23 2024: Debug:       [mschap] = noop
(4948) Tue Sep 17 13:34:23 2024: Debug: suffix: Checking for suffix after "@"
(4948) Tue Sep 17 13:34:23 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4948) Tue Sep 17 13:34:23 2024: Debug: suffix: No such realm "NULL"
(4948) Tue Sep 17 13:34:23 2024: Debug:       [suffix] = noop
(4948) Tue Sep 17 13:34:23 2024: Debug:       update control {
(4948) Tue Sep 17 13:34:23 2024: Debug:       } # update control = noop
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 12 length 6
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: No EAP Start, assuming  
it's an on-going EAP conversation
(4948) Tue Sep 17 13:34:23 2024: Debug:       [eap] = updated
(4948) Tue Sep 17 13:34:23 2024: Debug:       [files] = noop
(4948) Tue Sep 17 13:34:23 2024: Debug: ldap: EXPAND  
(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}})
(4948) Tue Sep 17 13:34:23 2024: Debug: ldap:    -->  
(sAMAccountName=20191010280)
(4948) Tue Sep 17 13:34:23 2024: Debug: ldap: Performing search in  
"DC=adm,DC=ifsul,DC=edu,DC=br" with filter  
"(sAMAccountName=20191010280)", scope "sub"
(4948) Tue Sep 17 13:34:23 2024: Debug: ldap: Waiting for search result...
(4948) Tue Sep 17 13:34:23 2024: Debug: ldap: User object found at DN  
"CN=Roger Miranda  
Muller,OU=Students,OU=Users,OU=CampusPelotas,DC=adm,DC=ifsul,DC=edu,DC=br"
(4948) Tue Sep 17 13:34:23 2024: Debug: ldap: Processing user attributes
(4948) Tue Sep 17 13:34:23 2024: Debug:       [ldap] = ok
(4948) Tue Sep 17 13:34:23 2024: Debug:       [expiration] = noop
(4948) Tue Sep 17 13:34:23 2024: Debug:       [logintime] = noop
(4948) Tue Sep 17 13:34:23 2024: Debug:       [pap] = noop
(4948) Tue Sep 17 13:34:23 2024: Debug:       if (!&control:Auth-Type  
&& &User-Password) {
(4948) Tue Sep 17 13:34:23 2024: Debug:       if (!&control:Auth-Type  
&& &User-Password)  -> FALSE
(4948) Tue Sep 17 13:34:23 2024: Debug:     } # authorize = updated
(4948) Tue Sep 17 13:34:23 2024: Debug:   Found Auth-Type = eap
(4948) Tue Sep 17 13:34:23 2024: Debug:   # Executing group from file  
/etc/freeradius/3.0/sites-enabled/inner-tunnel
(4948) Tue Sep 17 13:34:23 2024: Debug:     authenticate {
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Finished EAP session with  
state 0x3bfdb59b3af1afb3
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Previous EAP request  
found for state 0x3bfdb59b3af1afb3, released from the list
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Peer sent packet with  
method EAP MSCHAPv2 (26)
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Calling submodule  
eap_mschapv2 to process data
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Sending EAP Success (code  
3) ID 12 length 4
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Freeing handler
(4948) Tue Sep 17 13:34:23 2024: Debug:       [eap] = ok
(4948) Tue Sep 17 13:34:23 2024: Debug:     } # authenticate = ok
(4948) Tue Sep 17 13:34:23 2024: Debug:   # Executing section  
post-auth from file /etc/freeradius/3.0/sites-enabled/inner-tunnel
(4948) Tue Sep 17 13:34:23 2024: Debug:     post-auth {
(4948) Tue Sep 17 13:34:23 2024: Debug:       if (1) {
(4948) Tue Sep 17 13:34:23 2024: Debug:       if (1)  -> TRUE
(4948) Tue Sep 17 13:34:23 2024: Debug:       if (1)  {
(4948) Tue Sep 17 13:34:23 2024: Debug:         update reply {
(4948) Tue Sep 17 13:34:23 2024: Debug:         } # update reply = noop
(4948) Tue Sep 17 13:34:23 2024: Debug:         update {
(4948) Tue Sep 17 13:34:23 2024: Debug:           No attributes  
updated for RHS &reply:
(4948) Tue Sep 17 13:34:23 2024: Debug:         } # update = noop
(4948) Tue Sep 17 13:34:23 2024: Debug:       } # if (1)  = noop
(4948) Tue Sep 17 13:34:23 2024: Debug:     } # post-auth = noop
(4948) Tue Sep 17 13:34:23 2024: Debug: } # server inner-tunnel
(4948) Tue Sep 17 13:34:23 2024: Debug: Virtual server sending reply
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap: Got tunneled reply code 2
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap: Tunneled  
authentication was successful
(4948) Tue Sep 17 13:34:23 2024: Debug: eap_peap: SUCCESS
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: Sending EAP Request (code  
1) ID 13 length 46
(4948) Tue Sep 17 13:34:23 2024: Debug: eap: EAP session adding  
&reply:State = 0x739029df789d30bd
(4948) Tue Sep 17 13:34:23 2024: Debug:     [eap] = handled
(4948) Tue Sep 17 13:34:23 2024: Debug:   } # authenticate = handled
(4948) Tue Sep 17 13:34:23 2024: Debug: Using Post-Auth-Type Challenge
(4948) Tue Sep 17 13:34:23 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4948) Tue Sep 17 13:34:23 2024: Debug:   Challenge { ... } # empty  
sub-section is ignored
(4948) Tue Sep 17 13:34:23 2024: Debug: session-state: Saving cached  
attributes
(4948) Tue Sep 17 13:34:23 2024: Debug:   Framed-MTU = 994
(4948) Tue Sep 17 13:34:23 2024: Debug:   TLS-Session-Cipher-Suite =  
"ECDHE-RSA-AES128-GCM-SHA256"
(4948) Tue Sep 17 13:34:23 2024: Debug:   TLS-Session-Version = "TLS 1.2"
(4948) Tue Sep 17 13:34:23 2024: Debug: Sent Access-Challenge Id 105  
from 10.1.0.22:1812 to 10.1.0.14:34441 length 104
(4948) Tue Sep 17 13:34:23 2024: Debug:   EAP-Message =  
0x010d002e19001703030023bbea5dda47acad06042b01f3d25ad7b26c821bfe98e95094007ce255c6d07a3f713dfb
(4948) Tue Sep 17 13:34:23 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4948) Tue Sep 17 13:34:23 2024: Debug:   State =  
0x739029df789d30bdedd976aca8f84267
(4948) Tue Sep 17 13:34:23 2024: Debug: Finished request
(4949) Tue Sep 17 13:34:23 2024: Debug: Received Access-Request Id 106  
from 10.1.0.14:34441 to 10.1.0.22:1812 length 342
(4949) Tue Sep 17 13:34:23 2024: Debug:   User-Name = "20191010280"
(4949) Tue Sep 17 13:34:23 2024: Debug:   Chargeable-User-Identity = 0x08
(4949) Tue Sep 17 13:34:23 2024: Debug:   Location-Capable = Civic-Location
(4949) Tue Sep 17 13:34:23 2024: Debug:   Calling-Station-Id =  
"98-b8-ba-34-40-13"
(4949) Tue Sep 17 13:34:23 2024: Debug:   Called-Station-Id =  
"64-e9-50-67-2b-b0:IFSUL PEL"
(4949) Tue Sep 17 13:34:23 2024: Debug:   NAS-Port = 1
(4949) Tue Sep 17 13:34:23 2024: Debug:   Cisco-AVPair =  
"audit-session-id=08f910ac000332298eafe966"
(4949) Tue Sep 17 13:34:23 2024: Debug:   Acct-Session-Id =  
"66e9af8e/98:b8:ba:34:40:13/220964"
(4949) Tue Sep 17 13:34:23 2024: Debug:   NAS-IP-Address = 172.16.249.8
(4949) Tue Sep 17 13:34:23 2024: Debug:   NAS-Identifier =  
"IFSUL_PEL_WLAN_CONTROLLER"
(4949) Tue Sep 17 13:34:23 2024: Debug:   Airespace-Wlan-Id = 2
(4949) Tue Sep 17 13:34:23 2024: Debug:   Service-Type = Framed-User
(4949) Tue Sep 17 13:34:23 2024: Debug:   Framed-MTU = 1300
(4949) Tue Sep 17 13:34:23 2024: Debug:   NAS-Port-Type = Wireless-802.11
(4949) Tue Sep 17 13:34:23 2024: Debug:   Tunnel-Type:0 = VLAN
(4949) Tue Sep 17 13:34:23 2024: Debug:   Tunnel-Medium-Type:0 = IEEE-802
(4949) Tue Sep 17 13:34:23 2024: Debug:   Tunnel-Private-Group-Id:0 = "1"
(4949) Tue Sep 17 13:34:23 2024: Debug:   EAP-Message =  
0x020d002e190017030300230000000000000004d1a038336a625c1295a15c32f1d41a38236b3354822a3ed8743696
(4949) Tue Sep 17 13:34:23 2024: Debug:   State =  
0x739029df789d30bdedd976aca8f84267
(4949) Tue Sep 17 13:34:23 2024: Debug:   Message-Authenticator =  
0xa9bc3d18fd7e3cda151b0489af8cc162
(4949) Tue Sep 17 13:34:23 2024: Debug: Restoring &session-state
(4949) Tue Sep 17 13:34:23 2024: Debug:   &session-state:Framed-MTU = 994
(4949) Tue Sep 17 13:34:23 2024: Debug:    
&session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES128-GCM-SHA256"
(4949) Tue Sep 17 13:34:23 2024: Debug:    
&session-state:TLS-Session-Version = "TLS 1.2"
(4949) Tue Sep 17 13:34:23 2024: Debug: # Executing section authorize  
from file /etc/freeradius/3.0/sites-enabled/default
(4949) Tue Sep 17 13:34:23 2024: Debug:   authorize {
(4949) Tue Sep 17 13:34:23 2024: Debug:     policy filter_username {
(4949) Tue Sep 17 13:34:23 2024: Debug:       if (&User-Name) {
(4949) Tue Sep 17 13:34:23 2024: Debug:       if (&User-Name)  -> TRUE
(4949) Tue Sep 17 13:34:23 2024: Debug:       if (&User-Name)  {
(4949) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~ / /) {
(4949) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~ / /)  
  -> FALSE
(4949) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ ) {
(4949) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~  
/@[^@]*@/ )  -> FALSE
(4949) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~ /\.\./ ) {
(4949) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~  
/\.\./ )  -> FALSE
(4949) Tue Sep 17 13:34:23 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4949) Tue Sep 17 13:34:23 2024: Debug:         if ((&User-Name =~  
/@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(4949) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~ /\.$/)  {
(4949) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~  
/\.$/)   -> FALSE
(4949) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~ /@\./)  {
(4949) Tue Sep 17 13:34:23 2024: Debug:         if (&User-Name =~  
/@\./)   -> FALSE
(4949) Tue Sep 17 13:34:23 2024: Debug:       } # if (&User-Name)  = notfound
(4949) Tue Sep 17 13:34:23 2024: Debug:     } # policy filter_username  
= notfound
(4949) Tue Sep 17 13:34:23 2024: Debug:     [preprocess] = ok
(4949) Tue Sep 17 13:34:23 2024: Debug:     [chap] = noop
(4949) Tue Sep 17 13:34:23 2024: Debug:     [mschap] = noop
(4949) Tue Sep 17 13:34:23 2024: Debug:     [digest] = noop
(4949) Tue Sep 17 13:34:23 2024: Debug: suffix: Checking for suffix after "@"
(4949) Tue Sep 17 13:34:23 2024: Debug: suffix: No '@' in User-Name =  
"20191010280", looking up realm NULL
(4949) Tue Sep 17 13:34:23 2024: Debug: suffix: No such realm "NULL"
(4949) Tue Sep 17 13:34:23 2024: Debug:     [suffix] = noop
(4949) Tue Sep 17 13:34:23 2024: Debug: eap: Peer sent EAP Response  
(code 2) ID 13 length 46
(4949) Tue Sep 17 13:34:23 2024: Debug: eap: Continuing tunnel setup
(4949) Tue Sep 17 13:34:23 2024: Debug:     [eap] = ok
(4949) Tue Sep 17 13:34:23 2024: Debug:   } # authorize = ok
(4949) Tue Sep 17 13:34:23 2024: Debug: Found Auth-Type = eap
(4949) Tue Sep 17 13:34:23 2024: Debug: # Executing group from file  
/etc/freeradius/3.0/sites-enabled/default
(4949) Tue Sep 17 13:34:23 2024: Debug:   authenticate {
(4949) Tue Sep 17 13:34:23 2024: Debug: eap: Expiring EAP session with  
state 0xb3d0065db6d71f13
(4949) Tue Sep 17 13:34:23 2024: Debug: eap: Finished EAP session with  
state 0x739029df789d30bd
(4949) Tue Sep 17 13:34:23 2024: Debug: eap: Previous EAP request  
found for state 0x739029df789d30bd, released from the list
(4949) Tue Sep 17 13:34:23 2024: Debug: eap: Peer sent packet with  
method EAP PEAP (25)
(4949) Tue Sep 17 13:34:23 2024: Debug: eap: Calling submodule  
eap_peap to process data
(4949) Tue Sep 17 13:34:23 2024: Debug: eap_peap: (TLS) EAP Done  
initial handshake
(4949) Tue Sep 17 13:34:23 2024: Debug: eap_peap: Session established.  
  Decoding tunneled attributes
(4949) Tue Sep 17 13:34:23 2024: Debug: eap_peap: PEAP state send tlv success
(4949) Tue Sep 17 13:34:23 2024: Debug: eap_peap: Received EAP-TLV response
(4949) Tue Sep 17 13:34:23 2024: Debug: eap_peap: Success
(4949) Tue Sep 17 13:34:23 2024: Debug: eap: Sending EAP Success (code  
3) ID 13 length 4
(4949) Tue Sep 17 13:34:23 2024: Debug: eap: Freeing handler
(4949) Tue Sep 17 13:34:23 2024: Debug:     [eap] = ok
(4949) Tue Sep 17 13:34:23 2024: Debug:   } # authenticate = ok
(4949) Tue Sep 17 13:34:23 2024: Debug: # Executing section post-auth  
from file /etc/freeradius/3.0/sites-enabled/default
(4949) Tue Sep 17 13:34:23 2024: Debug:   post-auth {
(4949) Tue Sep 17 13:34:23 2024: Debug:     if  
(session-state:User-Name && reply:User-Name && request:User-Name &&  
(reply:User-Name == request:User-Name)) {
(4949) Tue Sep 17 13:34:23 2024: Debug:     if  
(session-state:User-Name && reply:User-Name && request:User-Name &&  
(reply:User-Name == request:User-Name))  -> FALSE
(4949) Tue Sep 17 13:34:23 2024: Debug:     update {
(4949) Tue Sep 17 13:34:23 2024: Debug:     } # update = noop
(4949) Tue Sep 17 13:34:23 2024: Debug:     [exec] = noop
(4949) Tue Sep 17 13:34:23 2024: Debug:     policy  
remove_reply_message_if_eap {
(4949) Tue Sep 17 13:34:23 2024: Debug:       if (&reply:EAP-Message  
&& &reply:Reply-Message) {
(4949) Tue Sep 17 13:34:23 2024: Debug:       if (&reply:EAP-Message  
&& &reply:Reply-Message)  -> FALSE
(4949) Tue Sep 17 13:34:23 2024: Debug:       else {
(4949) Tue Sep 17 13:34:23 2024: Debug:         [noop] = noop
(4949) Tue Sep 17 13:34:23 2024: Debug:       } # else = noop
(4949) Tue Sep 17 13:34:23 2024: Debug:     } # policy  
remove_reply_message_if_eap = noop
(4949) Tue Sep 17 13:34:23 2024: Debug:     if (EAP-Key-Name &&  
&reply:EAP-Session-Id) {
(4949) Tue Sep 17 13:34:23 2024: Debug:     if (EAP-Key-Name &&  
&reply:EAP-Session-Id)  -> FALSE
(4949) Tue Sep 17 13:34:23 2024: Debug:   } # post-auth = noop
(4949) Tue Sep 17 13:34:23 2024: Debug: Sent Access-Accept Id 106 from  
10.1.0.22:1812 to 10.1.0.14:34441 length 179
(4949) Tue Sep 17 13:34:23 2024: Debug:   MS-MPPE-Recv-Key =  
0xe7966cc2d61ef16c8865a5142f0d882aabf8a162fdd20e60723cecd6c0b2639f
(4949) Tue Sep 17 13:34:23 2024: Debug:   MS-MPPE-Send-Key =  
0x02e43d3ebd4dcd4096743eef970d1e2378dd4223c88cfbe764701fde666f8ef0
(4949) Tue Sep 17 13:34:23 2024: Debug:   EAP-Message = 0x030d0004
(4949) Tue Sep 17 13:34:23 2024: Debug:   Message-Authenticator =  
0x00000000000000000000000000000000
(4949) Tue Sep 17 13:34:23 2024: Debug:   User-Name = "20191010280"
(4949) Tue Sep 17 13:34:23 2024: Debug:   Framed-MTU += 994
(4949) Tue Sep 17 13:34:23 2024: Debug: Finished request

Re: TLS errors and clients sometimes rejected

Rodrigo Abrantes Antunes