Question
Credit One Bank
US
Last activity: 12 Feb 2020 16:28 EST
LDAP AD Authentication failues - how to enable LDAP logging?
We have multiple AD servers under a CNAME
Our Pega application attempts to perform LDAP Auth against a server listed in this CNAME.
This works fine most of the time. Occasionally we get an External AUTH failure and users are unable to login.
How do we enable more logging for the LDAP AD authentication?
[tomcat@laswcmprd01data02 logs]$ nslookup fnbm.corp
Server: Proprietary information hidden
Address: Proprietary information hidden#53
Name: ad_cname.corp
Address: Proprietary information hidden
Name: ad_cname.corp
Address: Proprietary information hidden
Name: ad_cname.corp
Address: Proprietary information hidden
Name: ad_cname.corp
Address: Proprietary information hidden
Name: ad_cname.corp
Address: Proprietary information hidden
We have multiple AD servers under a CNAME
Our Pega application attempts to perform LDAP Auth against a server listed in this CNAME.
This works fine most of the time. Occasionally we get an External AUTH failure and users are unable to login.
How do we enable more logging for the LDAP AD authentication?
[tomcat@laswcmprd01data02 logs]$ nslookup fnbm.corp
Server: Proprietary information hidden
Address: Proprietary information hidden#53
Name: ad_cname.corp
Address: Proprietary information hidden
Name: ad_cname.corp
Address: Proprietary information hidden
Name: ad_cname.corp
Address: Proprietary information hidden
Name: ad_cname.corp
Address: Proprietary information hidden
Name: ad_cname.corp
Address: Proprietary information hidden
External authentication failed:
javax.naming.CommunicationException: AD_CNAME:389
at com.sun.jndi.ldap.Connection.<init>(Connection.java:238) ~[?:1.8.0_181]
at com.sun.jndi.ldap.LdapClient.<init>(LdapClient.java:137) ~[?:1.8.0_181]
at com.sun.jndi.ldap.LdapClient.getInstance(LdapClient.java:1615) ~[?:1.8.0_181]
at com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2749) ~[?:1.8.0_181]
at com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:319) ~[?:1.8.0_181]
at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:192) ~[?:1.8.0_181]
at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:210) ~[?:1.8.0_181]
at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:153) ~[?:1.8.0_181]
at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:83) ~[?:1.8.0_181]
at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:684) ~[?:1.8.0_181]
at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:313) ~[?:1.8.0_181]
at javax.naming.InitialContext.init(InitialContext.java:244) ~[?:1.8.0_181]
at javax.naming.InitialContext.<init>(InitialContext.java:216) ~[?:1.8.0_181]
at javax.naming.directory.InitialDirContext.<init>(InitialDirContext.java:101) ~[?:1.8.0_181]
at com.pegarules.generated.activity.ra_action_authenticationldapverifycredentials_ab6bace28b3af2ab0886d7af8a654d98.step3_circum0(ra_action_authenticationldapverifycredentials_ab6bace28b3af2ab0886d7af8a654d98.java:793) ~[?:?]
at com.pegarules.generated.activity.ra_action_authenticationldapverifycredentials_ab6bace28b3af2ab0886d7af8a654d98.perform(ra_action_authenticationldapverifycredentials_ab6bace28b3af2ab0886d7af8a654d98.java:104) ~[?:?]
at com.pega.pegarules.session.internal.mgmt.Executable.doActivity(Executable.java:3556) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.mgmt.Executable.invokeActivity(Executable.java:10885) ~[prprivate.jar:?]
at com.pegarules.generated.activity.ra_action_authenticationldap_41dc4e39384c3bd5e2fa99cc916a78b6.step2_circum0(ra_action_authenticationldap_41dc4e39384c3bd5e2fa99cc916a78b6.java:323) ~[?:?]
at com.pegarules.generated.activity.ra_action_authenticationldap_41dc4e39384c3bd5e2fa99cc916a78b6.perform(ra_action_authenticationldap_41dc4e39384c3bd5e2fa99cc916a78b6.java:88) ~[?:?]
at com.pega.pegarules.session.internal.mgmt.Executable.doActivity(Executable.java:3556) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.mgmt.authentication.AuthenticationUtil.runActivity(AuthenticationUtil.java:237) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.mgmt.authentication.SchemePRCustom.authenticateOperator(SchemePRCustom.java:715) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.mgmt.authentication.Authentication.doAuthentication(Authentication.java:491) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.engineinterface.service.HTTPAuthenticationHandler.performAuthentication(HTTPAuthenticationHandler.java:251) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.engineinterface.service.HTTPAuthenticationHandler.doHttpReqAuthentication(HTTPAuthenticationHandler.java:94) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.engineinterface.service.HttpAPI.handleAuthentication(HttpAPI.java:2542) ~[prprivate.jar:?]
at com.pega.pegarules.session.external.engineinterface.service.EngineAPI.activityExecutionProlog(EngineAPI.java:594) ~[prenginext.jar:?]
at com.pega.pegarules.session.external.engineinterface.service.EngineAPI.processRequestInner(EngineAPI.java:433) ~[prenginext.jar:?]
at sun.reflect.GeneratedMethodAccessor87.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_181]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_181]
at com.pega.pegarules.session.internal.PRSessionProviderImpl.performTargetActionWithLock(PRSessionProviderImpl.java:1377) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.PRSessionProviderImpl.doWithRequestorLocked(PRSessionProviderImpl.java:1109) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.PRSessionProviderImpl.doWithRequestorLocked(PRSessionProviderImpl.java:963) ~[prprivate.jar:?]
at com.pega.pegarules.session.external.engineinterface.service.EngineAPI.processRequest(EngineAPI.java:361) ~[prenginext.jar:?]
at com.pega.pegarules.session.internal.engineinterface.service.HttpAPI.invoke(HttpAPI.java:883) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.engineinterface.etier.impl.EngineImpl._invokeEngine_privact(EngineImpl.java:331) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.engineinterface.etier.impl.EngineImpl.invokeEngine(EngineImpl.java:274) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.engineinterface.etier.impl.EngineImpl.invokeEngine(EngineImpl.java:251) ~[prprivate.jar:?]
at com.pega.pegarules.priv.context.JNDIEnvironment.invokeEngineInner(JNDIEnvironment.java:275) ~[prpublic.jar:?]
at com.pega.pegarules.priv.context.JNDIEnvironment.invokeEngine(JNDIEnvironment.java:220) ~[prpublic.jar:?]
at com.pega.pegarules.web.impl.WebStandardImpl.makeEtierRequest(WebStandardImpl.java:733) ~[prwebj2ee.jar:?]
at com.pega.pegarules.web.impl.WebStandardImpl.doPost(WebStandardImpl.java:399) ~[prwebj2ee.jar:?]
at sun.reflect.GeneratedMethodAccessor85.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_181]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_181]
at com.pega.pegarules.internal.bootstrap.PRBootstrap.invokeMethod(PRBootstrap.java:370) ~[prbootstrap-8.1.2-340.jar:8.1.2-340]
at com.pega.pegarules.internal.bootstrap.PRBootstrap.invokeMethodPropagatingThrowable(PRBootstrap.java:411) ~[prbootstrap-8.1.2-340.jar:8.1.2-340]
at com.pega.pegarules.boot.internal.extbridge.AppServerBridgeToPega.invokeMethodPropagatingThrowable(AppServerBridgeToPega.java:224) ~[prbootstrap-api-8.1.2-340.jar:8.1.2-340]
at com.pega.pegarules.boot.internal.extbridge.AppServerBridgeToPega.invokeMethod(AppServerBridgeToPega.java:273) ~[prbootstrap-api-8.1.2-340.jar:8.1.2-340]
at com.pega.pegarules.internal.web.servlet.WebStandardBoot.doPost(WebStandardBoot.java:129) ~[prbootstrap-api-8.1.2-340.jar:8.1.2-340]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:661) ~[servlet-api.jar:?]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) ~[servlet-api.jar:?]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[catalina.jar:8.5.15]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[catalina.jar:8.5.15]
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) ~[tomcat-websocket.jar:8.5.15]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[catalina.jar:8.5.15]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[catalina.jar:8.5.15]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) ~[catalina.jar:8.5.15]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) ~[catalina.jar:8.5.15]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:595) ~[catalina.jar:8.5.15]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) ~[catalina.jar:8.5.15]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80) ~[catalina.jar:8.5.15]
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:624) ~[catalina.jar:8.5.15]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) ~[catalina.jar:8.5.15]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) ~[catalina.jar:8.5.15]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799) ~[tomcat-coyote.jar:8.5.15]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) ~[tomcat-coyote.jar:8.5.15]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861) ~[tomcat-coyote.jar:8.5.15]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455) ~[tomcat-coyote.jar:8.5.15]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-coyote.jar:8.5.15]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_181]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_181]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-util.jar:8.5.15]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_181]
Caused by: java.net.ConnectException: Connection timed out (Connection timed out)
at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:1.8.0_181]
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[?:1.8.0_181]
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[?:1.8.0_181]
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[?:1.8.0_181]
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:1.8.0_181]
at java.net.Socket.connect(Socket.java:589) ~[?:1.8.0_181]
at java.net.Socket.connect(Socket.java:538) ~[?:1.8.0_181]
at java.net.Socket.<init>(Socket.java:434) ~[?:1.8.0_181]
at java.net.Socket.<init>(Socket.java:211) ~[?:1.8.0_181]
at com.sun.jndi.ldap.Connection.createSocket(Connection.java:375) ~[?:1.8.0_181]
at com.sun.jndi.ldap.Connection.<init>(Connection.java:215) ~[?:1.8.0_181]
***Edited by Moderator Marissa to update SR Details***
Accepted Solution
Credit One Bank
US
Hi Harish,
We took two actions: 1) added the logging 2) removed the CNAME for multiple ADs and replaced with single AD.
At this point we believe that 1 of the AD servers was having sporadic issues.
With a single AD server we have not seen any issues. We are working to replace the 1 'bad' AD server and will revert back to the CNAME.
Thanks for the help!
Pegasystems Inc.
US
Hi Robert,
As you might be aware, the debug on LDAP Authentication activities may not help much as the failure is external.
The 2nd step (Java) of AuthenticationLDAPVerifyCredentials OOTB activity does the actual LDAP AD lookup with the help of com.sun.jndi.ldap.XXXX classes from the JDK. Pega may not have any control to enable debug logging level on JDK specific libraries.
The libraries are internal to JDK and as per the article, you may try the below JVM arguments to see if it helps to log additional logging.
-Dcom.sun.jndi.ldap.connect.pool.debug=all
Info on LDAP system settings- https://docs.oracle.com/javase/jndi/tutorial/ldap/connect/config.html
Let me know if that helps!
Accepted Solution
Credit One Bank
US
Hi Harish,
We took two actions: 1) added the logging 2) removed the CNAME for multiple ADs and replaced with single AD.
At this point we believe that 1 of the AD servers was having sporadic issues.
With a single AD server we have not seen any issues. We are working to replace the 1 'bad' AD server and will revert back to the CNAME.
Thanks for the help!