eap_peap: ERROR: System call (I/O) error (-1)
Arnaud LAURIOU
arnaud.lauriou at renater.fr
Wed May 15 14:20:13 CEST 2019
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
More information about the Freeradius-Users
mailing list