Hello, I few releases back we had EAP-TTLS/TLS working (maybe 2 years ago??) Since then it has stopped and I am having trouble finding the root cause. Protocols like EAP-TLS and EAP-TTLS/MSCHAPV2 are working, and I verified the certificates and keys. I have attached the output from 'radiusd -X' below. I see a lot of posts have a nice condensed dump of the configuration, if someone could tell me how to get the dump I will attach it also. Near the end is the statement: [ttls] WARNING: diameter2vp skipping long attribute 3005705648, attr I found this in the source code but am not sure if is is part of the problem or just a non-fatal warning. Thank you for any help you can provide. NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020300061500 State = 0x761f94dc741c81c1389e58c98036d07f Message-Authenticator = 0xb32ee439c871fca74db681b61df4ed0a # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 3 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] Received TLS ACK [ttls] ACK handshake fragment handler [ttls] eaptls_verify returned 1 [ttls] eaptls_process returned 13 ++[eap] returns handled Sending Access-Challenge of id 150 to 10.0.1.254 port 1025 EAP-Message = 0x0104040015c000000c578b377bc03abc12d9efd6a6057b6a8068e1c0d78eb5ea8a54d5d52c230626dd9f4b2ff161ac9d17dda991270ce17612c56b52c8adc23c017778aeed9a4d8f1e96e2cd2447783b8e9ca80f678749b48c7cd00590b3b9bd1bfcfe82e57b612889d8f9fa5f0c375e67d3480cd881a393ce30690c841d014ba04e96aa9526a9bc86ca35ebc4bf7fd86fbff92d8fb97b76772ff49fff6f5d43a4fa90865178e2d85d3b393ecf020b69bba1b65c8d773197db60a12244a8980d0a9cd445e4134f8a401c4b813e14300f76d62a25fe73a6860d790005733082056f30820357a003020102020900e69fcd1da395f8d1300d06092a864886 EAP-Message = 0xf70d0101050500304e310b30090603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d20446576696365204341301e170d3132303330383134343335385a170d3232303330383134343335385a304e310b30090603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d2044657669636520434130820222300d06092a864886f70d01010105000382020f003082020a0282020100d3eb1fb917fd39578eeb97d1825ab99c826c9bab8f EAP-Message = 0x36eaa024842596cbfa775ac29a078a4dbffcb8672975c3360be599e79e282b76c133d091561c118294dce53ed7afd6c216b6a42b5babfd26b5d1743fd46a73c7d4e0e2f19775ad1ffda3dc526c29be5be8f951a5c4e195132e62e8b7084eb74d54f4f2b670ae7669582c3c42a69b833873e2bd4c8a4e25ad6db8762d943389ce3b876005d0d67384c1e1c45c14dccee08c93b29a8f7da340b6157b13b499b3678a7f96cc338b4eca643b3e91dd1e3bf6d67a39801e2fca2ba7e7463f7f4fe9f6f79dbb0e43d970386d0476f281f2c902f85f390febf77414946f0c632a3c084c0dbd26c212d20fabe73d32f7113d15e0b9fa6cb31e9b95821db543f16f EAP-Message = 0x3bfdcbbc791e2a734b645267a4d16f2906b48752285c75d749696c6094c7494216837c01f6287789977924590c132376dac76a59498020eea75d9f508a974b45051eeb3e71d8b48df1d98bf22424e05c33a9bab9de0556e5289805e58f663f30af7883a7b8a5e32b0fd314c40cb67bce2339adf9a908d226a5b338f74fa5db4a8504cea4e785c8f03d9acdd5a358bba70cbf1c633655e08a937305066d8cabb8198a0871acf035a412930d367c5222b37a819cff91947f986c55edff51b2380588ea734e453ef8c515f97c6795c8e25de79d25d9eb41e6683b6e24cebcb372c3f19321cfa7469870a6e410010a770203010001a350304e301d0603551d EAP-Message = 0x0e04160414baa2501fb648ce Message-Authenticator = 0x00000000000000000000000000000000 State = 0x761f94dc751b81c1389e58c98036d07f Finished request 44. Going to the next request Waking up in 4.6 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=151, length=199 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020400061500 State = 0x761f94dc751b81c1389e58c98036d07f Message-Authenticator = 0x9cf6a18d92fbce74c557c2aeec86317c # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 4 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] Received TLS ACK [ttls] ACK handshake fragment handler [ttls] eaptls_verify returned 1 [ttls] eaptls_process returned 13 ++[eap] returns handled Sending Access-Challenge of id 151 to 10.0.1.254 port 1025 EAP-Message = 0x0105040015c000000c573f2efdfa4fee6ce894bef51ae1301f0603551d23041830168014baa2501fb648ce3f2efdfa4fee6ce894bef51ae1300c0603551d13040530030101ff300d06092a864886f70d01010505000382020100399fd531e7af489dc26dd1fb956d857530d63f1675eb72ed55f92fe4b0914f92335c418b3b1974e9f59da7b2ed57609f7afd99b4eed6efe8e7c736aef94f414e3348ee64d9433f2d484c011b9a7f43e5fbd97b37a2a7810e3ab37469f51264b5ede9a3e47bd60a7ed438b8bf2603c03b1290c0819b8f485f97e012029a1712e0b4adda8f6e69f409897c0e08f6484d80b92830a976115fc9a27b3701320e49849f1a17 EAP-Message = 0x83fb02351233fdaf0597f648cc306f0e28502465193ef8665da49b84c15d4fd4cf32d2fb510907638fb6453b5176b1047366b9c9a9d4583e139d51390236be52f79776f1b0160439dfbf39d6b49ab6677034398d0c34c5d33db7d04298ea97f034aedcef56b0bef88ff3eae5a452f3e152e1883d05ca35be380bbfed2549f380e758ec5c9445651367443b2a1cdb93139ed7e944b6dfabd796e794ebf62b6755f54978f1a12911ad6f5bf358de8b210bccbfccccf5dfd1539ce1b85f478331a03df27b2c4d06b1a48fa708fab13acdb5e6c453825bbd47c6c06f3692a7fd3332eb5463a279bed9a3d3d3ed7205652df474cba6bb81d4337ae231b58775 EAP-Message = 0xa63da01d1e050cdfd5895bd8c1606cad391c373badf0bb76fcb1a658ff1db760f65b6064adfdb33150537e839789cd430360b983908082d45abaecc38bde1179c83da08925438b7134883807cbd6f11f1ade5ef7b3c9cc19058ab4497ca706a6160301020d0c0002090080d0d6b54e7f02a1f12b53d11521a2df0f47df59ba4e72828003bc47d4fe2ca20295bde105d30e7455ad165507b5a71caa9e4dbeab3dd7442ca803afe3eba4e661dc2a84bc717ea92750d76c663186702f275656b7b31770f9492b41fecb7cc2e2365235bb45c188e5cdc8c77331912903f2d2c42f27e86a5146827964cd4b70ab000102008036dcbe879d2416c5eb1cf77cac EAP-Message = 0x73932f4176dd4e5a44a071d9c8bbe29698f1135ebd07b893dbdf58f5abb1c5b5d8cf894098e66428679cd39160bba67909cc88a1fbaa6d072b56df34e9131d764c45b0781c39d85ab6d1feaf164d9f103d2a33838735a6c09ebf0e2a0b2a0a47dc8d5cc82495db6e282c6175df054a1b07cf9f01006f8294da73d8931de354f423195a96a99b46ebc87ba4a3bafae3daf7ca6b625a061ec21a3ac17384107d0bdb64f91014edef701168e1819e9dba9cd20589abca5c87fedcdf68ed2244d8705138703ebb7b97e3fc37aff3b0d3bdf4358c9606a4f441576bd83784383bc42d48c19165f50bc2367451d2c83f9c5ad0904dd4d036312b6517804ab51e EAP-Message = 0x696b2fd0fd024afb51a530f1 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x761f94dc721a81c1389e58c98036d07f Finished request 45. Going to the next request Waking up in 4.3 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=152, length=199 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020500061500 State = 0x761f94dc721a81c1389e58c98036d07f Message-Authenticator = 0x4b0d6bf2e3c31ecba4d67a116f44cf08 # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 5 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] Received TLS ACK [ttls] ACK handshake fragment handler [ttls] eaptls_verify returned 1 [ttls] eaptls_process returned 13 ++[eap] returns handled Sending Access-Challenge of id 152 to 10.0.1.254 port 1025 EAP-Message = 0x0106007f158000000c57bcac2060ce3a7be3428c6509139a0d9f517755693f3d1e03ca4abcfc9f8c0c2a8cfc8c3a07321278d8adc562b3062800465fb4101e710b97d059e382df96beb1f02ea7bba99b9dfc64fc811e47624864d9c02960d032b88ad82c500bff4033b05b66b410940bf28b1ff46d7b16030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x761f94dc731981c1389e58c98036d07f Finished request 46. Going to the next request Waking up in 3.9 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=153, length=401 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020600d01580000000c616030100861000008200805c39448d5e1adc9473099da6f3b5e977eb4b6c228b42aa0025fdbdfc12e1e734c501144bbb819bcffa06e93063c8d81d2beb8b7bb708c8fecc30583848552f62b6cfdf03e4dcba79783aef1bcdc1ea35e508dbbfb0c686d2c77cd2a1f5ca6176136c69dc18eeddd88ec2cc148884fb6a1ab1c6f239dfa14d3bfcb099dcda89fe140301000101160301003063bdc079d511f15b530d36bc81f9f01f59d815f5145d98788c1e35dfb18d828361878373ae7a4f4608fe50e0071abfb4 State = 0x761f94dc731981c1389e58c98036d07f Message-Authenticator = 0xfa7e5dc46932d17158f0fb5364793a71 # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 6 length 208 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS TLS Length 198 [ttls] Length Included [ttls] eaptls_verify returned 11 [ttls] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange [ttls] TLS_accept: SSLv3 read client key exchange A [ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001] [ttls] <<< TLS 1.0 Handshake [length 0010], Finished [ttls] TLS_accept: SSLv3 read finished A [ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001] [ttls] TLS_accept: SSLv3 write change cipher spec A [ttls] >>> TLS 1.0 Handshake [length 0010], Finished [ttls] TLS_accept: SSLv3 write finished A [ttls] TLS_accept: SSLv3 flush data [ttls] (other): SSL negotiation finished successfully SSL Connection Established [ttls] eaptls_process returned 13 ++[eap] returns handled Sending Access-Challenge of id 153 to 10.0.1.254 port 1025 EAP-Message = 0x0107004515800000003b14030100010116030100308bc073fb3c44054ff68892a215cd7ca55c5b7a696ecabcc664ded2883c400f5ec132d4d107271be3002b8018c09a77dd Message-Authenticator = 0x00000000000000000000000000000000 State = 0x761f94dc701881c1389e58c98036d07f Finished request 47. Going to the next request Waking up in 3.5 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=154, length=309 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x0207007415800000006a1703010020e277aca30a7252afb157379c5f561322e844f05a3f5e6e4aaa0f78f38a40ef4717030100402ce22f92eceaff1915ecb76561fce1ae518aaa3e26e9df62908a7a3fbd2c96c55430c8edf09840a9abe7cc15ad64c2d348f721b6874a0f125eed7cb83766834f State = 0x761f94dc701881c1389e58c98036d07f Message-Authenticator = 0x425f940358452267ee6fb7621b1f31ae # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 7 length 116 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS TLS Length 106 [ttls] Length Included [ttls] eaptls_verify returned 11 [ttls] eaptls_process returned 7 [ttls] Session established. Proceeding to decode tunneled attributes. [ttls] Got tunneled request EAP-Message = 0x0200001101303030303030303030303030 FreeRADIUS-Proxied-To = 127.0.0.1 [ttls] Got tunneled identity of anonymous [ttls] Setting default EAP type for tunneled EAP session. [ttls] Sending tunneled request EAP-Message = 0x0200001101303030303030303030303030 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "anonymous" server inner-tunnel { # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel +- entering group authorize {...} ++[chap] returns noop ++[mschap] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok ++[control] returns ok [inner-eap] EAP packet type response id 0 length 17 [inner-eap] No EAP Start, assuming it's an on-going EAP conversation ++[inner-eap] returns updated [files] users: Matched entry anonymous at line 47 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = inner-eap # Executing group from file /etc/raddb/sites-enabled/inner-tunnel +- entering group authenticate {...} [inner-eap] EAP Identity [inner-eap] processing type tls [tls] Requiring client certificate [tls] Initiate [tls] Start returned 1 ++[inner-eap] returns handled } # server inner-tunnel [ttls] Got tunneled reply code 11 EAP-Message = 0x010100060d20 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x8ffb87098ffa8a38ce217d93eaf46dce [ttls] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 154 to 10.0.1.254 port 1025 EAP-Message = 0x0108003f1580000000351703010030bcb4c7bdf42078e61e6f63f53e998ee0b34de3a872e2a5557c55e54a9504c220130bb0682513d40d444fdc662e6ae4a3 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x761f94dc711781c1389e58c98036d07f Finished request 48. Going to the next request Waking up in 3.5 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=155, length=421 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020800e41580000000da170301002054f684ef417c190834493fa41656d4ab37a98c23bb2671afe611bc030bb3e50b17030100b0652320857a88f73b92201d3f52e5a5e56ae75e90be6cea591b2db17485cf858d634810a4c696a2c750a4dbeefc1bebfb13aefdc2bc74cad9a6875ba3a9ac9d7e89606c5d25d330ced0b3cea0da88bc4df72822f2be67757a600ddb8d49cfde1657f371886d6b1edcf3f66ac609aecbf2845676d2dac6adc5f843d2e7ca81503264a0baa0cbf36abd994758b4a22b088808c2ff870ca8376fcff6bd8a2a74ba102eeecbc229ba9b586c6ce264acddd0fc State = 0x761f94dc711781c1389e58c98036d07f Message-Authenticator = 0x3d8ebc1962b4e2ced1d627184f26397f # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 8 length 228 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS TLS Length 218 [ttls] Length Included [ttls] eaptls_verify returned 11 [ttls] eaptls_process returned 7 [ttls] Session established. Proceeding to decode tunneled attributes. [ttls] Got tunneled request EAP-Message = 0x020100890d800000007f160301007a0100007603015f12fd9e5afbeb33a851e5cf0eec68da09bcefef5b2dbb9d4d979f9cffc0c1a2000048c022c021003900380088008700350084c01cc01b00160013000ac01fc01e00330032009a009900450044002f009600410007000500040015001200090014001100080006000300ff01000005000f000101 FreeRADIUS-Proxied-To = 127.0.0.1 [ttls] Sending tunneled request EAP-Message = 0x020100890d800000007f160301007a0100007603015f12fd9e5afbeb33a851e5cf0eec68da09bcefef5b2dbb9d4d979f9cffc0c1a2000048c022c021003900380088008700350084c01cc01b00160013000ac01fc01e00330032009a009900450044002f009600410007000500040015001200090014001100080006000300ff01000005000f000101 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "anonymous" State = 0x8ffb87098ffa8a38ce217d93eaf46dce server inner-tunnel { # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel +- entering group authorize {...} ++[chap] returns noop ++[mschap] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok ++[control] returns ok [inner-eap] EAP packet type response id 1 length 137 [inner-eap] No EAP Start, assuming it's an on-going EAP conversation ++[inner-eap] returns updated [files] users: Matched entry anonymous at line 47 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = inner-eap # Executing group from file /etc/raddb/sites-enabled/inner-tunnel +- entering group authenticate {...} [inner-eap] Request found, released from the list [inner-eap] EAP/tls [inner-eap] processing type tls [tls] Authenticate [tls] processing EAP-TLS TLS Length 127 [tls] Length Included [tls] eaptls_verify returned 11 [tls] (other): before/accept initialization [tls] TLS_accept: before/accept initialization [tls] <<< TLS 1.0 Handshake [length 007a], ClientHello [tls] TLS_accept: SSLv3 read client hello A [tls] >>> TLS 1.0 Handshake [length 0036], ServerHello [tls] TLS_accept: SSLv3 write server hello A [tls] >>> TLS 1.0 Handshake [length 09fc], Certificate [tls] TLS_accept: SSLv3 write certificate A [tls] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange [tls] TLS_accept: SSLv3 write key exchange A [tls] >>> TLS 1.0 Handshake [length 0062], CertificateRequest [tls] TLS_accept: SSLv3 write certificate request A [tls] TLS_accept: SSLv3 flush data [tls] TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode [tls] eaptls_process returned 13 ++[inner-eap] returns handled } # server inner-tunnel [ttls] Got tunneled reply code 11 EAP-Message = 0x010203800dc000000cb5160301003602000032030152fa57ab2a2fd6841821e126ac6511783c3f3f168808dac332240be8a16b604c00003900000aff01000100000f00010116030109fc0b0009f80009f500047c3082047830820260a00302010202010b300d06092a864886f70d0101050500304e310b30090603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d20446576696365204341301e170d3132303330383134333730355a170d3232303330363134333730355a3040310b30090603550406130255533120301e060355040a0c17 EAP-Message = 0x4361726573747265616d204865616c74682c20496e632e310f300d06035504030c0673767239393830820122300d06092a864886f70d01010105000382010f003082010a0282010100b76170da326c4bcef5c64402d66566b7304e83d3ceeb33aefe0a63037d8441aa10bf72a2e011dc859f65f544bd2fc152e1476d62d0cd735d0f8cb6e47b4620438b9004e66f88504c7ffddeb11f27ee46ce0c2bd84d81db792252fa71d7a83408de900afbcfffd7251aa702a2345d7bc5aba0d762d6a2ad23af0098043482c8897b2faf91ab0f5d8312d5af33796884a4ce52e28cd3d345ea48113b2662c3c3081b1f634e3801b8e52fb6bc29c17e8a851b3fb44f EAP-Message = 0x88ead4013f140c10818a9cf80d1d9d5375d5552a403e71f10412774bfc835162ecd40bf7d98f8e1127a5be8a0bed7829fe0636f4f293537646ca4bea3d5152cf78cca369e58cb94b91e1269d0203010001a36f306d30090603551d1304023000300b0603551d0f0404030205a0301d0603551d0e04160414a099086e62bcbca450563c4c0d0d1a303c1ca52e301f0603551d23041830168014f4638fe7f1bcfcd00e02e0a3387e5ecfce60663030130603551d25040c300a06082b06010505070301300d06092a864886f70d01010505000382020100633588e4eaf0e4e090b8ff48b1ccf651af706f3d080149190166d2a325a01fa44360c26da30852 EAP-Message = 0xbdb26b21401cf6d789c83d725c3affa9c7a2954349a249868c2c607b6a5b586dfcdf091929e9d15a0a1ecb0c6cd092cf7883d7ca795a5125a5ac1ca78f9f01cd3fc1d1d492dea54cba85a87bd087fcff5d7acaeafe8899a1523b63944eba4c1624833e9d93e8fb3092faebf5bc664c95719436e6c957019a91ede0e8e2fb3d39b0ec9e56810b19167a Message-Authenticator = 0x00000000000000000000000000000000 State = 0x8ffb87098ef98a38ce217d93eaf46dce [ttls] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 155 to 10.0.1.254 port 1025 EAP-Message = 0x010903df1580000003d517030103d08200aef0fb3b2f70d5ac4051ade8cd61c9ed710ce8797568fd055dc426630092062509afbe5dbcbfefec3c10de05aafce1439f9ecf1aa677e3e0053b0ce09f561c1dedd394f6ab54e88105caa4b1365b53b6f8d0b036e3ade1efcf4708a29a48c27b7663e7a8d841c156501e74d081168928572b50ce275827330c52195d23cf1c6b98af7fba74b5a502ddf1a0e10c655d02ca9246837e5f9879504b5b065e5d33101ac61c576c3558a37d3579d6d964352832d7c56fcdf3863a32892efabe0e138c6c89905c2f7f46f760b5f3b50c5304a142d8b6a20478660c6bd056a56ebef1496ea42417ebe48b1ff03a5074 EAP-Message = 0x5853b1132680fa25d2ce3bb8e46d510b3a69fec0207d53ca69c9c991d489739343162e9a3d14c4acb2fba4991225d27eb5db98cbbdb868b253a78f0a78e0e53fa145a11d8ae163218d3e52ec84621e2bd02f0f0e966347bd1fb7b1a64f50924b06eaf81ef38ae9210e858095b02d94f9235dba866902718dacfc1db528166cf1db8adc84679762432c8eac56a21b1b0a4ff3cc7b6c0ce20d72cb103e251f00d8ae78994eb540fc4f085d365a16b25e88f60171120868661513967bfa531979a0cf019a7b1904178b2c16cc344cacaf611672d9112ebf35c82ac5dbb3e6fa0cbd498ab65a386f0e9eed8c4a90f92b309f5634534b64a0ce8e239362464d EAP-Message = 0x2f7083f241e625e7faf233fbd6724189aa28a73aa1b6ce292ea6378a54b495dd9652fbe666df1c9b1fb4ff74832825c26f3cb6ca807382a99ed3c53c1be97522f05310b0679a405aa60f78f6e09dbdffc811d90cdb2c72672d5691a8abeb25e07bfc1866737bc831d4084c8090499accd865b7662a9bc9def6d8605319a0b02db9755fb279ac09846240035d5467a86209c3ea1accaa89e68fa7b83be9991ec5c4087ac4346ccdcbbb1f152445df03c1fe495130548e56e9a59689f6d12ec302b9105bba91ec2612cfd2a9f0a90120f818b5a64ceb79eb38405edffa190a4d2064fa2c4dcdb6e322f6c2f88f5b98ff143b3870399e489b18a99056c820 EAP-Message = 0xefe1e63df3af4ab06fb5ec72081e4bf1cf790dccb3da9a90360b7074c996ad70b2b7d0b40f0335dbe27d170c87c8815d5aaf6e9c452bfdd1753c7fa6d1dae36588ea8d850e7397df1a39a77a845f93c553936922e4f758e68451780b62942cc4e763e7b5805c8a78150d6658267da5c778be7ddbc5c4019d32d1304cf52e503d0c8816274736ad8a1c890364f9b2b8a3442895a06d3fcecef660638d6ecd01c27e2ce3bd88b4da14cbc9cb55f6473254e880587951fc7971a3a64cf5ed55eb2579003c5148bd5277873128afecf88af4c0e7ca22795b4dd5871d90938d2ae4a2e149a910a31d4044 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x761f94dc7e1681c1389e58c98036d07f Finished request 49. Going to the next request Waking up in 3.2 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=156, length=293 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x0209006415800000005a170301002008fbc5352c3ae3acc15cdad51302d1287863876898c671d62ed7e35bb05d89011703010030632c786d4a84019d484665bcb6f17f7b0a3c74dd64e7e19d8f7c8cf02778eccbeb377fe8c02a47c6e1590022aba6927b State = 0x761f94dc7e1681c1389e58c98036d07f Message-Authenticator = 0x5d251aa722847d535f92fe5ea2dd8279 # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 9 length 100 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS TLS Length 90 [ttls] Length Included [ttls] eaptls_verify returned 11 [ttls] eaptls_process returned 7 [ttls] Session established. Proceeding to decode tunneled attributes. [ttls] Got tunneled request EAP-Message = 0x020200060d00 FreeRADIUS-Proxied-To = 127.0.0.1 [ttls] Sending tunneled request EAP-Message = 0x020200060d00 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "anonymous" State = 0x8ffb87098ef98a38ce217d93eaf46dce server inner-tunnel { # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel +- entering group authorize {...} ++[chap] returns noop ++[mschap] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok ++[control] returns ok [inner-eap] EAP packet type response id 2 length 6 [inner-eap] No EAP Start, assuming it's an on-going EAP conversation ++[inner-eap] returns updated [files] users: Matched entry anonymous at line 47 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = inner-eap # Executing group from file /etc/raddb/sites-enabled/inner-tunnel +- entering group authenticate {...} [inner-eap] Request found, released from the list [inner-eap] EAP/tls [inner-eap] processing type tls [tls] Authenticate [tls] processing EAP-TLS [tls] Received TLS ACK [tls] ACK handshake fragment handler [tls] eaptls_verify returned 1 [tls] eaptls_process returned 13 ++[inner-eap] returns handled } # server inner-tunnel [ttls] Got tunneled reply code 11 EAP-Message = 0x010303800dc000000cb5f57cc0140449bae0b3f0fbe6feb4aa2119ddcf7cf9c82cb830b9d97943ae20c9a2c28df58e6a3cf9064d68203a73858dcc2455b827199199f2705a4f52c4931feb6a04496b15dcf9936996b90977167140475734fc8447b952a564dc73c2bd6a5146ead281a845b3046297845fb323fd7050a6d3f049d0d20dd2e22b980edb5da743adb1ca429374cbd34aa953ddc6615ca92f250ffc13d0ce8594d6e370e2961ed256eba43cba54fdce0a729b4fcd7de584f891ed4f799af530a855ef1c1862f4c9de40dde31369a15792a23bbd73dba235ddd74669ec807f48547f1422aba3bfcc89234c0fed5d151fdafb29b19829bbb67a EAP-Message = 0x281f561721450d5b3d03b983d73137fdff06ca0b3062f6a2a6e0286479c6f327ff54fc19a4fe0283c53d6cd151ccfd25e5e96cad3568119d2d711aec91291649709d77cea8abc804e673e4ec168a844b1312158c0eba53ac455e9d5cd20005733082056f30820357a003020102020900cdd24c0540e41aa7300d06092a864886f70d0101050500304e310b30090603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d20446576696365204341301e170d3132303330383134333433395a170d3232303330383134333433395a304e310b3009 EAP-Message = 0x0603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d2044657669636520434130820222300d06092a864886f70d01010105000382020f003082020a0282020100c15110872e2e4a5740b2806926c2a8987dd7aab026b7ef0d2eff5321d107c6fdef6ba3e2380f7e7327ecdde1de555a61c300e738206831313edff00753619e76aac958bfcbabb6139aeed98a6b236c4877befb74390a7b73872cab14a974e3c039b97b98dde3cde395b74806a81ade977ec12bfa3d8796b175bc72556c62f3c6242eeb1fe0046f6ef423a48fb2151ac753c3 EAP-Message = 0xe46525ec5715e8eb6cdc235e8c0c40ff219999b616a88feb3d878fa4ba057004dff8709d028fffe2e088f30b1102f873529a1422d612450cd062130ac1b13c1af3e52ef94d75583a494fc733b851109c0c8f1c03f9d96aa9eb7b3f4c31b342c9640c3df94e9bbe833f8dd984befb55e7bec0664efb09769b23cfe7b3e36a1088f03ec961981da5216d Message-Authenticator = 0x00000000000000000000000000000000 State = 0x8ffb87098df88a38ce217d93eaf46dce [ttls] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 156 to 10.0.1.254 port 1025 EAP-Message = 0x010a03df1580000003d517030103d03b00291e79190901cf469987a7f843defb8ed1a2e1a28d26c9ac28d35b5a2401cf16082c122634f17ea75d7c2063cee2d9c4ff8c41f2443bc4b5c7db2b6183e55a366799bb794955f7817e9811654251dc184e78a711f31316d385aaef27b24817dfa73e35656acf123cc069c428e6a59c51b04c5b5149bf0aae76530948b0a955338210a149c6d243549d0b1c8133df0e9a402e33fa8966a1948a0c0048f5ced07bb92a188feac85499b592a9214c9b032d23d86a169ebc55af408914fa1da79f8b9811a48a842e32e4a2b91d064d202de2433ca04bb7b5ee40831d76c5209e0d9238a5a9065eb42c70d52be511 EAP-Message = 0xc5637c7db5d79acfe6b0b42fe7e8e6c4c6080ec9fc454b6ea79e22fd8133ae74ebd67b3db050f4d485bba4985987364ecebfe0f6f319a6a63fed6432e447eb4988acb2b52c7d75d646ca3b5cb9da52635f3203aca6596098280cdcd2fdf6bb53451efaeb1a59558e652163ac481308e42be15182dd8259eb3e6814c9d9ecd66d57bca4e583d5534f11cf7aa6941bae7bb7001b7c5c5603d7264e947043bd249d2026afc6bc1095c625939763fa8365561f29e7e2084f365c1974a5b70a669c2968d484036dfef6077ce4ce05261b13781eb3d796fa4e4362586022121340404ed1a0416ed362ffd448eae4b03f0934664221043573979292dda7bed81e EAP-Message = 0x332f25c746b9b4f65b20fdd93a6c725b11d386f63f1678b5c927c34e913a826dfa6c73fe8d75218c23911407b9b15312692ea347ca3b45e1d01961192d222e51cd0d9ce800d568ed4886965958bb92251c0b83ae51edceb85ddf8ed110eef39ca2cf5939b1ce1a8e935f19c5155db158f798448b48fa33c25bb1967b9f31535b433b16ce11c6136b88fcc8b657bb9244faba4c6a6f5fcbf935edc52df1071edbe780997fce75d82295894ed460591a82c27ee76964c5263b9af4d8b7280fa5afb4329a9ae26098143b8fc28cc4b8601298aec61746b40a5a16c9b9626a331fbb49d23ef0a4691821d4b06a6bf5ab2a8315dce58f50ad2847feff10fdcf EAP-Message = 0x94adbc038b6819ce53bc258897d6ccd6b9e6547c2a1180d5d10c97939ba69fcb0591c028c15710f191725400f21f4a1af3c4d9d39c6be5cf265f560faaf82f818f13599ef9e81e354621228e54b5bf693de42772c51521cd99b55abbec56cb067db505ab9b1c248d81e7dae882aa7d357e344b266c6b5b1030ac70551943efa6b08654b7864edc918f277cbe6d9b9da38ebc2888eec11b738744d762e48b52563ede85361d5af53232f4b2bf032f6f8517d0bce703401bee2640cc5c2eeecb271b96bff9be7c0f281391643bf366aeb9853ef2ccb14090cb98189d85e121967c4e034f7f3e0d09bb Message-Authenticator = 0x00000000000000000000000000000000 State = 0x761f94dc7f1581c1389e58c98036d07f Finished request 50. Going to the next request Waking up in 1.8 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=157, length=293 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020a006415800000005a170301002087325f201a8ce28867d4d624b06f91bae623bfaf69e425181a12402cf3364deb170301003062d47d61e49b407e61440407c311ef5250d4b7cd4f16a8dc89d998737e1413276cab1bcc7eee5c5ca698364e7ac8e6b3 State = 0x761f94dc7f1581c1389e58c98036d07f Message-Authenticator = 0xa2d396b72ed793f0a509ee0d8fd0544a # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 10 length 100 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS TLS Length 90 [ttls] Length Included [ttls] eaptls_verify returned 11 [ttls] eaptls_process returned 7 [ttls] Session established. Proceeding to decode tunneled attributes. [ttls] Got tunneled request EAP-Message = 0x020300060d00 FreeRADIUS-Proxied-To = 127.0.0.1 [ttls] Sending tunneled request EAP-Message = 0x020300060d00 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "anonymous" State = 0x8ffb87098df88a38ce217d93eaf46dce server inner-tunnel { # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel +- entering group authorize {...} ++[chap] returns noop ++[mschap] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok ++[control] returns ok [inner-eap] EAP packet type response id 3 length 6 [inner-eap] No EAP Start, assuming it's an on-going EAP conversation ++[inner-eap] returns updated [files] users: Matched entry anonymous at line 47 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = inner-eap # Executing group from file /etc/raddb/sites-enabled/inner-tunnel +- entering group authenticate {...} [inner-eap] Request found, released from the list [inner-eap] EAP/tls [inner-eap] processing type tls [tls] Authenticate [tls] processing EAP-TLS [tls] Received TLS ACK [tls] ACK handshake fragment handler [tls] eaptls_verify returned 1 [tls] eaptls_process returned 13 ++[inner-eap] returns handled } # server inner-tunnel [ttls] Got tunneled reply code 11 EAP-Message = 0x010403800dc000000cb5ec415c7548aa7c51315941ee74c7c4e21124581dd8a3b7c4831877cbea385ce297c87149c7d1240f1d875875891bf1018a2be82bd839bf7516e693ae403bff49731aadbd295b96f062caef2565d0107954809f92d89b786787b712a0360efbe34c0c926a568550642de96d84940b2996b05873c2635786520315a3fcd9e79924f7b4b81d4ebf751ca81b810ddfed5f016bd0befadf29863d0ccbd4cdfccc3c3b69c831ef10e11b66b563c2f04a31bf743ee3896b2f052806fd0d0b21604023707f5cac625ca44f32b346d8f7def63c2ec1cdc75037bf8a82c3d26a8a0124010f7acb8d33970203010001a350304e301d060355 EAP-Message = 0x1d0e04160414f4638fe7f1bcfcd00e02e0a3387e5ecfce606630301f0603551d23041830168014f4638fe7f1bcfcd00e02e0a3387e5ecfce606630300c0603551d13040530030101ff300d06092a864886f70d010105050003820201002aedad2a256b0fd6d3f11f74c30f1ed9652c8d82bff6779c09a32d6dea2fb9febd4525b7b3105b13967c3b5d5d61745264620c312d6fce405dd4ddfe4b72abe7e0d2c475b99133294a5cc91c4c328624bed219d73e62dd222b3a76f2de154114ae1e0b7fd615702ac7e1bbc30abf603258daa805479ebec4d0bea30599881df284a427dcf4396efda6122e65c265df815593f1224194deb4d4fe52d86337fd4e EAP-Message = 0x59331b5d3d0a40effc7d49a1a7860f7dc6d67ee31df8d30780f0dcf1353ef7b892d2da1aa70c436e9250dd9aade9ce5bcedc64cc959be7965ea227a8f1512e794f06e30e1294f314b6ae77ade19c0d73600259c4c7942204d7b58843bd9a65bb28657ae46cb4737c26a00421559de2e0e9613d29d20d30fe65fb2283b1d650092fbb8c62c5b091aec7fb64ff3c65487de63740c93c4adf2253abd0c4ae3afe09298ac0b468c0290130f3a1c08425dee9b7ca0004fbb32d5f4bba7a2517b130308b537fd0cde88c6cf035cc6c9581d2138c17e3187a6a926983dd64081680c56a57bd6696e18fbd28ab9a9ad54578d0bdeb1ffa28bfa39f6fd5acc6481d EAP-Message = 0x66beb3d335c77c76994fc91228198746f6133c9d3b435df2daae2a114bf7641b6298cbd23b52606c26832285ac539dfb2cfc362ffa520c374a44ad55584edb2505ecd417ad985065cc54a7a2bb4f5dc39f70bfc35fe207de3a79ed8c4bc4d30addb818160301020d0c0002090080d0d6b54e7f02a1f12b53d11521a2df0f47df59ba4e72828003bc47 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x8ffb87098cff8a38ce217d93eaf46dce [ttls] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 157 to 10.0.1.254 port 1025 EAP-Message = 0x010b03df1580000003d517030103d0c2fabef7808c1df30b72895545c41d2f0a433bbc1b792433fe42ecd0ca7cec555f0303f88eb9579944ac935f327322f2083da502c1ce24eef48be8c5ce900a351c8aa4475cadfac53880bfc96117af0c72e82a0a73d787af96e65ae4e232cd97c43e3bc4c599728af435def711e8aa3234d68a6d4211da252f47c7572aeed4e72421787148e9ee99803d7c5caf573a4bde4cb7f0245f5dbb381c6e1c74c3f5f99fcc1df77c9ce0292014c913104a6df483301e9cede488c6a5104db080b7f41271259c5eb92d9df5462f1e32d791e95837d8ce082b38bc12819128d783c28e50f98ea3ed200c5c89f37d49b1c0a5 EAP-Message = 0x2b9f7b5f42c67ca3b352e70f90185a96ac4400acd727d7b08dd844dd53dde4e2f36f9ebc1cea9e6c4c3aa4895aa63574ef34e78aa02b18234286cd9d31ebb1cd185b36af1eefe9f3967eec66161ba4d0ea0be615356d528221c7f6ff006e9c185ff3d32b5fa0e82eeaff6c5b8c248964ddd29a1733c7301ca37c3f2fa7483e5eb4bf401b89c73beb6fca94e9d864877f683ed29b89dc6f357e3940d26f7db6a1a7c468b14323c4d1bc5490d70babd942d6931561a05ddd53b41e594efc1a00954f8c78de67a703accaa26084e578a4d0d81803eccabd4880a95f24c67f990e2b338c01dca7028a67a6469e3317234f7d0b6a8bace2c108226eaf451ad5 EAP-Message = 0xb383a6a4c3c6027dc36f694d2e92cce86a36097d6f6792effbef8eeeb52fe6c25866f042529c2d6ef787c003445e484b089230636cd844254a8a19ea8da85ebf4bd9c02102f9b230adb924bba39c52af9910619cdd38f38a7cec698d6634ec7dbb80b1bd362f86207302c24423aecf64154ab944ab30600e0950cdddba836cc19fe7569dec7802ef86427bf21d8b3d02e320168d37d67d532a704eaf511428b3ecf858dd37af46f551712958b2d1962c93dd2f0190f821ba8525b9a005c1eb586b4a4f9cda5ea36a36a4ea01bad0ea36dd5c4b116cd6e72972214697858b58e52499da73fd721a61a6246111c0b331d6d2ca69b57534824527d092c53a EAP-Message = 0x0fdb6fdc12f292c0c1fca33064dd37d13c02a2cdc66b7cff911b0a3305ef883a161057f0e1fdab820cfddea475b06b825a6d7653e4c83216fa6c351609a8e703468800d319afc8ba4959b585ee6f81aa20086ad4ed663ca0283e369b1f40415b4c1f656504cdd2216e0e6bb1a61d8fb9cec0149ed2e74bb9727d855bda12d8e061e42c5f57b66ff921392ad24d2c28026c38f841ad332c82f9c83ba3d8108fc67725c944a0cdbb053fd8ff45a0e5b862fa9c3c69eecd3138f5dc476317b752f27ffdda5f9dcc7438fbe56c708126bb5c54b3f2b77f972c848770ed4b5e42ea5749464ec9bce46a85 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x761f94dc7c1481c1389e58c98036d07f Finished request 51. Going to the next request Waking up in 0.8 seconds. Cleaning up request 41 ID 147 with timestamp +2390 Cleaning up request 42 ID 148 with timestamp +2390 Cleaning up request 43 ID 149 with timestamp +2390 Waking up in 0.3 seconds. Cleaning up request 44 ID 150 with timestamp +2390 Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=158, length=293 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020b006415800000005a1703010020725c045571549f2efca53c13f5ecb4fb0b5175f64e5653b27887e4e78b25cef51703010030365526c1bf9f20fa9866f3c39857931108948794d84491a364880958d71ca1518e4686ee8fae0fb0cf3f1b2039de55bc State = 0x761f94dc7c1481c1389e58c98036d07f Message-Authenticator = 0xec5cb4cf863e261b285b3eebbc84a7b7 # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 11 length 100 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS TLS Length 90 [ttls] Length Included [ttls] eaptls_verify returned 11 [ttls] eaptls_process returned 7 [ttls] Session established. Proceeding to decode tunneled attributes. [ttls] Got tunneled request EAP-Message = 0x020400060d00 FreeRADIUS-Proxied-To = 127.0.0.1 [ttls] Sending tunneled request EAP-Message = 0x020400060d00 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "anonymous" State = 0x8ffb87098cff8a38ce217d93eaf46dce server inner-tunnel { # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel +- entering group authorize {...} ++[chap] returns noop ++[mschap] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok ++[control] returns ok [inner-eap] EAP packet type response id 4 length 6 [inner-eap] No EAP Start, assuming it's an on-going EAP conversation ++[inner-eap] returns updated [files] users: Matched entry anonymous at line 47 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = inner-eap # Executing group from file /etc/raddb/sites-enabled/inner-tunnel +- entering group authenticate {...} [inner-eap] Request found, released from the list [inner-eap] EAP/tls [inner-eap] processing type tls [tls] Authenticate [tls] processing EAP-TLS [tls] Received TLS ACK [tls] ACK handshake fragment handler [tls] eaptls_verify returned 1 [tls] eaptls_process returned 13 ++[inner-eap] returns handled } # server inner-tunnel [ttls] Got tunneled reply code 11 EAP-Message = 0x0105025d0d8000000cb5d4fe2ca20295bde105d30e7455ad165507b5a71caa9e4dbeab3dd7442ca803afe3eba4e661dc2a84bc717ea92750d76c663186702f275656b7b31770f9492b41fecb7cc2e2365235bb45c188e5cdc8c77331912903f2d2c42f27e86a5146827964cd4b70ab00010200809453f07e77c20e39e71a85f4e49bbede2a27540093957296fb7e8227ec1a5580d5f55935aeb36fd4897ae3b4299b93b85c1c2418b49537c8a46c1289ac6405d094c29130e302c1db50b6738feb776b01d0eef77e193020f1a989496d3cefec9797c47acf0889516ed8837c7fa88d2eb05c19b3714293b55399ccb3f09726c26401006c25e34d03f302 EAP-Message = 0x01ba22522f7ac4028f28cc061a708ef9fa9507c656ad4c924b84984f412524fdcfa08eb619a386f5e9d9213494a8bc7409993cae4bd6b361174703b031056d7594b371569b45ad0d162a133e94705e637c966ff6d7887882bc17e73b250bc28ea1ba6e3aa890c1e9db3574e83cd28f5ad878748fc1175356de5eed25a66d7184503277dfc2e49bfa9db21161dd750a70d6c99c6dad9b349f9620e97326fcc22734b1704d816bbde328982af200b687298771977f99fbe407c98a9d909df26bca0a9928cda3676f46899766ac56cb5cc5e74c1c7d36b359b4b6728bbd4aee7243a34ce1008300eda5a24d0cfcdfe0138ebb56cb0e24a0e7d24216030100 EAP-Message = 0x620d00005a05030401024000520050304e310b30090603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d204465766963652043410e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x8ffb87098bfe8a38ce217d93eaf46dce [ttls] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 158 to 10.0.1.254 port 1025 EAP-Message = 0x010c02af1580000002a517030102a0100719a572f72047eca3918e647cd68db7b89845fc5032d1082f92a9f93e9c38ef5d40fc010a82a7837b8de2be1947054ab98f40051c23ead0addeeb47ee64f73146b54fa84e17a96d19d106c749f5c0f7d6b08bf1e54c997f60dc18bfccb527d7b1b80786168cf9bd600b687b09f169dc0a1ce35125ace3ce6c3e5fa1bd9af5c1a9bc3b84e0810aa698136fbcab9300bde56c9421194ced06283b4837e81b6e06496f675e5b5a2c426dc24649a1fa160f7904bebe4c9003cd691c3a5b511e004a980c2e965b5dd81b4dbb5fa85f64e1b496271a1fab20d9ac25a329b7d5f74cf3af7df94894c6facbd77e4a35c6 EAP-Message = 0x6d2ff10eed956d67e597230cad0e01a0935cb2fac5d3d597625622bcdd1f1076b28be3295ab5b235c1c9770838a10c7094bc54d937529b6c6ddcfc831353feba5b358f502a3533e3efb92c326cf6ce3864c754a01cbff8c0aeb13e6c9c8e9ae98932e2825764ca2f8fad229ce4ac57249360b425ea3cc4fed7cff3dfba1cfec3dc7b7aaaa880832a8c3584556ae8e60bb067ebc6685d15064cd29642b5f5cfbf9d122bae67a8e119d3758d237e0478baa536eeb38c542071744af9a6213e13330b9b26acc4a55b50f1a9e80245d400b7a0bb272e7de3fd72b81a31189cde80426416b4f5e66b470ad4ca032541a870c8eeb60ff21013efbac257595425 EAP-Message = 0x50ff0950ba7ebcb942a45d8fff2504b686aec981a32311389ad86583d754bc330fa774c24cbf2d544c5d0a9cdcd468711589d6ebfafcb110c66c1a7867df22a13d6029db0a45ae88e97d92c70a31f0d82c8777896d22f1c6fbb7a5be56dcb59e3dd084a3385a8ed4323cb842bbee7a83fe4652919fa687d71dd75b33465f6af8e75ef02aee28dfc556ca151e254c189b8705dd1fb5a55fd3578be18b5cefad41ce6703169b8789ceede74740ba0c200c9bcbd8cee7 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x761f94dc7d1381c1389e58c98036d07f Finished request 52. Going to the next request Waking up in 0.2 seconds. Cleaning up request 45 ID 151 with timestamp +2391 Waking up in 0.3 seconds. Cleaning up request 46 ID 152 with timestamp +2391 Waking up in 0.3 seconds. Cleaning up request 47 ID 153 with timestamp +2391 Cleaning up request 48 ID 154 with timestamp +2391 Waking up in 0.3 seconds. Cleaning up request 49 ID 155 with timestamp +2392 Waking up in 1.3 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=159, length=1599 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020c057415800000056a17030100208f2d62933be444f56030a98ace30b40c340c0fba9465a773e844374eb5c3d10f1703010540f4dd89242a6133d2394798f08cb44425e7b66eb249edd2ac7d652cadedb3ced613182e9dce19b3b1a30b59ef06c2a26747cb9ecd94c31be2ca458853ecf1e131cb5c904b1680d34dea29c5702f38a3806951b803a48ae9ba3f295670a92966efa7201954b6c98433e43b1e4b9818677e569fb8474de71f7ea02f98ba1e27da5226f1db156318f9f55ffabc8997ee20512b7a2eebf19eb1fcabbbd4718bdfa47971f3c0c88770822241a2d797cd48b93357a4982ad7eb2c0d26ca1d446c578e6f6f7271979e536c48ea EAP-Message = 0xa5c8005057fad34851362037cea053e9e8a1af55365d01418a5029780a1e65763c3f0fe398fff6ceaf0e5b5ff11a0c5bbe2466e3fc2376e5703cdb9ee1e88b61069c23d05884f96de23ecd58065027aa2a799556dcce888c24c1aa35b36cee4d3bc7e8f055e30330c8773ad75223131e4e87f3f4417503aef5ed27dbbfe0c8496b8344bdc8175527af7f665e041ae714bad49de730bd298dfd8d6d02895fa266b0af94a4d7d18e9e39764ce68ec055616dc210b12513721b7b90e48f4d12e8d5ae2f88de562f6dc3e5ee97dfad2f05d18043fb401defda59742d6feebd20641de09ff200a6a04c71e3cf3e073e5004166f4077d6338fc4d5d2ba3513dd EAP-Message = 0x50d0d76634be5f4886eeaaea789ec0f4cdd39b6eac6d734f8cad6b82c886c25d83e3ea29fb997321a11fd21d4a1305203aa1942d70b8b41442893fff1163c405c524bf208a99a475217d94929089c5dd41295f5b495ddabce16eb3f7981f7ab0206402503ecb8928b942e2d84d3a53867eb3af5d0827399a4dec4cbdbbd7eb8d62ab766365bb48ba17653b677e7be1c4ded600d125190192e071b7018d34870ecdaed9c99cd68cfc6ed5afb833c285d344a945f8fbd918ba9e14ab3f30d452b23fefb12b4640bdf8f0033634090bf082122b739dc9710ae54123ed30642f95c595fbcc6ab51eca133ba9c5f7cbf330e7be996b4cbc96175d4942a23ff6 EAP-Message = 0x2419e601c44cadcc9dd56d3f37da7f878e7d9218c172c079cc59f45e950c65a197777b8748993fd4d019cefb3e68df6b5f8e75801cba63ed00a99444899e43dcdbfd8ec0928948f419dd0c7d20b04747d7b6eeec0b2c48f798cb4d4f46bf2eadad7ce0b1c319023bee64b9160a83fab28fd5098037f1472d428dce61b64f80bc351355a58aef5b692473a5281fbbc5e8ec5c4c749afde522c33957b88529829d053f040052256d6dff7728d3a924acc12691eb7548a123819a0dce06467f5578c05d24f46e6e5313d95db48848009fa37137b8aa3ba13fd1082eb487a8321ecd7fa75c8b3efb3623bf2ca91b6556b67c8a345440196c5f2990de161433 EAP-Message = 0xfc17ea4fb385c1b1e7b82e0ddfc72b55db07116719e19077f5e1fff992a04700dd222efff91d52ea1a8df6ecc05bcfe9e42148a162ba0d2b0d224872ee2adfed1c94ed5d5052c14f5a17df542e80044797fea0b8f9f48f91639c079a999cf7a855c1043948aafbf8b57e44094c1701c8eea57f2a4ad49f54f59c001f19fa37ec3a8ef69408bbe38c5bbed07f4da54f67d14f5ad80bf59d329deedc658b99d07a86c07e0ddae4ff73be5a5aadee874954827bde51bd0d9941aeb6c50adce24e59a4f18abb7e671e2246171fcdce76228b590134970be9b9a2740f525e4222ee56cf2c6045b3bcdc66bcdc18040487a2c08abb92cc11a8e43ff14fbbfda0 EAP-Message = 0x17fa4a9ebaa1f14b16cfbcfac1ecca4aff4900d99b1580967a27b3dcf829e2fb1e4fd3a44e4d2520d9aced20be7964e25c2189ded39a529813d7d48839fbc945bc5b0c3a9a9918fb5eaab44df82da22a75b563e725888c8cd98732380b1acf03aaff2d37a5811435fc144961638292b431097e5748651833cd43fc744a390b293b51ff State = 0x761f94dc7d1381c1389e58c98036d07f Message-Authenticator = 0x50fec34474bd5ecc650245b062713045 # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "anonymous", looking up realm NULL [suffix] Found realm "NULL" [suffix] Adding Stripped-User-Name = "anonymous" [suffix] Adding Realm = "NULL" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 12 length 253 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS TLS Length 1386 [ttls] Length Included [ttls] eaptls_verify returned 11 [ttls] eaptls_process returned 7 [ttls] Session established. Proceeding to decode tunneled attributes. [ttls] WARNING: diameter2vp skipping long attribute 3005705648, attr [eap] Handler failed in EAP/ttls rlm_eap_ttls: Freeing handler for user anonymous [eap] Failed in EAP select ++[eap] returns invalid Failed to authenticate the user. Using Post-Auth-Type REJECT # Executing group from file /etc/raddb/sites-enabled/default +- entering group REJECT {...} [attr_filter.access_reject] expand: %{User-Name} -> anonymous attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 53 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 53 Sending Access-Reject of id 159 to 10.0.1.254 port 1025 EAP-Message = 0x040c0004 Message-Authenticator = 0x00000000000000000000000000000000 Waking up in 0.1 seconds. Cleaning up request 50 ID 156 with timestamp +2393 Waking up in 1.0 seconds. Cleaning up request 51 ID 157 with timestamp +2394 Waking up in 1.3 seconds. Cleaning up request 52 ID 158 with timestamp +2395 Waking up in 2.4 seconds. Cleaning up request 53 ID 159 with timestamp +2397 Ready to process requests. -- Greg Huber Embedded Development Carestream Health
greg.huber wrote:
I few releases back we had EAP-TTLS/TLS working (maybe 2 years ago??) Since then it has stopped and I am having trouble finding the root cause. Protocols like EAP-TLS and EAP-TTLS/MSCHAPV2 are working, and I verified the certificates and keys.
It should work, though I haven't tested it recently.
I have attached the output from 'radiusd -X' below. I see a lot of posts have a nice condensed dump of the configuration, if someone could tell me how to get the dump I will attach it also.
"radiusd -X". It will print out the configuration it reads.
Near the end is the statement:
[ttls] WARNING: diameter2vp skipping long attribute 3005705648, attr
Hmm... that's wrong. It looks like your C compiler is broken. Which OS / C compiler are you using? What supplicant are you using?
I found this in the source code but am not sure if is is part of the problem or just a non-fatal warning.
The debug log shows it's the cause of the error. The supplicant is sending some weird non-EAP data inside of the tunnel. This is one case where you should run "radiusd -Xx", do the authentication, and post it to the list. The extra "x" will cause the server to print out a hex dump of the data inside of the tunnel. That will help us figure out what's going wrong. You don't need to post all of the debug output. Just the line: [ttls] Session established. Proceeding to decode tunneled attributes. and then the hex dump, which should be shortly after that. Alan DeKok.
Thank you for getting back so quickly. Below is the excerpt you requested, I hope there is enough We are running "FreeRADIUS Version 2.2.0" The package was compiled by Red Hat and we are running it on Fedora 19. The client is running wpa_supplicant 2.0 compiled for ARM. I have also tried version 0.5.9 of the supplicant with similar results. Tue Feb 11 13:45:17 2014 : Info: [ttls] Session established. Proceeding to decode tunneled attributes. Tue Feb 11 13:45:17 2014 : Info: [ttls] Got tunneled request EAP-Message = 0x0200000e01616e6f6e796d6f7573 FreeRADIUS-Proxied-To = 127.0.0.1 Tue Feb 11 13:45:17 2014 : Info: [ttls] Got tunneled identity of anonymous Tue Feb 11 13:45:17 2014 : Info: [ttls] Setting default EAP type for tunneled EAP session. Tue Feb 11 13:45:17 2014 : Info: [ttls] Sending tunneled request EAP-Message = 0x0200000e01616e6f6e796d6f7573 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "anonymous" server inner-tunnel { Tue Feb 11 13:45:17 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 13:45:17 2014 : Info: +- entering group authorize {...} Tue Feb 11 13:45:17 2014 : Info: ++[chap] returns noop Tue Feb 11 13:45:17 2014 : Info: ++[mschap] returns noop Tue Feb 11 13:45:17 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 13:45:17 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 13:45:17 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 13:45:17 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 13:45:17 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 13:45:17 2014 : Info: ++[suffix] returns ok Tue Feb 11 13:45:17 2014 : Info: ++[control] returns ok Tue Feb 11 13:45:17 2014 : Info: [inner-eap] EAP packet type response id 0 length 14 Tue Feb 11 13:45:17 2014 : Info: [inner-eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 11 13:45:17 2014 : Info: ++[inner-eap] returns updated Tue Feb 11 13:45:17 2014 : Info: [files] users: Matched entry anonymous at line 45 Tue Feb 11 13:45:17 2014 : Info: ++[files] returns ok Tue Feb 11 13:45:17 2014 : Info: ++[expiration] returns noop Tue Feb 11 13:45:17 2014 : Info: ++[logintime] returns noop Tue Feb 11 13:45:17 2014 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 11 13:45:17 2014 : Info: ++[pap] returns noop Tue Feb 11 13:45:17 2014 : Info: Found Auth-Type = inner-eap Tue Feb 11 13:45:17 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 13:45:17 2014 : Info: +- entering group authenticate {...} Tue Feb 11 13:45:17 2014 : Info: [inner-eap] EAP Identity Tue Feb 11 13:45:17 2014 : Info: [inner-eap] processing type tls Tue Feb 11 13:45:17 2014 : Info: [tls] Requiring client certificate Tue Feb 11 13:45:17 2014 : Info: [tls] Initiate Tue Feb 11 13:45:17 2014 : Info: [tls] Start returned 1 Tue Feb 11 13:45:17 2014 : Info: ++[inner-eap] returns handled } # server inner-tunnel Tue Feb 11 13:45:17 2014 : Info: [ttls] Got tunneled reply code 11 EAP-Message = 0x010100060d20 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x684f998a684e94c5cdbcbd88fff6aa2e Tue Feb 11 13:45:17 2014 : Info: [ttls] Got tunneled Access-Challenge Tue Feb 11 13:45:17 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 193 to 10.0.1.254 port 1025 EAP-Message = 0x0109003f158000000035170301003042c13a23d83deaa1c47b3c0320f418db1e54351306414aafe66a32ef7ca79b46102410bcad6c1a3a09cbfb8244b0b067 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x8d8d0ad78a841f65d1cd9864e3d16b9c Tue Feb 11 13:45:17 2014 : Info: Finished request 20. Tue Feb 11 13:45:17 2014 : Debug: Going to the next request Tue Feb 11 13:45:17 2014 : Debug: Waking up in 3.5 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=194, length=418 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020900e41580000000da170301002088322fc184326ac1d25b98fb3b8cd6dedd7258b024e54123649565ded46b18b717030100b0c35cbedadcb4d87cadd8cd390a45defcc30810bb7caa519107c664280a7e186f3ebf7712afa8e06c5ab27a9d85aedb5615ab0463548b73f6324e93755944f5fb1f67f07205a6a5e31531a0b59d0727e379251446ec406f0646ba396c048c00f417bc636371dde4d0dab4d889317b226596fba560f4d4e5625cdc01bbeb25ed36a29f1927227d590a44a4f4ddfd3bae4677d82ae16a8834bc96dc0cd06d945d36c54f5dfaea81ff05a7cccf57eb6b046c State = 0x8d8d0ad78a841f65d1cd9864e3d16b9c Message-Authenticator = 0xf8956678bb28ca3569e75c6e3cf6250c Greg Huber Embedded Development Carestream Health On 02/11/2014 01:06 PM, Alan DeKok wrote:
[ttls] Session established.
greg.huber wrote:
Thank you for getting back so quickly.
Below is the excerpt you requested, I hope there is enough
Well, no. It doesn't include any of the hex dumps I need. It just includes the same attribute names / values as before. Please post the whole debug output. Alan DeKok.
Lets try this again. This time I included everything. If this is incomplete I can recompile from source, The Fedora team may have 'patched' the source for their own purposes. And again, I really appreciate your assistance. Thank you. [root@localhost /]# radiusd -Xx Tue Feb 11 16:18:00 2014 : Info: FreeRADIUS Version 2.2.0, for host x86_64-redhat-linux-gnu, built on Feb 14 2013 at 18:14:38 Tue Feb 11 16:18:00 2014 : Info: Copyright (C) 1999-2012 The FreeRADIUS server project and contributors. Tue Feb 11 16:18:00 2014 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Tue Feb 11 16:18:00 2014 : Info: PARTICULAR PURPOSE. Tue Feb 11 16:18:00 2014 : Info: You may redistribute copies of FreeRADIUS under the terms of the Tue Feb 11 16:18:00 2014 : Info: GNU General Public License v2. Tue Feb 11 16:18:00 2014 : Info: Starting - reading configuration files ... Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/radiusd.conf Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/proxy.conf Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/clients.conf Tue Feb 11 16:18:00 2014 : Debug: including files in directory /etc/raddb/modules/ Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/files Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/opendirectory Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/mac2ip Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/pap Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/preprocess Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/passwd Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/cui Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/inner-eap Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/detail.log Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/radrelay Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/detail Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/checkval Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/acct_unique Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/always Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/echo Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/attr_rewrite Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/dhcp_sqlippool Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/etc_group Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/rediswho Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/sql_log Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/redis Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/linelog Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/logintime Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/attr_filter Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/unix Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/replicate Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/wimax Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/smbpasswd Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/detail.example.com Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/smsotp Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/sqlcounter_expire_on_login Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/mschap Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/otp Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/dynamic_clients Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/mac2vlan Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/counter Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/soh Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/chap Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/realm Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/ippool Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/expiration Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/cache Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/policy Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/sradutmp Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/radutmp Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/ntlm_auth Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/expr Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/perl Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/exec Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/pam Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/modules/digest Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/eap.conf Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/policy.conf Tue Feb 11 16:18:00 2014 : Debug: including files in directory /etc/raddb/sites-enabled/ Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 16:18:00 2014 : Debug: including configuration file /etc/raddb/sites-enabled/control-socket Tue Feb 11 16:18:00 2014 : Debug: main { Tue Feb 11 16:18:00 2014 : Debug: user = "radiusd" Tue Feb 11 16:18:00 2014 : Debug: group = "radiusd" Tue Feb 11 16:18:00 2014 : Debug: allow_core_dumps = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: including dictionary file /etc/raddb/dictionary Tue Feb 11 16:18:00 2014 : Debug: main { Tue Feb 11 16:18:00 2014 : Debug: name = "radiusd" Tue Feb 11 16:18:00 2014 : Debug: prefix = "/usr" Tue Feb 11 16:18:00 2014 : Debug: localstatedir = "/var" Tue Feb 11 16:18:00 2014 : Debug: sbindir = "/usr/sbin" Tue Feb 11 16:18:00 2014 : Debug: logdir = "/var/log/radius" Tue Feb 11 16:18:00 2014 : Debug: run_dir = "/var/run/radiusd" Tue Feb 11 16:18:00 2014 : Debug: libdir = "/usr/lib64/freeradius" Tue Feb 11 16:18:00 2014 : Debug: radacctdir = "/var/log/radius/radacct" Tue Feb 11 16:18:00 2014 : Debug: hostname_lookups = no Tue Feb 11 16:18:00 2014 : Debug: max_request_time = 30 Tue Feb 11 16:18:00 2014 : Debug: cleanup_delay = 5 Tue Feb 11 16:18:00 2014 : Debug: max_requests = 1024 Tue Feb 11 16:18:00 2014 : Debug: pidfile = "/var/run/radiusd/radiusd.pid" Tue Feb 11 16:18:00 2014 : Debug: checkrad = "/usr/sbin/checkrad" Tue Feb 11 16:18:00 2014 : Debug: debug_level = 0 Tue Feb 11 16:18:00 2014 : Debug: proxy_requests = yes Tue Feb 11 16:18:00 2014 : Debug: log { Tue Feb 11 16:18:00 2014 : Debug: stripped_names = no Tue Feb 11 16:18:00 2014 : Debug: auth = no Tue Feb 11 16:18:00 2014 : Debug: auth_badpass = no Tue Feb 11 16:18:00 2014 : Debug: auth_goodpass = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: security { Tue Feb 11 16:18:00 2014 : Debug: max_attributes = 200 Tue Feb 11 16:18:00 2014 : Debug: reject_delay = 1 Tue Feb 11 16:18:00 2014 : Debug: status_server = yes Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: radiusd: #### Loading Realms and Home Servers #### Tue Feb 11 16:18:00 2014 : Debug: proxy server { Tue Feb 11 16:18:00 2014 : Debug: retry_delay = 5 Tue Feb 11 16:18:00 2014 : Debug: retry_count = 3 Tue Feb 11 16:18:00 2014 : Debug: default_fallback = no Tue Feb 11 16:18:00 2014 : Debug: dead_time = 120 Tue Feb 11 16:18:00 2014 : Debug: wake_all_if_all_dead = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: home_server localhost { Tue Feb 11 16:18:00 2014 : Debug: ipaddr = 127.0.0.1 Tue Feb 11 16:18:00 2014 : Debug: port = 1812 Tue Feb 11 16:18:00 2014 : Debug: type = "auth" Tue Feb 11 16:18:00 2014 : Debug: secret = "testing123" Tue Feb 11 16:18:00 2014 : Debug: response_window = 20 Tue Feb 11 16:18:00 2014 : Debug: max_outstanding = 65536 Tue Feb 11 16:18:00 2014 : Debug: require_message_authenticator = yes Tue Feb 11 16:18:00 2014 : Debug: zombie_period = 40 Tue Feb 11 16:18:00 2014 : Debug: status_check = "status-server" Tue Feb 11 16:18:00 2014 : Debug: ping_interval = 30 Tue Feb 11 16:18:00 2014 : Debug: check_interval = 30 Tue Feb 11 16:18:00 2014 : Debug: num_answers_to_alive = 3 Tue Feb 11 16:18:00 2014 : Debug: num_pings_to_alive = 3 Tue Feb 11 16:18:00 2014 : Debug: revive_interval = 120 Tue Feb 11 16:18:00 2014 : Debug: status_check_timeout = 4 Tue Feb 11 16:18:00 2014 : Debug: coa { Tue Feb 11 16:18:00 2014 : Debug: irt = 2 Tue Feb 11 16:18:00 2014 : Debug: mrt = 16 Tue Feb 11 16:18:00 2014 : Debug: mrc = 5 Tue Feb 11 16:18:00 2014 : Debug: mrd = 30 Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: home_server_pool my_auth_failover { Tue Feb 11 16:18:00 2014 : Debug: type = fail-over Tue Feb 11 16:18:00 2014 : Debug: home_server = localhost Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: realm example.com { Tue Feb 11 16:18:00 2014 : Debug: auth_pool = my_auth_failover Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: realm LOCAL { Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: realm NULL { Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: radiusd: #### Loading Clients #### Tue Feb 11 16:18:00 2014 : Debug: client localhost { Tue Feb 11 16:18:00 2014 : Debug: ipaddr = 127.0.0.1 Tue Feb 11 16:18:00 2014 : Debug: require_message_authenticator = no Tue Feb 11 16:18:00 2014 : Debug: secret = "aize1Iep" Tue Feb 11 16:18:00 2014 : Debug: nastype = "other" Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: client 10.0.1.0/24 { Tue Feb 11 16:18:00 2014 : Debug: require_message_authenticator = no Tue Feb 11 16:18:00 2014 : Debug: secret = "hooSaib0" Tue Feb 11 16:18:00 2014 : Debug: shortname = "10.0.1.0" Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: client 10.95.0.0/16 { Tue Feb 11 16:18:00 2014 : Debug: require_message_authenticator = no Tue Feb 11 16:18:00 2014 : Debug: secret = "axahTh6m" Tue Feb 11 16:18:00 2014 : Debug: shortname = "10.95.0.0" Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: client 10.122.0.0/16 { Tue Feb 11 16:18:00 2014 : Debug: require_message_authenticator = no Tue Feb 11 16:18:00 2014 : Debug: secret = "aiw8Mie6" Tue Feb 11 16:18:00 2014 : Debug: shortname = "10.122.0.0" Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: radiusd: #### Instantiating modules #### Tue Feb 11 16:18:00 2014 : Debug: instantiate { Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_exec, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_exec Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "exec" from file /etc/raddb/modules/exec Tue Feb 11 16:18:00 2014 : Debug: exec { Tue Feb 11 16:18:00 2014 : Debug: wait = no Tue Feb 11 16:18:00 2014 : Debug: input_pairs = "request" Tue Feb 11 16:18:00 2014 : Debug: shell_escape = yes Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_expr, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_expr Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "expr" from file /etc/raddb/modules/expr Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_expiration, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_expiration Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "expiration" from file /etc/raddb/modules/expiration Tue Feb 11 16:18:00 2014 : Debug: expiration { Tue Feb 11 16:18:00 2014 : Debug: reply-message = "Password Has Expired " Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_logintime, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_logintime Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "logintime" from file /etc/raddb/modules/logintime Tue Feb 11 16:18:00 2014 : Debug: logintime { Tue Feb 11 16:18:00 2014 : Debug: reply-message = "You are calling outside your allowed timespan " Tue Feb 11 16:18:00 2014 : Debug: minimum-timeout = 60 Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: radiusd: #### Loading Virtual Servers #### Tue Feb 11 16:18:00 2014 : Debug: server { # from file /etc/raddb/radiusd.conf Tue Feb 11 16:18:00 2014 : Debug: modules { Tue Feb 11 16:18:00 2014 : Debug: Module: Creating Auth-Type = digest Tue Feb 11 16:18:00 2014 : Debug: Module: Creating Post-Auth-Type = REJECT Tue Feb 11 16:18:00 2014 : Debug: Module: Checking authenticate {...} for more modules to load Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_pap, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_pap Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "pap" from file /etc/raddb/modules/pap Tue Feb 11 16:18:00 2014 : Debug: pap { Tue Feb 11 16:18:00 2014 : Debug: encryption_scheme = "auto" Tue Feb 11 16:18:00 2014 : Debug: auto_header = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_chap, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_chap Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "chap" from file /etc/raddb/modules/chap Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_mschap, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_mschap Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "mschap" from file /etc/raddb/modules/mschap Tue Feb 11 16:18:00 2014 : Debug: mschap { Tue Feb 11 16:18:00 2014 : Debug: use_mppe = yes Tue Feb 11 16:18:00 2014 : Debug: require_encryption = no Tue Feb 11 16:18:00 2014 : Debug: require_strong = no Tue Feb 11 16:18:00 2014 : Debug: with_ntdomain_hack = no Tue Feb 11 16:18:00 2014 : Debug: allow_retry = yes Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_digest, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_digest Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "digest" from file /etc/raddb/modules/digest Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_eap, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_eap Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "eap" from file /etc/raddb/eap.conf Tue Feb 11 16:18:00 2014 : Debug: eap { Tue Feb 11 16:18:00 2014 : Debug: default_eap_type = "tls" Tue Feb 11 16:18:00 2014 : Debug: timer_expire = 60 Tue Feb 11 16:18:00 2014 : Debug: ignore_unknown_eap_types = no Tue Feb 11 16:18:00 2014 : Debug: cisco_accounting_username_bug = no Tue Feb 11 16:18:00 2014 : Debug: max_sessions = 4096 Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to sub-module rlm_eap_md5 Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating eap-md5 Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to sub-module rlm_eap_leap Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating eap-leap Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to sub-module rlm_eap_gtc Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating eap-gtc Tue Feb 11 16:18:00 2014 : Debug: gtc { Tue Feb 11 16:18:00 2014 : Debug: challenge = "Password: " Tue Feb 11 16:18:00 2014 : Debug: auth_type = "PAP" Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to sub-module rlm_eap_tls Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating eap-tls Tue Feb 11 16:18:00 2014 : Debug: tls { Tue Feb 11 16:18:00 2014 : Debug: rsa_key_exchange = no Tue Feb 11 16:18:00 2014 : Debug: dh_key_exchange = yes Tue Feb 11 16:18:00 2014 : Debug: rsa_key_length = 512 Tue Feb 11 16:18:00 2014 : Debug: dh_key_length = 512 Tue Feb 11 16:18:00 2014 : Debug: verify_depth = 0 Tue Feb 11 16:18:00 2014 : Debug: CA_path = "/etc/raddb/certs" Tue Feb 11 16:18:00 2014 : Debug: pem_file_type = yes Tue Feb 11 16:18:00 2014 : Debug: private_key_file = "/etc/raddb/certs/svr999.key" Tue Feb 11 16:18:00 2014 : Debug: certificate_file = "/etc/raddb/certs/svr999.pem" Tue Feb 11 16:18:00 2014 : Debug: CA_file = "/etc/raddb/certs/RootCA_1.pem" Tue Feb 11 16:18:00 2014 : Debug: private_key_password = "sundance" Tue Feb 11 16:18:00 2014 : Debug: dh_file = "/etc/raddb/certs/dh" Tue Feb 11 16:18:00 2014 : Debug: random_file = "/dev/urandom" Tue Feb 11 16:18:00 2014 : Debug: fragment_size = 1024 Tue Feb 11 16:18:00 2014 : Debug: include_length = yes Tue Feb 11 16:18:00 2014 : Debug: check_crl = no Tue Feb 11 16:18:00 2014 : Debug: cipher_list = "DEFAULT" Tue Feb 11 16:18:00 2014 : Debug: cache { Tue Feb 11 16:18:00 2014 : Debug: enable = no Tue Feb 11 16:18:00 2014 : Debug: lifetime = 24 Tue Feb 11 16:18:00 2014 : Debug: max_entries = 255 Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: verify { Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: ocsp { Tue Feb 11 16:18:00 2014 : Debug: enable = no Tue Feb 11 16:18:00 2014 : Debug: override_cert_url = yes Tue Feb 11 16:18:00 2014 : Debug: url = "http://127.0.0.1/ocsp/" Tue Feb 11 16:18:00 2014 : Debug: use_nonce = yes Tue Feb 11 16:18:00 2014 : Debug: timeout = 0 Tue Feb 11 16:18:00 2014 : Debug: softfail = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to sub-module rlm_eap_ttls Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating eap-ttls Tue Feb 11 16:18:00 2014 : Debug: ttls { Tue Feb 11 16:18:00 2014 : Debug: default_eap_type = "tls" Tue Feb 11 16:18:00 2014 : Debug: copy_request_to_tunnel = no Tue Feb 11 16:18:00 2014 : Debug: use_tunneled_reply = no Tue Feb 11 16:18:00 2014 : Debug: virtual_server = "inner-tunnel" Tue Feb 11 16:18:00 2014 : Debug: include_length = yes Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to sub-module rlm_eap_peap Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating eap-peap Tue Feb 11 16:18:00 2014 : Debug: peap { Tue Feb 11 16:18:00 2014 : Debug: default_eap_type = "mschapv2" Tue Feb 11 16:18:00 2014 : Debug: copy_request_to_tunnel = no Tue Feb 11 16:18:00 2014 : Debug: use_tunneled_reply = no Tue Feb 11 16:18:00 2014 : Debug: proxy_tunneled_request_as_eap = yes Tue Feb 11 16:18:00 2014 : Debug: virtual_server = "inner-tunnel" Tue Feb 11 16:18:00 2014 : Debug: soh = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating eap-mschapv2 Tue Feb 11 16:18:00 2014 : Debug: mschapv2 { Tue Feb 11 16:18:00 2014 : Debug: with_ntdomain_hack = no Tue Feb 11 16:18:00 2014 : Debug: send_error = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Checking authorize {...} for more modules to load Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_preprocess, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_preprocess Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "preprocess" from file /etc/raddb/modules/preprocess Tue Feb 11 16:18:00 2014 : Debug: preprocess { Tue Feb 11 16:18:00 2014 : Debug: huntgroups = "/etc/raddb/huntgroups" Tue Feb 11 16:18:00 2014 : Debug: hints = "/etc/raddb/hints" Tue Feb 11 16:18:00 2014 : Debug: with_ascend_hack = no Tue Feb 11 16:18:00 2014 : Debug: ascend_channels_per_line = 23 Tue Feb 11 16:18:00 2014 : Debug: with_ntdomain_hack = no Tue Feb 11 16:18:00 2014 : Debug: with_specialix_jetstream_hack = no Tue Feb 11 16:18:00 2014 : Debug: with_cisco_vsa_hack = no Tue Feb 11 16:18:00 2014 : Debug: with_alvarion_vsa_hack = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: reading pairlist file /etc/raddb/huntgroups Tue Feb 11 16:18:00 2014 : Debug: reading pairlist file /etc/raddb/hints Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_realm, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_realm Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "suffix" from file /etc/raddb/modules/realm Tue Feb 11 16:18:00 2014 : Debug: realm suffix { Tue Feb 11 16:18:00 2014 : Debug: format = "suffix" Tue Feb 11 16:18:00 2014 : Debug: delimiter = "@" Tue Feb 11 16:18:00 2014 : Debug: ignore_default = no Tue Feb 11 16:18:00 2014 : Debug: ignore_null = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_files, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_files Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "files" from file /etc/raddb/modules/files Tue Feb 11 16:18:00 2014 : Debug: files { Tue Feb 11 16:18:00 2014 : Debug: usersfile = "/etc/raddb/users" Tue Feb 11 16:18:00 2014 : Debug: acctusersfile = "/etc/raddb/acct_users" Tue Feb 11 16:18:00 2014 : Debug: preproxy_usersfile = "/etc/raddb/preproxy_users" Tue Feb 11 16:18:00 2014 : Debug: compat = "no" Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: reading pairlist file /etc/raddb/users Tue Feb 11 16:18:00 2014 : Debug: reading pairlist file /etc/raddb/acct_users Tue Feb 11 16:18:00 2014 : Debug: reading pairlist file /etc/raddb/preproxy_users Tue Feb 11 16:18:00 2014 : Debug: Module: Checking preacct {...} for more modules to load Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_acct_unique Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "acct_unique" from file /etc/raddb/modules/acct_unique Tue Feb 11 16:18:00 2014 : Debug: acct_unique { Tue Feb 11 16:18:00 2014 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, NAS-Identifier, NAS-Port" Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Checking accounting {...} for more modules to load Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_detail, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_detail Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "detail" from file /etc/raddb/modules/detail Tue Feb 11 16:18:00 2014 : Debug: detail { Tue Feb 11 16:18:00 2014 : Debug: detailfile = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" Tue Feb 11 16:18:00 2014 : Debug: header = "%t" Tue Feb 11 16:18:00 2014 : Debug: detailperm = 384 Tue Feb 11 16:18:00 2014 : Debug: dirperm = 493 Tue Feb 11 16:18:00 2014 : Debug: locking = no Tue Feb 11 16:18:00 2014 : Debug: log_packet_header = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_attr_filter Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "attr_filter.accounting_response" from file /etc/raddb/modules/attr_filter Tue Feb 11 16:18:00 2014 : Debug: attr_filter attr_filter.accounting_response { Tue Feb 11 16:18:00 2014 : Debug: attrsfile = "/etc/raddb/attrs.accounting_response" Tue Feb 11 16:18:00 2014 : Debug: key = "%{User-Name}" Tue Feb 11 16:18:00 2014 : Debug: relaxed = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: reading pairlist file /etc/raddb/attrs.accounting_response Tue Feb 11 16:18:00 2014 : Debug: Module: Checking session {...} for more modules to load Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_radutmp, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_radutmp Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "radutmp" from file /etc/raddb/modules/radutmp Tue Feb 11 16:18:00 2014 : Debug: radutmp { Tue Feb 11 16:18:00 2014 : Debug: filename = "/var/log/radius/radutmp" Tue Feb 11 16:18:00 2014 : Debug: username = "%{User-Name}" Tue Feb 11 16:18:00 2014 : Debug: case_sensitive = yes Tue Feb 11 16:18:00 2014 : Debug: check_with_nas = yes Tue Feb 11 16:18:00 2014 : Debug: perm = 384 Tue Feb 11 16:18:00 2014 : Debug: callerid = yes Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Checking post-proxy {...} for more modules to load Tue Feb 11 16:18:00 2014 : Debug: Module: Checking post-auth {...} for more modules to load Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "attr_filter.access_reject" from file /etc/raddb/modules/attr_filter Tue Feb 11 16:18:00 2014 : Debug: attr_filter attr_filter.access_reject { Tue Feb 11 16:18:00 2014 : Debug: attrsfile = "/etc/raddb/attrs.access_reject" Tue Feb 11 16:18:00 2014 : Debug: key = "%{User-Name}" Tue Feb 11 16:18:00 2014 : Debug: relaxed = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: reading pairlist file /etc/raddb/attrs.access_reject Tue Feb 11 16:18:00 2014 : Debug: } # modules Tue Feb 11 16:18:00 2014 : Debug: } # server Tue Feb 11 16:18:00 2014 : Debug: server inner-tunnel { # from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 16:18:00 2014 : Debug: modules { Tue Feb 11 16:18:00 2014 : Debug: Module: Creating Auth-Type = inner-eap Tue Feb 11 16:18:00 2014 : Debug: Module: Checking authenticate {...} for more modules to load Tue Feb 11 16:18:00 2014 : Debug: (Loaded rlm_unix, checking if it's valid) Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to module rlm_unix Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "unix" from file /etc/raddb/modules/unix Tue Feb 11 16:18:00 2014 : Debug: unix { Tue Feb 11 16:18:00 2014 : Debug: radwtmp = "/var/log/radius/radwtmp" Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating module "inner-eap" from file /etc/raddb/modules/inner-eap Tue Feb 11 16:18:00 2014 : Debug: eap inner-eap { Tue Feb 11 16:18:00 2014 : Debug: default_eap_type = "tls" Tue Feb 11 16:18:00 2014 : Debug: timer_expire = 60 Tue Feb 11 16:18:00 2014 : Debug: ignore_unknown_eap_types = no Tue Feb 11 16:18:00 2014 : Debug: cisco_accounting_username_bug = no Tue Feb 11 16:18:00 2014 : Debug: max_sessions = 2048 Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to sub-module rlm_eap_md5 Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating eap-md5 Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to sub-module rlm_eap_gtc Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating eap-gtc Tue Feb 11 16:18:00 2014 : Debug: gtc { Tue Feb 11 16:18:00 2014 : Debug: challenge = "Password: " Tue Feb 11 16:18:00 2014 : Debug: auth_type = "PAP" Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating eap-mschapv2 Tue Feb 11 16:18:00 2014 : Debug: mschapv2 { Tue Feb 11 16:18:00 2014 : Debug: with_ntdomain_hack = no Tue Feb 11 16:18:00 2014 : Debug: send_error = no Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Linked to sub-module rlm_eap_tls Tue Feb 11 16:18:00 2014 : Debug: Module: Instantiating eap-tls Tue Feb 11 16:18:00 2014 : Debug: tls { Tue Feb 11 16:18:00 2014 : Debug: rsa_key_exchange = no Tue Feb 11 16:18:00 2014 : Debug: dh_key_exchange = yes Tue Feb 11 16:18:00 2014 : Debug: rsa_key_length = 512 Tue Feb 11 16:18:00 2014 : Debug: dh_key_length = 512 Tue Feb 11 16:18:00 2014 : Debug: verify_depth = 0 Tue Feb 11 16:18:00 2014 : Debug: pem_file_type = yes Tue Feb 11 16:18:00 2014 : Debug: private_key_file = "/etc/raddb/certs/svr998.key" Tue Feb 11 16:18:00 2014 : Debug: certificate_file = "/etc/raddb/certs/svr998.pem" Tue Feb 11 16:18:00 2014 : Debug: CA_file = "/etc/raddb/certs/RootCA_2.pem" Tue Feb 11 16:18:00 2014 : Debug: private_key_password = "sundance" Tue Feb 11 16:18:00 2014 : Debug: dh_file = "/etc/raddb/certs/dh" Tue Feb 11 16:18:00 2014 : Debug: random_file = "/dev/urandom" Tue Feb 11 16:18:00 2014 : Debug: fragment_size = 896 Tue Feb 11 16:18:00 2014 : Debug: include_length = yes Tue Feb 11 16:18:00 2014 : Debug: check_crl = no Tue Feb 11 16:18:00 2014 : Debug: cipher_list = "DEFAULT" Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: Module: Checking authorize {...} for more modules to load Tue Feb 11 16:18:00 2014 : Debug: Module: Checking session {...} for more modules to load Tue Feb 11 16:18:00 2014 : Debug: Module: Checking post-proxy {...} for more modules to load Tue Feb 11 16:18:00 2014 : Debug: Module: Checking post-auth {...} for more modules to load Tue Feb 11 16:18:00 2014 : Debug: } # modules Tue Feb 11 16:18:00 2014 : Debug: } # server Tue Feb 11 16:18:00 2014 : Debug: radiusd: #### Opening IP addresses and Ports #### Tue Feb 11 16:18:00 2014 : Debug: listen { Tue Feb 11 16:18:00 2014 : Debug: type = "auth" Tue Feb 11 16:18:00 2014 : Debug: ipaddr = * Tue Feb 11 16:18:00 2014 : Debug: port = 0 Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: listen { Tue Feb 11 16:18:00 2014 : Debug: type = "acct" Tue Feb 11 16:18:00 2014 : Debug: ipaddr = * Tue Feb 11 16:18:00 2014 : Debug: port = 0 Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: listen { Tue Feb 11 16:18:00 2014 : Debug: type = "control" Tue Feb 11 16:18:00 2014 : Debug: listen { Tue Feb 11 16:18:00 2014 : Debug: socket = "/var/run/radiusd/radiusd.sock" Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: listen { Tue Feb 11 16:18:00 2014 : Debug: type = "auth" Tue Feb 11 16:18:00 2014 : Debug: ipaddr = 127.0.0.1 Tue Feb 11 16:18:00 2014 : Debug: port = 18120 Tue Feb 11 16:18:00 2014 : Debug: } Tue Feb 11 16:18:00 2014 : Debug: ... adding new socket proxy address * port 51076 Tue Feb 11 16:18:00 2014 : Debug: Listening on authentication address * port 1812 Tue Feb 11 16:18:00 2014 : Debug: Listening on accounting address * port 1813 Tue Feb 11 16:18:00 2014 : Debug: Listening on command file /var/run/radiusd/radiusd.sock Tue Feb 11 16:18:00 2014 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Tue Feb 11 16:18:00 2014 : Debug: Listening on proxy address * port 1814 Tue Feb 11 16:18:00 2014 : Info: Ready to process requests. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=212, length=186 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x0200000e01616e6f6e796d6f7573 Message-Authenticator = 0x4c3a620d5f9093ff5ee013959a44e25d Tue Feb 11 16:18:09 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:09 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:09 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:09 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:09 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:09 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:09 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:09 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:09 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:09 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:09 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:09 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:09 2014 : Info: [eap] EAP packet type response id 0 length 14 Tue Feb 11 16:18:09 2014 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 11 16:18:09 2014 : Info: ++[eap] returns updated Tue Feb 11 16:18:09 2014 : Info: [files] users: Matched entry anonymous at line 45 Tue Feb 11 16:18:09 2014 : Info: ++[files] returns ok Tue Feb 11 16:18:09 2014 : Info: ++[expiration] returns noop Tue Feb 11 16:18:09 2014 : Info: ++[logintime] returns noop Tue Feb 11 16:18:09 2014 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 11 16:18:09 2014 : Info: ++[pap] returns noop Tue Feb 11 16:18:09 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:09 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:09 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:09 2014 : Info: [eap] EAP Identity Tue Feb 11 16:18:09 2014 : Info: [eap] processing type tls Tue Feb 11 16:18:09 2014 : Info: [tls] Requiring client certificate Tue Feb 11 16:18:09 2014 : Info: [tls] Initiate Tue Feb 11 16:18:09 2014 : Info: [tls] Start returned 1 Tue Feb 11 16:18:09 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 212 to 10.0.1.254 port 1025 EAP-Message = 0x010100060d20 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x325569cf32546429029862537b62c2e7 Tue Feb 11 16:18:09 2014 : Info: Finished request 0. Tue Feb 11 16:18:09 2014 : Debug: Going to the next request Tue Feb 11 16:18:09 2014 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=213, length=196 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020100060315 State = 0x325569cf32546429029862537b62c2e7 Message-Authenticator = 0x0381a3bebefa2c956a1992f637deb642 Tue Feb 11 16:18:10 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:10 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:10 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:10 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:10 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:10 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:10 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:10 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:10 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:10 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:10 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:10 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:10 2014 : Info: [eap] EAP packet type response id 1 length 6 Tue Feb 11 16:18:10 2014 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 11 16:18:10 2014 : Info: ++[eap] returns updated Tue Feb 11 16:18:10 2014 : Info: [files] users: Matched entry anonymous at line 45 Tue Feb 11 16:18:10 2014 : Info: ++[files] returns ok Tue Feb 11 16:18:10 2014 : Info: ++[expiration] returns noop Tue Feb 11 16:18:10 2014 : Info: ++[logintime] returns noop Tue Feb 11 16:18:10 2014 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 11 16:18:10 2014 : Info: ++[pap] returns noop Tue Feb 11 16:18:10 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:10 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:10 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:10 2014 : Info: [eap] Request found, released from the list Tue Feb 11 16:18:10 2014 : Info: [eap] EAP NAK Tue Feb 11 16:18:10 2014 : Info: [eap] EAP-NAK asked for EAP-Type/ttls Tue Feb 11 16:18:10 2014 : Info: [eap] processing type tls Tue Feb 11 16:18:10 2014 : Info: [tls] Initiate Tue Feb 11 16:18:10 2014 : Info: [tls] Start returned 1 Tue Feb 11 16:18:10 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 213 to 10.0.1.254 port 1025 EAP-Message = 0x010200061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x325569cf33577c29029862537b62c2e7 Tue Feb 11 16:18:10 2014 : Info: Finished request 1. Tue Feb 11 16:18:10 2014 : Debug: Going to the next request Tue Feb 11 16:18:10 2014 : Debug: Waking up in 4.6 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=214, length=327 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x0202008915800000007f160301007a01000076030191a1be34b0329a0fb39da88930eeb32351fad4efc0bf58bb41f2e12f5ef9926e000048c022c021003900380088008700350084c01cc01b00160013000ac01fc01e00330032009a009900450044002f009600410007000500040015001200090014001100080006000300ff01000005000f000101 State = 0x325569cf33577c29029862537b62c2e7 Message-Authenticator = 0xbd42012df8ceb1f4a12bd98127efa7a4 Tue Feb 11 16:18:10 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:10 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:10 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:10 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:10 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:10 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:10 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:10 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:10 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:10 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:10 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:10 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:10 2014 : Info: [eap] EAP packet type response id 2 length 137 Tue Feb 11 16:18:10 2014 : Info: [eap] Continuing tunnel setup. Tue Feb 11 16:18:10 2014 : Info: ++[eap] returns ok Tue Feb 11 16:18:10 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:10 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:10 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:10 2014 : Info: [eap] Request found, released from the list Tue Feb 11 16:18:10 2014 : Info: [eap] EAP/ttls Tue Feb 11 16:18:10 2014 : Info: [eap] processing type ttls Tue Feb 11 16:18:10 2014 : Info: [ttls] Authenticate Tue Feb 11 16:18:10 2014 : Info: [ttls] processing EAP-TLS Tue Feb 11 16:18:10 2014 : Debug: TLS Length 127 Tue Feb 11 16:18:10 2014 : Info: [ttls] Length Included Tue Feb 11 16:18:10 2014 : Info: [ttls] eaptls_verify returned 11 Tue Feb 11 16:18:10 2014 : Info: [ttls] (other): before/accept initialization Tue Feb 11 16:18:10 2014 : Info: [ttls] TLS_accept: before/accept initialization Tue Feb 11 16:18:10 2014 : Info: [ttls] <<< TLS 1.0 Handshake [length 007a], ClientHello Tue Feb 11 16:18:10 2014 : Info: [ttls] TLS_accept: SSLv3 read client hello A Tue Feb 11 16:18:10 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 0036], ServerHello Tue Feb 11 16:18:10 2014 : Info: [ttls] TLS_accept: SSLv3 write server hello A Tue Feb 11 16:18:10 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 09fc], Certificate Tue Feb 11 16:18:10 2014 : Info: [ttls] TLS_accept: SSLv3 write certificate A Tue Feb 11 16:18:10 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange Tue Feb 11 16:18:10 2014 : Info: [ttls] TLS_accept: SSLv3 write key exchange A Tue Feb 11 16:18:10 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Tue Feb 11 16:18:10 2014 : Info: [ttls] TLS_accept: SSLv3 write server done A Tue Feb 11 16:18:10 2014 : Info: [ttls] TLS_accept: SSLv3 flush data Tue Feb 11 16:18:10 2014 : Info: [ttls] TLS_accept: Need to read more data: SSLv3 read client certificate A Tue Feb 11 16:18:10 2014 : Debug: In SSL Handshake Phase Tue Feb 11 16:18:10 2014 : Debug: In SSL Accept mode Tue Feb 11 16:18:10 2014 : Info: [ttls] eaptls_process returned 13 Tue Feb 11 16:18:10 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 214 to 10.0.1.254 port 1025 EAP-Message = 0x0103040015c000000c57160301003602000032030152fa93924ab9dc6854874cccfd87a0c5f5e34ad5b9fc8b87bd7eeaeecb7481cb00003900000aff01000100000f00010116030109fc0b0009f80009f500047c3082047830820260a00302010202010d300d06092a864886f70d0101050500304e310b30090603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d20446576696365204341301e170d3132303330383134343632335a170d3232303330363134343632335a3040310b30090603550406130255533120301e060355040a0c17 EAP-Message = 0x4361726573747265616d204865616c74682c20496e632e310f300d06035504030c0673767239393930820122300d06092a864886f70d01010105000382010f003082010a0282010100b6110b670d55a4bbbdd8a503a5072997546113f1aa0a5cdcff10a785f10081ca7980bce887d34ebd0ecb6dfd76d47fdb6f426267d3ca7960f8b03ab22da896b4148980fbdce06e0e9d593cfb44d88dc11d9ee69426d77a7b7d7aab1516e29d1eb97b642493d85c03177b2450440bc6e64d444cc7981f6839c7b8c0c1c4fcd47b005919dbb91914d197319eb041713a0f83b1a7baa9aa628b600e35970e937e35439626d1250063be91e189abc588b71526655308 EAP-Message = 0x6d0dc519425db0a86f62b7542aa432d36948b30ce0d9e2199519c52488048cdc276ceb9e93ad9956948d7fa2f923605b72d980d9e4343f8816e7338153274174181bca0a8cd75fe7877564610203010001a36f306d30090603551d1304023000300b0603551d0f0404030205a0301d0603551d0e04160414f47cb8064b70edf5548b0017a61029365f30ce02301f0603551d23041830168014baa2501fb648ce3f2efdfa4fee6ce894bef51ae130130603551d25040c300a06082b06010505070301300d06092a864886f70d01010505000382020100bcf6abd117cff2b740225cc8846de2003d110302f3c2b408479af914f7ba7b94df12521e42ae84 EAP-Message = 0x7d87e5ace5f0085e9e5840dd4a014dd81072321923ddae890a7c978f97bab66ebed4cf2c1b910d4362a8a32767bc372ca44b61e70fd8fabe0b3b6ec3ebcecf40c023bcc1a34722b30ac1c6e46d16d5a944edfa4d1dc7cd0d2eeb318ffb99eba549d2755936df1ae49aa9231faf3983d2eaa0c08383af636b14f3b586551b7ac229ddd091d169f785a3b24b377fb476bcf5cd176063cfac648c610abfac4bf94f6f267a6c4d01f0b54dcee4fcafee35d95a02c09688ccd42ee62ad49d11b5289422c635125e1b45aac3bcfb6764c2e920f5ec8c5248f85eb4ef983ef461b8bb501dd2bb1ca17382b92c170ec3ea8e7d8803e254e86acedf1bc468967d16 EAP-Message = 0x328cc6e43fa42670d70db1b3 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x325569cf30567c29029862537b62c2e7 Tue Feb 11 16:18:10 2014 : Info: Finished request 2. Tue Feb 11 16:18:10 2014 : Debug: Going to the next request Tue Feb 11 16:18:10 2014 : Debug: Waking up in 4.6 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=215, length=196 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020300061500 State = 0x325569cf30567c29029862537b62c2e7 Message-Authenticator = 0xd2ecf088c7f74792c91a7a7a0b366224 Tue Feb 11 16:18:10 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:10 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:10 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:10 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:10 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:10 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:10 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:10 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:10 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:10 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:10 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:10 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:10 2014 : Info: [eap] EAP packet type response id 3 length 6 Tue Feb 11 16:18:10 2014 : Info: [eap] Continuing tunnel setup. Tue Feb 11 16:18:10 2014 : Info: ++[eap] returns ok Tue Feb 11 16:18:10 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:10 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:10 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:10 2014 : Info: [eap] Request found, released from the list Tue Feb 11 16:18:10 2014 : Info: [eap] EAP/ttls Tue Feb 11 16:18:10 2014 : Info: [eap] processing type ttls Tue Feb 11 16:18:10 2014 : Info: [ttls] Authenticate Tue Feb 11 16:18:10 2014 : Info: [ttls] processing EAP-TLS Tue Feb 11 16:18:10 2014 : Info: [ttls] Received TLS ACK Tue Feb 11 16:18:10 2014 : Info: [ttls] ACK handshake fragment handler Tue Feb 11 16:18:10 2014 : Info: [ttls] eaptls_verify returned 1 Tue Feb 11 16:18:10 2014 : Info: [ttls] eaptls_process returned 13 Tue Feb 11 16:18:10 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 215 to 10.0.1.254 port 1025 EAP-Message = 0x0104040015c000000c578b377bc03abc12d9efd6a6057b6a8068e1c0d78eb5ea8a54d5d52c230626dd9f4b2ff161ac9d17dda991270ce17612c56b52c8adc23c017778aeed9a4d8f1e96e2cd2447783b8e9ca80f678749b48c7cd00590b3b9bd1bfcfe82e57b612889d8f9fa5f0c375e67d3480cd881a393ce30690c841d014ba04e96aa9526a9bc86ca35ebc4bf7fd86fbff92d8fb97b76772ff49fff6f5d43a4fa90865178e2d85d3b393ecf020b69bba1b65c8d773197db60a12244a8980d0a9cd445e4134f8a401c4b813e14300f76d62a25fe73a6860d790005733082056f30820357a003020102020900e69fcd1da395f8d1300d06092a864886 EAP-Message = 0xf70d0101050500304e310b30090603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d20446576696365204341301e170d3132303330383134343335385a170d3232303330383134343335385a304e310b30090603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d2044657669636520434130820222300d06092a864886f70d01010105000382020f003082020a0282020100d3eb1fb917fd39578eeb97d1825ab99c826c9bab8f EAP-Message = 0x36eaa024842596cbfa775ac29a078a4dbffcb8672975c3360be599e79e282b76c133d091561c118294dce53ed7afd6c216b6a42b5babfd26b5d1743fd46a73c7d4e0e2f19775ad1ffda3dc526c29be5be8f951a5c4e195132e62e8b7084eb74d54f4f2b670ae7669582c3c42a69b833873e2bd4c8a4e25ad6db8762d943389ce3b876005d0d67384c1e1c45c14dccee08c93b29a8f7da340b6157b13b499b3678a7f96cc338b4eca643b3e91dd1e3bf6d67a39801e2fca2ba7e7463f7f4fe9f6f79dbb0e43d970386d0476f281f2c902f85f390febf77414946f0c632a3c084c0dbd26c212d20fabe73d32f7113d15e0b9fa6cb31e9b95821db543f16f EAP-Message = 0x3bfdcbbc791e2a734b645267a4d16f2906b48752285c75d749696c6094c7494216837c01f6287789977924590c132376dac76a59498020eea75d9f508a974b45051eeb3e71d8b48df1d98bf22424e05c33a9bab9de0556e5289805e58f663f30af7883a7b8a5e32b0fd314c40cb67bce2339adf9a908d226a5b338f74fa5db4a8504cea4e785c8f03d9acdd5a358bba70cbf1c633655e08a937305066d8cabb8198a0871acf035a412930d367c5222b37a819cff91947f986c55edff51b2380588ea734e453ef8c515f97c6795c8e25de79d25d9eb41e6683b6e24cebcb372c3f19321cfa7469870a6e410010a770203010001a350304e301d0603551d EAP-Message = 0x0e04160414baa2501fb648ce Message-Authenticator = 0x00000000000000000000000000000000 State = 0x325569cf31517c29029862537b62c2e7 Tue Feb 11 16:18:10 2014 : Info: Finished request 3. Tue Feb 11 16:18:10 2014 : Debug: Going to the next request Tue Feb 11 16:18:10 2014 : Debug: Waking up in 4.3 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=216, length=196 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020400061500 State = 0x325569cf31517c29029862537b62c2e7 Message-Authenticator = 0xec861482bbcd1cbe2117c05af76a8cc1 Tue Feb 11 16:18:11 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:11 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:11 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:11 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:11 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:11 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:11 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:11 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:11 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:11 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:11 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:11 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:11 2014 : Info: [eap] EAP packet type response id 4 length 6 Tue Feb 11 16:18:11 2014 : Info: [eap] Continuing tunnel setup. Tue Feb 11 16:18:11 2014 : Info: ++[eap] returns ok Tue Feb 11 16:18:11 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:11 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:11 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:11 2014 : Info: [eap] Request found, released from the list Tue Feb 11 16:18:11 2014 : Info: [eap] EAP/ttls Tue Feb 11 16:18:11 2014 : Info: [eap] processing type ttls Tue Feb 11 16:18:11 2014 : Info: [ttls] Authenticate Tue Feb 11 16:18:11 2014 : Info: [ttls] processing EAP-TLS Tue Feb 11 16:18:11 2014 : Info: [ttls] Received TLS ACK Tue Feb 11 16:18:11 2014 : Info: [ttls] ACK handshake fragment handler Tue Feb 11 16:18:11 2014 : Info: [ttls] eaptls_verify returned 1 Tue Feb 11 16:18:11 2014 : Info: [ttls] eaptls_process returned 13 Tue Feb 11 16:18:11 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 216 to 10.0.1.254 port 1025 EAP-Message = 0x0105040015c000000c573f2efdfa4fee6ce894bef51ae1301f0603551d23041830168014baa2501fb648ce3f2efdfa4fee6ce894bef51ae1300c0603551d13040530030101ff300d06092a864886f70d01010505000382020100399fd531e7af489dc26dd1fb956d857530d63f1675eb72ed55f92fe4b0914f92335c418b3b1974e9f59da7b2ed57609f7afd99b4eed6efe8e7c736aef94f414e3348ee64d9433f2d484c011b9a7f43e5fbd97b37a2a7810e3ab37469f51264b5ede9a3e47bd60a7ed438b8bf2603c03b1290c0819b8f485f97e012029a1712e0b4adda8f6e69f409897c0e08f6484d80b92830a976115fc9a27b3701320e49849f1a17 EAP-Message = 0x83fb02351233fdaf0597f648cc306f0e28502465193ef8665da49b84c15d4fd4cf32d2fb510907638fb6453b5176b1047366b9c9a9d4583e139d51390236be52f79776f1b0160439dfbf39d6b49ab6677034398d0c34c5d33db7d04298ea97f034aedcef56b0bef88ff3eae5a452f3e152e1883d05ca35be380bbfed2549f380e758ec5c9445651367443b2a1cdb93139ed7e944b6dfabd796e794ebf62b6755f54978f1a12911ad6f5bf358de8b210bccbfccccf5dfd1539ce1b85f478331a03df27b2c4d06b1a48fa708fab13acdb5e6c453825bbd47c6c06f3692a7fd3332eb5463a279bed9a3d3d3ed7205652df474cba6bb81d4337ae231b58775 EAP-Message = 0xa63da01d1e050cdfd5895bd8c1606cad391c373badf0bb76fcb1a658ff1db760f65b6064adfdb33150537e839789cd430360b983908082d45abaecc38bde1179c83da08925438b7134883807cbd6f11f1ade5ef7b3c9cc19058ab4497ca706a6160301020d0c0002090080d0d6b54e7f02a1f12b53d11521a2df0f47df59ba4e72828003bc47d4fe2ca20295bde105d30e7455ad165507b5a71caa9e4dbeab3dd7442ca803afe3eba4e661dc2a84bc717ea92750d76c663186702f275656b7b31770f9492b41fecb7cc2e2365235bb45c188e5cdc8c77331912903f2d2c42f27e86a5146827964cd4b70ab000102008069645413c4a93090be62a3bfc8 EAP-Message = 0x210b3db3ecaa1908c00bf920a08f0cc2d5b4312112087efaef020bdbf7d53f124891b0119811bf4417c6944cbc8d4ad04ddee2efb51088c88d4a62f077d51bcfd8f4226646e057db178df82d89306a3c4e50ba590f7851a589fe415eb8c47f226403a44c3776313fd008c5b20ba18ad54c2592010046eb8ccde4d21b900e74283b1b963c852b8ec2f8ddb5c70ee696140a218a52816d269611cdf0e3adc075a3e3120b6204d3c338f5a22e6e0bb779bab15883950c9387fc2baead7b6e93ebf3182f719a0cc123f429048fd4219e815e8e59b03ca4e1e5ccd6512315e06ff6d97a7a9377bcdf6f6c54ceea8298d8f2ec5fc7106e44f195ea2a65c329fe EAP-Message = 0x61637fb69f6991a4d5ec87ad Message-Authenticator = 0x00000000000000000000000000000000 State = 0x325569cf36507c29029862537b62c2e7 Tue Feb 11 16:18:11 2014 : Info: Finished request 4. Tue Feb 11 16:18:11 2014 : Debug: Going to the next request Tue Feb 11 16:18:11 2014 : Debug: Waking up in 3.9 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=217, length=196 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020500061500 State = 0x325569cf36507c29029862537b62c2e7 Message-Authenticator = 0x7419e0d618c752d909c0d2990bbdad36 Tue Feb 11 16:18:11 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:11 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:11 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:11 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:11 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:11 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:11 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:11 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:11 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:11 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:11 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:11 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:11 2014 : Info: [eap] EAP packet type response id 5 length 6 Tue Feb 11 16:18:11 2014 : Info: [eap] Continuing tunnel setup. Tue Feb 11 16:18:11 2014 : Info: ++[eap] returns ok Tue Feb 11 16:18:11 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:11 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:11 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:11 2014 : Info: [eap] Request found, released from the list Tue Feb 11 16:18:11 2014 : Info: [eap] EAP/ttls Tue Feb 11 16:18:11 2014 : Info: [eap] processing type ttls Tue Feb 11 16:18:11 2014 : Info: [ttls] Authenticate Tue Feb 11 16:18:11 2014 : Info: [ttls] processing EAP-TLS Tue Feb 11 16:18:11 2014 : Info: [ttls] Received TLS ACK Tue Feb 11 16:18:11 2014 : Info: [ttls] ACK handshake fragment handler Tue Feb 11 16:18:11 2014 : Info: [ttls] eaptls_verify returned 1 Tue Feb 11 16:18:11 2014 : Info: [ttls] eaptls_process returned 13 Tue Feb 11 16:18:11 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 217 to 10.0.1.254 port 1025 EAP-Message = 0x0106007f158000000c571e8c488420691a311c9763b795f40b5e25dfd7ab24abbbbc2b35e81ff9bcad4e148e608ef33d0f3da171f126613ec2f4dd7f00c10dae39b4eb86bca2fe70dc05eb42b0a94bdb47dd95c76e095e256185aa0efa158826128abc44d4fda3b540b39b74f6a4400adf461bbcef2f16030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x325569cf37537c29029862537b62c2e7 Tue Feb 11 16:18:11 2014 : Info: Finished request 5. Tue Feb 11 16:18:11 2014 : Debug: Going to the next request Tue Feb 11 16:18:11 2014 : Debug: Waking up in 3.6 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=218, length=398 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020600d01580000000c616030100861000008200809dc118176df8e3a7d74f8740290abacd68e6f2b625505528ab90da9fa3897dcea7ef5f0bcefe02a4fcb10309bf3a7df0b4ac31b1bcfd8f44f190f0a033c91d0fe437071755ed3255075ca8f1cecf54551c2dda4fe9fcd1264d40ea49928bbc55409d73ef071944dfd147f741456b570797b43b2784d6f20c8f727a1d10fdd8b91403010001011603010030035fb308fc2f0bc43913992133f2a81dd4e2d1ae7e9dbb98ff86d900e3398abb99ed04f09153fd035923f0c562b3c9f0 State = 0x325569cf37537c29029862537b62c2e7 Message-Authenticator = 0x989787e74f9d0ca95994b15e849fe299 Tue Feb 11 16:18:11 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:11 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:11 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:11 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:11 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:11 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:11 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:11 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:11 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:11 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:11 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:11 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:11 2014 : Info: [eap] EAP packet type response id 6 length 208 Tue Feb 11 16:18:11 2014 : Info: [eap] Continuing tunnel setup. Tue Feb 11 16:18:11 2014 : Info: ++[eap] returns ok Tue Feb 11 16:18:11 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:11 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:11 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:11 2014 : Info: [eap] Request found, released from the list Tue Feb 11 16:18:11 2014 : Info: [eap] EAP/ttls Tue Feb 11 16:18:11 2014 : Info: [eap] processing type ttls Tue Feb 11 16:18:11 2014 : Info: [ttls] Authenticate Tue Feb 11 16:18:11 2014 : Info: [ttls] processing EAP-TLS Tue Feb 11 16:18:11 2014 : Debug: TLS Length 198 Tue Feb 11 16:18:11 2014 : Info: [ttls] Length Included Tue Feb 11 16:18:11 2014 : Info: [ttls] eaptls_verify returned 11 Tue Feb 11 16:18:11 2014 : Info: [ttls] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange Tue Feb 11 16:18:11 2014 : Info: [ttls] TLS_accept: SSLv3 read client key exchange A Tue Feb 11 16:18:11 2014 : Info: [ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001] Tue Feb 11 16:18:11 2014 : Info: [ttls] <<< TLS 1.0 Handshake [length 0010], Finished Tue Feb 11 16:18:11 2014 : Info: [ttls] TLS_accept: SSLv3 read finished A Tue Feb 11 16:18:11 2014 : Info: [ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001] Tue Feb 11 16:18:11 2014 : Info: [ttls] TLS_accept: SSLv3 write change cipher spec A Tue Feb 11 16:18:11 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 0010], Finished Tue Feb 11 16:18:11 2014 : Info: [ttls] TLS_accept: SSLv3 write finished A Tue Feb 11 16:18:11 2014 : Info: [ttls] TLS_accept: SSLv3 flush data Tue Feb 11 16:18:11 2014 : Info: [ttls] (other): SSL negotiation finished successfully Tue Feb 11 16:18:11 2014 : Debug: SSL Connection Established Tue Feb 11 16:18:11 2014 : Info: [ttls] eaptls_process returned 13 Tue Feb 11 16:18:11 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 218 to 10.0.1.254 port 1025 EAP-Message = 0x0107004515800000003b1403010001011603010030145f6188219e3ae493cbf79de7614afc534b6633807bf9c5226d853facfff9be3c2a7bf84dd98b1b6bd1c44928dc3e24 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x325569cf34527c29029862537b62c2e7 Tue Feb 11 16:18:11 2014 : Info: Finished request 6. Tue Feb 11 16:18:11 2014 : Debug: Going to the next request Tue Feb 11 16:18:11 2014 : Debug: Waking up in 3.2 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=219, length=290 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x0207006415800000005a17030100204563ff20857fabc96c29995af66ad610ae8446ee56450d39c2098b55f35bcfaa17030100303a3dad52c03e30e918d749bc8b5135112c035723b288c84766bbd12956eb86c8d4132bfe0fc7c0161ffa0c09d22bceb7 State = 0x325569cf34527c29029862537b62c2e7 Message-Authenticator = 0x3a4de0a2a2a01ac5a74c1e3c66cb8f7c Tue Feb 11 16:18:11 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:11 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:11 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:11 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:11 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:11 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:11 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:11 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:11 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:11 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:11 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:11 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:11 2014 : Info: [eap] EAP packet type response id 7 length 100 Tue Feb 11 16:18:11 2014 : Info: [eap] Continuing tunnel setup. Tue Feb 11 16:18:11 2014 : Info: ++[eap] returns ok Tue Feb 11 16:18:11 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:11 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:11 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:11 2014 : Info: [eap] Request found, released from the list Tue Feb 11 16:18:11 2014 : Info: [eap] EAP/ttls Tue Feb 11 16:18:11 2014 : Info: [eap] processing type ttls Tue Feb 11 16:18:11 2014 : Info: [ttls] Authenticate Tue Feb 11 16:18:11 2014 : Info: [ttls] processing EAP-TLS Tue Feb 11 16:18:11 2014 : Debug: TLS Length 90 Tue Feb 11 16:18:11 2014 : Info: [ttls] Length Included Tue Feb 11 16:18:11 2014 : Info: [ttls] eaptls_verify returned 11 Tue Feb 11 16:18:11 2014 : Info: [ttls] eaptls_process returned 7 Tue Feb 11 16:18:11 2014 : Info: [ttls] Session established. Proceeding to decode tunneled attributes. Tue Feb 11 16:18:11 2014 : Info: [ttls] Got tunneled request EAP-Message = 0x0200000e01616e6f6e796d6f7573 FreeRADIUS-Proxied-To = 127.0.0.1 Tue Feb 11 16:18:11 2014 : Info: [ttls] Got tunneled identity of anonymous Tue Feb 11 16:18:11 2014 : Info: [ttls] Setting default EAP type for tunneled EAP session. Tue Feb 11 16:18:11 2014 : Info: [ttls] Sending tunneled request EAP-Message = 0x0200000e01616e6f6e796d6f7573 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "anonymous" server inner-tunnel { Tue Feb 11 16:18:11 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 16:18:11 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:11 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:11 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:11 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:11 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:11 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:11 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:11 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:11 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:11 2014 : Info: ++[control] returns ok Tue Feb 11 16:18:11 2014 : Info: [inner-eap] EAP packet type response id 0 length 14 Tue Feb 11 16:18:11 2014 : Info: [inner-eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 11 16:18:11 2014 : Info: ++[inner-eap] returns updated Tue Feb 11 16:18:11 2014 : Info: [files] users: Matched entry anonymous at line 45 Tue Feb 11 16:18:11 2014 : Info: ++[files] returns ok Tue Feb 11 16:18:11 2014 : Info: ++[expiration] returns noop Tue Feb 11 16:18:11 2014 : Info: ++[logintime] returns noop Tue Feb 11 16:18:11 2014 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 11 16:18:11 2014 : Info: ++[pap] returns noop Tue Feb 11 16:18:11 2014 : Info: Found Auth-Type = inner-eap Tue Feb 11 16:18:11 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 16:18:11 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:11 2014 : Info: [inner-eap] EAP Identity Tue Feb 11 16:18:11 2014 : Info: [inner-eap] processing type tls Tue Feb 11 16:18:11 2014 : Info: [tls] Requiring client certificate Tue Feb 11 16:18:11 2014 : Info: [tls] Initiate Tue Feb 11 16:18:11 2014 : Info: [tls] Start returned 1 Tue Feb 11 16:18:11 2014 : Info: ++[inner-eap] returns handled } # server inner-tunnel Tue Feb 11 16:18:11 2014 : Info: [ttls] Got tunneled reply code 11 EAP-Message = 0x010100060d20 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x8ffc85fa8ffd88bdbab7b09df5e88573 Tue Feb 11 16:18:11 2014 : Info: [ttls] Got tunneled Access-Challenge Tue Feb 11 16:18:11 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 219 to 10.0.1.254 port 1025 EAP-Message = 0x0108003f1580000000351703010030963cc5e729f4ab074fa291ebba72bcfada562e3a46648d4a662d92faec53ce5b3c664e609b23dcaf7856dae293861e42 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x325569cf355d7c29029862537b62c2e7 Tue Feb 11 16:18:11 2014 : Info: Finished request 7. Tue Feb 11 16:18:11 2014 : Debug: Going to the next request Tue Feb 11 16:18:11 2014 : Debug: Waking up in 3.2 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=220, length=418 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020800e41580000000da1703010020a8bfd5b7521a2d7a6538828c2e26b701aae0e57d8bc46f8756badd4cf65b374f17030100b0df16b0f9bf43e9837a807ba203b6f5ca5051cd28ca2640c0012cdc52722c17e9b18cb900ce7686ff21ff41dc160fee96902c557952d6d61bd6de02e4c08c2afa14286ea662f9a1de86cb6d55d6e081af39dd2247dc3c83c5a08543aaebf06e892517fdc970ef70ca8228dba91297b99fb800c857fb768e4740a9764f2f11c9b728e0e8d00e8e07a682005b5c93808eafc6abc108ab0f9f54657753b40fd61245dcf26b57691bcd04e89a16e2d11e841b State = 0x325569cf355d7c29029862537b62c2e7 Message-Authenticator = 0x1e384fd506d35fe37b28a8ca10095b99 Tue Feb 11 16:18:12 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:12 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:12 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:12 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:12 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:12 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:12 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:12 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:12 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:12 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:12 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:12 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:12 2014 : Info: [eap] EAP packet type response id 8 length 228 Tue Feb 11 16:18:12 2014 : Info: [eap] Continuing tunnel setup. Tue Feb 11 16:18:12 2014 : Info: ++[eap] returns ok Tue Feb 11 16:18:12 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:12 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:12 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:12 2014 : Info: [eap] Request found, released from the list Tue Feb 11 16:18:12 2014 : Info: [eap] EAP/ttls Tue Feb 11 16:18:12 2014 : Info: [eap] processing type ttls Tue Feb 11 16:18:12 2014 : Info: [ttls] Authenticate Tue Feb 11 16:18:12 2014 : Info: [ttls] processing EAP-TLS Tue Feb 11 16:18:12 2014 : Debug: TLS Length 218 Tue Feb 11 16:18:12 2014 : Info: [ttls] Length Included Tue Feb 11 16:18:12 2014 : Info: [ttls] eaptls_verify returned 11 Tue Feb 11 16:18:12 2014 : Info: [ttls] eaptls_process returned 7 Tue Feb 11 16:18:12 2014 : Info: [ttls] Session established. Proceeding to decode tunneled attributes. Tue Feb 11 16:18:12 2014 : Info: [ttls] Got tunneled request EAP-Message = 0x020100890d800000007f160301007a0100007603012490ba67ff4c044ccc1520fbd0abc0c150ce517483f8928492165c55754d2c10000048c022c021003900380088008700350084c01cc01b00160013000ac01fc01e00330032009a009900450044002f009600410007000500040015001200090014001100080006000300ff01000005000f000101 FreeRADIUS-Proxied-To = 127.0.0.1 Tue Feb 11 16:18:12 2014 : Info: [ttls] Sending tunneled request EAP-Message = 0x020100890d800000007f160301007a0100007603012490ba67ff4c044ccc1520fbd0abc0c150ce517483f8928492165c55754d2c10000048c022c021003900380088008700350084c01cc01b00160013000ac01fc01e00330032009a009900450044002f009600410007000500040015001200090014001100080006000300ff01000005000f000101 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "anonymous" State = 0x8ffc85fa8ffd88bdbab7b09df5e88573 server inner-tunnel { Tue Feb 11 16:18:12 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 16:18:12 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:12 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:12 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:12 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:12 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:12 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:12 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:12 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:12 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:12 2014 : Info: ++[control] returns ok Tue Feb 11 16:18:12 2014 : Info: [inner-eap] EAP packet type response id 1 length 137 Tue Feb 11 16:18:12 2014 : Info: [inner-eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 11 16:18:12 2014 : Info: ++[inner-eap] returns updated Tue Feb 11 16:18:12 2014 : Info: [files] users: Matched entry anonymous at line 45 Tue Feb 11 16:18:12 2014 : Info: ++[files] returns ok Tue Feb 11 16:18:12 2014 : Info: ++[expiration] returns noop Tue Feb 11 16:18:12 2014 : Info: ++[logintime] returns noop Tue Feb 11 16:18:12 2014 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 11 16:18:12 2014 : Info: ++[pap] returns noop Tue Feb 11 16:18:12 2014 : Info: Found Auth-Type = inner-eap Tue Feb 11 16:18:12 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 16:18:12 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:12 2014 : Info: [inner-eap] Request found, released from the list Tue Feb 11 16:18:12 2014 : Info: [inner-eap] EAP/tls Tue Feb 11 16:18:12 2014 : Info: [inner-eap] processing type tls Tue Feb 11 16:18:12 2014 : Info: [tls] Authenticate Tue Feb 11 16:18:12 2014 : Info: [tls] processing EAP-TLS Tue Feb 11 16:18:12 2014 : Debug: TLS Length 127 Tue Feb 11 16:18:12 2014 : Info: [tls] Length Included Tue Feb 11 16:18:12 2014 : Info: [tls] eaptls_verify returned 11 Tue Feb 11 16:18:12 2014 : Info: [tls] (other): before/accept initialization Tue Feb 11 16:18:12 2014 : Info: [tls] TLS_accept: before/accept initialization Tue Feb 11 16:18:12 2014 : Info: [tls] <<< TLS 1.0 Handshake [length 007a], ClientHello Tue Feb 11 16:18:12 2014 : Info: [tls] TLS_accept: SSLv3 read client hello A Tue Feb 11 16:18:12 2014 : Info: [tls] >>> TLS 1.0 Handshake [length 0036], ServerHello Tue Feb 11 16:18:12 2014 : Info: [tls] TLS_accept: SSLv3 write server hello A Tue Feb 11 16:18:12 2014 : Info: [tls] >>> TLS 1.0 Handshake [length 09fc], Certificate Tue Feb 11 16:18:12 2014 : Info: [tls] TLS_accept: SSLv3 write certificate A Tue Feb 11 16:18:12 2014 : Info: [tls] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange Tue Feb 11 16:18:12 2014 : Info: [tls] TLS_accept: SSLv3 write key exchange A Tue Feb 11 16:18:12 2014 : Info: [tls] >>> TLS 1.0 Handshake [length 0062], CertificateRequest Tue Feb 11 16:18:12 2014 : Info: [tls] TLS_accept: SSLv3 write certificate request A Tue Feb 11 16:18:12 2014 : Info: [tls] TLS_accept: SSLv3 flush data Tue Feb 11 16:18:12 2014 : Info: [tls] TLS_accept: Need to read more data: SSLv3 read client certificate A Tue Feb 11 16:18:12 2014 : Debug: In SSL Handshake Phase Tue Feb 11 16:18:12 2014 : Debug: In SSL Accept mode Tue Feb 11 16:18:12 2014 : Info: [tls] eaptls_process returned 13 Tue Feb 11 16:18:12 2014 : Info: ++[inner-eap] returns handled } # server inner-tunnel Tue Feb 11 16:18:12 2014 : Info: [ttls] Got tunneled reply code 11 EAP-Message = 0x010203800dc000000cb5160301003602000032030152fa93941ae584486e95af9fdcae2171bb8c927a7e563c124bf844e534a7361900003900000aff01000100000f00010116030109fc0b0009f80009f500047c3082047830820260a00302010202010b300d06092a864886f70d0101050500304e310b30090603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d20446576696365204341301e170d3132303330383134333730355a170d3232303330363134333730355a3040310b30090603550406130255533120301e060355040a0c17 EAP-Message = 0x4361726573747265616d204865616c74682c20496e632e310f300d06035504030c0673767239393830820122300d06092a864886f70d01010105000382010f003082010a0282010100b76170da326c4bcef5c64402d66566b7304e83d3ceeb33aefe0a63037d8441aa10bf72a2e011dc859f65f544bd2fc152e1476d62d0cd735d0f8cb6e47b4620438b9004e66f88504c7ffddeb11f27ee46ce0c2bd84d81db792252fa71d7a83408de900afbcfffd7251aa702a2345d7bc5aba0d762d6a2ad23af0098043482c8897b2faf91ab0f5d8312d5af33796884a4ce52e28cd3d345ea48113b2662c3c3081b1f634e3801b8e52fb6bc29c17e8a851b3fb44f EAP-Message = 0x88ead4013f140c10818a9cf80d1d9d5375d5552a403e71f10412774bfc835162ecd40bf7d98f8e1127a5be8a0bed7829fe0636f4f293537646ca4bea3d5152cf78cca369e58cb94b91e1269d0203010001a36f306d30090603551d1304023000300b0603551d0f0404030205a0301d0603551d0e04160414a099086e62bcbca450563c4c0d0d1a303c1ca52e301f0603551d23041830168014f4638fe7f1bcfcd00e02e0a3387e5ecfce60663030130603551d25040c300a06082b06010505070301300d06092a864886f70d01010505000382020100633588e4eaf0e4e090b8ff48b1ccf651af706f3d080149190166d2a325a01fa44360c26da30852 EAP-Message = 0xbdb26b21401cf6d789c83d725c3affa9c7a2954349a249868c2c607b6a5b586dfcdf091929e9d15a0a1ecb0c6cd092cf7883d7ca795a5125a5ac1ca78f9f01cd3fc1d1d492dea54cba85a87bd087fcff5d7acaeafe8899a1523b63944eba4c1624833e9d93e8fb3092faebf5bc664c95719436e6c957019a91ede0e8e2fb3d39b0ec9e56810b19167a Message-Authenticator = 0x00000000000000000000000000000000 State = 0x8ffc85fa8efe88bdbab7b09df5e88573 Tue Feb 11 16:18:12 2014 : Info: [ttls] Got tunneled Access-Challenge Tue Feb 11 16:18:12 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 220 to 10.0.1.254 port 1025 EAP-Message = 0x010903df1580000003d517030103d0ad59c96654ae1dd88fe37f23aa768b8099ac08de3c8fdbb47ffcead68bfd6e6dce52f3f4b4eed13cefd423913767ea051db35da37bc5d88b8a6eb1006c2f71aa7209020b76a94ae0ed652f13519e165af3723718ee00fcd7c3a49428289925fbedfb56ed8cbeff59c7ff763b262489dcf085b8fc997086ca1e004f5e5361404f9d3b5731a7bd7bc566611ff77914ac724ff08e091f4b6cc7b26a943ef41cd97363794945db2e9605b7d85f8f854d278af2c7101a8f5804872db117a642e9b9da85d0974deb6f05d0bc1d4e8093e67a3bf03fc65ca6b8d21f87a5124d2d40e6e380a4728cac1230aabc49b91cabcd EAP-Message = 0x17be20bc1c78563e013eb153f7183ff8ca4bcb1a0e8160b7ecb484147e6a33acac358f4fe0979c29916622dbd0f426a648dee0f76efa852749a75917dddfd4a6fd9851b24cfd5b6d32137710b8b8a4e72241bd93a28973105c1cf9615595d56f80c7c8220ebf9dee507436d0ab0323533f65043bb3e55ab7e60af74bce75118a1d345003015c682f139b5bab1d937c64777131e9849fb5a9c6c0905279c3b3324929f2a1136d3a52f096f570d26dc0ce9e7088eff06ea7144888004cb1bc042bfe760b7545728b8b1896bf002faa6df4d6386aa1554e81c12421c6f42126e210a2bc6281dc6ade44332f240ea89adbd81db3aaba319ddc31aa99fff56c EAP-Message = 0xa188a513aebb068d29a091703319448149a981a56495d21748024a03cf6119f921e64e1dc133694b84c9f27055437dc795204ecdc49c8a4084f45c98d0fad7315dd1977522be13554cba6ec4cbe0139d3a94042d3f5eae564829ef6b02c6667e3e9f7e7bf16a3baf7b992860ea589142c384ea1a326d8011aae705ee788cc701ca3ce75e4bdda97caf1810a20c667fa352f0150c28201ed3f191b22ec3455b39d59e0bdd716761c33ed09a4c5961aa952abfcdcf102e0dc067fbac74df6211b9db70a2baefc120c5f26fa5ff159ad0b060a641851f98ab8732645fbc689f0f718ae9f81cc5893d7b77f47d02cde630b1ef68b0490578e741290e476a11 EAP-Message = 0x622836013c5fc1413c05b4f366d6265db3a9d0f832289ea3a088f666ff1bfe3aecece5a69578a0fbf69bed8678ecd4c0afaec733091cc78692605eaa89e41efab17c779180232a5e70ff4c63ca658cb2c035e3aeb87f4ae23470eb5f17fcd38c247e16e0265540266c427468c81f46fc99767d434679024ebc6c1dddbd923bd726e2eb47378326bb9e8580ea4f0bae8d8cc39f1ebafce5d03f335646909efce54af8fdfb7509c08814e946742e78a53b1e7b6ed5077941ee28318197eea0844314be44a40415c693d8635375df676a2406c74b3bf0eae3c9688e58c0c8ebc6eaa82e0b39e86cb2b5 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x325569cf3a5c7c29029862537b62c2e7 Tue Feb 11 16:18:12 2014 : Info: Finished request 8. Tue Feb 11 16:18:12 2014 : Debug: Going to the next request Tue Feb 11 16:18:12 2014 : Debug: Waking up in 2.8 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=221, length=290 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x0209006415800000005a1703010020b44ee68322cc6c46cb35ca5291e90273c347edf6fa833efb4539bd6b4dce1c0a17030100302aa7c5542088c6e78ad376dd5dc25b37452185dd06e4c433752fbe4efc5df4f49e43d7b407951387b464ca303ea1d0f2 State = 0x325569cf3a5c7c29029862537b62c2e7 Message-Authenticator = 0x3089e0481b24585447ca8291416a8763 Tue Feb 11 16:18:13 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:13 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:13 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:13 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:13 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:13 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:13 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:13 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:13 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:13 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:13 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:13 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:13 2014 : Info: [eap] EAP packet type response id 9 length 100 Tue Feb 11 16:18:13 2014 : Info: [eap] Continuing tunnel setup. Tue Feb 11 16:18:13 2014 : Info: ++[eap] returns ok Tue Feb 11 16:18:13 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:13 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:13 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:13 2014 : Info: [eap] Request found, released from the list Tue Feb 11 16:18:13 2014 : Info: [eap] EAP/ttls Tue Feb 11 16:18:13 2014 : Info: [eap] processing type ttls Tue Feb 11 16:18:13 2014 : Info: [ttls] Authenticate Tue Feb 11 16:18:13 2014 : Info: [ttls] processing EAP-TLS Tue Feb 11 16:18:13 2014 : Debug: TLS Length 90 Tue Feb 11 16:18:13 2014 : Info: [ttls] Length Included Tue Feb 11 16:18:13 2014 : Info: [ttls] eaptls_verify returned 11 Tue Feb 11 16:18:13 2014 : Info: [ttls] eaptls_process returned 7 Tue Feb 11 16:18:13 2014 : Info: [ttls] Session established. Proceeding to decode tunneled attributes. Tue Feb 11 16:18:13 2014 : Info: [ttls] Got tunneled request EAP-Message = 0x020200060d00 FreeRADIUS-Proxied-To = 127.0.0.1 Tue Feb 11 16:18:13 2014 : Info: [ttls] Sending tunneled request EAP-Message = 0x020200060d00 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "anonymous" State = 0x8ffc85fa8efe88bdbab7b09df5e88573 server inner-tunnel { Tue Feb 11 16:18:13 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 16:18:13 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:13 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:13 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:13 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:13 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:13 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:13 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:13 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:13 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:13 2014 : Info: ++[control] returns ok Tue Feb 11 16:18:13 2014 : Info: [inner-eap] EAP packet type response id 2 length 6 Tue Feb 11 16:18:13 2014 : Info: [inner-eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 11 16:18:13 2014 : Info: ++[inner-eap] returns updated Tue Feb 11 16:18:13 2014 : Info: [files] users: Matched entry anonymous at line 45 Tue Feb 11 16:18:13 2014 : Info: ++[files] returns ok Tue Feb 11 16:18:13 2014 : Info: ++[expiration] returns noop Tue Feb 11 16:18:13 2014 : Info: ++[logintime] returns noop Tue Feb 11 16:18:13 2014 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 11 16:18:13 2014 : Info: ++[pap] returns noop Tue Feb 11 16:18:13 2014 : Info: Found Auth-Type = inner-eap Tue Feb 11 16:18:13 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 16:18:13 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:13 2014 : Info: [inner-eap] Request found, released from the list Tue Feb 11 16:18:13 2014 : Info: [inner-eap] EAP/tls Tue Feb 11 16:18:13 2014 : Info: [inner-eap] processing type tls Tue Feb 11 16:18:13 2014 : Info: [tls] Authenticate Tue Feb 11 16:18:13 2014 : Info: [tls] processing EAP-TLS Tue Feb 11 16:18:13 2014 : Info: [tls] Received TLS ACK Tue Feb 11 16:18:13 2014 : Info: [tls] ACK handshake fragment handler Tue Feb 11 16:18:13 2014 : Info: [tls] eaptls_verify returned 1 Tue Feb 11 16:18:13 2014 : Info: [tls] eaptls_process returned 13 Tue Feb 11 16:18:13 2014 : Info: ++[inner-eap] returns handled } # server inner-tunnel Tue Feb 11 16:18:13 2014 : Info: [ttls] Got tunneled reply code 11 EAP-Message = 0x010303800dc000000cb5f57cc0140449bae0b3f0fbe6feb4aa2119ddcf7cf9c82cb830b9d97943ae20c9a2c28df58e6a3cf9064d68203a73858dcc2455b827199199f2705a4f52c4931feb6a04496b15dcf9936996b90977167140475734fc8447b952a564dc73c2bd6a5146ead281a845b3046297845fb323fd7050a6d3f049d0d20dd2e22b980edb5da743adb1ca429374cbd34aa953ddc6615ca92f250ffc13d0ce8594d6e370e2961ed256eba43cba54fdce0a729b4fcd7de584f891ed4f799af530a855ef1c1862f4c9de40dde31369a15792a23bbd73dba235ddd74669ec807f48547f1422aba3bfcc89234c0fed5d151fdafb29b19829bbb67a EAP-Message = 0x281f561721450d5b3d03b983d73137fdff06ca0b3062f6a2a6e0286479c6f327ff54fc19a4fe0283c53d6cd151ccfd25e5e96cad3568119d2d711aec91291649709d77cea8abc804e673e4ec168a844b1312158c0eba53ac455e9d5cd20005733082056f30820357a003020102020900cdd24c0540e41aa7300d06092a864886f70d0101050500304e310b30090603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d20446576696365204341301e170d3132303330383134333433395a170d3232303330383134333433395a304e310b3009 EAP-Message = 0x0603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d2044657669636520434130820222300d06092a864886f70d01010105000382020f003082020a0282020100c15110872e2e4a5740b2806926c2a8987dd7aab026b7ef0d2eff5321d107c6fdef6ba3e2380f7e7327ecdde1de555a61c300e738206831313edff00753619e76aac958bfcbabb6139aeed98a6b236c4877befb74390a7b73872cab14a974e3c039b97b98dde3cde395b74806a81ade977ec12bfa3d8796b175bc72556c62f3c6242eeb1fe0046f6ef423a48fb2151ac753c3 EAP-Message = 0xe46525ec5715e8eb6cdc235e8c0c40ff219999b616a88feb3d878fa4ba057004dff8709d028fffe2e088f30b1102f873529a1422d612450cd062130ac1b13c1af3e52ef94d75583a494fc733b851109c0c8f1c03f9d96aa9eb7b3f4c31b342c9640c3df94e9bbe833f8dd984befb55e7bec0664efb09769b23cfe7b3e36a1088f03ec961981da5216d Message-Authenticator = 0x00000000000000000000000000000000 State = 0x8ffc85fa8dff88bdbab7b09df5e88573 Tue Feb 11 16:18:13 2014 : Info: [ttls] Got tunneled Access-Challenge Tue Feb 11 16:18:13 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 221 to 10.0.1.254 port 1025 EAP-Message = 0x010a03df1580000003d517030103d028e488b22f92ac28bbdf52d2ba450dd661024876e2f967ae85334726ea7a31ff9d1f7bb0d98777108f44a11df9ec7199dee0bfc45175471d2f031bee5a4e0ac3efb66a4981a2259fe08ce9b2745c7b1f700cb65a8779f325dc8b935dc9d084e59b17493fba4c9679bbcf5bd0a5968a8b1d678d9e56b6ee2283f9c2f2e13b49549cad1c55ea622365d53cd61cf60c45e707f0c98462f691192e1dca60a13b515a5570dfa923a1d6623bc86956cf4194545403e1b5b04522851aaf0107f03aa3a4e43a7541789ff668a04d7f1e05d0ec6286204509e6fc186bc77951a70e851d4d5a1f378b96d28e9be84e53379131 EAP-Message = 0x7d5981a1ed56cf6f9165cc8d83b3cead2a259d492821ea0a0b7118f332e98b4452ae18293f34b04db25868ea78c510b81bcd0572309101dbe64b6cb597bc53c42f661352ae9f3e25ca3795ecfd6e24fc220c56c8e88d9fa08c43ba6c088156b7eca8d265a135ee4fe3ccf17136360a43c03c3ad8d4d1c4915a35211bc0194a494d5b0a2fe75d0ec13b250e8c3b564995937035217d9a49eed060efd7c1acee153def8117b3ab8cc2a68a80ffbc09aac6d005462178a394db7266822853af9d7c1507e6611afdfe5f0b1a5da89dbed844c67571a8460e725fd5666e4e29d3caf5220f9bded75ef4a63c43cb0307d18ffcecdbc6d5c671ceb27486cda9a0 EAP-Message = 0xc9f58a3164073f5d54b54c0c7aa11bf381470ef6fd0f768cf8087ff6a445d21e317a30c9d857a7a7ba8d7066b7b2765d7b43ccd6a240f005c08a4dc98fd64332598241db1060e32f1ef5b4fcfc6136ad8f7500ec023f46e46cf4abea71a0a8d9ed9e3b7efe0cd389ec639871efeb1220598a010bc7587b75e60097934843b4a688f35802a003036d54dea177c47bb293ffa5c6c888a4581b83e7a8554ca40aa53f269a807b0d47a29b2a9cf8a97d6a183f10c46529322985dd53b04d0e5020cb20b65fe8757a0f35a7d6fccb55bcf928a90970324b8e28264969edb7d97f406e538d183781fee33fece865a4143b43bc5f664e21cda060765332ace367 EAP-Message = 0xaa84169f7490dab9c3d13317842f4d32ed16b83649207094c6950d82f3b2a98c71cf541d380e5d96f59da96d1bb5bb813b261d9686f4d06d1ecaba3f5b8ff683c6afed168a7586635d2ca460d5b410a9cc31713894d7ddc2a7a8cbeb18461f233415d17431b709b28088736833bde6c389ea117e3c9650c6c2f95b3bf26272bfc58765d9885b1622e914c0fc82fa0e7aa22c235917ea348ee1f649aaccd79fdcac4406290f516654da3b7d94dd7cab784ec924791eb47bfd6feadd05b387455a6ef29e23cdc7c88d8bbdfdf51938ff41ff4ddc7e9019831a69229fb6ba7bc18fd6a9fa086a6ba28b Message-Authenticator = 0x00000000000000000000000000000000 State = 0x325569cf3b5f7c29029862537b62c2e7 Tue Feb 11 16:18:13 2014 : Info: Finished request 9. Tue Feb 11 16:18:13 2014 : Debug: Going to the next request Tue Feb 11 16:18:13 2014 : Debug: Waking up in 1.5 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=222, length=290 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020a006415800000005a170301002087c0d862449443246ab63a05dec044e0f500d83673ee28019c88ea68bd419b1a1703010030bb6bf89b456d2f20ea8882c269139c77618c32ff4d8f293fc4167382c3828a278240108196a8c5d22d0178fc9ff53625 State = 0x325569cf3b5f7c29029862537b62c2e7 Message-Authenticator = 0x1202e406a0c0d773b8d6f33c3d11d870 Tue Feb 11 16:18:14 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:14 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:14 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:14 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:14 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:14 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:14 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:14 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:14 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:14 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:14 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:14 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:14 2014 : Info: [eap] EAP packet type response id 10 length 100 Tue Feb 11 16:18:14 2014 : Info: [eap] Continuing tunnel setup. Tue Feb 11 16:18:14 2014 : Info: ++[eap] returns ok Tue Feb 11 16:18:14 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:14 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:14 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:14 2014 : Info: [eap] Request found, released from the list Tue Feb 11 16:18:14 2014 : Info: [eap] EAP/ttls Tue Feb 11 16:18:14 2014 : Info: [eap] processing type ttls Tue Feb 11 16:18:14 2014 : Info: [ttls] Authenticate Tue Feb 11 16:18:14 2014 : Info: [ttls] processing EAP-TLS Tue Feb 11 16:18:14 2014 : Debug: TLS Length 90 Tue Feb 11 16:18:14 2014 : Info: [ttls] Length Included Tue Feb 11 16:18:14 2014 : Info: [ttls] eaptls_verify returned 11 Tue Feb 11 16:18:14 2014 : Info: [ttls] eaptls_process returned 7 Tue Feb 11 16:18:14 2014 : Info: [ttls] Session established. Proceeding to decode tunneled attributes. Tue Feb 11 16:18:14 2014 : Info: [ttls] Got tunneled request EAP-Message = 0x020300060d00 FreeRADIUS-Proxied-To = 127.0.0.1 Tue Feb 11 16:18:14 2014 : Info: [ttls] Sending tunneled request EAP-Message = 0x020300060d00 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "anonymous" State = 0x8ffc85fa8dff88bdbab7b09df5e88573 server inner-tunnel { Tue Feb 11 16:18:14 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 16:18:14 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:14 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:14 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:14 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:14 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:14 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:14 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:14 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:14 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:14 2014 : Info: ++[control] returns ok Tue Feb 11 16:18:14 2014 : Info: [inner-eap] EAP packet type response id 3 length 6 Tue Feb 11 16:18:14 2014 : Info: [inner-eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 11 16:18:14 2014 : Info: ++[inner-eap] returns updated Tue Feb 11 16:18:14 2014 : Info: [files] users: Matched entry anonymous at line 45 Tue Feb 11 16:18:14 2014 : Info: ++[files] returns ok Tue Feb 11 16:18:14 2014 : Info: ++[expiration] returns noop Tue Feb 11 16:18:14 2014 : Info: ++[logintime] returns noop Tue Feb 11 16:18:14 2014 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 11 16:18:14 2014 : Info: ++[pap] returns noop Tue Feb 11 16:18:14 2014 : Info: Found Auth-Type = inner-eap Tue Feb 11 16:18:14 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 16:18:14 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:14 2014 : Info: [inner-eap] Request found, released from the list Tue Feb 11 16:18:14 2014 : Info: [inner-eap] EAP/tls Tue Feb 11 16:18:14 2014 : Info: [inner-eap] processing type tls Tue Feb 11 16:18:14 2014 : Info: [tls] Authenticate Tue Feb 11 16:18:14 2014 : Info: [tls] processing EAP-TLS Tue Feb 11 16:18:14 2014 : Info: [tls] Received TLS ACK Tue Feb 11 16:18:14 2014 : Info: [tls] ACK handshake fragment handler Tue Feb 11 16:18:14 2014 : Info: [tls] eaptls_verify returned 1 Tue Feb 11 16:18:14 2014 : Info: [tls] eaptls_process returned 13 Tue Feb 11 16:18:14 2014 : Info: ++[inner-eap] returns handled } # server inner-tunnel Tue Feb 11 16:18:14 2014 : Info: [ttls] Got tunneled reply code 11 EAP-Message = 0x010403800dc000000cb5ec415c7548aa7c51315941ee74c7c4e21124581dd8a3b7c4831877cbea385ce297c87149c7d1240f1d875875891bf1018a2be82bd839bf7516e693ae403bff49731aadbd295b96f062caef2565d0107954809f92d89b786787b712a0360efbe34c0c926a568550642de96d84940b2996b05873c2635786520315a3fcd9e79924f7b4b81d4ebf751ca81b810ddfed5f016bd0befadf29863d0ccbd4cdfccc3c3b69c831ef10e11b66b563c2f04a31bf743ee3896b2f052806fd0d0b21604023707f5cac625ca44f32b346d8f7def63c2ec1cdc75037bf8a82c3d26a8a0124010f7acb8d33970203010001a350304e301d060355 EAP-Message = 0x1d0e04160414f4638fe7f1bcfcd00e02e0a3387e5ecfce606630301f0603551d23041830168014f4638fe7f1bcfcd00e02e0a3387e5ecfce606630300c0603551d13040530030101ff300d06092a864886f70d010105050003820201002aedad2a256b0fd6d3f11f74c30f1ed9652c8d82bff6779c09a32d6dea2fb9febd4525b7b3105b13967c3b5d5d61745264620c312d6fce405dd4ddfe4b72abe7e0d2c475b99133294a5cc91c4c328624bed219d73e62dd222b3a76f2de154114ae1e0b7fd615702ac7e1bbc30abf603258daa805479ebec4d0bea30599881df284a427dcf4396efda6122e65c265df815593f1224194deb4d4fe52d86337fd4e EAP-Message = 0x59331b5d3d0a40effc7d49a1a7860f7dc6d67ee31df8d30780f0dcf1353ef7b892d2da1aa70c436e9250dd9aade9ce5bcedc64cc959be7965ea227a8f1512e794f06e30e1294f314b6ae77ade19c0d73600259c4c7942204d7b58843bd9a65bb28657ae46cb4737c26a00421559de2e0e9613d29d20d30fe65fb2283b1d650092fbb8c62c5b091aec7fb64ff3c65487de63740c93c4adf2253abd0c4ae3afe09298ac0b468c0290130f3a1c08425dee9b7ca0004fbb32d5f4bba7a2517b130308b537fd0cde88c6cf035cc6c9581d2138c17e3187a6a926983dd64081680c56a57bd6696e18fbd28ab9a9ad54578d0bdeb1ffa28bfa39f6fd5acc6481d EAP-Message = 0x66beb3d335c77c76994fc91228198746f6133c9d3b435df2daae2a114bf7641b6298cbd23b52606c26832285ac539dfb2cfc362ffa520c374a44ad55584edb2505ecd417ad985065cc54a7a2bb4f5dc39f70bfc35fe207de3a79ed8c4bc4d30addb818160301020d0c0002090080d0d6b54e7f02a1f12b53d11521a2df0f47df59ba4e72828003bc47 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x8ffc85fa8cf888bdbab7b09df5e88573 Tue Feb 11 16:18:14 2014 : Info: [ttls] Got tunneled Access-Challenge Tue Feb 11 16:18:14 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 222 to 10.0.1.254 port 1025 EAP-Message = 0x010b03df1580000003d517030103d063125e58f7b50b2224f3d744e342485fa9f7834179928e16984d6788f91e408d2842974d55b44eff25bcd4889424471adfc5519121ed4f75c790575cdcb6ef26c04fcb4be1fff448c93599d7dc48d9ea85045ddbd6e3df2a516f355a4e9453fc34ead7849ee05e0ef55f729f01dbf914b8fbe55d75275e99ead089af34c6788d66328dcb052f24e2e7e4ec0953b2048c51f7a3c7dd07f3beb221675cda2acba881d7c7421abbaec8521f09864d06c4a3094a4f179fb52738335ee3f14a5358ee2732b63d1e374fa666dc27e534d5ddd0377cd6ee9068cc401e1a109c0c10e99b9157a173741e6972790ec5fc9948 EAP-Message = 0x5bba07d307ed366d8856be3c817b4dcb5b4e3ac4f9d893aeb92cf9529378e11ebe4de0de73f00eb36209c94518d144349a907447433e89d0f602f29e63984943efebe3e85c7946fbec1df4646d007dacd6cef82a03580212d9b857b94b8bb53d381753f9364fa2494d9faa25702e5f7d2a8d72b78f1f66e756fc4371458edaf1abba2c6174ccf1943cd6f65b372dc629af75a01f7f6733a111087a28949741aa9b15e9cd18b95a8fc86ed008b5e1cd3ebca8025f0051c22d087ec12a07ee3528e079ff5da32ca6e2b304924d8544b408d66bd2e0a62a9a68186f386c1316e8ddfc132e70a11c8fe3e13c44c81026c1b0000a55bd639a011fbccad9cb29 EAP-Message = 0x76ffedc912b3a9f346b16212cd81877cdc067fa22194f9038ad9879695ee470a07de51d859282905a038304b132f3fe1ccc5e97b00fa9ee63647bfe53c32ceb18dc8d8f5a3d7ad8447ef632b53b79bd483f1acc1ef725c7ab01495730e05d920ab9f18076932ed6ace2987c0b8f1ff2d7cc99f089568737560073dc50e619b4422b36635c1755d950fe0c332539d58a53bf40f3d277b432ebfbc2eda14ac98727d0033efa9f9ed31a943a5f2f069a35f8b020f8f9311557bc04e8e028efc894684039052d5d05c27db661e91f7b309946310f24cd86ece18833347c3c92490d91b87ef88e0f661fec44e8dba482c1429f8451d54f1ebea7fb5f6841688 EAP-Message = 0x2cb183fa422b24782f91be473b8e57684f8f19545b6a8d4471241cc21fb618aa18066692fb65f98aa0619fc8c4449e3f6594e431409e26d774ed5c7602fbeac0211ccde915798f0432d938a02c0e9e7f74578147d3af31428e3ebe108b9e26518b3a89f82101c913c9a4b7c73315e18df3af0f86a9bc1eb000f0f64854045baf976d663b427d79020f16bba6f2f51bdd567f2fc29794c334ee1500be057c793c5fda9f451e17ce7037a5f704a0f59dccab64012955d9ee4676f7f08f9e3c23dce35fff1c5c562e768a1e7343a5ca8b1b0375d04a04530126dd03c5e4335bb6d525b6856ef9e02ccb Message-Authenticator = 0x00000000000000000000000000000000 State = 0x325569cf385e7c29029862537b62c2e7 Tue Feb 11 16:18:14 2014 : Info: Finished request 10. Tue Feb 11 16:18:14 2014 : Debug: Going to the next request Tue Feb 11 16:18:14 2014 : Debug: Waking up in 0.5 seconds. Tue Feb 11 16:18:14 2014 : Info: Cleaning up request 0 ID 212 with timestamp +9 Tue Feb 11 16:18:14 2014 : Debug: Waking up in 0.3 seconds. Tue Feb 11 16:18:15 2014 : Info: Cleaning up request 1 ID 213 with timestamp +10 Tue Feb 11 16:18:15 2014 : Info: Cleaning up request 2 ID 214 with timestamp +10 Tue Feb 11 16:18:15 2014 : Debug: Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=223, length=290 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020b006415800000005a170301002032323bc0de2f60e1f02b33ee11c3fd97378a719b793de476eb1744f6ea8523591703010030f0e3e2c6cf17707a2ff9f81e8383412a6315341df392e81c0a8a936e553bdf78c121edf443b888071f2504d02eb0f79e State = 0x325569cf385e7c29029862537b62c2e7 Message-Authenticator = 0x6de8e1f188038bb1d97b62dd1d33ef55 Tue Feb 11 16:18:15 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:15 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:15 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:15 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:15 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:15 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:15 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:15 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:15 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:15 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:15 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:15 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:15 2014 : Info: [eap] EAP packet type response id 11 length 100 Tue Feb 11 16:18:15 2014 : Info: [eap] Continuing tunnel setup. Tue Feb 11 16:18:15 2014 : Info: ++[eap] returns ok Tue Feb 11 16:18:15 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:15 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:15 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:15 2014 : Info: [eap] Request found, released from the list Tue Feb 11 16:18:15 2014 : Info: [eap] EAP/ttls Tue Feb 11 16:18:15 2014 : Info: [eap] processing type ttls Tue Feb 11 16:18:15 2014 : Info: [ttls] Authenticate Tue Feb 11 16:18:15 2014 : Info: [ttls] processing EAP-TLS Tue Feb 11 16:18:15 2014 : Debug: TLS Length 90 Tue Feb 11 16:18:15 2014 : Info: [ttls] Length Included Tue Feb 11 16:18:15 2014 : Info: [ttls] eaptls_verify returned 11 Tue Feb 11 16:18:15 2014 : Info: [ttls] eaptls_process returned 7 Tue Feb 11 16:18:15 2014 : Info: [ttls] Session established. Proceeding to decode tunneled attributes. Tue Feb 11 16:18:15 2014 : Info: [ttls] Got tunneled request EAP-Message = 0x020400060d00 FreeRADIUS-Proxied-To = 127.0.0.1 Tue Feb 11 16:18:15 2014 : Info: [ttls] Sending tunneled request EAP-Message = 0x020400060d00 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "anonymous" State = 0x8ffc85fa8cf888bdbab7b09df5e88573 server inner-tunnel { Tue Feb 11 16:18:15 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 16:18:15 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:15 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:15 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:15 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:15 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:15 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:15 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:15 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:15 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:15 2014 : Info: ++[control] returns ok Tue Feb 11 16:18:15 2014 : Info: [inner-eap] EAP packet type response id 4 length 6 Tue Feb 11 16:18:15 2014 : Info: [inner-eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 11 16:18:15 2014 : Info: ++[inner-eap] returns updated Tue Feb 11 16:18:15 2014 : Info: [files] users: Matched entry anonymous at line 45 Tue Feb 11 16:18:15 2014 : Info: ++[files] returns ok Tue Feb 11 16:18:15 2014 : Info: ++[expiration] returns noop Tue Feb 11 16:18:15 2014 : Info: ++[logintime] returns noop Tue Feb 11 16:18:15 2014 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Tue Feb 11 16:18:15 2014 : Info: ++[pap] returns noop Tue Feb 11 16:18:15 2014 : Info: Found Auth-Type = inner-eap Tue Feb 11 16:18:15 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/inner-tunnel Tue Feb 11 16:18:15 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:15 2014 : Info: [inner-eap] Request found, released from the list Tue Feb 11 16:18:15 2014 : Info: [inner-eap] EAP/tls Tue Feb 11 16:18:15 2014 : Info: [inner-eap] processing type tls Tue Feb 11 16:18:15 2014 : Info: [tls] Authenticate Tue Feb 11 16:18:15 2014 : Info: [tls] processing EAP-TLS Tue Feb 11 16:18:15 2014 : Info: [tls] Received TLS ACK Tue Feb 11 16:18:15 2014 : Info: [tls] ACK handshake fragment handler Tue Feb 11 16:18:15 2014 : Info: [tls] eaptls_verify returned 1 Tue Feb 11 16:18:15 2014 : Info: [tls] eaptls_process returned 13 Tue Feb 11 16:18:15 2014 : Info: ++[inner-eap] returns handled } # server inner-tunnel Tue Feb 11 16:18:15 2014 : Info: [ttls] Got tunneled reply code 11 EAP-Message = 0x0105025d0d8000000cb5d4fe2ca20295bde105d30e7455ad165507b5a71caa9e4dbeab3dd7442ca803afe3eba4e661dc2a84bc717ea92750d76c663186702f275656b7b31770f9492b41fecb7cc2e2365235bb45c188e5cdc8c77331912903f2d2c42f27e86a5146827964cd4b70ab000102008002b1f074694aa88d1ea95c17fa7151846ad0413ef24f8befdadf1f6025628417d0abec715aec24ff2eddaf1c0d0dd1fd1b3f584d6eb74fe5c974d2ae7e4b018bcd8ad82f124245d59b96bec29bb2fef1172e6af0ec8911f4e98a5315fdc7b1e43c2039a723e2c53a0d99c38d7d6615f84a6f3211fa50702e4e4235ab02a8032d01001041ffd98f6d9c EAP-Message = 0x722ab0ea66bf340c4ff63bf9f7f55d6f52e9d631450d447e8946ab7b1220e48025b4b72feec2ddb0ff64c742da97348b58e069898be67b1046821fa7a24b0da9c98a6a77daea9c0d0a3156a824dfce703e33b23662e503e1e470391a58620bba37098efcc7adebc79e43bb6aa116af23c5061e3679379f289ccaca4c756db71f74d2b0b3b16980f4f65801a5927ec041f92f62e337367e0af1fa4fa829a40182acd753d05ddfcad688200435362cc9fbc6b7a669b61263dfac66f4281a3daa129d940b4377c6050114ffbc23f9033a28ac3f5ae59c3523ce9a79a18b6d279ecab240f15b07ffccc024d2e969649d22812235cec847b8feff3e16030100 EAP-Message = 0x620d00005a05030401024000520050304e310b30090603550406130255533120301e060355040a0c174361726573747265616d204865616c74682c20496e632e311d301b06035504030c144361726573747265616d204465766963652043410e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x8ffc85fa8bf988bdbab7b09df5e88573 Tue Feb 11 16:18:15 2014 : Info: [ttls] Got tunneled Access-Challenge Tue Feb 11 16:18:15 2014 : Info: ++[eap] returns handled Sending Access-Challenge of id 223 to 10.0.1.254 port 1025 EAP-Message = 0x010c02af1580000002a517030102a01cda24d09d49dcb8ca520352c74afe45f9133e2847b05e3728669ce19cb1b2bf4feff1adabefd991c8acf5b0c973bfe43e5f9d7bdf5a6b767db614dcd796087a9d79ef23bc886c7686245c602fbc8a9ec7a1c08fa27f14abf0c7bf8e5df0b1e6600e15645b6a7b676e45db76000fda6b362d1e0e130abb509abf8f7698b9c5061b7ce58e5cca57941c8d1d945eeec5ff515da8deaa034eec2367109b8ad50f05eeebc1dd1b5815a7a2a88d1f1efbd3256d9493434d0ffc4de30bc7592c496c44202667b84cb425e2ac03f99756ef1d112b103d6eb0f172f87a42ecc3e9c2d8e7b4d77413c8b0518765ee0c5b1802 EAP-Message = 0x6d6c53274eb1b1fdb12e1dc5f7666f2c9c2b4d2b68c627d224a06250abca477012ac84f98c170461fd5ad9510ff7a450035d196c2203371ec9d5880cf2bf32231684182b1c4ca52f454518bf88494599930a2d4fd87e8e461015c535fbadeaeea9ab902898b57e8fd5d3645890501d1471daf69fc72055dc15b67bc78286b44777c60a80cf8341d027792cc98b852592f340bb33d8c14f06ddc9ac647b2ef9fe2a86348ad9c5302936ca9e637fd777149fefb7023de902eb66bc47d22034eadb9322215a9cea8a0fbc065646566117fdbc0464e54e83e8c6556b7c5d3a14629ae7a4804bcec25dcc785ab5a6ec4e7646c5d58f39b33e2e63f6c0c43b1c EAP-Message = 0x14dbf81cda861342ab4db2a7f18f3050aed1ad6ba4ee04092a53192f034ceebaa196d99a9fe518241b3c6502aeadc582b3c322bb567fa0a41928b8c0e7f6328330b33af79f5052bf3c37ae0ed79f3cb5fe0df51a53c15e0a3d639ac0a2cfdfb1606a493114d6bc2a5ea2a4232904e2ffc6bd510202b7204b97e5faae72fd3fbbf7fc523fdef77d90de465da29dc928f6fb3d4ea9c95f8273096f9d7be9feaf516160e7bc491affd48c77625d63e914fbd293176c9c Message-Authenticator = 0x00000000000000000000000000000000 State = 0x325569cf39597c29029862537b62c2e7 Tue Feb 11 16:18:15 2014 : Info: Finished request 11. Tue Feb 11 16:18:15 2014 : Debug: Going to the next request Tue Feb 11 16:18:15 2014 : Debug: Waking up in 0.2 seconds. Tue Feb 11 16:18:15 2014 : Info: Cleaning up request 3 ID 215 with timestamp +10 Tue Feb 11 16:18:15 2014 : Debug: Waking up in 0.3 seconds. Tue Feb 11 16:18:16 2014 : Info: Cleaning up request 4 ID 216 with timestamp +11 Tue Feb 11 16:18:16 2014 : Debug: Waking up in 0.3 seconds. Tue Feb 11 16:18:16 2014 : Info: Cleaning up request 5 ID 217 with timestamp +11 Tue Feb 11 16:18:16 2014 : Debug: Waking up in 0.3 seconds. Tue Feb 11 16:18:16 2014 : Info: Cleaning up request 6 ID 218 with timestamp +11 Tue Feb 11 16:18:16 2014 : Info: Cleaning up request 7 ID 219 with timestamp +11 Tue Feb 11 16:18:16 2014 : Debug: Waking up in 0.3 seconds. Tue Feb 11 16:18:17 2014 : Info: Cleaning up request 8 ID 220 with timestamp +12 Tue Feb 11 16:18:17 2014 : Debug: Waking up in 1.3 seconds. rad_recv: Access-Request packet from host 10.0.1.254 port 1025, id=224, length=1596 User-Name = "anonymous" NAS-IP-Address = 10.0.1.254 NAS-Identifier = "00:24:01:12:de:7a" NAS-Port = 0 Called-Station-Id = "00-24-01-12-DE-7A:RADIUS_TEST_AP" Calling-Station-Id = "00-0E-8E-42-CB-20" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020c057415800000056a170301002043b9a91c7f9fcd828f0615341c57fb895217f0833a3d02530faa0ee08e2b239a17030105409086e4a8c997e3194b10882d01219532d26196e94e8aa1d6b6d19f46b237af864a9c409c4f77c401d0ccee5044fd588fb313acac38359d0575dec4acdfa1ca8491ecb0fae9569501f476eb40e65df3a55539b35763501bbe00c2ffc3ea2f6b9f6fc96a197d081b47e21a5c93d61139e7c25ab8f25318883ce477c342b3d7ee0dd0393f85555d74aca5bfc2de63875536749a71a4c50244f8d5f9677272a4a158837bd6e3dc57e642f67ae1ebc9b65834850f9ede23fc27a121f12fa701524af9ecc61042d9c3e5ee36 EAP-Message = 0x3d22278251a3fce80c1daabae4b70da2b639411328f203206f79b8e7878ec7d02443c76817799b838de446df9dac2f25be42cf63b9db2788c89a463be810d540d37dd328e275234b2883bafe5991623aef428a5cad82eb859182d10665892545c96f2812e6d23bd9c677b91f35ea67bd3760637008123e35a26c34a003687d527f1d0b39167e413e7e9f435a4a743addd585ebb3f86ac4bd06dc0ee901c3f050a68f4cbf464d5e880c61167b21fd795b8cc19b9feb1fe4bec867d06d60d96e761888608b89358432c8f2319cac31aaacda59fbb1741cd20f042391f511b2704dc5594f744508982cc1f11ef59c98527ccf2f14ccaf676f914b631f7896 EAP-Message = 0xf8259cd0294afc6661e41e22eaa4deaaca23bdb9b08e2c0baaf419d1c6e406f46926daed37067aea6d0efd9a41f3296461ed40588854a7794aef639195bbe8c1335aeae1ea5b511696e8dc0aa00a994e92b860def6d95396071d44cebde1c51942845a85ded6b50943482a4d67bc0c006fee9c16690d410fccf486eb879e9c024a67e1caef90dec15be4c61ee8b23ac27ba5219da8538e61c986ba754eda95222e4e5b33496b65b9430b71f2dcf6825bea0bb10790c2edd41f0fb2eb54931193f292f37f0dcb0410ed2862cd600a79cb120c2165de1ba0de8cccaba30b49f3b00120faa593b692bb7ed7acc2a709da49126d418a4f7f79e75f3b670da0 EAP-Message = 0xdae46e2ea5ce7f3ee78e7442768545d87711ffc88075a51b099ca020274a2dbfb8a1012e687973102d442bb27da53bf1740a27fae888efb6dcfdc4aa21a9aa5018974f65937a271a346a66aa88d3bd551700c9007fbc62d22e6ca558c9a67b3cf6a0d0819cb1ef634f1ff858dd21650d197bad1d84f8b89362ef7eaeba5e870aa2ff9000838a7add5140e8f0ef057553bbf2acf1ac1f6f2f28c17d4ce5673e6cca064b08bf645ce3da651d52e5b68d426b12eb4a87b8c23c6a27cd3da6a56063d01d87971d6b119b66b2aac3a1fc950cc59d91bd665430df195bcc3a19e00b09dfd1fced0ca57c3b2d298feec36a33e3c95e338d318485f26811b36e53 EAP-Message = 0x28a6cc65d11acd2863df59e33a827dc5cccd5961818b1a140f09053eeaf32e6b406d0ff39e982bdf45901cb3a27ccadad5eb9f85d584d9e3b1e649d0c365ba732cf9f1dfa73921de4631f1f3422ad35aa18bb0dd19feed95d664b032b1acef5f54699f703fe95422c56a249b5bbaa98b9d82e1f6377933e3328332066ddd57b7100b21839e49c83f5a9846c61842a921287950791cbc4e0c80604ddd94f385da6435a0e8de3ff2751d5794cc39b1517b3e50e0c123a49ec04142f50d0ce9b060cb12319d59cf9cc0b44464f8c5c24cb23036eaaef42fc5b1414d4adc1eed4ca0af915e963fa5b8f786bb16f02636dc84b777f38bbde8aa091722b0c00d EAP-Message = 0xc1803dee022335d74a930b4c678d441f88b438d52e095621b0ed95258afd0e8a28f71ad84cf69592d65efcbba882d3062bf01425015e41a3f3c9d91a5d04b9c5c998c8bbb04ae2febb3a9283a5f2efdbaacae657741c906674a370ef88ca60e195ecaac4f3924ba56c8f79c8877aba491040a40bab3790da618c3da55a71c81a39d03b State = 0x325569cf39597c29029862537b62c2e7 Message-Authenticator = 0x09126b66c53b4950b4e1626027c9e3d2 Tue Feb 11 16:18:17 2014 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:17 2014 : Info: +- entering group authorize {...} Tue Feb 11 16:18:17 2014 : Info: ++[preprocess] returns ok Tue Feb 11 16:18:17 2014 : Info: ++[chap] returns noop Tue Feb 11 16:18:17 2014 : Info: ++[mschap] returns noop Tue Feb 11 16:18:17 2014 : Info: ++[digest] returns noop Tue Feb 11 16:18:17 2014 : Info: [suffix] No '@' in User-Name = "anonymous", looking up realm NULL Tue Feb 11 16:18:17 2014 : Info: [suffix] Found realm "NULL" Tue Feb 11 16:18:17 2014 : Info: [suffix] Adding Stripped-User-Name = "anonymous" Tue Feb 11 16:18:17 2014 : Info: [suffix] Adding Realm = "NULL" Tue Feb 11 16:18:17 2014 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 11 16:18:17 2014 : Info: ++[suffix] returns ok Tue Feb 11 16:18:17 2014 : Info: [eap] EAP packet type response id 12 length 253 Tue Feb 11 16:18:17 2014 : Info: [eap] Continuing tunnel setup. Tue Feb 11 16:18:17 2014 : Info: ++[eap] returns ok Tue Feb 11 16:18:17 2014 : Info: Found Auth-Type = EAP Tue Feb 11 16:18:17 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:17 2014 : Info: +- entering group authenticate {...} Tue Feb 11 16:18:17 2014 : Info: [eap] Request found, released from the list Tue Feb 11 16:18:17 2014 : Info: [eap] EAP/ttls Tue Feb 11 16:18:17 2014 : Info: [eap] processing type ttls Tue Feb 11 16:18:17 2014 : Info: [ttls] Authenticate Tue Feb 11 16:18:17 2014 : Info: [ttls] processing EAP-TLS Tue Feb 11 16:18:17 2014 : Debug: TLS Length 1386 Tue Feb 11 16:18:17 2014 : Info: [ttls] Length Included Tue Feb 11 16:18:17 2014 : Info: [ttls] eaptls_verify returned 11 Tue Feb 11 16:18:17 2014 : Info: [ttls] eaptls_process returned 7 Tue Feb 11 16:18:17 2014 : Info: [ttls] Session established. Proceeding to decode tunneled attributes. Tue Feb 11 16:18:17 2014 : Info: [ttls] WARNING: diameter2vp skipping long attribute 1116614064, attr Tue Feb 11 16:18:17 2014 : Info: [eap] Handler failed in EAP/ttls Tue Feb 11 16:18:17 2014 : Debug: rlm_eap_ttls: Freeing handler for user anonymous Tue Feb 11 16:18:17 2014 : Info: [eap] Failed in EAP select Tue Feb 11 16:18:17 2014 : Info: ++[eap] returns invalid Tue Feb 11 16:18:17 2014 : Info: Failed to authenticate the user. Tue Feb 11 16:18:17 2014 : Info: Using Post-Auth-Type REJECT Tue Feb 11 16:18:17 2014 : Info: # Executing group from file /etc/raddb/sites-enabled/default Tue Feb 11 16:18:17 2014 : Info: +- entering group REJECT {...} Tue Feb 11 16:18:17 2014 : Info: [attr_filter.access_reject] expand: %{User-Name} -> anonymous Tue Feb 11 16:18:17 2014 : Debug: attr_filter: Matched entry DEFAULT at line 11 Tue Feb 11 16:18:17 2014 : Info: ++[attr_filter.access_reject] returns updated Tue Feb 11 16:18:17 2014 : Info: Delaying reject of request 12 for 1 seconds Tue Feb 11 16:18:17 2014 : Debug: Going to the next request Tue Feb 11 16:18:17 2014 : Debug: Waking up in 0.9 seconds. Tue Feb 11 16:18:18 2014 : Info: Sending delayed reject for request 12 Sending Access-Reject of id 224 to 10.0.1.254 port 1025 EAP-Message = 0x040c0004 Message-Authenticator = 0x00000000000000000000000000000000 Tue Feb 11 16:18:18 2014 : Debug: Waking up in 0.1 seconds. Tue Feb 11 16:18:18 2014 : Info: Cleaning up request 9 ID 221 with timestamp +13 Tue Feb 11 16:18:18 2014 : Debug: Waking up in 1.0 seconds. Tue Feb 11 16:18:19 2014 : Info: Cleaning up request 10 ID 222 with timestamp +14 Tue Feb 11 16:18:19 2014 : Debug: Waking up in 1.0 seconds. Tue Feb 11 16:18:20 2014 : Info: Cleaning up request 11 ID 223 with timestamp +15 Tue Feb 11 16:18:20 2014 : Debug: Waking up in 2.7 seconds. Tue Feb 11 16:18:23 2014 : Info: Cleaning up request 12 ID 224 with timestamp +17 Tue Feb 11 16:18:23 2014 : Info: Ready to process requests. Greg Huber Embedded Development Carestream Health On 02/11/2014 02:21 PM, Alan DeKok wrote:
greg.huber wrote:
Thank you for getting back so quickly.
Below is the excerpt you requested, I hope there is enough Well, no. It doesn't include any of the hex dumps I need. It just includes the same attribute names / values as before.
Please post the whole debug output.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
greg.huber wrote:
Lets try this again. This time I included everything.
If this is incomplete I can recompile from source,
I think you'll have to do that.
Tue Feb 11 16:18:17 2014 : Info: [ttls] Session established. Proceeding to decode tunneled attributes.
It *should* have the inner tunnel data here. Instead, there's nothing.
Tue Feb 11 16:18:17 2014 : Info: [ttls] WARNING: diameter2vp skipping long attribute 1116614064, attr
That message is still weird. It's printing out something very wrong. Please build from a fresh checkout from "git". That might help: $ git clone https://github.com/FreeRADIUS/freeradius-server.git $ cd freeradius-server $ git checkout -b v2.x.x origin/v2.2.x $ ./configure ... $ make install You may want to do this on a test VM, to avoid breaking a production machine. Alan DeKok.
Lets try this again. This time I included everything. If this is incomplete I can recompile from source, The Fedora team may have 'patched' the source for their own purposes. And again, I really appreciate your assistance. Thank you. Greg Huber Embedded Development Carestream Health On 02/11/2014 02:21 PM, Alan DeKok wrote:
greg.huber wrote:
Thank you for getting back so quickly.
Below is the excerpt you requested, I hope there is enough Well, no. It doesn't include any of the hex dumps I need. It just includes the same attribute names / values as before.
Please post the whole debug output.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
participants (2)
-
Alan DeKok -
greg.huber