EAP TLS: rlm_eap: Failed in handler
Sorry...my first posting was not easy to read ;-(
Here the same subject in a readable format
Hello!
I tried to use eap tls.
When I started radius everything looked fine.
Then radius receives an access request and answers with an access challenge containing EAP TLS START.
No problem so far. But when radius receives the TLS client hello in the next step it fails with
"rlm_eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request" and "rlm_eap: failed in handler".
I am rather confused now.
Perhaps one of the experts could give me hint concerning the cause.
Thanks in advance!
Greetings
Michael Heiart
Module: Loaded eap
eap: default_eap_type = "tls"
eap: timer_expire = 60
eap: ignore_unknown_eap_types = no
eap: cisco_accounting_username_bug = no
tls: rsa_key_exchange = no
tls: dh_key_exchange = yes
tls: rsa_key_length = 512
tls: dh_key_length = 512 tls: verify_depth = 0
tls: CA_path = "(null)" tls: pem_file_type = yes
tls: private_key_file = "/usr/local/etc/raddb/certs/cert-srv.pem"
tls: certificate_file = "/usr/local/etc/raddb/certs/cert-srv.pem"
tls: CA_file = "/usr/local/etc/raddb/certs/demoCA/cacert.pem"
tls: private_key_password = "whatever" tls: dh_file = "/usr/local/etc/raddb/certs/dh"
tls: random_file = "/usr/local/etc/raddb/certs/random" tls: fragment_size = 1024
tls: include_length = yes
tls: check_crl = no tls: check_cert_cn = "(null)"
rlm_eap: Loaded and initialized type tls
Module: Instantiated eap (eap)
...
Listening on authentication *:1812
Listening on accounting *:1813
Listening on proxy *:1814 Ready to process requests.
...
rad_recv: Access-Request packet from host 127.0.0.1:32858, id=167, length=95
User-Name = "Server certificate"
EAP-Message = 0x02b6001701536572766572206365727469666963617465
NAS-IP-Address = 127.0.0.2
NAS-Port = 0
Message-Authenticator = 0x0012efe996568bc1ca6419e4c07ce713
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
modcall[authorize]: module "preprocess" returns ok for request 0
radius_xlat: '/usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709
modcall[authorize]: module "auth_log" returns ok for request 0
modcall[authorize]: module "chap" returns noop for request 0
rlm_realm: No '@' in User-Name = "Server certificate", looking up realm NULL
rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 0
rlm_eap: EAP packet type response id 182 length 23
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 0
users: Matched DEFAULT at 154
modcall[authorize]: module "files" returns ok for request 0
modcall: group authorize returns updated for request 0
rad_check_password: Found Auth-Type EAP auth: type "EAP"
Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 0
rlm_eap: EAP Identity rlm_eap: processing type tls
rlm_eap_tls: Requiring client certificate
rlm_eap_tls: Initiate
rlm_eap_tls: Start returned 1
modcall[authenticate]: module "eap" returns handled for request 0
modcall: group authenticate returns handled for request 0
Sending Access-Challenge of id 167 to 127.0.0.1:32858
EAP-Message = 0x01b700060d20
Message-Authenticator = 0x
State = 0x172cf45df81917d900bc7f4cd4353545
Finished request 0 Going to the next request
--- Walking the entire request list
--- Waking up in 6 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:32858, id=168, length=152
User-Name = "Server certificate"
EAP-Message = 0x02b700500d8000461603010041013d030140ee5e798623d9c38b893a0d87ba4681324740e7f1b264453463058af5167c4a1600040005000a000900640062000300060013001200630100
NAS-IP-Address = 127.0.0.2
NAS-Port = 0
Message-Authenticator = 0x2816e26924e7c987dc6ccb8e4729e0d4
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 1
modcall[authorize]: module "preprocess" returns ok for request 1
radius_xlat: '/usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709
modcall[authorize]: module "auth_log" returns ok for request 1
modcall[authorize]: module "chap" returns noop for request 1
rlm_realm: No '@' in User-Name = "Server certificate", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[authorize]: module "suffix" returns noop for request 1
rlm_eap: EAP packet type response id 183 length 80
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 1
users: Matched DEFAULT at 154
Re: EAP TLS: rlm_eap: Failed in handler
What are you using for a Supplicant???
gm...
- Original Message -
From:
[EMAIL PROTECTED]
To: [EMAIL PROTECTED]
Sent: Friday, July 09, 2004 5:37 AM
Subject: EAP TLS: rlm_eap: Failed in
handler
Sorry...my first posting was not easy to read ;-(Here the
same subject in a readable formatHello!I tried to use eap tls.
When I started radius everything looked fine. Then radius receives
an access request and answers with an access challenge containing EAP TLS
START. No problem so far. But when radius receives the TLS client hello in
the next step it fails with "rlm_eap: Either EAP-request timed out OR
EAP-response to an unknown EAP-request" and "rlm_eap: failed in handler".
I am rather confused now. Perhaps one of the experts could give me
hint concerning the cause. Thanks in advance! Greetings
Michael Heiart Module: Loaded eap eap: default_eap_type =
"tls" eap: timer_expire = 60 eap: ignore_unknown_eap_types = no
eap: cisco_accounting_username_bug = no tls: rsa_key_exchange = no
tls: dh_key_exchange = yes tls: rsa_key_length = 512 tls:
dh_key_length = 512 tls: verify_depth = 0 tls: CA_path = "(null)" tls:
pem_file_type = yes tls: private_key_file =
"/usr/local/etc/raddb/certs/cert-srv.pem" tls: certificate_file =
"/usr/local/etc/raddb/certs/cert-srv.pem" tls: CA_file =
"/usr/local/etc/raddb/certs/demoCA/cacert.pem" tls: private_key_password =
"whatever" tls: dh_file = "/usr/local/etc/raddb/certs/dh" tls: random_file
= "/usr/local/etc/raddb/certs/random" tls: fragment_size = 1024 tls:
include_length = yes tls: check_crl = no tls: check_cert_cn = "(null)"
rlm_eap: Loaded and initialized type tls Module: Instantiated eap
(eap)... Listening on authentication *:1812 Listening on
accounting *:1813 Listening on proxy *:1814 Ready to process
requests rad_recv: Access-Request packet from host
127.0.0.1:32858, id=167, length=95 User-Name = "Server certificate"
EAP-Message = 0x02b6001701536572766572206365727469666963617465
NAS-IP-Address = 127.0.0.2 NAS-Port = 0 Message-Authenticator =
0x0012efe996568bc1ca6419e4c07ce713 Processing the authorize section of
radiusd.conf modcall: entering group authorize for request 0
modcall[authorize]: module "preprocess" returns ok for request 0
radius_xlat:
'/usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709'
rlm_detail:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709
modcall[authorize]: module "auth_log" returns ok for request 0
modcall[authorize]: module "chap" returns noop for request 0
rlm_realm: No '@' in User-Name = "Server certificate", looking up realm
NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix"
returns noop for request 0 rlm_eap: EAP packet type response id 182 length
23 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 0 users:
Matched DEFAULT at 154 modcall[authorize]: module "files" returns ok for
request 0 modcall: group authorize returns updated for request 0
rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing
the authenticate section of radiusd.conf modcall: entering group authenticate
for request 0 rlm_eap: EAP Identity rlm_eap: processing type tls
rlm_eap_tls: Requiring client certificate rlm_eap_tls: Initiate
rlm_eap_tls: Start returned 1 modcall[authenticate]: module "eap"
returns handled for request 0 modcall: group authenticate returns handled
for request 0 Sending Access-Challenge of id 167 to 127.0.0.1:32858
EAP-Message = 0x01b700060d20 Message-Authenticator =
0x State =
0x172cf45df81917d900bc7f4cd4353545 Finished request 0 Going to the next
request --- Walking the entire request list --- Waking up in 6
seconds... rad_recv: Access-Request packet from host 127.0.0.1:32858,
id=168, length=152 User-Name = "Server certificate" EAP-Message =
0x02b700500d8000461603010041013d030140ee5e798623d9c38b893a0d87ba4681324740e7f1b264453463058af5167c4a1600040005000a000900640062000300060013001200630100NAS-IP-Address
= 127.0.0.2 NAS-Port = 0 Message-Authenticator =
0x2816e26924e7c987dc6ccb8e4729e0d4 Processing the authorize section of
radiusd.conf modcall: entering group authorize for request 1
modcall[authorize]: module "preprocess" returns ok for request 1
radius_xlat:
'/usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709'
rlm_detail:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands t
Re: Re: EAP TLS: rlm_eap: Failed in handler
Hello!
Perhaps I should describe the components in detail:
-openssl-0.9.7d
-radius latest pre3 Version
-peer and radius use the demo certificates that come with radius
-pppd with additional source code which capsulates and decapsulates EAP
(the NAS becomes a "proxy" for EAP between peer and radius with this source code)
-Client/Peer: XP
I know that my "proxy" source code for the pppd can cause problems,
because it has not been tested with radius in detail so far
but from the the radius output I can see that the communication looks more or less
like the output written when a professional AP talks to radius.
In http://www.freeradius.org/doc/EAPTLS.pdf the last few pages show the communication between
a cispo AP340 and radius. It does not show something completly different...or does it?
I ASSUME that the radius does not realize that the access request containing the TLS client hello belongs
to the existing request that it initiated in the previous step. But why does this happen?
The Radius id and the the EAP id are correct, too.
Greetings
Michael Heiart
BTW: I did not set the Auth-Type to EAP;-)
//=
Module: Loaded eap
eap: default_eap_type = "tls"
eap: timer_expire = 60
eap: ignore_unknown_eap_types = no
eap: cisco_accounting_username_bug = no
tls: rsa_key_exchange = no
tls: dh_key_exchange = yes
tls: rsa_key_length = 512
tls: dh_key_length = 512 tls: verify_depth = 0
tls: CA_path = "(null)" tls: pem_file_type = yes
tls: private_key_file = "/usr/local/etc/raddb/certs/cert-srv.pem"
tls: certificate_file = "/usr/local/etc/raddb/certs/cert-srv.pem"
tls: CA_file = "/usr/local/etc/raddb/certs/demoCA/cacert.pem"
tls: private_key_password = "whatever" tls: dh_file = "/usr/local/etc/raddb/certs/dh"
tls: random_file = "/usr/local/etc/raddb/certs/random" tls: fragment_size = 1024
tls: include_length = yes
tls: check_crl = no tls: check_cert_cn = "(null)"
rlm_eap: Loaded and initialized type tls
Module: Instantiated eap (eap)
...
Listening on authentication *:1812
Listening on accounting *:1813
Listening on proxy *:1814 Ready to process requests.
...
rad_recv: Access-Request packet from host 127.0.0.1:32858, id=167, length=95
User-Name = "Server certificate"
EAP-Message = 0x02b6001701536572766572206365727469666963617465
NAS-IP-Address = 127.0.0.2
NAS-Port = 0
Message-Authenticator = 0x0012efe996568bc1ca6419e4c07ce713
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
modcall[authorize]: module "preprocess" returns ok for request 0
radius_xlat: '/usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709
modcall[authorize]: module "auth_log" returns ok for request 0
modcall[authorize]: module "chap" returns noop for request 0
rlm_realm: No '@' in User-Name = "Server certificate", looking up realm NULL
rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 0
rlm_eap: EAP packet type response id 182 length 23
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 0
users: Matched DEFAULT at 154
modcall[authorize]: module "files" returns ok for request 0
modcall: group authorize returns updated for request 0
rad_check_password: Found Auth-Type EAP auth: type "EAP"
Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 0
rlm_eap: EAP Identity rlm_eap: processing type tls
rlm_eap_tls: Requiring client certificate
rlm_eap_tls: Initiate
rlm_eap_tls: Start returned 1
modcall[authenticate]: module "eap" returns handled for request 0
modcall: group authenticate returns handled for request 0
Sending Access-Challenge of id 167 to 127.0.0.1:32858
EAP-Message = 0x01b700060d20
Message-Authenticator = 0x
State = 0x172cf45df81917d900bc7f4cd4353545
Finished request 0 Going to the next request
--- Walking the entire request list
--- Waking up in 6 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:32858, id=168, length=152
User-Name = "Server certificate"
EAP-Message = 0x02b700500d8000461603010041013d030140ee5e798623d9c38b893a0d87ba4681324740e7f1b264453463058af5167c4a1600040005000a000900640062000300060013001200630100
NAS-IP-Address = 127.0.0.2
NAS-Port = 0
Message-Authenticator = 0x2816e26924e7c987dc6ccb8e4729e0d4
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 1
modcall[authorize]: module "preprocess" returns ok for request 1
radius_xlat: '/usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709'
rlm_detail:
Re: EAP TLS: rlm_eap: Failed in handler
And the same again.my linux email client behaves a little strange...
Hello!
Perhaps I should describe the components in detail:
-openssl-0.9.7d -radius latest pre3 Version
-peer and radius use the demo certificates that come with radius
-pppd with additional source code which capsulates and decapsulates EAP
(the NAS becomes a "proxy" for EAP between peer and radius with this source code)
-Client/Peer: XP
I know that my "proxy" source code for the pppd can cause problems,
because it has not been tested with radius in detail so far but
from the the radius output I can see that the communication looks more or less
like the output written when a professional AP talks to radius.
In http://www.freeradius.org/doc/EAPTLS.pdf the last few pages show the communication between
a cispo AP340 and radius. It does not show something completly different...or does it?
I ASSUME that the radius does not realize that the access request containing the TLS client hello belongs to the existing request that it initiated in the previous step. But why does this happen? The Radius id and the the EAP id are correct, too.
Greetings
Michael Heiart
BTW: I did not set the Auth-Type to EAP ;-)
// ==
Module: Loaded eap
eap: default_eap_type = "tls"
eap: timer_expire = 60
eap: ignore_unknown_eap_types = no
eap: cisco_accounting_username_bug = no
tls: rsa_key_exchange = no
tls: dh_key_exchange = yes
tls: rsa_key_length = 512
tls: dh_key_length = 512 tls: verify_depth = 0
tls: CA_path = "(null)" tls: pem_file_type = yes
tls: private_key_file = "/usr/local/etc/raddb/certs/cert-srv.pem"
tls: certificate_file = "/usr/local/etc/raddb/certs/cert-srv.pem"
tls: CA_file = "/usr/local/etc/raddb/certs/demoCA/cacert.pem"
tls: private_key_password = "whatever" tls: dh_file = "/usr/local/etc/raddb/certs/dh"
tls: random_file = "/usr/local/etc/raddb/certs/random" tls: fragment_size = 1024
tls: include_length = yes
tls: check_crl = no tls: check_cert_cn = "(null)"
rlm_eap: Loaded and initialized type tls
Module: Instantiated eap (eap)
...
Listening on authentication *:1812
Listening on accounting *:1813
Listening on proxy *:1814 Ready to process requests.
...
rad_recv: Access-Request packet from host 127.0.0.1:32858, id=167, length=95
User-Name = "Server certificate"
EAP-Message = 0x02b6001701536572766572206365727469666963617465
NAS-IP-Address = 127.0.0.2
NAS-Port = 0
Message-Authenticator = 0x0012efe996568bc1ca6419e4c07ce713
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
modcall[authorize]: module "preprocess" returns ok for request 0
radius_xlat: '/usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709
modcall[authorize]: module "auth_log" returns ok for request 0
modcall[authorize]: module "chap" returns noop for request 0
rlm_realm: No '@' in User-Name = "Server certificate", looking up realm NULL
rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 0
rlm_eap: EAP packet type response id 182 length 23
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 0
users: Matched DEFAULT at 154
modcall[authorize]: module "files" returns ok for request 0
modcall: group authorize returns updated for request 0
rad_check_password: Found Auth-Type EAP auth: type "EAP"
Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 0
rlm_eap: EAP Identity rlm_eap: processing type tls
rlm_eap_tls: Requiring client certificate
rlm_eap_tls: Initiate
rlm_eap_tls: Start returned 1
modcall[authenticate]: module "eap" returns handled for request 0
modcall: group authenticate returns handled for request 0
Sending Access-Challenge of id 167 to 127.0.0.1:32858
EAP-Message = 0x01b700060d20
Message-Authenticator = 0x
State = 0x172cf45df81917d900bc7f4cd4353545
Finished request 0 Going to the next request
--- Walking the entire request list
--- Waking up in 6 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:32858, id=168, length=152
User-Name = "Server certificate"
EAP-Message = 0x02b700500d8000461603010041013d030140ee5e798623d9c38b893a0d87ba4681324740e7f1b264453463058af5167c4a1600040005000a000900640062000300060013001200630100
NAS-IP-Address = 127.0.0.2
NAS-Port = 0
Message-Authenticator = 0x2816e26924e7c987dc6ccb8e4729e0d4
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 1
modcall[authorize]: module "preprocess" returns ok for request 1
radius_xlat: '/usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20040709'
rlm_detail:
