Hi, Problem resolved : the server name in the new X.509 EAP server certificate (CN) was mismatched from the one used in Android EAP profile (serverID in eap-config file). Regards, Arnaud Lauriou On 5/15/19 2:20 PM, Arnaud LAURIOU wrote:
Hi,
We are upgrading our freeradius servers : 3.0.19 (from packages.networkradius.com) under Ubuntu 18.04.
Tests are good with most clients (linux, windows, mac) but fail with Android clients (version 7) with a EAP error message.
The first EAP exchanges seem to work fine (sections 0 to 4) then fail in section 5.
Here is the log : Ready to process requests (0) Received Access-Request Id 102 from 195.220.94.1:1645 to 194.57.4.197:1812 length 157 (0) User-Name = "anonymous@renater.fr" (0) Framed-MTU = 1400 (0) Called-Station-Id = "0012.d942.a460" (0) Calling-Station-Id = "ccc0.7942.6070" (0) Service-Type = Login-User (0) Message-Authenticator = 0xa0adc019dd45f629b627b8812b24032b (0) EAP-Message = 0x0201001901616e6f6e796d6f75734072656e617465722e6672 (0) NAS-Port-Type = Wireless-802.11 (0) NAS-Port = 314 (0) NAS-IP-Address = 195.220.94.1 (0) NAS-Identifier = "ap1000" (0) # Executing section authorize from file /etc/freeradius/sites-enabled/eduroam (0) authorize { (0) policy filter_username { (0) if (&User-Name) { (0) if (&User-Name) -> TRUE (0) if (&User-Name) { (0) if (&User-Name =~ / /) { (0) if (&User-Name =~ / /) -> FALSE (0) if (&User-Name =~ /@[^@]*@/ ) { (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (0) if (&User-Name =~ /\.\./ ) { (0) if (&User-Name =~ /\.\./ ) -> FALSE (0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) { (0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE (0) if (&User-Name =~ /\.$/) { (0) if (&User-Name =~ /\.$/) -> FALSE (0) if (&User-Name =~ /@\./) { (0) if (&User-Name =~ /@\./) -> FALSE (0) if (&User-Name !~ /@renater.fr/) { (0) if (&User-Name !~ /@renater.fr/) -> FALSE (0) } # if (&User-Name) = notfound (0) } # policy filter_username = notfound (0) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) { (0) EXPAND %{client:shortname} (0) --> borne-rennes-1100 (0) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) -> TRUE (0) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) { (0) update request { (0) Operator-Name := "1renater.fr" (0) } # update request = noop (0) } # if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) = noop (0) policy cui.authorize { (0) if ("%{client:add_cui}" == 'yes') { (0) EXPAND %{client:add_cui} (0) --> yes (0) if ("%{client:add_cui}" == 'yes') -> TRUE (0) if ("%{client:add_cui}" == 'yes') { (0) update request { (0) &Chargeable-User-Identity := 0x00 (0) } # update request = noop (0) } # if ("%{client:add_cui}" == 'yes') = noop (0) } # policy cui.authorize = noop (0) auth_log: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (0) auth_log: --> /var/log/freeradius/radacct/195.220.94.1/auth-detail-20190515 (0) auth_log: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/195.220.94.1/auth-detail-20190515 (0) auth_log: EXPAND %t (0) auth_log: --> Wed May 15 10:01:24 2019 (0) [auth_log] = ok (0) suffix: Checking for suffix after "@" (0) suffix: Looking up realm "renater.fr" for User-Name = "anonymous@renater.fr" (0) suffix: Found realm "renater.fr" (0) suffix: Adding Realm = "renater.fr" (0) suffix: Authentication realm is LOCAL (0) [suffix] = ok (0) eap: Peer sent EAP Response (code 2) ID 1 length 25 (0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (0) [eap] = ok (0) } # authorize = ok (0) Found Auth-Type = eap (0) # Executing group from file /etc/freeradius/sites-enabled/eduroam (0) authenticate { (0) eap: Peer sent packet with method EAP Identity (1) (0) eap: Calling submodule eap_peap to process data (0) eap_peap: Initiating new TLS session (0) eap_peap: [eaptls start] = request (0) eap: Sending EAP Request (code 1) ID 2 length 6 (0) eap: EAP session adding &reply:State = 0xcaaa2a6ccaa833e7 (0) [eap] = handled (0) } # authenticate = handled (0) Using Post-Auth-Type Challenge (0) Post-Auth-Type sub-section not found. Ignoring. (0) # Executing group from file /etc/freeradius/sites-enabled/eduroam (0) Sent Access-Challenge Id 102 from 194.57.4.197:1812 to 195.220.94.1:1645 length 0 (0) EAP-Message = 0x010200061920 (0) Message-Authenticator = 0x00000000000000000000000000000000 (0) State = 0xcaaa2a6ccaa833e7ad7633b276a93937 (0) Finished request Waking up in 4.9 seconds. (1) Received Access-Request Id 103 from 195.220.94.1:1645 to 194.57.4.197:1812 length 317 (1) User-Name = "anonymous@renater.fr" (1) Framed-MTU = 1400 (1) Called-Station-Id = "0012.d942.a460" (1) Calling-Station-Id = "ccc0.7942.6070" (1) Service-Type = Login-User (1) Message-Authenticator = 0xb384c184c8fe45956c9246c04902dc31 (1) EAP-Message = 0x020200a719800000009d1603010098010000940303f94b22c62eeae3503df6f5e1bff784a2afda34d472918e62076ac43a07b9b3bc00003cc02bc02f009ec02cc030009fcca9cca8c009c023c013c02700330067c00ac024c014c0280039006bc007c011009c009d002f003c0035003d0005000a0100002fff0100010000170000000d0010000e0403040105030501060306010201000b00020100000a00080006001d00170018 (1) NAS-Port-Type = Wireless-802.11 (1) NAS-Port = 314 (1) State = 0xcaaa2a6ccaa833e7ad7633b276a93937 (1) NAS-IP-Address = 195.220.94.1 (1) NAS-Identifier = "ap1000" (1) session-state: No cached attributes (1) # Executing section authorize from file /etc/freeradius/sites-enabled/eduroam (1) authorize { (1) policy filter_username { (1) if (&User-Name) { (1) if (&User-Name) -> TRUE (1) if (&User-Name) { (1) if (&User-Name =~ / /) { (1) if (&User-Name =~ / /) -> FALSE (1) if (&User-Name =~ /@[^@]*@/ ) { (1) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (1) if (&User-Name =~ /\.\./ ) { (1) if (&User-Name =~ /\.\./ ) -> FALSE (1) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) { (1) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE (1) if (&User-Name =~ /\.$/) { (1) if (&User-Name =~ /\.$/) -> FALSE (1) if (&User-Name =~ /@\./) { (1) if (&User-Name =~ /@\./) -> FALSE (1) if (&User-Name !~ /@renater.fr/) { (1) if (&User-Name !~ /@renater.fr/) -> FALSE (1) } # if (&User-Name) = notfound (1) } # policy filter_username = notfound (1) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) { (1) EXPAND %{client:shortname} (1) --> borne-rennes-1100 (1) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) -> TRUE (1) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) { (1) update request { (1) Operator-Name := "1renater.fr" (1) } # update request = noop (1) } # if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) = noop (1) policy cui.authorize { (1) if ("%{client:add_cui}" == 'yes') { (1) EXPAND %{client:add_cui} (1) --> yes (1) if ("%{client:add_cui}" == 'yes') -> TRUE (1) if ("%{client:add_cui}" == 'yes') { (1) update request { (1) &Chargeable-User-Identity := 0x00 (1) } # update request = noop (1) } # if ("%{client:add_cui}" == 'yes') = noop (1) } # policy cui.authorize = noop (1) auth_log: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (1) auth_log: --> /var/log/freeradius/radacct/195.220.94.1/auth-detail-20190515 (1) auth_log: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/195.220.94.1/auth-detail-20190515 (1) auth_log: EXPAND %t (1) auth_log: --> Wed May 15 10:01:24 2019 (1) [auth_log] = ok (1) suffix: Checking for suffix after "@" (1) suffix: Looking up realm "renater.fr" for User-Name = "anonymous@renater.fr" (1) suffix: Found realm "renater.fr" (1) suffix: Adding Realm = "renater.fr" (1) suffix: Authentication realm is LOCAL (1) [suffix] = ok (1) eap: Peer sent EAP Response (code 2) ID 2 length 167 (1) eap: Continuing tunnel setup (1) [eap] = ok (1) } # authorize = ok (1) Found Auth-Type = eap (1) # Executing group from file /etc/freeradius/sites-enabled/eduroam (1) authenticate { (1) eap: Expiring EAP session with state 0xcaaa2a6ccaa833e7 (1) eap: Finished EAP session with state 0xcaaa2a6ccaa833e7 (1) eap: Previous EAP request found for state 0xcaaa2a6ccaa833e7, released from the list (1) eap: Peer sent packet with method EAP PEAP (25) (1) eap: Calling submodule eap_peap to process data (1) eap_peap: Continuing EAP-TLS (1) eap_peap: Peer indicated complete TLS record size will be 157 bytes (1) eap_peap: Got complete TLS record (157 bytes) (1) eap_peap: [eaptls verify] = length included (1) eap_peap: (other): before SSL initialization (1) eap_peap: TLS_accept: before SSL initialization (1) eap_peap: TLS_accept: before SSL initialization (1) eap_peap: <<< recv TLS 1.2 [length 0098] (1) eap_peap: TLS_accept: SSLv3/TLS read client hello (1) eap_peap: >>> send TLS 1.2 [length 003d] (1) eap_peap: TLS_accept: SSLv3/TLS write server hello (1) eap_peap: >>> send TLS 1.2 [length 0c90] (1) eap_peap: TLS_accept: SSLv3/TLS write certificate (1) eap_peap: >>> send TLS 1.2 [length 014d] (1) eap_peap: TLS_accept: SSLv3/TLS write key exchange (1) eap_peap: >>> send TLS 1.2 [length 0004] (1) eap_peap: TLS_accept: SSLv3/TLS write server done (1) eap_peap: TLS_accept: Need to read more data: SSLv3/TLS write server done (1) eap_peap: TLS - In Handshake Phase (1) eap_peap: TLS - got 3634 bytes of data (1) eap_peap: [eaptls process] = handled (1) eap: Sending EAP Request (code 1) ID 3 length 1024 (1) eap: EAP session adding &reply:State = 0xcaaa2a6ccba933e7 (1) [eap] = handled (1) } # authenticate = handled (1) Using Post-Auth-Type Challenge (1) Post-Auth-Type sub-section not found. Ignoring. (1) # Executing group from file /etc/freeradius/sites-enabled/eduroam (1) Sent Access-Challenge Id 103 from 194.57.4.197:1812 to 195.220.94.1:1645 length 0 (1) EAP-Message = 0x0103040019c000000e32160303003d02000039030349a0e794e6bc9ac98b22c390967324e4711c255b0bafc92c5c0b74d1b437b35e00c02f000011ff01000100000b000403000102001700001603030c900b000c8c000c890007843082078030820668a00302010202100cf0c689f2b6db0e4f019ae302502e32300d06092a864886f70d01010b05003064310b3009060355040613024e4c311630140603550408130d4e6f6f72642d486f6c6c616e643112301006035504071309416d7374657264616d310f300d060355040a1306544552454e41311830160603550403130f544552454e412053534c2043412033301e170d3139303431363030303030305a170d3231303731393030303030305a30818f310b3009060355040613024652310e300c060355040713055061726973313f303d060355040a13365245532e204e41542e2044452054454c45434f4d2e20504f5552204c4120544543482e204420454e532e204554204c4120524543482e312f302d060355 (1) Message-Authenticator = 0x00000000000000000000000000000000 (1) State = 0xcaaa2a6ccba933e7ad7633b276a93937 (1) Finished request Waking up in 4.9 seconds. (2) Received Access-Request Id 104 from 195.220.94.1:1645 to 194.57.4.197:1812 length 156 (2) User-Name = "anonymous@renater.fr" (2) Framed-MTU = 1400 (2) Called-Station-Id = "0012.d942.a460" (2) Calling-Station-Id = "ccc0.7942.6070" (2) Service-Type = Login-User (2) Message-Authenticator = 0xc3b7d99ca284d8f861e93b8a9ecb97b8 (2) EAP-Message = 0x020300061900 (2) NAS-Port-Type = Wireless-802.11 (2) NAS-Port = 314 (2) State = 0xcaaa2a6ccba933e7ad7633b276a93937 (2) NAS-IP-Address = 195.220.94.1 (2) NAS-Identifier = "ap1000" (2) session-state: No cached attributes (2) # Executing section authorize from file /etc/freeradius/sites-enabled/eduroam (2) authorize { (2) policy filter_username { (2) if (&User-Name) { (2) if (&User-Name) -> TRUE (2) if (&User-Name) { (2) if (&User-Name =~ / /) { (2) if (&User-Name =~ / /) -> FALSE (2) if (&User-Name =~ /@[^@]*@/ ) { (2) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (2) if (&User-Name =~ /\.\./ ) { (2) if (&User-Name =~ /\.\./ ) -> FALSE (2) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) { (2) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE (2) if (&User-Name =~ /\.$/) { (2) if (&User-Name =~ /\.$/) -> FALSE (2) if (&User-Name =~ /@\./) { (2) if (&User-Name =~ /@\./) -> FALSE (2) if (&User-Name !~ /@renater.fr/) { (2) if (&User-Name !~ /@renater.fr/) -> FALSE (2) } # if (&User-Name) = notfound (2) } # policy filter_username = notfound (2) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) { (2) EXPAND %{client:shortname} (2) --> borne-rennes-1100 (2) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) -> TRUE (2) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) { (2) update request { (2) Operator-Name := "1renater.fr" (2) } # update request = noop (2) } # if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) = noop (2) policy cui.authorize { (2) if ("%{client:add_cui}" == 'yes') { (2) EXPAND %{client:add_cui} (2) --> yes (2) if ("%{client:add_cui}" == 'yes') -> TRUE (2) if ("%{client:add_cui}" == 'yes') { (2) update request { (2) &Chargeable-User-Identity := 0x00 (2) } # update request = noop (2) } # if ("%{client:add_cui}" == 'yes') = noop (2) } # policy cui.authorize = noop (2) auth_log: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (2) auth_log: --> /var/log/freeradius/radacct/195.220.94.1/auth-detail-20190515 (2) auth_log: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/195.220.94.1/auth-detail-20190515 (2) auth_log: EXPAND %t (2) auth_log: --> Wed May 15 10:01:24 2019 (2) [auth_log] = ok (2) suffix: Checking for suffix after "@" (2) suffix: Looking up realm "renater.fr" for User-Name = "anonymous@renater.fr" (2) suffix: Found realm "renater.fr" (2) suffix: Adding Realm = "renater.fr" (2) suffix: Authentication realm is LOCAL (2) [suffix] = ok (2) eap: Peer sent EAP Response (code 2) ID 3 length 6 (2) eap: Continuing tunnel setup (2) [eap] = ok (2) } # authorize = ok (2) Found Auth-Type = eap (2) # Executing group from file /etc/freeradius/sites-enabled/eduroam (2) authenticate { (2) eap: Expiring EAP session with state 0xcaaa2a6ccba933e7 (2) eap: Finished EAP session with state 0xcaaa2a6ccba933e7 (2) eap: Previous EAP request found for state 0xcaaa2a6ccba933e7, released from the list (2) eap: Peer sent packet with method EAP PEAP (25) (2) eap: Calling submodule eap_peap to process data (2) eap_peap: Continuing EAP-TLS (2) eap_peap: Peer ACKed our handshake fragment (2) eap_peap: [eaptls verify] = request (2) eap_peap: [eaptls process] = handled (2) eap: Sending EAP Request (code 1) ID 4 length 1020 (2) eap: EAP session adding &reply:State = 0xcaaa2a6cc8ae33e7 (2) [eap] = handled (2) } # authenticate = handled (2) Using Post-Auth-Type Challenge (2) Post-Auth-Type sub-section not found. Ignoring. (2) # Executing group from file /etc/freeradius/sites-enabled/eduroam (2) Sent Access-Challenge Id 104 from 194.57.4.197:1812 to 195.220.94.1:1645 length 0 (2) EAP-Message = 0x010403fc1940332e63726c304c0603551d2004453043303706096086480186fd6c0101302a302806082b06010505070201161c68747470733a2f2f7777772e64696769636572742e636f6d2f4350533008060667810c010202306e06082b0601050507010104623060302406082b060105050730018618687474703a2f2f6f6373702e64696769636572742e636f6d303806082b06010505073002862c687474703a2f2f636163657274732e64696769636572742e636f6d2f544552454e4153534c4341332e637274300c0603551d130101ff04023000308201f6060a2b06010401d679020402048201e6048201e201e0007600ee4bbdb775ce60bae142691fabe19e66a30f7e5fb072d88300c47b897aa8fdcb0000016a268a5a9d000004030047304502201d5d5db28b56e2d37b6d45a00c9f7818066493c657cbb0bf6f03bc2683529e8c022100eeee46573a2cb109e769cb71924f257162c62983e5029ee9ff2420a62554f6430077008775bfe7597cf88c43995f (2) Message-Authenticator = 0x00000000000000000000000000000000 (2) State = 0xcaaa2a6cc8ae33e7ad7633b276a93937 (2) Finished request Waking up in 4.9 seconds. (3) Received Access-Request Id 105 from 195.220.94.1:1645 to 194.57.4.197:1812 length 156 (3) User-Name = "anonymous@renater.fr" (3) Framed-MTU = 1400 (3) Called-Station-Id = "0012.d942.a460" (3) Calling-Station-Id = "ccc0.7942.6070" (3) Service-Type = Login-User (3) Message-Authenticator = 0x0eec5ab7b19d608c9d73b4c13de1df93 (3) EAP-Message = 0x020400061900 (3) NAS-Port-Type = Wireless-802.11 (3) NAS-Port = 314 (3) State = 0xcaaa2a6cc8ae33e7ad7633b276a93937 (3) NAS-IP-Address = 195.220.94.1 (3) NAS-Identifier = "ap1000" (3) session-state: No cached attributes (3) # Executing section authorize from file /etc/freeradius/sites-enabled/eduroam (3) authorize { (3) policy filter_username { (3) if (&User-Name) { (3) if (&User-Name) -> TRUE (3) if (&User-Name) { (3) if (&User-Name =~ / /) { (3) if (&User-Name =~ / /) -> FALSE (3) if (&User-Name =~ /@[^@]*@/ ) { (3) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (3) if (&User-Name =~ /\.\./ ) { (3) if (&User-Name =~ /\.\./ ) -> FALSE (3) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) { (3) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE (3) if (&User-Name =~ /\.$/) { (3) if (&User-Name =~ /\.$/) -> FALSE (3) if (&User-Name =~ /@\./) { (3) if (&User-Name =~ /@\./) -> FALSE (3) if (&User-Name !~ /@renater.fr/) { (3) if (&User-Name !~ /@renater.fr/) -> FALSE (3) } # if (&User-Name) = notfound (3) } # policy filter_username = notfound (3) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) { (3) EXPAND %{client:shortname} (3) --> borne-rennes-1100 (3) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) -> TRUE (3) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) { (3) update request { (3) Operator-Name := "1renater.fr" (3) } # update request = noop (3) } # if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) = noop (3) policy cui.authorize { (3) if ("%{client:add_cui}" == 'yes') { (3) EXPAND %{client:add_cui} (3) --> yes (3) if ("%{client:add_cui}" == 'yes') -> TRUE (3) if ("%{client:add_cui}" == 'yes') { (3) update request { (3) &Chargeable-User-Identity := 0x00 (3) } # update request = noop (3) } # if ("%{client:add_cui}" == 'yes') = noop (3) } # policy cui.authorize = noop (3) auth_log: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (3) auth_log: --> /var/log/freeradius/radacct/195.220.94.1/auth-detail-20190515 (3) auth_log: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/195.220.94.1/auth-detail-20190515 (3) auth_log: EXPAND %t (3) auth_log: --> Wed May 15 10:01:24 2019 (3) [auth_log] = ok (3) suffix: Checking for suffix after "@" (3) suffix: Looking up realm "renater.fr" for User-Name = "anonymous@renater.fr" (3) suffix: Found realm "renater.fr" (3) suffix: Adding Realm = "renater.fr" (3) suffix: Authentication realm is LOCAL (3) [suffix] = ok (3) eap: Peer sent EAP Response (code 2) ID 4 length 6 (3) eap: Continuing tunnel setup (3) [eap] = ok (3) } # authorize = ok (3) Found Auth-Type = eap (3) # Executing group from file /etc/freeradius/sites-enabled/eduroam (3) authenticate { (3) eap: Expiring EAP session with state 0xcaaa2a6cc8ae33e7 (3) eap: Finished EAP session with state 0xcaaa2a6cc8ae33e7 (3) eap: Previous EAP request found for state 0xcaaa2a6cc8ae33e7, released from the list (3) eap: Peer sent packet with method EAP PEAP (25) (3) eap: Calling submodule eap_peap to process data (3) eap_peap: Continuing EAP-TLS (3) eap_peap: Peer ACKed our handshake fragment (3) eap_peap: [eaptls verify] = request (3) eap_peap: [eaptls process] = handled (3) eap: Sending EAP Request (code 1) ID 5 length 1020 (3) eap: EAP session adding &reply:State = 0xcaaa2a6cc9af33e7 (3) [eap] = handled (3) } # authenticate = handled (3) Using Post-Auth-Type Challenge (3) Post-Auth-Type sub-section not found. Ignoring. (3) # Executing group from file /etc/freeradius/sites-enabled/eduroam (3) Sent Access-Challenge Id 105 from 194.57.4.197:1812 to 195.220.94.1:1645 length 0 (3) EAP-Message = 0x010503fc19403fdb959a91cb6aeeefe465300d06092a864886f70d01010b05003065310b300906035504061302555331153013060355040a130c446967694365727420496e6331193017060355040b13107777772e64696769636572742e636f6d312430220603550403131b4469676943657274204173737572656420494420526f6f74204341301e170d3134313131383132303030305a170d3234313131383132303030305a3064310b3009060355040613024e4c311630140603550408130d4e6f6f72642d486f6c6c616e643112301006035504071309416d7374657264616d310f300d060355040a1306544552454e41311830160603550403130f544552454e412053534c204341203330820122300d06092a864886f70d01010105000382010f003082010a0282010100c5760f0fd943293b6c6dd147adde10bf23c278a84a7735f1235be04c1e41e7c23100bd88374575ddb90210801e8fed64230445a7a0393b814dcf633fc249ff229e88b0d296b95c8a74 (3) Message-Authenticator = 0x00000000000000000000000000000000 (3) State = 0xcaaa2a6cc9af33e7ad7633b276a93937 (3) Finished request Waking up in 4.9 seconds. (4) Received Access-Request Id 106 from 195.220.94.1:1645 to 194.57.4.197:1812 length 156 (4) User-Name = "anonymous@renater.fr" (4) Framed-MTU = 1400 (4) Called-Station-Id = "0012.d942.a460" (4) Calling-Station-Id = "ccc0.7942.6070" (4) Service-Type = Login-User (4) Message-Authenticator = 0xd94cb1d71dbe58181bc61743c36af928 (4) EAP-Message = 0x020500061900 (4) NAS-Port-Type = Wireless-802.11 (4) NAS-Port = 314 (4) State = 0xcaaa2a6cc9af33e7ad7633b276a93937 (4) NAS-IP-Address = 195.220.94.1 (4) NAS-Identifier = "ap1000" (4) session-state: No cached attributes (4) # Executing section authorize from file /etc/freeradius/sites-enabled/eduroam (4) authorize { (4) policy filter_username { (4) if (&User-Name) { (4) if (&User-Name) -> TRUE (4) if (&User-Name) { (4) if (&User-Name =~ / /) { (4) if (&User-Name =~ / /) -> FALSE (4) if (&User-Name =~ /@[^@]*@/ ) { (4) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (4) if (&User-Name =~ /\.\./ ) { (4) if (&User-Name =~ /\.\./ ) -> FALSE (4) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) { (4) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE (4) if (&User-Name =~ /\.$/) { (4) if (&User-Name =~ /\.$/) -> FALSE (4) if (&User-Name =~ /@\./) { (4) if (&User-Name =~ /@\./) -> FALSE (4) if (&User-Name !~ /@renater.fr/) { (4) if (&User-Name !~ /@renater.fr/) -> FALSE (4) } # if (&User-Name) = notfound (4) } # policy filter_username = notfound (4) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) { (4) EXPAND %{client:shortname} (4) --> borne-rennes-1100 (4) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) -> TRUE (4) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) { (4) update request { (4) Operator-Name := "1renater.fr" (4) } # update request = noop (4) } # if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) = noop (4) policy cui.authorize { (4) if ("%{client:add_cui}" == 'yes') { (4) EXPAND %{client:add_cui} (4) --> yes (4) if ("%{client:add_cui}" == 'yes') -> TRUE (4) if ("%{client:add_cui}" == 'yes') { (4) update request { (4) &Chargeable-User-Identity := 0x00 (4) } # update request = noop (4) } # if ("%{client:add_cui}" == 'yes') = noop (4) } # policy cui.authorize = noop (4) auth_log: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (4) auth_log: --> /var/log/freeradius/radacct/195.220.94.1/auth-detail-20190515 (4) auth_log: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/195.220.94.1/auth-detail-20190515 (4) auth_log: EXPAND %t (4) auth_log: --> Wed May 15 10:01:24 2019 (4) [auth_log] = ok (4) suffix: Checking for suffix after "@" (4) suffix: Looking up realm "renater.fr" for User-Name = "anonymous@renater.fr" (4) suffix: Found realm "renater.fr" (4) suffix: Adding Realm = "renater.fr" (4) suffix: Authentication realm is LOCAL (4) [suffix] = ok (4) eap: Peer sent EAP Response (code 2) ID 5 length 6 (4) eap: Continuing tunnel setup (4) [eap] = ok (4) } # authorize = ok (4) Found Auth-Type = eap (4) # Executing group from file /etc/freeradius/sites-enabled/eduroam (4) authenticate { (4) eap: Expiring EAP session with state 0xcaaa2a6cc9af33e7 (4) eap: Finished EAP session with state 0xcaaa2a6cc9af33e7 (4) eap: Previous EAP request found for state 0xcaaa2a6cc9af33e7, released from the list (4) eap: Peer sent packet with method EAP PEAP (25) (4) eap: Calling submodule eap_peap to process data (4) eap_peap: Continuing EAP-TLS (4) eap_peap: Peer ACKed our handshake fragment (4) eap_peap: [eaptls verify] = request (4) eap_peap: [eaptls process] = handled (4) eap: Sending EAP Request (code 1) ID 6 length 598 (4) eap: EAP session adding &reply:State = 0xcaaa2a6cceac33e7 (4) [eap] = handled (4) } # authenticate = handled (4) Using Post-Auth-Type Challenge (4) Post-Auth-Type sub-section not found. Ignoring. (4) # Executing group from file /etc/freeradius/sites-enabled/eduroam (4) Sent Access-Challenge Id 106 from 194.57.4.197:1812 to 195.220.94.1:1645 length 0 (4) EAP-Message = 0x01060256190098cf27364f11327474e640dd1dcdf2687735afb38c5dc604bf15f423678bb96f9704eb469dc2cdc9d1a4ae812ec9bab1e880d01cc939c15676596c9c7de3a9f0d3d134d83c49598b1a98cebfc6f2d83035ffe96f5da0af3aee6653aeaa8c69c8be9aa7a07bd8824b3313c807f377d7f364cd9e63f9422753ae103389723715f1bef71e35a2cec32df2d7b2e60bc769c0e51f5f7c699b7ece261a3344c3ba77053bba5d3f4189fa163bee046e5bac564bef8c70f24a7b57bd196e8b360754262d8609941f5f37abf0233f8f2c5f969e4771a844dea9b9852fb53460a55f09a09a431dd4bf2d44d68ddafd75cb5f16a00e61c2703d36160303014d0c0001490300174104338c12bd74ede52c52ca7f42320ec6f8b6504ffbee03cf64072b00d86733e5bdd64ad52a632dc45754243f5aeb2a255f98aaf93eed501786b8ec1e063e791ff104010100a09b99efec1da8d887c2b04a9f2085dd42d2880a6265447194091665e1c7f159b7aeea5e0217e455b641 (4) Message-Authenticator = 0x00000000000000000000000000000000 (4) State = 0xcaaa2a6cceac33e7ad7633b276a93937 (4) Finished request Waking up in 4.9 seconds. (5) Received Access-Request Id 107 from 195.220.94.1:1645 to 194.57.4.197:1812 length 167 (5) User-Name = "anonymous@renater.fr" (5) Framed-MTU = 1400 (5) Called-Station-Id = "0012.d942.a460" (5) Calling-Station-Id = "ccc0.7942.6070" (5) Service-Type = Login-User (5) Message-Authenticator = 0xd4447da78b6f5e04c59616dc33ec3fbe (5) EAP-Message = 0x0206001119800000000715030300020250 (5) NAS-Port-Type = Wireless-802.11 (5) NAS-Port = 314 (5) State = 0xcaaa2a6cceac33e7ad7633b276a93937 (5) NAS-IP-Address = 195.220.94.1 (5) NAS-Identifier = "ap1000" (5) session-state: No cached attributes (5) # Executing section authorize from file /etc/freeradius/sites-enabled/eduroam (5) authorize { (5) policy filter_username { (5) if (&User-Name) { (5) if (&User-Name) -> TRUE (5) if (&User-Name)�� { (5) if (&User-Name =~ / /) { (5) if (&User-Name =~ / /) -> FALSE (5) if (&User-Name =~ /@[^@]*@/ ) { (5) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (5) if (&User-Name =~ /\.\./ ) { (5) if (&User-Name =~ /\.\./ ) -> FALSE (5) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) { (5) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE (5) if (&User-Name =~ /\.$/) { (5) if (&User-Name =~ /\.$/) -> FALSE (5) if (&User-Name =~ /@\./) { (5) if (&User-Name =~ /@\./) -> FALSE (5) if (&User-Name !~ /@renater.fr/) { (5) if (&User-Name !~ /@renater.fr/) -> FALSE (5) } # if (&User-Name) = notfound (5) } # policy filter_username = notfound (5) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) { (5) EXPAND %{client:shortname} (5) --> borne-rennes-1100 (5) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) -> TRUE (5) if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) { (5) update request { (5) Operator-Name := "1renater.fr" (5) } # update request = noop (5) } # if ("%{client:shortname}" !~ /rad[1-2]\.eduroam\.fr/) = noop (5) policy cui.authorize { (5) if ("%{client:add_cui}" == 'yes') { (5) EXPAND %{client:add_cui} (5) --> yes (5) if ("%{client:add_cui}" == 'yes') -> TRUE (5) if ("%{client:add_cui}" == 'yes') { (5) update request { (5) &Chargeable-User-Identity := 0x00 (5) } # update request = noop (5) } # if ("%{client:add_cui}" == 'yes') = noop (5) } # policy cui.authorize = noop (5) auth_log: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d (5) auth_log: --> /var/log/freeradius/radacct/195.220.94.1/auth-detail-20190515 (5) auth_log: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/195.220.94.1/auth-detail-20190515 (5) auth_log: EXPAND %t (5) auth_log: --> Wed May 15 10:01:24 2019 (5) [auth_log] = ok (5) suffix: Checking for suffix after "@" (5) suffix: Looking up realm "renater.fr" for User-Name = "anonymous@renater.fr" (5) suffix: Found realm "renater.fr" (5) suffix: Adding Realm = "renater.fr" (5) suffix: Authentication realm is LOCAL (5) [suffix] = ok (5) eap: Peer sent EAP Response (code 2) ID 6 length 17 (5) eap: Continuing tunnel setup (5) [eap] = ok (5) } # authorize = ok (5) Found Auth-Type = eap (5) # Executing group from file /etc/freeradius/sites-enabled/eduroam (5) authenticate { (5) eap: Expiring EAP session with state 0xcaaa2a6cceac33e7 (5) eap: Finished EAP session with state 0xcaaa2a6cceac33e7 (5) eap: Previous EAP request found for state 0xcaaa2a6cceac33e7, released from the list (5) eap: Peer sent packet with method EAP PEAP (25) (5) eap: Calling submodule eap_peap to process data (5) eap_peap: Continuing EAP-TLS (5) eap_peap: Peer indicated complete TLS record size will be 7 bytes (5) eap_peap: Got complete TLS record (7 bytes) (5) eap_peap: [eaptls verify] = length included (5) eap_peap: <<< recv TLS 1.2 [length 0002] (5) eap_peap: ERROR: TLS Alert read:fatal:internal error (5) eap_peap: TLS_accept: Need to read more data: SSLv3/TLS write server done (5) eap_peap: ERROR: Failed in __FUNCTION__ (SSL_read): error:14094438:SSL routines:ssl3_read_bytes:tlsv1 alert internal error (5) eap_peap: ERROR: System call (I/O) error (-1) (5) eap_peap: ERROR: TLS receive handshake failed during operation (5) eap_peap: ERROR: [eaptls process] = fail (5) eap: ERROR: Failed continuing EAP PEAP (25) session. EAP sub-module failed (5) eap: Sending EAP Failure (code 4) ID 6 length 4 (5) eap: Failed in EAP select (5) [eap] = invalid (5) } # authenticate = invalid (5) Failed to authenticate the user (5) Using Post-Auth-Type Reject (5) # Executing group from file /etc/freeradius/sites-enabled/eduroam (5) Post-Auth-Type REJECT { (5) reply_log: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d (5) reply_log: --> /var/log/freeradius/radacct/195.220.94.1/reply-detail-20190515 (5) reply_log: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d expands to /var/log/freeradius/radacct/195.220.94.1/reply-detail-20190515 (5) reply_log: EXPAND %t (5) reply_log: --> Wed May 15 10:01:24 2019 (5) [reply_log] = ok (5) eduroam_cui_log: EXPAND eduroam_log.%{%{reply:Packet-Type}:-format} (5) eduroam_cui_log: --> eduroam_log.Access-Reject (5) eduroam_cui_log: EXPAND %t : eduroam-auth#ORG=%{request:Realm}#USER=%{User-Name}#CSI=%{%{Calling-Station-Id}:-Unknown Caller Id}#NAS=%{%{Called-Station-Id}:-Unknown Access Point}#CUI=%{%{reply:Chargeable-User-Identity}:-Unknown}#MSG=%{%{reply:Reply-Message}:-No Failure Reason}#RESULT=FAIL# (5) eduroam_cui_log: --> Wed May 15 10:01:24 2019 : eduroam-auth#ORG=renater.fr#USER=anonymous@renater.fr#CSI=ccc0.7942.6070#NAS=0012.d942.a460#CUI=Unknown#MSG=No Failure Reason#RESULT=FAIL# (5) eduroam_cui_log: EXPAND /var/log/freeradius/radius.log (5) eduroam_cui_log: --> /var/log/freeradius/radius.log (5) [eduroam_cui_log] = ok (5) } # Post-Auth-Type REJECT = ok (5) Login incorrect (eap_peap: TLS Alert read:fatal:internal error): [anonymous@renater.fr] (from client borne-rennes-1100 port 314 cli ccc0.7942.6070) (5) Sent Access-Reject Id 107 from 194.57.4.197:1812 to 195.220.94.1:1645 length 0 (5) EAP-Message = 0x04060004 (5) Message-Authenticator = 0x00000000000000000000000000000000 (5) Finished request
Any idea how to correct this error ?
Regards,
Arnaud Lauriou - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html