eap_peap: ERROR: System call (I/O) error (-1)

Arnaud LAURIOU arnaud.lauriou at renater.fr
Thu May 16 15:19:50 CEST 2019


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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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



More information about the Freeradius-Users mailing list