Re: problems with 802.1x - EAP-TLS

Vladimir, you have idea which problem in this configuration? Help me pleas=
e, =20

thank=B4s

Galvao

2005/5/10, Galvao Rezende <galvaorezende@gmail.com>:
> #########Complete log##############3
> Starting - reading configuration files ...
> reread_config: reading radiusd.conf
> Config: including file: /usr/local/etc/raddb/proxy.conf
> Config: including file: /usr/local/etc/raddb/clients.conf
> Config: including file: /usr/local/etc/raddb/snmp.conf
> Config: including file: /usr/local/etc/raddb/eap.conf
> Config: including file: /usr/local/etc/raddb/sql.conf
> main: prefix =3D "/usr/local"
> main: localstatedir =3D "/var"
> main: logdir =3D "/var/log/raddb"
> main: libdir =3D "/usr/local/lib"
> main: radacctdir =3D "/var/log/raddb/radacct"
> main: hostname_lookups =3D no
> main: max_request_time =3D 30
> main: cleanup_delay =3D 5
> main: max_requests =3D 256
> main: delete_blocked_requests =3D 0
> main: port =3D 0
> main: allow_core_dumps =3D no
> main: log_stripped_names =3D no
> main: log_file =3D "/var/log/raddb/radius.log"
> main: log_auth =3D no
> main: log_auth_badpass =3D no
> main: log_auth_goodpass =3D no
> main: pidfile =3D "/var/run/radiusd/radiusd.pid"
> main: user =3D "(null)"
> main: group =3D "(null)"
> main: usercollide =3D no
> main: lower_user =3D "no"
> main: lower_pass =3D "no"
> main: nospace_user =3D "no"
> main: nospace_pass =3D "no"
> main: checkrad =3D "/usr/local/sbin/checkrad"
> main: proxy_requests =3D yes
> proxy: retry_delay =3D 5
> proxy: retry_count =3D 3
> proxy: synchronous =3D no
> proxy: default_fallback =3D yes
> proxy: dead_time =3D 120
> proxy: post_proxy_authorize =3D yes
> proxy: wake_all_if_all_dead =3D no
> security: max_attributes =3D 200
> security: reject_delay =3D 1
> security: status_server =3D no
> main: debug_level =3D 0
> read_config_files: reading dictionary
> read_config_files: reading naslist
> Using deprecated naslist file. Support for this will go away soon.
> read_config_files: reading clients
> read_config_files: reading realms
> radiusd: entering modules setup
> Module: Library search path is /usr/local/lib
> Module: Loaded expr
> Module: Instantiated expr (expr)
> Module: Loaded System
> unix: cache =3D no
> unix: passwd =3D "(null)"
> unix: shadow =3D "(null)"
> unix: group =3D "(null)"
> unix: radwtmp =3D "/var/log/raddb/radwtmp"
> unix: usegroup =3D no
> unix: cache_reload =3D 600
> Module: Instantiated unix (unix)
> Module: Loaded eap
> eap: default_eap_type =3D "tls"
> eap: timer_expire =3D 60
> eap: ignore_unknown_eap_types =3D no
> eap: cisco_accounting_username_bug =3D no
> tls: rsa_key_exchange =3D no
> tls: dh_key_exchange =3D yes
> tls: rsa_key_length =3D 512
> tls: dh_key_length =3D 512
> tls: verify_depth =3D 0
> tls: CA_path =3D "(null)"
> tls: pem_file_type =3D yes
> tls: private_key_file =3D "/usr/local/openssl/misc1/servidor-key.pem"
> tls: certificate_file =3D "/usr/local/openssl/misc1/servidor.pem"
> tls: CA_file =3D "/usr/local/openssl/misc1/demoCA/cacert.pem"
> tls: private_key_password =3D "registro"
> tls: dh_file =3D "/usr/local/openssl/misc1/dh"
> tls: random_file =3D "/usr/local/openssl/misc1/random"
> tls: fragment_size =3D 1024
> tls: include_length =3D yes
> tls: check_crl =3D no
> tls: check_cert_cn =3D "(null)"
> rlm_eap: Loaded and initialized type tls
> Module: Instantiated eap (eap)
> Module: Loaded preprocess
> preprocess: huntgroups =3D "/usr/local/etc/raddb/huntgroups"
> preprocess: hints =3D "/usr/local/etc/raddb/hints"
> preprocess: with_ascend_hack =3D no
> preprocess: ascend_channels_per_line =3D 23
> preprocess: with_ntdomain_hack =3D no
> preprocess: with_specialix_jetstream_hack =3D no
> preprocess: with_cisco_vsa_hack =3D no
> Module: Instantiated preprocess (preprocess)
> Module: Loaded detail
> detail: detailfile =3D
> "/var/log/raddb/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d"
> detail: detailperm =3D 384
> detail: dirperm =3D 493
> detail: locking =3D no
> Module: Instantiated detail (auth_log)
> Module: Loaded realm
> realm: format =3D "suffix"
> realm: delimiter =3D "@"
> realm: ignore_default =3D no
> realm: ignore_null =3D no
> Module: Instantiated realm (suffix)
> Module: Loaded files
> files: usersfile =3D "/usr/local/etc/raddb/users"
> files: acctusersfile =3D "/usr/local/etc/raddb/acct_users"
> files: preproxy_usersfile =3D "/usr/local/etc/raddb/preproxy_users"
> files: compat =3D "no"
> Module: Instantiated files (files)
> Module: Loaded Acct-Unique-Session-Id
> acct_unique: key =3D "User-Name, Acct-Session-Id, NAS-IP-Address,
> Client-IP-Address, NAS-Port"
> Module: Instantiated acct_unique (acct_unique)
> detail: detailfile =3D
> "/var/log/raddb/radacct/%{Client-IP-Address}/detail-%Y%m%d"
> detail: detailperm =3D 384
> detail: dirperm =3D 493
> detail: locking =3D no
> Module: Instantiated detail (detail)
> Module: Loaded radutmp
> radutmp: filename =3D "/var/log/raddb/radutmp"
> radutmp: username =3D "%{User-Name}"
> radutmp: case_sensitive =3D yes
> radutmp: check_with_nas =3D yes
> radutmp: perm =3D 384
> radutmp: callerid =3D yes
> Module: Instantiated radutmp (radutmp)
> Listening on authentication *:1812
> Listening on accounting *:1813
> Listening on proxy *:1814
> Ready to process requests.
> rad_recv: Access-Request packet from host 172.16.0.2:1041, id=3D17, lengt=
h=3D177
> User-Name =3D "registro@172.16.0.1"
> Cisco-AVPair =3D "ssid=3DTESTEFR"
> NAS-IP-Address =3D 172.16.0.2
> Called-Station-Id =3D "004096544cbc"
> Calling-Station-Id =3D "000cf1516d62"
> NAS-Identifier =3D "AP350-544cbc"
> NAS-Port =3D 37
> Framed-MTU =3D 1400
> NAS-Port-Type =3D Wireless-802.11
> Service-Type =3D Login-User
> EAP-Message =3D 0x0239001801726567697374726f403137322e31362e302e31
> Message-Authenticator =3D 0x538b10a9e0546f1135890e951ae1dbec
> 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: '/var/log/raddb/radacct/172.16.0.2/auth-detail-20050510'
> rlm_detail: /var/log/raddb/radacct/%{Client-IP-Address}/auth-detail-%Y%m%=
d
> expands to /var/log/raddb/radacct/172.16.0.2/auth-detail-20050510
> modcall[authorize]: module "auth_log" returns ok for request 0
> rlm_realm: Looking up realm "172.16.0.1" for User-Name =3D
> "registro@172.16.0.1"
> rlm_realm: No such realm "172.16.0.1"
> modcall[authorize]: module "suffix" returns noop for request 0
> rlm_eap: EAP packet type response id 57 length 24
> rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> modcall[authorize]: module "eap" returns updated for request 0
> modcall[authorize]: module "files" returns notfound 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 17 to 172.16.0.2:1041
> EAP-Message =3D 0x013a00060d20
> Message-Authenticator =3D 0x00000000000000000000000000000000
> State =3D 0xfcc6ff6dedae304bd9ff13c405208a18
> 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 172.16.0.2:1042, id=3D18, lengt=
h=3D251
> User-Name =3D "registro@172.16.0.1"
> Cisco-AVPair =3D "ssid=3DTESTEFR"
> NAS-IP-Address =3D 172.16.0.2
> Called-Station-Id =3D "004096544cbc"
> Calling-Station-Id =3D "000cf1516d62"
> NAS-Identifier =3D "AP350-544cbc"
> NAS-Port =3D 37
> Framed-MTU =3D 1400
> State =3D 0xfcc6ff6dedae304bd9ff13c405208a18
> NAS-Port-Type =3D Wireless-802.11
> Service-Type =3D Login-User
> EAP-Message =3D 0x023a00500d800000004616030100410100003d03014280b8 =
9cc9d9798cde65e3502c124d8b9eba237c6d6314669dc1245f 76de1fbc00001600040005000=
a000900640062000300060013001200630100
> Message-Authenticator =3D 0xb3e8a06152224b73a731fad4b775c42a
> 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: '/var/log/raddb/radacct/172.16.0.2/auth-detail-20050510'
> rlm_detail: /var/log/raddb/radacct/%{Client-IP-Address}/auth-detail-%Y%m%=
d
> expands to /var/log/raddb/radacct/172.16.0.2/auth-detail-20050510
> modcall[authorize]: module "auth_log" returns ok for request 1
> rlm_realm: Looking up realm "172.16.0.1" for User-Name =3D
> "registro@172.16.0.1"
> rlm_realm: No such realm "172.16.0.1"
> modcall[authorize]: module "suffix" returns noop for request 1
> rlm_eap: EAP packet type response id 58 length 80
> rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> modcall[authorize]: module "eap" returns updated for request 1
> modcall[authorize]: module "files" returns notfound for request 1
> modcall: group authorize returns updated for request 1
> rad_check_password: Found Auth-Type EAP
> auth: type "EAP"
> Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 1
> rlm_eap: Request found, released from the list
> rlm_eap: EAP/tls
> rlm_eap: processing type tls
> rlm_eap_tls: Authenticate
> rlm_eap_tls: processing TLS
> rlm_eap_tls: Length Included
> eaptls_verify returned 11
> (other): before/accept initialization
> TLS_accept: before/accept initialization
> rlm_eap_tls: <<< TLS 1.0 Handshake [length 0041], ClientHello
> TLS_accept: SSLv3 read client hello A
> rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello
> TLS_accept: SSLv3 write server hello A
> rlm_eap_tls: >>> TLS 1.0 Handshake [length 03df], Certificate
> TLS_accept: SSLv3 write certificate A
> rlm_eap_tls: >>> TLS 1.0 Handshake [length 00ab], CertificateRequest
> TLS_accept: SSLv3 write certificate request A
> TLS_accept: SSLv3 flush data
> TLS_accept:error in SSLv3 read client certificate A
> In SSL Handshake Phase
> In SSL Accept mode
> eaptls_process returned 13
> modcall[authenticate]: module "eap" returns handled for request 1
> modcall: group authenticate returns handled for request 1
> Sending Access-Challenge of id 18 to 172.16.0.2:1042
> EAP-Message =3D 0x013b040a0dc0000004e3160301004a0200004603014280b8 =
c621ca6a04519aa72eee2578a420d5a1aaf6feb3bf61649e71 d85a70f7206865243d938b7e9=
7b31bfe83870d8a1eb76a45cd100f2f0b4e868329e7ae7d2c0 0040016030103df0b0003db00=
03d80003d5308203d13082033aa003020102020103300d0609 2a864886f70d0101040500308=
199310b3009060355040613024252311230100603550408130 953616f205061756c6f311230=
100603550407130953616f205061756c6f3114301206035504 0a130b526567697374726f204=
25231143012060355040b130b526567697374726f204252311 1300f06035504031308726567=
69737472
> EAP-Message =3D 0x6f3123302106092a864886f70d01090116146f7065726164 =
6f7240726567697374726f2e6272301e170d30353034323930 30313031345a170d303630343=
2393030313031345a308199310b30090603550406130242523 1123010060355040813095361=
6f205061756c6f311230100603550407130953616f20506175 6c6f31143012060355040a130=
b526567697374726f20425231143012060355040b130b52656 7697374726f2042523111300f=
06035504031308726567697374726f3123302106092a864886 f70d01090116146f706572616=
46f7240726567697374726f2e627230819f300d06092a86488 6f70d010101050003818d0030=
81890281
> EAP-Message =3D 0x81009a54a72fd8086941545f68d0545b7f6e302b8f64d049 =
5a9947fe3a5fc271051e97260bdd73098804f8213e37b69c29 a476b9ac7f24d5aebfc90d5a3=
c79a8a478ae7ef872d67e25dd886f1c11f1da066e94249720a df39c145fccbeda9d4989d076=
9977ee3130e4dac0fa067e25f59c228def7f2a12831f1eca77 5afcb3d4e4b10203010001a38=
201253082012130090603551d1304023000302c06096086480 186f842010d041f161d4f7065=
6e53534c2047656e6572617465642043657274696669636174 65301d0603551d0e04160414e=
df961cd84c7ad4c1432c98464ac3f30507c97393081c606035 51d230481be3081bb8014a870=
f94a04f0
> EAP-Message =3D 0x666076f58683622b6c9daaacef45a1819fa4819c30819931 =
0b300906035504061302425231123010060355040813095361 6f205061756c6f31123010060=
3550407130953616f205061756c6f31143012060355040a130 b526567697374726f20425231=
143012060355040b130b526567697374726f2042523111300f 0603550403130872656769737=
4726f3123302106092a864886f70d01090116146f706572616 46f7240726567697374726f2e=
6272820100300d06092a864886f70d01010405000381810019 57374aa695a34df252001b3d8=
55fd4598c9b5f61ed0245b46e1278b62ec3cf2af83c27379b3 3f004d8c76d70b569c88cfa75=
6bed8d49
> EAP-Message =3D 0xc28dc46044f0a5f044ec4d1542bfb6726057d1eb3e53
> Message-Authenticator =3D 0x00000000000000000000000000000000
> State =3D 0x2332e69b6edb0f5f4ab61cf0a5faddf8
> Finished request 1
> Going to the next request
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 172.16.0.2:1043, id=3D19, lengt=
h=3D177
> User-Name =3D "registro@172.16.0.1"
> Cisco-AVPair =3D "ssid=3DTESTEFR"
> NAS-IP-Address =3D 172.16.0.2
> Called-Station-Id =3D "004096544cbc"
> Calling-Station-Id =3D "000cf1516d62"
> NAS-Identifier =3D "AP350-544cbc"
> NAS-Port =3D 37
> Framed-MTU =3D 1400
> State =3D 0x2332e69b6edb0f5f4ab61cf0a5faddf8
> NAS-Port-Type =3D Wireless-802.11
> Service-Type =3D Login-User
> EAP-Message =3D 0x023b00060d00
> Message-Authenticator =3D 0x154b747b7e4373067b4fb062ca0a3ef0
> Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 2
> modcall[authorize]: module "preprocess" returns ok for request 2
> radius_xlat: '/var/log/raddb/radacct/172.16.0.2/auth-detail-20050510'
> rlm_detail: /var/log/raddb/radacct/%{Client-IP-Address}/auth-detail-%Y%m%=
d
> expands to /var/log/raddb/radacct/172.16.0.2/auth-detail-20050510
> modcall[authorize]: module "auth_log" returns ok for request 2
> rlm_realm: Looking up realm "172.16.0.1" for User-Name =3D
> "registro@172.16.0.1"
> rlm_realm: No such realm "172.16.0.1"
> modcall[authorize]: module "suffix" returns noop for request 2
> rlm_eap: EAP packet type response id 59 length 6
> rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> modcall[authorize]: module "eap" returns updated for request 2
> modcall[authorize]: module "files" returns notfound for request 2
> modcall: group authorize returns updated for request 2
> rad_check_password: Found Auth-Type EAP
> auth: type "EAP"
> Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 2
> rlm_eap: Request found, released from the list
> rlm_eap: EAP/tls
> rlm_eap: processing type tls
> rlm_eap_tls: Authenticate
> rlm_eap_tls: processing TLS
> rlm_eap_tls: Received EAP-TLS ACK message
> rlm_eap_tls: ack handshake fragment handler
> eaptls_verify returned 1
> eaptls_process returned 13
> modcall[authenticate]: module "eap" returns handled for request 2
> modcall: group authenticate returns handled for request 2
> Sending Access-Challenge of id 19 to 172.16.0.2:1043
> EAP-Message =3D 0x013c00ed0d80000004e38237eaf7880b068b460ddbd2261a =
dc8d59bd30cc239ded22283dd27df46b28f7f2428a3811d305 78d1a4950df1b58e712fab821=
6030100ab0d0000a3020102009e009c308199310b300906035 5040613024252311230100603=
550408130953616f205061756c6f3112301006035504071309 53616f205061756c6f3114301=
2060355040a130b526567697374726f2042523114301206035 5040b130b526567697374726f=
2042523111300f06035504031308726567697374726f312330 2106092a864886f70d0109011=
6146f70657261646f7240726567697374726f2e62720e00000 0
> Message-Authenticator =3D 0x00000000000000000000000000000000
> State =3D 0x96120aa4b02b8c5ff04209db298efd1a
> Finished request 2
> Going to the next request
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 172.16.0.2:1044, id=3D20, lengt=
h=3D1498
> User-Name =3D "registro@172.16.0.1"
> Cisco-AVPair =3D "ssid=3DTESTEFR"
> NAS-IP-Address =3D 172.16.0.2
> Called-Station-Id =3D "004096544cbc"
> Calling-Station-Id =3D "000cf1516d62"
> NAS-Identifier =3D "AP350-544cbc"
> NAS-Port =3D 37
> Framed-MTU =3D 1400
> State =3D 0x96120aa4b02b8c5ff04209db298efd1a
> NAS-Port-Type =3D Wireless-802.11
> Service-Type =3D Login-User
> EAP-Message =3D 0x023c05250d800000051b16030104eb0b0003db0003d80003 =
d5308203d13082033aa003020102020104300d06092a864886 f70d0101040500308199310b3=
009060355040613024252311230100603550408130953616f2 05061756c6f31123010060355=
0407130953616f205061756c6f31143012060355040a130b52 6567697374726f20425231143=
012060355040b130b526567697374726f2042523111300f060 3550403130872656769737472=
6f3123302106092a864886f70d01090116146f70657261646f 7240726567697374726f2e627=
2301e170d3035303432393030353534395a170d30363034323 93030353534395a308199310b=
30090603
> EAP-Message =3D 0x55040613024252311230100603550408130953616f205061 =
756c6f311230100603550407130953616f205061756c6f3114 3012060355040a130b5265676=
97374726f20425231143012060355040b130b5265676973747 26f2042523111300f06035504=
031308726567697374726f3123302106092a864886f70d0109 0116146f70657261646f72407=
26567697374726f2e627230819f300d06092a864886f70d010 101050003818d003081890281=
8100d7899bb64777601a498fccaffc163ba9fcc1e8a3fdf2db 09f28deea572332998b5e2c92=
c261871567252e54037b812388c83b313a7acec320ece838af 61e3776bc2942466ea9a85377=
ebf17194
> EAP-Message =3D 0x16bdbe8e3dbedee663c0ff30a0a5402ae9b2aa4eead19e0a =
3808705eeb39ee115b9a0d6601461dbb4f25f0c85f583f9d1b 2dbd0203010001a3820125308=
2012130090603551d1304023000302c06096086480186f8420 10d041f161d4f70656e53534c=
2047656e657261746564204365727469666963617465301d06 03551d0e041604141219cdbe7=
f71815d1f9ee897caf9aead2e96cf663081c60603551d23048 1be3081bb8014a870f94a04f0=
666076f58683622b6c9daaacef45a1819fa4819c308199310b 3009060355040613024252311=
230100603550408130953616f205061756c6f3112301006035 50407130953616f205061756c=
6f311430
> EAP-Message =3D 0x12060355040a130b526567697374726f2042523114301206 =
0355040b130b526567697374726f2042523111300f06035504 031308726567697374726f312=
3302106092a864886f70d01090116146f70657261646f72407 26567697374726f2e62728201=
00300d06092a864886f70d0101040500038181006d739a758b 706d31eadd83e9d5c79861c6a=
9cc3a7898ff4f77b2fa82fb5144d5ab8d936b7072665562ca5 b4293a99fd20319be28e9be46=
d4abfe84eb4689fbcdf73509ab8dc5a91557557b8b35e60888 fadb6f725aa19750fd8003f49=
797d14a14f8790221dcd36d462bcb12e75ea39bb51cefaad34 f33589e7c7b6f3cc9c0761000=
00820080
> EAP-Message =3D 0x7eb4547b1f3db566c130ea5724565b401a2077965c8c73f9 =
21741143b940608485efd0c97d347813f79d06e93102fb8360 724bc712437ddea30493cf391=
9a54d4ae180dd30d73787cb93123ed2049e9dde0e32c9b13ea 08267cc94481bacc4d15628c4=
62b560f00be7c57d8d34abd430d8d6885019a75cbd5eeb4ac8 92e0d87a0f0000820080704fc=
d1a3240f1cd7fd16197dfc98bfcb49131c6371a0b8af003ca6 5b5535fd46ebbaa93612e4547=
0432d09f86ccd3345d24bae00fdf136a0a06a40acc5f45d827 19d62dcc7066bb5893d7ebc69=
7d63bd30b7e60847d77e389ba211dc852f46403f06dec333ac e9f34e748a859e3bdc5d1451e=
1bdb263a
> EAP-Message =3D 0x5dff9248c1d03d76c0140301000101160301002002edbc2f =
77f3aa0710a7da4ca5c84c7d3e7631dea7615960728e1bc1d7 27e576
> Message-Authenticator =3D 0x6d83b27900e6fc2c9fd89d4b269ded37
> Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 3
> modcall[authorize]: module "preprocess" returns ok for request 3
> radius_xlat: '/var/log/raddb/radacct/172.16.0.2/auth-detail-20050510'
> rlm_detail: /var/log/raddb/radacct/%{Client-IP-Address}/auth-detail-%Y%m%=
d
> expands to /var/log/raddb/radacct/172.16.0.2/auth-detail-20050510
> modcall[authorize]: module "auth_log" returns ok for request 3
> rlm_realm: Looking up realm "172.16.0.1" for User-Name =3D
> "registro@172.16.0.1"
> rlm_realm: No such realm "172.16.0.1"
> modcall[authorize]: module "suffix" returns noop for request 3
> rlm_eap: EAP packet type response id 60 length 253
> rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> modcall[authorize]: module "eap" returns updated for request 3
> modcall[authorize]: module "files" returns notfound for request 3
> modcall: group authorize returns updated for request 3
> rad_check_password: Found Auth-Type EAP
> auth: type "EAP"
> Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 3
> rlm_eap: Request found, released from the list
> rlm_eap: EAP/tls
> rlm_eap: processing type tls
> rlm_eap_tls: Authenticate
> rlm_eap_tls: processing TLS
> rlm_eap_tls: Length Included
> eaptls_verify returned 11
> rlm_eap_tls: <<< TLS 1.0 Handshake [length 03df], Certificate
> chain-depth=3D1,
> error=3D0
> --> User-Name =3D registro@172.16.0.1
> --> BUF-Name =3D registro
> --> subject =3D /C=3DBR/ST=3DSao Paulo/L=3DSao Paulo/O=3DRegistro BR/OU=
=3DRegistro
> BR/CN=3Dregistro/emailAddress=3Doperador@registro.br
> --> issuer =3D /C=3DBR/ST=3DSao Paulo/L=3DSao Paulo/O=3DRegistro BR/OU=
=3DRegistro
> BR/CN=3Dregistro/emailAddress=3Doperador@registro.br
> --> verify return:1
> chain-depth=3D0,
> error=3D0
> --> User-Name =3D registro@172.16.0.1
> --> BUF-Name =3D registro
> --> subject =3D /C=3DBR/ST=3DSao Paulo/L=3DSao Paulo/O=3DRegistro BR/OU=
=3DRegistro
> BR/CN=3Dregistro/emailAddress=3Doperador@registro.br
> --> issuer =3D /C=3DBR/ST=3DSao Paulo/L=3DSao Paulo/O=3DRegistro BR/OU=
=3DRegistro
> BR/CN=3Dregistro/emailAddress=3Doperador@registro.br
> --> verify return:1
> TLS_accept: SSLv3 read client certificate A
> rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
> TLS_accept: SSLv3 read client key exchange A
> rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], CertificateVerify
> TLS_accept: SSLv3 read certificate verify A
> rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
> rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
> TLS_accept: SSLv3 read finished A
> rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
> TLS_accept: SSLv3 write change cipher spec A
> rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
> TLS_accept: SSLv3 write finished A
> TLS_accept: SSLv3 flush data
> (other): SSL negotiation finished successfully
> SSL Connection Established
> eaptls_process returned 13
> modcall[authenticate]: module "eap" returns handled for request 3
> modcall: group authenticate returns handled for request 3
> Sending Access-Challenge of id 20 to 172.16.0.2:1044
> EAP-Message =3D 0x013d00350d800000002b1403010001011603010020b354d5 =
618ce3410f4fcd0213badac95e81c7d0c5596e031d3ffe7245 1ee4a904
> Message-Authenticator =3D 0x00000000000000000000000000000000
> State =3D 0x393ab2c490d15f1d67d77e819d83e363
> Finished request 3
> Going to the next request
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 172.16.0.2:1045, id=3D21, lengt=
h=3D204
> User-Name =3D "registro@172.16.0.1"
> Cisco-AVPair =3D "ssid=3DTESTEFR"
> NAS-IP-Address =3D 172.16.0.2
> Called-Station-Id =3D "004096544cbc"
> Calling-Station-Id =3D "000cf1516d62"
> NAS-Identifier =3D "AP350-544cbc"
> NAS-Port =3D 37
> Framed-MTU =3D 1400
> State =3D 0x393ab2c490d15f1d67d77e819d83e363
> NAS-Port-Type =3D Wireless-802.11
> Service-Type =3D Login-User
> EAP-Message =3D 0x023d00210d8000000017150301001222243cc44b57c1008a =
ddca5f7b2b8106b199
> Message-Authenticator =3D 0x50bb07214456ae90679e4c6b66c52d63
> Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 4
> modcall[authorize]: module "preprocess" returns ok for request 4
> radius_xlat: '/var/log/raddb/radacct/172.16.0.2/auth-detail-20050510'
> rlm_detail: /var/log/raddb/radacct/%{Client-IP-Address}/auth-detail-%Y%m%=
d
> expands to /var/log/raddb/radacct/172.16.0.2/auth-detail-20050510
> modcall[authorize]: module "auth_log" returns ok for request 4
> rlm_realm: Looking up realm "172.16.0.1" for User-Name =3D
> "registro@172.16.0.1"
> rlm_realm: No such realm "172.16.0.1"
> modcall[authorize]: module "suffix" returns noop for request 4
> rlm_eap: EAP packet type response id 61 length 33
> rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> modcall[authorize]: module "eap" returns updated for request 4
> modcall[authorize]: module "files" returns notfound for request 4
> modcall: group authorize returns updated for request 4
> rad_check_password: Found Auth-Type EAP
> auth: type "EAP"
> Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 4
> rlm_eap: Request found, released from the list
> rlm_eap: EAP/tls
> rlm_eap: processing type tls
> rlm_eap_tls: Authenticate
> rlm_eap_tls: processing TLS
> rlm_eap_tls: Length Included
> eaptls_verify returned 11
> eaptls_process returned 7
> rlm_eap_tls: Received unexpected tunneled data after successful handshak=
e.
> rlm_eap: Handler failed in EAP/tls
> rlm_eap: Failed in EAP select
> modcall[authenticate]: module "eap" returns invalid for request 4
> modcall: group authenticate returns invalid for request 4
> auth: Failed to validate the user.
> Delaying request 4 for 1 seconds
> Finished request 4
> Going to the next request
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 172.16.0.2:1045, id=3D21, lengt=
h=3D204
> Sending Access-Reject of id 21 to 172.16.0.2:1045
> EAP-Message =3D 0x043d0004
> Message-Authenticator =3D 0x00000000000000000000000000000000
> --- Walking the entire request list ---
> Waking up in 1 seconds...
> --- Walking the entire request list ---
> Cleaning up request 0 ID 17 with timestamp 4280b8c6
> Cleaning up request 1 ID 18 with timestamp 4280b8c6
> Cleaning up request 2 ID 19 with timestamp 4280b8c6
> Cleaning up request 3 ID 20 with timestamp 4280b8c6
> Cleaning up request 4 ID 21 with timestamp 4280b8c6
> Nothing to do. Sleeping until we see a request.
> rad_recv: Access-Request packet from host 172.16.0.2:1046, id=3D22, lengt=
h=3D155
> User-Name =3D "registro"
> Cisco-AVPair =3D "ssid=3DTESTEFR"
> NAS-IP-Address =3D 172.16.0.2
> Called-Station-Id =3D "004096544cbc"
> Calling-Station-Id =3D "000cf1516d62"
> NAS-Identifier =3D "AP350-544cbc"
> NAS-Port =3D 37
> Framed-MTU =3D 1400
> NAS-Port-Type =3D Wireless-802.11
> Service-Type =3D Login-User
> EAP-Message =3D 0x023f000d01726567697374726f
> Message-Authenticator =3D 0x33496ff71adff3407fb7f01359fac762
> Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 5
> modcall[authorize]: module "preprocess" returns ok for request 5
> radius_xlat: '/var/log/raddb/radacct/172.16.0.2/auth-detail-20050510'
> rlm_detail: /var/log/raddb/radacct/%{Client-IP-Address}/auth-detail-%Y%m%=
d
> expands to /var/log/raddb/radacct/172.16.0.2/auth-detail-20050510
> modcall[authorize]: module "auth_log" returns ok for request 5
> rlm_realm: No '@' in User-Name =3D "registro", looking up realm NULL
> rlm_realm: No such realm "NULL"
> modcall[authorize]: module "suffix" returns noop for request 5
> rlm_eap: EAP packet type response id 63 length 13
> rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> modcall[authorize]: module "eap" returns updated for request 5
> users: Matched entry registro at line 1
> modcall[authorize]: module "files" returns ok for request 5
> modcall: group authorize returns updated for request 5
> rad_check_password: Found Auth-Type EAP
> auth: type "EAP"
> Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 5
> 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 5
> modcall: group authenticate returns handled for request 5
> Sending Access-Challenge of id 22 to 172.16.0.2:1046
> EAP-Message =3D 0x014000060d20
> Message-Authenticator =3D 0x00000000000000000000000000000000
> State =3D 0x890737d0208d24d62ad5af7b7c0f9994
> Finished request 5
> Going to the next request
> --- Walking the entire request list ---
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 172.16.0.2:1047, id=3D23, lengt=
h=3D240
> User-Name =3D "registro"
> Cisco-AVPair =3D "ssid=3DTESTEFR"
> NAS-IP-Address =3D 172.16.0.2
> Called-Station-Id =3D "004096544cbc"
> Calling-Station-Id =3D "000cf1516d62"
> NAS-Identifier =3D "AP350-544cbc"
> NAS-Port =3D 37
> Framed-MTU =3D 1400
> State =3D 0x890737d0208d24d62ad5af7b7c0f9994
> NAS-Port-Type =3D Wireless-802.11
> Service-Type =3D Login-User
> EAP-Message =3D 0x024000500d800000004616030100410100003d03014280b8 =
a9112eb7a7cfafc5ac54b984db5859e80a6bd7f15973e0703f 9078270c00001600040005000=
a000900640062000300060013001200630100
> Message-Authenticator =3D 0x0538d6266a2616a1335b779fa8582719
> Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 6
> modcall[authorize]: module "preprocess" returns ok for request 6
> radius_xlat: '/var/log/raddb/radacct/172.16.0.2/auth-detail-20050510'
> rlm_detail: /var/log/raddb/radacct/%{Client-IP-Address}/auth-detail-%Y%m%=
d
> expands to /var/log/raddb/radacct/172.16.0.2/auth-detail-20050510
> modcall[authorize]: module "auth_log" returns ok for request 6
> rlm_realm: No '@' in User-Name =3D "registro", looking up realm NULL
> rlm_realm: No such realm "NULL"
> modcall[authorize]: module "suffix" returns noop for request 6
> rlm_eap: EAP packet type response id 64 length 80
> rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> modcall[authorize]: module "eap" returns updated for request 6
> users: Matched entry registro at line 1
> modcall[authorize]: module "files" returns ok for request 6
> modcall: group authorize returns updated for request 6
> rad_check_password: Found Auth-Type EAP
> auth: type "EAP"
> Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 6
> rlm_eap: Request found, released from the list
> rlm_eap: EAP/tls
> rlm_eap: processing type tls
> rlm_eap_tls: Authenticate
> rlm_eap_tls: processing TLS
> rlm_eap_tls: Length Included
> eaptls_verify returned 11
> (other): before/accept initialization
> TLS_accept: before/accept initialization
> rlm_eap_tls: <<< TLS 1.0 Handshake [length 0041], ClientHello
> TLS_accept: SSLv3 read client hello A
> rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello
> TLS_accept: SSLv3 write server hello A
> rlm_eap_tls: >>> TLS 1.0 Handshake [length 03df], Certificate
> TLS_accept: SSLv3 write certificate A
> rlm_eap_tls: >>> TLS 1.0 Handshake [length 00ab], CertificateRequest
> TLS_accept: SSLv3 write certificate request A
> TLS_accept: SSLv3 flush data
> TLS_accept:error in SSLv3 read client certificate A
> In SSL Handshake Phase
> In SSL Accept mode
> eaptls_process returned 13
> modcall[authenticate]: module "eap" returns handled for request 6
> modcall: group authenticate returns handled for request 6
> Sending Access-Challenge of id 23 to 172.16.0.2:1047
> EAP-Message =3D 0x0141040a0dc0000004e3160301004a0200004603014280b8 =
d3477c612cd4cc35cc446e837fb968f7bcf1381ca950a0da30 73d48122203b6a6e5cbd48045=
99a20248f22a58d730d42aefddf544cecaf4c4c40dbf9f7ee0 0040016030103df0b0003db00=
03d80003d5308203d13082033aa003020102020103300d0609 2a864886f70d0101040500308=
199310b3009060355040613024252311230100603550408130 953616f205061756c6f311230=
100603550407130953616f205061756c6f3114301206035504 0a130b526567697374726f204=
25231143012060355040b130b526567697374726f204252311 1300f06035504031308726567=
69737472
> EAP-Message =3D 0x6f3123302106092a864886f70d01090116146f7065726164 =
6f7240726567697374726f2e6272301e170d30353034323930 30313031345a170d303630343=
2393030313031345a308199310b30090603550406130242523 1123010060355040813095361=
6f205061756c6f311230100603550407130953616f20506175 6c6f31143012060355040a130=
b526567697374726f20425231143012060355040b130b52656 7697374726f2042523111300f=
06035504031308726567697374726f3123302106092a864886 f70d01090116146f706572616=
46f7240726567697374726f2e627230819f300d06092a86488 6f70d010101050003818d0030=
81890281
> EAP-Message =3D 0x81009a54a72fd8086941545f68d0545b7f6e302b8f64d049 =
5a9947fe3a5fc271051e97260bdd73098804f8213e37b69c29 a476b9ac7f24d5aebfc90d5a3=
c79a8a478ae7ef872d67e25dd886f1c11f1da066e94249720a df39c145fccbeda9d4989d076=
9977ee3130e4dac0fa067e25f59c228def7f2a12831f1eca77 5afcb3d4e4b10203010001a38=
201253082012130090603551d1304023000302c06096086480 186f842010d041f161d4f7065=
6e53534c2047656e6572617465642043657274696669636174 65301d0603551d0e04160414e=
df961cd84c7ad4c1432c98464ac3f30507c97393081c606035 51d230481be3081bb8014a870=
f94a04f0
> EAP-Message =3D 0x666076f58683622b6c9daaacef45a1819fa4819c30819931 =
0b300906035504061302425231123010060355040813095361 6f205061756c6f31123010060=
3550407130953616f205061756c6f31143012060355040a130 b526567697374726f20425231=
143012060355040b130b526567697374726f2042523111300f 0603550403130872656769737=
4726f3123302106092a864886f70d01090116146f706572616 46f7240726567697374726f2e=
6272820100300d06092a864886f70d01010405000381810019 57374aa695a34df252001b3d8=
55fd4598c9b5f61ed0245b46e1278b62ec3cf2af83c27379b3 3f004d8c76d70b569c88cfa75=
6bed8d49
> EAP-Message =3D 0xc28dc46044f0a5f044ec4d1542bfb6726057d1eb3e53
> Message-Authenticator =3D 0x00000000000000000000000000000000
> State =3D 0xa0a6379bec566ff9c679f2ad1d306e52
> Finished request 6
> Going to the next request
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 172.16.0.2:1048, id=3D24, lengt=
h=3D166
> User-Name =3D "registro"
> Cisco-AVPair =3D "ssid=3DTESTEFR"
> NAS-IP-Address =3D 172.16.0.2
> Called-Station-Id =3D "004096544cbc"
> Calling-Station-Id =3D "000cf1516d62"
> NAS-Identifier =3D "AP350-544cbc"
> NAS-Port =3D 37
> Framed-MTU =3D 1400
> State =3D 0xa0a6379bec566ff9c679f2ad1d306e52
> NAS-Port-Type =3D Wireless-802.11
> Service-Type =3D Login-User
> EAP-Message =3D 0x024100060d00
> Message-Authenticator =3D 0xcfe23c642748fe56654a78e3a2c71e45
> Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 7
> modcall[authorize]: module "preprocess" returns ok for request 7
> radius_xlat: '/var/log/raddb/radacct/172.16.0.2/auth-detail-20050510'
> rlm_detail: /var/log/raddb/radacct/%{Client-IP-Address}/auth-detail-%Y%m%=
d
> expands to /var/log/raddb/radacct/172.16.0.2/auth-detail-20050510
> modcall[authorize]: module "auth_log" returns ok for request 7
> rlm_realm: No '@' in User-Name =3D "registro", looking up realm NULL
> rlm_realm: No such realm "NULL"
> modcall[authorize]: module "suffix" returns noop for request 7
> rlm_eap: EAP packet type response id 65 length 6
> rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> modcall[authorize]: module "eap" returns updated for request 7
> users: Matched entry registro at line 1
> modcall[authorize]: module "files" returns ok for request 7
> modcall: group authorize returns updated for request 7
> rad_check_password: Found Auth-Type EAP
> auth: type "EAP"
> Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 7
> rlm_eap: Request found, released from the list
> rlm_eap: EAP/tls
> rlm_eap: processing type tls
> rlm_eap_tls: Authenticate
> rlm_eap_tls: processing TLS
> rlm_eap_tls: Received EAP-TLS ACK message
> rlm_eap_tls: ack handshake fragment handler
> eaptls_verify returned 1
> eaptls_process returned 13
> modcall[authenticate]: module "eap" returns handled for request 7
> modcall: group authenticate returns handled for request 7
> Sending Access-Challenge of id 24 to 172.16.0.2:1048
> EAP-Message =3D 0x014200ed0d80000004e38237eaf7880b068b460ddbd2261a =
dc8d59bd30cc239ded22283dd27df46b28f7f2428a3811d305 78d1a4950df1b58e712fab821=
6030100ab0d0000a3020102009e009c308199310b300906035 5040613024252311230100603=
550408130953616f205061756c6f3112301006035504071309 53616f205061756c6f3114301=
2060355040a130b526567697374726f2042523114301206035 5040b130b526567697374726f=
2042523111300f06035504031308726567697374726f312330 2106092a864886f70d0109011=
6146f70657261646f7240726567697374726f2e62720e00000 0
> Message-Authenticator =3D 0x00000000000000000000000000000000
> State =3D 0x463c231cd6051bb8535cb2281847b149
> Finished request 7
> Going to the next request
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 172.16.0.2:1049, id=3D25, lengt=
h=3D1487
> User-Name =3D "registro"
> Cisco-AVPair =3D "ssid=3DTESTEFR"
> NAS-IP-Address =3D 172.16.0.2
> Called-Station-Id =3D "004096544cbc"
> Calling-Station-Id =3D "000cf1516d62"
> NAS-Identifier =3D "AP350-544cbc"
> NAS-Port =3D 37
> Framed-MTU =3D 1400
> State =3D 0x463c231cd6051bb8535cb2281847b149
> NAS-Port-Type =3D Wireless-802.11
> Service-Type =3D Login-User
> EAP-Message =3D 0x024205250d800000051b16030104eb0b0003db0003d80003 =
d5308203d13082033aa003020102020104300d06092a864886 f70d0101040500308199310b3=
009060355040613024252311230100603550408130953616f2 05061756c6f31123010060355=
0407130953616f205061756c6f31143012060355040a130b52 6567697374726f20425231143=
012060355040b130b526567697374726f2042523111300f060 3550403130872656769737472=
6f3123302106092a864886f70d01090116146f70657261646f 7240726567697374726f2e627=
2301e170d3035303432393030353534395a170d30363034323 93030353534395a308199310b=
30090603
> EAP-Message =3D 0x55040613024252311230100603550408130953616f205061 =
756c6f311230100603550407130953616f205061756c6f3114 3012060355040a130b5265676=
97374726f20425231143012060355040b130b5265676973747 26f2042523111300f06035504=
031308726567697374726f3123302106092a864886f70d0109 0116146f70657261646f72407=
26567697374726f2e627230819f300d06092a864886f70d010 101050003818d003081890281=
8100d7899bb64777601a498fccaffc163ba9fcc1e8a3fdf2db 09f28deea572332998b5e2c92=
c261871567252e54037b812388c83b313a7acec320ece838af 61e3776bc2942466ea9a85377=
ebf17194
> EAP-Message =3D 0x16bdbe8e3dbedee663c0ff30a0a5402ae9b2aa4eead19e0a =
3808705eeb39ee115b9a0d6601461dbb4f25f0c85f583f9d1b 2dbd0203010001a3820125308=
2012130090603551d1304023000302c06096086480186f8420 10d041f161d4f70656e53534c=
2047656e657261746564204365727469666963617465301d06 03551d0e041604141219cdbe7=
f71815d1f9ee897caf9aead2e96cf663081c60603551d23048 1be3081bb8014a870f94a04f0=
666076f58683622b6c9daaacef45a1819fa4819c308199310b 3009060355040613024252311=
230100603550408130953616f205061756c6f3112301006035 50407130953616f205061756c=
6f311430
> EAP-Message =3D 0x12060355040a130b526567697374726f2042523114301206 =
0355040b130b526567697374726f2042523111300f06035504 031308726567697374726f312=
3302106092a864886f70d01090116146f70657261646f72407 26567697374726f2e62728201=
00300d06092a864886f70d0101040500038181006d739a758b 706d31eadd83e9d5c79861c6a=
9cc3a7898ff4f77b2fa82fb5144d5ab8d936b7072665562ca5 b4293a99fd20319be28e9be46=
d4abfe84eb4689fbcdf73509ab8dc5a91557557b8b35e60888 fadb6f725aa19750fd8003f49=
797d14a14f8790221dcd36d462bcb12e75ea39bb51cefaad34 f33589e7c7b6f3cc9c0761000=
00820080
> EAP-Message =3D 0x76908ffdf24ea47c10b999f89173ffbfc5b01a1470c57fa1 =
567d647f673f3fc17839cae77e6dd0fc550716734fda0bd993 9a9d7e90ed4097da39636ec19=
4e7bea2e9004c53933e7303d62c670dc6cf698e72c33c5ed34 574640a7176a43ac37597981f=
018fd3aa68a49d14d10095a4de68296d6eb691bcb0f34c2e09 e9ffa2660f00008200808a1a9=
b2df9b3f09d36ceef61fca8b04d203aaa111947b5dd4770ec3 33a6c34fa3f0a6a46236796c9=
4252475076716a875f67399b7a06ebea6cf3a923ced79e777f 06ea1bfb336fb7eca4ad4f13c=
aa6dbc5e918cf5a3394a476212398c209c6aaea41165f9f3b4 79df05bbd96a26eb5f4ffbc60=
5226fdcd
> EAP-Message =3D 0xb5475c666c1e9781611403010001011603010020c3032d6f =
b19765aa65464328a2ad297a501da02d953af9774cd3b51d12 e6cfb8
> Message-Authenticator =3D 0x668f9fe4ca905539420714df652dbd1e
> Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 8
> modcall[authorize]: module "preprocess" returns ok for request 8
> radius_xlat: '/var/log/raddb/radacct/172.16.0.2/auth-detail-20050510'
> rlm_detail: /var/log/raddb/radacct/%{Client-IP-Address}/auth-detail-%Y%m%=
d
> expands to /var/log/raddb/radacct/172.16.0.2/auth-detail-20050510
> modcall[authorize]: module "auth_log" returns ok for request 8
> rlm_realm: No '@' in User-Name =3D "registro", looking up realm NULL
> rlm_realm: No such realm "NULL"
> modcall[authorize]: module "suffix" returns noop for request 8
> rlm_eap: EAP packet type response id 66 length 253
> rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> modcall[authorize]: module "eap" returns updated for request 8
> users: Matched entry registro at line 1
> modcall[authorize]: module "files" returns ok for request 8
> modcall: group authorize returns updated for request 8
> rad_check_password: Found Auth-Type EAP
> auth: type "EAP"
> Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 8
> rlm_eap: Request found, released from the list
> rlm_eap: EAP/tls
> rlm_eap: processing type tls
> rlm_eap_tls: Authenticate
> rlm_eap_tls: processing TLS
> rlm_eap_tls: Length Included
> eaptls_verify returned 11
> rlm_eap_tls: <<< TLS 1.0 Handshake [length 03df], Certificate
> chain-depth=3D1,
> error=3D0
> --> User-Name =3D registro
> --> BUF-Name =3D registro
> --> subject =3D /C=3DBR/ST=3DSao Paulo/L=3DSao Paulo/O=3DRegistro BR/OU=
=3DRegistro
> BR/CN=3Dregistro/emailAddress=3Doperador@registro.br
> --> issuer =3D /C=3DBR/ST=3DSao Paulo/L=3DSao Paulo/O=3DRegistro BR/OU=
=3DRegistro
> BR/CN=3Dregistro/emailAddress=3Doperador@registro.br
> --> verify return:1
> chain-depth=3D0,
> error=3D0
> --> User-Name =3D registro
> --> BUF-Name =3D registro
> --> subject =3D /C=3DBR/ST=3DSao Paulo/L=3DSao Paulo/O=3DRegistro BR/OU=
=3DRegistro
> BR/CN=3Dregistro/emailAddress=3Doperador@registro.br
> --> issuer =3D /C=3DBR/ST=3DSao Paulo/L=3DSao Paulo/O=3DRegistro BR/OU=
=3DRegistro
> BR/CN=3Dregistro/emailAddress=3Doperador@registro.br
> --> verify return:1
> TLS_accept: SSLv3 read client certificate A
> rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
> TLS_accept: SSLv3 read client key exchange A
> rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], CertificateVerify
> TLS_accept: SSLv3 read certificate verify A
> rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
> rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
> TLS_accept: SSLv3 read finished A
> rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
> TLS_accept: SSLv3 write change cipher spec A
> rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
> TLS_accept: SSLv3 write finished A
> TLS_accept: SSLv3 flush data
> (other): SSL negotiation finished successfully
> SSL Connection Established
> eaptls_process returned 13
> modcall[authenticate]: module "eap" returns handled for request 8
> modcall: group authenticate returns handled for request 8
> Sending Access-Challenge of id 25 to 172.16.0.2:1049
> EAP-Message =3D 0x014300350d800000002b140301000101160301002000b6cd =
81dd79f8755113a035e5b9d7775f7977f8687feacecd9ad7ac a9c5ef29
> Message-Authenticator =3D 0x00000000000000000000000000000000
> State =3D 0x0ed8f8eabdcd074e8db993175f260f11
> Finished request 8
> Going to the next request
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 172.16.0.2:1050, id=3D26, lengt=
h=3D193
> User-Name =3D "registro"
> Cisco-AVPair =3D "ssid=3DTESTEFR"
> NAS-IP-Address =3D 172.16.0.2
> Called-Station-Id =3D "004096544cbc"
> Calling-Station-Id =3D "000cf1516d62"
> NAS-Identifier =3D "AP350-544cbc"
> NAS-Port =3D 37
> Framed-MTU =3D 1400
> State =3D 0x0ed8f8eabdcd074e8db993175f260f11
> NAS-Port-Type =3D Wireless-802.11
> Service-Type =3D Login-User
> EAP-Message =3D 0x024300210d800000001715030100124ff1ff7a39c6fb0865 =
bbd0b7e4280bc2fdda
> Message-Authenticator =3D 0xeab66a38edd56eb442480d656b86bff9
> Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 9
> modcall[authorize]: module "preprocess" returns ok for request 9
> radius_xlat: '/var/log/raddb/radacct/172.16.0.2/auth-detail-20050510'
> rlm_detail: /var/log/raddb/radacct/%{Client-IP-Address}/auth-detail-%Y%m%=
d
> expands to /var/log/raddb/radacct/172.16.0.2/auth-detail-20050510
> modcall[authorize]: module "auth_log" returns ok for request 9
> rlm_realm: No '@' in User-Name =3D "registro", looking up realm NULL
> rlm_realm: No such realm "NULL"
> modcall[authorize]: module "suffix" returns noop for request 9
> rlm_eap: EAP packet type response id 67 length 33
> rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> modcall[authorize]: module "eap" returns updated for request 9
> users: Matched entry registro at line 1
> modcall[authorize]: module "files" returns ok for request 9
> modcall: group authorize returns updated for request 9
> rad_check_password: Found Auth-Type EAP
> auth: type "EAP"
> Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 9
> rlm_eap: Request found, released from the list
> rlm_eap: EAP/tls
> rlm_eap: processing type tls
> rlm_eap_tls: Authenticate
> rlm_eap_tls: processing TLS
> rlm_eap_tls: Length Included
> eaptls_verify returned 11
> eaptls_process returned 7
> rlm_eap_tls: Received unexpected tunneled data after successful handshak=
e.
> rlm_eap: Handler failed in EAP/tls
> rlm_eap: Failed in EAP select
> modcall[authenticate]: module "eap" returns invalid for request 9
> modcall: group authenticate returns invalid for request 9
> auth: Failed to validate the user.
> Delaying request 9 for 1 seconds
> Finished request 9
> Going to the next request
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 172.16.0.2:1050, id=3D26, lengt=
h=3D193
> Sending Access-Reject of id 26 to 172.16.0.2:1050
> EAP-Message =3D 0x04430004
> Message-Authenticator =3D 0x00000000000000000000000000000000
> --- Walking the entire request list ---
> Waking up in 1 seconds...
> --- Walking the entire request list ---
> Cleaning up request 5 ID 22 with timestamp 4280b8d3
> Cleaning up request 6 ID 23 with timestamp 4280b8d3
> Cleaning up request 7 ID 24 with timestamp 4280b8d3
> Cleaning up request 8 ID 25 with timestamp 4280b8d3
> Cleaning up request 9 ID 26 with timestamp 4280b8d3
> Nothing to do. Sleeping until we see a request.
>=20
> ############## ##################
>=20
> 2005/5/10, Vladimir Vuksan <vlists@veus.hr>:
> > Galvao Rezende wrote:
> >
> > >problems with 802.1x - EAP-TLS
> > >
> > >I'm having trouble at authentication using radius, openssl and
> > >EAP-TLS, using AP CISCO 350 Series. Look at radius output.
> > >
> > >
> > It doesn't appear that is the whole output. There is no Reject message
> > that I can see.
> >
> > Vladimir
> >
> > -
> > List info/subscribe/unsubscribe? See http://www.freeradius.org/list/use=
rs.html
> >
>

-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html