- Freeradius-Users - lists.freeradius.org

Authentication failing when using *@domain.com
by Ryan Garrett 25 Oct '10

25 Oct '10

freeradius-users(a)lists.freeradius.org Hi, I've read a lot the past few days trying to figure out why this is failing, and all of the solutions I find don't seem to work. I have a test account setup within a test domain. The username is "dadmin". If I authenticate with just "dadmin" it works fine, I get an access accept response and I am up and running. However, if I try "dadmin(a)testlab.net" authentication is rejected. My main concern is the fact that during the process, it says "testlab.net" was not found, using NULL for the Realm. Any help would be greatly appreciate, and if needed I can get another log with Fallthrough prevented after the MSCHAP module. A condensed debug log is here, it is the transaction only, without the config: rad_recv: Access-Request packet from host 10.10.10.33 port 1812, id=48, length=151 NAS-IP-Address = 10.10.10.33 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "dadmin(a)testlab.net" Called-Station-Id = "00-08-20-FE-F6-81" Calling-Station-Id = "00-11-43-9C-01-97" Service-Type = Framed-User Framed-MTU = 1500 EAP-Message = 0x02000017016461646d696e40746573746c61622e6e6574 Message-Authenticator = 0x44cd0ce3a9cd21f99f2aa81790828195 Thu Oct 14 15:10:55 2010 : Info: +- entering group authorize {...} Thu Oct 14 15:10:55 2010 : Info: ++[preprocess] returns ok Thu Oct 14 15:10:55 2010 : Info: ++[chap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[mschap] returns noop Thu Oct 14 15:10:55 2010 : Info: [suffix] Looking up realm "testlab.net" for User-Name = "dadmin(a)testlab.net" Thu Oct 14 15:10:55 2010 : Info: [suffix] No such realm "testlab.net" Thu Oct 14 15:10:55 2010 : Info: ++[suffix] returns noop Thu Oct 14 15:10:55 2010 : Info: [eap] EAP packet type response id 0 length 23 Thu Oct 14 15:10:55 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns updated Thu Oct 14 15:10:55 2010 : Info: ++[unix] returns notfound Thu Oct 14 15:10:55 2010 : Info: ++[files] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[expiration] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[logintime] returns noop Thu Oct 14 15:10:55 2010 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Thu Oct 14 15:10:55 2010 : Info: ++[pap] returns noop Thu Oct 14 15:10:55 2010 : Info: Found Auth-Type = EAP Thu Oct 14 15:10:55 2010 : Info: +- entering group authenticate {...} Thu Oct 14 15:10:55 2010 : Info: [eap] EAP Identity Thu Oct 14 15:10:55 2010 : Info: [eap] processing type tls Thu Oct 14 15:10:55 2010 : Info: [tls] Initiate Thu Oct 14 15:10:55 2010 : Info: [tls] Start returned 1 Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 48 to 10.10.10.33 port 1812 EAP-Message = 0x010100061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x06aeb03006afa983ae3f9911df8bd844 Thu Oct 14 15:10:55 2010 : Info: Finished request 0. Thu Oct 14 15:10:55 2010 : Debug: Going to the next request Thu Oct 14 15:10:55 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.10.10.33 port 1812, id=49, length=268 NAS-IP-Address = 10.10.10.33 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "dadmin(a)testlab.net" Called-Station-Id = "00-08-20-FE-F6-81" Calling-Station-Id = "00-11-43-9C-01-97" Service-Type = Framed-User Framed-MTU = 1500 State = 0x06aeb03006afa983ae3f9911df8bd844 EAP-Message = 0x0201007a198000000070160301006b0100006703014cb746e874a5b79f870f64af3b396b705ce9c3705ba420507e4ed5a7ee5aadfa00003a00390038008800870035008400160013000a00330032009a009900450044002f00960041000500040015001200090014001100080006000300ff0100000400230000 Message-Authenticator = 0x0181c350f91e4324ee6bd7a580902517 Thu Oct 14 15:10:55 2010 : Info: +- entering group authorize {...} Thu Oct 14 15:10:55 2010 : Info: ++[preprocess] returns ok Thu Oct 14 15:10:55 2010 : Info: ++[chap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[mschap] returns noop Thu Oct 14 15:10:55 2010 : Info: [suffix] Looking up realm "testlab.net" for User-Name = "dadmin(a)testlab.net" Thu Oct 14 15:10:55 2010 : Info: [suffix] No such realm "testlab.net" Thu Oct 14 15:10:55 2010 : Info: ++[suffix] returns noop Thu Oct 14 15:10:55 2010 : Info: [eap] EAP packet type response id 1 length 122 Thu Oct 14 15:10:55 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns ok Thu Oct 14 15:10:55 2010 : Info: Found Auth-Type = EAP Thu Oct 14 15:10:55 2010 : Info: +- entering group authenticate {...} Thu Oct 14 15:10:55 2010 : Info: [eap] Request found, released from the list Thu Oct 14 15:10:55 2010 : Info: [eap] EAP/peap Thu Oct 14 15:10:55 2010 : Info: [eap] processing type peap Thu Oct 14 15:10:55 2010 : Info: [peap] processing EAP-TLS Thu Oct 14 15:10:55 2010 : Debug: TLS Length 112 Thu Oct 14 15:10:55 2010 : Info: [peap] Length Included Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_verify returned 11 Thu Oct 14 15:10:55 2010 : Info: [peap] (other): before/accept initialization Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: before/accept initialization Thu Oct 14 15:10:55 2010 : Info: [peap] <<< TLS 1.0 Handshake [length 006b], ClientHello Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: SSLv3 read client hello A Thu Oct 14 15:10:55 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 0031], ServerHello Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: SSLv3 write server hello A Thu Oct 14 15:10:55 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 085e], Certificate Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: SSLv3 write certificate A Thu Oct 14 15:10:55 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: SSLv3 write key exchange A Thu Oct 14 15:10:55 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: SSLv3 write server done A Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: SSLv3 flush data Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A Thu Oct 14 15:10:55 2010 : Debug: In SSL Handshake Phase Thu Oct 14 15:10:55 2010 : Debug: In SSL Accept mode Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_process returned 13 Thu Oct 14 15:10:55 2010 : Info: [peap] EAPTLS_HANDLED Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 49 to 10.10.10.33 port 1812 EAP-Message = 0x0102040019c000000ab416030100310200002d03014cb763cfa064453757d0c5be1dc586ac1b1858eb7c0a76c7e416b1ec7ab40b72000039000005ff01000100160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c65204365727469666963617465204175 EAP-Message = 0x74686f72697479301e170d3130313031323136323332345a170d3131313031323136323332345a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100ba9088fd0d00ca0dda3515e6a0c2c74fb00cf68c2df91db508b8fccd049fe8acd620fd2f77351357832ee3e202dbd5eff0b71b78d8c271 EAP-Message = 0x0343e4f5376421f172a54444bde1775eedf1558e49262d28729d83998cd3f582d6ccf964efc755f7ec6d68457358246b578bbae24caf6744580ae063cbef9eef84d28bb6e245a0c55358f8b1d642acd6bfd36e046610b58641f5c3afdcb5faa5e7e2be75cc0d005b8d7bceda1d6d3e3541a8c895f788e91bd707af74b949a75675f9f3dacfcd69fecb1aaac3400394c7c6e8231b3856140b016e5608224733732fffdbf3e84fbd85097045a44e46fc64cbf14c434b387c0e088e564bae85cdd534e9b4ffdc38fa8e070203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003820101006070 EAP-Message = 0x7fb95980faec94e4af1c14f2e05a13e76fbcf988d73afb09f3e67139a476550680bf79d342cc39a9d2cc109da4d0803c7a1cbdfc689edd88a0508929f72b7c6c7a39a4e5d608546a30df35de80eefc2e93ce460f8290408bda43de75c4e52d81bd9d83dadfcba81aacee7c841f878aaf0c26c048087d067ac706d0e18ed01eb64a690c790cf633df898718812ab599bce194dc6badda360f367d9164e78025bb778b010df2bb3bcf70e440d73dddec4c1298b9282bf516fef843f2587b0645440c55af35ed52eac6a0cc432373fa83ec889a3e2ea950ec8e08f4d1e1b03f08f8a1ba25044ccadc2ff2934a30db2ca10d6e8edd103b7f4010ddf3a949c6 EAP-Message = 0x660004ab308204a73082038f Message-Authenticator = 0x00000000000000000000000000000000 State = 0x06aeb03007aca983ae3f9911df8bd844 Thu Oct 14 15:10:55 2010 : Info: Finished request 1. Thu Oct 14 15:10:55 2010 : Debug: Going to the next request Thu Oct 14 15:10:55 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.10.10.33 port 1812, id=50, length=152 NAS-IP-Address = 10.10.10.33 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "dadmin(a)testlab.net" Called-Station-Id = "00-08-20-FE-F6-81" Calling-Station-Id = "00-11-43-9C-01-97" Service-Type = Framed-User Framed-MTU = 1500 State = 0x06aeb03007aca983ae3f9911df8bd844 EAP-Message = 0x020200061900 Message-Authenticator = 0x4227505e9a315072b0915cfe8ca62d36 Thu Oct 14 15:10:55 2010 : Info: +- entering group authorize {...} Thu Oct 14 15:10:55 2010 : Info: ++[preprocess] returns ok Thu Oct 14 15:10:55 2010 : Info: ++[chap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[mschap] returns noop Thu Oct 14 15:10:55 2010 : Info: [suffix] Looking up realm "testlab.net" for User-Name = "dadmin(a)testlab.net" Thu Oct 14 15:10:55 2010 : Info: [suffix] No such realm "testlab.net" Thu Oct 14 15:10:55 2010 : Info: ++[suffix] returns noop Thu Oct 14 15:10:55 2010 : Info: [eap] EAP packet type response id 2 length 6 Thu Oct 14 15:10:55 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns ok Thu Oct 14 15:10:55 2010 : Info: Found Auth-Type = EAP Thu Oct 14 15:10:55 2010 : Info: +- entering group authenticate {...} Thu Oct 14 15:10:55 2010 : Info: [eap] Request found, released from the list Thu Oct 14 15:10:55 2010 : Info: [eap] EAP/peap Thu Oct 14 15:10:55 2010 : Info: [eap] processing type peap Thu Oct 14 15:10:55 2010 : Info: [peap] processing EAP-TLS Thu Oct 14 15:10:55 2010 : Info: [peap] Received TLS ACK Thu Oct 14 15:10:55 2010 : Info: [peap] ACK handshake fragment handler Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_verify returned 1 Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_process returned 13 Thu Oct 14 15:10:55 2010 : Info: [peap] EAPTLS_HANDLED Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 50 to 10.10.10.33 port 1812 EAP-Message = 0x010303fc1940a003020102020900afb897aa159b806f300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3130313031323136323332345a170d3131313031323136323332345a308193310b3009060355040613024652310f300d0603550408130652616469757331 EAP-Message = 0x12301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100e149ca60167db7ece7aecfa377f9651e54839449936b92b8057229dd8cef84462c7b9c34f54ac1289175efd2bc0a87b32aaee1f6f1b3e55bd0239602332542332d2fddcd95ebbd6f700cdda24d5afbf4eddb2d7e5bd70ae7a89fbfd5dbeed0c0e862e850d355e352 EAP-Message = 0x6b2a2440b4fa8115aeac9ec642cdd9a1778c8b0568394c4dc02fbc50bc175af15fac4c6c62641c026e122568aeddf6f910217a07daf389be40f4121bbeeb8eabea4bea1504aeb986424753d3122c005db7291d234da903d050037a285ffb1c3327fb5f9f3fc996ef62f7af136291fa79dd4e1fdb6bf1927f2368111360d0e212f0eddec26d331add19704eb6c480ebbc8021318dea0573d30203010001a381fb3081f8301d0603551d0e04160414bb6e4f7b559c26023a5f971ce852f3a7ab6f7bf73081c80603551d230481c03081bd8014bb6e4f7b559c26023a5f971ce852f3a7ab6f7bf7a18199a48196308193310b300906035504061302465231 EAP-Message = 0x0f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479820900afb897aa159b806f300c0603551d13040530030101ff300d06092a864886f70d010105050003820101004eabf4cda96e3bdbcf51ffe9dd73bda03bdcb1c72a43602e8ac4a685714ce598e03decf7fd608b40c42b454e7872c316d2bd10f98c7e2c24bfb05f1e31712625e7ae1d01fbf9279f16c8ec EAP-Message = 0x72273ae1706c1072 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x06aeb03004ada983ae3f9911df8bd844 Thu Oct 14 15:10:55 2010 : Info: Finished request 2. Thu Oct 14 15:10:55 2010 : Debug: Going to the next request Thu Oct 14 15:10:55 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.10.10.33 port 1812, id=51, length=152 NAS-IP-Address = 10.10.10.33 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "dadmin(a)testlab.net" Called-Station-Id = "00-08-20-FE-F6-81" Calling-Station-Id = "00-11-43-9C-01-97" Service-Type = Framed-User Framed-MTU = 1500 State = 0x06aeb03004ada983ae3f9911df8bd844 EAP-Message = 0x020300061900 Message-Authenticator = 0x0ef06ec7be7508f66227787866ff8524 Thu Oct 14 15:10:55 2010 : Info: +- entering group authorize {...} Thu Oct 14 15:10:55 2010 : Info: ++[preprocess] returns ok Thu Oct 14 15:10:55 2010 : Info: ++[chap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[mschap] returns noop Thu Oct 14 15:10:55 2010 : Info: [suffix] Looking up realm "testlab.net" for User-Name = "dadmin(a)testlab.net" Thu Oct 14 15:10:55 2010 : Info: [suffix] No such realm "testlab.net" Thu Oct 14 15:10:55 2010 : Info: ++[suffix] returns noop Thu Oct 14 15:10:55 2010 : Info: [eap] EAP packet type response id 3 length 6 Thu Oct 14 15:10:55 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns ok Thu Oct 14 15:10:55 2010 : Info: Found Auth-Type = EAP Thu Oct 14 15:10:55 2010 : Info: +- entering group authenticate {...} Thu Oct 14 15:10:55 2010 : Info: [eap] Request found, released from the list Thu Oct 14 15:10:55 2010 : Info: [eap] EAP/peap Thu Oct 14 15:10:55 2010 : Info: [eap] processing type peap Thu Oct 14 15:10:55 2010 : Info: [peap] processing EAP-TLS Thu Oct 14 15:10:55 2010 : Info: [peap] Received TLS ACK Thu Oct 14 15:10:55 2010 : Info: [peap] ACK handshake fragment handler Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_verify returned 1 Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_process returned 13 Thu Oct 14 15:10:55 2010 : Info: [peap] EAPTLS_HANDLED Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 51 to 10.10.10.33 port 1812 EAP-Message = 0x010402ce1900b7f17a9246391154d8df1d5e5befea9bb7b855a10e08b6163f9a93ed8093e90487af811d2e68b4beaefce1bc0b1831087dd5e8d273751d426ac32db2072dd5542895d9b31069b51fd4a72531a37ee6fc81d0538968425364563b033b3b2251abb0e31efb350470af37b2c7f7685b1b81a0f7fb37f45bf8d77b4097fe670e2fb94dd925d86cbec7b582ec9151b5b2e961fd1543b1d7a814c07b170e249080cd979431e742c079444128b948791e160301020d0c0002090080f7ec626d0f236a54260ad55c3e9ac7460ea9a11d512ccc96b2374913412e776186a895a392f2f7600d523e9499e4bf092469d003a3a09d98b02c4220e0b51f EAP-Message = 0x18284932c402e8e46a43c3e440f08a819257b03843f90121f9a4147fdd635e0bf5028fa1a3c139eea779b369cf00dd1b867db9d3838b969c6259efe21798e2b74b0001020080b5b42c81f09bebe3105f7285d32aeb963af323e3d723ba72f21259f4c0404c20a9d574d904504da1d66f7297bddcdc5f42e651c63e1c478daf9050a10d29034e6dcb1208d753a361e911974090a010957a36693314a07d023adb267d52348d4d9a5f66e6cc608faa5f0c3505d5ff3ffa491c9f7b8333a10123d9f64f1c1e868001008b3dd77cbd7dac702985d59d70b8342f3ee4ab85536bf916fad701eb58f381fee786e27e938506df61ceca4386aa6354f564066967 EAP-Message = 0x50915b9f0f7b3db3b1d8924f1eeb00eed83d9e563d20dbdd0aafb9f46fe1e13afe224cdcb04d8dfb58ab86e2ac72a087d9cc8645bf6c91d2521a8bf0459e8f50514a589641bdfd4f514ee6786a32506376cd16edfc565df833e085f7768c20083a0014e365a440bf9ce752ff3ecd521f9a48ff2d172a9d0b02e6f96fbe9238534bad5d9a640a48617518fe5e9d300b19f26005f852b91e0021485bbd5a511d9ecea0fbf8bedf7415dcd945a9a1e7d775216d8856cc9be9065235784aa38c69a5fe7deedb9464b2cac5104c16030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x06aeb03005aaa983ae3f9911df8bd844 Thu Oct 14 15:10:55 2010 : Info: Finished request 3. Thu Oct 14 15:10:55 2010 : Debug: Going to the next request Thu Oct 14 15:10:55 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.10.10.33 port 1812, id=52, length=354 NAS-IP-Address = 10.10.10.33 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "dadmin(a)testlab.net" Called-Station-Id = "00-08-20-FE-F6-81" Calling-Station-Id = "00-11-43-9C-01-97" Service-Type = Framed-User Framed-MTU = 1500 State = 0x06aeb03005aaa983ae3f9911df8bd844 EAP-Message = 0x020400d01980000000c6160301008610000082008004a011641119957c7d3a2ad11731a72071077439b92752f8f6a4264dea8f9eef4f180b25a2707a6ca7032ab06542cc040c9221d7a0267d2c63480ac8af8a84a47afcdcf7e53a81cbdd437ab92cdbdba69db3fd06b3784c0dd6b100c8575e41e0f97fdd6d66861349959e7d70fdb83a3dbf85956b41f956df85ae7f88c8b665a314030100010116030100304d5d0b546892c84cbf453606dbb793a9812248f8ed4dcd7791c08c25ef6d067a1219f97a826227c9f562c0a1cffb8945 Message-Authenticator = 0x29f278d7fe9364e01d44b83ee3aa05bb Thu Oct 14 15:10:55 2010 : Info: +- entering group authorize {...} Thu Oct 14 15:10:55 2010 : Info: ++[preprocess] returns ok Thu Oct 14 15:10:55 2010 : Info: ++[chap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[mschap] returns noop Thu Oct 14 15:10:55 2010 : Info: [suffix] Looking up realm "testlab.net" for User-Name = "dadmin(a)testlab.net" Thu Oct 14 15:10:55 2010 : Info: [suffix] No such realm "testlab.net" Thu Oct 14 15:10:55 2010 : Info: ++[suffix] returns noop Thu Oct 14 15:10:55 2010 : Info: [eap] EAP packet type response id 4 length 208 Thu Oct 14 15:10:55 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns ok Thu Oct 14 15:10:55 2010 : Info: Found Auth-Type = EAP Thu Oct 14 15:10:55 2010 : Info: +- entering group authenticate {...} Thu Oct 14 15:10:55 2010 : Info: [eap] Request found, released from the list Thu Oct 14 15:10:55 2010 : Info: [eap] EAP/peap Thu Oct 14 15:10:55 2010 : Info: [eap] processing type peap Thu Oct 14 15:10:55 2010 : Info: [peap] processing EAP-TLS Thu Oct 14 15:10:55 2010 : Debug: TLS Length 198 Thu Oct 14 15:10:55 2010 : Info: [peap] Length Included Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_verify returned 11 Thu Oct 14 15:10:55 2010 : Info: [peap] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: SSLv3 read client key exchange A Thu Oct 14 15:10:55 2010 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] Thu Oct 14 15:10:55 2010 : Info: [peap] <<< TLS 1.0 Handshake [length 0010], Finished Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: SSLv3 read finished A Thu Oct 14 15:10:55 2010 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: SSLv3 write change cipher spec A Thu Oct 14 15:10:55 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 0010], Finished Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: SSLv3 write finished A Thu Oct 14 15:10:55 2010 : Info: [peap] TLS_accept: SSLv3 flush data Thu Oct 14 15:10:55 2010 : Info: [peap] (other): SSL negotiation finished successfully Thu Oct 14 15:10:55 2010 : Debug: SSL Connection Established Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_process returned 13 Thu Oct 14 15:10:55 2010 : Info: [peap] EAPTLS_HANDLED Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 52 to 10.10.10.33 port 1812 EAP-Message = 0x0105004119001403010001011603010030d33e2fd48b5787a88ab2985f891c38f97c03f4f07f398e00c60d36682496368566f4e2fd24ba4749353eaa1751bf8770 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x06aeb03002aba983ae3f9911df8bd844 Thu Oct 14 15:10:55 2010 : Info: Finished request 4. Thu Oct 14 15:10:55 2010 : Debug: Going to the next request Thu Oct 14 15:10:55 2010 : Debug: Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 10.10.10.33 port 1812, id=53, length=152 NAS-IP-Address = 10.10.10.33 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "dadmin(a)testlab.net" Called-Station-Id = "00-08-20-FE-F6-81" Calling-Station-Id = "00-11-43-9C-01-97" Service-Type = Framed-User Framed-MTU = 1500 State = 0x06aeb03002aba983ae3f9911df8bd844 EAP-Message = 0x020500061900 Message-Authenticator = 0x0bad3604fc8ae67ac3e52c0475676c03 Thu Oct 14 15:10:55 2010 : Info: +- entering group authorize {...} Thu Oct 14 15:10:55 2010 : Info: ++[preprocess] returns ok Thu Oct 14 15:10:55 2010 : Info: ++[chap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[mschap] returns noop Thu Oct 14 15:10:55 2010 : Info: [suffix] Looking up realm "testlab.net" for User-Name = "dadmin(a)testlab.net" Thu Oct 14 15:10:55 2010 : Info: [suffix] No such realm "testlab.net" Thu Oct 14 15:10:55 2010 : Info: ++[suffix] returns noop Thu Oct 14 15:10:55 2010 : Info: [eap] EAP packet type response id 5 length 6 Thu Oct 14 15:10:55 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns ok Thu Oct 14 15:10:55 2010 : Info: Found Auth-Type = EAP Thu Oct 14 15:10:55 2010 : Info: +- entering group authenticate {...} Thu Oct 14 15:10:55 2010 : Info: [eap] Request found, released from the list Thu Oct 14 15:10:55 2010 : Info: [eap] EAP/peap Thu Oct 14 15:10:55 2010 : Info: [eap] processing type peap Thu Oct 14 15:10:55 2010 : Info: [peap] processing EAP-TLS Thu Oct 14 15:10:55 2010 : Info: [peap] Received TLS ACK Thu Oct 14 15:10:55 2010 : Info: [peap] ACK handshake is finished Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_verify returned 3 Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_process returned 3 Thu Oct 14 15:10:55 2010 : Info: [peap] EAPTLS_SUCCESS Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 53 to 10.10.10.33 port 1812 EAP-Message = 0x0106002b19001703010020f90caf7acffb8eaee4706dcb171f0d8804e5b59d1ebd264d1dd84bab90389d10 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x06aeb03003a8a983ae3f9911df8bd844 Thu Oct 14 15:10:55 2010 : Info: Finished request 5. Thu Oct 14 15:10:55 2010 : Debug: Going to the next request Thu Oct 14 15:10:55 2010 : Debug: Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 10.10.10.33 port 1812, id=54, length=242 NAS-IP-Address = 10.10.10.33 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "dadmin(a)testlab.net" Called-Station-Id = "00-08-20-FE-F6-81" Calling-Station-Id = "00-11-43-9C-01-97" Service-Type = Framed-User Framed-MTU = 1500 State = 0x06aeb03003a8a983ae3f9911df8bd844 EAP-Message = 0x0206006019001703010020894cf05a26c94c44b8746e3037cd1f8e57af4a91e02dcdcaa63f809288f554f01703010030f402b5d3ad2ad83497fd775555a21f4f5282d2d8ac49de0b8bb3226b791475b31bb484be6d7edf68a1b35d57eb9815f0 Message-Authenticator = 0x7c403ad9b6637e92232f33f76a61fadc Thu Oct 14 15:10:55 2010 : Info: +- entering group authorize {...} Thu Oct 14 15:10:55 2010 : Info: ++[preprocess] returns ok Thu Oct 14 15:10:55 2010 : Info: ++[chap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[mschap] returns noop Thu Oct 14 15:10:55 2010 : Info: [suffix] Looking up realm "testlab.net" for User-Name = "dadmin(a)testlab.net" Thu Oct 14 15:10:55 2010 : Info: [suffix] No such realm "testlab.net" Thu Oct 14 15:10:55 2010 : Info: ++[suffix] returns noop Thu Oct 14 15:10:55 2010 : Info: [eap] EAP packet type response id 6 length 96 Thu Oct 14 15:10:55 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns ok Thu Oct 14 15:10:55 2010 : Info: Found Auth-Type = EAP Thu Oct 14 15:10:55 2010 : Info: +- entering group authenticate {...} Thu Oct 14 15:10:55 2010 : Info: [eap] Request found, released from the list Thu Oct 14 15:10:55 2010 : Info: [eap] EAP/peap Thu Oct 14 15:10:55 2010 : Info: [eap] processing type peap Thu Oct 14 15:10:55 2010 : Info: [peap] processing EAP-TLS Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_verify returned 7 Thu Oct 14 15:10:55 2010 : Info: [peap] Done initial handshake Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_process returned 7 Thu Oct 14 15:10:55 2010 : Info: [peap] EAPTLS_OK Thu Oct 14 15:10:55 2010 : Info: [peap] Session established. Decoding tunneled attributes. Thu Oct 14 15:10:55 2010 : Info: [peap] Identity - dadmin(a)testlab.net Thu Oct 14 15:10:55 2010 : Info: [peap] Got tunneled request EAP-Message = 0x02060017016461646d696e40746573746c61622e6e6574 server { Thu Oct 14 15:10:55 2010 : Debug: PEAP: Got tunneled identity of dadmin(a)testlab.net Thu Oct 14 15:10:55 2010 : Debug: PEAP: Setting default EAP type for tunneled EAP session. Thu Oct 14 15:10:55 2010 : Debug: PEAP: Setting User-Name to dadmin(a)testlab.net Sending tunneled request EAP-Message = 0x02060017016461646d696e40746573746c61622e6e6574 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "dadmin(a)testlab.net" server inner-tunnel { Thu Oct 14 15:10:55 2010 : Info: +- entering group authorize {...} Thu Oct 14 15:10:55 2010 : Info: ++[chap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[mschap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[unix] returns notfound Thu Oct 14 15:10:55 2010 : Info: [suffix] Looking up realm "testlab.net" for User-Name = "dadmin(a)testlab.net" Thu Oct 14 15:10:55 2010 : Info: [suffix] No such realm "testlab.net" Thu Oct 14 15:10:55 2010 : Info: ++[suffix] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[control] returns noop Thu Oct 14 15:10:55 2010 : Info: [eap] EAP packet type response id 6 length 23 Thu Oct 14 15:10:55 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns updated Thu Oct 14 15:10:55 2010 : Info: ++[files] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[expiration] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[logintime] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[pap] returns noop Thu Oct 14 15:10:55 2010 : Info: Found Auth-Type = EAP Thu Oct 14 15:10:55 2010 : Info: +- entering group authenticate {...} Thu Oct 14 15:10:55 2010 : Info: [eap] EAP Identity Thu Oct 14 15:10:55 2010 : Info: [eap] processing type mschapv2 Thu Oct 14 15:10:55 2010 : Debug: rlm_eap_mschapv2: Issuing Challenge Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns handled } # server inner-tunnel Thu Oct 14 15:10:55 2010 : Info: [peap] Got tunneled reply code 11 EAP-Message = 0x0107002c1a0107002710124f49e92bdac6201443bdfb4fc50cf16461646d696e40746573746c61622e6e6574 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xe54962e3e54e788f34681171ec09adc4 Thu Oct 14 15:10:55 2010 : Info: [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x0107002c1a0107002710124f49e92bdac6201443bdfb4fc50cf16461646d696e40746573746c61622e6e6574 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xe54962e3e54e788f34681171ec09adc4 Thu Oct 14 15:10:55 2010 : Info: [peap] Got tunneled Access-Challenge Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 54 to 10.10.10.33 port 1812 EAP-Message = 0x0107004b19001703010040e0e0cb61ee45ef5e301540a163cc543fb45229a6b65f36ed2b92eb05850865aec4374fcc0f5ea9e6891b9859c0b6dd76c020e61502f43af85f5b788e4a937065 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x06aeb03000a9a983ae3f9911df8bd844 Thu Oct 14 15:10:55 2010 : Info: Finished request 6. Thu Oct 14 15:10:55 2010 : Debug: Going to the next request Thu Oct 14 15:10:55 2010 : Debug: Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 10.10.10.33 port 1812, id=55, length=290 NAS-IP-Address = 10.10.10.33 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "dadmin(a)testlab.net" Called-Station-Id = "00-08-20-FE-F6-81" Calling-Station-Id = "00-11-43-9C-01-97" Service-Type = Framed-User Framed-MTU = 1500 State = 0x06aeb03000a9a983ae3f9911df8bd844 EAP-Message = 0x0207009019001703010020d7e4957202a4993b6a7365571d10cc68c1c0f5000a523711682f8b0caf4b17f51703010060a13c82fb21ce6e0b65fb1cb17b23fb81b3753111b39aeba49bc56f048b4112cf29d2c1c62edc32d8f518cc243b2d29f5c201c9f3969be8fbd919c047283a40b0f584d98dbb866ad316f78fdaa33aaae68bea17ab8a65358757845ffa94d6be9c Message-Authenticator = 0xe94cb62805092bf334e7f12b9808f652 Thu Oct 14 15:10:55 2010 : Info: +- entering group authorize {...} Thu Oct 14 15:10:55 2010 : Info: ++[preprocess] returns ok Thu Oct 14 15:10:55 2010 : Info: ++[chap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[mschap] returns noop Thu Oct 14 15:10:55 2010 : Info: [suffix] Looking up realm "testlab.net" for User-Name = "dadmin(a)testlab.net" Thu Oct 14 15:10:55 2010 : Info: [suffix] No such realm "testlab.net" Thu Oct 14 15:10:55 2010 : Info: ++[suffix] returns noop Thu Oct 14 15:10:55 2010 : Info: [eap] EAP packet type response id 7 length 144 Thu Oct 14 15:10:55 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns ok Thu Oct 14 15:10:55 2010 : Info: Found Auth-Type = EAP Thu Oct 14 15:10:55 2010 : Info: +- entering group authenticate {...} Thu Oct 14 15:10:55 2010 : Info: [eap] Request found, released from the list Thu Oct 14 15:10:55 2010 : Info: [eap] EAP/peap Thu Oct 14 15:10:55 2010 : Info: [eap] processing type peap Thu Oct 14 15:10:55 2010 : Info: [peap] processing EAP-TLS Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_verify returned 7 Thu Oct 14 15:10:55 2010 : Info: [peap] Done initial handshake Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_process returned 7 Thu Oct 14 15:10:55 2010 : Info: [peap] EAPTLS_OK Thu Oct 14 15:10:55 2010 : Info: [peap] Session established. Decoding tunneled attributes. Thu Oct 14 15:10:55 2010 : Info: [peap] EAP type mschapv2 Thu Oct 14 15:10:55 2010 : Info: [peap] Got tunneled request EAP-Message = 0x0207004d1a02070048319bfa28d8361e67306d7b5b4ff7077d85000000000000000091eb33b42e07518e52bc05bf8b6b2bf33b271c6654edf3b3006461646d696e40746573746c61622e6e6574 server { Thu Oct 14 15:10:55 2010 : Debug: PEAP: Setting User-Name to dadmin(a)testlab.net Sending tunneled request EAP-Message = 0x0207004d1a02070048319bfa28d8361e67306d7b5b4ff7077d85000000000000000091eb33b42e07518e52bc05bf8b6b2bf33b271c6654edf3b3006461646d696e40746573746c61622e6e6574 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "dadmin(a)testlab.net" State = 0xe54962e3e54e788f34681171ec09adc4 server inner-tunnel { Thu Oct 14 15:10:55 2010 : Info: +- entering group authorize {...} Thu Oct 14 15:10:55 2010 : Info: ++[chap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[mschap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[unix] returns notfound Thu Oct 14 15:10:55 2010 : Info: [suffix] Looking up realm "testlab.net" for User-Name = "dadmin(a)testlab.net" Thu Oct 14 15:10:55 2010 : Info: [suffix] No such realm "testlab.net" Thu Oct 14 15:10:55 2010 : Info: ++[suffix] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[control] returns noop Thu Oct 14 15:10:55 2010 : Info: [eap] EAP packet type response id 7 length 77 Thu Oct 14 15:10:55 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns updated Thu Oct 14 15:10:55 2010 : Info: ++[files] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[expiration] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[logintime] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[pap] returns noop Thu Oct 14 15:10:55 2010 : Info: Found Auth-Type = EAP Thu Oct 14 15:10:55 2010 : Info: +- entering group authenticate {...} Thu Oct 14 15:10:55 2010 : Info: [eap] Request found, released from the list Thu Oct 14 15:10:55 2010 : Info: [eap] EAP/mschapv2 Thu Oct 14 15:10:55 2010 : Info: [eap] processing type mschapv2 Thu Oct 14 15:10:55 2010 : Info: [mschapv2] +- entering group MS-CHAP {...} Thu Oct 14 15:10:55 2010 : Info: [mschap] Told to do MS-CHAPv2 for dadmin(a)testlab.net with NT-Password Thu Oct 14 15:10:55 2010 : Info: [mschap] expand: --username=%{mschap:User-Name} -> --username=dadmin(a)testlab.net Thu Oct 14 15:10:55 2010 : Info: [mschap] No NT-Domain was found in the User-Name. Thu Oct 14 15:10:55 2010 : Info: [mschap] expand: --domain=%{mschap:NT-Domain:-TESTLAB} -> --domain=TESTLAB Thu Oct 14 15:10:55 2010 : Info: [mschap] mschap2: 12 Thu Oct 14 15:10:55 2010 : Info: [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=863bbef1e761f451 Thu Oct 14 15:10:55 2010 : Info: [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=91eb33b42e07518e52bc05bf8b6b2bf33b271c6654edf3b3 Thu Oct 14 15:10:55 2010 : Debug: Exec-Program output: Logon failure (0xc000006d) Thu Oct 14 15:10:55 2010 : Debug: Exec-Program-Wait: plaintext: Logon failure (0xc000006d) Thu Oct 14 15:10:55 2010 : Debug: Exec-Program: returned: 1 Thu Oct 14 15:10:55 2010 : Info: [mschap] External script failed. Thu Oct 14 15:10:55 2010 : Info: [mschap] FAILED: MS-CHAP2-Response is incorrect Thu Oct 14 15:10:55 2010 : Info: ++[mschap] returns reject Thu Oct 14 15:10:55 2010 : Info: [eap] Freeing handler Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns reject Thu Oct 14 15:10:55 2010 : Info: Failed to authenticate the user. } # server inner-tunnel Thu Oct 14 15:10:55 2010 : Info: [peap] Got tunneled reply code 3 MS-CHAP-Error = "\007E=691 R=1" EAP-Message = 0x04070004 Message-Authenticator = 0x00000000000000000000000000000000 Thu Oct 14 15:10:55 2010 : Info: [peap] Got tunneled reply RADIUS code 3 MS-CHAP-Error = "\007E=691 R=1" EAP-Message = 0x04070004 Message-Authenticator = 0x00000000000000000000000000000000 Thu Oct 14 15:10:55 2010 : Info: [peap] Tunneled authentication was rejected. Thu Oct 14 15:10:55 2010 : Info: [peap] FAILURE Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 55 to 10.10.10.33 port 1812 EAP-Message = 0x0108002b19001703010020498aa0405fb3369ddf5fd951847b1e5a4708ceda5b79cf85bf00d99b9571afcf Message-Authenticator = 0x00000000000000000000000000000000 State = 0x06aeb03001a6a983ae3f9911df8bd844 Thu Oct 14 15:10:55 2010 : Info: Finished request 7. Thu Oct 14 15:10:55 2010 : Debug: Going to the next request Thu Oct 14 15:10:55 2010 : Debug: Waking up in 4.7 seconds. rad_recv: Access-Request packet from host 10.10.10.33 port 1812, id=56, length=226 NAS-IP-Address = 10.10.10.33 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "dadmin(a)testlab.net" Called-Station-Id = "00-08-20-FE-F6-81" Calling-Station-Id = "00-11-43-9C-01-97" Service-Type = Framed-User Framed-MTU = 1500 State = 0x06aeb03001a6a983ae3f9911df8bd844 EAP-Message = 0x02080050190017030100205411269d41c6a25aeac21543c6b38ec3f5859913aaf177060237311a8074882417030100203ca6e5472ca61249f52ea2f387570ca90092efcdc37594a61be5e810cb7f0673 Message-Authenticator = 0x7bb0d939e5cd49c378681bb927a5309c Thu Oct 14 15:10:55 2010 : Info: +- entering group authorize {...} Thu Oct 14 15:10:55 2010 : Info: ++[preprocess] returns ok Thu Oct 14 15:10:55 2010 : Info: ++[chap] returns noop Thu Oct 14 15:10:55 2010 : Info: ++[mschap] returns noop Thu Oct 14 15:10:55 2010 : Info: [suffix] Looking up realm "testlab.net" for User-Name = "dadmin(a)testlab.net" Thu Oct 14 15:10:55 2010 : Info: [suffix] No such realm "testlab.net" Thu Oct 14 15:10:55 2010 : Info: ++[suffix] returns noop Thu Oct 14 15:10:55 2010 : Info: [eap] EAP packet type response id 8 length 80 Thu Oct 14 15:10:55 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns ok Thu Oct 14 15:10:55 2010 : Info: Found Auth-Type = EAP Thu Oct 14 15:10:55 2010 : Info: +- entering group authenticate {...} Thu Oct 14 15:10:55 2010 : Info: [eap] Request found, released from the list Thu Oct 14 15:10:55 2010 : Info: [eap] EAP/peap Thu Oct 14 15:10:55 2010 : Info: [eap] processing type peap Thu Oct 14 15:10:55 2010 : Info: [peap] processing EAP-TLS Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_verify returned 7 Thu Oct 14 15:10:55 2010 : Info: [peap] Done initial handshake Thu Oct 14 15:10:55 2010 : Info: [peap] eaptls_process returned 7 Thu Oct 14 15:10:55 2010 : Info: [peap] EAPTLS_OK Thu Oct 14 15:10:55 2010 : Info: [peap] Session established. Decoding tunneled attributes. Thu Oct 14 15:10:55 2010 : Info: [peap] Received EAP-TLV response. Thu Oct 14 15:10:55 2010 : Info: [peap] Had sent TLV failure. User was rejected earlier in this session. Thu Oct 14 15:10:55 2010 : Info: [eap] Handler failed in EAP/peap Thu Oct 14 15:10:55 2010 : Info: [eap] Failed in EAP select Thu Oct 14 15:10:55 2010 : Info: ++[eap] returns invalid Thu Oct 14 15:10:55 2010 : Info: Failed to authenticate the user. Thu Oct 14 15:10:55 2010 : Info: Using Post-Auth-Type Reject Thu Oct 14 15:10:55 2010 : Info: +- entering group REJECT {...} Thu Oct 14 15:10:55 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> dadmin(a)testlab.net Thu Oct 14 15:10:55 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11 Thu Oct 14 15:10:55 2010 : Info: ++[attr_filter.access_reject] returns updated Thu Oct 14 15:10:55 2010 : Info: Delaying reject of request 8 for 1 seconds Thu Oct 14 15:10:55 2010 : Debug: Going to the next request Thu Oct 14 15:10:55 2010 : Debug: Waking up in 0.9 seconds. Thu Oct 14 15:10:56 2010 : Info: Sending delayed reject for request 8 Sending Access-Reject of id 56 to 10.10.10.33 port 1812 EAP-Message = 0x04080004 Message-Authenticator = 0x00000000000000000000000000000000 Thu Oct 14 15:10:56 2010 : Debug: Waking up in 3.7 seconds. Thu Oct 14 15:11:00 2010 : Info: Cleaning up request 0 ID 48 with timestamp +12 Thu Oct 14 15:11:00 2010 : Info: Cleaning up request 1 ID 49 with timestamp +12 Thu Oct 14 15:11:00 2010 : Info: Cleaning up request 2 ID 50 with timestamp +12 Thu Oct 14 15:11:00 2010 : Info: Cleaning up request 3 ID 51 with timestamp +12 Thu Oct 14 15:11:00 2010 : Info: Cleaning up request 4 ID 52 with timestamp +12 Thu Oct 14 15:11:00 2010 : Info: Cleaning up request 5 ID 53 with timestamp +12 Thu Oct 14 15:11:00 2010 : Info: Cleaning up request 6 ID 54 with timestamp +12 Thu Oct 14 15:11:00 2010 : Info: Cleaning up request 7 ID 55 with timestamp +12 Thu Oct 14 15:11:00 2010 : Debug: Waking up in 1.0 seconds. Thu Oct 14 15:11:01 2010 : Info: Cleaning up request 8 ID 56 with timestamp +12 Thu Oct 14 15:11:01 2010 : Debug: Ready to process requests.

2 4

Replacing User-Password in config items with Cleartext-Password.
by Blake Hodder 25 Oct '10

25 Oct '10

Hi, I have currently just setup a new freeradius server and have the request being accepted but I get the following warning: rlm_sql (sql): Released sql socket id: 19 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop ++[pap] returns updated rad_check_password: Found Auth-Type !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! !!! Replacing User-Password in config items with Cleartext-Password. !!! !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! !!! Please update your configuration so that the "known good" !!! !!! clear text password is in Cleartext-Password, and not in User-Password. !!! !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! auth: type "PAP" How do I get rid of this complaint from the system? Thanks, Blake Hodder --

2 1

update/replace reply
by Wayne Lee 25 Oct '10

25 Oct '10

Hello List Hopefully somebody will point me in the right direction. I posted a message last week about my confusion with unlang, Alan correctly pointed out some of the mistakes I was making and I was able to fix them but I've hit another issue. What is the best way to do the following ? If calling-station-id and group match send below (request from provider) Tunnel-Type = "L2TP", Tunnel-Medium-Type = "IP", Tunnel-Server-Endpoint := "192.168.0.1", Cisco-AVPair := "vpdn:tunnel-id=provider.net", Cisco-AVPair := "vpdn:l2tp-tunnel-password=abc", If calling-station-id missing but group matches send below (request from my LNS's) Framed-IP-Address Framed-IP-Netmask Cisco-AVPair 1 Cisco-AVPair 2 All the reply info is mixed within the group-reply and user-reply. Do I use different tables or a mixture of files and sql if so how do I set which to use depending on the requestor ? I have read the man pages, archive and google plus ran in debug mode but I just don't understand how to use separate files/tables per requestor to do this part. Version = 2.1.10+dfsg-1~bpo50+1 on Debian Thanks Wayne

1 0

are there any characters not allowed in a password used with LDAP "bind as user"?
by mark.leese＠stfc.ac.uk 25 Oct '10

25 Oct '10

Hi, For a couple of years I've been successfully using FreeRADIUS to authenticate some users against Active Directory using cleartext passwords, a Perl script to do some department checking, and a simple LDAP "bind as user". I've now got at least one user who fails authentication, and I'm wondering if the problem is a backslash in their password. The password is... w[)xg=\7k2 I can use the same username and password to successfully LDAP bind to AD using a tool like ldapsearch from my Linux based RADIUS server, but using RADIUS itself fails. If it helps here's the -X debug trace: Wed Oct 20 15:36:19 2010 : Debug: Ready to process requests. rad_recv: Access-Request packet from host 172.16.80.3 port 20002, id=9, length=135 User-Name = "bill" Calling-Station-Id = "00-24-D7-40-8C-8C" Called-Station-Id = "00-0B-0E-DE-AB-80" NAS-Port = 52340 NAS-Port-Type = Wireless-802.11 NAS-IP-Address = 172.16.80.3 User-Password = "w[)xg=\\7k2" Wed Oct 20 15:39:10 2010 : Info: +- entering group authorize {...} Wed Oct 20 15:39:10 2010 : Info: ++[preprocess] returns ok Wed Oct 20 15:39:10 2010 : Info: [auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/172.16.80.3/auth-detail-20101020 Wed Oct 20 15:39:10 2010 : Info: [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/172.16.80.3/auth-detail-20101020 Wed Oct 20 15:39:10 2010 : Info: [auth_log] expand: %t -> Wed Oct 20 15:39:10 2010 Wed Oct 20 15:39:10 2010 : Info: ++[auth_log] returns ok Wed Oct 20 15:39:10 2010 : Info: [ldap] performing user authorization for bill Wed Oct 20 15:39:10 2010 : Info: [ldap] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details Wed Oct 20 15:39:10 2010 : Info: [ldap] expand: (sAMAccountName=%{Stripped-User-Name:-%{User-Name}}) -> (sAMAccountName=bill) Wed Oct 20 15:39:10 2010 : Info: [ldap] expand: dc=fed,dc=foo,dc=ac,dc=uk -> dc=fed,dc=foo,dc=ac,dc=uk Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: attempting LDAP reconnection Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: (re)connect to logonserv.fed.foo.ac.uk:389, authentication 0 Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: bind as / to logonserv.fed.foo.ac.uk:389 Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: waiting for bind result ... Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: Bind was successful Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: performing search in dc=fed,dc=foo,dc=ac,dc=uk, with filter (sAMAccountName=bill) Wed Oct 20 15:39:10 2010 : Info: [ldap] looking for check items in directory... Wed Oct 20 15:39:10 2010 : Info: [ldap] looking for reply items in directory... Wed Oct 20 15:39:10 2010 : Debug: WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? Wed Oct 20 15:39:10 2010 : Info: [ldap] Setting Auth-Type = LDAP Wed Oct 20 15:39:10 2010 : Info: [ldap] user bill authorized to use remote access Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Wed Oct 20 15:39:10 2010 : Info: ++[ldap] returns ok Wed Oct 20 15:39:10 2010 : Info: ++[expiration] returns noop Wed Oct 20 15:39:10 2010 : Info: ++[logintime] returns noop Wed Oct 20 15:39:10 2010 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Oct 20 15:39:10 2010 : Info: ++[pap] returns noop Wed Oct 20 15:39:10 2010 : Info: ++? if (control:Auth-Type == LDAP) Wed Oct 20 15:39:10 2010 : Info: ? Evaluating (control:Auth-Type == LDAP) -> TRUE Wed Oct 20 15:39:10 2010 : Info: ++? if (control:Auth-Type == LDAP) -> TRUE Wed Oct 20 15:39:10 2010 : Info: ++- entering if (control:Auth-Type == LDAP) {...} Wed Oct 20 15:39:10 2010 : Debug: rlm_perl: Added pair NAS-Port-Type = Wireless-802.11 Wed Oct 20 15:39:10 2010 : Debug: rlm_perl: Added pair Called-Station-Id = 00-0B-0E-DE-AB-80 Wed Oct 20 15:39:10 2010 : Debug: rlm_perl: Added pair Calling-Station-Id = 00-24-D7-40-8C-8C Wed Oct 20 15:39:10 2010 : Debug: rlm_perl: Added pair User-Name = bill Wed Oct 20 15:39:10 2010 : Debug: rlm_perl: Added pair NAS-Identifier = Trapeze Wed Oct 20 15:39:10 2010 : Debug: rlm_perl: Added pair User-Password = w[)xg=\\7k2 Wed Oct 20 15:39:10 2010 : Debug: rlm_perl: Added pair NAS-Port = 52340 Wed Oct 20 15:39:10 2010 : Debug: rlm_perl: Added pair NAS-IP-Address = 172.16.80.3 Wed Oct 20 15:39:10 2010 : Debug: rlm_perl: Added pair Auth-Type = LDAP Wed Oct 20 15:39:10 2010 : Debug: rlm_perl: Added pair Ldap-UserDn = CN=bill,OU=Facility Users,OU=FBU,DC=fed,DC=foo,DC=ac,DC=uk Wed Oct 20 15:39:10 2010 : Info: +++[perl] returns noop Wed Oct 20 15:39:10 2010 : Info: ++- if (control:Auth-Type == LDAP) returns noop Wed Oct 20 15:39:10 2010 : Info: Found Auth-Type = LDAP Wed Oct 20 15:39:10 2010 : Info: +- entering group LDAP {...} Wed Oct 20 15:39:10 2010 : Info: [ldap] login attempt by "bill" with password "w[)xg=\\7k2" Wed Oct 20 15:39:10 2010 : Info: [ldap] user DN: CN=bill,OU=Facility Users,OU=FBU,DC=fed,DC=foo,DC=ac,DC=uk Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: (re)connect to logonserv.fed.foo.ac.uk:389, authentication 1 Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: bind as CN=bill,OU=Facility Users,OU=FBU,DC=fed,DC=foo,DC=ac,DC=uk/w[)xg=\\7k2 to logonserv.fed.foo.ac.uk:389 Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: waiting for bind result ... Wed Oct 20 15:39:10 2010 : Debug: rlm_ldap: Bind failed with invalid credentials Wed Oct 20 15:39:10 2010 : Info: ++[ldap] returns reject Wed Oct 20 15:39:10 2010 : Info: Failed to authenticate the user. Wed Oct 20 15:39:10 2010 : Auth: Login incorrect (rlm_ldap: Bind as user failed): [bill] (from client wireless-2 port 52340 cli 00-24-D7-40-8C-8C) Wed Oct 20 15:39:10 2010 : Info: Using Post-Auth-Type Reject I don't know whether the problem lies with me (for allowing a backslash in the password in the first place) the NAS for appearing to 'escape' the backslash (with a backslash) or the way I've configured FreeRADIUS. Can anyone give me any pointers? Thanks in advance of any advice, Cheers, Mark. -- Scanned by iCritical.

2 3

plpgsql freeradius authentication function
by Kafui Akyea 25 Oct '10

25 Oct '10

Hi I have a plpgsql function being called from freeradius to do authentication but i keep getting Access-Reject from radius although when i run the function without freeradius it works fine. Please find below the function and how i call it CREATE OR REPLACE FUNCTION try (your_name TEXT, tiger TEXT) RETURNS RECORD AS $$ DECLARE users_rec RECORD; BEGIN if tiger = '0000' then SELECT INTO users_rec * FROM aniradcheck WHERE username = your_name; else SELECT INTO users_rec * FROM radcheck WHERE username = your_name; end if; RETURN users_rec.username; END; $$ LANGUAGE plpgsql; SELECT id,username,attribute,op,value FROM try('7140944444','0000') as(id integer,username varchar,attribute varchar,op character,value varchar); Appreciate if you can help Thanks

4 11

Problems -- rad_verify: invalid signature (err=2)！（shared secret is incorrect）
by Xiaochen 25 Oct '10

25 Oct '10

Hi all, I am using Fedora 12 and Freeradius 1.2.9 to do some COA test. When AAA sends Disconnect-request to my AGW, the AGW reply with a Disconnect-ACK, and my MS disconnects. But the rad_verify says: ----------------------------------------------------------------------- Received Disconnect-ACK packet from clinet 100.1.6.4 port 3799 with invalid signature (err=2)! (shared secret is incorrect. ----------------------------------------------------------------------- In fact the shared secret is correct!!! My disconnect packt.txt is like: ----------------------------------------------------------------------- Acct-Session-Id="00000001" Calling-Station-Id="001E310008CC" User-Name="wimax(a)zte.com" X-Ascend-Session-Svr-Key="0123456789" NAS-IP-Address=100.1.6.4 NAS-Identifier=CATR WiMAX-DM-Action-Code="0xffff" WiMAX-AAA-Session-Id="00000002" ----------------------------------------------------------------------- I don’t know how to solve this problem, can you please give any suggestions? Thanks a lot! Xiaochen @ a WiMAX Lab

3 2

FR 2.1.11git, Dead home server status server reply - possible minor bug
by James J J Hooper 25 Oct '10

25 Oct '10

Hi Alan et al, {Running FR from GIT upto commit b42665d4475835f38fe71ef749e39cd22587bcfa, Sat Oct 9 17:52} Doing: /bin/echo "Message-Authenticator = 0x00, FreeRADIUS-Statistics-Type = 131, FreeRADIUS-Stats-Server-IP-Address = ".....", FreeRADIUS-Stats-Server-Port = 1812" | /usr/local/bin/radclient localhost:18120 status secret when the homeserver is "dead" I get back: Received response ID 178, code 2, length = 200 FreeRADIUS-Stats-Server-IP-Address = ..... FreeRADIUS-Stats-Server-Port = 1812 FreeRADIUS-Stats-Server-Outstanding-Requests = 0 FreeRADIUS-Stats-Server-State = Dead FreeRADIUS-Stats-Server-Time-Of-Death = "Jan 6 1970 18:54:00 UTC" FreeRADIUS-Total-Proxy-Access-Requests = 1651 FreeRADIUS-Total-Proxy-Access-Accepts = 122 FreeRADIUS-Total-Proxy-Access-Rejects = 60 FreeRADIUS-Total-Proxy-Access-Challenges = 1345 FreeRADIUS-Total-Proxy-Auth-Responses = 1527 FreeRADIUS-Total-Proxy-Auth-Duplicate-Requests = 0 FreeRADIUS-Total-Proxy-Auth-Malformed-Requests = 0 FreeRADIUS-Total-Proxy-Auth-Invalid-Requests = 0 FreeRADIUS-Total-Proxy-Auth-Dropped-Requests = 0 FreeRADIUS-Total-Proxy-Auth-Unknown-Types = 0 The date (Time-Of-Death) seems a little odd. I poked around in the code and got as far as the below, which looks possibly wrong, but I don't understand C enough to work out what to do with it from the surrounding code: /src/main/event.c: /* * Enable the zombie period when we notice that the home * server hasn't responded for a while. We back-date the * zombie period to when we last received a response from * the home server. */ home->state = HOME_STATE_ZOMBIE; home->zombie_period_start.tv_sec = home->last_packet; home->zombie_period_start.tv_sec = USEC / 2; {Apologies if I'm totally going in the wrong direction} Regards, James -- James J J Hooper Network Specialist Information Services University of Bristol http://www.wireless.bristol.ac.uk --

2 1

RE: How to raise numbers of request/sec in Freeradius
by Robin 25 Oct '10

25 Oct '10

Hi Alan, Thanks your reply firstly. I use Mysql to authentication. When I use a PPPOE client to call FreeRADIUS one time,that’s all ok. I create 200 pppoe accounts as dialing client in Mikrotik server. When I use them to call FreeRADIUS at the same time, I find only about 5-20 successful logins by sec. I don’t know how to increase the numbers? If you have any details information, I can provide to you. Expect to your help. Thank you very much! Robin -----Original Message----- From: Alan DeKok [mailto:aland@deployingradius.com] Sent: Friday, October 22, 2010 5:18 PM To: FreeRadius users mailing list Subject: Re: How to raise numbers of request/sec in Freeradius Robin wrote: > I use the tools of Evolynx Radius Load Test to test number of request by > second. I find only max 20-25 requests/sec in Freeradius. > > > > Can I raise the number via editing configuration files? When authentication is from the "users" file, the server can do 10K requests/s. The issue isn't FreeRADIUS. It's something else. So... what are you doing with the authentication requests? Alan DeKok.

2 1

www.freeradius.org url link error
by Omer Faruk SEN 25 Oct '10

25 Oct '10

Hi, At http://freeradius.org/ for release 2.1.10 there is a clause Added RFCs 5607, 5904, and 5997. For 5607 http://ietf.org/rfc/rfc5607.txt But for others: http://ietf.org/rfc/rfc5904 and http://ietf.org/rfc/rfc5997 was used.They should be: http://ietf.org/rfc/rfc5904.txt http://ietf.org/rfc/rfc5997.txt No big deal. Just wanted to inform. Regards.

2 1

Re: freeradius proxy can't recognize Delegated-IPv6-Prefix attribute
by ichiro tanaka 25 Oct '10

25 Oct '10

thanks Alan. (i couldn't get your reply to my mailbox. so, i made a new mail. sorry...) > Fix the proxy so that it's using the dictionaries from 2.1.10. The >debug *claims* it's 2.1.10, but the Delegated-IPv6-Prefix attribute *is* >defined in the dictionaries for 2.1.10. > > Alan DeKok. My freeradius proxy already includes "dictionary.rfc4818". Do I need something? [[ radiusd -X ]] including configuration file /tmp/radius/etc/raddb/sites-enabled/default including configuration file /tmp/radius/etc/raddb/sites-enabled/inner-tunnel including dictionary file /tmp/radius/etc/raddb/dictionary main { prefix = "/tmp/radius" localstatedir = "/tmp/radius/var" [[ /tmp/radius/etc/raddb/dictionary ]] $INCLUDE /tmp/radius/share/freeradius/dictionary [[ /tmp/radius/share/freeradius/dictionary ]] $INCLUDE dictionary.rfc4679 $INCLUDE dictionary.rfc4818 ~~~~~~~~~~~~~~~~~~~~~~~~~~~ $INCLUDE dictionary.rfc4849 [[ dictionary.rfc4818 ]] ATTRIBUTE Delegated-IPv6-Prefix 123 ipv6prefix

3 5