Hi guys, I need your help for a strange problem.
I want to authenticate users connected to a Cisco Aironet 1240 AG with their AD account and sometimes it's working and sometimes not and now doesn't want to work without changing something on the configuration... The AD authentication with ntlm_auth is working fine but just after that, the freeradius send a access-challenge to the aironet and nothing after that, no access-accept or access-reject. The windows part. works correctly (kinit, net join and ntlm_auth) I use the virtual server inner-tunnel for handle EAP/PEAP stuff, listen on different ports (auth 1814/ acct 1815) The aironet and the freeradius are synchronized with the same ntp server. Freeradius 2.1.8 samba 3.3.10 Debian 3.1 You can see a below the detail of a full session between the aironet and the freeradius. Many thanks for any tips. rad_recv: Access-Request packet from host 10.0.0.77 port 1645, id=172, length=146 User-Name = "AD_DOMAIN\\user_test_wifi" Framed-MTU = 1400 Called-Station-Id = "001c.f661.2861" Calling-Station-Id = "0018.de10.fcef" Service-Type = Login-User Message-Authenticator = 0xed65b0ebeb73a88b8467cc86843891e8 EAP-Message = 0x0201001501424f5552424f4e5c61626172616b6174 NAS-Port-Type = Wireless-802.11 NAS-Port = 879 NAS-Port-Id = "879" NAS-IP-Address = 10.0.0.77 Tue Feb 9 19:31:31 2010 : Info: server inner-tunnel { Tue Feb 9 19:31:31 2010 : Info: +- entering group authorize {...} Tue Feb 9 19:31:31 2010 : Info: ++[mschap] returns noop Tue Feb 9 19:31:31 2010 : Info: [eap] EAP packet type response id 1 length 21 Tue Feb 9 19:31:31 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 9 19:31:31 2010 : Info: ++[eap] returns updated Tue Feb 9 19:31:31 2010 : Info: Found Auth-Type = EAP Tue Feb 9 19:31:31 2010 : Info: +- entering group authenticate {...} Tue Feb 9 19:31:31 2010 : Info: [eap] EAP Identity Tue Feb 9 19:31:31 2010 : Info: [eap] processing type tls Tue Feb 9 19:31:31 2010 : Info: [tls] Requiring client certificate Tue Feb 9 19:31:31 2010 : Info: [tls] Initiate Tue Feb 9 19:31:31 2010 : Info: [tls] Start returned 1 Tue Feb 9 19:31:31 2010 : Info: ++[eap] returns handled Tue Feb 9 19:31:31 2010 : Info: } # server inner-tunnel Sending Access-Challenge of id 172 to 10.0.0.77 port 1645 EAP-Message = 0x010200060d20 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x630766f363056b37ef480b6cd7986d15 Tue Feb 9 19:31:31 2010 : Info: Finished request 0. Tue Feb 9 19:31:31 2010 : Debug: Going to the next request Tue Feb 9 19:31:31 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.0.77 port 1645, id=173, length=149 User-Name = "AD_DOMAIN\\user_test_wifi" Framed-MTU = 1400 Called-Station-Id = "001c.f661.2861" Calling-Station-Id = "0018.de10.fcef" Service-Type = Login-User Message-Authenticator = 0x412cd5decbd056652c741d532d91f91e EAP-Message = 0x020200060319 NAS-Port-Type = Wireless-802.11 NAS-Port = 879 NAS-Port-Id = "879" State = 0x630766f363056b37ef480b6cd7986d15 NAS-IP-Address = 10.0.0.77 Tue Feb 9 19:31:31 2010 : Info: server inner-tunnel { Tue Feb 9 19:31:31 2010 : Info: +- entering group authorize {...} Tue Feb 9 19:31:31 2010 : Info: ++[mschap] returns noop Tue Feb 9 19:31:31 2010 : Info: [eap] EAP packet type response id 2 length 6 Tue Feb 9 19:31:31 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 9 19:31:31 2010 : Info: ++[eap] returns updated Tue Feb 9 19:31:31 2010 : Info: Found Auth-Type = EAP Tue Feb 9 19:31:31 2010 : Info: +- entering group authenticate {...} Tue Feb 9 19:31:31 2010 : Info: [eap] Request found, released from the list Tue Feb 9 19:31:31 2010 : Info: [eap] EAP NAK Tue Feb 9 19:31:31 2010 : Info: [eap] EAP-NAK asked for EAP-Type/peap Tue Feb 9 19:31:31 2010 : Info: [eap] processing type tls Tue Feb 9 19:31:31 2010 : Info: [tls] Initiate Tue Feb 9 19:31:31 2010 : Info: [tls] Start returned 1 Tue Feb 9 19:31:31 2010 : Info: ++[eap] returns handled Tue Feb 9 19:31:31 2010 : Info: } # server inner-tunnel Sending Access-Challenge of id 173 to 10.0.0.77 port 1645 EAP-Message = 0x010300061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x630766f362047f37ef480b6cd7986d15 Tue Feb 9 19:31:31 2010 : Info: Finished request 1. Tue Feb 9 19:31:31 2010 : Debug: Going to the next request Tue Feb 9 19:31:31 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.0.77 port 1645, id=174, length=223 User-Name = "AD_DOMAIN\\user_test_wifi" Framed-MTU = 1400 Called-Station-Id = "001c.f661.2861" Calling-Station-Id = "0018.de10.fcef" Service-Type = Login-User Message-Authenticator = 0x45716fc71f57bd4a24613a3c5fda46e0 EAP-Message = 0x0203005019800000004616030100410100003d03014b71aa07cdc3058a38c645ee719f9b192d6b0588401da3361551528ad2b8acd100001600040005000a000900640062000300060013001200630100 NAS-Port-Type = Wireless-802.11 NAS-Port = 879 NAS-Port-Id = "879" State = 0x630766f362047f37ef480b6cd7986d15 NAS-IP-Address = 10.0.0.77 Tue Feb 9 19:31:31 2010 : Info: server inner-tunnel { Tue Feb 9 19:31:31 2010 : Info: +- entering group authorize {...} Tue Feb 9 19:31:31 2010 : Info: ++[mschap] returns noop Tue Feb 9 19:31:31 2010 : Info: [eap] EAP packet type response id 3 length 80 Tue Feb 9 19:31:31 2010 : Info: [eap] Continuing tunnel setup. Tue Feb 9 19:31:31 2010 : Info: ++[eap] returns ok Tue Feb 9 19:31:31 2010 : Info: Found Auth-Type = EAP Tue Feb 9 19:31:31 2010 : Info: +- entering group authenticate {...} Tue Feb 9 19:31:31 2010 : Info: [eap] Request found, released from the list Tue Feb 9 19:31:31 2010 : Info: [eap] EAP/peap Tue Feb 9 19:31:31 2010 : Info: [eap] processing type peap Tue Feb 9 19:31:31 2010 : Info: [peap] processing EAP-TLS Tue Feb 9 19:31:31 2010 : Debug: TLS Length 70 Tue Feb 9 19:31:31 2010 : Info: [peap] Length Included Tue Feb 9 19:31:31 2010 : Info: [peap] eaptls_verify returned 11 Tue Feb 9 19:31:31 2010 : Info: [peap] (other): before/accept initialization Tue Feb 9 19:31:31 2010 : Info: [peap] TLS_accept: before/accept initialization Tue Feb 9 19:31:31 2010 : Info: [peap] <<< TLS 1.0 Handshake [length 0041], ClientHello Tue Feb 9 19:31:31 2010 : Info: [peap] TLS_accept: SSLv3 read client hello A Tue Feb 9 19:31:31 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 002a], ServerHello Tue Feb 9 19:31:31 2010 : Info: [peap] TLS_accept: SSLv3 write server hello A Tue Feb 9 19:31:31 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 080f], Certificate Tue Feb 9 19:31:31 2010 : Info: [peap] TLS_accept: SSLv3 write certificate A Tue Feb 9 19:31:31 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Tue Feb 9 19:31:31 2010 : Info: [peap] TLS_accept: SSLv3 write server done A Tue Feb 9 19:31:31 2010 : Info: [peap] TLS_accept: SSLv3 flush data Tue Feb 9 19:31:31 2010 : Info: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A Tue Feb 9 19:31:31 2010 : Debug: In SSL Handshake Phase Tue Feb 9 19:31:31 2010 : Debug: In SSL Accept mode Tue Feb 9 19:31:31 2010 : Info: [peap] eaptls_process returned 13 Tue Feb 9 19:31:31 2010 : Info: [peap] EAPTLS_HANDLED Tue Feb 9 19:31:31 2010 : Info: ++[eap] returns handled Tue Feb 9 19:31:31 2010 : Info: } # server inner-tunnel Sending Access-Challenge of id 174 to 10.0.0.77 port 1645 EAP-Message = 0x0104040019c00000084c160301002a0200002603014b71aa035643367e71cace85998919065779df3128414b5239fc9d8485742d5600000400160301080f0b00080b000808000387308203833082026ba00302010202010e300d06092a864886f70d0101040500308183310b3009060355040613024652310d300b060355040813045041434131123010060355040713094d61727365696c6c653110300e060355040a1307426f7572626f6e3128302606092a864886f70d010901161972657365617540626f7572626f6e2d6f6e6c696e652e636f6d311530130603550403130c426f7572626f6e2057696669301e170d303830373331303730343234 EAP-Message = 0x5a170d3138303732393037303432345a306d310b3009060355040613024652310d300b06035504081304504143413110300e060355040a1307426f7572626f6e311330110603550403130a4d414e494e464c5830353128302606092a864886f70d010901161972657365617540626f7572626f6e2d6f6e6c696e652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100a7b78af2a06be87092e46edae10420955634dc12701bfafadba2005b5aeefd926a9b2630d51153cb6035c944506fb09ceb04e6343bc8a70d52f8790fee747a62f961719f388b2ae54e1e526efcd1884ff3082eaa1a6a686b6df4c4bd9f EAP-Message = 0x2d69075201778f2a0c9eff2161bd51d64c9339c9178eba5e230919d6aafd4e20907039ae58582ba2f500865af2801ce591bae42f2e343862d2f3faf55c0398f21250e282663a57532bb8bc0d8849f90b75f7691af328cc79bf8a056300e8e81d0a71a33688fedd2c9507ea5d1bf97aea13fd18806f78d05648bd838d333723015e31c4e5359f9604ec1d76efc9c109c7b595cffc138c52739c08e974b828f378fdb4e30203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003820101007fc48e89deb24e8e24e4c534e81c1df703c9d1384acae44c58c5d01cd968e66bf0e63d1f628f6153 EAP-Message = 0x83ec8ee5d7723b9ab51bd2dc5bf601d8ce5e613847cb8dd45ee71a9b026ec6930d31b03edee7af52760334c56a0974a135e8b8b36dab96d61eab510d2fa58df2a872358ee805b5890534aefe5d2e5dfd05071e6c7f409692b3a1bc5191ea4a7413537e1b3b87cd735d82689d5feadc2c1bfebb2f07d2a8bca706f9ff939b3bcb1884f9f4921c5ebafa5559d21ab8cde1f3894f7d0e62c972ec09d02dd2b7b7afdf9b7a6581c46a461d5b0f230591e4ba967920625c8000ed4314ba6e380ceab5774300916c5f1b3be3b1bdb9abf61c8e0ba851806531029600047b308204773082035fa003020102020900b766438b321f9f9c300d06092a864886f70d EAP-Message = 0x0101040500308183310b3009 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x630766f361037f37ef480b6cd7986d15 Tue Feb 9 19:31:31 2010 : Info: Finished request 2. Tue Feb 9 19:31:31 2010 : Debug: Going to the next request Tue Feb 9 19:31:31 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.0.77 port 1645, id=175, length=149 User-Name = "AD_DOMAIN\\user_test_wifi" Framed-MTU = 1400 Called-Station-Id = "001c.f661.2861" Calling-Station-Id = "0018.de10.fcef" Service-Type = Login-User Message-Authenticator = 0x5d0b3a377ada40b679cbc9e64f9575dd EAP-Message = 0x020400061900 NAS-Port-Type = Wireless-802.11 NAS-Port = 879 NAS-Port-Id = "879" State = 0x630766f361037f37ef480b6cd7986d15 NAS-IP-Address = 10.0.0.77 Tue Feb 9 19:31:31 2010 : Info: server inner-tunnel { Tue Feb 9 19:31:31 2010 : Info: +- entering group authorize {...} Tue Feb 9 19:31:31 2010 : Info: ++[mschap] returns noop Tue Feb 9 19:31:31 2010 : Info: [eap] EAP packet type response id 4 length 6 Tue Feb 9 19:31:31 2010 : Info: [eap] Continuing tunnel setup. Tue Feb 9 19:31:31 2010 : Info: ++[eap] returns ok Tue Feb 9 19:31:31 2010 : Info: Found Auth-Type = EAP Tue Feb 9 19:31:31 2010 : Info: +- entering group authenticate {...} Tue Feb 9 19:31:31 2010 : Info: [eap] Request found, released from the list Tue Feb 9 19:31:31 2010 : Info: [eap] EAP/peap Tue Feb 9 19:31:31 2010 : Info: [eap] processing type peap Tue Feb 9 19:31:31 2010 : Info: [peap] processing EAP-TLS Tue Feb 9 19:31:31 2010 : Info: [peap] Received TLS ACK Tue Feb 9 19:31:31 2010 : Info: [peap] ACK handshake fragment handler Tue Feb 9 19:31:31 2010 : Info: [peap] eaptls_verify returned 1 Tue Feb 9 19:31:31 2010 : Info: [peap] eaptls_process returned 13 Tue Feb 9 19:31:31 2010 : Info: [peap] EAPTLS_HANDLED Tue Feb 9 19:31:31 2010 : Info: ++[eap] returns handled Tue Feb 9 19:31:31 2010 : Info: } # server inner-tunnel Sending Access-Challenge of id 175 to 10.0.0.77 port 1645 EAP-Message = 0x010503fc1940060355040613024652310d300b060355040813045041434131123010060355040713094d61727365696c6c653110300e060355040a1307426f7572626f6e3128302606092a864886f70d010901161972657365617540626f7572626f6e2d6f6e6c696e652e636f6d311530130603550403130c426f7572626f6e2057696669301e170d3038303732393039303035375a170d3138303732373039303035375a308183310b3009060355040613024652310d300b060355040813045041434131123010060355040713094d61727365696c6c653110300e060355040a1307426f7572626f6e3128302606092a864886f70d01090116197265 EAP-Message = 0x7365617540626f7572626f6e2d6f6e6c696e652e636f6d311530130603550403130c426f7572626f6e205769666930820122300d06092a864886f70d01010105000382010f003082010a0282010100cde4d0567cae3d2e4ef240e6cf4e3897636d8db29147bc849f76ab9739f20dd2a58b3233330d35e5ab0203ec6aa360ee4553814a5329d7b016ce84d0bc12feef460a48a4fda42f58ec497dc0d6558e35e83992e4dfbd776b478ce74dcca59fd138749ca23b95c67035207ad2ca0f048d41e2b0eaf859091b61d5c64463172198c24513f63b2b2b96ad604ca115abf3ee3d1b74534b99770775e2807e211d248283a6c82ca92f54273d49586d01a6 EAP-Message = 0xc598e321aa9c56100a1cf5624b465f2c9a06df1ab2d2b463894732630b5c3387d9c7ced4de1831e0b38b57e80f2e0126557838e32e92fe26c5286765bb95555d893f63cdb44c22803c278fdb55b29f11a1170203010001a381eb3081e8301d0603551d0e04160414db839d9de5c1dc00c2bd064b745f4ecdd4d2c28a3081b80603551d230481b03081ad8014db839d9de5c1dc00c2bd064b745f4ecdd4d2c28aa18189a48186308183310b3009060355040613024652310d300b060355040813045041434131123010060355040713094d61727365696c6c653110300e060355040a1307426f7572626f6e3128302606092a864886f70d010901161972 EAP-Message = 0x657365617540626f7572626f6e2d6f6e6c696e652e636f6d311530130603550403130c426f7572626f6e2057696669820900b766438b321f9f9c300c0603551d13040530030101ff300d06092a864886f70d01010405000382010100251a3ffcc78e8dbe969a4f961e585036481111ae2b26c492435e7240e91edb58320f3fe213708938e37b38707253dc741124fb2bfb6f9d52fbc0a6b702aeb86ff30517be2472bbef215d4dcb4a9978402b32a3fb0320ab05a5fbdfa93d011e09d24936a5f20fb94ca54103c042c8be8b111126a3b957b9c8bc025a86c69d4a2eca3a184368c0a3bc5e0c24eeb041d8ad02211767d8144c5dee5b06980cb9408280 EAP-Message = 0x2e483ef0ee3b57d6 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x630766f360027f37ef480b6cd7986d15 Tue Feb 9 19:31:31 2010 : Info: Finished request 3. Tue Feb 9 19:31:31 2010 : Debug: Going to the next request Tue Feb 9 19:31:31 2010 : Debug: Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 10.0.0.77 port 1645, id=176, length=149 User-Name = "AD_DOMAIN\\user_test_wifi" Framed-MTU = 1400 Called-Station-Id = "001c.f661.2861" Calling-Station-Id = "0018.de10.fcef" Service-Type = Login-User Message-Authenticator = 0x3ac2f01811b4629fdcd317157c47b538 EAP-Message = 0x020500061900 NAS-Port-Type = Wireless-802.11 NAS-Port = 879 NAS-Port-Id = "879" State = 0x630766f360027f37ef480b6cd7986d15 NAS-IP-Address = 10.0.0.77 Tue Feb 9 19:31:31 2010 : Info: server inner-tunnel { Tue Feb 9 19:31:31 2010 : Info: +- entering group authorize {...} Tue Feb 9 19:31:31 2010 : Info: ++[mschap] returns noop Tue Feb 9 19:31:31 2010 : Info: [eap] EAP packet type response id 5 length 6 Tue Feb 9 19:31:31 2010 : Info: [eap] Continuing tunnel setup. Tue Feb 9 19:31:31 2010 : Info: ++[eap] returns ok Tue Feb 9 19:31:31 2010 : Info: Found Auth-Type = EAP Tue Feb 9 19:31:31 2010 : Info: +- entering group authenticate {...} Tue Feb 9 19:31:31 2010 : Info: [eap] Request found, released from the list Tue Feb 9 19:31:31 2010 : Info: [eap] EAP/peap Tue Feb 9 19:31:31 2010 : Info: [eap] processing type peap Tue Feb 9 19:31:31 2010 : Info: [peap] processing EAP-TLS Tue Feb 9 19:31:31 2010 : Info: [peap] Received TLS ACK Tue Feb 9 19:31:31 2010 : Info: [peap] ACK handshake fragment handler Tue Feb 9 19:31:31 2010 : Info: [peap] eaptls_verify returned 1 Tue Feb 9 19:31:31 2010 : Info: [peap] eaptls_process returned 13 Tue Feb 9 19:31:31 2010 : Info: [peap] EAPTLS_HANDLED Tue Feb 9 19:31:31 2010 : Info: ++[eap] returns handled Tue Feb 9 19:31:31 2010 : Info: } # server inner-tunnel Sending Access-Challenge of id 176 to 10.0.0.77 port 1645 EAP-Message = 0x010600661900cc3f738e0bb90eb43d082127c7cdc508523e8d839599dc81a4163bd1a2af448c98bb160534531881e4b11ea1a1299f7b1629fc3ef4c2fc3bf925285e87f0c980e14b3272e948f23ff1e54b5a9fada91f718325413ff25c16030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x630766f367017f37ef480b6cd7986d15 Tue Feb 9 19:31:31 2010 : Info: Finished request 4. Tue Feb 9 19:31:31 2010 : Debug: Going to the next request Tue Feb 9 19:31:31 2010 : Debug: Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 10.0.0.77 port 1645, id=177, length=465 User-Name = "AD_DOMAIN\\user_test_wifi" Framed-MTU = 1400 Called-Station-Id = "001c.f661.2861" Calling-Station-Id = "0018.de10.fcef" Service-Type = Login-User Message-Authenticator = 0x024a73e43a438c4f39a58124a4b38dfc EAP-Message = 0x0206014019800000013616030101061000010201003c496a8eb52168b966e1b1ef6a790f57ccbdb76e3896c91311820bb5ede6c0d41b5dda5a85476a61bcfa5a51c9225cc474cd1dd27af1a74679ae8dc4d1676817a38979e43f1fe6b5f09ab7e841dccd504f255c86d7dce5c4d5760048c8196c1938319713b3448aee99abbb077497ff1e222c782f2d0494d370f74f84ee1b0a863b0614047996817c16248d8328efe7ecda902251dd8d57a8ed70af7e5fafee26d53ac394209b637127c039ab1154fbb6ddb19ac64ab030eeea931871b1f4cd5f5613537eb283e20763feaee30c49eebe3d8bddf0b4846b1134a81af4b792ce07578ca8c312236f2f EAP-Message = 0xc932090c584389a1bb72fd70793b1a969521c0206eab7e8c14030100010116030100200c71dab31b9d5950bb4848a49f11003a72b8e9cdff7e4353588e9ffbd15bedb9 NAS-Port-Type = Wireless-802.11 NAS-Port = 879 NAS-Port-Id = "879" State = 0x630766f367017f37ef480b6cd7986d15 NAS-IP-Address = 10.0.0.77 Tue Feb 9 19:31:31 2010 : Info: server inner-tunnel { Tue Feb 9 19:31:31 2010 : Info: +- entering group authorize {...} Tue Feb 9 19:31:31 2010 : Info: ++[mschap] returns noop Tue Feb 9 19:31:31 2010 : Info: [eap] EAP packet type response id 6 length 253 Tue Feb 9 19:31:31 2010 : Info: [eap] Continuing tunnel setup. Tue Feb 9 19:31:31 2010 : Info: ++[eap] returns ok Tue Feb 9 19:31:31 2010 : Info: Found Auth-Type = EAP Tue Feb 9 19:31:31 2010 : Info: +- entering group authenticate {...} Tue Feb 9 19:31:31 2010 : Info: [eap] Request found, released from the list Tue Feb 9 19:31:31 2010 : Info: [eap] EAP/peap Tue Feb 9 19:31:31 2010 : Info: [eap] processing type peap Tue Feb 9 19:31:31 2010 : Info: [peap] processing EAP-TLS Tue Feb 9 19:31:31 2010 : Debug: TLS Length 310 Tue Feb 9 19:31:31 2010 : Info: [peap] Length Included Tue Feb 9 19:31:31 2010 : Info: [peap] eaptls_verify returned 11 Tue Feb 9 19:31:31 2010 : Info: [peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange Tue Feb 9 19:31:31 2010 : Info: [peap] TLS_accept: SSLv3 read client key exchange A Tue Feb 9 19:31:31 2010 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] Tue Feb 9 19:31:31 2010 : Info: [peap] <<< TLS 1.0 Handshake [length 0010], Finished Tue Feb 9 19:31:31 2010 : Info: [peap] TLS_accept: SSLv3 read finished A Tue Feb 9 19:31:31 2010 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] Tue Feb 9 19:31:31 2010 : Info: [peap] TLS_accept: SSLv3 write change cipher spec A Tue Feb 9 19:31:31 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 0010], Finished Tue Feb 9 19:31:31 2010 : Info: [peap] TLS_accept: SSLv3 write finished A Tue Feb 9 19:31:31 2010 : Info: [peap] TLS_accept: SSLv3 flush data Tue Feb 9 19:31:31 2010 : Info: [peap] (other): SSL negotiation finished successfully Tue Feb 9 19:31:31 2010 : Debug: SSL Connection Established Tue Feb 9 19:31:31 2010 : Info: [peap] eaptls_process returned 13 Tue Feb 9 19:31:31 2010 : Info: [peap] EAPTLS_HANDLED Tue Feb 9 19:31:31 2010 : Info: ++[eap] returns handled Tue Feb 9 19:31:31 2010 : Info: } # server inner-tunnel Sending Access-Challenge of id 177 to 10.0.0.77 port 1645 EAP-Message = 0x0107003119001403010001011603010020a56dfc42f5d1060f090b69cc7b8f37f3daee63f4f8da90203a1e5a1bcd82f342 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x630766f366007f37ef480b6cd7986d15 Tue Feb 9 19:31:31 2010 : Info: Finished request 5. Tue Feb 9 19:31:31 2010 : Debug: Going to the next request Tue Feb 9 19:31:31 2010 : Debug: Waking up in 4.7 seconds. rad_recv: Access-Request packet from host 10.0.0.77 port 1645, id=178, length=149 User-Name = "AD_DOMAIN\\user_test_wifi" Framed-MTU = 1400 Called-Station-Id = "001c.f661.2861" Calling-Station-Id = "0018.de10.fcef" Service-Type = Login-User Message-Authenticator = 0x629c55793c4cbadf76846f2f29db3db4 EAP-Message = 0x020700061900 NAS-Port-Type = Wireless-802.11 NAS-Port = 879 NAS-Port-Id = "879" State = 0x630766f366007f37ef480b6cd7986d15 NAS-IP-Address = 10.0.0.77 Tue Feb 9 19:31:32 2010 : Info: server inner-tunnel { Tue Feb 9 19:31:32 2010 : Info: +- entering group authorize {...} Tue Feb 9 19:31:32 2010 : Info: ++[mschap] returns noop Tue Feb 9 19:31:32 2010 : Info: [eap] EAP packet type response id 7 length 6 Tue Feb 9 19:31:32 2010 : Info: [eap] Continuing tunnel setup. Tue Feb 9 19:31:32 2010 : Info: ++[eap] returns ok Tue Feb 9 19:31:32 2010 : Info: Found Auth-Type = EAP Tue Feb 9 19:31:32 2010 : Info: +- entering group authenticate {...} Tue Feb 9 19:31:32 2010 : Info: [eap] Request found, released from the list Tue Feb 9 19:31:32 2010 : Info: [eap] EAP/peap Tue Feb 9 19:31:32 2010 : Info: [eap] processing type peap Tue Feb 9 19:31:32 2010 : Info: [peap] processing EAP-TLS Tue Feb 9 19:31:32 2010 : Info: [peap] Received TLS ACK Tue Feb 9 19:31:32 2010 : Info: [peap] ACK handshake is finished Tue Feb 9 19:31:32 2010 : Info: [peap] eaptls_verify returned 3 Tue Feb 9 19:31:32 2010 : Info: [peap] eaptls_process returned 3 Tue Feb 9 19:31:32 2010 : Info: [peap] EAPTLS_SUCCESS Tue Feb 9 19:31:32 2010 : Info: ++[eap] returns handled Tue Feb 9 19:31:32 2010 : Info: } # server inner-tunnel Sending Access-Challenge of id 178 to 10.0.0.77 port 1645 EAP-Message = 0x0108002019001703010015338a9d72cc9bb34a8f252b4d7857636b5d2a9b4db3 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x630766f3650f7f37ef480b6cd7986d15 Tue Feb 9 19:31:32 2010 : Info: Finished request 6. Tue Feb 9 19:31:32 2010 : Debug: Going to the next request Tue Feb 9 19:31:32 2010 : Debug: Waking up in 3.5 seconds. rad_recv: Access-Request packet from host 10.0.0.77 port 1645, id=179, length=187 User-Name = "AD_DOMAIN\\user_test_wifi" Framed-MTU = 1400 Called-Station-Id = "001c.f661.2861" Calling-Station-Id = "0018.de10.fcef" Service-Type = Login-User Message-Authenticator = 0x500d56edad68bdbda0e5b3912480a1f6 EAP-Message = 0x0208002c19001703010021b6c2b8543fbb5966a77182d6f87791d0e16c87a89f58a0b67058189c046188b3fa NAS-Port-Type = Wireless-802.11 NAS-Port = 879 NAS-Port-Id = "879" State = 0x630766f3650f7f37ef480b6cd7986d15 NAS-IP-Address = 10.0.0.77 Tue Feb 9 19:31:34 2010 : Info: server inner-tunnel { Tue Feb 9 19:31:34 2010 : Info: +- entering group authorize {...} Tue Feb 9 19:31:34 2010 : Info: ++[mschap] returns noop Tue Feb 9 19:31:34 2010 : Info: [eap] EAP packet type response id 8 length 44 Tue Feb 9 19:31:34 2010 : Info: [eap] Continuing tunnel setup. Tue Feb 9 19:31:34 2010 : Info: ++[eap] returns ok Tue Feb 9 19:31:34 2010 : Info: Found Auth-Type = EAP Tue Feb 9 19:31:34 2010 : Info: +- entering group authenticate {...} Tue Feb 9 19:31:34 2010 : Info: [eap] Request found, released from the list Tue Feb 9 19:31:34 2010 : Info: [eap] EAP/peap Tue Feb 9 19:31:34 2010 : Info: [eap] processing type peap Tue Feb 9 19:31:34 2010 : Info: [peap] processing EAP-TLS Tue Feb 9 19:31:34 2010 : Info: [peap] eaptls_verify returned 7 Tue Feb 9 19:31:34 2010 : Info: [peap] Done initial handshake Tue Feb 9 19:31:34 2010 : Info: [peap] eaptls_process returned 7 Tue Feb 9 19:31:34 2010 : Info: [peap] EAPTLS_OK Tue Feb 9 19:31:34 2010 : Info: [peap] Session established. Decoding tunneled attributes. Tue Feb 9 19:31:34 2010 : Info: [peap] Identity - AD_DOMAIN\user_test_wifi Tue Feb 9 19:31:34 2010 : Info: [peap] Got tunneled request EAP-Message = 0x0208001501424f5552424f4e5c61626172616b6174 server inner-tunnel { Tue Feb 9 19:31:34 2010 : Debug: PEAP: Got tunneled identity of AD_DOMAIN\user_test_wifi Tue Feb 9 19:31:34 2010 : Debug: PEAP: Setting default EAP type for tunneled EAP session. Tue Feb 9 19:31:34 2010 : Debug: PEAP: Setting User-Name to AD_DOMAIN\user_test_wifi Sending tunneled request EAP-Message = 0x0208001501424f5552424f4e5c61626172616b6174 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "AD_DOMAIN\\user_test_wifi" server inner-tunnel { Tue Feb 9 19:31:34 2010 : Info: +- entering group authorize {...} Tue Feb 9 19:31:34 2010 : Info: ++[mschap] returns noop Tue Feb 9 19:31:34 2010 : Info: [eap] EAP packet type response id 8 length 21 Tue Feb 9 19:31:34 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 9 19:31:34 2010 : Info: ++[eap] returns updated Tue Feb 9 19:31:34 2010 : Info: Found Auth-Type = EAP Tue Feb 9 19:31:34 2010 : Info: +- entering group authenticate {...} Tue Feb 9 19:31:34 2010 : Info: [eap] EAP Identity Tue Feb 9 19:31:34 2010 : Info: [eap] processing type mschapv2 Tue Feb 9 19:31:34 2010 : Debug: rlm_eap_mschapv2: Issuing Challenge Tue Feb 9 19:31:34 2010 : Info: ++[eap] returns handled } # server inner-tunnel Tue Feb 9 19:31:34 2010 : Info: [peap] Got tunneled reply code 11 EAP-Message = 0x0109002a1a01090025101c8be56c40b9a54755d20939ec8df613424f5552424f4e5c61626172616b6174 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x201838bd20112259733e0bf834fb291f Tue Feb 9 19:31:34 2010 : Info: [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x0109002a1a01090025101c8be56c40b9a54755d20939ec8df613424f5552424f4e5c61626172616b6174 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x201838bd20112259733e0bf834fb291f Tue Feb 9 19:31:34 2010 : Info: [peap] Got tunneled Access-Challenge Tue Feb 9 19:31:34 2010 : Info: ++[eap] returns handled Tue Feb 9 19:31:34 2010 : Info: } # server inner-tunnel Sending Access-Challenge of id 179 to 10.0.0.77 port 1645 EAP-Message = 0x0109004119001703010036e406e613a4f321e4655c7c579132115ccc4bb4877b10ffc97a61c4cb688dea5d4c1cf9a9f27a95ebbd8ba6338742f3efa4807a43ece1 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x630766f3640e7f37ef480b6cd7986d15 Tue Feb 9 19:31:34 2010 : Info: Finished request 7. Tue Feb 9 19:31:34 2010 : Debug: Going to the next request Tue Feb 9 19:31:34 2010 : Debug: Waking up in 2.1 seconds. rad_recv: Access-Request packet from host 10.0.0.77 port 1645, id=180, length=241 User-Name = "AD_DOMAIN\\user_test_wifi" Framed-MTU = 1400 Called-Station-Id = "001c.f661.2861" Calling-Station-Id = "0018.de10.fcef" Service-Type = Login-User Message-Authenticator = 0x31542e43fae0a5114d2097298c39dbd2 EAP-Message = 0x02090062190017030100572fd5ebb3225905f570376310014d9354d08bb9d9679612b9656c27ef7ada8d6b490ae14d389d9b475c26b5273a0d0129d1e3fce2764acb32ade4a614891eaee57ece9593753cec60a828360cd03b295ffedc5456dc7c73 NAS-Port-Type = Wireless-802.11 NAS-Port = 879 NAS-Port-Id = "879" State = 0x630766f3640e7f37ef480b6cd7986d15 NAS-IP-Address = 10.0.0.77 Tue Feb 9 19:31:35 2010 : Info: server inner-tunnel { Tue Feb 9 19:31:35 2010 : Info: +- entering group authorize {...} Tue Feb 9 19:31:35 2010 : Info: ++[mschap] returns noop Tue Feb 9 19:31:35 2010 : Info: [eap] EAP packet type response id 9 length 98 Tue Feb 9 19:31:35 2010 : Info: [eap] Continuing tunnel setup. Tue Feb 9 19:31:35 2010 : Info: ++[eap] returns ok Tue Feb 9 19:31:35 2010 : Info: Found Auth-Type = EAP Tue Feb 9 19:31:35 2010 : Info: +- entering group authenticate {...} Tue Feb 9 19:31:35 2010 : Info: [eap] Request found, released from the list Tue Feb 9 19:31:35 2010 : Info: [eap] EAP/peap Tue Feb 9 19:31:35 2010 : Info: [eap] processing type peap Tue Feb 9 19:31:35 2010 : Info: [peap] processing EAP-TLS Tue Feb 9 19:31:35 2010 : Info: [peap] eaptls_verify returned 7 Tue Feb 9 19:31:35 2010 : Info: [peap] Done initial handshake Tue Feb 9 19:31:35 2010 : Info: [peap] eaptls_process returned 7 Tue Feb 9 19:31:35 2010 : Info: [peap] EAPTLS_OK Tue Feb 9 19:31:35 2010 : Info: [peap] Session established. Decoding tunneled attributes. Tue Feb 9 19:31:35 2010 : Info: [peap] EAP type mschapv2 Tue Feb 9 19:31:35 2010 : Info: [peap] Got tunneled request EAP-Message = 0x0209004b1a020900463159c4b01853f7bc645db17d14cc43e45b0000000000000000f8311309285cb367f0f69e17c8573225debc330a6f2b0acd00424f5552424f4e5c61626172616b6174 server inner-tunnel { Tue Feb 9 19:31:35 2010 : Debug: PEAP: Setting User-Name to AD_DOMAIN\user_test_wifi Sending tunneled request EAP-Message = 0x0209004b1a020900463159c4b01853f7bc645db17d14cc43e45b0000000000000000f8311309285cb367f0f69e17c8573225debc330a6f2b0acd00424f5552424f4e5c61626172616b6174 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "AD_DOMAIN\\user_test_wifi" State = 0x201838bd20112259733e0bf834fb291f server inner-tunnel { Tue Feb 9 19:31:35 2010 : Info: +- entering group authorize {...} Tue Feb 9 19:31:35 2010 : Info: ++[mschap] returns noop Tue Feb 9 19:31:35 2010 : Info: [eap] EAP packet type response id 9 length 75 Tue Feb 9 19:31:35 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 9 19:31:35 2010 : Info: ++[eap] returns updated Tue Feb 9 19:31:35 2010 : Info: Found Auth-Type = EAP Tue Feb 9 19:31:35 2010 : Info: +- entering group authenticate {...} Tue Feb 9 19:31:35 2010 : Info: [eap] Request found, released from the list Tue Feb 9 19:31:35 2010 : Info: [eap] EAP/mschapv2 Tue Feb 9 19:31:35 2010 : Info: [eap] processing type mschapv2 Tue Feb 9 19:31:35 2010 : Info: [mschapv2] +- entering group MS-CHAP {...} Tue Feb 9 19:31:35 2010 : Info: [mschap] Told to do MS-CHAPv2 for user_test_wifi with NT-Password Tue Feb 9 19:31:35 2010 : Info: [mschap] expand: --username=%{mschap:User-Name:-None} -> --username=user_test_wifi Tue Feb 9 19:31:35 2010 : Info: [mschap] expand: %{mschap:NT-Domain} -> AD_DOMAIN Tue Feb 9 19:31:35 2010 : Info: [mschap] expand: --domain=%{%{mschap:NT-Domain}:-AD_DOMAIN} -> --domain=AD_DOMAIN Tue Feb 9 19:31:35 2010 : Info: [mschap] mschap2: 1c Tue Feb 9 19:31:35 2010 : Info: [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=a408dd1bfedc11a4 Tue Feb 9 19:31:35 2010 : Info: [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=f8311309285cb367f0f69e17c8573225debc330a6f2b0acd Tue Feb 9 19:31:35 2010 : Debug: Exec-Program output: NT_KEY: CF98AB81F3DA1FD14394045CBDF4EE95 Tue Feb 9 19:31:35 2010 : Debug: Exec-Program-Wait: plaintext: NT_KEY: CF98AB81F3DA1FD14394045CBDF4EE95 Tue Feb 9 19:31:35 2010 : Debug: Exec-Program: returned: 0 Tue Feb 9 19:31:35 2010 : Info: [mschap] adding MS-CHAPv2 MPPE keys Tue Feb 9 19:31:35 2010 : Info: ++[mschap] returns ok Tue Feb 9 19:31:35 2010 : Debug: MSCHAP Success Tue Feb 9 19:31:35 2010 : Info: ++[eap] returns handled } # server inner-tunnel Tue Feb 9 19:31:35 2010 : Info: [peap] Got tunneled reply code 11 EAP-Message = 0x010a00331a0309002e533d38373446314345433434313841443045443633443131343232423639374542364334374241383141 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x201838bd21122259733e0bf834fb291f Tue Feb 9 19:31:35 2010 : Info: [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x010a00331a0309002e533d38373446314345433434313841443045443633443131343232423639374542364334374241383141 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x201838bd21122259733e0bf834fb291f Tue Feb 9 19:31:35 2010 : Info: [peap] Got tunneled Access-Challenge Tue Feb 9 19:31:35 2010 : Info: ++[eap] returns handled Tue Feb 9 19:31:35 2010 : Info: } # server inner-tunnel Sending Access-Challenge of id 180 to 10.0.0.77 port 1645 EAP-Message = 0x010a004a1900170301003fb59942b3af54f208315acdd63f76b9e69db5149b4cfc84a670ae4c1b54e82ae74d9af17979e7e1d1d755e8c03b38656ae4cde15a7936d288a423466d5f4d35 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x630766f36b0d7f37ef480b6cd7986d15 Tue Feb 9 19:31:35 2010 : Info: Finished request 8. Tue Feb 9 19:31:35 2010 : Debug: Going to the next request Tue Feb 9 19:31:35 2010 : Debug: Waking up in 0.5 seconds. Tue Feb 9 19:31:36 2010 : Info: Cleaning up request 0 ID 172 with timestamp +134 Tue Feb 9 19:31:36 2010 : Info: Cleaning up request 1 ID 173 with timestamp +134 Tue Feb 9 19:31:36 2010 : Info: Cleaning up request 2 ID 174 with timestamp +134 Tue Feb 9 19:31:36 2010 : Info: Cleaning up request 3 ID 175 with timestamp +134 Tue Feb 9 19:31:36 2010 : Info: Cleaning up request 4 ID 176 with timestamp +134 Tue Feb 9 19:31:36 2010 : Info: Cleaning up request 5 ID 177 with timestamp +134 Tue Feb 9 19:31:36 2010 : Debug: Waking up in 1.2 seconds. Tue Feb 9 19:31:37 2010 : Info: Cleaning up request 6 ID 178 with timestamp +135 Tue Feb 9 19:31:37 2010 : Debug: Waking up in 1.4 seconds. Tue Feb 9 19:31:39 2010 : Info: Cleaning up request 7 ID 179 with timestamp +137 Tue Feb 9 19:31:39 2010 : Debug: Waking up in 1.5 seconds. Tue Feb 9 19:31:40 2010 : Info: Cleaning up request 8 ID 180 with timestamp +138 Tue Feb 9 19:31:40 2010 : Info: Ready to process requests. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html