cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
1860
Views
0
Helpful
3
Replies

Testing Windows 8 Consumer Preview with ACS 5.2 PEAP auth

We are deploying ACS 5.2 to replace our ACS 4.2 in production.  I have two wireless networks setup as WPA2-Enterprise.  One points at the ACS 4.2 and the other at the ACS 5.2.  Both use the same SSL certificate with the same CN.  Both authenticate Windows 7 clients.  However, Windows 8 CP will only authenticate to the ACS 4.2 and not to ACS 5.2.  The error it gives is:

11051 Radius packet contains invalid state attribute

It also shows no authentication method (most of the time).

Occasionally, I get a request that actually shows an authentication method of PEAP (EAP-MSCHAPv2) which is what it should be.  On those requests, I get error:

24444 Active Directory operation has failed because of an unspecified error in the ACS.

Both ACs 4.2 and ACS 5.2 are pointed at the same Windows AD source.

Anyone have any ideas?  Is there any other information I can provide to help troubleshoot?  I know Windows 8 is not even out yet.  But, it would be nice to have it working.

Thanks!

Jodie

3 Replies 3

Tarik Admani
VIP Alumni
VIP Alumni

Jodie,

If you want to troubleshoot this issue you can do the following:

ssh into the ACS 5.2 appliance, > "acs-config" > enter you web credentials

After logging in (takes 45 seconds for the username to prompt) "debug-adclient enable"

After this reproduce the issue, then under monitoring and reporting note the time the authentication occured.

You can download the support bundle from the monitoring and reports section, uncheck the encryption option for the support bundle, only check to gather debug-logs for the last 1 day.

After you get the support bundle then extract and go to the debug-logs directory and open the ACSADAgent.log file and capture the output at the timestamp you saw, and post it here.

Thanks

Tarik Admani

Thanks Tarik!  I appreciate the detailed steps to collect the information to help troubleshoot this issue.

Here are the logs requested:

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ping=""> daemon.execute executing request 'ping' in thread 3029719968

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> daemon.execute executing request 'MS-RPC user authentication' in thread 3054898080

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> daemon.execute I:IPCClient1::doNetLogonSamLogon - user=SH-HIS\jcrouch

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> base.adagent Find GUID: fa61e77fbfc98044b7153bf5abc9fd78 (7)

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> com.centrify.smb.smbserver SMB Connect to server sh-dc03.shv.lsuhsc-s.edu

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> base.adagent Domain Level for '' is not PreW2K8

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> dns.findsrv FindSrvFromDns(0): _kerberos._tcp.LSUHSC-S._sites.SHV.LSUHSC-S.EDU

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> dns.findsrv FindFromDns(0): _kerberos._tcp.LSUHSC-S._sites.SHV.LSUHSC-S.EDU

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> dns.findsrv FindSrvFromDns(0): _kerberos._tcp.SHV.LSUHSC-S.EDU

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> dns.findsrv FindFromDns(0): _kerberos._tcp.SHV.LSUHSC-S.EDU

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> dns.controllers Updated controller info: last update = Wed May  2 08:01:16 2012, siteName = 'LSUHSC-S', m_serviceType = KDC, domain = 'SHV.LSUHSC-S.EDU', site list = (sh-dc03.shv.lsuhsc-s.edu:88 sh-dc04.shv.lsuhsc-s.edu:88 sh-epic-dc01.shv.lsuhsc-s.edu:88), inferior list = (afm-dc01.shv.lsuhsc-s.edu:88)

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> dns.findkdc Kerberos lookup of SHV.LSUHSC-S.EDU: DNS resolve to sh-dc03.shv.lsuhsc-s.edu:88 sh-dc04.shv.lsuhsc-s.edu:88 sh-epic-dc01.shv.lsuhsc-s.edu:88 afm-dc01.shv.lsuhsc-s.edu:88

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> dns.findkdc Kerberos lookup of SHV.LSUHSC-S.EDU: DNS resolve to sh-dc03.shv.lsuhsc-s.edu:88 sh-dc04.shv.lsuhsc-s.edu:88 sh-epic-dc01.shv.lsuhsc-s.edu:88 afm-dc01.shv.lsuhsc-s.edu:88

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> base.osutil Module=Kerberos : initSecurityContext - gss_init_sec_context failed (reference ../smb/utils/gsskerberos.cpp:198 rc: -1765328352)

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> smb.rpc.schannel SecureChannel::close: m_fh=0x0

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> com.centrify.smb.smbserver SMB disconnect from server sh-dc03.shv.lsuhsc-s.edu

May  2 08:16:36 sh-netacs2 adclient[7987]: DEBUG <19 ms-rpc="" user="" authentication=""> daemon.execute O:IPCClient1::netLogonSamLogon - user=SH-HIS\jcrouch (ntStatus=0xc0000001)

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG daemon.main now = Wed May  2 08:16:46 2012, nextPasswordChange: Wed May  2 08:50:46 2012, lastKrb5ConfUpdate: Thu Jan  1 00:00:00 1970, lastKrb5Renew: Wed May  2 08:03:16 2012, lastBindingRefresh: Wed May  2 08:16:16 2012, lastCacheCleanup: Wed May  2 08:16:16 2012, lastPrevalidate: Wed May  2 08:03:16 2012, lastChkDatadir: Wed May  2 08:12:46 2012, lastAzmanRefresh: Wed May  2 08:15:16 2012

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.bind.healing trying unexpected disconnect reconnect sh-dc03.shv.lsuhsc-s.edu(GC)

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adagent (re)acquiring Init credentials

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.kerberos.adhelpers acquiring machine credentials

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.kerberos.adhelpers Using keytab WRFILE:/etc/krb5.keytab

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adagent Domain Level for '' is not PreW2K8

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG dns.findkdc Kerberos lookup of SHV.LSUHSC-S.EDU: DNS resolve to sh-dc03.shv.lsuhsc-s.edu:88 sh-dc04.shv.lsuhsc-s.edu:88 sh-epic-dc01.shv.lsuhsc-s.edu:88 afm-dc01.shv.lsuhsc-s.edu:88

May  2 08:16:46 sh-netacs2 last message repeated 3 times

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.kerberos.adhelpers Encryption (id 18) is not supported by KDC. Try next in the list

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG dns.findkdc Kerberos lookup of SHV.LSUHSC-S.EDU: DNS resolve to sh-dc03.shv.lsuhsc-s.edu:88 sh-dc04.shv.lsuhsc-s.edu:88 sh-epic-dc01.shv.lsuhsc-s.edu:88 afm-dc01.shv.lsuhsc-s.edu:88

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG dns.findkdc Kerberos lookup of SHV.LSUHSC-S.EDU: DNS resolve to sh-dc03.shv.lsuhsc-s.edu:88 sh-dc04.shv.lsuhsc-s.edu:88 sh-epic-dc01.shv.lsuhsc-s.edu:88 afm-dc01.shv.lsuhsc-s.edu:88

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.kerberos.adhelpers Encryption (id 17) is not supported by KDC. Try next in the list

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.kerberos.adhelpers Encryption (id 23) is not supported by KDC. Try next in the list

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG dns.findkdc Kerberos lookup of SHV.LSUHSC-S.EDU: DNS resolve to sh-dc03.shv.lsuhsc-s.edu:88 sh-dc04.shv.lsuhsc-s.edu:88 sh-epic-dc01.shv.lsuhsc-s.edu:88 afm-dc01.shv.lsuhsc-s.edu:88

May  2 08:16:46 sh-netacs2 last message repeated 3 times

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.osutil Module=Kerberos : KDC refused skey: Clock skew too great (reference base/adhelpers.cpp:215 rc: -1765328347)

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.bind.cache postStart/getInitCreds threw: KDC refused skey: Clock skew too great

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.bind.healing unexpected disconnect reconnect sh-dc03.shv.lsuhsc-s.edu(GC) failed: KDC refused skey: Clock skew too great

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.bind.healing trying unexpected disconnect reconnect sh-dc03.shv.lsuhsc-s.edu

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adagent (re)acquiring Init credentials

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.kerberos.adhelpers acquiring machine credentials

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.kerberos.adhelpers Using keytab WRFILE:/etc/krb5.keytab

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adagent Domain Level for '' is not PreW2K8

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG dns.findkdc Kerberos lookup of SHV.LSUHSC-S.EDU: DNS resolve to sh-dc03.shv.lsuhsc-s.edu:88 sh-dc04.shv.lsuhsc-s.edu:88 sh-epic-dc01.shv.lsuhsc-s.edu:88 afm-dc01.shv.lsuhsc-s.edu:88

May  2 08:16:46 sh-netacs2 last message repeated 3 times

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.kerberos.adhelpers Encryption (id 18) is not supported by KDC. Try next in the list

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG dns.findkdc Kerberos lookup of SHV.LSUHSC-S.EDU: DNS resolve to sh-dc03.shv.lsuhsc-s.edu:88 sh-dc04.shv.lsuhsc-s.edu:88 sh-epic-dc01.shv.lsuhsc-s.edu:88 afm-dc01.shv.lsuhsc-s.edu:88

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG dns.findkdc Kerberos lookup of SHV.LSUHSC-S.EDU: DNS resolve to sh-dc03.shv.lsuhsc-s.edu:88 sh-dc04.shv.lsuhsc-s.edu:88 sh-epic-dc01.shv.lsuhsc-s.edu:88 afm-dc01.shv.lsuhsc-s.edu:88

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.kerberos.adhelpers Encryption (id 17) is not supported by KDC. Try next in the list

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.kerberos.adhelpers Encryption (id 23) is not supported by KDC. Try next in the list

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG dns.findkdc Kerberos lookup of SHV.LSUHSC-S.EDU: DNS resolve to sh-dc03.shv.lsuhsc-s.edu:88 sh-dc04.shv.lsuhsc-s.edu:88 sh-epic-dc01.shv.lsuhsc-s.edu:88 afm-dc01.shv.lsuhsc-s.edu:88

May  2 08:16:46 sh-netacs2 last message repeated 3 times

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.osutil Module=Kerberos : KDC refused skey: Clock skew too great (reference base/adhelpers.cpp:215 rc: -1765328347)

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.bind.cache postStart/getInitCreds threw: KDC refused skey: Clock skew too great

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.bind.healing unexpected disconnect reconnect sh-dc03.shv.lsuhsc-s.edu failed: KDC refused skey: Clock skew too great

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo start updateDomainInfoMap

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo Using existing search marker

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adagent addMap: LSUHSC-S.EDU <-> LSUHSC-S

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adagent addMap: SHV.LSUHSC-S.EDU <-> SH-HIS

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adagent addMap: EAC.LSUHSC-S.EDU <-> LSUMC-EAC

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adagent addMap: LSUHSC.EDU <-> LSUHSC

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adagent addMap: MASTER.LSUHSC.EDU <-> LSUMC-MASTER

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo Using domainInfoMap from cache, it was not expired  (size=5)

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo DC=lsuhsc-s,DC=edu

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     CN              = LSUHSC-S.EDU

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     SID             = S-1-5-21-4197722968-216021789-2322446462

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_ATTRS     = 0x20

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_DIRECTION = 3

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_TYPE      = 2

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     NTLM NAME       = LSUHSC-S

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     LOCAL FOREST    = YES

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo DC=shv,DC=lsuhsc-s,DC=edu

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     CN              = SHV.LSUHSC-S.EDU

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     SID             = S-1-5-21-341470825-1660045691-689510791

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_ATTRS     = 0x20

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_DIRECTION = 3

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_TYPE      = 2

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     NTLM NAME       = SH-HIS

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     LOCAL FOREST    = YES

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo DC=eac,DC=lsuhsc-s,DC=edu

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     CN              = EAC.LSUHSC-S.EDU

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     SID             = S-1-5-21-1451108202-1290631035-623647154

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_ATTRS     = 0x20

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_DIRECTION = 3

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_TYPE      = 2

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     NTLM NAME       = LSUMC-EAC

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     LOCAL FOREST    = YES

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo CN=lsuhsc.edu,CN=System,DC=lsuhsc-s,DC=edu

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     CN              = LSUHSC.EDU

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     SID             = S-1-5-21-2419512895-2621689230-2851238096

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_ATTRS     = 0x8

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_DIRECTION = 3

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_TYPE      = 2

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     NTLM NAME       = LSUHSC

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     LOCAL FOREST    = NO

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo CN=master.lsuhsc.edu,CN=System,DC=shv,DC=lsuhsc-s,DC=edu

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     CN              = MASTER.LSUHSC.EDU

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     SID             = S-1-5-21-2113824390-172908180-308554878

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_ATTRS     = 0x4

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_DIRECTION = 2

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     TRUST_TYPE      = 2

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     NTLM NAME       = LSUMC-MASTER

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG base.adgent.domaininfo     LOCAL FOREST    = NO

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG util.except (TryAgain) : start up not complete (reference base/adagent.cpp:2201 rc: 0)

May  2 08:16:46 sh-netacs2 adclient[7987]: DEBUG daemon.main Delay /etc/krb5.conf update, start up not complete

May  2 08:16:59 sh-netacs2 debugd[2553]: [8075]: locks:file: lock.c[357] [daemon]: obtained repos-mgr lock

May  2 08:16:59 sh-netacs2 debugd[2553]: [8075]: config:repository: rm_repos_cfg.c[251] [daemon]: scanning the tmp dir

May  2 08:16:59 sh-netacs2 debugd[2553]: [8075]: locks:file: lock.c[371] [daemon]: released repos-mgr lock

May  2 08:16:59 sh-netacs2 debugd[2553]: [8075]: locks:file: lock.c[357] [daemon]: obtained repos-mgr lock

May  2 08:16:59 sh-netacs2 debugd[2553]: [8075]: config:repository: rm_repos_cfg.c[251] [daemon]: scanning the tmp dir

May  2 08:16:59 sh-netacs2 debugd[2553]: [8075]: locks:file: lock.c[371] [daemon]: released repos-mgr lock

Jodie,

Please check your ntp configuration, are you using an ntp server or did you manually set the clock on ACS 5? It look as if the ACS isnt able to connect to the domain using its computer account. Point the ACS to a reliable ntp server or set the clock as close as you can to the current time.

Thanks

tarik Admani