TLS errors and clients sometimes rejected
Hi, sometimes clients are rejected with the errors below, and sometimes the same clients are accepted. I thought that this could be because of old clients and then defined this but the errors continued: cipher_list = "DEFAULT@SECLEVEL=0" tls_min_version = "1.0" tls_max_version = "1.2" Any ideas what might be going wrong? Freeradius 3.2.1 (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 (6470) eap_peap: (TLS) send TLS 1.0 Alert, fatal protocol_version (6470) eap_peap: ERROR: (TLS) Alert write:fatal:protocol version (6470) eap_peap: (TLS) Server : Need to read more data: error (6470) eap_peap: ERROR: (TLS) Failed reading from OpenSSL: error:0A00010B:SSL routines::wrong version number (6470) eap_peap: ERROR: (TLS) System call (I/O) error (-1) (6470) eap_peap: ERROR: (TLS) EAP Receive handshake failed during operation (6470) eap_peap: ERROR: [eaptls process] = fail (6470) eap: ERROR: Failed continuing EAP PEAP (25) session. EAP sub-module failed (7412) eap_peap: (TLS) recv TLS 1.2 Alert, fatal internal_error (7412) eap_peap: (TLS) The client is informing us that there is a failure inside the TLS protocol exchange. (7412) eap_peap: ERROR: (TLS) Alert read:fatal:internal error (7412) eap_peap: (TLS) Server : Need to read more data: error (7412) eap_peap: ERROR: (TLS) Failed reading from OpenSSL: error:0A000438:SSL routines::tlsv1 alert internal error (7412) eap_peap: (TLS) In Handshake Phase (7412) eap_peap: (TLS) Application data. (7412) eap_peap: ERROR: (TLS) Cannot continue, as the peer is misbehaving. (7412) eap_peap: ERROR: [eaptls process] = fail (7412) eap: ERROR: Failed continuing EAP PEAP (25) session. EAP sub-module failed
On Sep 17, 2024, at 10:31 AM, Rodrigo Abrantes Antunes <rodrigoantunes@pelotas.ifsul.edu.br> wrote
Hi, sometimes clients are rejected with the errors below, and sometimes the same clients are accepted. I thought that this could be because of old clients and then defined this but the errors continued:
cipher_list = "DEFAULT@SECLEVEL=0" tls_min_version = "1.0" tls_max_version = "1.2"
Any ideas what might be going wrong?
The client is saying it doesn't like FreeRADIUS, or vice-versa.
Freeradius 3.2.1
(911) eap_peap: (TLS) send TLS 1.2 Alert, fatal protocol_version
FreeRADIUS doesn't like the TLS version used by the client.
(7412) eap_peap: (TLS) recv TLS 1.2 Alert, fatal internal_error (7412) eap_peap: (TLS) The client is informing us that there is a failure inside the TLS protocol exchange.
The client doesn't like the data that FreeRADIUS sends. There's little to do except upgrade the client. Alan DeKok.
Citando Alan DeKok <aland@deployingradius.com>:
The client is saying it doesn't like FreeRADIUS, or vice-versa.
cipher_list = "DEFAULT@SECLEVEL=0" tls_min_version = "1.0" tls_max_version = "1.2" These options doesn't say that freeradius should support all tls versions until 1.2? Why freeradius wouldn't like the TLS version used by the client? And why sometimes the same clients are accepted? I have another freeradius server version 2.2.5 that don't have this problem, all users can use the internet no matter the client's tls version.
There's little to do except upgrade the client.
These are android devices that can't upgrade. I can't ask the students to buy another cellphone and I need to allow them to access the internet.
On Sep 17, 2024, at 11:06 AM, Rodrigo Abrantes Antunes <rodrigoantunes@pelotas.ifsul.edu.br> wrote:
cipher_list = "DEFAULT@SECLEVEL=0" tls_min_version = "1.0" tls_max_version = "1.2"
These options doesn't say that freeradius should support all tls versions until 1.2? Why freeradius wouldn't like the TLS version used by the client?
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.
And why sometimes the same clients are accepted?
Look at the logs. It's not possible to debug complicated TLS issues by looking at 3-4 lines of TLS logs.
I have another freeradius server version 2.2.5 that don't have this problem, all users can use the internet no matter the client's tls version.\
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.
There's little to do except upgrade the client.
These are android devices that can't upgrade. I can't ask the students to buy another cellphone and I need to allow them to access the internet.
Then use 2.2.5 and an old version of OpenSSL. At some point, the old TLS ciphers will be officially deprecated and unsupported. At which point they won't work. This isn't really a FreeRADIUS issue. FreeRADIUS uses OpenSSL for all TLS negotiation. If OpenSSL says it doesn't like the client (or vice versa), then there is often very little that FreeRADIUS can do to fix it. 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. Alan DeKok.
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
On Sep 17, 2024, at 12:46 PM, Rodrigo Abrantes Antunes <rodrigoantunes@pelotas.ifsul.edu.br> wrote:
## REJECTED .. (911) eap_peap: (TLS) send TLS 1.2 Alert, fatal protocol_version (911) eap_peap: ERROR: (TLS) Alert write:fatal:protocol version
Ah, that's the other end saying it doesn't like the protocol version which FreeRADIUS is using. It should negotiate a mutually compatible TLS version, but... whatever.
Doesn't cipher_list = "DEFAULT@SECLEVEL=0" says the server to support the old ciphers?
That configuratio tells OpenSSL to support the old ciphers. Mostly. Some newer OS distributions have removed support for old TLS versions from OpenSSL. You will need to investigate your local OS to see what it supports, and what TLS versions are supported by the OpenSSL libraries. Again... this isn't a FreeRADIUS issue. No amount of poking FreeRADIUS will get OpenSSL to support TLS 1.0 with triple-DES, if that's what the clients are using. You night just need to upgrade the client, or build a custom version of OpenSSL.
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?
Live with the fact the some devices won't work, because they're too old. Alan DeKok.
On Sep 17, 2024, at 12:46 PM, Rodrigo Abrantes Antunes <rodrigoantunes@pelotas.ifsul.edu.br> wrote:
## REJECTED .. (911) eap_peap: (TLS) send TLS 1.2 Alert, fatal protocol_version (911) eap_peap: ERROR: (TLS) Alert write:fatal:protocol version
Ah, that's the other end saying it doesn't like the protocol version which FreeRADIUS is using.
It should negotiate a mutually compatible TLS version, but... whatever.
Doesn't cipher_list = "DEFAULT@SECLEVEL=0" says the server to support the old ciphers?
That configuratio tells OpenSSL to support the old ciphers. Mostly.
Some newer OS distributions have removed support for old TLS versions from OpenSSL. You will need to investigate your local OS to see what it supports, and what TLS versions are supported by the OpenSSL libraries.
Again... this isn't a FreeRADIUS issue. No amount of poking FreeRADIUS will get OpenSSL to support TLS 1.0 with triple-DES, if that's what the clients are using. You night just need to upgrade the client, or build a custom version of OpenSSL.
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?
Live with the fact the some devices won't work, because they're too old.
What can explain that sometimes the same clients get accepted? I have sent the accept log in the other email. I kick the user from the wireless controller and it get accepted, but after some time it get rejected but soon it get accepted again, it seems to be random (see below). Could be that the client or the server is doing some kind of failover? Trying one version, if it dont work try another? If yes, is this configurable? 2024-09-17T13:34:00.037165-03:00 ifs01sv004 radiusd[124150]: (4131) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 1 cli 70-18-8b-fd-8f-e5) 2024-09-17T13:34:18.500907-03:00 ifs01sv004 radiusd[124150]: (4757) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 0 via TLS tunnel) 2024-09-17T13:34:18.504874-03:00 ifs01sv004 radiusd[124150]: (4758) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 1 cli 2a-93-80-4d-f3-c3) 2024-09-17T13:36:52.439539-03:00 ifs01sv004 radiusd[124150]: (7831) Login incorrect (eap_peap: (TLS) Alert write:fatal:protocol version): [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 1 cli 2a-93-80-4d-f3-c3) 2024-09-17T13:37:58.161709-03:00 ifs01sv004 radiusd[124150]: (9110) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 0 via TLS tunnel) 2024-09-17T13:37:58.166535-03:00 ifs01sv004 radiusd[124150]: (9112) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 1 cli 2a-93-80-4d-f3-c3) 2024-09-17T13:38:19.715578-03:00 ifs01sv004 radiusd[124150]: (9543) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 0 via TLS tunnel) 2024-09-17T13:38:19.720846-03:00 ifs01sv004 radiusd[124150]: (9544) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 1 cli 2a-93-80-4d-f3-c3) 2024-09-17T13:38:54.160824-03:00 ifs01sv004 radiusd[124150]: (10034) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 0 via TLS tunnel) 2024-09-17T13:38:54.171994-03:00 ifs01sv004 radiusd[124150]: (10035) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 1 cli 2a-93-80-4d-f3-c3) 2024-09-17T13:41:08.645238-03:00 ifs01sv004 radiusd[124150]: (11986) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 0 via TLS tunnel) 2024-09-17T13:41:08.650699-03:00 ifs01sv004 radiusd[124150]: (11987) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 1 cli 2a-93-80-4d-f3-c3) 2024-09-17T13:43:23.660156-03:00 ifs01sv004 radiusd[124150]: (14127) Login incorrect (eap_peap: (TLS) Alert write:fatal:protocol version): [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 1 cli 2a-93-80-4d-f3-c3) 2024-09-17T13:43:38.674200-03:00 ifs01sv004 radiusd[124150]: (14462) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 0 via TLS tunnel) 2024-09-17T13:43:38.678449-03:00 ifs01sv004 radiusd[124150]: (14463) Login OK: [202011160097/<via Auth-Type = eap>] (from client cisco-wlc port 1 cli 2a-93-80-4d-f3-c3)
On Sep 18, 2024, at 8:02 AM, Rodrigo Abrantes Antunes <rodrigoantunes@pelotas.ifsul.edu.br> wrote:
What can explain that sometimes the same clients get accepted? I have sent the accept log in the other email.
You'd have to look at the logs on the user device to see what it's doing and why.
I kick the user from the wireless controller and it get accepted, but after some time it get rejected but soon it get accepted again, it seems to be random (see below).
Could be that the client or the server is doing some kind of failover? Trying one version, if it dont work try another? If yes, is this configurable?
The systems should negotiate properly. If FreeRADIUS works properly for every other device, and only one device (or a small number of them) misbehaves, then the issue is the device. I've tried to explain as clearly as I can what your options are here. It's not productive to keep trying to figure out "but WHY"? Device vendors do all kinds of stupid things. They usually fix the issues over time. If you have devices which are 5-6 years old and use old TLS protocols... upgrade. Don't waste your time trying to figure it out. That effort has already been done, and all of the fixes are in the software on the updated devices. This isn't a FreeRADIUS problem. No amount of poking FreeRADIUS will fix bugs in 5 year-old devices. I can't answer your question, other than with vague generalities "old devices do that". If you truly want to understand, you need to get into those old devices, and debug them. That isn't a FreeRADIUS issue. And no other action will have you truly understand what those devices are doing, and why. If you're not going to do that, then drop the topic. You've been told the only answer which is available. Asking the same question over and over won't get you a different answer. Alan DeKok.
The systems should negotiate properly.
If FreeRADIUS works properly for every other device, and only one device (or a small number of them) misbehaves, then the issue is the device.
It's not one, it's around 400 devices, probably from students. I can't reject them. I will need to keep the old freeradius running then. Is it possible to configure a failover between two radius servers? If the user was rejected by the new one (beucause of old tls), try the old one?
On Sep 18, 2024, at 8:39 AM, Rodrigo Abrantes Antunes <rodrigoantunes@pelotas.ifsul.edu.br> wrote:
It's not one, it's around 400 devices, probably from students. I can't reject them. I will need to keep the old freeradius running then. Is it possible to configure a failover between two radius servers? If the user was rejected by the new one (beucause of old tls), try the old one?
No. The only thing you can do is the following: * run both servers * the new one is the default server, and does authentication for all new devices * the new one is also configured as a proxy, to send some packets to the old server * list the MAC addresses the broken devices on the proxy (SQL, or "users" file) * if a request comes in with a matching MAC, proxy it to the old * the old server only handles the old devices That should work. Alan DeKok.
The only thing you can do is the following:
* run both servers
* the new one is the default server, and does authentication for all new devices
* the new one is also configured as a proxy, to send some packets to the old server
* list the MAC addresses the broken devices on the proxy (SQL, or "users" file)
* if a request comes in with a matching MAC, proxy it to the old
* the old server only handles the old devices
That should work.
Oh, that will help, thanks!!
participants (2)
-
Alan DeKok -
Rodrigo Abrantes Antunes