May 2012 - Freeradius-Users - lists.freeradius.org

MSCHAP Errors
by sgilmour 15 May '12

15 May '12

Hi, I am running freeradius with Ubuntu and with the Active Directory Configuration. When doing PEAP authentication I keep on getting a MSCHAP Error. Not sure where to make changes or what changes to make. Is there something I need to add in the Radiusd.conf or the eap.conf file? Thanks in Advance for your help, Scott rad_recv: Access-Request packet from host 192.168.175.60 port 65202, id=132, length=146 User-Name = "SQA\\sqapeap" Service-Type = Framed-User Called-Station-Id = "00-1F-45-A7-9A-4E" Calling-Station-Id = "08-00-27-0D-CB-01" NAS-IP-Address = 192.168.175.60 NAS-Port = 128 NAS-Port-Id = "ge.3.24" Framed-MTU = 1500 NAS-Port-Type = Ethernet EAP-Message = 0x02010010015351415c73716170656170 Message-Authenticator = 0x6b9ffc8200a2e75ddfedebf83d4ab93a Fri May 11 08:08:12 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:12 2012 : Info: +- entering group authorize {...} Fri May 11 08:08:12 2012 : Info: ++[preprocess] returns ok Fri May 11 08:08:12 2012 : Info: ++[chap] returns noop Fri May 11 08:08:12 2012 : Info: ++[mschap] returns noop Fri May 11 08:08:12 2012 : Info: ++[digest] returns noop Fri May 11 08:08:12 2012 : Info: [suffix] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:12 2012 : Info: [suffix] No such realm "NULL" Fri May 11 08:08:12 2012 : Info: ++[suffix] returns noop Fri May 11 08:08:12 2012 : Info: [ntdomain] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:12 2012 : Info: [ntdomain] No such realm "NULL" Fri May 11 08:08:12 2012 : Info: ++[ntdomain] returns noop Fri May 11 08:08:12 2012 : Info: [eap] EAP packet type response id 1 length 16 Fri May 11 08:08:12 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Fri May 11 08:08:12 2012 : Info: ++[eap] returns updated Fri May 11 08:08:12 2012 : Info: ++[files] returns noop Fri May 11 08:08:12 2012 : Info: ++[expiration] returns noop Fri May 11 08:08:12 2012 : Info: ++[logintime] returns noop Fri May 11 08:08:12 2012 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Fri May 11 08:08:12 2012 : Info: ++[pap] returns noop Fri May 11 08:08:12 2012 : Info: ++? if (!control:Auth-Type) Fri May 11 08:08:12 2012 : Info: ? Evaluating !(control:Auth-Type) -> FALSE Fri May 11 08:08:12 2012 : Info: ++? if (!control:Auth-Type) -> FALSE Fri May 11 08:08:12 2012 : Info: Found Auth-Type = EAP Fri May 11 08:08:12 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:12 2012 : Info: +- entering group authenticate {...} Fri May 11 08:08:12 2012 : Info: [eap] EAP Identity Fri May 11 08:08:12 2012 : Info: [eap] processing type tls Fri May 11 08:08:12 2012 : Info: [tls] Initiate Fri May 11 08:08:12 2012 : Info: [tls] Start returned 1 Fri May 11 08:08:12 2012 : Info: ++[eap] returns handled Sending Access-Challenge of id 132 to 192.168.175.60 port 65202 EAP-Message = 0x010200061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xaa86bc7baa84a5473544135e4511878c Fri May 11 08:08:12 2012 : Info: Finished request 108. Fri May 11 08:08:12 2012 : Debug: Going to the next request Fri May 11 08:08:12 2012 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.175.60 port 65202, id=133, length=253 User-Name = "SQA\\sqapeap" Service-Type = Framed-User Called-Station-Id = "00-1F-45-A7-9A-4E" Calling-Station-Id = "08-00-27-0D-CB-01" NAS-IP-Address = 192.168.175.60 NAS-Port = 128 NAS-Port-Id = "ge.3.24" Framed-MTU = 1500 NAS-Port-Type = Ethernet State = 0xaa86bc7baa84a5473544135e4511878c EAP-Message = 0x0202006919800000005f160301005a0100005603014fad0132e1cd0d0b2431012b494f3795220fdba7d1e6c6a9be582687d5d2124b000018002f00350005000ac013c014c009c00a003200380013000401000015ff01000100000a0006000400170018000b00020100 Message-Authenticator = 0x6474a496d418b6236c2405061711197b Fri May 11 08:08:13 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authorize {...} Fri May 11 08:08:13 2012 : Info: ++[preprocess] returns ok Fri May 11 08:08:13 2012 : Info: ++[chap] returns noop Fri May 11 08:08:13 2012 : Info: ++[mschap] returns noop Fri May 11 08:08:13 2012 : Info: ++[digest] returns noop Fri May 11 08:08:13 2012 : Info: [suffix] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [suffix] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[suffix] returns noop Fri May 11 08:08:13 2012 : Info: [ntdomain] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [ntdomain] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[ntdomain] returns noop Fri May 11 08:08:13 2012 : Info: [eap] EAP packet type response id 2 length 105 Fri May 11 08:08:13 2012 : Info: [eap] Continuing tunnel setup. Fri May 11 08:08:13 2012 : Info: ++[eap] returns ok Fri May 11 08:08:13 2012 : Info: Found Auth-Type = EAP Fri May 11 08:08:13 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authenticate {...} Fri May 11 08:08:13 2012 : Info: [eap] Request found, released from the list Fri May 11 08:08:13 2012 : Info: [eap] EAP/peap Fri May 11 08:08:13 2012 : Info: [eap] processing type peap Fri May 11 08:08:13 2012 : Info: [peap] processing EAP-TLS Fri May 11 08:08:13 2012 : Debug: TLS Length 95 Fri May 11 08:08:13 2012 : Info: [peap] Length Included Fri May 11 08:08:13 2012 : Info: [peap] eaptls_verify returned 11 Fri May 11 08:08:13 2012 : Info: [peap] (other): before/accept initialization Fri May 11 08:08:13 2012 : Info: [peap] TLS_accept: before/accept initialization Fri May 11 08:08:13 2012 : Info: [peap] <<< TLS 1.0 Handshake [length 005a], ClientHello Fri May 11 08:08:13 2012 : Info: [peap] TLS_accept: SSLv3 read client hello A Fri May 11 08:08:13 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 0031], ServerHello Fri May 11 08:08:13 2012 : Info: [peap] TLS_accept: SSLv3 write server hello A Fri May 11 08:08:13 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 0668], Certificate Fri May 11 08:08:13 2012 : Info: [peap] TLS_accept: SSLv3 write certificate A Fri May 11 08:08:13 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Fri May 11 08:08:13 2012 : Info: [peap] TLS_accept: SSLv3 write server done A Fri May 11 08:08:13 2012 : Info: [peap] TLS_accept: SSLv3 flush data Fri May 11 08:08:13 2012 : Info: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A Fri May 11 08:08:13 2012 : Debug: In SSL Handshake Phase Fri May 11 08:08:13 2012 : Debug: In SSL Accept mode Fri May 11 08:08:13 2012 : Info: [peap] eaptls_process returned 13 Fri May 11 08:08:13 2012 : Info: [peap] EAPTLS_HANDLED Fri May 11 08:08:13 2012 : Info: ++[eap] returns handled Sending Access-Challenge of id 133 to 192.168.175.60 port 65202 EAP-Message = 0x0103040019c0000006ac16030100310200002d03014fad012d75fe0859349a42c0195d6ac5c14e2fd6931b128896862f3d545ecf1900002f000005ff0100010016030106680b0006640006610002da308202d6308201bea003020102020101300d06092a864886f70d0101050500305031133011060a0992268993f22c64011916036e657431133011060a0992268993f22c6401191603535141312430220603550403131b53514120323030382053797374656d204365727469666963617465301e170d3132303531303139343030395a170d3133303531303139343030395a3078310b3009060355040613025553310b300906035504080c024e4831 EAP-Message = 0x0e300c06035504070c0553616c656d310c300a060355040a0c03535141310c300a060355040b0c03535141310e300c06035504030c0553636f74743120301e06092a864886f70d01090116117371612e656e746572617379732e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100cdf0ea02581b682e86d3fed11ab7f54da248a1ec6dbfd5535d85a44ac3ed3bdbbe16d6363b7c875a3f99cf1f9814bf428ec5e5751518e410f9a1043b2db75b55b1705e91038a3dcc78f9029038048d8e8138094fbff1820ebb74742222fb9a55e69b3a878c838576589eb4af2aaa966d9f58ce61b1fdd8c64db0c111a192f7cd020301 EAP-Message = 0x0001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010505000382010100b88c1d290a9d1a6c2ca060c0c0a97759d2e22b0814a513b1ad33e90baf162a06b73031b68a4af7932c0d9d804132245311e9e89364eb0170aa4be2e15a4d634c362adaece67dce2db986e39115c0a79e98b53f3406791a44486c41d998c311f2174385d00ce10449cb20b27b5112295a5afad0acc80775cada5399110cf36a51bb60fe7e1bd6a37b41fe9c3610be081b64a11049be9343037c80f65fe7f6b54b3a08c3a0e7ee6d17d26660c87fb131ebf0a602bbb74517df57ff37259ed572c5ced7d3bd17dc403abd071eee1eba EAP-Message = 0x439704ce0c37c762409e6b758cb1362f2117c2aaa8398f8d485a09bf64f8a8f02ff8356fecd6ac5405a284fb361c0c05e18a0003813082037d30820265a003020102021052e1d7f24b931dbc4e684cd8cf2e9853300d06092a864886f70d0101050500305031133011060a0992268993f22c64011916036e657431133011060a0992268993f22c6401191603535141312430220603550403131b53514120323030382053797374656d2043657274696669636174653020170d3131313132383230313534335a180f32313131313132383230323534325a305031133011060a0992268993f22c64011916036e657431133011060a0992268993f22c6401 EAP-Message = 0x191603535141312430220603 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xaa86bc7bab85a5473544135e4511878c Fri May 11 08:08:13 2012 : Info: Finished request 109. Fri May 11 08:08:13 2012 : Debug: Going to the next request Fri May 11 08:08:13 2012 : Debug: Waking up in 4.4 seconds. rad_recv: Access-Request packet from host 192.168.175.60 port 65202, id=134, length=154 User-Name = "SQA\\sqapeap" Service-Type = Framed-User Called-Station-Id = "00-1F-45-A7-9A-4E" Calling-Station-Id = "08-00-27-0D-CB-01" NAS-IP-Address = 192.168.175.60 NAS-Port = 128 NAS-Port-Id = "ge.3.24" Framed-MTU = 1500 NAS-Port-Type = Ethernet State = 0xaa86bc7bab85a5473544135e4511878c EAP-Message = 0x020300061900 Message-Authenticator = 0x000b75dcd813bd4f8963f6eb54bacb57 Fri May 11 08:08:13 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authorize {...} Fri May 11 08:08:13 2012 : Info: ++[preprocess] returns ok Fri May 11 08:08:13 2012 : Info: ++[chap] returns noop Fri May 11 08:08:13 2012 : Info: ++[mschap] returns noop Fri May 11 08:08:13 2012 : Info: ++[digest] returns noop Fri May 11 08:08:13 2012 : Info: [suffix] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [suffix] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[suffix] returns noop Fri May 11 08:08:13 2012 : Info: [ntdomain] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [ntdomain] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[ntdomain] returns noop Fri May 11 08:08:13 2012 : Info: [eap] EAP packet type response id 3 length 6 Fri May 11 08:08:13 2012 : Info: [eap] Continuing tunnel setup. Fri May 11 08:08:13 2012 : Info: ++[eap] returns ok Fri May 11 08:08:13 2012 : Info: Found Auth-Type = EAP Fri May 11 08:08:13 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authenticate {...} Fri May 11 08:08:13 2012 : Info: [eap] Request found, released from the list Fri May 11 08:08:13 2012 : Info: [eap] EAP/peap Fri May 11 08:08:13 2012 : Info: [eap] processing type peap Fri May 11 08:08:13 2012 : Info: [peap] processing EAP-TLS Fri May 11 08:08:13 2012 : Info: [peap] Received TLS ACK Fri May 11 08:08:13 2012 : Info: [peap] ACK handshake fragment handler Fri May 11 08:08:13 2012 : Info: [peap] eaptls_verify returned 1 Fri May 11 08:08:13 2012 : Info: [peap] eaptls_process returned 13 Fri May 11 08:08:13 2012 : Info: [peap] EAPTLS_HANDLED Fri May 11 08:08:13 2012 : Info: ++[eap] returns handled Sending Access-Challenge of id 134 to 192.168.175.60 port 65202 EAP-Message = 0x010402bc1900550403131b53514120323030382053797374656d20436572746966696361746530820122300d06092a864886f70d01010105000382010f003082010a0282010100b9042e7582826074208089933fdc1fc8bf8e64239b70ef9aec7d2ee32530c1f3bc858121e93418665c044a0249ab154afd55a2e256079aefe6573832b063c1b2758d224b2f41ba18e01bce10c09ad63597f52dc3a2440266d4ee210f0abcd2423555dfda3877f7a73662cec9031c52e63598ea99cead364c83ddfcad4dcb7bcee41692fa4c06f662f893192b68bc89a4abfffbbdab460f9d982910e788579aec31fe59b32c36092736773bb45136cf221eed38e6f8f0 EAP-Message = 0xbeca302387bddfaaf7d5829da1eca9bded6069d973a2b480614a4cde83184550e254a84466598ab46e170e6c7029e3c46f21e747eb9615fc2514890a20fbc670163206e53d8b52536e790203010001a351304f300b0603551d0f040403020186300f0603551d130101ff040530030101ff301d0603551d0e041604146e3141ffc209e19ce5bc6d9c84b5bd4c0e79d5b3301006092b06010401823715010403020100300d06092a864886f70d010105050003820101002156ce1cf81ed9b8790efe81b455a0343aae7934d7ee0adde1320fd5541c9e742e69800db373f3b6e7d6220c01eb8a6dfde466954584d89f74afa1b50f28407b74da0a44bde2f6 EAP-Message = 0x509c207af6f798370c7f7c74a4310d60cd1fdf1d61b16cae7fd22f65d23aec863fffa4c1d0f0a2cb79510c671e8c3b8b331d7839e978e91d0845e3df7d6c41f752307faf9d3f16e1c2d144a551873b1ca4d9ed3fa335012e0183bce5da28c0ff82ecbf9e080473ce9895328be6a82f7db1f0ae388e1abb70178951917b8aa3f72ecec031de3e21aa7f23621a5486974122c35ca5aaa1573fd88c29ee6bcd6f75c69b67590589d83f50cbcff092511676d3c1f431e55fd0cc7a16030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xaa86bc7ba882a5473544135e4511878c Fri May 11 08:08:13 2012 : Info: Finished request 110. Fri May 11 08:08:13 2012 : Debug: Going to the next request Fri May 11 08:08:13 2012 : Debug: Waking up in 4.4 seconds. rad_recv: Access-Request packet from host 192.168.175.60 port 65202, id=135, length=356 User-Name = "SQA\\sqapeap" Service-Type = Framed-User Called-Station-Id = "00-1F-45-A7-9A-4E" Calling-Station-Id = "08-00-27-0D-CB-01" NAS-IP-Address = 192.168.175.60 NAS-Port = 128 NAS-Port-Id = "ge.3.24" Framed-MTU = 1500 NAS-Port-Type = Ethernet State = 0xaa86bc7ba882a5473544135e4511878c EAP-Message = 0x020400d01980000000c61603010086100000820080463837b28480ac2091fb5909466b4725bdbe02f0668e83e5f7b201fee88e3df3b1c4f73a52d49ed5ff52d196635efedf4e54883838a7afcd250a4198559f47af9bbc772d455be7661ad548acedd2b09bc402abd4f539cbf0203a3331d6c72f23224f10a73cd5d5d8826116eb302ba50726ea284ea102fed52d40827af8f06d6c14030100010116030100306f70fbdd038353383d237716dac89ac623320a0f62b076b6d371deb0f53d9a6fd7f20bd59b4ce1a160c8f9ea8d697ab8 Message-Authenticator = 0xd2b60ab5163a0a60b3803399892e8ad1 Fri May 11 08:08:13 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authorize {...} Fri May 11 08:08:13 2012 : Info: ++[preprocess] returns ok Fri May 11 08:08:13 2012 : Info: ++[chap] returns noop Fri May 11 08:08:13 2012 : Info: ++[mschap] returns noop Fri May 11 08:08:13 2012 : Info: ++[digest] returns noop Fri May 11 08:08:13 2012 : Info: [suffix] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [suffix] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[suffix] returns noop Fri May 11 08:08:13 2012 : Info: [ntdomain] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [ntdomain] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[ntdomain] returns noop Fri May 11 08:08:13 2012 : Info: [eap] EAP packet type response id 4 length 208 Fri May 11 08:08:13 2012 : Info: [eap] Continuing tunnel setup. Fri May 11 08:08:13 2012 : Info: ++[eap] returns ok Fri May 11 08:08:13 2012 : Info: Found Auth-Type = EAP Fri May 11 08:08:13 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authenticate {...} Fri May 11 08:08:13 2012 : Info: [eap] Request found, released from the list Fri May 11 08:08:13 2012 : Info: [eap] EAP/peap Fri May 11 08:08:13 2012 : Info: [eap] processing type peap Fri May 11 08:08:13 2012 : Info: [peap] processing EAP-TLS Fri May 11 08:08:13 2012 : Debug: TLS Length 198 Fri May 11 08:08:13 2012 : Info: [peap] Length Included Fri May 11 08:08:13 2012 : Info: [peap] eaptls_verify returned 11 Fri May 11 08:08:13 2012 : Info: [peap] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange Fri May 11 08:08:13 2012 : Info: [peap] TLS_accept: SSLv3 read client key exchange A Fri May 11 08:08:13 2012 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] Fri May 11 08:08:13 2012 : Info: [peap] <<< TLS 1.0 Handshake [length 0010], Finished Fri May 11 08:08:13 2012 : Info: [peap] TLS_accept: SSLv3 read finished A Fri May 11 08:08:13 2012 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] Fri May 11 08:08:13 2012 : Info: [peap] TLS_accept: SSLv3 write change cipher spec A Fri May 11 08:08:13 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 0010], Finished Fri May 11 08:08:13 2012 : Info: [peap] TLS_accept: SSLv3 write finished A Fri May 11 08:08:13 2012 : Info: [peap] TLS_accept: SSLv3 flush data Fri May 11 08:08:13 2012 : Info: [peap] (other): SSL negotiation finished successfully Fri May 11 08:08:13 2012 : Debug: SSL Connection Established Fri May 11 08:08:13 2012 : Info: [peap] eaptls_process returned 13 Fri May 11 08:08:13 2012 : Info: [peap] EAPTLS_HANDLED Fri May 11 08:08:13 2012 : Info: ++[eap] returns handled Sending Access-Challenge of id 135 to 192.168.175.60 port 65202 EAP-Message = 0x0105004119001403010001011603010030838d15cd73ed5acd80788f0f744777bbfb8f3496d0dbfe71c9daf3593ba18400ae3b6df1d139fa8710ea64bc780e3103 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xaa86bc7ba983a5473544135e4511878c Fri May 11 08:08:13 2012 : Info: Finished request 111. Fri May 11 08:08:13 2012 : Debug: Going to the next request Fri May 11 08:08:13 2012 : Debug: Waking up in 4.3 seconds. rad_recv: Access-Request packet from host 192.168.175.60 port 65202, id=136, length=154 User-Name = "SQA\\sqapeap" Service-Type = Framed-User Called-Station-Id = "00-1F-45-A7-9A-4E" Calling-Station-Id = "08-00-27-0D-CB-01" NAS-IP-Address = 192.168.175.60 NAS-Port = 128 NAS-Port-Id = "ge.3.24" Framed-MTU = 1500 NAS-Port-Type = Ethernet State = 0xaa86bc7ba983a5473544135e4511878c EAP-Message = 0x020500061900 Message-Authenticator = 0x81fced2e4c993f65247ce06be7d72a0c Fri May 11 08:08:13 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authorize {...} Fri May 11 08:08:13 2012 : Info: ++[preprocess] returns ok Fri May 11 08:08:13 2012 : Info: ++[chap] returns noop Fri May 11 08:08:13 2012 : Info: ++[mschap] returns noop Fri May 11 08:08:13 2012 : Info: ++[digest] returns noop Fri May 11 08:08:13 2012 : Info: [suffix] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [suffix] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[suffix] returns noop Fri May 11 08:08:13 2012 : Info: [ntdomain] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [ntdomain] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[ntdomain] returns noop Fri May 11 08:08:13 2012 : Info: [eap] EAP packet type response id 5 length 6 Fri May 11 08:08:13 2012 : Info: [eap] Continuing tunnel setup. Fri May 11 08:08:13 2012 : Info: ++[eap] returns ok Fri May 11 08:08:13 2012 : Info: Found Auth-Type = EAP Fri May 11 08:08:13 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authenticate {...} Fri May 11 08:08:13 2012 : Info: [eap] Request found, released from the list Fri May 11 08:08:13 2012 : Info: [eap] EAP/peap Fri May 11 08:08:13 2012 : Info: [eap] processing type peap Fri May 11 08:08:13 2012 : Info: [peap] processing EAP-TLS Fri May 11 08:08:13 2012 : Info: [peap] Received TLS ACK Fri May 11 08:08:13 2012 : Info: [peap] ACK handshake is finished Fri May 11 08:08:13 2012 : Info: [peap] eaptls_verify returned 3 Fri May 11 08:08:13 2012 : Info: [peap] eaptls_process returned 3 Fri May 11 08:08:13 2012 : Info: [peap] EAPTLS_SUCCESS Fri May 11 08:08:13 2012 : Info: [peap] Session established. Decoding tunneled attributes. Fri May 11 08:08:13 2012 : Info: [peap] Peap state TUNNEL ESTABLISHED Fri May 11 08:08:13 2012 : Info: ++[eap] returns handled Sending Access-Challenge of id 136 to 192.168.175.60 port 65202 EAP-Message = 0x0106002b19001703010020a7117ca0f626e9300ef5cfdf57fc9a14218ef6fe762945152331ee0d8a146294 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xaa86bc7bae80a5473544135e4511878c Fri May 11 08:08:13 2012 : Info: Finished request 112. Fri May 11 08:08:13 2012 : Debug: Going to the next request Fri May 11 08:08:13 2012 : Debug: Waking up in 4.3 seconds. rad_recv: Access-Request packet from host 192.168.175.60 port 65202, id=137, length=207 User-Name = "SQA\\sqapeap" Service-Type = Framed-User Called-Station-Id = "00-1F-45-A7-9A-4E" Calling-Station-Id = "08-00-27-0D-CB-01" NAS-IP-Address = 192.168.175.60 NAS-Port = 128 NAS-Port-Id = "ge.3.24" Framed-MTU = 1500 NAS-Port-Type = Ethernet State = 0xaa86bc7bae80a5473544135e4511878c EAP-Message = 0x0206003b190017030100309654ab90a674acdf836a4484b10af45223b24a84aea92020e329df8c2f4c8adae101fc89f98a9b5574dcd59ee84a8d81 Message-Authenticator = 0xff44378d5ab27db959ad202ba7850b00 Fri May 11 08:08:13 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authorize {...} Fri May 11 08:08:13 2012 : Info: ++[preprocess] returns ok Fri May 11 08:08:13 2012 : Info: ++[chap] returns noop Fri May 11 08:08:13 2012 : Info: ++[mschap] returns noop Fri May 11 08:08:13 2012 : Info: ++[digest] returns noop Fri May 11 08:08:13 2012 : Info: [suffix] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [suffix] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[suffix] returns noop Fri May 11 08:08:13 2012 : Info: [ntdomain] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [ntdomain] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[ntdomain] returns noop Fri May 11 08:08:13 2012 : Info: [eap] EAP packet type response id 6 length 59 Fri May 11 08:08:13 2012 : Info: [eap] Continuing tunnel setup. Fri May 11 08:08:13 2012 : Info: ++[eap] returns ok Fri May 11 08:08:13 2012 : Info: Found Auth-Type = EAP Fri May 11 08:08:13 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authenticate {...} Fri May 11 08:08:13 2012 : Info: [eap] Request found, released from the list Fri May 11 08:08:13 2012 : Info: [eap] EAP/peap Fri May 11 08:08:13 2012 : Info: [eap] processing type peap Fri May 11 08:08:13 2012 : Info: [peap] processing EAP-TLS Fri May 11 08:08:13 2012 : Info: [peap] eaptls_verify returned 7 Fri May 11 08:08:13 2012 : Info: [peap] Done initial handshake Fri May 11 08:08:13 2012 : Info: [peap] eaptls_process returned 7 Fri May 11 08:08:13 2012 : Info: [peap] EAPTLS_OK Fri May 11 08:08:13 2012 : Info: [peap] Session established. Decoding tunneled attributes. Fri May 11 08:08:13 2012 : Info: [peap] Peap state WAITING FOR INNER IDENTITY Fri May 11 08:08:13 2012 : Info: [peap] Identity - SQA\sqapeap Fri May 11 08:08:13 2012 : Info: [peap] Got inner identity 'SQA\sqapeap' Fri May 11 08:08:13 2012 : Info: [peap] Setting default EAP type for tunneled EAP session. Fri May 11 08:08:13 2012 : Info: [peap] Got tunneled request EAP-Message = 0x02060010015351415c73716170656170 server { Fri May 11 08:08:13 2012 : Debug: PEAP: Setting User-Name to SQA\sqapeap Sending tunneled request EAP-Message = 0x02060010015351415c73716170656170 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "SQA\\sqapeap" server inner-tunnel { Fri May 11 08:08:13 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel Fri May 11 08:08:13 2012 : Info: +- entering group authorize {...} Fri May 11 08:08:13 2012 : Info: ++[chap] returns noop Fri May 11 08:08:13 2012 : Info: ++[mschap] returns noop Fri May 11 08:08:13 2012 : Info: ++[unix] returns notfound Fri May 11 08:08:13 2012 : Info: [suffix] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [suffix] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[suffix] returns noop Fri May 11 08:08:13 2012 : Info: ++[control] returns noop Fri May 11 08:08:13 2012 : Info: [eap] EAP packet type response id 6 length 16 Fri May 11 08:08:13 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Fri May 11 08:08:13 2012 : Info: ++[eap] returns updated Fri May 11 08:08:13 2012 : Info: ++[files] returns noop Fri May 11 08:08:13 2012 : Info: ++[expiration] returns noop Fri May 11 08:08:13 2012 : Info: ++[logintime] returns noop Fri May 11 08:08:13 2012 : Info: ++[pap] returns noop Fri May 11 08:08:13 2012 : Info: Found Auth-Type = EAP Fri May 11 08:08:13 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel Fri May 11 08:08:13 2012 : Info: +- entering group authenticate {...} Fri May 11 08:08:13 2012 : Info: [eap] EAP Identity Fri May 11 08:08:13 2012 : Info: [eap] processing type mschapv2 Fri May 11 08:08:13 2012 : Debug: rlm_eap_mschapv2: Issuing Challenge Fri May 11 08:08:13 2012 : Info: ++[eap] returns handled } # server inner-tunnel Fri May 11 08:08:13 2012 : Info: [peap] Got tunneled reply code 11 EAP-Message = 0x010700251a0107002010624dc963efbbc11443de20dbf8bd85dd5351415c73716170656170 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x59b4f31f59b3e9805d8ea2f4cd3c97e6 Fri May 11 08:08:13 2012 : Info: [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x010700251a0107002010624dc963efbbc11443de20dbf8bd85dd5351415c73716170656170 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x59b4f31f59b3e9805d8ea2f4cd3c97e6 Fri May 11 08:08:13 2012 : Info: [peap] Got tunneled Access-Challenge PEAP tunnel data out 0000: 1a 01 07 00 20 10 62 4d c9 63 ef bb c1 14 43 de PEAP tunnel data out 0010: 20 db f8 bd 85 dd 53 51 41 5c 73 71 61 70 65 61 PEAP tunnel data out 0020: 70 Fri May 11 08:08:13 2012 : Info: ++[eap] returns handled Sending Access-Challenge of id 137 to 192.168.175.60 port 65202 EAP-Message = 0x0107004b190017030100404c5f068f847f32059de6bba78bad464999de2685c4822ef1a0be6c23946a39f8dc6ce8af49120518a2d6a4c7d24274f82681cc2aba2c4dcc9f2b8cbcedc1f559 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xaa86bc7baf81a5473544135e4511878c Fri May 11 08:08:13 2012 : Info: Finished request 113. Fri May 11 08:08:13 2012 : Debug: Going to the next request Fri May 11 08:08:13 2012 : Debug: Waking up in 4.3 seconds. rad_recv: Access-Request packet from host 192.168.175.60 port 65202, id=138, length=255 User-Name = "SQA\\sqapeap" Service-Type = Framed-User Called-Station-Id = "00-1F-45-A7-9A-4E" Calling-Station-Id = "08-00-27-0D-CB-01" NAS-IP-Address = 192.168.175.60 NAS-Port = 128 NAS-Port-Id = "ge.3.24" Framed-MTU = 1500 NAS-Port-Type = Ethernet State = 0xaa86bc7baf81a5473544135e4511878c EAP-Message = 0x0207006b19001703010060d68c17c32bbdaf3df7da97a3e0e39e0e1a714b96ddc8c96b1ab1b08913479d66a9aefd071e7ebcf92e57af93058998d4a78ed1ec7adb91cd1fd895013488f59f7a2c64440d18932893e658efc5606eb3186bcf28c4a21ca590986f2daa88c166 Message-Authenticator = 0x65ad45297a9fe402a2370ae211ac674e Fri May 11 08:08:13 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authorize {...} Fri May 11 08:08:13 2012 : Info: ++[preprocess] returns ok Fri May 11 08:08:13 2012 : Info: ++[chap] returns noop Fri May 11 08:08:13 2012 : Info: ++[mschap] returns noop Fri May 11 08:08:13 2012 : Info: ++[digest] returns noop Fri May 11 08:08:13 2012 : Info: [suffix] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [suffix] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[suffix] returns noop Fri May 11 08:08:13 2012 : Info: [ntdomain] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [ntdomain] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[ntdomain] returns noop Fri May 11 08:08:13 2012 : Info: [eap] EAP packet type response id 7 length 107 Fri May 11 08:08:13 2012 : Info: [eap] Continuing tunnel setup. Fri May 11 08:08:13 2012 : Info: ++[eap] returns ok Fri May 11 08:08:13 2012 : Info: Found Auth-Type = EAP Fri May 11 08:08:13 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authenticate {...} Fri May 11 08:08:13 2012 : Info: [eap] Request found, released from the list Fri May 11 08:08:13 2012 : Info: [eap] EAP/peap Fri May 11 08:08:13 2012 : Info: [eap] processing type peap Fri May 11 08:08:13 2012 : Info: [peap] processing EAP-TLS Fri May 11 08:08:13 2012 : Info: [peap] eaptls_verify returned 7 Fri May 11 08:08:13 2012 : Info: [peap] Done initial handshake Fri May 11 08:08:13 2012 : Info: [peap] eaptls_process returned 7 Fri May 11 08:08:13 2012 : Info: [peap] EAPTLS_OK Fri May 11 08:08:13 2012 : Info: [peap] Session established. Decoding tunneled attributes. Fri May 11 08:08:13 2012 : Info: [peap] Peap state phase2 Fri May 11 08:08:13 2012 : Info: [peap] EAP type mschapv2 Fri May 11 08:08:13 2012 : Info: [peap] Got tunneled request EAP-Message = 0x020700461a02070041313f56ccb5d1debad1683c00be09180fe8000000000000000046eb0f981a6121ad65e5726b0ee0e2097d610172204c7f24005351415c73716170656170 server { Fri May 11 08:08:13 2012 : Debug: PEAP: Setting User-Name to SQA\sqapeap Sending tunneled request EAP-Message = 0x020700461a02070041313f56ccb5d1debad1683c00be09180fe8000000000000000046eb0f981a6121ad65e5726b0ee0e2097d610172204c7f24005351415c73716170656170 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "SQA\\sqapeap" State = 0x59b4f31f59b3e9805d8ea2f4cd3c97e6 server inner-tunnel { Fri May 11 08:08:13 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel Fri May 11 08:08:13 2012 : Info: +- entering group authorize {...} Fri May 11 08:08:13 2012 : Info: ++[chap] returns noop Fri May 11 08:08:13 2012 : Info: ++[mschap] returns noop Fri May 11 08:08:13 2012 : Info: ++[unix] returns notfound Fri May 11 08:08:13 2012 : Info: [suffix] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [suffix] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[suffix] returns noop Fri May 11 08:08:13 2012 : Info: ++[control] returns noop Fri May 11 08:08:13 2012 : Info: [eap] EAP packet type response id 7 length 70 Fri May 11 08:08:13 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Fri May 11 08:08:13 2012 : Info: ++[eap] returns updated Fri May 11 08:08:13 2012 : Info: ++[files] returns noop Fri May 11 08:08:13 2012 : Info: ++[expiration] returns noop Fri May 11 08:08:13 2012 : Info: ++[logintime] returns noop Fri May 11 08:08:13 2012 : Info: ++[pap] returns noop Fri May 11 08:08:13 2012 : Info: Found Auth-Type = EAP Fri May 11 08:08:13 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel Fri May 11 08:08:13 2012 : Info: +- entering group authenticate {...} Fri May 11 08:08:13 2012 : Info: [eap] Request found, released from the list Fri May 11 08:08:13 2012 : Info: [eap] EAP/mschapv2 Fri May 11 08:08:13 2012 : Info: [eap] processing type mschapv2 Fri May 11 08:08:13 2012 : Info: [mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel Fri May 11 08:08:13 2012 : Info: [mschapv2] +- entering group MS-CHAP {...} Fri May 11 08:08:13 2012 : Info: [mschap] Creating challenge hash with username: sqapeap Fri May 11 08:08:13 2012 : Info: [mschap] Told to do MS-CHAPv2 for sqapeap with NT-Password Fri May 11 08:08:13 2012 : Info: [mschap] expand: %{Stripped-User-Name} -> Fri May 11 08:08:13 2012 : Info: [mschap] ... expanding second conditional Fri May 11 08:08:13 2012 : Info: [mschap] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details Fri May 11 08:08:13 2012 : Info: [mschap] expand: %{User-Name:-None} -> SQA\sqapeap Fri May 11 08:08:13 2012 : Info: [mschap] expand: --username=%{%{Stripped-User-Name}:-%{User-Name:-None}} -> --username=SQA\sqapeap Fri May 11 08:08:13 2012 : Info: [mschap] mschap2: 62 Fri May 11 08:08:13 2012 : Info: [mschap] Creating challenge hash with username: sqapeap Fri May 11 08:08:13 2012 : Info: [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=ab56b7e9f5df9308 Fri May 11 08:08:13 2012 : Info: [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=46eb0f981a6121ad65e5726b0ee0e2097d610172204c7f24 Fri May 11 08:08:13 2012 : Debug: Exec-Program output: Access denied (0xc0000022) Fri May 11 08:08:13 2012 : Debug: Exec-Program-Wait: plaintext: Access denied (0xc0000022) Fri May 11 08:08:13 2012 : Debug: Exec-Program: returned: 1 Fri May 11 08:08:13 2012 : Info: [mschap] External script failed. Fri May 11 08:08:13 2012 : Info: [mschap] FAILED: MS-CHAP2-Response is incorrect Fri May 11 08:08:13 2012 : Info: ++[mschap] returns reject Fri May 11 08:08:13 2012 : Info: [eap] Freeing handler Fri May 11 08:08:13 2012 : Info: ++[eap] returns reject Fri May 11 08:08:13 2012 : Info: Failed to authenticate the user. } # server inner-tunnel Fri May 11 08:08:13 2012 : Info: [peap] Got tunneled reply code 3 MS-CHAP-Error = "\007E=691 R=1" EAP-Message = 0x04070004 Message-Authenticator = 0x00000000000000000000000000000000 Fri May 11 08:08:13 2012 : Info: [peap] Got tunneled reply RADIUS code 3 MS-CHAP-Error = "\007E=691 R=1" EAP-Message = 0x04070004 Message-Authenticator = 0x00000000000000000000000000000000 Fri May 11 08:08:13 2012 : Info: [peap] Tunneled authentication was rejected. Fri May 11 08:08:13 2012 : Info: [peap] FAILURE Fri May 11 08:08:13 2012 : Info: ++[eap] returns handled Sending Access-Challenge of id 138 to 192.168.175.60 port 65202 EAP-Message = 0x0108002b1900170301002041bcaaa17289a1c5162cb498969093ca0dd2347fe21bc72882bc25f3835f9a2a Message-Authenticator = 0x00000000000000000000000000000000 State = 0xaa86bc7bac8ea5473544135e4511878c Fri May 11 08:08:13 2012 : Info: Finished request 114. Fri May 11 08:08:13 2012 : Debug: Going to the next request Fri May 11 08:08:13 2012 : Debug: Waking up in 4.2 seconds. rad_recv: Access-Request packet from host 192.168.175.60 port 65202, id=139, length=191 User-Name = "SQA\\sqapeap" Service-Type = Framed-User Called-Station-Id = "00-1F-45-A7-9A-4E" Calling-Station-Id = "08-00-27-0D-CB-01" NAS-IP-Address = 192.168.175.60 NAS-Port = 128 NAS-Port-Id = "ge.3.24" Framed-MTU = 1500 NAS-Port-Type = Ethernet State = 0xaa86bc7bac8ea5473544135e4511878c EAP-Message = 0x0208002b19001703010020cf6d10b0828e97582b1814a25179ee1804abcc2a0a1c2381dfcf15f4a17f523e Message-Authenticator = 0x4ae4c683b92e1a5c105a719db10398c9 Fri May 11 08:08:13 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authorize {...} Fri May 11 08:08:13 2012 : Info: ++[preprocess] returns ok Fri May 11 08:08:13 2012 : Info: ++[chap] returns noop Fri May 11 08:08:13 2012 : Info: ++[mschap] returns noop Fri May 11 08:08:13 2012 : Info: ++[digest] returns noop Fri May 11 08:08:13 2012 : Info: [suffix] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [suffix] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[suffix] returns noop Fri May 11 08:08:13 2012 : Info: [ntdomain] No '@' in User-Name = "SQA\sqapeap", looking up realm NULL Fri May 11 08:08:13 2012 : Info: [ntdomain] No such realm "NULL" Fri May 11 08:08:13 2012 : Info: ++[ntdomain] returns noop Fri May 11 08:08:13 2012 : Info: [eap] EAP packet type response id 8 length 43 Fri May 11 08:08:13 2012 : Info: [eap] Continuing tunnel setup. Fri May 11 08:08:13 2012 : Info: ++[eap] returns ok Fri May 11 08:08:13 2012 : Info: Found Auth-Type = EAP Fri May 11 08:08:13 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group authenticate {...} Fri May 11 08:08:13 2012 : Info: [eap] Request found, released from the list Fri May 11 08:08:13 2012 : Info: [eap] EAP/peap Fri May 11 08:08:13 2012 : Info: [eap] processing type peap Fri May 11 08:08:13 2012 : Info: [peap] processing EAP-TLS Fri May 11 08:08:13 2012 : Info: [peap] eaptls_verify returned 7 Fri May 11 08:08:13 2012 : Info: [peap] Done initial handshake Fri May 11 08:08:13 2012 : Info: [peap] eaptls_process returned 7 Fri May 11 08:08:13 2012 : Info: [peap] EAPTLS_OK Fri May 11 08:08:13 2012 : Info: [peap] Session established. Decoding tunneled attributes. Fri May 11 08:08:13 2012 : Info: [peap] Peap state send tlv failure Fri May 11 08:08:13 2012 : Info: [peap] Received EAP-TLV response. Fri May 11 08:08:13 2012 : Info: [peap] The users session was previously rejected: returning reject (again.) Fri May 11 08:08:13 2012 : Info: [peap] *** This means you need to read the PREVIOUS messages in the debug output Fri May 11 08:08:13 2012 : Info: [peap] *** to find out the reason why the user was rejected. Fri May 11 08:08:13 2012 : Info: [peap] *** Look for "reject" or "fail". Those earlier messages will tell you. Fri May 11 08:08:13 2012 : Info: [peap] *** what went wrong, and how to fix the problem. Fri May 11 08:08:13 2012 : Info: [eap] Handler failed in EAP/peap Fri May 11 08:08:13 2012 : Info: [eap] Failed in EAP select Fri May 11 08:08:13 2012 : Info: ++[eap] returns invalid Fri May 11 08:08:13 2012 : Info: Failed to authenticate the user. Fri May 11 08:08:13 2012 : Info: Using Post-Auth-Type Reject Fri May 11 08:08:13 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Fri May 11 08:08:13 2012 : Info: +- entering group REJECT {...} Fri May 11 08:08:13 2012 : Info: [attr_filter.access_reject] expand: %{User-Name} -> SQA\sqapeap Fri May 11 08:08:13 2012 : Debug: attr_filter: Matched entry DEFAULT at line 11 Fri May 11 08:08:13 2012 : Info: ++[attr_filter.access_reject] returns updated Fri May 11 08:08:13 2012 : Info: Delaying reject of request 115 for 1 seconds Fri May 11 08:08:13 2012 : Debug: Going to the next request Fri May 11 08:08:13 2012 : Debug: Waking up in 0.9 seconds. Fri May 11 08:08:14 2012 : Info: Sending delayed reject for request 115 Sending Access-Reject of id 139 to 192.168.175.60 port 65202 EAP-Message = 0x04080004 Message-Authenticator = 0x00000000000000000000000000000000 Fri May 11 08:08:14 2012 : Debug: Waking up in 3.2 seconds. Fri May 11 08:08:17 2012 : Info: Cleaning up request 108 ID 132 with timestamp +1769 Fri May 11 08:08:17 2012 : Debug: Waking up in 0.5 seconds. Fri May 11 08:08:18 2012 : Info: Cleaning up request 109 ID 133 with timestamp +1770 Fri May 11 08:08:18 2012 : Info: Cleaning up request 110 ID 134 with timestamp +1770 Fri May 11 08:08:18 2012 : Info: Cleaning up request 111 ID 135 with timestamp +1770 Fri May 11 08:08:18 2012 : Info: Cleaning up request 112 ID 136 with timestamp +1770 Fri May 11 08:08:18 2012 : Info: Cleaning up request 113 ID 137 with timestamp +1770 Fri May 11 08:08:18 2012 : Info: Cleaning up request 114 ID 138 with timestamp +1770 Fri May 11 08:08:18 2012 : Debug: Waking up in 1.0 seconds. Fri May 11 08:08:19 2012 : Info: Cleaning up request 115 ID 139 with timestamp +1770 Fri May 11 08:08:19 2012 : Info: Ready to process requests. -- View this message in context: http://freeradius.1045715.n5.nabble.com/MSCHAP-Errors-tp5702886.html Sent from the FreeRadius - User mailing list archive at Nabble.com.

4 5

EAP/TTLS Auth problem
by Steve Hopps 15 May '12

15 May '12

I'm trying to use FreeRadius with OpenLDAP for authentication of some Nanostation M2 access points, but have had no luck getting it to work. When using rad_eap_test to experiment, I logged the following: Found Auth-Type = PAP # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group PAP {...} [pap] login attempt with password "-removed-" [pap] Using CRYPT password "*" [pap] Passwords don't match ++[pap] returns reject Failed to authenticate the user. Can anyone suggest what I'm doing wrong? The output for this section is the same with rad_eap_test or the AP itself.

4 11

Re:Specific User Trace and multiple radiusd instant(Tom Deng)
by 全球无线联盟 15 May '12

15 May '12

Fajar, Yes. We're using Linux ES 5.4. We're leasing a virtual server from a vendor. While Linux ES 5.4 is the Linux server it can provide. Actually, it helped us. As we need PPTP VPN dailup for our application, the PPTP VPN installation on 5.4 is very smooth. While we can't make it work on Linux ES 6.0/6.1. We got two freeradius versions available on 5.4, freeradius1 and freeradius2, and we selected freeradius2. Thanks for advise raddebug. So far, it doesn't work well for us. As your advise, we actually tried radmin. radmin> debug condition '(User-Name == 1)' radmin> radmin> show debug level 4 radmin> show debug condition (User-Name == 1) //"1" is the username. radmin> show debug file /var/log/radius/tom.log We tail -f /var/log/radius/tom.log. We found two issues. 1. The output from the radmin is diffirent from "Radius -X". While we consider radiusd -X output more helpful information. While radmin didn't. 2. We like to filter the debug information for user "1" only, while the radmin still output all users. Can you please help to advise what would be the reason? You mentioned ixc virtualization, do you have a web site link for this software? I googled it, but not found. As we leasing the virtual server, we failed to nest install VMWare on our server. So your virtual server may work. Hello, James, Thanks for your reply. As mentioned previously, we failed to install VMWare on our leased virtual box. The reason to want multiple radiusd is, we don't know the raddebug solution previouly. We planed run second freeradius for debug only. We also need multiple radiusd instant for some other reason. Alan, We tried to configure multiple instances, but failed. So we need a handy configuration guide. Thank you all. Tom Deng.

3 2

Anon repo access?
by Brian Julin 15 May '12

15 May '12

Is anyone else getting this problem, or have I just managed to confuse git somehow? $ git pull origin master fatal: remote error: access denied or repository not exported: /freeradius-server.git $ git remote -v origin git://git.freeradius.org/freeradius-server.git (fetch) origin git://git.freeradius.org/freeradius-server.git (push)

3 2

Acct session ID shows "0"
by Sharad P 15 May '12

15 May '12

hi, I have one doubt in my Acct session id i had clients mac address then ssid and then session id.but in some of the Act session id it shows clients mac address then ssid and then 0.because of which i get huge Acct session time about 947412332...please see the logs below.radius new is my ssid.it would be very helpful if you solve the query. NAS-IP-Address = 192.168.200.56 NAS-Identifier = "E1C76A60846" Called-Station-Id = "00:06:5a:01:1b:d9" NAS-Port = 1 NAS-Port-Type = Wireless-802.11 User-Name = "Unknown" Calling-Station-Id = "00:14:a4:87:04:15" Acct-Status-Type = Stop Acct-Session-Id = "00:14:a4:87:04:15:radius new:947412116" Acct-Input-Octets = 0 Acct-Output-Octets = 225 Acct-Input-Packets = 0 Acct-Output-Packets = 5 Acct-Session-Time = 15 Acct-Terminate-Cause = User-Request Client-IP-Address = 192.168.200.56 Acct-Unique-Session-Id = "61a2b61dd6a83f91" Timestamp = 1337005110 Mon May 14 19:51:50 2012 NAS-IP-Address = 192.168.200.56 NAS-Identifier = "E1C76A60846" Called-Station-Id = "00:06:5a:01:1b:d9" NAS-Port = 1 NAS-Port-Type = Wireless-802.11 User-Name = "Unknown" Calling-Station-Id = "00:14:a4:87:04:15" Acct-Status-Type = Stop Acct-Session-Id = "00:14:a4:87:04:15:radius new:0" Acct-Input-Octets = 2833 Acct-Output-Octets = 4355 Acct-Input-Packets = 24 Acct-Output-Packets = 19 Acct-Session-Time = 947412332 Acct-Terminate-Cause = User-Request Client-IP-Address = 192.168.200.56 Acct-Unique-Session-Id = "48d0d61e828c612f" Timestamp = 1337005310 -- View this message in context: http://freeradius.1045715.n5.nabble.com/Acct-session-ID-shows-0-tp5709113.h… Sent from the FreeRadius - User mailing list archive at Nabble.com.

4 8

Logrotate tool
by yagizozen 15 May '12

15 May '12

Hello everyone, As you know, FR has a radius.log file under /var/log/radius directory. I noticed that inside the logrorate file, radius.log is set to rotate every month. Like this : /var/log/radius/radius.log { monthly rotate 100 create missingok compress } This is by default. I changed this to "daily" but the problem is, I need to restart radius everytime when the new day comes in order to write to NEW radius.log file. If I do not restart, it tries to point the compress version of the old radius.log. Why is that? I also can not do this inside an external script. When I rename the file inside the script, it still writes to the new renamed radius.log file. Any suggestions or any place for me to read? Thanks You in advance. -- View this message in context: http://freeradius.1045715.n5.nabble.com/Logrotate-tool-tp5709081.html Sent from the FreeRadius - User mailing list archive at Nabble.com.

3 3

return list
by Luo, Frank Y.F. Mr. 15 May '12

15 May '12

I have a senario, no ldap schema extension is wanted ( no ldap group or profile is wanted); we do use ldap authentication though; and it works fine. after authentication, we need to check one ldap attribute like "vpn" and and return "class: ou={ldap vpn value}" back to the radius client (the cisco concentrator). So in the sites_avaiable/default, I have this post-auth { update reply { class = "ou=%Profile" } and in ldap.attrmap, i have replyItem Profile VPN There must a syntax error on how to refer a ldap attribute value here. since what I got is this # Executing section post-auth from file /opt/freeradius/etc/raddb/sites-enabled/default +- entering group post-auth {...} WARNING: Unknown variable '%P': See 'doc/variables.txt' expand: ou=%Profile -> ou=%Profile ++[reply] returns noop Any clue how to implement this? THanks Frank

2 1

change of acct_status type
by Sharad P 15 May '12

15 May '12

hi, can I change ACCT_STATUS_TYPE to interim update.if yes.Please tell me the procedure. Thanks. -- View this message in context: http://freeradius.1045715.n5.nabble.com/change-of-acct-status-type-tp570979… Sent from the FreeRadius - User mailing list archive at Nabble.com.

2 3

Multiple challenges to login
by Maria Sanchez 14 May '12

14 May '12

We are having problems when accessing our sites. No matter which browser we use to access it always requests authentication twice. We have an Apache web server (v.2.2) with mod_auth_radius 2.0 installed. And we have mounted a Jboss application using mod_jk module and protected access to it. I am not able to find any information about this and this is becoming a big problem. This is the configuration for radius.conf: <Location /> AuthType Basic AuthName "RADIUS authentication" AuthBasicAuthoritative Off AuthRadiusAuthoritative on AuthRadiusCookieValid 0 AuthRadiusActive On require valid-user </Location> I have been playing with the values of the cookies, I originally had it in 5 and changed it to 0 but didn't help. Any ideas why this can be happening? Thanks, Maria

2 1

Re:re: Re: Ldap attribute in pre-proxy possible?
by Mike 14 May '12

14 May '12

> Phil, I meant to say proxy-request, not proxy-reply. Secondly, why would you need a log file to show an attribute expanding to nothing? I just told you it is expanding to nothing aka it has no assigned value once reaching the pre-proxy stage. > Message: 3 > Date: Fri, 11 May 2012 18:07:40 +0100 > From: Phil Mayers <p.mayers(a)imperial.ac.uk> > To: freeradius-users(a)lists.freeradius.org > Subject: Re: Ldap attribute in pre-proxy possible? > Message-ID: <4FAD475C.7090109(a)imperial.ac.uk> > Content-Type: text/plain; charset=ISO-8859-1; format=flowed > > On 11/05/12 16:39, Mike wrote: >> Hello, >> >> Is it possible store and access an ldap attribute in pre-proxy? 1. >> Attribute defined in dictionary 2. Attribute mapped in ldap.attrmap >> 2. Trying to access using: >> >> pre-proxy { If (%{reply:attributename} == "cookies" { update >> proxy-reply { Whatever = "cookies" }} } > > You can't update the proxy-reply in pre-proxy; there is no proxy-reply > at this stage. > >> >> the problem is the attribute is expanding to nothing. This does work >> in the auth section but i need to update the proxy msg. What am i >> doing wrong? > > We don't know, because we're not psychic and you didn't include a debug > of it failing. > > > > ------------------------------ > > Message: 4 > Date: Fri, 11 May 2012 13:42:29 -0400 > From: "Luo, Frank Y.F. Mr." <luoy(a)muohio.edu> > To: "freeradius-users(a)lists.freeradius.org" > <freeradius-users(a)lists.freeradius.org> > Subject: max_request > Message-ID: <200CB918-2061-4829-A888-8901A235E952(a)muohio.edu> > Content-Type: text/plain; charset="us-ascii" > > So there is this setting max_request that the server keeps track of. The question is how i can find the current active request that the server keeps track of. > > My experience is the sever silently drops the connection if max_request is reached. So I want to find out more info about the current status of the server. > > Thanks > > Frank > > > > ------------------------------ > > Message: 5 > Date: Fri, 11 May 2012 20:25:06 +0200 > From: Alan DeKok <aland(a)deployingradius.com> > To: FreeRadius users mailing list > <freeradius-users(a)lists.freeradius.org> > Subject: Re: max_request > Message-ID: <4FAD5982.1080708(a)deployingradius.com> > Content-Type: text/plain; charset=ISO-8859-1 > > Luo, Frank Y.F. Mr. wrote: >> So there is this setting max_request that the server keeps track of. The question is how i can find the current active request that the server keeps track of. >> >> My experience is the sever silently drops the connection if max_request is reached. So I want to find out more info about the current status of the server. > > In 2.1.12, there's no way to see that number in a "live" server. > > Alan DeKok. > > > ------------------------------ > > Message: 6 > Date: Fri, 11 May 2012 14:31:09 -0400 > From: "Luo, Frank Y.F. Mr." <luoy(a)muohio.edu> > To: FreeRadius users mailing list > <freeradius-users(a)lists.freeradius.org> > Subject: Re: max_request > Message-ID: <0C11C863-C520-491D-AD91-320B65E54B97(a)muohio.edu> > Content-Type: text/plain; charset="us-ascii" > > are you sure? > > Then how do i know I run out of request number and need to increase it? > > Thanks > > Frank > On May 11, 2012, at 2:25 PM, Alan DeKok wrote: > >> Luo, Frank Y.F. Mr. wrote: >>> So there is this setting max_request that the server keeps track of. The question is how i can find the current active request that the server keeps track of. >>> >>> My experience is the sever silently drops the connection if max_request is reached. So I want to find out more info about the current status of the server. >> >> In 2.1.12, there's no way to see that number in a "live" server. >> >> Alan DeKok. >> - >> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html > > > > ------------------------------ > > Message: 7 > Date: Fri, 11 May 2012 20:39:03 +0200 > From: Alan DeKok <aland(a)deployingradius.com> > To: FreeRadius users mailing list > <freeradius-users(a)lists.freeradius.org> > Subject: Re: max_request > Message-ID: <4FAD5CC7.1090502(a)deployingradius.com> > Content-Type: text/plain; charset=ISO-8859-1 > > Luo, Frank Y.F. Mr. wrote: >> are you sure? >> >> Then how do i know I run out of request number and need to increase it? > > You read the logs. > > You CANNOT increase it while the server is running. > > The best approach is to set it to a large value, and ignore it. If > you get errors in the logs about "max_requests", it means that something > is catastrophically wrong. Increasing "max_requests" WILL NOT HELP. > > You will need to fix the underlying problem: usually a slow / broken > database. > > Alan DeKok. > > > ------------------------------ > > Message: 8 > Date: Fri, 11 May 2012 14:45:29 -0400 > From: "Luo, Frank Y.F. Mr." <luoy(a)muohio.edu> > To: FreeRadius users mailing list > <freeradius-users(a)lists.freeradius.org> > Subject: Re: max_request > Message-ID: <A6E5F923-8012-468F-8E93-5CA954B97F87(a)muohio.edu> > Content-Type: text/plain; charset="us-ascii" > > I will read the logs - but what I look for in the log? > > I already set it to a large value and don't expect problem but i wan to verify that by either find the "active" request number or look for something in log to make sure it is / is not this max_request problem. > > THanks > > Frank > > > On May 11, 2012, at 2:39 PM, Alan DeKok wrote: > >> Luo, Frank Y.F. Mr. wrote: >>> are you sure? >>> >>> Then how do i know I run out of request number and need to increase it? >> >> You read the logs. >> >> You CANNOT increase it while the server is running. >> >> The best approach is to set it to a large value, and ignore it. If >> you get errors in the logs about "max_requests", it means that something >> is catastrophically wrong. Increasing "max_requests" WILL NOT HELP. >> >> You will need to fix the underlying problem: usually a slow / broken >> database. >> >> Alan DeKok. >> - >> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html > > > > ------------------------------ > > Message: 9 > Date: Fri, 11 May 2012 14:12:16 -0500 > From: Steve Hopps <steve.hopps(a)gmail.com> > To: freeradius-users(a)lists.freeradius.org > Subject: EAP/TTLS Auth problem > Message-ID: > <CAOxapJxED9bgrpE=UCpcrNi9NGKMv7U-EyaSzh2As=xTw2VZwQ(a)mail.gmail.com> > Content-Type: text/plain; charset=ISO-8859-1 > > I'm trying to use FreeRadius with OpenLDAP for authentication of some > Nanostation M2 access points, but have had no luck getting it to work. > When using rad_eap_test to experiment, I logged the following: > > Found Auth-Type = PAP > # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel > +- entering group PAP {...} > [pap] login attempt with password "-removed-" > [pap] Using CRYPT password "*" > [pap] Passwords don't match > ++[pap] returns reject > Failed to authenticate the user. > > Can anyone suggest what I'm doing wrong? The output for this section > is the same with rad_eap_test or the AP itself. > > > ------------------------------ > > - > List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html > > End of Freeradius-Users Digest, Vol 85, Issue 39 > ************************************************

3 2