- Freeradius-Users - lists.freeradius.org

ERROR: eap_peap: We sent a success, but the client did not agree
by Marco Santantonio 05 Oct '18

05 Oct '18

Hi, I have a problem with a windows 10 client that fails to access our wifi wpa2 enterprise PEAP-mschapv2. This is our infrastructure: CISCO WLC -> PROXY-RADIUS -> AUTH-RADIUS OS: Debian GNU / Linux 9 (Stretch) Freeradius 3.0.12 from STABLE repository I am attaching the output of the raddebug. Analyzing the log I see that the TLS tunnel is correctly created, mschap authentication goes to good end (package 12014208) but then I see this error: (12014210) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Client rejected our response. The password is probably incorrect (12014210) Fri Sep 28 16:27:46 2018: ERROR: eap_peap: We sent a success, but the client did not agree (12014210) Fri Sep 28 16:27:46 2018: ERROR: eap: Failed continuing EAP PEAP (25) session. EAP sub-module failed and the user can not log in. I can not understand why even if the mschap authentication was successful, the error above appears. Moreover only this client complains about the problem, all others works correctly. Thanks for your help! (12014187) Fri Sep 28 16:27:43 2018: Debug: Received Access-Request Id 3 from 130.192.119.80:33713 to 192.168.19.93:1812 length 293 (12014187) Fri Sep 28 16:27:43 2018: Debug: User-Name = "USER" (12014187) Fri Sep 28 16:27:43 2018: Debug: Chargeable-User-Identity = 0x00 (12014187) Fri Sep 28 16:27:43 2018: Debug: Location-Capable = Civix-Location (12014187) Fri Sep 28 16:27:43 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014187) Fri Sep 28 16:27:43 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014187) Fri Sep 28 16:27:43 2018: Debug: NAS-Port = 13 (12014187) Fri Sep 28 16:27:43 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014187) Fri Sep 28 16:27:43 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014187) Fri Sep 28 16:27:43 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014187) Fri Sep 28 16:27:43 2018: Debug: NAS-Identifier = "wlc-lin" (12014187) Fri Sep 28 16:27:43 2018: Debug: Airespace-Wlan-Id = 1 (12014187) Fri Sep 28 16:27:43 2018: Debug: Service-Type = Framed-User (12014187) Fri Sep 28 16:27:43 2018: Debug: Framed-MTU = 1300 (12014187) Fri Sep 28 16:27:43 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014187) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Type:0 = VLAN (12014187) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014187) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014187) Fri Sep 28 16:27:43 2018: Debug: EAP-Message = 0x02020015016d61747469612e6265676f766f657661 (12014187) Fri Sep 28 16:27:43 2018: Debug: Message-Authenticator = 0xf9bd98f7b7c84e260c6dbfaaa97bc62f (12014187) Fri Sep 28 16:27:43 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:43 CEST" (12014187) Fri Sep 28 16:27:43 2018: Debug: Proxy-State = 0x313635 (12014187) Fri Sep 28 16:27:43 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (12014187) Fri Sep 28 16:27:43 2018: Debug: authorize { (12014187) Fri Sep 28 16:27:43 2018: Debug: policy forbid_win_host_auth { (12014187) Fri Sep 28 16:27:43 2018: Debug: if ( &User-Name =~ /^host\// ) { (12014187) Fri Sep 28 16:27:43 2018: Debug: if ( &User-Name =~ /^host\// ) -> FALSE (12014187) Fri Sep 28 16:27:43 2018: Debug: } # policy forbid_win_host_auth = notfound (12014187) Fri Sep 28 16:27:43 2018: Debug: policy normalize_username { (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") { (12014187) Fri Sep 28 16:27:43 2018: Debug: EXPAND %{tolower:%{User-Name}} (12014187) Fri Sep 28 16:27:43 2018: Debug: --> USER (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") -> FALSE (12014187) Fri Sep 28 16:27:43 2018: Debug: else { (12014187) Fri Sep 28 16:27:43 2018: Debug: [noop] = noop (12014187) Fri Sep 28 16:27:43 2018: Debug: } # else = noop (12014187) Fri Sep 28 16:27:43 2018: Debug: } # policy normalize_username = noop (12014187) Fri Sep 28 16:27:43 2018: Debug: policy filter_username { (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) { (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) -> TRUE (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) { (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ / /) { (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014187) Fri Sep 28 16:27:43 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014187) Fri Sep 28 16:27:43 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.$/) { (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /(a)\./) { (12014187) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014187) Fri Sep 28 16:27:43 2018: Debug: } # if (&User-Name) = noop (12014187) Fri Sep 28 16:27:43 2018: Debug: } # policy filter_username = noop (12014187) Fri Sep 28 16:27:43 2018: Debug: [preprocess] = ok (12014187) Fri Sep 28 16:27:43 2018: Debug: [mschap] = noop (12014187) Fri Sep 28 16:27:43 2018: Debug: suffix: Checking for suffix after "@" (12014187) Fri Sep 28 16:27:43 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014187) Fri Sep 28 16:27:43 2018: Debug: suffix: No such realm "NULL" (12014187) Fri Sep 28 16:27:43 2018: Debug: [suffix] = noop (12014187) Fri Sep 28 16:27:43 2018: Debug: eap: Peer sent EAP Response (code 2) ID 2 length 21 (12014187) Fri Sep 28 16:27:43 2018: Debug: eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (12014187) Fri Sep 28 16:27:43 2018: Debug: [eap] = ok (12014187) Fri Sep 28 16:27:43 2018: Debug: } # authorize = ok (12014187) Fri Sep 28 16:27:43 2018: Debug: Found Auth-Type = eap (12014187) Fri Sep 28 16:27:43 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014187) Fri Sep 28 16:27:43 2018: Debug: authenticate { (12014187) Fri Sep 28 16:27:43 2018: Debug: eap: Peer sent packet with method EAP Identity (1) (12014187) Fri Sep 28 16:27:43 2018: Debug: eap: Calling submodule eap_peap to process data (12014187) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Initiating new EAP-TLS session (12014187) Fri Sep 28 16:27:43 2018: Debug: eap_peap: [eaptls start] = request (12014187) Fri Sep 28 16:27:43 2018: Debug: eap: Sending EAP Request (code 1) ID 3 length 6 (12014187) Fri Sep 28 16:27:43 2018: Debug: eap: EAP session adding &reply:State = 0x4a8916764a8a0f76 (12014187) Fri Sep 28 16:27:43 2018: Debug: [eap] = handled (12014187) Fri Sep 28 16:27:43 2018: Debug: } # authenticate = handled (12014187) Fri Sep 28 16:27:43 2018: Debug: Using Post-Auth-Type Challenge (12014187) Fri Sep 28 16:27:43 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (12014187) Fri Sep 28 16:27:43 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014187) Fri Sep 28 16:27:43 2018: Debug: Sent Access-Challenge Id 3 from 192.168.19.93:1812 to 130.192.119.80:33713 length 0 (12014187) Fri Sep 28 16:27:43 2018: Debug: EAP-Message = 0x010300061920 (12014187) Fri Sep 28 16:27:43 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014187) Fri Sep 28 16:27:43 2018: Debug: State = 0x4a8916764a8a0f7661caf9ec4798bf13 (12014187) Fri Sep 28 16:27:43 2018: Debug: Proxy-State = 0x313635 (12014187) Fri Sep 28 16:27:43 2018: Debug: Finished request (12014188) Fri Sep 28 16:27:43 2018: Debug: Received Access-Request Id 31 from 130.192.119.80:33713 to 192.168.19.93:1812 length 456 (12014188) Fri Sep 28 16:27:43 2018: Debug: User-Name = "USER" (12014188) Fri Sep 28 16:27:43 2018: Debug: Chargeable-User-Identity = 0x00 (12014188) Fri Sep 28 16:27:43 2018: Debug: Location-Capable = Civix-Location (12014188) Fri Sep 28 16:27:43 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014188) Fri Sep 28 16:27:43 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014188) Fri Sep 28 16:27:43 2018: Debug: NAS-Port = 13 (12014188) Fri Sep 28 16:27:43 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014188) Fri Sep 28 16:27:43 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014188) Fri Sep 28 16:27:43 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014188) Fri Sep 28 16:27:43 2018: Debug: NAS-Identifier = "wlc-lin" (12014188) Fri Sep 28 16:27:43 2018: Debug: Airespace-Wlan-Id = 1 (12014188) Fri Sep 28 16:27:43 2018: Debug: Service-Type = Framed-User (12014188) Fri Sep 28 16:27:43 2018: Debug: Framed-MTU = 1300 (12014188) Fri Sep 28 16:27:43 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014188) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Type:0 = VLAN (12014188) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014188) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014188) Fri Sep 28 16:27:43 2018: Debug: EAP-Message = 0x020300a619800000009c16030300970100009303035bae3a5ea7ccc2962e30c5aefec92da9c3e60e4b9d3bd55a7795a57f6aa5455300002ac02cc02bc030c02f009f009ec024c023c028c027c00ac009c014c013009d009c003d003c0035002f000a01000040000500050100000000000a00080006001d (12014188) Fri Sep 28 16:27:43 2018: Debug: State = 0x4a8916764a8a0f7661caf9ec4798bf13 (12014188) Fri Sep 28 16:27:43 2018: Debug: Message-Authenticator = 0x96867235312b66c230053355627f173d (12014188) Fri Sep 28 16:27:43 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:43 CEST" (12014188) Fri Sep 28 16:27:43 2018: Debug: Proxy-State = 0x313636 (12014188) Fri Sep 28 16:27:43 2018: Debug: session-state: No cached attributes (12014188) Fri Sep 28 16:27:43 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (12014188) Fri Sep 28 16:27:43 2018: Debug: authorize { (12014188) Fri Sep 28 16:27:43 2018: Debug: policy forbid_win_host_auth { (12014188) Fri Sep 28 16:27:43 2018: Debug: if ( &User-Name =~ /^host\// ) { (12014188) Fri Sep 28 16:27:43 2018: Debug: if ( &User-Name =~ /^host\// ) -> FALSE (12014188) Fri Sep 28 16:27:43 2018: Debug: } # policy forbid_win_host_auth = notfound (12014188) Fri Sep 28 16:27:43 2018: Debug: policy normalize_username { (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") { (12014188) Fri Sep 28 16:27:43 2018: Debug: EXPAND %{tolower:%{User-Name}} (12014188) Fri Sep 28 16:27:43 2018: Debug: --> USER (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") -> FALSE (12014188) Fri Sep 28 16:27:43 2018: Debug: else { (12014188) Fri Sep 28 16:27:43 2018: Debug: [noop] = noop (12014188) Fri Sep 28 16:27:43 2018: Debug: } # else = noop (12014188) Fri Sep 28 16:27:43 2018: Debug: } # policy normalize_username = noop (12014188) Fri Sep 28 16:27:43 2018: Debug: policy filter_username { (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) { (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) -> TRUE (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) { (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ / /) { (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014188) Fri Sep 28 16:27:43 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014188) Fri Sep 28 16:27:43 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.$/) { (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /(a)\./) { (12014188) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014188) Fri Sep 28 16:27:43 2018: Debug: } # if (&User-Name) = noop (12014188) Fri Sep 28 16:27:43 2018: Debug: } # policy filter_username = noop (12014188) Fri Sep 28 16:27:43 2018: Debug: [preprocess] = ok (12014188) Fri Sep 28 16:27:43 2018: Debug: [mschap] = noop (12014188) Fri Sep 28 16:27:43 2018: Debug: suffix: Checking for suffix after "@" (12014188) Fri Sep 28 16:27:43 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014188) Fri Sep 28 16:27:43 2018: Debug: suffix: No such realm "NULL" (12014188) Fri Sep 28 16:27:43 2018: Debug: [suffix] = noop (12014188) Fri Sep 28 16:27:43 2018: Debug: eap: Peer sent EAP Response (code 2) ID 3 length 166 (12014188) Fri Sep 28 16:27:43 2018: Debug: eap: Continuing tunnel setup (12014188) Fri Sep 28 16:27:43 2018: Debug: [eap] = ok (12014188) Fri Sep 28 16:27:43 2018: Debug: } # authorize = ok (12014188) Fri Sep 28 16:27:43 2018: Debug: Found Auth-Type = eap (12014188) Fri Sep 28 16:27:43 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014188) Fri Sep 28 16:27:43 2018: Debug: authenticate { (12014188) Fri Sep 28 16:27:43 2018: Debug: eap: Expiring EAP session with state 0x3284a47d328ebe20 (12014188) Fri Sep 28 16:27:43 2018: Debug: eap: Finished EAP session with state 0x4a8916764a8a0f76 (12014188) Fri Sep 28 16:27:43 2018: Debug: eap: Previous EAP request found for state 0x4a8916764a8a0f76, released from the list (12014188) Fri Sep 28 16:27:43 2018: Debug: eap: Peer sent packet with method EAP PEAP (25) (12014188) Fri Sep 28 16:27:43 2018: Debug: eap: Calling submodule eap_peap to process data (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Continuing EAP-TLS (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Peer indicated complete TLS record size will be 156 bytes (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Got complete TLS record (156 bytes) (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: [eaptls verify] = length included (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: (other): before SSL initialization (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: before SSL initialization (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: before SSL initialization (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: SSLv3/TLS read client hello (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: SSLv3/TLS write server hello (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: SSLv3/TLS write certificate (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: SSLv3/TLS write key exchange (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: SSLv3/TLS write server done (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: Need to read more data: SSLv3/TLS write server done (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: In SSL Handshake Phase (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: In SSL Accept mode (12014188) Fri Sep 28 16:27:43 2018: Debug: eap_peap: [eaptls process] = handled (12014188) Fri Sep 28 16:27:43 2018: Debug: eap: Sending EAP Request (code 1) ID 4 length 1014 (12014188) Fri Sep 28 16:27:43 2018: Debug: eap: EAP session adding &reply:State = 0x4a8916764b8d0f76 (12014188) Fri Sep 28 16:27:43 2018: Debug: [eap] = handled (12014188) Fri Sep 28 16:27:43 2018: Debug: } # authenticate = handled (12014188) Fri Sep 28 16:27:43 2018: Debug: Using Post-Auth-Type Challenge (12014188) Fri Sep 28 16:27:43 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (12014188) Fri Sep 28 16:27:43 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014188) Fri Sep 28 16:27:43 2018: Debug: Sent Access-Challenge Id 31 from 192.168.19.93:1812 to 130.192.119.80:33713 length 0 (12014188) Fri Sep 28 16:27:43 2018: Debug: EAP-Message = 0x010403f619c000000fa2160303003d020000390303ca0711321a19105799591371046c5540290f34e4d6d9b6c19a2e73ae4aa1c31000c030000011ff01000100000b000403000102001700001603030e000b000dfc000df9000536308205323082041aa00302010202100c0b470919f41d1d2384e8715b (12014188) Fri Sep 28 16:27:43 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014188) Fri Sep 28 16:27:43 2018: Debug: State = 0x4a8916764b8d0f7661caf9ec4798bf13 (12014188) Fri Sep 28 16:27:43 2018: Debug: Proxy-State = 0x313636 (12014188) Fri Sep 28 16:27:43 2018: Debug: Finished request (12014189) Fri Sep 28 16:27:43 2018: Debug: Received Access-Request Id 254 from 130.192.119.80:33713 to 192.168.19.93:1812 length 296 (12014189) Fri Sep 28 16:27:43 2018: Debug: User-Name = "USER" (12014189) Fri Sep 28 16:27:43 2018: Debug: Chargeable-User-Identity = 0x00 (12014189) Fri Sep 28 16:27:43 2018: Debug: Location-Capable = Civix-Location (12014189) Fri Sep 28 16:27:43 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014189) Fri Sep 28 16:27:43 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014189) Fri Sep 28 16:27:43 2018: Debug: NAS-Port = 13 (12014189) Fri Sep 28 16:27:43 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014189) Fri Sep 28 16:27:43 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014189) Fri Sep 28 16:27:43 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014189) Fri Sep 28 16:27:43 2018: Debug: NAS-Identifier = "wlc-lin" (12014189) Fri Sep 28 16:27:43 2018: Debug: Airespace-Wlan-Id = 1 (12014189) Fri Sep 28 16:27:43 2018: Debug: Service-Type = Framed-User (12014189) Fri Sep 28 16:27:43 2018: Debug: Framed-MTU = 1300 (12014189) Fri Sep 28 16:27:43 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014189) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Type:0 = VLAN (12014189) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014189) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014189) Fri Sep 28 16:27:43 2018: Debug: EAP-Message = 0x020400061900 (12014189) Fri Sep 28 16:27:43 2018: Debug: State = 0x4a8916764b8d0f7661caf9ec4798bf13 (12014189) Fri Sep 28 16:27:43 2018: Debug: Message-Authenticator = 0x6157ae71fe63d397936d792731d9612d (12014189) Fri Sep 28 16:27:43 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:43 CEST" (12014189) Fri Sep 28 16:27:43 2018: Debug: Proxy-State = 0x313637 (12014189) Fri Sep 28 16:27:43 2018: Debug: session-state: No cached attributes (12014189) Fri Sep 28 16:27:43 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (12014189) Fri Sep 28 16:27:43 2018: Debug: authorize { (12014189) Fri Sep 28 16:27:43 2018: Debug: policy forbid_win_host_auth { (12014189) Fri Sep 28 16:27:43 2018: Debug: if ( &User-Name =~ /^host\// ) { (12014189) Fri Sep 28 16:27:43 2018: Debug: if ( &User-Name =~ /^host\// ) -> FALSE (12014189) Fri Sep 28 16:27:43 2018: Debug: } # policy forbid_win_host_auth = notfound (12014189) Fri Sep 28 16:27:43 2018: Debug: policy normalize_username { (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") { (12014189) Fri Sep 28 16:27:43 2018: Debug: EXPAND %{tolower:%{User-Name}} (12014189) Fri Sep 28 16:27:43 2018: Debug: --> USER (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") -> FALSE (12014189) Fri Sep 28 16:27:43 2018: Debug: else { (12014189) Fri Sep 28 16:27:43 2018: Debug: [noop] = noop (12014189) Fri Sep 28 16:27:43 2018: Debug: } # else = noop (12014189) Fri Sep 28 16:27:43 2018: Debug: } # policy normalize_username = noop (12014189) Fri Sep 28 16:27:43 2018: Debug: policy filter_username { (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) { (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) -> TRUE (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) { (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ / /) { (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014189) Fri Sep 28 16:27:43 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014189) Fri Sep 28 16:27:43 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.$/) { (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /(a)\./) { (12014189) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014189) Fri Sep 28 16:27:43 2018: Debug: } # if (&User-Name) = noop (12014189) Fri Sep 28 16:27:43 2018: Debug: } # policy filter_username = noop (12014189) Fri Sep 28 16:27:43 2018: Debug: [preprocess] = ok (12014189) Fri Sep 28 16:27:43 2018: Debug: [mschap] = noop (12014189) Fri Sep 28 16:27:43 2018: Debug: suffix: Checking for suffix after "@" (12014189) Fri Sep 28 16:27:43 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014189) Fri Sep 28 16:27:43 2018: Debug: suffix: No such realm "NULL" (12014189) Fri Sep 28 16:27:43 2018: Debug: [suffix] = noop (12014189) Fri Sep 28 16:27:43 2018: Debug: eap: Peer sent EAP Response (code 2) ID 4 length 6 (12014189) Fri Sep 28 16:27:43 2018: Debug: eap: Continuing tunnel setup (12014189) Fri Sep 28 16:27:43 2018: Debug: [eap] = ok (12014189) Fri Sep 28 16:27:43 2018: Debug: } # authorize = ok (12014189) Fri Sep 28 16:27:43 2018: Debug: Found Auth-Type = eap (12014189) Fri Sep 28 16:27:43 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014189) Fri Sep 28 16:27:43 2018: Debug: authenticate { (12014189) Fri Sep 28 16:27:43 2018: Debug: eap: Expiring EAP session with state 0x3284a47d328ebe20 (12014189) Fri Sep 28 16:27:43 2018: Debug: eap: Finished EAP session with state 0x4a8916764b8d0f76 (12014189) Fri Sep 28 16:27:43 2018: Debug: eap: Previous EAP request found for state 0x4a8916764b8d0f76, released from the list (12014189) Fri Sep 28 16:27:43 2018: Debug: eap: Peer sent packet with method EAP PEAP (25) (12014189) Fri Sep 28 16:27:43 2018: Debug: eap: Calling submodule eap_peap to process data (12014189) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Continuing EAP-TLS (12014189) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Peer ACKed our handshake fragment (12014189) Fri Sep 28 16:27:43 2018: Debug: eap_peap: [eaptls verify] = request (12014189) Fri Sep 28 16:27:43 2018: Debug: eap_peap: [eaptls process] = handled (12014189) Fri Sep 28 16:27:43 2018: Debug: eap: Sending EAP Request (code 1) ID 5 length 1010 (12014189) Fri Sep 28 16:27:43 2018: Debug: eap: EAP session adding &reply:State = 0x4a891676488c0f76 (12014189) Fri Sep 28 16:27:43 2018: Debug: [eap] = handled (12014189) Fri Sep 28 16:27:43 2018: Debug: } # authenticate = handled (12014189) Fri Sep 28 16:27:43 2018: Debug: Using Post-Auth-Type Challenge (12014189) Fri Sep 28 16:27:43 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (12014189) Fri Sep 28 16:27:43 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014189) Fri Sep 28 16:27:43 2018: Debug: Sent Access-Challenge Id 254 from 192.168.19.93:1812 to 130.192.119.80:33713 length 0 (12014189) Fri Sep 28 16:27:43 2018: Debug: EAP-Message = 0x010503f2194008060667810c010202306e06082b0601050507010104623060302406082b060105050730018618687474703a2f2f6f6373702e64696769636572742e636f6d303806082b06010505073002862c687474703a2f2f636163657274732e64696769636572742e636f6d2f544552454e415353 (12014189) Fri Sep 28 16:27:43 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014189) Fri Sep 28 16:27:43 2018: Debug: State = 0x4a891676488c0f7661caf9ec4798bf13 (12014189) Fri Sep 28 16:27:43 2018: Debug: Proxy-State = 0x313637 (12014189) Fri Sep 28 16:27:43 2018: Debug: Finished request (12014190) Fri Sep 28 16:27:43 2018: Debug: Received Access-Request Id 4 from 130.192.119.80:33713 to 192.168.19.93:1812 length 296 (12014190) Fri Sep 28 16:27:43 2018: Debug: User-Name = "USER" (12014190) Fri Sep 28 16:27:43 2018: Debug: Chargeable-User-Identity = 0x00 (12014190) Fri Sep 28 16:27:43 2018: Debug: Location-Capable = Civix-Location (12014190) Fri Sep 28 16:27:43 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014190) Fri Sep 28 16:27:43 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014190) Fri Sep 28 16:27:43 2018: Debug: NAS-Port = 13 (12014190) Fri Sep 28 16:27:43 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014190) Fri Sep 28 16:27:43 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014190) Fri Sep 28 16:27:43 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014190) Fri Sep 28 16:27:43 2018: Debug: NAS-Identifier = "wlc-lin" (12014190) Fri Sep 28 16:27:43 2018: Debug: Airespace-Wlan-Id = 1 (12014190) Fri Sep 28 16:27:43 2018: Debug: Service-Type = Framed-User (12014190) Fri Sep 28 16:27:43 2018: Debug: Framed-MTU = 1300 (12014190) Fri Sep 28 16:27:43 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014190) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Type:0 = VLAN (12014190) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014190) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014190) Fri Sep 28 16:27:43 2018: Debug: EAP-Message = 0x020500061900 (12014190) Fri Sep 28 16:27:43 2018: Debug: State = 0x4a891676488c0f7661caf9ec4798bf13 (12014190) Fri Sep 28 16:27:43 2018: Debug: Message-Authenticator = 0xb11330e666b8f603e83639bc481f4367 (12014190) Fri Sep 28 16:27:43 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:43 CEST" (12014190) Fri Sep 28 16:27:43 2018: Debug: Proxy-State = 0x313638 (12014190) Fri Sep 28 16:27:43 2018: Debug: session-state: No cached attributes (12014190) Fri Sep 28 16:27:43 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (12014190) Fri Sep 28 16:27:43 2018: Debug: authorize { (12014190) Fri Sep 28 16:27:43 2018: Debug: policy forbid_win_host_auth { (12014190) Fri Sep 28 16:27:43 2018: Debug: if ( &User-Name =~ /^host\// ) { (12014190) Fri Sep 28 16:27:43 2018: Debug: if ( &User-Name =~ /^host\// ) -> FALSE (12014190) Fri Sep 28 16:27:43 2018: Debug: } # policy forbid_win_host_auth = notfound (12014190) Fri Sep 28 16:27:43 2018: Debug: policy normalize_username { (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") { (12014190) Fri Sep 28 16:27:43 2018: Debug: EXPAND %{tolower:%{User-Name}} (12014190) Fri Sep 28 16:27:43 2018: Debug: --> USER (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") -> FALSE (12014190) Fri Sep 28 16:27:43 2018: Debug: else { (12014190) Fri Sep 28 16:27:43 2018: Debug: [noop] = noop (12014190) Fri Sep 28 16:27:43 2018: Debug: } # else = noop (12014190) Fri Sep 28 16:27:43 2018: Debug: } # policy normalize_username = noop (12014190) Fri Sep 28 16:27:43 2018: Debug: policy filter_username { (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) { (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) -> TRUE (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) { (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ / /) { (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014190) Fri Sep 28 16:27:43 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014190) Fri Sep 28 16:27:43 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.$/) { (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /(a)\./) { (12014190) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014190) Fri Sep 28 16:27:43 2018: Debug: } # if (&User-Name) = noop (12014190) Fri Sep 28 16:27:43 2018: Debug: } # policy filter_username = noop (12014190) Fri Sep 28 16:27:43 2018: Debug: [preprocess] = ok (12014190) Fri Sep 28 16:27:43 2018: Debug: [mschap] = noop (12014190) Fri Sep 28 16:27:43 2018: Debug: suffix: Checking for suffix after "@" (12014190) Fri Sep 28 16:27:43 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014190) Fri Sep 28 16:27:43 2018: Debug: suffix: No such realm "NULL" (12014190) Fri Sep 28 16:27:43 2018: Debug: [suffix] = noop (12014190) Fri Sep 28 16:27:43 2018: Debug: eap: Peer sent EAP Response (code 2) ID 5 length 6 (12014190) Fri Sep 28 16:27:43 2018: Debug: eap: Continuing tunnel setup (12014190) Fri Sep 28 16:27:43 2018: Debug: [eap] = ok (12014190) Fri Sep 28 16:27:43 2018: Debug: } # authorize = ok (12014190) Fri Sep 28 16:27:43 2018: Debug: Found Auth-Type = eap (12014190) Fri Sep 28 16:27:43 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014190) Fri Sep 28 16:27:43 2018: Debug: authenticate { (12014190) Fri Sep 28 16:27:43 2018: Debug: eap: Expiring EAP session with state 0x3284a47d328ebe20 (12014190) Fri Sep 28 16:27:43 2018: Debug: eap: Finished EAP session with state 0x4a891676488c0f76 (12014190) Fri Sep 28 16:27:43 2018: Debug: eap: Previous EAP request found for state 0x4a891676488c0f76, released from the list (12014190) Fri Sep 28 16:27:43 2018: Debug: eap: Peer sent packet with method EAP PEAP (25) (12014190) Fri Sep 28 16:27:43 2018: Debug: eap: Calling submodule eap_peap to process data (12014190) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Continuing EAP-TLS (12014190) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Peer ACKed our handshake fragment (12014190) Fri Sep 28 16:27:43 2018: Debug: eap_peap: [eaptls verify] = request (12014190) Fri Sep 28 16:27:43 2018: Debug: eap_peap: [eaptls process] = handled (12014190) Fri Sep 28 16:27:43 2018: Debug: eap: Sending EAP Request (code 1) ID 6 length 1010 (12014190) Fri Sep 28 16:27:43 2018: Debug: eap: EAP session adding &reply:State = 0x4a891676498f0f76 (12014190) Fri Sep 28 16:27:43 2018: Debug: [eap] = handled (12014190) Fri Sep 28 16:27:43 2018: Debug: } # authenticate = handled (12014190) Fri Sep 28 16:27:43 2018: Debug: Using Post-Auth-Type Challenge (12014190) Fri Sep 28 16:27:43 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (12014190) Fri Sep 28 16:27:43 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014190) Fri Sep 28 16:27:43 2018: Debug: Sent Access-Challenge Id 4 from 192.168.19.93:1812 to 130.192.119.80:33713 length 0 (12014190) Fri Sep 28 16:27:43 2018: Debug: EAP-Message = 0x010603f219401d130101ff040830060101ff020100300e0603551d0f0101ff040403020186307906082b06010505070101046d306b302406082b060105050730018618687474703a2f2f6f6373702e64696769636572742e636f6d304306082b060105050730028637687474703a2f2f63616365727473 (12014190) Fri Sep 28 16:27:43 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014190) Fri Sep 28 16:27:43 2018: Debug: State = 0x4a891676498f0f7661caf9ec4798bf13 (12014190) Fri Sep 28 16:27:43 2018: Debug: Proxy-State = 0x313638 (12014190) Fri Sep 28 16:27:43 2018: Debug: Finished request (12014191) Fri Sep 28 16:27:43 2018: Debug: Received Access-Request Id 76 from 130.192.119.80:33713 to 192.168.19.93:1812 length 296 (12014191) Fri Sep 28 16:27:43 2018: Debug: User-Name = "USER" (12014191) Fri Sep 28 16:27:43 2018: Debug: Chargeable-User-Identity = 0x00 (12014191) Fri Sep 28 16:27:43 2018: Debug: Location-Capable = Civix-Location (12014191) Fri Sep 28 16:27:43 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014191) Fri Sep 28 16:27:43 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014191) Fri Sep 28 16:27:43 2018: Debug: NAS-Port = 13 (12014191) Fri Sep 28 16:27:43 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014191) Fri Sep 28 16:27:43 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014191) Fri Sep 28 16:27:43 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014191) Fri Sep 28 16:27:43 2018: Debug: NAS-Identifier = "wlc-lin" (12014191) Fri Sep 28 16:27:43 2018: Debug: Airespace-Wlan-Id = 1 (12014191) Fri Sep 28 16:27:43 2018: Debug: Service-Type = Framed-User (12014191) Fri Sep 28 16:27:43 2018: Debug: Framed-MTU = 1300 (12014191) Fri Sep 28 16:27:43 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014191) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Type:0 = VLAN (12014191) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014191) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014191) Fri Sep 28 16:27:43 2018: Debug: EAP-Message = 0x020600061900 (12014191) Fri Sep 28 16:27:43 2018: Debug: State = 0x4a891676498f0f7661caf9ec4798bf13 (12014191) Fri Sep 28 16:27:43 2018: Debug: Message-Authenticator = 0xa74588a00ca5aa323596e13a85ac485b (12014191) Fri Sep 28 16:27:43 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:43 CEST" (12014191) Fri Sep 28 16:27:43 2018: Debug: Proxy-State = 0x313639 (12014191) Fri Sep 28 16:27:43 2018: Debug: session-state: No cached attributes (12014191) Fri Sep 28 16:27:43 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (12014191) Fri Sep 28 16:27:43 2018: Debug: authorize { (12014191) Fri Sep 28 16:27:43 2018: Debug: policy forbid_win_host_auth { (12014191) Fri Sep 28 16:27:43 2018: Debug: if ( &User-Name =~ /^host\// ) { (12014191) Fri Sep 28 16:27:43 2018: Debug: if ( &User-Name =~ /^host\// ) -> FALSE (12014191) Fri Sep 28 16:27:43 2018: Debug: } # policy forbid_win_host_auth = notfound (12014191) Fri Sep 28 16:27:43 2018: Debug: policy normalize_username { (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") { (12014191) Fri Sep 28 16:27:43 2018: Debug: EXPAND %{tolower:%{User-Name}} (12014191) Fri Sep 28 16:27:43 2018: Debug: --> USER (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") -> FALSE (12014191) Fri Sep 28 16:27:43 2018: Debug: else { (12014191) Fri Sep 28 16:27:43 2018: Debug: [noop] = noop (12014191) Fri Sep 28 16:27:43 2018: Debug: } # else = noop (12014191) Fri Sep 28 16:27:43 2018: Debug: } # policy normalize_username = noop (12014191) Fri Sep 28 16:27:43 2018: Debug: policy filter_username { (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) { (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) -> TRUE (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) { (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ / /) { (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014191) Fri Sep 28 16:27:43 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014191) Fri Sep 28 16:27:43 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.$/) { (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /(a)\./) { (12014191) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014191) Fri Sep 28 16:27:43 2018: Debug: } # if (&User-Name) = noop (12014191) Fri Sep 28 16:27:43 2018: Debug: } # policy filter_username = noop (12014191) Fri Sep 28 16:27:43 2018: Debug: [preprocess] = ok (12014191) Fri Sep 28 16:27:43 2018: Debug: [mschap] = noop (12014191) Fri Sep 28 16:27:43 2018: Debug: suffix: Checking for suffix after "@" (12014191) Fri Sep 28 16:27:43 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014191) Fri Sep 28 16:27:43 2018: Debug: suffix: No such realm "NULL" (12014191) Fri Sep 28 16:27:43 2018: Debug: [suffix] = noop (12014191) Fri Sep 28 16:27:43 2018: Debug: eap: Peer sent EAP Response (code 2) ID 6 length 6 (12014191) Fri Sep 28 16:27:43 2018: Debug: eap: Continuing tunnel setup (12014191) Fri Sep 28 16:27:43 2018: Debug: [eap] = ok (12014191) Fri Sep 28 16:27:43 2018: Debug: } # authorize = ok (12014191) Fri Sep 28 16:27:43 2018: Debug: Found Auth-Type = eap (12014191) Fri Sep 28 16:27:43 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014191) Fri Sep 28 16:27:43 2018: Debug: authenticate { (12014191) Fri Sep 28 16:27:43 2018: Debug: eap: Expiring EAP session with state 0x3284a47d328ebe20 (12014191) Fri Sep 28 16:27:43 2018: Debug: eap: Finished EAP session with state 0x4a891676498f0f76 (12014191) Fri Sep 28 16:27:43 2018: Debug: eap: Previous EAP request found for state 0x4a891676498f0f76, released from the list (12014191) Fri Sep 28 16:27:43 2018: Debug: eap: Peer sent packet with method EAP PEAP (25) (12014191) Fri Sep 28 16:27:43 2018: Debug: eap: Calling submodule eap_peap to process data (12014191) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Continuing EAP-TLS (12014191) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Peer ACKed our handshake fragment (12014191) Fri Sep 28 16:27:43 2018: Debug: eap_peap: [eaptls verify] = request (12014191) Fri Sep 28 16:27:43 2018: Debug: eap_peap: [eaptls process] = handled (12014191) Fri Sep 28 16:27:43 2018: Debug: eap: Sending EAP Request (code 1) ID 7 length 996 (12014191) Fri Sep 28 16:27:43 2018: Debug: eap: EAP session adding &reply:State = 0x4a8916764e8e0f76 (12014191) Fri Sep 28 16:27:43 2018: Debug: [eap] = handled (12014191) Fri Sep 28 16:27:43 2018: Debug: } # authenticate = handled (12014191) Fri Sep 28 16:27:43 2018: Debug: Using Post-Auth-Type Challenge (12014191) Fri Sep 28 16:27:43 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (12014191) Fri Sep 28 16:27:43 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014191) Fri Sep 28 16:27:43 2018: Debug: Sent Access-Challenge Id 76 from 192.168.19.93:1812 to 130.192.119.80:33713 length 0 (12014191) Fri Sep 28 16:27:43 2018: Debug: EAP-Message = 0x010703e419000282010100ad0e15cee443805cb187f3b760f97112a5aedc269488aaf4cef520392858600cf880daa9159532613cb5b128848a8adc9f0a0c83177a8f90ac8ae779535c31842af60f98323676ccdedd3ca8a2ef6afb21f25261df9f20d71fe2b1d9fe1864d2125b5ff9581835bc47cda136 (12014191) Fri Sep 28 16:27:43 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014191) Fri Sep 28 16:27:43 2018: Debug: State = 0x4a8916764e8e0f7661caf9ec4798bf13 (12014191) Fri Sep 28 16:27:43 2018: Debug: Proxy-State = 0x313639 (12014191) Fri Sep 28 16:27:43 2018: Debug: Finished request (12014192) Fri Sep 28 16:27:43 2018: Debug: Received Access-Request Id 13 from 130.192.119.80:33713 to 192.168.19.93:1812 length 426 (12014192) Fri Sep 28 16:27:43 2018: Debug: User-Name = "USER" (12014192) Fri Sep 28 16:27:43 2018: Debug: Chargeable-User-Identity = 0x00 (12014192) Fri Sep 28 16:27:43 2018: Debug: Location-Capable = Civix-Location (12014192) Fri Sep 28 16:27:43 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014192) Fri Sep 28 16:27:43 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014192) Fri Sep 28 16:27:43 2018: Debug: NAS-Port = 13 (12014192) Fri Sep 28 16:27:43 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014192) Fri Sep 28 16:27:43 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014192) Fri Sep 28 16:27:43 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014192) Fri Sep 28 16:27:43 2018: Debug: NAS-Identifier = "wlc-lin" (12014192) Fri Sep 28 16:27:43 2018: Debug: Airespace-Wlan-Id = 1 (12014192) Fri Sep 28 16:27:43 2018: Debug: Service-Type = Framed-User (12014192) Fri Sep 28 16:27:43 2018: Debug: Framed-MTU = 1300 (12014192) Fri Sep 28 16:27:43 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014192) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Type:0 = VLAN (12014192) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014192) Fri Sep 28 16:27:43 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014192) Fri Sep 28 16:27:43 2018: Debug: EAP-Message = 0x0207008819800000007e160303004610000042410492cc0a049c313744be89f4fad474e76bf5bbbe8f7630e42dfef34a53dfce8a44ea1e37b1a61895e4776f47577c5b6bda0e3aff2934b6898549ac1b7b3f7c249e14030300010116030300280000000000000000d349e31e6d934aae9a1c69e7478279 (12014192) Fri Sep 28 16:27:43 2018: Debug: State = 0x4a8916764e8e0f7661caf9ec4798bf13 (12014192) Fri Sep 28 16:27:43 2018: Debug: Message-Authenticator = 0x7114901a53f0d646ce8518bec779ec21 (12014192) Fri Sep 28 16:27:43 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:43 CEST" (12014192) Fri Sep 28 16:27:43 2018: Debug: Proxy-State = 0x313730 (12014192) Fri Sep 28 16:27:43 2018: Debug: session-state: No cached attributes (12014192) Fri Sep 28 16:27:43 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (12014192) Fri Sep 28 16:27:43 2018: Debug: authorize { (12014192) Fri Sep 28 16:27:43 2018: Debug: policy forbid_win_host_auth { (12014192) Fri Sep 28 16:27:43 2018: Debug: if ( &User-Name =~ /^host\// ) { (12014192) Fri Sep 28 16:27:43 2018: Debug: if ( &User-Name =~ /^host\// ) -> FALSE (12014192) Fri Sep 28 16:27:43 2018: Debug: } # policy forbid_win_host_auth = notfound (12014192) Fri Sep 28 16:27:43 2018: Debug: policy normalize_username { (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") { (12014192) Fri Sep 28 16:27:43 2018: Debug: EXPAND %{tolower:%{User-Name}} (12014192) Fri Sep 28 16:27:43 2018: Debug: --> USER (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") -> FALSE (12014192) Fri Sep 28 16:27:43 2018: Debug: else { (12014192) Fri Sep 28 16:27:43 2018: Debug: [noop] = noop (12014192) Fri Sep 28 16:27:43 2018: Debug: } # else = noop (12014192) Fri Sep 28 16:27:43 2018: Debug: } # policy normalize_username = noop (12014192) Fri Sep 28 16:27:43 2018: Debug: policy filter_username { (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) { (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) -> TRUE (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name) { (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ / /) { (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014192) Fri Sep 28 16:27:43 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014192) Fri Sep 28 16:27:43 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.$/) { (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /(a)\./) { (12014192) Fri Sep 28 16:27:43 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014192) Fri Sep 28 16:27:43 2018: Debug: } # if (&User-Name) = noop (12014192) Fri Sep 28 16:27:43 2018: Debug: } # policy filter_username = noop (12014192) Fri Sep 28 16:27:43 2018: Debug: [preprocess] = ok (12014192) Fri Sep 28 16:27:43 2018: Debug: [mschap] = noop (12014192) Fri Sep 28 16:27:43 2018: Debug: suffix: Checking for suffix after "@" (12014192) Fri Sep 28 16:27:43 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014192) Fri Sep 28 16:27:43 2018: Debug: suffix: No such realm "NULL" (12014192) Fri Sep 28 16:27:43 2018: Debug: [suffix] = noop (12014192) Fri Sep 28 16:27:43 2018: Debug: eap: Peer sent EAP Response (code 2) ID 7 length 136 (12014192) Fri Sep 28 16:27:43 2018: Debug: eap: Continuing tunnel setup (12014192) Fri Sep 28 16:27:43 2018: Debug: [eap] = ok (12014192) Fri Sep 28 16:27:43 2018: Debug: } # authorize = ok (12014192) Fri Sep 28 16:27:43 2018: Debug: Found Auth-Type = eap (12014192) Fri Sep 28 16:27:43 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014192) Fri Sep 28 16:27:43 2018: Debug: authenticate { (12014192) Fri Sep 28 16:27:43 2018: Debug: eap: Expiring EAP session with state 0x3284a47d328ebe20 (12014192) Fri Sep 28 16:27:43 2018: Debug: eap: Finished EAP session with state 0x4a8916764e8e0f76 (12014192) Fri Sep 28 16:27:43 2018: Debug: eap: Previous EAP request found for state 0x4a8916764e8e0f76, released from the list (12014192) Fri Sep 28 16:27:43 2018: Debug: eap: Peer sent packet with method EAP PEAP (25) (12014192) Fri Sep 28 16:27:43 2018: Debug: eap: Calling submodule eap_peap to process data (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Continuing EAP-TLS (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Peer indicated complete TLS record size will be 126 bytes (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: Got complete TLS record (126 bytes) (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: [eaptls verify] = length included (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: SSLv3/TLS write server done (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: SSLv3/TLS read client key exchange (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: SSLv3/TLS read change cipher spec (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: SSLv3/TLS read finished (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: SSLv3/TLS write change cipher spec (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: TLS_accept: SSLv3/TLS write finished (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: (other): SSL negotiation finished successfully (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: SSL Connection Established (12014192) Fri Sep 28 16:27:43 2018: Debug: eap_peap: [eaptls process] = handled (12014192) Fri Sep 28 16:27:43 2018: Debug: eap: Sending EAP Request (code 1) ID 8 length 57 (12014192) Fri Sep 28 16:27:43 2018: Debug: eap: EAP session adding &reply:State = 0x4a8916764f810f76 (12014192) Fri Sep 28 16:27:43 2018: Debug: [eap] = handled (12014192) Fri Sep 28 16:27:43 2018: Debug: } # authenticate = handled (12014192) Fri Sep 28 16:27:43 2018: Debug: Using Post-Auth-Type Challenge (12014192) Fri Sep 28 16:27:43 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (12014192) Fri Sep 28 16:27:43 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014192) Fri Sep 28 16:27:43 2018: Debug: Sent Access-Challenge Id 13 from 192.168.19.93:1812 to 130.192.119.80:33713 length 0 (12014192) Fri Sep 28 16:27:43 2018: Debug: EAP-Message = 0x0108003919001403030001011603030028ad1ff295a543d4925d728be01399e83219afc001b8ed4d3ee1772404eecaebf64d10d02295d8db61 (12014192) Fri Sep 28 16:27:43 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014192) Fri Sep 28 16:27:43 2018: Debug: State = 0x4a8916764f810f7661caf9ec4798bf13 (12014192) Fri Sep 28 16:27:43 2018: Debug: Proxy-State = 0x313730 (12014192) Fri Sep 28 16:27:43 2018: Debug: Finished request (12014206) Fri Sep 28 16:27:46 2018: Debug: Received Access-Request Id 114 from 130.192.119.80:33713 to 192.168.19.93:1812 length 296 (12014206) Fri Sep 28 16:27:46 2018: Debug: User-Name = "USER" (12014206) Fri Sep 28 16:27:46 2018: Debug: Chargeable-User-Identity = 0x00 (12014206) Fri Sep 28 16:27:46 2018: Debug: Location-Capable = Civix-Location (12014206) Fri Sep 28 16:27:46 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014206) Fri Sep 28 16:27:46 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014206) Fri Sep 28 16:27:46 2018: Debug: NAS-Port = 13 (12014206) Fri Sep 28 16:27:46 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014206) Fri Sep 28 16:27:46 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014206) Fri Sep 28 16:27:46 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014206) Fri Sep 28 16:27:46 2018: Debug: NAS-Identifier = "wlc-lin" (12014206) Fri Sep 28 16:27:46 2018: Debug: Airespace-Wlan-Id = 1 (12014206) Fri Sep 28 16:27:46 2018: Debug: Service-Type = Framed-User (12014206) Fri Sep 28 16:27:46 2018: Debug: Framed-MTU = 1300 (12014206) Fri Sep 28 16:27:46 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014206) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Type:0 = VLAN (12014206) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014206) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014206) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x020800061900 (12014206) Fri Sep 28 16:27:46 2018: Debug: State = 0x4a8916764f810f7661caf9ec4798bf13 (12014206) Fri Sep 28 16:27:46 2018: Debug: Message-Authenticator = 0x92a0fff2fc7057153e5d6702efc8873d (12014206) Fri Sep 28 16:27:46 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:46 CEST" (12014206) Fri Sep 28 16:27:46 2018: Debug: Proxy-State = 0x313736 (12014206) Fri Sep 28 16:27:46 2018: Debug: session-state: No cached attributes (12014206) Fri Sep 28 16:27:46 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (12014206) Fri Sep 28 16:27:46 2018: Debug: authorize { (12014206) Fri Sep 28 16:27:46 2018: Debug: policy forbid_win_host_auth { (12014206) Fri Sep 28 16:27:46 2018: Debug: if ( &User-Name =~ /^host\// ) { (12014206) Fri Sep 28 16:27:46 2018: Debug: if ( &User-Name =~ /^host\// ) -> FALSE (12014206) Fri Sep 28 16:27:46 2018: Debug: } # policy forbid_win_host_auth = notfound (12014206) Fri Sep 28 16:27:46 2018: Debug: policy normalize_username { (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") { (12014206) Fri Sep 28 16:27:46 2018: Debug: EXPAND %{tolower:%{User-Name}} (12014206) Fri Sep 28 16:27:46 2018: Debug: --> USER (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") -> FALSE (12014206) Fri Sep 28 16:27:46 2018: Debug: else { (12014206) Fri Sep 28 16:27:46 2018: Debug: [noop] = noop (12014206) Fri Sep 28 16:27:46 2018: Debug: } # else = noop (12014206) Fri Sep 28 16:27:46 2018: Debug: } # policy normalize_username = noop (12014206) Fri Sep 28 16:27:46 2018: Debug: policy filter_username { (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) -> TRUE (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) { (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014206) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014206) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) { (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) { (12014206) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014206) Fri Sep 28 16:27:46 2018: Debug: } # if (&User-Name) = noop (12014206) Fri Sep 28 16:27:46 2018: Debug: } # policy filter_username = noop (12014206) Fri Sep 28 16:27:46 2018: Debug: [preprocess] = ok (12014206) Fri Sep 28 16:27:46 2018: Debug: [mschap] = noop (12014206) Fri Sep 28 16:27:46 2018: Debug: suffix: Checking for suffix after "@" (12014206) Fri Sep 28 16:27:46 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014206) Fri Sep 28 16:27:46 2018: Debug: suffix: No such realm "NULL" (12014206) Fri Sep 28 16:27:46 2018: Debug: [suffix] = noop (12014206) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent EAP Response (code 2) ID 8 length 6 (12014206) Fri Sep 28 16:27:46 2018: Debug: eap: Continuing tunnel setup (12014206) Fri Sep 28 16:27:46 2018: Debug: [eap] = ok (12014206) Fri Sep 28 16:27:46 2018: Debug: } # authorize = ok (12014206) Fri Sep 28 16:27:46 2018: Debug: Found Auth-Type = eap (12014206) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014206) Fri Sep 28 16:27:46 2018: Debug: authenticate { (12014206) Fri Sep 28 16:27:46 2018: Debug: eap: Expiring EAP session with state 0x3284a47d328ebe20 (12014206) Fri Sep 28 16:27:46 2018: Debug: eap: Finished EAP session with state 0x4a8916764f810f76 (12014206) Fri Sep 28 16:27:46 2018: Debug: eap: Previous EAP request found for state 0x4a8916764f810f76, released from the list (12014206) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent packet with method EAP PEAP (25) (12014206) Fri Sep 28 16:27:46 2018: Debug: eap: Calling submodule eap_peap to process data (12014206) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Continuing EAP-TLS (12014206) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Peer ACKed our handshake fragment. handshake is finished (12014206) Fri Sep 28 16:27:46 2018: Debug: eap_peap: [eaptls verify] = success (12014206) Fri Sep 28 16:27:46 2018: Debug: eap_peap: [eaptls process] = success (12014206) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Session established. Decoding tunneled attributes (12014206) Fri Sep 28 16:27:46 2018: Debug: eap_peap: PEAP state TUNNEL ESTABLISHED (12014206) Fri Sep 28 16:27:46 2018: Debug: eap: Sending EAP Request (code 1) ID 9 length 40 (12014206) Fri Sep 28 16:27:46 2018: Debug: eap: EAP session adding &reply:State = 0x4a8916764c800f76 (12014206) Fri Sep 28 16:27:46 2018: Debug: [eap] = handled (12014206) Fri Sep 28 16:27:46 2018: Debug: } # authenticate = handled (12014206) Fri Sep 28 16:27:46 2018: Debug: Using Post-Auth-Type Challenge (12014206) Fri Sep 28 16:27:46 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (12014206) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014206) Fri Sep 28 16:27:46 2018: Debug: Sent Access-Challenge Id 114 from 192.168.19.93:1812 to 130.192.119.80:33713 length 0 (12014206) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x010900281900170303001dad1ff295a543d493985fec914519565dd6c4a59cb71424a1b6bf75c011 (12014206) Fri Sep 28 16:27:46 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014206) Fri Sep 28 16:27:46 2018: Debug: State = 0x4a8916764c800f7661caf9ec4798bf13 (12014206) Fri Sep 28 16:27:46 2018: Debug: Proxy-State = 0x313736 (12014206) Fri Sep 28 16:27:46 2018: Debug: Finished request (12014207) Fri Sep 28 16:27:46 2018: Debug: Received Access-Request Id 34 from 130.192.119.80:33713 to 192.168.19.93:1812 length 342 (12014207) Fri Sep 28 16:27:46 2018: Debug: User-Name = "USER" (12014207) Fri Sep 28 16:27:46 2018: Debug: Chargeable-User-Identity = 0x00 (12014207) Fri Sep 28 16:27:46 2018: Debug: Location-Capable = Civix-Location (12014207) Fri Sep 28 16:27:46 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014207) Fri Sep 28 16:27:46 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014207) Fri Sep 28 16:27:46 2018: Debug: NAS-Port = 13 (12014207) Fri Sep 28 16:27:46 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014207) Fri Sep 28 16:27:46 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014207) Fri Sep 28 16:27:46 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014207) Fri Sep 28 16:27:46 2018: Debug: NAS-Identifier = "wlc-lin" (12014207) Fri Sep 28 16:27:46 2018: Debug: Airespace-Wlan-Id = 1 (12014207) Fri Sep 28 16:27:46 2018: Debug: Service-Type = Framed-User (12014207) Fri Sep 28 16:27:46 2018: Debug: Framed-MTU = 1300 (12014207) Fri Sep 28 16:27:46 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014207) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Type:0 = VLAN (12014207) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014207) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014207) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x02090034190017030300290000000000000001cc129720c2092186d6eefa43bb9b9e015b0f486ae1501f8b5074d17be5f9e6743f (12014207) Fri Sep 28 16:27:46 2018: Debug: State = 0x4a8916764c800f7661caf9ec4798bf13 (12014207) Fri Sep 28 16:27:46 2018: Debug: Message-Authenticator = 0x271d46101a1c2c015fa1b1d233e6f42a (12014207) Fri Sep 28 16:27:46 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:46 CEST" (12014207) Fri Sep 28 16:27:46 2018: Debug: Proxy-State = 0x313737 (12014207) Fri Sep 28 16:27:46 2018: Debug: session-state: No cached attributes (12014207) Fri Sep 28 16:27:46 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (12014207) Fri Sep 28 16:27:46 2018: Debug: authorize { (12014207) Fri Sep 28 16:27:46 2018: Debug: policy forbid_win_host_auth { (12014207) Fri Sep 28 16:27:46 2018: Debug: if ( &User-Name =~ /^host\// ) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if ( &User-Name =~ /^host\// ) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: } # policy forbid_win_host_auth = notfound (12014207) Fri Sep 28 16:27:46 2018: Debug: policy normalize_username { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") { (12014207) Fri Sep 28 16:27:46 2018: Debug: EXPAND %{tolower:%{User-Name}} (12014207) Fri Sep 28 16:27:46 2018: Debug: --> USER (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: else { (12014207) Fri Sep 28 16:27:46 2018: Debug: [noop] = noop (12014207) Fri Sep 28 16:27:46 2018: Debug: } # else = noop (12014207) Fri Sep 28 16:27:46 2018: Debug: } # policy normalize_username = noop (12014207) Fri Sep 28 16:27:46 2018: Debug: policy filter_username { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) -> TRUE (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: } # if (&User-Name) = noop (12014207) Fri Sep 28 16:27:46 2018: Debug: } # policy filter_username = noop (12014207) Fri Sep 28 16:27:46 2018: Debug: [preprocess] = ok (12014207) Fri Sep 28 16:27:46 2018: Debug: [mschap] = noop (12014207) Fri Sep 28 16:27:46 2018: Debug: suffix: Checking for suffix after "@" (12014207) Fri Sep 28 16:27:46 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014207) Fri Sep 28 16:27:46 2018: Debug: suffix: No such realm "NULL" (12014207) Fri Sep 28 16:27:46 2018: Debug: [suffix] = noop (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent EAP Response (code 2) ID 9 length 52 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: Continuing tunnel setup (12014207) Fri Sep 28 16:27:46 2018: Debug: [eap] = ok (12014207) Fri Sep 28 16:27:46 2018: Debug: } # authorize = ok (12014207) Fri Sep 28 16:27:46 2018: Debug: Found Auth-Type = eap (12014207) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014207) Fri Sep 28 16:27:46 2018: Debug: authenticate { (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: Expiring EAP session with state 0x3284a47d328ebe20 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: Finished EAP session with state 0x4a8916764c800f76 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: Previous EAP request found for state 0x4a8916764c800f76, released from the list (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent packet with method EAP PEAP (25) (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: Calling submodule eap_peap to process data (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Continuing EAP-TLS (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: [eaptls verify] = ok (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Done initial handshake (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: [eaptls process] = ok (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Session established. Decoding tunneled attributes (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: PEAP state WAITING FOR INNER IDENTITY (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Identity - USER (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Got inner identity 'USER' (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Setting default EAP type for tunneled EAP session (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Got tunneled request (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: EAP-Message = 0x02090015016d61747469612e6265676f766f657661 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Setting User-Name to USER (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Sending tunneled request to inner-tunnel (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: EAP-Message = 0x02090015016d61747469612e6265676f766f657661 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: User-Name = "USER" (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Chargeable-User-Identity = 0x00 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Location-Capable = Civix-Location (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Calling-Station-Id = "00-24-54-F2-B4-53" (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Called-Station-Id = "053-D-004:unito-wifi" (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: NAS-Port = 13 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: NAS-IP-Address = 172.31.254.253 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: NAS-Identifier = "wlc-lin" (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Airespace-Wlan-Id = 1 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Service-Type = Framed-User (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Framed-MTU = 1300 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: NAS-Port-Type = Wireless-802.11 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Tunnel-Type:0 = VLAN (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Tunnel-Medium-Type:0 = IEEE-802 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Tunnel-Private-Group-Id:0 = "940" (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Event-Timestamp = "Sep 28 2018 16:27:46 CEST" (12014207) Fri Sep 28 16:27:46 2018: Debug: Virtual server inner-tunnel received request (12014207) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x02090015016d61747469612e6265676f766f657661 (12014207) Fri Sep 28 16:27:46 2018: Debug: FreeRADIUS-Proxied-To = 127.0.0.1 (12014207) Fri Sep 28 16:27:46 2018: Debug: User-Name = "USER" (12014207) Fri Sep 28 16:27:46 2018: Debug: Chargeable-User-Identity = 0x00 (12014207) Fri Sep 28 16:27:46 2018: Debug: Location-Capable = Civix-Location (12014207) Fri Sep 28 16:27:46 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014207) Fri Sep 28 16:27:46 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014207) Fri Sep 28 16:27:46 2018: Debug: NAS-Port = 13 (12014207) Fri Sep 28 16:27:46 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014207) Fri Sep 28 16:27:46 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014207) Fri Sep 28 16:27:46 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014207) Fri Sep 28 16:27:46 2018: Debug: NAS-Identifier = "wlc-lin" (12014207) Fri Sep 28 16:27:46 2018: Debug: Airespace-Wlan-Id = 1 (12014207) Fri Sep 28 16:27:46 2018: Debug: Service-Type = Framed-User (12014207) Fri Sep 28 16:27:46 2018: Debug: Framed-MTU = 1300 (12014207) Fri Sep 28 16:27:46 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014207) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Type:0 = VLAN (12014207) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014207) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014207) Fri Sep 28 16:27:46 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:46 CEST" (12014207) Fri Sep 28 16:27:46 2018: WARNING: Outer and inner identities are the same. User privacy is compromised. (12014207) Fri Sep 28 16:27:46 2018: Debug: server inner-tunnel { (12014207) Fri Sep 28 16:27:46 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/inner-tunnel (12014207) Fri Sep 28 16:27:46 2018: Debug: authorize { (12014207) Fri Sep 28 16:27:46 2018: Debug: policy filter_username { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) -> TRUE (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: } # if (&User-Name) = notfound (12014207) Fri Sep 28 16:27:46 2018: Debug: } # policy filter_username = notfound (12014207) Fri Sep 28 16:27:46 2018: Debug: policy filter_inner_identity { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (!&outer.request:User-Name || !&User-Name) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (!&outer.request:User-Name || !&User-Name) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&outer.request:User-Name != &User-Name) { (12014207) Fri Sep 28 16:27:46 2018: Debug: if (&outer.request:User-Name != &User-Name) -> FALSE (12014207) Fri Sep 28 16:27:46 2018: Debug: } # policy filter_inner_identity = notfound (12014207) Fri Sep 28 16:27:46 2018: Debug: [chap] = noop (12014207) Fri Sep 28 16:27:46 2018: Debug: [mschap] = noop (12014207) Fri Sep 28 16:27:46 2018: Debug: suffix: Checking for suffix after "@" (12014207) Fri Sep 28 16:27:46 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014207) Fri Sep 28 16:27:46 2018: Debug: suffix: No such realm "NULL" (12014207) Fri Sep 28 16:27:46 2018: Debug: [suffix] = noop (12014207) Fri Sep 28 16:27:46 2018: Debug: update control { (12014207) Fri Sep 28 16:27:46 2018: Debug: } # update control = noop (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent EAP Response (code 2) ID 9 length 21 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (12014207) Fri Sep 28 16:27:46 2018: Debug: [eap] = ok (12014207) Fri Sep 28 16:27:46 2018: Debug: } # authorize = ok (12014207) Fri Sep 28 16:27:46 2018: Debug: Found Auth-Type = eap (12014207) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/inner-tunnel (12014207) Fri Sep 28 16:27:46 2018: Debug: authenticate { (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent packet with method EAP Identity (1) (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: Calling submodule eap_mschapv2 to process data (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_mschapv2: Issuing Challenge (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: Sending EAP Request (code 1) ID 10 length 43 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: EAP session adding &reply:State = 0xd17b9cafd17186c4 (12014207) Fri Sep 28 16:27:46 2018: Debug: [eap] = handled (12014207) Fri Sep 28 16:27:46 2018: Debug: } # authenticate = handled (12014207) Fri Sep 28 16:27:46 2018: Debug: } # server inner-tunnel (12014207) Fri Sep 28 16:27:46 2018: Debug: Virtual server sending reply (12014207) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x010a002b1a010a0026101e491bc846728e627f87d42331372f0d667265657261646975732d332e302e3132 (12014207) Fri Sep 28 16:27:46 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014207) Fri Sep 28 16:27:46 2018: Debug: State = 0xd17b9cafd17186c4a414169edff77c76 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Got tunneled reply code 11 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: EAP-Message = 0x010a002b1a010a0026101e491bc846728e627f87d42331372f0d667265657261646975732d332e302e3132 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: State = 0xd17b9cafd17186c4a414169edff77c76 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Got tunneled Access-Challenge (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: Sending EAP Request (code 1) ID 10 length 74 (12014207) Fri Sep 28 16:27:46 2018: Debug: eap: EAP session adding &reply:State = 0x4a8916764d830f76 (12014207) Fri Sep 28 16:27:46 2018: Debug: [eap] = handled (12014207) Fri Sep 28 16:27:46 2018: Debug: } # authenticate = handled (12014207) Fri Sep 28 16:27:46 2018: Debug: Using Post-Auth-Type Challenge (12014207) Fri Sep 28 16:27:46 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (12014207) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014207) Fri Sep 28 16:27:46 2018: Debug: Sent Access-Challenge Id 34 from 192.168.19.93:1812 to 130.192.119.80:33713 length 0 (12014207) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x010a004a1900170303003fad1ff295a543d494b2b6f96343807584afc9f5973ba753882cf60d9a68f9ea519be8e97d0b98e137b5e8fad21229717437b422c1d75b5d702f4950ae389880 (12014207) Fri Sep 28 16:27:46 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014207) Fri Sep 28 16:27:46 2018: Debug: State = 0x4a8916764d830f7661caf9ec4798bf13 (12014207) Fri Sep 28 16:27:46 2018: Debug: Proxy-State = 0x313737 (12014207) Fri Sep 28 16:27:46 2018: Debug: Finished request (12014208) Fri Sep 28 16:27:46 2018: Debug: Received Access-Request Id 199 from 130.192.119.80:33713 to 192.168.19.93:1812 length 396 (12014208) Fri Sep 28 16:27:46 2018: Debug: User-Name = "USER" (12014208) Fri Sep 28 16:27:46 2018: Debug: Chargeable-User-Identity = 0x00 (12014208) Fri Sep 28 16:27:46 2018: Debug: Location-Capable = Civix-Location (12014208) Fri Sep 28 16:27:46 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014208) Fri Sep 28 16:27:46 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014208) Fri Sep 28 16:27:46 2018: Debug: NAS-Port = 13 (12014208) Fri Sep 28 16:27:46 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014208) Fri Sep 28 16:27:46 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014208) Fri Sep 28 16:27:46 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014208) Fri Sep 28 16:27:46 2018: Debug: NAS-Identifier = "wlc-lin" (12014208) Fri Sep 28 16:27:46 2018: Debug: Airespace-Wlan-Id = 1 (12014208) Fri Sep 28 16:27:46 2018: Debug: Service-Type = Framed-User (12014208) Fri Sep 28 16:27:46 2018: Debug: Framed-MTU = 1300 (12014208) Fri Sep 28 16:27:46 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014208) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Type:0 = VLAN (12014208) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014208) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014208) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x020a006a1900170303005f000000000000000210e73a15c1bc6370114d34f8a46f47d8a421c6234b6a5e4fa1f118283243f0d1fc00dd18be0bd3eb733a5112fd6819bd806f8c61335fa3ddd7c99b5045c78454da1cd74a259538748837440828877a981da96fac673ab2 (12014208) Fri Sep 28 16:27:46 2018: Debug: State = 0x4a8916764d830f7661caf9ec4798bf13 (12014208) Fri Sep 28 16:27:46 2018: Debug: Message-Authenticator = 0x12f38c9312ff1590f52aad1d29c064b6 (12014208) Fri Sep 28 16:27:46 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:46 CEST" (12014208) Fri Sep 28 16:27:46 2018: Debug: Proxy-State = 0x313738 (12014208) Fri Sep 28 16:27:46 2018: Debug: session-state: No cached attributes (12014208) Fri Sep 28 16:27:46 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (12014208) Fri Sep 28 16:27:46 2018: Debug: authorize { (12014208) Fri Sep 28 16:27:46 2018: Debug: policy forbid_win_host_auth { (12014208) Fri Sep 28 16:27:46 2018: Debug: if ( &User-Name =~ /^host\// ) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if ( &User-Name =~ /^host\// ) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: } # policy forbid_win_host_auth = notfound (12014208) Fri Sep 28 16:27:46 2018: Debug: policy normalize_username { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") { (12014208) Fri Sep 28 16:27:46 2018: Debug: EXPAND %{tolower:%{User-Name}} (12014208) Fri Sep 28 16:27:46 2018: Debug: --> USER (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: else { (12014208) Fri Sep 28 16:27:46 2018: Debug: [noop] = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: } # else = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: } # policy normalize_username = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: policy filter_username { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) -> TRUE (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: } # if (&User-Name) = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: } # policy filter_username = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: [preprocess] = ok (12014208) Fri Sep 28 16:27:46 2018: Debug: [mschap] = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: suffix: Checking for suffix after "@" (12014208) Fri Sep 28 16:27:46 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014208) Fri Sep 28 16:27:46 2018: Debug: suffix: No such realm "NULL" (12014208) Fri Sep 28 16:27:46 2018: Debug: [suffix] = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent EAP Response (code 2) ID 10 length 106 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Continuing tunnel setup (12014208) Fri Sep 28 16:27:46 2018: Debug: [eap] = ok (12014208) Fri Sep 28 16:27:46 2018: Debug: } # authorize = ok (12014208) Fri Sep 28 16:27:46 2018: Debug: Found Auth-Type = eap (12014208) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014208) Fri Sep 28 16:27:46 2018: Debug: authenticate { (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Expiring EAP session with state 0x3284a47d328ebe20 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Finished EAP session with state 0x4a8916764d830f76 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Previous EAP request found for state 0x4a8916764d830f76, released from the list (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent packet with method EAP PEAP (25) (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Calling submodule eap_peap to process data (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Continuing EAP-TLS (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: [eaptls verify] = ok (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Done initial handshake (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: [eaptls process] = ok (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Session established. Decoding tunneled attributes (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: PEAP state phase2 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: EAP method MSCHAPv2 (26) (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Got tunneled request (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: EAP-Message = 0x020a004b1a020a004631e2af7c69e50b037a8e2c6739d0d8c44c00000000000000006897fcaba602febac38bdb8a4efa8e1d89b8c2b6e74199d0006d61747469612e6265676f766f657661 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Setting User-Name to USER (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Sending tunneled request to inner-tunnel (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: EAP-Message = 0x020a004b1a020a004631e2af7c69e50b037a8e2c6739d0d8c44c00000000000000006897fcaba602febac38bdb8a4efa8e1d89b8c2b6e74199d0006d61747469612e6265676f766f657661 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: User-Name = "USER" (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: State = 0xd17b9cafd17186c4a414169edff77c76 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Chargeable-User-Identity = 0x00 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Location-Capable = Civix-Location (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Calling-Station-Id = "00-24-54-F2-B4-53" (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Called-Station-Id = "053-D-004:unito-wifi" (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: NAS-Port = 13 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: NAS-IP-Address = 172.31.254.253 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: NAS-Identifier = "wlc-lin" (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Airespace-Wlan-Id = 1 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Service-Type = Framed-User (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Framed-MTU = 1300 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: NAS-Port-Type = Wireless-802.11 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Tunnel-Type:0 = VLAN (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Tunnel-Medium-Type:0 = IEEE-802 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Tunnel-Private-Group-Id:0 = "940" (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Event-Timestamp = "Sep 28 2018 16:27:46 CEST" (12014208) Fri Sep 28 16:27:46 2018: Debug: Virtual server inner-tunnel received request (12014208) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x020a004b1a020a004631e2af7c69e50b037a8e2c6739d0d8c44c00000000000000006897fcaba602febac38bdb8a4efa8e1d89b8c2b6e74199d0006d61747469612e6265676f766f657661 (12014208) Fri Sep 28 16:27:46 2018: Debug: FreeRADIUS-Proxied-To = 127.0.0.1 (12014208) Fri Sep 28 16:27:46 2018: Debug: User-Name = "USER" (12014208) Fri Sep 28 16:27:46 2018: Debug: State = 0xd17b9cafd17186c4a414169edff77c76 (12014208) Fri Sep 28 16:27:46 2018: Debug: Chargeable-User-Identity = 0x00 (12014208) Fri Sep 28 16:27:46 2018: Debug: Location-Capable = Civix-Location (12014208) Fri Sep 28 16:27:46 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014208) Fri Sep 28 16:27:46 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014208) Fri Sep 28 16:27:46 2018: Debug: NAS-Port = 13 (12014208) Fri Sep 28 16:27:46 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014208) Fri Sep 28 16:27:46 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014208) Fri Sep 28 16:27:46 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014208) Fri Sep 28 16:27:46 2018: Debug: NAS-Identifier = "wlc-lin" (12014208) Fri Sep 28 16:27:46 2018: Debug: Airespace-Wlan-Id = 1 (12014208) Fri Sep 28 16:27:46 2018: Debug: Service-Type = Framed-User (12014208) Fri Sep 28 16:27:46 2018: Debug: Framed-MTU = 1300 (12014208) Fri Sep 28 16:27:46 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014208) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Type:0 = VLAN (12014208) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014208) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014208) Fri Sep 28 16:27:46 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:46 CEST" (12014208) Fri Sep 28 16:27:46 2018: WARNING: Outer and inner identities are the same. User privacy is compromised. (12014208) Fri Sep 28 16:27:46 2018: Debug: server inner-tunnel { (12014208) Fri Sep 28 16:27:46 2018: Debug: session-state: No cached attributes (12014208) Fri Sep 28 16:27:46 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/inner-tunnel (12014208) Fri Sep 28 16:27:46 2018: Debug: authorize { (12014208) Fri Sep 28 16:27:46 2018: Debug: policy filter_username { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) -> TRUE (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: } # if (&User-Name) = notfound (12014208) Fri Sep 28 16:27:46 2018: Debug: } # policy filter_username = notfound (12014208) Fri Sep 28 16:27:46 2018: Debug: policy filter_inner_identity { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (!&outer.request:User-Name || !&User-Name) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (!&outer.request:User-Name || !&User-Name) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&outer.request:User-Name != &User-Name) { (12014208) Fri Sep 28 16:27:46 2018: Debug: if (&outer.request:User-Name != &User-Name) -> FALSE (12014208) Fri Sep 28 16:27:46 2018: Debug: } # policy filter_inner_identity = notfound (12014208) Fri Sep 28 16:27:46 2018: Debug: [chap] = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: [mschap] = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: suffix: Checking for suffix after "@" (12014208) Fri Sep 28 16:27:46 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014208) Fri Sep 28 16:27:46 2018: Debug: suffix: No such realm "NULL" (12014208) Fri Sep 28 16:27:46 2018: Debug: [suffix] = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: update control { (12014208) Fri Sep 28 16:27:46 2018: Debug: } # update control = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent EAP Response (code 2) ID 10 length 75 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: No EAP Start, assuming it's an on-going EAP conversation (12014208) Fri Sep 28 16:27:46 2018: Debug: [eap] = updated (12014208) Fri Sep 28 16:27:46 2018: Debug: [files] = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: [expiration] = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: [logintime] = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: [pap] = noop (12014208) Fri Sep 28 16:27:46 2018: Debug: } # authorize = updated (12014208) Fri Sep 28 16:27:46 2018: Debug: Found Auth-Type = eap (12014208) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/inner-tunnel (12014208) Fri Sep 28 16:27:46 2018: Debug: authenticate { (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Expiring EAP session with state 0x3284a47d328ebe20 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Finished EAP session with state 0xd17b9cafd17186c4 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Previous EAP request found for state 0xd17b9cafd17186c4, released from the list (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent packet with method EAP MSCHAPv2 (26) (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Calling submodule eap_mschapv2 to process data (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_mschapv2: # Executing group from file /etc/freeradius/3.0/sites-enabled/inner-tunnel (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_mschapv2: authenticate { (12014208) Fri Sep 28 16:27:46 2018: Debug: mschap: Creating challenge hash with username: USER (12014208) Fri Sep 28 16:27:46 2018: Debug: mschap: Client is using MS-CHAPv2 (12014208) Fri Sep 28 16:27:46 2018: Debug: mschap: EXPAND %{%{Stripped-User-Name}:-%{%{mschap:User-Name}:-None}} (12014208) Fri Sep 28 16:27:46 2018: Debug: mschap: --> USER (12014208) Fri Sep 28 16:27:46 2018: Debug: mschap: sending authentication request user='USER' domain='ateneo' (12014208) Fri Sep 28 16:27:46 2018: Debug: mschap: Authenticated successfully (12014208) Fri Sep 28 16:27:46 2018: Debug: mschap: Adding MS-CHAPv2 MPPE keys (12014208) Fri Sep 28 16:27:46 2018: Debug: [mschap] = ok (12014208) Fri Sep 28 16:27:46 2018: Debug: } # authenticate = ok (12014208) Fri Sep 28 16:27:46 2018: Debug: MSCHAP Success (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Sending EAP Request (code 1) ID 11 length 51 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: EAP session adding &reply:State = 0xd17b9cafd07086c4 (12014208) Fri Sep 28 16:27:46 2018: Debug: [eap] = handled (12014208) Fri Sep 28 16:27:46 2018: Debug: } # authenticate = handled (12014208) Fri Sep 28 16:27:46 2018: Debug: } # server inner-tunnel (12014208) Fri Sep 28 16:27:46 2018: Debug: Virtual server sending reply (12014208) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x010b00331a030a002e533d44364238374641423034413243463344363443334535324336423338374345314639424231334139 (12014208) Fri Sep 28 16:27:46 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014208) Fri Sep 28 16:27:46 2018: Debug: State = 0xd17b9cafd07086c4a414169edff77c76 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Got tunneled reply code 11 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: EAP-Message = 0x010b00331a030a002e533d44364238374641423034413243463344363443334535324336423338374345314639424231334139 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: State = 0xd17b9cafd07086c4a414169edff77c76 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Got tunneled Access-Challenge (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: Sending EAP Request (code 1) ID 11 length 82 (12014208) Fri Sep 28 16:27:46 2018: Debug: eap: EAP session adding &reply:State = 0x4a89167642820f76 (12014208) Fri Sep 28 16:27:46 2018: Debug: [eap] = handled (12014208) Fri Sep 28 16:27:46 2018: Debug: } # authenticate = handled (12014208) Fri Sep 28 16:27:46 2018: Debug: Using Post-Auth-Type Challenge (12014208) Fri Sep 28 16:27:46 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (12014208) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014208) Fri Sep 28 16:27:46 2018: Debug: Sent Access-Challenge Id 199 from 192.168.19.93:1812 to 130.192.119.80:33713 length 0 (12014208) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x010b005219001703030047ad1ff295a543d495b30dda05842023a40d0664a7d1dddae763d5ad58141c61532011d406bae71ac22dc90a0ab35caa9b8fabdd1ad1535887f6ddb7f70a283bca04cb1963cd544d (12014208) Fri Sep 28 16:27:46 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014208) Fri Sep 28 16:27:46 2018: Debug: State = 0x4a89167642820f7661caf9ec4798bf13 (12014208) Fri Sep 28 16:27:46 2018: Debug: Proxy-State = 0x313738 (12014208) Fri Sep 28 16:27:46 2018: Debug: Finished request (12014209) Fri Sep 28 16:27:46 2018: Debug: Received Access-Request Id 165 from 130.192.119.80:33713 to 192.168.19.93:1812 length 327 (12014209) Fri Sep 28 16:27:46 2018: Debug: User-Name = "USER" (12014209) Fri Sep 28 16:27:46 2018: Debug: Chargeable-User-Identity = 0x00 (12014209) Fri Sep 28 16:27:46 2018: Debug: Location-Capable = Civix-Location (12014209) Fri Sep 28 16:27:46 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014209) Fri Sep 28 16:27:46 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014209) Fri Sep 28 16:27:46 2018: Debug: NAS-Port = 13 (12014209) Fri Sep 28 16:27:46 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014209) Fri Sep 28 16:27:46 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014209) Fri Sep 28 16:27:46 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014209) Fri Sep 28 16:27:46 2018: Debug: NAS-Identifier = "wlc-lin" (12014209) Fri Sep 28 16:27:46 2018: Debug: Airespace-Wlan-Id = 1 (12014209) Fri Sep 28 16:27:46 2018: Debug: Service-Type = Framed-User (12014209) Fri Sep 28 16:27:46 2018: Debug: Framed-MTU = 1300 (12014209) Fri Sep 28 16:27:46 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014209) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Type:0 = VLAN (12014209) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014209) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014209) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x020b00251900170303001a00000000000000038a42de4b968ff0f4bb626c51eb7b83ea5735 (12014209) Fri Sep 28 16:27:46 2018: Debug: State = 0x4a89167642820f7661caf9ec4798bf13 (12014209) Fri Sep 28 16:27:46 2018: Debug: Message-Authenticator = 0x4bd4ce4907cf523a46b3491550e274b6 (12014209) Fri Sep 28 16:27:46 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:46 CEST" (12014209) Fri Sep 28 16:27:46 2018: Debug: Proxy-State = 0x313739 (12014209) Fri Sep 28 16:27:46 2018: Debug: session-state: No cached attributes (12014209) Fri Sep 28 16:27:46 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (12014209) Fri Sep 28 16:27:46 2018: Debug: authorize { (12014209) Fri Sep 28 16:27:46 2018: Debug: policy forbid_win_host_auth { (12014209) Fri Sep 28 16:27:46 2018: Debug: if ( &User-Name =~ /^host\// ) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if ( &User-Name =~ /^host\// ) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: } # policy forbid_win_host_auth = notfound (12014209) Fri Sep 28 16:27:46 2018: Debug: policy normalize_username { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") { (12014209) Fri Sep 28 16:27:46 2018: Debug: EXPAND %{tolower:%{User-Name}} (12014209) Fri Sep 28 16:27:46 2018: Debug: --> USER (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: else { (12014209) Fri Sep 28 16:27:46 2018: Debug: [noop] = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: } # else = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: } # policy normalize_username = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: policy filter_username { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) -> TRUE (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: } # if (&User-Name) = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: } # policy filter_username = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: [preprocess] = ok (12014209) Fri Sep 28 16:27:46 2018: Debug: [mschap] = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: suffix: Checking for suffix after "@" (12014209) Fri Sep 28 16:27:46 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014209) Fri Sep 28 16:27:46 2018: Debug: suffix: No such realm "NULL" (12014209) Fri Sep 28 16:27:46 2018: Debug: [suffix] = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent EAP Response (code 2) ID 11 length 37 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Continuing tunnel setup (12014209) Fri Sep 28 16:27:46 2018: Debug: [eap] = ok (12014209) Fri Sep 28 16:27:46 2018: Debug: } # authorize = ok (12014209) Fri Sep 28 16:27:46 2018: Debug: Found Auth-Type = eap (12014209) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014209) Fri Sep 28 16:27:46 2018: Debug: authenticate { (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Expiring EAP session with state 0x3284a47d328ebe20 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Finished EAP session with state 0x4a89167642820f76 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Previous EAP request found for state 0x4a89167642820f76, released from the list (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent packet with method EAP PEAP (25) (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Calling submodule eap_peap to process data (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Continuing EAP-TLS (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: [eaptls verify] = ok (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Done initial handshake (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: [eaptls process] = ok (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Session established. Decoding tunneled attributes (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: PEAP state phase2 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: EAP method MSCHAPv2 (26) (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Got tunneled request (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: EAP-Message = 0x020b00061a03 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Setting User-Name to USER (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Sending tunneled request to inner-tunnel (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: EAP-Message = 0x020b00061a03 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: User-Name = "USER" (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: State = 0xd17b9cafd07086c4a414169edff77c76 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Chargeable-User-Identity = 0x00 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Location-Capable = Civix-Location (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Calling-Station-Id = "00-24-54-F2-B4-53" (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Called-Station-Id = "053-D-004:unito-wifi" (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: NAS-Port = 13 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: NAS-IP-Address = 172.31.254.253 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: NAS-Identifier = "wlc-lin" (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Airespace-Wlan-Id = 1 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Service-Type = Framed-User (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Framed-MTU = 1300 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: NAS-Port-Type = Wireless-802.11 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Tunnel-Type:0 = VLAN (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Tunnel-Medium-Type:0 = IEEE-802 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Tunnel-Private-Group-Id:0 = "940" (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Event-Timestamp = "Sep 28 2018 16:27:46 CEST" (12014209) Fri Sep 28 16:27:46 2018: Debug: Virtual server inner-tunnel received request (12014209) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x020b00061a03 (12014209) Fri Sep 28 16:27:46 2018: Debug: FreeRADIUS-Proxied-To = 127.0.0.1 (12014209) Fri Sep 28 16:27:46 2018: Debug: User-Name = "USER" (12014209) Fri Sep 28 16:27:46 2018: Debug: State = 0xd17b9cafd07086c4a414169edff77c76 (12014209) Fri Sep 28 16:27:46 2018: Debug: Chargeable-User-Identity = 0x00 (12014209) Fri Sep 28 16:27:46 2018: Debug: Location-Capable = Civix-Location (12014209) Fri Sep 28 16:27:46 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014209) Fri Sep 28 16:27:46 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014209) Fri Sep 28 16:27:46 2018: Debug: NAS-Port = 13 (12014209) Fri Sep 28 16:27:46 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014209) Fri Sep 28 16:27:46 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014209) Fri Sep 28 16:27:46 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014209) Fri Sep 28 16:27:46 2018: Debug: NAS-Identifier = "wlc-lin" (12014209) Fri Sep 28 16:27:46 2018: Debug: Airespace-Wlan-Id = 1 (12014209) Fri Sep 28 16:27:46 2018: Debug: Service-Type = Framed-User (12014209) Fri Sep 28 16:27:46 2018: Debug: Framed-MTU = 1300 (12014209) Fri Sep 28 16:27:46 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014209) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Type:0 = VLAN (12014209) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014209) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014209) Fri Sep 28 16:27:46 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:46 CEST" (12014209) Fri Sep 28 16:27:46 2018: WARNING: Outer and inner identities are the same. User privacy is compromised. (12014209) Fri Sep 28 16:27:46 2018: Debug: server inner-tunnel { (12014209) Fri Sep 28 16:27:46 2018: Debug: session-state: No cached attributes (12014209) Fri Sep 28 16:27:46 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/inner-tunnel (12014209) Fri Sep 28 16:27:46 2018: Debug: authorize { (12014209) Fri Sep 28 16:27:46 2018: Debug: policy filter_username { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) -> TRUE (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: } # if (&User-Name) = notfound (12014209) Fri Sep 28 16:27:46 2018: Debug: } # policy filter_username = notfound (12014209) Fri Sep 28 16:27:46 2018: Debug: policy filter_inner_identity { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (!&outer.request:User-Name || !&User-Name) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (!&outer.request:User-Name || !&User-Name) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&outer.request:User-Name != &User-Name) { (12014209) Fri Sep 28 16:27:46 2018: Debug: if (&outer.request:User-Name != &User-Name) -> FALSE (12014209) Fri Sep 28 16:27:46 2018: Debug: } # policy filter_inner_identity = notfound (12014209) Fri Sep 28 16:27:46 2018: Debug: [chap] = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: [mschap] = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: suffix: Checking for suffix after "@" (12014209) Fri Sep 28 16:27:46 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014209) Fri Sep 28 16:27:46 2018: Debug: suffix: No such realm "NULL" (12014209) Fri Sep 28 16:27:46 2018: Debug: [suffix] = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: update control { (12014209) Fri Sep 28 16:27:46 2018: Debug: } # update control = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent EAP Response (code 2) ID 11 length 6 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: No EAP Start, assuming it's an on-going EAP conversation (12014209) Fri Sep 28 16:27:46 2018: Debug: [eap] = updated (12014209) Fri Sep 28 16:27:46 2018: Debug: [files] = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: [expiration] = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: [logintime] = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: [pap] = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: } # authorize = updated (12014209) Fri Sep 28 16:27:46 2018: Debug: Found Auth-Type = eap (12014209) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/inner-tunnel (12014209) Fri Sep 28 16:27:46 2018: Debug: authenticate { (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Expiring EAP session with state 0x3284a47d328ebe20 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Finished EAP session with state 0xd17b9cafd07086c4 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Previous EAP request found for state 0xd17b9cafd07086c4, released from the list (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent packet with method EAP MSCHAPv2 (26) (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Calling submodule eap_mschapv2 to process data (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Sending EAP Success (code 3) ID 11 length 4 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Freeing handler (12014209) Fri Sep 28 16:27:46 2018: Debug: [eap] = ok (12014209) Fri Sep 28 16:27:46 2018: Debug: } # authenticate = ok (12014209) Fri Sep 28 16:27:46 2018: Debug: # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/inner-tunnel (12014209) Fri Sep 28 16:27:46 2018: Debug: post-auth { (12014209) Fri Sep 28 16:27:46 2018: Debug: update { (12014209) Fri Sep 28 16:27:46 2018: Debug: } # update = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: update outer.session-state { (12014209) Fri Sep 28 16:27:46 2018: Debug: } # update outer.session-state = noop (12014209) Fri Sep 28 16:27:46 2018: Debug: unito-linelog-eap: EXPAND custom.%{%{reply:Packet-Type}:-default} (12014209) Fri Sep 28 16:27:46 2018: Debug: unito-linelog-eap: --> custom.Access-Accept (12014209) Fri Sep 28 16:27:46 2018: Debug: unito-linelog-eap: EXPAND ACCEPTED (%{%{Stripped-User-Name}:-%{User-Name}}) (OUTER=%{%{outer.request:User-Name}:-Unknown}) (MAC=%{%{request:Calling-Station-Id}:-Unknown}) (CSID=%{request:Called-Station-Id}) (12014209) Fri Sep 28 16:27:46 2018: Debug: unito-linelog-eap: --> ACCEPTED (USER) (OUTER=USER) (MAC=00-24-54-F2-B4-53) (CSID=053-D-004:unito-wifi) (12014209) Fri Sep 28 16:27:46 2018: Debug: [unito-linelog-eap] = ok (12014209) Fri Sep 28 16:27:46 2018: Debug: } # post-auth = ok (12014209) Fri Sep 28 16:27:46 2018: Debug: } # server inner-tunnel (12014209) Fri Sep 28 16:27:46 2018: Debug: Virtual server sending reply (12014209) Fri Sep 28 16:27:46 2018: Debug: MS-MPPE-Encryption-Policy = Encryption-Allowed (12014209) Fri Sep 28 16:27:46 2018: Debug: MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed (12014209) Fri Sep 28 16:27:46 2018: Debug: MS-MPPE-Send-Key = 0x7266b1a55bb76baa8b669b27a29bcd15 (12014209) Fri Sep 28 16:27:46 2018: Debug: MS-MPPE-Recv-Key = 0x802d880cd66d80ac457ebbc473566b03 (12014209) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x030b0004 (12014209) Fri Sep 28 16:27:46 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014209) Fri Sep 28 16:27:46 2018: Debug: User-Name = "USER" (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Got tunneled reply code 2 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: MS-MPPE-Encryption-Policy = Encryption-Allowed (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: MS-MPPE-Send-Key = 0x7266b1a55bb76baa8b669b27a29bcd15 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: MS-MPPE-Recv-Key = 0x802d880cd66d80ac457ebbc473566b03 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: EAP-Message = 0x030b0004 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: User-Name = "USER" (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Tunneled authentication was successful (12014209) Fri Sep 28 16:27:46 2018: Debug: eap_peap: SUCCESS (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: Sending EAP Request (code 1) ID 12 length 46 (12014209) Fri Sep 28 16:27:46 2018: Debug: eap: EAP session adding &reply:State = 0x4a89167643850f76 (12014209) Fri Sep 28 16:27:46 2018: Debug: [eap] = handled (12014209) Fri Sep 28 16:27:46 2018: Debug: } # authenticate = handled (12014209) Fri Sep 28 16:27:46 2018: Debug: Using Post-Auth-Type Challenge (12014209) Fri Sep 28 16:27:46 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (12014209) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014209) Fri Sep 28 16:27:46 2018: Debug: session-state: Saving cached attributes (12014209) Fri Sep 28 16:27:46 2018: Debug: User-Name += "USER" (12014209) Fri Sep 28 16:27:46 2018: Debug: Sent Access-Challenge Id 165 from 192.168.19.93:1812 to 130.192.119.80:33713 length 0 (12014209) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x010c002e19001703030023ad1ff295a543d4966d076f6ae66986ec710a95864c191a47a4f8f209c35c39af94a296 (12014209) Fri Sep 28 16:27:46 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014209) Fri Sep 28 16:27:46 2018: Debug: State = 0x4a89167643850f7661caf9ec4798bf13 (12014209) Fri Sep 28 16:27:46 2018: Debug: Proxy-State = 0x313739 (12014209) Fri Sep 28 16:27:46 2018: Debug: Finished request (12014210) Fri Sep 28 16:27:46 2018: Debug: Received Access-Request Id 247 from 130.192.119.80:33713 to 192.168.19.93:1812 length 336 (12014210) Fri Sep 28 16:27:46 2018: Debug: User-Name = "USER" (12014210) Fri Sep 28 16:27:46 2018: Debug: Chargeable-User-Identity = 0x00 (12014210) Fri Sep 28 16:27:46 2018: Debug: Location-Capable = Civix-Location (12014210) Fri Sep 28 16:27:46 2018: Debug: Calling-Station-Id = "00-24-54-F2-B4-53" (12014210) Fri Sep 28 16:27:46 2018: Debug: Called-Station-Id = "053-D-004:unito-wifi" (12014210) Fri Sep 28 16:27:46 2018: Debug: NAS-Port = 13 (12014210) Fri Sep 28 16:27:46 2018: Debug: Cisco-AVPair = "audit-session-id=ac1ffefd0013f7385bae1886" (12014210) Fri Sep 28 16:27:46 2018: Debug: Acct-Session-Id = "5bae1883/00:24:54:f2:b4:53/1359867" (12014210) Fri Sep 28 16:27:46 2018: Debug: NAS-IP-Address = 172.31.254.253 (12014210) Fri Sep 28 16:27:46 2018: Debug: NAS-Identifier = "wlc-lin" (12014210) Fri Sep 28 16:27:46 2018: Debug: Airespace-Wlan-Id = 1 (12014210) Fri Sep 28 16:27:46 2018: Debug: Service-Type = Framed-User (12014210) Fri Sep 28 16:27:46 2018: Debug: Framed-MTU = 1300 (12014210) Fri Sep 28 16:27:46 2018: Debug: NAS-Port-Type = Wireless-802.11 (12014210) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Type:0 = VLAN (12014210) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Medium-Type:0 = IEEE-802 (12014210) Fri Sep 28 16:27:46 2018: Debug: Tunnel-Private-Group-Id:0 = "940" (12014210) Fri Sep 28 16:27:46 2018: Debug: EAP-Message = 0x020c002e1900170303002300000000000000046d1c6ef9533507adc1bf7af1f99b3c7cad118fac74da98772b4fda (12014210) Fri Sep 28 16:27:46 2018: Debug: State = 0x4a89167643850f7661caf9ec4798bf13 (12014210) Fri Sep 28 16:27:46 2018: Debug: Message-Authenticator = 0x0dbfe7856dbd45f1ddabd9f5ec69f137 (12014210) Fri Sep 28 16:27:46 2018: Debug: Event-Timestamp = "Sep 28 2018 16:27:46 CEST" (12014210) Fri Sep 28 16:27:46 2018: Debug: Proxy-State = 0x313830 (12014210) Fri Sep 28 16:27:46 2018: Debug: Restoring &session-state (12014210) Fri Sep 28 16:27:46 2018: Debug: &session-state:User-Name += "USER" (12014210) Fri Sep 28 16:27:46 2018: Debug: # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (12014210) Fri Sep 28 16:27:46 2018: Debug: authorize { (12014210) Fri Sep 28 16:27:46 2018: Debug: policy forbid_win_host_auth { (12014210) Fri Sep 28 16:27:46 2018: Debug: if ( &User-Name =~ /^host\// ) { (12014210) Fri Sep 28 16:27:46 2018: Debug: if ( &User-Name =~ /^host\// ) -> FALSE (12014210) Fri Sep 28 16:27:46 2018: Debug: } # policy forbid_win_host_auth = notfound (12014210) Fri Sep 28 16:27:46 2018: Debug: policy normalize_username { (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") { (12014210) Fri Sep 28 16:27:46 2018: Debug: EXPAND %{tolower:%{User-Name}} (12014210) Fri Sep 28 16:27:46 2018: Debug: --> USER (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name != "%{tolower:%{User-Name}}") -> FALSE (12014210) Fri Sep 28 16:27:46 2018: Debug: else { (12014210) Fri Sep 28 16:27:46 2018: Debug: [noop] = noop (12014210) Fri Sep 28 16:27:46 2018: Debug: } # else = noop (12014210) Fri Sep 28 16:27:46 2018: Debug: } # policy normalize_username = noop (12014210) Fri Sep 28 16:27:46 2018: Debug: policy filter_username { (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) -> TRUE (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name) { (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) { (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ / /) -> FALSE (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) { (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (12014210) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (12014210) Fri Sep 28 16:27:46 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) { (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) { (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (12014210) Fri Sep 28 16:27:46 2018: Debug: } # if (&User-Name) = noop (12014210) Fri Sep 28 16:27:46 2018: Debug: } # policy filter_username = noop (12014210) Fri Sep 28 16:27:46 2018: Debug: [preprocess] = ok (12014210) Fri Sep 28 16:27:46 2018: Debug: [mschap] = noop (12014210) Fri Sep 28 16:27:46 2018: Debug: suffix: Checking for suffix after "@" (12014210) Fri Sep 28 16:27:46 2018: Debug: suffix: No '@' in User-Name = "USER", looking up realm NULL (12014210) Fri Sep 28 16:27:46 2018: Debug: suffix: No such realm "NULL" (12014210) Fri Sep 28 16:27:46 2018: Debug: [suffix] = noop (12014210) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent EAP Response (code 2) ID 12 length 46 (12014210) Fri Sep 28 16:27:46 2018: Debug: eap: Continuing tunnel setup (12014210) Fri Sep 28 16:27:46 2018: Debug: [eap] = ok (12014210) Fri Sep 28 16:27:46 2018: Debug: } # authorize = ok (12014210) Fri Sep 28 16:27:46 2018: Debug: Found Auth-Type = eap (12014210) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014210) Fri Sep 28 16:27:46 2018: Debug: authenticate { (12014210) Fri Sep 28 16:27:46 2018: Debug: eap: Expiring EAP session with state 0x3284a47d328ebe20 (12014210) Fri Sep 28 16:27:46 2018: Debug: eap: Finished EAP session with state 0x4a89167643850f76 (12014210) Fri Sep 28 16:27:46 2018: Debug: eap: Previous EAP request found for state 0x4a89167643850f76, released from the list (12014210) Fri Sep 28 16:27:46 2018: Debug: eap: Peer sent packet with method EAP PEAP (25) (12014210) Fri Sep 28 16:27:46 2018: Debug: eap: Calling submodule eap_peap to process data (12014210) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Continuing EAP-TLS (12014210) Fri Sep 28 16:27:46 2018: Debug: eap_peap: [eaptls verify] = ok (12014210) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Done initial handshake (12014210) Fri Sep 28 16:27:46 2018: Debug: eap_peap: [eaptls process] = ok (12014210) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Session established. Decoding tunneled attributes (12014210) Fri Sep 28 16:27:46 2018: Debug: eap_peap: PEAP state send tlv success (12014210) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Received EAP-TLV response (12014210) Fri Sep 28 16:27:46 2018: Debug: eap_peap: Client rejected our response. The password is probably incorrect (12014210) Fri Sep 28 16:27:46 2018: ERROR: eap_peap: We sent a success, but the client did not agree (12014210) Fri Sep 28 16:27:46 2018: ERROR: eap: Failed continuing EAP PEAP (25) session. EAP sub-module failed (12014210) Fri Sep 28 16:27:46 2018: Debug: eap: Sending EAP Failure (code 4) ID 12 length 4 (12014210) Fri Sep 28 16:27:46 2018: Debug: eap: Failed in EAP select (12014210) Fri Sep 28 16:27:46 2018: Debug: [eap] = invalid (12014210) Fri Sep 28 16:27:46 2018: Debug: } # authenticate = invalid (12014210) Fri Sep 28 16:27:46 2018: Debug: Failed to authenticate the user (12014210) Fri Sep 28 16:27:46 2018: Debug: Using Post-Auth-Type Reject (12014210) Fri Sep 28 16:27:46 2018: Debug: # Executing group from file /etc/freeradius/3.0/sites-enabled/default (12014210) Fri Sep 28 16:27:46 2018: Debug: Post-Auth-Type REJECT { (12014210) Fri Sep 28 16:27:46 2018: Debug: attr_filter.access_reject: EXPAND %{User-Name} (12014210) Fri Sep 28 16:27:46 2018: Debug: attr_filter.access_reject: --> USER (12014210) Fri Sep 28 16:27:46 2018: Debug: attr_filter.access_reject: Matched entry DEFAULT at line 11 (12014210) Fri Sep 28 16:27:46 2018: Debug: [attr_filter.access_reject] = updated (12014210) Fri Sep 28 16:27:46 2018: Debug: [eap] = noop (12014210) Fri Sep 28 16:27:46 2018: Debug: policy remove_reply_message_if_eap { (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&reply:EAP-Message && &reply:Reply-Message) { (12014210) Fri Sep 28 16:27:46 2018: Debug: if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (12014210) Fri Sep 28 16:27:46 2018: Debug: else { (12014210) Fri Sep 28 16:27:46 2018: Debug: [noop] = noop (12014210) Fri Sep 28 16:27:46 2018: Debug: } # else = noop (12014210) Fri Sep 28 16:27:46 2018: Debug: } # policy remove_reply_message_if_eap = noop (12014210) Fri Sep 28 16:27:46 2018: Debug: if (!&EAP-Message) { (12014210) Fri Sep 28 16:27:46 2018: Debug: if (!&EAP-Message) -> FALSE (12014210) Fri Sep 28 16:27:46 2018: Debug: } # Post-Auth-Type REJECT = updated (12014210) Fri Sep 28 16:27:46 2018: Debug: Delaying response for 1.000000 seconds (12014209) Fri Sep 28 16:27:46 2018: Debug: Cleaning up request packet ID 165 with timestamp +1919353 (12014210) Fri Sep 28 16:27:47 2018: Debug: Sending delayed response (12014210) Fri Sep 28 16:27:47 2018: Debug: Sent Access-Reject Id 247 from 192.168.19.93:1812 to 130.192.119.80:33713 length 49 (12014210) Fri Sep 28 16:27:47 2018: Debug: EAP-Message = 0x040c0004 (12014210) Fri Sep 28 16:27:47 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (12014210) Fri Sep 28 16:27:47 2018: Debug: Proxy-State = 0x313830 (12014187) Fri Sep 28 16:27:47 2018: Debug: Cleaning up request packet ID 3 with timestamp +1919350 (12014188) Fri Sep 28 16:27:48 2018: Debug: Cleaning up request packet ID 31 with timestamp +1919350 (12014189) Fri Sep 28 16:27:48 2018: Debug: Cleaning up request packet ID 254 with timestamp +1919350 (12014190) Fri Sep 28 16:27:48 2018: Debug: Cleaning up request packet ID 4 with timestamp +1919350 (12014191) Fri Sep 28 16:27:48 2018: Debug: Cleaning up request packet ID 76 with timestamp +1919350 (12014192) Fri Sep 28 16:27:48 2018: Debug: Cleaning up request packet ID 13 with timestamp +1919350 (12014206) Fri Sep 28 16:27:51 2018: Debug: Cleaning up request packet ID 114 with timestamp +1919353 (12014207) Fri Sep 28 16:27:51 2018: Debug: Cleaning up request packet ID 34 with timestamp +1919353 (12014208) Fri Sep 28 16:27:51 2018: Debug: Cleaning up request packet ID 199 with timestamp +1919353 (12014210) Fri Sep 28 16:27:51 2018: Debug: Cleaning up request packet ID 247 with timestamp +1919353 -- **************************************** Marco Santantonio Direzione Sistemi Informativi, Portale, E-learning Sezione Fonia, VoIP e WiFi www.unito.it ****************************************

1 0

64 bit integers to be used in comparisons in unlang stattements
by Ali Arslan 04 Oct '18

04 Oct '18

Hi, In unlang statements i need to store input and output octet sums from accounting table to keep if conditions simple and readable, but unlang does not support 64 bit integers so i need another integer variable to keep gigaword carry which needs the same sql query to be executed multiple times. Isn't it possible to add "long integer" support to unlang to be used in calculations, not to be sent on wire? Results can be stored in string variables, but again we need casting to long integer in comparison. As being a newbie in freeradius world i may be missing some other simple workarounds for the problem stated above, if so i need some suggestions to hande this problem. Thanks.

2 1

mschap and ldap issue
by Amstaff zg 03 Oct '18

03 Oct '18

Hi everyone, I'm having issue with mschap auth with ldap background. My log says: No Cleartext-Password configured. Cannot create LM-Password. FAILED: No NT/LM-Password. Cannot perform authentication. I've found few questions like this on your mailing list but none of them helped. Can someone tell me what am I doing wrong? Thanks. Cheers, K

3 3

Problem with rlm_sql_oracle to initialise.
by Saurabh Lahoti 03 Oct '18

03 Oct '18

Hi, While running radiusd -X, below error is interpreted for rlm_sql_oracle: rlm_sql (sqlADSL): Opening additional connection (0), 1 of 32 pending slots used rlm_sql_oracle: Couldn't init Oracle OCI environment (OCIEnvCreate()) rlm_sql (sqlADSL): Opening connection failed (0) rlm_sql (sqlADSL): Removing connection pool /usr/app/radius/etc/raddb/mods-enabled/sql[20]: Instantiation failed for module "sqlADSL" Could you please help how to get rid of this error..? ---- *Thanks & Kind Regards,* Saurabh LAHOTI. *Ideas enlighten Innovation**!!!* Please consider the environment before printing this mail..!!

2 1

fair usage policy best practices
by Ali Arslan 02 Oct '18

02 Oct '18

Hi, I am a newbie in freeradius. My radius server should handle multiple NAS devices from multiple vendors (Cisco, Mikrotik, juniper). I want to implement FUP (fair usage policy), Every user may buy different rates and fair usage limits, after he/she downloads fair usage limit quantity the rate will be lower. I see 2 options: 1- An application that checks periodically the download quantities of users and and send SSH command to server to request CoA from NAS like: echo "User-Name={UserName}, Rate-Limit={RateLimit}" | radclient NAS-IP:coaPort CoA secret 2- Unlang code in default site accounting section In first option the check period should be low enough so that users wont download too much excess of their limit, this will hang server. I need your suggestions about best practices for FUP, and some instructions if second option is suggested. a. arslan

2 3

Can I define an internal attribute for a module?
by Alejandro Perez-Mendez 02 Oct '18

02 Oct '18

Hi, I'm developing a Python module that implements a very simple TOTP functionality (it basically replaces the value of Cleartext-Password with the original value plus the expected TOTP code), so the user has to provide a concatenation of the original password and the OTP code to authenticate. This works well so far. The doubt I have is where and how to store the OTP secret codes. So far, for development, I have a Python dictionary defined on the Python module with all the User-Name -> Secret key associations, but having these on the code is not a good practice and it requires managing two user lists, one for authentication (users file or SQL DB or LDAP...) plus this OTP secret list. This might lead to inconsistencies. The first option I thought of was to make use of the config {} subsection of the python module, but it would still be a second user list (besides the main one used for authentication). Then I thought that I might be able to define an internal attribute (similar to Cleartext-Password) that contained the OTP secret. It would be defined as follows: ATTRIBUTE OTP-Secret 3000 string And then use it on the "users" file or on the DB as follows: alex(a)test.org Cleartext-Password := "OneTestingPassword", OTP-Secret := "7MR674BRPXXNYGGMPFA52MW6GSMA6JQL" This way I would be able to define the OTP Secret right next to the user password, on any backend that I'd like to use (users file, LDAP, SQL...). I've tested it and it works, so question is: Can I define internal attributes for private module usage? If so, how are numbers allocated? Can I use any number I want if it's not currently in use? Thanks, -- Alejandro Perez-Mendez Technical Specialist (AAA), Trust & Identity M (+34) 619 333 219 Skype alejandro_perez_mendez jisc.ac.uk Jisc is a registered charity (number 1149740) and a company limited by guarantee which is registered in England under Company No. 5747339, VAT No. GB 197 0632 86. Jisc’s registered office is: One Castlepark, Tower Hill, Bristol, BS2 0JA. T 0203 697 5800. Jisc Services Limited is a wholly owned Jisc subsidiary and a company limited by guarantee which is registered in England under company number 2881024, VAT number GB 197 0632 86. The registered office is: One Castle Park, Tower Hill, Bristol BS2 0JA. T 0203 697 5800.

3 3

how to allow only AD domain members
by Walter Laub 02 Oct '18

02 Oct '18

Hi, I configured to authenticate (via winbindd) against AD. It works, but it is possible to authenticate as well on non-AD-member devices with an AD user. Is it possible to authenticate only with the mandatory criteria "AD membership"? Thank you. Regards, Wlater

2 1

smstop with Cisco Wireless
by Paul Aviles 01 Oct '18

01 Oct '18

Hello, I am new to the community and was wondering if anyone has manage to configure freeradius with a Cisco 5508 or 2504 controller for guest authentication with smstop. The goal is to provide a static wep2 password and force the users to enter their cell number where they will receive an sms message for 2 factor authentication. If the number matches, then the user will be authenticated. I currently have regular freeradius and a 2504 working, but missing the smstop/capture/validate part. Anyone with something similar out there? Regards, Paul

2 1

Config FreeRadius (3.0.16) to work with SQL: The Guide is outdated - please helps
by james.ngobui＠gmail.com 01 Oct '18

01 Oct '18

Hello everyone, Recently, I implemented freeradius for our home office. I was able to use the method of editing the user file to add user to authorize them using our network. Now I would like to use mySQL with phpMyAdmin to control and manage other users. So I installed Lamp Stack from here: https://www.digitalocean.com/community/tutorials/how-to-install-linux-apache -mysql-php-lamp-stack-ubuntu-18-04 which basically install Apache server, SQL server and PHP server. I have all 3 up and run OK. Anyway, after that I follow the Guide here to setup the mySQL https://wiki.freeradius.org/guide/SQL-HOWTO-for-freeradius-3.x-on-Debian-Ubu ntu After I finished installing the freeradius-mysql module and created the "radius" database, it shows up in the phpMyAdmin windows. I was excited. However, further more in the Guide, I found a lot of difference/discrepancies in term of file names, location of the files like sql (not sure if sql.conf?). It seems that the Guide is now outdated and pending for update to catch up with the new version of Freeradius file organization As a result, when I attempt to use SQL to authorize the users, the server keeps rejecting my username/password I run radtest and it says "No reply from server" Could someone please instruct me how to start from the scratch again with a proper file's names, locations of each required files, what to edit, etc..? I thank you very much indeed for your support. Again, thanks James --- This email has been checked for viruses by AVG. https://www.avg.com

7 15

pass_all_vps option for rlm_python
by work vlpl 01 Oct '18

01 Oct '18

Hello, I found the not described option `pass_all_vps` for rlm_python module. Is this option intended only for testing? I am asking because neither https://wiki.freeradius.org/modules/Rlm_python page, neither default python config files from `.../raddb/mods-available` does not say anything about this options. I am -- Vladimir

4 7