Hi everybody , i'm in a serious trouble :-( Can't get accept with eap/tls. My setup is: freeradius snapshot 20040405 openssl latest snapshot 0.9.7 cisco ap 350 series supplicant: win xp sp1,pcmcia card cisco aironet 350
I followed http://www.impossiblereflex.com/8021x/eap-tls-HOWTO.htm and http://www.dslreports.com/forum/remark,9286052. I get this "eaptls_process returned 13" but SSL negotiation finished successfully. I also tried to limit fragment_size in eap.conf and NASTYPE in clients. conf unsuccessfully. It's very important to me to work it out. Thanks a lot! ------------------------------------------------------------------- Listening on IP address *, ports 1812/udp and 1813/udp, with proxy on 1814/udp. Ready to process requests. rad_recv: Access-Request packet from host 160.78.27.14:1631, id=95, length=172 Thread 1 got semaphore Thread 1 handling request 0, (1 handled so far) --- Walking the entire request list --- Waking up in 5 seconds... User-Name = "Rinaldo Bergamini" Cisco-AVPair = "ssid=qosnet" NAS-IP-Address = 160.78.27.14 Called-Station-Id = "004096586593" Calling-Station-Id = "000bbe371047" NAS-Identifier = "AP350-586593" Threads: total/active/spare threads = 5/1/4 NAS-Port = 38 Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Service-Type = Login-User EAP-Message = 0x020b00160152696e616c646f2042657267616d696e69 Message-Authenticator = 0x145cf7a6e04df58ac9728d3bc182dc64 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 0 modcall[authorize]: module "preprocess" returns ok for request 0 rlm_realm: No '@' in User-Name = "Rinaldo Bergamini", 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 11 length 22 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 0 users: Matched Rinaldo Bergamini at 97 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 95 to 160.78.27.14:1631 EAP-Message = 0x010c00060d20 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x99f405885345311f5f4500694fda302b Finished request 0 Going to the next request Thread 1 waiting to be assigned a request rad_recv: Access-Request packet from host 160.78.27.14:1632, id=96, length=248 Thread 2 got semaphore Thread 2 handling request 1, (1 handled so far) User-Name = "Rinaldo Bergamini" Waking up in 5 seconds... Cisco-AVPair = "ssid=qosnet" NAS-IP-Address = 160.78.27.14 Called-Station-Id = "004096586593" Calling-Station-Id = "000bbe371047" NAS-Identifier = "AP350-586593" NAS-Port = 38 Framed-MTU = 1400 State = 0x99f405885345311f5f4500694fda302b NAS-Port-Type = Wireless-802.11 Service-Type = Login-User EAP-Message = 0x020c00500d800000004616030100410100003d0301407274b9cc82fcd51f27098da5c30c2afdc0d6c8e0f85fec407d8044b3b83f0600001600040005000a000900640062000300060013001200630100 Message-Authenticator = 0x42da5e037024afa4f67e98bda17cdba4 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 1 modcall[authorize]: module "preprocess" returns ok for request 1 rlm_realm: No '@' in User-Name = "Rinaldo Bergamini", 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 12 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 Rinaldo Bergamini at 97 modcall[authorize]: module "files" returns ok 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 04ff], Certificate TLS_accept: SSLv3 write certificate A rlm_eap_tls: >>> TLS 1.0 Handshake [length 0078], 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 96 to 160.78.27.14:1632 EAP-Message = 0x010d040a0dc0000005d0160301004a02000046030140726636985901109b0329689dbd864ea034304a8327f36d540c0ff81a455b87208545528a22251db13f89e024a54ea2eecbb55807338607d3841a21dc3266420300040016030104ff0b0004fb0004f800026530820261308201caa00302010202010a300d06092a864886f70d01010405003067310d300b060355040a13044772696431133011060355040b130a476c6f6275735465737431263024060355040b131d73696d706c6543412d74726176696174612e63652e756e6970722e69743119301706035504031310476c6f6275732053696d706c65204341301e170d303430333235313230 EAP-Message = 0x3731345a170d3035303332353132303731345a306f310d300b060355040a13044772696431133011060355040b130a476c6f6275735465737431263024060355040b131d73696d706c6543412d74726176696174612e63652e756e6970722e69743121301f06035504031318686f73742f7061726d6130312e63652e756e6970722e697430819f300d06092a864886f70d010101050003818d0030818902818100c79a41c05b1d8f84765a3467d17631ed615737f616a74c1d2c6d9954b18a6d21c2b0d19bae8fdfaab7ae7f7553974f5845957b3b82fe382cd44c7f9346511db758cad67625a18426b1d0a80feeee1ba56269eea367417d8e82cccd09 EAP-Message = 0x9e9cc209538ea56d7dc9ea851b6d2481a68810f65de353a4439f1c230aaabf08ba8422170203010001a3153013301106096086480186f84201010404030204f0300d06092a864886f70d0101040500038181002fc6ed267f62eb493cd53826a152a688b6d8d6cf006e013c1c430e831c6d07f582cf9a34e00b078a5208c84d4802d69e8d684d9f6597b3785302f1fc1269c945d44405b1425017555ae18c0138f810028e058461f5ae7986cc76e082561e9f6b635f091e22e03d92a33da23e4b33a9ed1b7df67b79d79aedf6261fc64445228700028d30820289308201f2a003020102020100300d06092a864886f70d01010405003067310d300b0603 EAP-Message = 0x55040a13044772696431133011060355040b130a476c6f6275735465737431263024060355040b131d73696d706c6543412d74726176696174612e63652e756e6970722e69743119301706035504031310476c6f6275732053696d706c65204341301e170d3034303330323132303732395a170d3039303330313132303732395a3067310d300b060355040a13044772696431133011060355040b130a476c6f6275735465737431263024060355040b131d73696d706c6543412d74726176696174612e63652e756e6970722e69743119301706035504031310476c6f6275732053696d706c6520434130819f300d06092a864886f70d010101050003 EAP-Message = 0x818d0030818902818100c0a5527b6aa8528b646258bd Message-Authenticator = 0x00000000000000000000000000000000 State = 0x56c55778310d62ce8b5ef8f9dbaecb9e Finished request 1 Going to the next request Thread 2 waiting to be assigned a request rad_recv: Access-Request packet from host 160.78.27.14:1633, id=97, length=174 Thread 3 got semaphore Thread 3 handling request 2, (1 handled so far) Waking up in 5 seconds... User-Name = "Rinaldo Bergamini" Cisco-AVPair = "ssid=qosnet" NAS-IP-Address = 160.78.27.14 Called-Station-Id = "004096586593" Calling-Station-Id = "000bbe371047" NAS-Identifier = "AP350-586593" NAS-Port = 38 Framed-MTU = 1400 State = 0x56c55778310d62ce8b5ef8f9dbaecb9e NAS-Port-Type = Wireless-802.11 Service-Type = Login-User EAP-Message = 0x020d00060d00 Message-Authenticator = 0x2f6ff1440c408012ad525104832b5da8 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 2 modcall[authorize]: module "preprocess" returns ok for request 2 rlm_realm: No '@' in User-Name = "Rinaldo Bergamini", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 2 rlm_eap: EAP packet type response id 13 length 6 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 2 users: Matched Rinaldo Bergamini at 97 modcall[authorize]: module "files" returns ok 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 97 to 160.78.27.14:1633 EAP-Message = 0x010e01da0d80000005d0dcf84e5c29ea67fc5e386512efad8ec1426ee3cb2b588bc44fa22ee9ec5301e6235fb7a65ba7709d99b6cd3490f3f2532daa1d3c716e287b3fc38ba4f2a63df669c1f5139ec7aca187760c95a81ef86fd7e537ce60b48aa9ceff71742ba5035bd00b58b863922b34021f73af656b93c382b9adf70203010001a3453043300f0603551d130101ff040530030101ff301d0603551d0e04160414be146b7301fbe36adc51c004422accd77d2581cb301106096086480186f8420101040403020007300d06092a864886f70d010104050003818100610fcc79e40a24faab2ba3f83dea094602e03696d38d7ce499fe686033a34637 EAP-Message = 0x90fae19319bcb8e072ec381cb3248ca1ae780a7155dddb3eca1b3c856abe3ada7c047448fcbd4c157c45819af8636a5a54d75e65ce756129482eff1449cfd33f685ac5c51b9097c7f9554d9a99f5e9f6959cb5d36ebef23550b1c0ca1916c2ed16030100780d000070020102006b00693067310d300b060355040a13044772696431133011060355040b130a476c6f6275735465737431263024060355040b131d73696d706c6543412d74726176696174612e63652e756e6970722e69743119301706035504031310476c6f6275732053696d706c652043410e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xcde59bb2bd363df8e7cf8dd13a0c8a51 Finished request 2 Going to the next request Thread 3 waiting to be assigned a request rad_recv: Access-Request packet from host 160.78.27.14:1634, id=98, length=1138 Thread 4 got semaphore Thread 4 handling request 3, (1 handled so far) Waking up in 5 seconds... User-Name = "Rinaldo Bergamini" Cisco-AVPair = "ssid=qosnet" NAS-IP-Address = 160.78.27.14 Called-Station-Id = "004096586593" Calling-Station-Id = "000bbe371047" NAS-Identifier = "AP350-586593" NAS-Port = 38 Framed-MTU = 1400 State = 0xcde59bb2bd363df8e7cf8dd13a0c8a51 NAS-Port-Type = Wireless-802.11 Service-Type = Login-User EAP-Message = 0x020e03c40d80000003ba160301038a0b00027a00027700027430820270308201d9a003020102020109300d06092a864886f70d01010405003067310d300b060355040a13044772696431133011060355040b130a476c6f6275735465737431263024060355040b131d73696d706c6543412d74726176696174612e63652e756e6970722e69743119301706035504031310476c6f6275732053696d706c65204341301e170d3034303332353132303030355a170d3035303332353132303030355a307e310d300b060355040a13044772696431133011060355040b130a476c6f6275735465737431263024060355040b131d73696d706c6543412d7472 EAP-Message = 0x6176696174612e63652e756e6970722e697431143012060355040b130b63652e756e6970722e6974311a30180603550403131152696e616c646f2042657267616d696e6930819f300d06092a864886f70d010101050003818d0030818902818100c4aef4551b4f2413ac6372c10331b1cd7f4ef34fa5034a4f59a899b223a2eebf1100e0d0ac8f9e1f0eb67b246f52278707549a2859a7749421284a3638f00bbca3da8d6b46430a4430cbfc46025431ff42a323c55025b65ab23b8d345dd0ab0fb5a01d36a2e63d8e03a8ef5781c117ad00fadebb0b2749b41e4a4fc978014fd70203010001a3153013301106096086480186f84201010404030204f0 EAP-Message = 0x300d06092a864886f70d010104050003818100aade39094e6aa7282b781d98496ce01881b9d205f4c1b43a1a7b7c2b739b92b6b17e5b59f72710a2c41be6fa17ee2ffe040d81c0005eee995f320a7db15cf9372e1c0d18234482a195ccbe7be38a99dd8faeb3c1e3a562e604c533cf66e45078a9fd22486e2d0226b171e2e1843815b997311432839463b481f1daed4a4ac3a6100000820080a95f130f3b8ac4b90e85e8e56c0cc58454bba8e5f00657f345337dd898cf74728fc0e6ec989345f23dbd22930b7abcec767915d9aa6fea4d341cea13105d5a4f9bda7fbcc26d235ee31571395e63b64f360a96ac76dcd15157ef96c4eeb2e625d15481f7 EAP-Message = 0xba9df3668f5af99546d79098833723a537ecf11702d7eb41b94b0ce00f0000820080635783f3e176a397300e43fc10fce6e530c899ba746b8e6a2ca8205e37cfb109cee76a9b3857b59e37d403d07af34022ffad4546dae2cb05f2c69043b5619487d1b4adf4ff4b1ee5d0890d1abe2ec8c6d7cf5d839142e86d78ee98dedcae93397bd0998c86f1be1a4b8d35a7878f9324d9286cbdd8b30f0d9dc1ed2f6b32cbdc140301000101160301002072098cac682701cbfd2429bdebd3f4016d61c8733745a8f950f7d5fada8821b2 Message-Authenticator = 0x996bd44b789f19ce508745455c8b5e18 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 3 modcall[authorize]: module "preprocess" returns ok for request 3 rlm_realm: No '@' in User-Name = "Rinaldo Bergamini", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 3 rlm_eap: EAP packet type response id 14 length 253 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 3 users: Matched Rinaldo Bergamini at 97 modcall[authorize]: module "files" returns ok 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 027e], Certificate chain-depth=1, error=0 --> User-Name = Rinaldo Bergamini --> BUF-Name = Globus Simple CA --> subject = /O=Grid/OU=GlobusTest/OU=simpleCA-traviata.ce.unipr.it/CN=Globus Simple CA --> issuer = /O=Grid/OU=GlobusTest/OU=simpleCA-traviata.ce.unipr.it/CN=Globus Simple CA --> verify return:1 chain-depth=0, error=0 --> User-Name = Rinaldo Bergamini --> BUF-Name = Rinaldo Bergamini --> subject = /O=Grid/OU=GlobusTest/OU=simpleCA-traviata.ce.unipr.it/OU=ce. unipr.it/CN=Rinaldo Bergamini --> issuer = /O=Grid/OU=GlobusTest/OU=simpleCA-traviata.ce.unipr.it/CN=Globus Simple CA --> 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 98 to 160.78.27.14:1634 EAP-Message = 0x010f00350d800000002b14030100010116030100205b85712c2fdaf045e02ead6ac26a64fb98b3eb60a97fbb9427dfee3a4c2b1239 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x7dba785bd5a06e2fdde9e76d6702a879 Finished request 3 Going to the next request Thread 4 waiting to be assigned a request rad_recv: Access-Request packet from host 160.78.27.14:1635, id=99, length=201 Thread 5 got semaphore Thread 5 handling request 4, (1 handled so far) Waking up in 5 seconds... User-Name = "Rinaldo Bergamini" Cisco-AVPair = "ssid=qosnet" NAS-IP-Address = 160.78.27.14 Called-Station-Id = "004096586593" Calling-Station-Id = "000bbe371047" NAS-Identifier = "AP350-586593" NAS-Port = 38 Framed-MTU = 1400 State = 0x7dba785bd5a06e2fdde9e76d6702a879 NAS-Port-Type = Wireless-802.11 Service-Type = Login-User EAP-Message = 0x020f00210d80000000171503010012cbb99d0728dcb8e3614a6ac480571b244306 Message-Authenticator = 0x6bf21c1a50ffbffa32c651600767e8d2 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 4 modcall[authorize]: module "preprocess" returns ok for request 4 rlm_realm: No '@' in User-Name = "Rinaldo Bergamini", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 4 rlm_eap: EAP packet type response id 15 length 33 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 4 users: Matched Rinaldo Bergamini at 97 modcall[authorize]: module "files" returns ok 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 handshake. 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 Thread 5 waiting to be assigned a request rad_recv: Access-Request packet from host 160.78.27.14:1635, id=99, length=201 Sending Access-Reject of id 99 to 160.78.27.14:1635 EAP-Message = 0x040f0004 Message-Authenticator = 0x00000000000000000000000000000000 --- Walking the entire request list --- Waking up in 1 seconds... Threads: total/active/spare threads = 5/0/5 --- Walking the entire request list --- Cleaning up request 0 ID 95 with timestamp 40726636 Cleaning up request 1 ID 96 with timestamp 40726636 Cleaning up request 2 ID 97 with timestamp 40726636 Cleaning up request 3 ID 98 with timestamp 40726636 Cleaning up request 4 ID 99 with timestamp 40726636 Nothing to do. Sleeping until we see a request. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
