==> /var/log/shibboleth/idp-process.log <==

==> /var/log/shibboleth/idp-audit.log <==

==> /var/log/shibboleth/idp-process.log <==
16:08:03.422 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:144] - Begin initialize
16:08:03.423 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:180] - useFirstPass = false
16:08:03.424 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:181] - tryFirstPass = false
16:08:03.424 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:182] - storePass = false
16:08:03.424 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:183] - clearPass = false
16:08:03.425 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:184] - setLdapPrincipal = false
16:08:03.425 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:185] - setLdapDnPrincipal = false
16:08:03.426 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:186] - setLdapCredential = true
16:08:03.426 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:187] - defaultRole = []
16:08:03.426 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:188] - principalGroupName = null
16:08:03.427 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:189] - roleGroupName = null
16:08:03.427 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:77] - userRoleAttribute = []
16:08:03.428 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1385] - setting searchScope: ONELEVEL
16:08:03.429 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:427] - setting subtreeSearch: true
16:08:03.429 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1385] - setting searchScope: SUBTREE
16:08:03.430 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1309] - setting bindCredential: <suppressed>
16:08:03.430 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1834] - setting ssl: true
16:08:03.431 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1168] - setting ldapUrl: ldaps://192.168.148.134:636 ldaps://192.168.148.210:636
16:08:03.431 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:274] - setting userField: [sAMAccountName]
16:08:03.432 - TRACE [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:93] - setting connectionStrategy: RANDOM
16:08:03.432 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1119] - setting connectionHandler: edu.vt.middleware.ldap.handler.DefaultConnectionHandler@ee5de81
16:08:03.433 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1276] - setting bindDn: idp.ldap@kicds.com
16:08:03.433 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1370] - setting baseDn: ou=Students,dc=kicds,dc=com
16:08:03.434 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:83] - Created authenticator: edu.vt.middleware.ldap.auth.AuthenticatorConfig@359853771::env={java.naming.provider.url=ldaps://192.168.148.134:636 ldaps://192.168.148.210:636, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl}
16:08:03.435 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:412] - Begin getCredentials
16:08:03.435 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:413] -   useFistPass = false
16:08:03.435 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:414] -   tryFistPass = false
16:08:03.436 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:415] -   useCallback = false
16:08:03.436 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:416] -   callbackhandler class = javax.security.auth.login.LoginContext$SecureCallbackHandler
16:08:03.437 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:419] -   name callback class = javax.security.auth.callback.NameCallback
16:08:03.437 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:421] -   password callback class = javax.security.auth.callback.PasswordCallback
16:08:03.437 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:108] - Looking up DN using userField
16:08:03.438 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:193] - Search with the following parameters:
16:08:03.438 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:194] -   dn = ou=Students,dc=kicds,dc=com
16:08:03.439 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:195] -   filter = (sAMAccountName={0})
16:08:03.439 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:196] -   filterArgs = [6132922]
16:08:03.440 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:197] -   searchControls = javax.naming.directory.SearchControls@2c9b5c6d
16:08:03.440 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:198] -   handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler@bd10efc]
16:08:03.440 - TRACE [edu.vt.middleware.ldap.auth.SearchDnResolver:200] -   config = {java.naming.provider.url=ldaps://192.168.148.134:636 ldaps://192.168.148.210:636, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl}
16:08:03.441 - TRACE [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:93] - setting connectionStrategy: RANDOM
16:08:03.441 - TRACE [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:110] - setting connectionRetryExceptions: [class javax.naming.NamingException]
16:08:03.442 - TRACE [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:152] - {0} Attempting connection to ldaps://192.168.148.134:636 for strategy RANDOM
16:08:03.442 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the following parameters:
16:08:03.443 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] -   authtype = simple
16:08:03.443 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] -   dn = idp.ldap@kicds.com
16:08:03.444 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -   credential = <suppressed>
16:08:03.444 - TRACE [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:87] -   env = {java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.provider.url=ldaps://192.168.148.134:636, java.naming.security.protocol=ssl}
16:08:03.452 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:128] - Set hostname verifier for ldaps
16:08:03.471 - DEBUG [edu.vt.middleware.ldap.ssl.AggregateTrustManager:75] - invoking checkServerTrusted for sun.security.ssl.X509TrustManagerImpl@3958c3b1
16:08:03.472 - DEBUG [edu.vt.middleware.ldap.ssl.AggregateTrustManager:75] - invoking checkServerTrusted for edu.vt.middleware.ldap.ssl.HostnameVerifyingTrustManager@77e71285
16:08:03.472 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:122] - Verify with the following parameters:
16:08:03.473 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:123] -   hostname = 192.168.148.134
16:08:03.473 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:124] -   cert = CN=kicds.com, OU=KIC, O=Kaplan, L=London, ST=UK, C=UK
16:08:03.474 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:155] - verifyIP using subjectAltNames = [192.168.148.134, 192.168.148.210, 192.168.199.251]
16:08:03.475 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:161] - verifyIP found hostname match: 192.168.148.134
16:08:03.475 - DEBUG [edu.vt.middleware.ldap.ssl.AggregateTrustManager:90] - invoking getAcceptedIssuers invoked for sun.security.ssl.X509TrustManagerImpl@3958c3b1
16:08:03.476 - DEBUG [edu.vt.middleware.ldap.ssl.AggregateTrustManager:90] - invoking getAcceptedIssuers invoked for edu.vt.middleware.ldap.ssl.HostnameVerifyingTrustManager@77e71285
16:08:03.685 - TRACE [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler:69] - processing relative dn: CN=6132922
16:08:03.686 - TRACE [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler:95] - processed dn: CN=6132922,ou=Students,dc=kicds,dc=com
16:08:03.686 - TRACE [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:93] - setting connectionStrategy: RANDOM
16:08:03.687 - TRACE [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:110] - setting connectionRetryExceptions: [class javax.naming.NamingException]
16:08:03.687 - TRACE [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:152] - {1} Attempting connection to ldaps://192.168.148.134:636 for strategy RANDOM
16:08:03.687 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the following parameters:
16:08:03.688 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] -   authtype = simple
16:08:03.688 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] -   dn = CN=6132922,ou=Students,dc=kicds,dc=com
16:08:03.689 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -   credential = <suppressed>
16:08:03.689 - TRACE [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:87] -   env = {java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.provider.url=ldaps://192.168.148.134:636, java.naming.security.protocol=ssl}
16:08:03.693 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:128] - Set hostname verifier for ldaps
16:08:03.699 - DEBUG [edu.vt.middleware.ldap.ssl.AggregateTrustManager:75] - invoking checkServerTrusted for sun.security.ssl.X509TrustManagerImpl@71ce925b
16:08:03.699 - DEBUG [edu.vt.middleware.ldap.ssl.AggregateTrustManager:75] - invoking checkServerTrusted for edu.vt.middleware.ldap.ssl.HostnameVerifyingTrustManager@6156e93d
16:08:03.700 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:122] - Verify with the following parameters:
16:08:03.700 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:123] -   hostname = 192.168.148.134
16:08:03.701 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:124] -   cert = CN=kicds.com, OU=KIC, O=Kaplan, L=London, ST=UK, C=UK
16:08:03.702 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:155] - verifyIP using subjectAltNames = [192.168.148.134, 192.168.148.210, 192.168.199.251]
16:08:03.702 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:161] - verifyIP found hostname match: 192.168.148.134
16:08:03.703 - DEBUG [edu.vt.middleware.ldap.ssl.AggregateTrustManager:90] - invoking getAcceptedIssuers invoked for sun.security.ssl.X509TrustManagerImpl@71ce925b
16:08:03.703 - DEBUG [edu.vt.middleware.ldap.ssl.AggregateTrustManager:90] - invoking getAcceptedIssuers invoked for edu.vt.middleware.ldap.ssl.HostnameVerifyingTrustManager@6156e93d
16:08:03.915 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:163] - Error connecting to LDAP URL: ldaps://192.168.148.134:636
javax.naming.AuthenticationException: [LDAP: error code 49 - 80090308: LdapErr: DSID-0C0903A9, comment: AcceptSecurityContext error, data 52e, v1db1]
	at com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3087) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:3033) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2835) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2749) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:316) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:193) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:211) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:154) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:84) ~[na:1.7.0_21]
	at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:684) ~[na:1.7.0_21]
	at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:307) ~[na:1.7.0_21]
	at javax.naming.InitialContext.init(InitialContext.java:242) ~[na:1.7.0_21]
	at javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:153) ~[na:1.7.0_21]
	at edu.vt.middleware.ldap.handler.DefaultConnectionHandler.connectInternal(DefaultConnectionHandler.java:134) ~[vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.handler.AbstractConnectionHandler.connect(AbstractConnectionHandler.java:156) ~[vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.auth.handler.BindAuthenticationHandler.authenticate(BindAuthenticationHandler.java:53) [vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.auth.AbstractAuthenticator.authenticateAndAuthorize(AbstractAuthenticator.java:174) [vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.jaas.JaasAuthenticator.authenticate(JaasAuthenticator.java:74) [vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.auth.Authenticator.authenticate(Authenticator.java:320) [vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.auth.Authenticator.authenticate(Authenticator.java:277) [vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.jaas.JaasAuthenticator.authenticate(JaasAuthenticator.java:60) [vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.jaas.LdapLoginModule.login(LdapLoginModule.java:103) [vt-ldap-3.3.6.jar:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_21]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_21]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_21]
	at java.lang.reflect.Method.invoke(Method.java:601) ~[na:1.7.0_21]
	at javax.security.auth.login.LoginContext.invoke(LoginContext.java:784) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext.access$000(LoginContext.java:203) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext$4.run(LoginContext.java:698) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext$4.run(LoginContext.java:696) [na:1.7.0_21]
	at java.security.AccessController.doPrivileged(Native Method) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:695) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext.login(LoginContext.java:594) [na:1.7.0_21]
	at edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet.authenticateUser(UsernamePasswordLoginServlet.java:177) [shibboleth-identityprovider-2.3.8.jar:na]
	at edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet.service(UsernamePasswordLoginServlet.java:123) [shibboleth-identityprovider-2.3.8.jar:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) [tomcat6-servlet-2.5-api-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at unimr.shib2.UniMrMemcachedServletFilter.doFilter(UniMrMemcachedServletFilter.java:53) [unimr-memcached-idp2.4-rev218.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:50) [shibboleth-identityprovider-2.3.8.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:81) [shibboleth-identityprovider-2.3.8.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:52) [shibboleth-common-1.3.7.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina-6.0.24.jar:na]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina-6.0.24.jar:na]
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298) [catalina-6.0.24.jar:na]
	at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:769) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:698) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:891) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690) [tomcat-coyote-6.0.24.jar:na]
	at java.lang.Thread.run(Thread.java:722) [na:1.7.0_21]
16:08:03.916 - TRACE [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:152] - {1} Attempting connection to ldaps://192.168.148.210:636 for strategy RANDOM
16:08:03.916 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the following parameters:
16:08:03.916 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] -   authtype = simple
16:08:03.917 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] -   dn = CN=6132922,ou=Students,dc=kicds,dc=com
16:08:03.917 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -   credential = <suppressed>
16:08:03.917 - TRACE [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:87] -   env = {java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.provider.url=ldaps://192.168.148.210:636, java.naming.security.protocol=ssl}
16:08:03.919 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:128] - Set hostname verifier for ldaps
16:08:03.923 - DEBUG [edu.vt.middleware.ldap.ssl.AggregateTrustManager:75] - invoking checkServerTrusted for sun.security.ssl.X509TrustManagerImpl@1b6606b5
16:08:03.924 - DEBUG [edu.vt.middleware.ldap.ssl.AggregateTrustManager:75] - invoking checkServerTrusted for edu.vt.middleware.ldap.ssl.HostnameVerifyingTrustManager@16204e3c
16:08:03.924 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:122] - Verify with the following parameters:
16:08:03.925 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:123] -   hostname = 192.168.148.210
16:08:03.925 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:124] -   cert = CN=kicds.com, OU=KIC, O=Kaplan, L=London, ST=UK, C=UK
16:08:03.925 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:155] - verifyIP using subjectAltNames = [192.168.148.134, 192.168.148.210, 192.168.199.251]
16:08:03.925 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:161] - verifyIP found hostname match: 192.168.148.210
16:08:03.926 - DEBUG [edu.vt.middleware.ldap.ssl.AggregateTrustManager:90] - invoking getAcceptedIssuers invoked for sun.security.ssl.X509TrustManagerImpl@1b6606b5
16:08:03.926 - DEBUG [edu.vt.middleware.ldap.ssl.AggregateTrustManager:90] - invoking getAcceptedIssuers invoked for edu.vt.middleware.ldap.ssl.HostnameVerifyingTrustManager@16204e3c
16:08:04.141 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:163] - Error connecting to LDAP URL: ldaps://192.168.148.210:636
javax.naming.AuthenticationException: [LDAP: error code 49 - 80090308: LdapErr: DSID-0C0903A9, comment: AcceptSecurityContext error, data 52e, v1db1]
	at com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3087) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:3033) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2835) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2749) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:316) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:193) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:211) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:154) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:84) ~[na:1.7.0_21]
	at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:684) ~[na:1.7.0_21]
	at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:307) ~[na:1.7.0_21]
	at javax.naming.InitialContext.init(InitialContext.java:242) ~[na:1.7.0_21]
	at javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:153) ~[na:1.7.0_21]
	at edu.vt.middleware.ldap.handler.DefaultConnectionHandler.connectInternal(DefaultConnectionHandler.java:134) ~[vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.handler.AbstractConnectionHandler.connect(AbstractConnectionHandler.java:156) ~[vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.auth.handler.BindAuthenticationHandler.authenticate(BindAuthenticationHandler.java:53) [vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.auth.AbstractAuthenticator.authenticateAndAuthorize(AbstractAuthenticator.java:174) [vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.jaas.JaasAuthenticator.authenticate(JaasAuthenticator.java:74) [vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.auth.Authenticator.authenticate(Authenticator.java:320) [vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.auth.Authenticator.authenticate(Authenticator.java:277) [vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.jaas.JaasAuthenticator.authenticate(JaasAuthenticator.java:60) [vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.jaas.LdapLoginModule.login(LdapLoginModule.java:103) [vt-ldap-3.3.6.jar:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_21]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_21]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_21]
	at java.lang.reflect.Method.invoke(Method.java:601) ~[na:1.7.0_21]
	at javax.security.auth.login.LoginContext.invoke(LoginContext.java:784) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext.access$000(LoginContext.java:203) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext$4.run(LoginContext.java:698) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext$4.run(LoginContext.java:696) [na:1.7.0_21]
	at java.security.AccessController.doPrivileged(Native Method) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:695) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext.login(LoginContext.java:594) [na:1.7.0_21]
	at edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet.authenticateUser(UsernamePasswordLoginServlet.java:177) [shibboleth-identityprovider-2.3.8.jar:na]
	at edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet.service(UsernamePasswordLoginServlet.java:123) [shibboleth-identityprovider-2.3.8.jar:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) [tomcat6-servlet-2.5-api-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at unimr.shib2.UniMrMemcachedServletFilter.doFilter(UniMrMemcachedServletFilter.java:53) [unimr-memcached-idp2.4-rev218.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:50) [shibboleth-identityprovider-2.3.8.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:81) [shibboleth-identityprovider-2.3.8.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:52) [shibboleth-common-1.3.7.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina-6.0.24.jar:na]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina-6.0.24.jar:na]
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298) [catalina-6.0.24.jar:na]
	at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:769) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:698) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:891) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690) [tomcat-coyote-6.0.24.jar:na]
	at java.lang.Thread.run(Thread.java:722) [na:1.7.0_21]
16:08:04.142 - INFO [edu.vt.middleware.ldap.jaas.JaasAuthenticator:180] - Authentication failed for dn: CN=6132922,ou=Students,dc=kicds,dc=com
16:08:04.143 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:136] - Authentication failed
javax.naming.AuthenticationException: [LDAP: error code 49 - 80090308: LdapErr: DSID-0C0903A9, comment: AcceptSecurityContext error, data 52e, v1db1]
	at com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3087) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:3033) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2835) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2749) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:316) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:193) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:211) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:154) ~[na:1.7.0_21]
	at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:84) ~[na:1.7.0_21]
	at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:684) ~[na:1.7.0_21]
	at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:307) ~[na:1.7.0_21]
	at javax.naming.InitialContext.init(InitialContext.java:242) ~[na:1.7.0_21]
	at javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:153) ~[na:1.7.0_21]
	at edu.vt.middleware.ldap.handler.DefaultConnectionHandler.connectInternal(DefaultConnectionHandler.java:134) ~[vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.handler.AbstractConnectionHandler.connect(AbstractConnectionHandler.java:156) ~[vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.auth.handler.BindAuthenticationHandler.authenticate(BindAuthenticationHandler.java:53) ~[vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.auth.AbstractAuthenticator.authenticateAndAuthorize(AbstractAuthenticator.java:174) ~[vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.jaas.JaasAuthenticator.authenticate(JaasAuthenticator.java:74) ~[vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.auth.Authenticator.authenticate(Authenticator.java:320) ~[vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.auth.Authenticator.authenticate(Authenticator.java:277) ~[vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.jaas.JaasAuthenticator.authenticate(JaasAuthenticator.java:60) ~[vt-ldap-3.3.6.jar:na]
	at edu.vt.middleware.ldap.jaas.LdapLoginModule.login(LdapLoginModule.java:103) ~[vt-ldap-3.3.6.jar:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_21]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_21]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_21]
	at java.lang.reflect.Method.invoke(Method.java:601) ~[na:1.7.0_21]
	at javax.security.auth.login.LoginContext.invoke(LoginContext.java:784) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext.access$000(LoginContext.java:203) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext$4.run(LoginContext.java:698) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext$4.run(LoginContext.java:696) [na:1.7.0_21]
	at java.security.AccessController.doPrivileged(Native Method) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:695) [na:1.7.0_21]
	at javax.security.auth.login.LoginContext.login(LoginContext.java:594) [na:1.7.0_21]
	at edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet.authenticateUser(UsernamePasswordLoginServlet.java:177) [shibboleth-identityprovider-2.3.8.jar:na]
	at edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet.service(UsernamePasswordLoginServlet.java:123) [shibboleth-identityprovider-2.3.8.jar:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) [tomcat6-servlet-2.5-api-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at unimr.shib2.UniMrMemcachedServletFilter.doFilter(UniMrMemcachedServletFilter.java:53) [unimr-memcached-idp2.4-rev218.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:50) [shibboleth-identityprovider-2.3.8.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:81) [shibboleth-identityprovider-2.3.8.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:52) [shibboleth-common-1.3.7.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina-6.0.24.jar:na]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [catalina-6.0.24.jar:na]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina-6.0.24.jar:na]
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298) [catalina-6.0.24.jar:na]
	at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:769) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:698) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:891) [tomcat-coyote-6.0.24.jar:na]
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690) [tomcat-coyote-6.0.24.jar:na]
	at java.lang.Thread.run(Thread.java:722) [na:1.7.0_21]
16:08:04.145 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:264] - Begin abort